Browse Source

Clean up logging

Nathaniel van Diepen 4 years ago
parent
commit
bcc69fe961
2 changed files with 93 additions and 50 deletions
  1. 92 50
      backup.py
  2. 1 0
      etc/backup.d/backup.yml

+ 92 - 50
backup.py

@@ -54,8 +54,10 @@ class BackupException(Exception):
 class Job(object):
     pool = []
     maxthreads = 4
+    verbosity = 4
+    logTransitions = False
     READY = 0
-    ACTIVE = 1
+    QUEUED = 1
     RUNNING = 2
     FAILED = 3
     SUCCESSFUL = 4
@@ -81,13 +83,7 @@ class Job(object):
 
     def __str__(self):
         return 'Backup {0} Job #{1} ({2})'.format(
-                self._backup.name, self._backup.jobs.index(self), {
-                    Job.READY: 'ready',
-                    Job.ACTIVE: 'active',
-                    Job.RUNNING: 'running',
-                    Job.FAILED: 'failed',
-                    Job.SUCCESSFUL: 'successful',
-                }[self.state])
+                self._backup.name, self.index, self.getState())
 
     @property
     def config(self):
@@ -95,10 +91,13 @@ class Job(object):
 
     @property
     def state(self):
-        if self._state is Job.RUNNING:
+        if self._state is Job.READY and self in Job.pool:
+            self.setState(Job.QUEUED)
+
+        elif self._state is Job.RUNNING:
             code = self._process.poll()
             if code is not None:
-                self._state = Job.FAILED if code else Job.SUCCESSFUL
+                self.setState(Job.FAILED if code else Job.SUCCESSFUL)
                 Job.initPool()
 
         return self._state
@@ -110,23 +109,24 @@ class Job(object):
         if self in Job.pool:
             raise StateException('{} already in queued pool'.format(self))
 
-        self._state = Job.ACTIVE
+        self.setState(Job.QUEUED)
         Job.pool.append(self)
 
     @property
     def args(self):
         if Backup.engine == "rdiff-backup":
-            args = ['rdiff-backup']
-            for item in self.config['filters']:
-                if 'include' in item:
-                    args += ['--include', item['include']]
+            args = ['rdiff-backup', '-v{}'.format(Backup.verbosity)]
+            if 'filters' in self.config:
+                for item in self.config['filters']:
+                    if 'include' in item:
+                        args += ['--include', item['include']]
 
-                elif 'exclude' in item:
-                    args += ['--exclude', item['exclude']]
+                    elif 'exclude' in item:
+                        args += ['--exclude', item['exclude']]
 
-                else:
-                    raise BackupException(
-                        '{0} has an invalid filter {1}'.format(self, item))
+                    else:
+                        raise BackupException(
+                            '{0} has an invalid filter {1}'.format(self, item))
 
             return args + [self.fromPath, self.toPath]
 
@@ -166,20 +166,49 @@ class Job(object):
     def process(self):
         return self._process
 
+    @property
+    def index(self):
+        if not hasattr(self, '_index'):
+            self._index = self._backup.jobs.index(self)
+
+        return self._index
+
+    def log(self, text):
+        text = '[Backup {0} Job #{1}] {2}\n'.format(
+                self._backup.name, self.index, text)
+        print(text, end='')
+        self.logfile.write(text)
+        self.logfile.flush()
+
     def start(self):
-        if self.state is not Job.ACTIVE:
+        if self.state is not Job.QUEUED:
             raise StateException('Invalid state to start {}'.format(self))
 
+        self._backup.setStatus(Backup.RUNNING)
+        self.setState(Job.RUNNING)
         self._process = subprocess.Popen(
-                self.args, stdout=self.logfile, stderr=self.logfile,
-                stdin=subprocess.DEVNULL, universal_newlines=True)
-        self._state = Job.RUNNING
-        self._backup._state = Backup.RUNNING
+                self.args, stdout=self.logfile, stderr=subprocess.STDOUT,
+                stdin=subprocess.DEVNULL, universal_newlines=True, bufsize=1)
+
+    def setState(self, state):
+        self._state = state
+        self.log('{0} -> {1}'.format(
+                self.getState(self._state), self.getState(state)))
+
+    def getState(self, state=None):
+        return {
+            Job.READY: 'ready',
+            Job.QUEUED: 'queued',
+            Job.RUNNING: 'running',
+            Job.FAILED: 'failed',
+            Job.SUCCESSFUL: 'successful',
+        }[self.state if state is None else state]
 
 
 class Backup(object):
     instances = {}
     _queue = []
+    logTransitions = False
     engine = 'rdiff-backup'
     logdir = '/var/log/backup.d'
     BLOCKED = 0
@@ -241,19 +270,15 @@ class Backup(object):
         self._name = os.path.basename(self._path)
         self._logpath = os.path.realpath(os.path.join(
             Backup.logdir, '{}.log'.format(slugify(self._path))))
-        self._status = Backup.BLOCKED if self.blocking else Backup.READY
+        self._status = Backup.READY
+        if self.blocking:
+            self.setStatus(Backup.BLOCKED)
+
         Backup.instances[self._path] = self
 
     def __str__(self):
         return 'Backup {0} ({1}, {2} jobs)'.format(
-                self.name, {
-                    Backup.BLOCKED: 'blocked',
-                    Backup.READY: 'ready',
-                    Backup.QUEUED: 'queued',
-                    Backup.RUNNING: 'running',
-                    Backup.FAILED: 'failed',
-                    Backup.SUCCESSFUL: 'successful'
-                }[self.status], len([x for x in self.jobs
+                self.name, self.getStatus(), len([x for x in self.jobs
                     if x.state not in (Job.FAILED, Job.SUCCESSFUL)]))
 
     @property
@@ -275,36 +300,39 @@ class Backup(object):
     @property
     def logfile(self):
         if not hasattr(self, '_logfile'):
-            self._logfile = open(self.logpath, 'w')
+            self._logfile = open(self.logpath, 'w+')
 
         return self._logfile
 
     def log(self, text):
-        self._logfile.write(text)
+        text = '[Backup {0}] {1}\n'.format(self.name, text)
+        print(text, end='')
+        self.logfile.write(text)
+        self.logfile.flush()
 
     @property
     def status(self):
         if self.blocking:
             if [x for x in self.blocking if x.status is Backup.FAILED]:
-                self._status = Backup.FAILED
+                self.setStatus(Backup.FAILED)
 
             elif self._status is not Backup.BLOCKED:
-                self._status = Backup.BLOCKED
+                self.setStatus(Backup.BLOCKED)
 
         elif self._status is Backup.BLOCKED:
             if self not in Backup._queue:
-                self._status = Backup.READY
+                self.setStatus(Backup.READY)
 
             else:
-                self._status = Backup.QUEUED
+                self.setStatus(Backup.QUEUED)
                 for job in self.ready:
                     job.queue()
 
         elif self._status is Backup.QUEUED and self not in Backup._queue:
-            self._status = Backup.READY
+            self.setStatus(Backup.READY)
 
         if self._status in (Backup.RUNNING, Backup.QUEUED) and not self.pending:
-            self._status = Backup.FAILED if self.failed else Backup.SUCCESSFUL
+            self.setStatus(Backup.FAILED if self.failed else Backup.SUCCESSFUL)
 
         if self._status in (Backup.FAILED, Backup.SUCCESSFUL) \
                 and self in Backup._queue:
@@ -350,16 +378,27 @@ class Backup(object):
     def failed(self):
         return [x for x in self.jobs if x.state is Job.FAILED]
 
-    def setStatus(self, state):
-        if state in (None, False, True):
-            self._status = state
+    def setStatus(self, status):
+        self.log('{0} -> {1}'.format(
+            self.getStatus(self._status), self.getStatus(status)))
+        self._status = status
+
+    def getStatus(self, status=None):
+        return {
+            Backup.BLOCKED: 'blocked',
+            Backup.READY: 'ready',
+            Backup.QUEUED: 'queued',
+            Backup.RUNNING: 'running',
+            Backup.FAILED: 'failed',
+            Backup.SUCCESSFUL: 'successful'
+        }[self.status if status is None else status]
 
     def queue(self):
         if self in Backup._queue:
             raise StateException('Backup already queued')
 
         Backup._queue.append(self)
-        self._status = Backup.QUEUED
+        self.setStatus(Backup.QUEUED)
         if self.status is not Backup.BLOCKED:
             for job in self.ready:
                 job.queue()
@@ -384,7 +423,8 @@ def sources():
     with pushd('etc/backup.d'):
         for source in config()['sources']:
             source = os.path.realpath(source)
-            for path in glob('{}/*.yml'.format(source)):
+            for path in glob('{}/*.yml'.format(source)) + \
+                    glob('{}/*.yaml'.format(source)):
                 path = os.path.realpath(path)
                 with pushd(os.path.dirname(path)), open(path) as f:
                     data = yaml.load(f, Loader=yaml.SafeLoader)
@@ -422,11 +462,13 @@ def main(args):
     if 'maxthreads' in config():
         Job.maxthreads = config()['maxthreads']
 
+    if 'verbosity' in config():
+        Backup.verbosity = config()['verbosity']
+
+    Backup.logTransitions = Job.logTransitions = True
     Backup.load(sources().keys())
-    Backup._log()
     Backup.start()
-    Backup._log()
-    Backup.wait(True)
+    Backup.wait()
 
 
 if __name__ == '__main__':

+ 1 - 0
etc/backup.d/backup.yml

@@ -1,5 +1,6 @@
 ---
 engine: rdiff-backup
+verbosity: 4
 maxthreads: 4
 logdir: var/log/backup.d
 sources: