scheduler.py

#
# Aura Engine (https://gitlab.servus.at/aura/engine)
#
# Copyright (C) 2017-2020 - The Aura Engine Team.

# This program is free software: you can redistribute it and/or modify
# it under the terms of the GNU Affero General Public License as published by
# the Free Software Foundation, either version 3 of the License, or
# (at your option) any later version.

# This program 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 Affero General Public License for more details.

# You should have received a copy of the GNU Affero General Public License
# along with this program.  If not, see <http://www.gnu.org/licenses/>.


import logging
import threading
import time
import sqlalchemy

from enum                       import Enum
from operator                   import attrgetter
from datetime                   import datetime, timedelta

from src.base.config            import AuraConfig
from src.base.utils             import SimpleUtil as SU
from src.base.models            import AuraDatabaseModel, Schedule, Playlist
from src.base.exceptions        import NoActiveScheduleException, LoadSourceException
from src.core.control           import EngineExecutor
from src.core.engine            import Engine
from src.core.channels          import ChannelType, TransitionType, EntryPlayState
from src.core.resources         import ResourceClass, ResourceUtil
from src.scheduling.calendar    import AuraCalendarService
from src.scheduling.fallback    import FallbackManager




class EntryQueueState(Enum):
    """
    Types of playlist entry behaviours.
    """
    OKAY = "ok"
    CUT = "cut"
    OUT_OF_SCHEDULE = "oos"



class AuraScheduler(threading.Thread):
    """
    Aura Scheduler Class

    - Retrieves data from Steering and Tank
    - Executes engine actions in an automated fashion

    Attributes:
        config (AuraConfig):                    Holds the Engine Configuration
        logger:                                 The logger
        exit_event(threading.Event):            Used to exit the thread if requested
        engine:                            Virtual mixer
        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(List<threading.Timer>):   The timer queue of sound-system commands for playlists/entries to be played
    """
    config = None
    logger = None
    engine = None
    exit_event = None    
    is_initialized = None
    is_initialized = None

    last_successful_fetch = None
    programme = None
    message_timer = []
    fallback = None




    def __init__(self, engine):
        """
        Constructor

        Args:
            config (AuraConfig):        Reads the engine configuration
            engine (Engine):            The engine to play the schedule on
            func_on_init (Function):    The function to be called when the scheduler is initialized
        """
        self.config = AuraConfig.config()
        self.logger = logging.getLogger("AuraEngine")

        AuraScheduler.init_database()
        self.fallback = FallbackManager(self)
        self.engine = engine
        self.engine.scheduler = self
        self.is_soundsytem_init = False
        
        # Scheduler Initialization
        self.is_initialized = False
        self.is_engine_ready = False

        # Init scheduling thread
        threading.Thread.__init__(self)
        self.exit_event = threading.Event()
        self.start()



    def run(self):
        """
        Called when thread is started via `start()`. It does the 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 schedules of the programme, if the soundssystem is ready to accept commands.

        On every cycle the configuration file is reloaded, to allow modifications while running the engine.
        """
        while not self.exit_event.is_set():
            try:
                self.config.load_config()
                seconds_to_wait = int(self.config.get("fetching_frequency"))
                self.logger.info(SU.cyan(f"== start fetching new schedules (every {seconds_to_wait} seconds) =="))
                
                # Load some stuff from the API in any case
                self.fetch_new_programme()

                # Called upon first boot only
                if self.is_engine_ready:
                    if not self.is_initialized:

                        # Queue the start items
                        self.is_initialized = True
                        self.on_scheduler_ready()

                    # Queue all the other ones
                    self.queue_programme()

            except Exception as e:
                self.logger.critical(SU.red(f"Unhandled error while fetching & scheduling new programme! ({str(e)})"), e)
                # Keep on working anyway

            self.clean_timer_queue()
            self.print_timer_queue()
                        
            # FIXME better location for call
            if self.engine.event_dispatcher:
                current_timeslot = self.get_active_schedule()
                self.engine.event_dispatcher.on_timeslot(current_timeslot)
            
            EngineExecutor.log_commands()            
            self.exit_event.wait(seconds_to_wait)



#
#   PUBLIC METHODS
#


    def on_ready(self):
        """
        Called when the engine is ready.
        """
        self.is_engine_ready = True


    def on_scheduler_ready(self):
        """
        Called when the scheduler is ready.
        """
        self.logger.info(self.get_ascii_programme())

        try:
            self.play_active_entry()
            self.queue_startup_entries()
        except NoActiveScheduleException:
            # That's not good, but keep on working...
            pass



    def play_active_entry(self):
        """
        Plays the entry scheduled for the very current moment and forwards to the scheduled position in time. 
        Usually called when the Engine boots.

        Raises:
            (NoActiveScheduleException):    If there's no schedule in the programme, within the scheduling window
        """
        sleep_offset = 10
        active_schedule = self.get_active_schedule()

        # Schedule any available fallback playlist
        if active_schedule:
            self.fallback.queue_fallback_playlist(active_schedule)
            # Queue the fade-out of the schedule
            if not active_schedule.fadeouttimer:
                self.queue_end_of_schedule(active_schedule, True)

        active_entry = self.get_active_entry()
        if not active_entry:
            raise NoActiveScheduleException

        # In case of a file-system source, we need to fast-foward to the current marker as per schedule
        if active_entry.get_content_type() in ResourceClass.FILE.types:

            # Calculate the seconds we have to fast-forward
            now_unix = Engine.engine_time()
            seconds_to_seek = now_unix - active_entry.start_unix

            # If the seek exceeds the length of the current track, 
            # there's no need to do anything - the scheduler takes care of the rest
            if (seconds_to_seek + sleep_offset) > active_entry.duration:
                self.logger.info("The FFWD [>>] range exceeds the length of the entry. Drink some tea and wait for the sound of the next entry.")
            else:                
                # Pre-roll and play active entry
                self.engine.player.preload(active_entry)
                self.engine.player.play(active_entry, TransitionType.FADE)

                # Fast-forward to the scheduled position
                if seconds_to_seek > 0:
                    # Without plenty of timeout (10s) the seek doesn't work
                    def async_cue_seek(seconds_to_seek):
                        seconds_to_seek += sleep_offset
                        time.sleep(sleep_offset)
                        self.logger.info("Going to fast-forward %s seconds" % seconds_to_seek)
                        response = self.engine.player.queue_seek(active_entry.channel, seconds_to_seek)
                        self.logger.info("Sound-system seek response: " + response)

                    thread = threading.Thread(target = async_cue_seek, args = (seconds_to_seek,))
                    thread.start()                         

        elif active_entry.get_content_type() in ResourceClass.STREAM.types \
            or active_entry.get_content_type() in ResourceClass.LIVE.types:

            # Pre-roll and play active entry
            self.engine.player.preload(active_entry)
            self.engine.player.play(active_entry, TransitionType.FADE)

        else:
            self.logger.critical("Unknown Entry Type: %s" % active_entry)
        



    def get_active_entry(self):
        """
        Retrieves the current `PlaylistEntry` which should be played as per programme. 

        Returns:
            (PlaylistEntry): The track which is (or should) currently being played
        """
        now_unix = Engine.engine_time()

        # Load programme if necessary
        if not self.programme:
            self.load_programme_from_db()

        # Check for current schedule
        current_schedule = self.get_active_schedule()
        if not current_schedule:
            self.logger.warning(SU.red("There's no active timeslot"))
            return None

        # Check for scheduled playlist
        current_playlist = current_schedule.get_playlist()
        if not current_playlist:
            msg = "There's no playlist assigned to the current timeslot. Most likely a fallback will make things okay again."
            self.logger.warning(SU.red(msg))
            return None

        # Iterate over playlist entries and store the current one
        current_entry = None
        for entry in current_playlist.entries:
            if entry.start_unix <= now_unix and now_unix <= entry.end_unix:
                current_entry = entry
                break       
      
        if not current_entry:
            # Nothing playing ... fallback will kick-in
            msg = "There's no entry scheduled for playlist '%s' at %s" % (str(current_playlist), SU.fmt_time(now_unix))
            self.logger.warning(SU.red(msg))
            return None

        return current_entry



    def get_active_schedule(self):
        """
        Retrieves the schedule currently to be played. 
        
        Returns:
            (Schedule): The current schedule
        """
        current_schedule = None
        now_unix = Engine.engine_time()

        # Iterate over all schedules and find the one to be played right now
        if self.programme:
            for schedule in self.programme:
                if schedule.start_unix <= now_unix and now_unix < schedule.end_unix:
                    current_schedule = schedule
                    break
        
        return current_schedule



    def get_next_timeslots(self, max_count=0):
        """
        Retrieves the timeslots to be played after the current one.

        Args:
            max_count (Integer): Maximum of timeslots to return, if `0` all exitsing ones are returned
        Returns:
            ([Timeslot]): The next timeslots
        """
        now_unix = Engine.engine_time()
        next_schedules = []

        for schedule in self.programme:
            if schedule.start_unix > now_unix:
                if (len(next_schedules) < max_count) or max_count == 0:
                    next_schedules.append(schedule)
                else:
                    break
                
        return next_schedules


    def get_active_playlist(self):
        """
        Retrieves the currently playing playlist.

        Returns:
            (Playlist): The resolved playlist
        """
        schedule = self.get_active_schedule()
        if schedule:
            return schedule.get_playlist()
        return None



    def print_timer_queue(self):
        """
        Prints the current timer 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(SU.red("There's nothing in the Timer Queue!"))
        else:
            for msg in messages:
                message_queue += str(msg)+"\n"

            self.logger.info("Timer queue: \n" + message_queue) 



    def clean_timer_queue(self):
        """
        Removes inactive timers from the queue.
        """
        len_before = len(self.message_timer)
        self.message_timer[:] = [m for m in self.message_timer if m.is_alive()]
        len_after = len(self.message_timer)
        self.logger.debug("Removed %s finished timer objects from queue" % (len_before - len_after))




    def get_ascii_programme(self):
        """
        Creates a printable version of the current programme (playlists and entries as per schedule) 

        Returns:
            (String):   An ASCII representation of the programme
        """
        active_schedule = self.get_active_schedule()

        s = "\n\n   SCHEDULED NOW:"
        s += "\n┌──────────────────────────────────────────────────────────────────────────────────────────────────────"
        if active_schedule:
            planned_playlist = None
            if active_schedule.playlist:
                planned_playlist = active_schedule.playlist[0]

            (fallback_type, resolved_playlist) = self.fallback.resolve_playlist(active_schedule)

            s += "\n│   Playing timeslot %s         " % active_schedule
            if planned_playlist: 
                if resolved_playlist and resolved_playlist.playlist_id != planned_playlist.playlist_id:
                    s += "\n│       └── Playlist %s         " % planned_playlist
                    s += "\n│       "
                    s += SU.red("↑↑↑ That's the originally planned playlist.") + ("Instead playing the fallback playlist below ↓↓↓")

            if resolved_playlist:                                  
                if not planned_playlist:
                    s += "\n│                         "
                    s += SU.red("No playlist assigned to timeslot. Instead playing the `%s` playlist below ↓↓↓" % SU.cyan(str(fallback_type)))

                s += "\n│       └── Playlist %s         " % resolved_playlist

                active_entry = self.get_active_entry()

                # Finished entries
                for entry in resolved_playlist.entries:
                    if active_entry == entry:
                        break
                    else:
                        s += self.build_entry_string("\n│         └── ", entry, True)

                # Entry currently being played
                if active_entry:
                    s += "\n│         └── Entry %s | %s         " % \
                        (str(active_entry.entry_num+1), SU.green("PLAYING > "+str(active_entry)))

                    # Open entries for current playlist
                    rest_of_playlist = active_entry.get_next_entries(False)
                    entries = self.preprocess_entries(rest_of_playlist, False)
                    s += self.build_playlist_string(entries)
                    
            else:
                s += "\n│       └── %s" % (SU.red("No active playlist. There should be at least some fallback playlist running..."))
        else:
            s += "\n│   Nothing.           "
        s += "\n└──────────────────────────────────────────────────────────────────────────────────────────────────────"

        s += "\n   SCHEDULED NEXT:"
        s += "\n┌──────────────────────────────────────────────────────────────────────────────────────────────────────"

        next_schedules = self.get_next_timeslots()
        if not next_schedules:
            s += "\n│   Nothing.         "
        else:
            for schedule in next_schedules:        
                (fallback_type, resolved_playlist) = self.fallback.resolve_playlist(schedule)
                if resolved_playlist:

                    s += "\n│   Queued timeslot %s         " % schedule
                    s += "\n│      └── Playlist %s         (Type: %s)" % (resolved_playlist, SU.cyan(str(fallback_type)))
                    if resolved_playlist.end_unix > schedule.end_unix:
                        s += "\n│          %s!              " % \
                        (SU.red("↑↑↑ Playlist #%s ends after timeslot #%s!" % (resolved_playlist.playlist_id, schedule.schedule_id)))
                    
                    entries = self.preprocess_entries(resolved_playlist.entries, False)
                    s += self.build_playlist_string(entries)

        s += "\n└──────────────────────────────────────────────────────────────────────────────────────────────────────\n\n"
        return s



    def build_playlist_string(self, entries):
        """
        Returns a stringified list of entries
        """
        s = ""
        is_out_of_schedule = False

        for entry in entries:
            if entry.queue_state == EntryQueueState.OUT_OF_SCHEDULE and not is_out_of_schedule:
                s += "\n│             %s" % \
                    SU.red("↓↓↓ These entries won't be played because they are out of schedule.")
                is_out_of_schedule = True

            s += self.build_entry_string("\n│         └── ", entry, is_out_of_schedule)

        return s



    def build_entry_string(self, prefix, entry, strike):
        """
        Returns an stringified entry.
        """
        s = ""
        if entry.queue_state == EntryQueueState.CUT:
            s = "\n│             %s" % SU.red("↓↓↓ This entry is going to be cut.")

        if strike:
            entry_str = SU.strike(entry)
        else:
            entry_str = str(entry)

        entry_line = "%sEntry %s | %s" % (prefix, str(entry.entry_num+1), entry_str)
        return s + entry_line



#
#   PRIVATE METHODS
#



    def filter_scheduling_window(self, schedules):
        """
        Ignore schedules which are beyond the scheduling window. The end of the scheduling window
        is defined by the config option `scheduling_window_end`. This value defines the seconds
        minus the actual start time of the schedule.
        """
        now_unix = Engine.engine_time()
        len_before = len(schedules)
        window_start = self.config.get("scheduling_window_start")
        window_end = self.config.get("scheduling_window_end")
        schedules = list(filter(lambda s: (s.start_unix - window_end) > now_unix and (s.start_unix - window_start) < now_unix, schedules))
        len_after = len(schedules)
        self.logger.info("For now, skipped %s future schedule(s) which are out of the scheduling window (-%ss <-> -%ss)" % ((len_before - len_after), window_start, window_end))

        return schedules



    def is_schedule_in_window(self, schedule):
        """
        Checks if the schedule is within the scheduling window.
        """
        now_unix = Engine.engine_time()
        window_start = self.config.get("scheduling_window_start")
        window_end = self.config.get("scheduling_window_end")

        if schedule.start_unix - window_start < now_unix and \
            schedule.start_unix - window_end > now_unix:

            return True
        return False



    def queue_programme(self):
        """
        Queues the current programme (playlists as per schedule) by creating
        timed commands to the sound-system to enable the individual tracks of playlists. 
        """

        # Get a clean set of the timeslots within the scheduling window
        schedules = self.get_next_timeslots()
        schedules = self.filter_scheduling_window(schedules)

        # Queue the schedules, their playlists and entries
        if schedules:
            for next_schedule in schedules:
                # Schedule any available fallback playlist
                self.fallback.queue_fallback_playlist(next_schedule)

                if next_schedule.playlist:
                    self.queue_playlist_entries(next_schedule, next_schedule.get_playlist().entries, False, True)
                                
                # Queue the fade-out of the schedule
                if not next_schedule.fadeouttimer:
                    self.queue_end_of_schedule(next_schedule, True)

        self.logger.info(SU.green("Finished queuing programme."))



    def queue_startup_entries(self):
        """
        Queues all entries after the one currently playing upon startup. Don't use
        this method in any other scenario, as it doesn't respect the scheduling window.
        """
        current_schedule = self.get_active_schedule()
        
        # Queue the (rest of the) currently playing schedule upon startup
        if current_schedule:
            current_playlist = current_schedule.get_playlist()

            if current_playlist:
                active_entry = self.get_active_entry()

                # Finished entries
                for entry in current_playlist.entries:
                    if active_entry == entry:
                        break

                # Entry currently being played
                if active_entry:

                    # Queue open entries for current playlist
                    rest_of_playlist = active_entry.get_next_entries(True)
                    self.queue_playlist_entries(current_schedule, rest_of_playlist, False, True)

                    # Store them for later reference
                    current_schedule.queued_entries = [active_entry]
                    if rest_of_playlist:
                        current_schedule.queued_entries.append(rest_of_playlist)



    def queue_playlist_entries(self, schedule, entries, fade_in, fade_out):
        """
        Creates sound-system player commands for all playlist items to be executed at the scheduled time.

        Since each scheduled playlist can consist of multiple entry types such as *file*, *live*,
        and *stream*, the play-out of the schedule is actually a bit more complex. Before any playlist 
        entries of the schedule can be turned into sound, they need to be grouped, queued and pre-loaded.

        1. First, all entries are aggregated when they hold filesystem entries.
            Given you have a playlist with 10 entries, the first 4 are consisting of files, the next two
            of a a stream and a live source. The last 4 are files again. These entries are now
            aggregated into 4 groups: one for the files, one for the stream, one for the live entry
            and another one for files. For each group a timer for executing the next step is created.

        2. Now, the playlist entries are going to be "pre-loaded". This means that filesystem
            entries are queued and pre-loaded and entries which are based on audio streams are buffered.
            This is required to allow a seamless play-out, when its time to do so (in the next stage).
            Due to their nature, playlist entries which hold live audio sources are not affected by
            this stage at all.

        Args:
            schedule (Schedule):        The schedule this entries belong to
            entries ([PlaylistEntry]):  The playlist entries to be scheduled for playout
            fade_in (Boolean):          Fade-in at the beginning of the set of entries
            fade_out (Boolean):         Fade-out at the end of the set of entries

        Returns:
            (String):                   Formatted string to display playlist entries in log
        """       
        entry_groups = []
        entry_groups.append([])
        previous_entry = None
        index = 0

        # Mark entries which start after the end of their schedule or are cut
        clean_entries = self.preprocess_entries(entries, True)

        # Group/aggregate all filesystem entries, allowing them to be queued at once
        for entry in clean_entries:
            if previous_entry == None or \
                (previous_entry != None and \
                 previous_entry.get_content_type() == entry.get_content_type() and \
                 entry.get_content_type() in ResourceClass.FILE.types):
                
                entry_groups[index].append(entry)
            else:
                index += 1
                entry_groups.append([])
                entry_groups[index].append(entry)
            previous_entry = entry
        self.logger.info("Built %s entry group(s)" % len(entry_groups))
         
        # Schedule function calls
        do_queue_schedule_end = False
        if len(clean_entries) > 0 and len(entry_groups) > 0:
            for entries in entry_groups:
                if not isinstance(entries, list):
                    raise ValueError("Invalid Entry Group: %s" % str(entries))

                # Create timers for each entry group
                self.set_entries_timer(entries, fade_in, fade_out)

                # Store them for later reference
                schedule.queued_entries = clean_entries

        else:
            self.logger.warn(SU.red("Nothing to schedule ..."))



    def set_entries_timer(self, entries, fade_in, fade_out):
        """
        Creates timer for loading and playing one or multiple entries. Existing timers are 
        updated.

        Args:
            entries ([]): List of multiple filesystem entries, or a single entry of other types
        """
        play_timer = self.is_something_planned_at_time(entries[0].start_unix)
        now_unix = Engine.engine_time()
        diff = entries[0].start_unix - now_unix

        # Play function to be called by timer
        def do_play(entries):
            self.logger.info(SU.cyan("=== play('%s') ===" % ResourceUtil.get_entries_string(entries)))
            transition_type = TransitionType.INSTANT
            if fade_in:
                transition_type = TransitionType.FADE

            if entries[-1].status != EntryPlayState.READY:
                self.logger.critical(SU.red("PLAY: For some reason the entry/entries are not yet ready to be played (Entries: %s)" % ResourceUtil.get_entries_string(entries)))
                # Let 'em play anyway ...

            self.engine.player.play(entries[0], transition_type)
            self.logger.info(self.get_ascii_programme())


        if play_timer:
            # Check if the Playlist IDs are different
            if self.have_entries_changed(play_timer, entries):
                # If not, stop and remove the old timer, create a new one
                self.stop_timer(play_timer)                
            else:
                # If the playlist entries do not differ => reuse the old timer and do nothing
                self.logger.debug("Playlist Entry %s is already scheduled - no new timer created." % ResourceUtil.get_entries_string(entries))
                return
        
        # If nothing is planned at given time, create a new timer
        (entries[0].switchtimer, entries[0].loadtimer) = self.create_timer(diff, do_play, entries, switcher=True)



    def have_entries_changed(self, timer, new_entries):
        """
        Checks if the new entries and playlists are matching the existing queued ones,
        or if they should be updated.
        
        Args:
            timer (CallFunctionTimer):      The timer holding queued entries
            new_entries ([PlaylistEntry]):  The possibly updated entries

        Returns:
            (Boolean):  `True` if it has changed
        """
        old_entries = timer.entries

        if old_entries[0].playlist and new_entries[0].playlist:
            if old_entries[0].playlist.playlist_id != new_entries[0].playlist.playlist_id:
                return True
        if len(old_entries) != len(new_entries):
            return True

        for old_entry, new_entry in zip(old_entries, new_entries):
            if old_entry.source != new_entry.source:
                return True
        
        return False


    def preprocess_entries(self, entries, cut_oos):
        """
        Analyses and marks entries which are going to be cut or excluded.

        Args:
            entries ([PlaylistEntry]):  The playlist entries to be scheduled for playout
            cut_oos (Boolean):  If `True` entries which are 'out of schedule' are not returned

        Returns:
            ([PlaylistEntry]):  The list of processed playlist entries
        """
        clean_entries = []

        for entry in entries:

            if entry.entry_start >= entry.playlist.schedule.schedule_end:
                msg = "Filtered entry (%s) after end-of schedule (%s) ... SKIPPED" % (entry, entry.playlist.schedule)
                self.logger.warning(SU.red(msg))
                entry.queue_state = EntryQueueState.OUT_OF_SCHEDULE
            elif entry.end_unix > entry.playlist.schedule.end_unix:
                entry.queue_state = EntryQueueState.CUT
            else:
                entry.queue_state = EntryQueueState.OKAY
            
            if not entry.queue_state == EntryQueueState.OUT_OF_SCHEDULE or not cut_oos:
                clean_entries.append(entry)

        return clean_entries



    def queue_end_of_schedule(self, schedule, fade_out):
        """
        Queues a engine action to stop/fade-out the given schedule.

        Args:
            schedule (PlaylistEntry):  The schedule
            fade_out (Boolean):        If the schedule should be faded-out
        """
        schedule_end = schedule.schedule_end
        schedule_end_unix = schedule.end_unix
        now_unix = Engine.engine_time()
        fade_out_time = 0

        # Stop function to be called when schedule ends
        def do_stop(schedule):
            if schedule.has_queued_entries():
                last_entry = schedule.queued_entries[-1]
                self.logger.info(SU.cyan("=== stop('%s') ===" % str(last_entry.playlist.schedule)))
                transition_type = TransitionType.INSTANT
                if fade_out:
                    transition_type = TransitionType.FADE
                self.engine.player.stop(last_entry, transition_type)

        if fade_out == True:
            fade_out_time = int(round(float(self.config.get("fade_out_time")))) #TODO Use float
        
        # Stop any existing fade-out timer
        if schedule.fadeouttimer:
            schedule.fadeouttimer.cancel()
            self.message_timer.remove(schedule.fadeouttimer)

        # Create timer to fade-out
        start_fade_out = schedule_end_unix - now_unix - fade_out_time
        # last_entry = schedule.queued_entries[-1]
        schedule.fadeouttimer = self.create_timer(start_fade_out, do_stop, schedule, fadeout=True)

        self.logger.info("Fading out schedule in %s seconds at %s | Schedule: %s" % (str(start_fade_out), str(schedule_end), schedule))



    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.debug("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.debug("... Programme fetch via API done!")

        # Reset last successful fetch state
        lsf = self.last_successful_fetch
        self.last_successful_fetch = None

        if response is None:
            msg = SU.red("Trying to load programme from Engine Database, because AuraCalendarService returned an empty response.")
            self.logger.warning(msg)
        elif type(response) is list:
            self.programme = response
            if self.programme is not None and len(self.programme) > 0:
                self.last_successful_fetch = datetime.now()
                self.logger.info(SU.green("Finished fetching 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"):
            msg = SU.red("Trying to load programme from database only, because fetching was being aborted from AuraCalendarService! Reason: ")
            self.logger.warning(msg + response[16:])
        else:
            msg = SU.red("Trying to load programme from database only, because of an unknown response from AuraCalendarService: " + response)
            self.logger.warning(msg)

        # Always load latest programme from the database
        self.last_successful_fetch = lsf
        self.load_programme_from_db()
        self.logger.info(SU.green("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_programme()

        if not self.programme:
            self.logger.critical(SU.red("Could not load programme from database. We are in big trouble my friend!"))
            return



    def is_something_planned_at_time(self, given_time):
        """
        Checks for existing timers at the given time.
        """
        for t in self.message_timer:
            if t.fadein or t.switcher:
                if t.entries[0].start_unix == given_time:
                    return t
        return False



    def create_timer(self, diff, func, param, fadein=False, fadeout=False, switcher=False):
        """
        Creates a new timer for timed execution of mixer commands.

        Args:
            diff (Integer):     The difference in seconds from now, when the call should happen
            func (Function):    The function to call
            param ([]):         A schedule or list of entries

        Returns:
            (CallFunctionTimer, CallFunctionTimer):     In case of a "switch" command, the switch and pre-roll timer is returned
            (CallFunctionTimer):                        In all other cases only the timer for the command is returned
        """
        if not fadein and not fadeout and not switcher or fadein and fadeout or fadein and switcher or fadeout and switcher:
            raise ValueError("You have to call me with either fadein=true, fadeout=true or switcher=True")
        if not isinstance(param, list) and not isinstance(param, Schedule):
            raise ValueError("No list of entries nor schedule passed!")

        t = CallFunctionTimer(diff=diff, func=func, param=param, fadein=fadein, fadeout=fadeout, switcher=switcher)
        self.message_timer.append(t)
        t.start()

        if switcher:
            # Pre-roll function to be called by timer
            def do_preload(entries):
                try:
                    if entries[0].get_content_type() in ResourceClass.FILE.types:
                        self.logger.info(SU.cyan("=== preload_group('%s') ===" % ResourceUtil.get_entries_string(entries)))
                        self.engine.player.preload_group(entries, ChannelType.QUEUE)
                    else:
                        self.logger.info(SU.cyan("=== preload('%s') ===" % ResourceUtil.get_entries_string(entries)))
                        self.engine.player.preload(entries[0])
                except LoadSourceException as e: