Dreamtime scheduling: discount system sleep periods

Sun, 28 Jan 2018 00:11:18 +0000

author
Tuomo Valkonen <tuomov@iki.fi>
date
Sun, 28 Jan 2018 00:11:18 +0000
changeset 76
4b08fca3ce34
parent 75
2a44b9649212
child 77
e8773133bf79

Dreamtime scheduling: discount system sleep periods

backup.py file | annotate | diff | comparison | revisions
borgend.py file | annotate | diff | comparison | revisions
config.example.yaml file | annotate | diff | comparison | revisions
scheduler.py file | annotate | diff | comparison | revisions
sleep.py file | annotate | diff | comparison | revisions
ui.py file | annotate | diff | comparison | revisions
--- a/backup.py	Sat Jan 27 12:19:39 2018 +0000
+++ b/backup.py	Sun Jan 28 00:11:18 2018 +0000
@@ -7,6 +7,7 @@
 import time
 import borgend
 import repository
+import sleep
 from enum import IntEnum
 from instance import BorgInstance
 from threading import Thread, Lock, Condition
@@ -53,20 +54,19 @@
 class Operation:
     CREATE='create'
     PRUNE='prune'
-    def __init__(self, operation, when_monotonic, **kwargs):
+    def __init__(self, operation, time, **kwargs):
         self.operation=operation
-        self.when_monotonic=when_monotonic
+        self.time=time
         self.detail=kwargs
 
     def when(self):
-        return self.when_monotonic-time.monotonic()+time.time()
+        return self.time.realtime()
 
 
 class Status(Operation):
     def __init__(self, backup, op=None):
         if op:
-            super().__init__(op.operation, op.when_monotonic,
-                             **op.detail)
+            super().__init__(op.operation, op.time, **op.detail)
         else:
             super().__init__(None, None)
 
@@ -137,6 +137,20 @@
                                                     'Retry interval', loc,
                                                     config.defaults['retry_interval'])
 
+
+        scheduling=config.check_string(cfg, 'scheduling',
+                                      'Scheduling mode', loc,
+                                      default="dreamtime")
+
+        if scheduling=="dreamtime":
+            self.timeclass=sleep.DreamTime
+        elif scheduling=="realtime":
+            self.timeclass=sleep.MonotonicTime
+        elif scheduling=="manual":
+            self.backup_interval=0
+        else:
+            logging.error("Invalid time class '%s' for %s" % (scheduling, loc))
+
         self.paths=config.check_nonempty_list_of_strings(cfg, 'paths', 'Paths', loc)
 
         self.borg_parameters=config.BorgParameters.from_config(cfg, loc)
@@ -158,6 +172,7 @@
         self.lastrun_finished=None
         self.state=State.INACTIVE
         self.errors=Errors.OK
+        self.timeclass=sleep.DreamTime
 
         self.__decode_config(cfg)
 
@@ -285,7 +300,7 @@
         self.current_operation=op
         # Update scheduled time to real starting time to schedule
         # next run relative to this
-        self.current_operation.when_monotonic=time.monotonic()
+        self.current_operation.time=sleep.MonotonicTime.now()
         self.state=State.ACTIVE
         # Reset error status when starting a new operation
         self.errors=Errors.OK
@@ -354,7 +369,7 @@
             self.errors=self.errors.combine(Errors.ERRORS)
 
         if self.current_operation.operation=='create':
-            self.lastrun_when=self.current_operation.when_monotonic
+            self.lastrun_when=self.current_operation.time.monotonic()
             self.lastrun_finished=time.monotonic()
         self.thread_res=None
         self.thread_log=None
@@ -404,17 +419,17 @@
         if not self.scheduled_operation:
             op=self.__next_operation_unlocked()
         if op:
-            now=time.monotonic()
-            delay=max(0, op.when_monotonic-now)
-            self.logger.info("Scheduling '%s' (detail: %s) in %d seconds" %
-                             (str(op.operation), op.detail or 'none', delay))
+            self.logger.info("Scheduling '%s' (detail: %s) in %d seconds [%s]" %
+                             (str(op.operation), op.detail or 'none',
+                              op.time.seconds_to(),
+                              op.time.__class__.__name__))
 
             self.scheduled_operation=op
             self.state=State.SCHEDULED
             self.__update_status()
 
             # Wait under scheduled wait
-            self.scheduler.wait_until(now+delay, self._cond, self.backup_name)
+            self.scheduler.wait_until(op.time, self._cond, self.backup_name)
         else:
             # Nothing scheduled - just wait
             self.logger.info("Waiting for manual scheduling")
@@ -444,7 +459,6 @@
 
     def __next_operation_unlocked(self):
         # TODO: pruning as well
-        now=time.monotonic()
         if not self.lastrun_finished:
             initial_interval=self.retry_interval
             if initial_interval==0:
@@ -452,21 +466,20 @@
             if initial_interval==0:
                 return None
             else:
-                return Operation(Operation.CREATE, now+initial_interval,
-                                 reason='initial')
+                tm=self.timeclass.after(initial_interval)
+                return Operation(Operation.CREATE, tm, reason='initial')
         elif not self.errors.ok():
             if self.retry_interval==0:
                 return None
             else:
-                return Operation(Operation.CREATE,
-                                 self.lastrun_finished+self.retry_interval,
-                                 reason='retry')
+                tm=sleep.MonotonicTime(self.lastrun_finished+self.retry_interval)
+                return Operation(Operation.CREATE, tm, reason='retry')
         else:
             if self.backup_interval==0:
                 return None
             else:
-                return Operation(Operation.CREATE,
-                                 self.lastrun_when+self.backup_interval)
+                tm=self.timeclass.from_monotonic(self.lastrun_when+self.backup_interval)
+                return Operation(Operation.CREATE, tm)
 
     def __status_unlocked(self):
         callback=self.__status_update_callback
@@ -505,13 +518,13 @@
         return res[0]
 
     def create(self):
-        op=Operation(Operation.CREATE, time.monotonic(), reason='manual')
+        op=Operation(Operation.CREATE, sleep.MonotonicTime.now(), reason='manual')
         with self._cond:
             self.scheduled_operation=op
             self._cond.notify()
 
     def prune(self):
-        op=Operation(Operation.PRUNE, time.monotonic(), reason='manual')
+        op=Operation(Operation.PRUNE, sleep.MonotonicTime.now(), reason='manual')
         with self._cond:
             self.scheduled_operation=op
             self._cond.notify()
--- a/borgend.py	Sat Jan 27 12:19:39 2018 +0000
+++ b/borgend.py	Sun Jan 28 00:11:18 2018 +0000
@@ -103,6 +103,9 @@
         from backup import Backup
         from queue import Queue
         import signal, os
+        import sleep
+
+        sleep.start_monitoring()
 
         scheduler = Scheduler()
         scheduler.start()
--- a/config.example.yaml	Sat Jan 27 12:19:39 2018 +0000
+++ b/config.example.yaml	Sun Jan 28 00:11:18 2018 +0000
@@ -39,6 +39,9 @@
     backup_interval: 86400
     # Retry every 15 minutes if unable to connect / unfinished backup
     retry_interval: 900
+    # Scheduling mode: dreamtime/realtime/manual
+    # Dreamtime scheduling discounts system sleep periods.
+    scheduling: dreamtime
     repository: myserver
     archive_prefix: 'all@mylaptop-'
     archive_template: '{now:%Y-%m-%d_%H:%M:%S}'
@@ -54,19 +57,23 @@
 
   # 2. A subset of files $HOME more frequently to ssh://myserver.invalid
   - name: Work to 'myserver'
-   # Backup every 3 hours
-   backup_interval: 10800
-   # Retry every 15 minutes if unable to connect / unfinished backup
-   retry_interval: 900
-   repository: myserver
-   archive_prefix: 'work@mylaptop-'
-   archive_template: '{now:%Y-%m-%d_%H:%M:%S}'
-   paths:
-     - $HOME/work
+    # Backup every 3 hours
+    backup_interval: 10800
+    # Retry every 15 minutes if unable to connect / unfinished backup
+    retry_interval: 900
+    # Scheduling mode: dreamtime/realtime/manual
+    # Dreamtime scheduling discounts system sleep periods.
+    scheduling: dreamtime
+    repository: myserver
+    archive_prefix: 'work@mylaptop-'
+    archive_template: '{now:%Y-%m-%d_%H:%M:%S}'
+    paths:
+      - $HOME/work
 
   # 3. Manual backup to external hard drive
   - name: Home to 'backup1'
    # Manual backup
+   scheduling: manual
    backup_interval: 0
    retry_interval: 0
    repository: backup1
--- a/scheduler.py	Sat Jan 27 12:19:39 2018 +0000
+++ b/scheduler.py	Sun Jan 28 00:11:18 2018 +0000
@@ -6,6 +6,7 @@
 
 import time
 import borgend
+import sleep
 from threading import Condition, Lock, Thread
 
 logger=borgend.logger.getChild(__name__)
@@ -45,8 +46,11 @@
             n.prev=p
         if p:
             p.next=n
+        self.next=None
+        self.prev=None
 
 class ScheduledEvent(QueuedEvent):
+    #@accepts(ScheduledEvent, sleep.Time, threading.Cond, str)
     def __init__(self, when, cond, name=None):
         super().__init__(cond, name=name)
         self.when=when
@@ -90,6 +94,16 @@
             self._list=ev.next
         ev.unlink()
 
+    def _resort(self):
+        oldlist=self._list
+        self._list=None
+        while oldlist:
+            ev=oldlist
+            oldlist=oldlist.next
+            ev.unlink()
+            self._insert(ev)
+
+
 
 class Scheduler(QueueThread):
     # Default to precision of 60 seconds: the scheduler thread will never
@@ -99,6 +113,7 @@
         self.precision = precision
         self._next_event_time = None
         super().__init__(target = self._scheduler_thread, name = 'Scheduler')
+        sleep.add_callback(self, self._wakeup_callback)
 
     def _scheduler_thread(self):
         logger.debug("Scheduler thread started")
@@ -110,7 +125,7 @@
                 else:
                     # Wait at most precision seconds, or until next event if it
                     # comes earlier
-                    timeout=min(self.precision, self._list.when-now)
+                    timeout=min(self.precision, self._list.when.realtime()-now)
 
                 if not timeout or timeout>0:
                     logger.debug("Scheduler waiting %d seconds" % (timeout or (-1)))
@@ -119,7 +134,7 @@
 
                 logger.debug("Scheduler timed out")
 
-                while self._list and self._list.when <= now:
+                while self._list and self._list.when.monotonic() <= now:
                     ev=self._list
                     logger.debug("Scheduler activating %s" % (ev.name or "(unknown)"))
                     # We are only allowed to remove ev from list when ev.cond allows
@@ -128,6 +143,11 @@
                         ev.unlink()
                         ev.cond.notifyAll()
 
+    def _wakeup_callback(self):
+        logger.debug("Rescheduling events after wakeup")
+        with self._cond:
+            self._resort()
+
     def _wait(self, ev):
         with self._cond:
             self._insert(ev)
@@ -143,6 +163,7 @@
 
     # cond has to be acquired on entry!
     def wait_until(self, when, cond, name=None):
-        logger.debug("Scheduling '%s' at %d" % (name, when))
+        logger.debug("Scheduling '%s' in %s seconds [%s]" %
+                     (name, when.seconds_to(), when.__class__.__name__))
         self._wait(ScheduledEvent(when, cond, name))
 
--- a/sleep.py	Sat Jan 27 12:19:39 2018 +0000
+++ b/sleep.py	Sun Jan 28 00:11:18 2018 +0000
@@ -4,34 +4,199 @@
 
 import Foundation
 import AppKit
+import platform
+import time
+import threading
 import borgend
-import platform
+import weakref
+import datetime
 
 logger=borgend.logger.getChild(__name__)
 
+_dreamtime_monitor=[None]
+
+#
+# Support classes for dealing with different times
+#
+
+def dreamtime():
+    if _dreamtime_monitor[0]:
+        return max(0, time.monotonic()-_dreamtime_monitor[0].diff())
+    else:
+        return time.monotonic()
+
+class Time:
+    def realtime(self):
+        raise NotImplementedError
+
+    def monotonic(self):
+        raise NotImplementedError
+
+    @staticmethod
+    def _now():
+        raise NotImplementedError
+
+    @classmethod
+    def now(cls):
+        return cls(cls._now())
+
+    @classmethod
+    def from_realtime(cls, realtime):
+        return cls(realtime-time.time()+cls._now())
+
+    @classmethod
+    def from_monotonic(cls, monotonic):
+        return cls(monotonic-time.monotonic()+cls._now())
+
+    @classmethod
+    def after(cls, seconds):
+        return cls(cls._now()+seconds)
+
+    def datetime(self):
+        return datetime.datetime.fromtimestamp(self.realtime())
+
+    def seconds_to(self):
+        return self._value-self._now()
+
+    def __lt__(self, other):
+        return self.monotonic() < other.monotonic()
+
+    def __gt__(self, other):
+        return self.monotonic() > other.monotonic()
+
+    def __le__(self, other):
+        return self.monotonic() <= other.monotonic()
+
+    def __ge__(self, other):
+        return self.monotonic() >= other.monotonic()
+
+    def __eq__(self, other):
+        return self.monotonic() == other.realtime()
+
+class RealTime(Time):
+    def __init__(self, when):
+        self._value=when
+
+    def realtime(self):
+        return self._value
+
+    def monotonic(self):
+        return self._value+(time.monotonic()-time.time())
+
+    @staticmethod
+    def _now():
+        return time.time()
+
+class MonotonicTime(Time):
+    def __init__(self, when):
+        self._value=when
+
+    def realtime(self):
+        return self._value+(time.time()-time.monotonic())
+
+    def monotonic(self):
+        return self._value
+
+    @staticmethod
+    def _now():
+        return time.monotonic()
+
+class DreamTime(Time):
+    def __init__(self, when):
+        self._value=when
+
+    def realtime(self):
+        return self._value+(time.time()-dreamtime())
+
+    def monotonic(self):
+        return self._value+(time.monotonic()-dreamtime())
+
+    @staticmethod
+    def _now():
+        return dreamtime()
+
+#
+# Wake up / sleep handling
+#
+
 class SleepHandler(Foundation.NSObject):
     """ Handle wake/sleep notifications """
 
-    def handleSleepNotification(self, aNotification):
+    def init(self):
+        self.__sleeptime=None
+        self.__slept=0
+        self.__epoch=time.monotonic()
+        self._lock=threading.Lock()
+        self._callbacks=weakref.WeakKeyDictionary()
+
+        return self
+
+    def handleSleepNotification_(self, aNotification):
         logger.info("System going to sleep")
+        now=time.monotonic()
+        with self._lock:
+            self.__sleeptime=now
 
-    def handleWakeNotification(self, aNotification):
+    def handleWakeNotification_(self, aNotification):
         logger.info("System waking up from sleep")
+        try:
+            now=time.monotonic()
+            with self._lock:
+                if self.__sleeptime:
+                    slept=max(0, now-self.__sleeptime)
+                    logger.info("Slept %f seconds" % slept)
+                    self.__slept=self.__slept+slept
+                    self.__sleeptime=None
+                callbacks=self._callbacks.copy()
+        except:
+            logger.exception("Bug in wakeup handler")
 
-if platform.system()=='Darwin':
-    workspace = AppKit.NSWorkspace.sharedWorkspace()
-    notification_center = workspace.notificationCenter()
-    sleep_handler = SleepHandler.new()
+        for callback in callbacks.values():
+            try:
+                callback()
+            except Exception:
+                logger.exception("Error in wake notification callback")
 
-    notification_center.addObserver_selector_name_object_(
-        sleep_handler,
-        "handleSleepNotification",
-        AppKit.NSWorkspaceWillSleepNotification,
-        None)
+    # Return difference to time.monotonic()
+    def diff(self):
+        with self._lock:
+            diff=self.__epoch+self.__slept
+        return diff
+
+    # Obj-C hates this
+    # def add_callback(self, obj, callback):
+    #     with self.lock:
+    #         self.__callbacks[obj]=callback
+
+# obj is to use a a key in a weak key dictionary
+def add_callback(obj, callback):
+    monitor=_dreamtime_monitor[0]
+    if not monitor:
+        raise Exception("Dreamtime monitor not started")
+    else:
+        #monitor.add_my_callback(obj, callback)
+        with monitor._lock:
+            monitor._callbacks[obj]=callback
 
-    notification_center.addObserver_selector_name_object_(
-        sleep_handler,
-        "handleWakeNotification",
-        AppKit.NSWorkspaceDidWakeNotification,
-        None)
+def start_monitoring():
+    if platform.system()=='Darwin':
+        logger.debug("Starting to monitor system sleep")
+        workspace = AppKit.NSWorkspace.sharedWorkspace()
+        notification_center = workspace.notificationCenter()
+        _dreamtime_monitor[0] = SleepHandler.new()
 
+        notification_center.addObserver_selector_name_object_(
+            _dreamtime_monitor[0],
+            "handleSleepNotification:",
+            AppKit.NSWorkspaceWillSleepNotification,
+            None)
+
+        notification_center.addObserver_selector_name_object_(
+            _dreamtime_monitor[0],
+            "handleWakeNotification:",
+            AppKit.NSWorkspaceDidWakeNotification,
+            None)
+    else:
+        logger.warning(("No system sleep monitor implemented for '%s'"
+                       % platform.system()))
+
--- a/ui.py	Sat Jan 27 12:19:39 2018 +0000
+++ b/ui.py	Sun Jan 28 00:11:18 2018 +0000
@@ -8,6 +8,7 @@
 import logging
 import borgend
 import backup
+import sleep
 from threading import Lock, Timer
 from config import settings
 import objc
@@ -154,31 +155,25 @@
     def __init__(self, backups):
         self.lock=Lock()
         self.backups=backups
+        self.refresh_timer=None
+        self.refresh_timer_time=None
         self.statuses=[None]*len(backups)
 
-        with self.lock:
-            # Initialise reporting callbacks and local status copy
-            # (since rumps doesn't seem to be able to update menu items
-            # without rebuilding the whole menu, and we don't want to lock
-            # when calling Backup.status(), especially as we will be called
-            # from Backup reporting its status, we keep a copy to allow
-            # rebuilding the entire menu
-            for index in range(len(backups)):
-                b=backups[index]
-                # Python closures suck dog's balls; hence the _index=index hack
-                # See also http://math.andrej.com/2009/04/09/pythons-lambda-is-broken/
-                cb=(lambda status, errors=None, _index=index:
-                    self.__status_callback(_index, status, errorlog=errors))
-                b.set_status_update_callback(cb)
-                self.statuses[index]=b.status()
+        for index in range(len(backups)):
+            self.statuses[index]=backups[index].status()
+
+        menu, title=self.build_menu_and_timer()
+
+        super().__init__(title, menu=menu, quit_button=None)
 
-            self.refresh_timer=None
-            self.refresh_timer_time=None
+        for index in range(len(backups)):
+            # Python closures suck dog's balls; hence the _index=index hack
+            # See also http://math.andrej.com/2009/04/09/pythons-lambda-is-broken/
+            cb=(lambda status, errors=None, _index=index:
+                self.__status_callback(_index, status, errorlog=errors))
+            backups[index].set_status_update_callback(cb)
 
-            menu, title=self.build_menu_and_timer()
-
-            super().__init__(title, menu=menu, quit_button=None)
-
+        sleep.add_callback(self, self.refresh_ui)
 
     def __rebuild_menu(self):
         menu=[]

mercurial