fix logging code
[sitarba.git] / shbackup
index cbd5396cc897636c93a272c4df36caae195c4818..41658696b6097a9272b3e49a0f7e291ec515e004 100755 (executable)
--- a/shbackup
+++ b/shbackup
@@ -1,12 +1,16 @@
 #!/usr/bin/python3
 """Stefan Huber's simplistic backup solution."""
 
+__version__ = "0.1"
+__author__ = "Stefan Huber"
+
 import datetime
 import os, shutil, sys
 import configparser
 import hashlib
 import subprocess
 import random, re
+import logging
 
 
 Mode = ["full", "incr", "diff"]
@@ -31,11 +35,31 @@ class Backup:
         self.epoch = epoch
         self.mode = mode
 
+    @staticmethod
+    def fromDirName(dirname):
+            [strdate, strtime, epoch, mode] = dirname.split("-")
+
+            if not epoch in Epoch.keys():
+                raise ValueError("Invalid epoch: " + epoch)
+
+            if not mode in Mode:
+                raise ValueError("Invalid mode: " + mode)
+
+            date = datetime.datetime(int(strdate[0:4]),
+                    int(strdate[4:6]), int(strdate[6:8]),\
+                    int(strtime[0:2]), int(strtime[2:4]))
+
+            return Backup(date, epoch, mode)
+
     def __str__(self):
         return "[date: " + self.date.ctime() + \
                 ", epoch: " + self.epoch + \
                 ", mode: " + self.mode + "]"
 
+    def colAlignedString(self):
+        return "%16s    %8s    %4s" % ( \
+                self.date.strftime("%Y-%m-%d %H:%M"), self.epoch, self.mode)
+
     @staticmethod
     def getDirName(date, epoch, mode):
         """Get directory name of backup by given properties."""
@@ -196,18 +220,7 @@ class BackupManager:
         backups = []
 
         for entry in [ b for b in self.listAllDirs() if Backup.isBackupDir(b) ]:
-            [strdate, strtime, epoch, mode] = entry.split("-")
-
-            if not epoch in Epoch.keys():
-                raise ValueError("Invalid epoch: " + epoch)
-
-            if not mode in Mode:
-                raise ValueError("Invalid mode: " + mode)
-
-            date = datetime.datetime(int(strdate[0:4]),
-                    int(strdate[4:6]), int(strdate[6:8]),\
-                    int(strtime[0:2]), int(strtime[2:4]))
-            backups += [ Backup(date, epoch, mode) ]
+            backups += [ Backup.fromDirName(entry) ]
 
         return backups
 
@@ -242,7 +255,9 @@ class BackupManager:
     def backupFileSet(self, fileset, targetdir, since=None):
         """Create an archive for given fileset at given target directory."""
 
-        print("Running file set: " + fileset.name)
+        logfile = logging.getLogger('backuplog')
+        logfile.info("Running file set: " + fileset.name)
+
         tarpath = "/bin/tar"
         fsfn = os.path.join(targetdir, fileset.name) + "." + self.conf.format
 
@@ -255,12 +270,26 @@ class BackupManager:
             taropts += ["--exclude", pat]
 
         tarargs = [tarpath] + taropts + ["-f", fsfn] + fileset.dirs
-        #print("tarargs: ", tarargs)
-        tarp = subprocess.Popen( tarargs )
+        logfile.debug("tar call: " + " ".join(tarargs))
+        tarp = subprocess.Popen( tarargs, bufsize=-1, \
+                stdout=subprocess.PIPE, stderr=subprocess.PIPE )
+
+        # Output stdout of tar
+        while tarp.poll() == None:
+            l = tarp.stdout.readline()
+            if l != "":
+                logging.debug(l.decode().rstrip())
+
+        # Output remaining output of tar
+        for l in tarp.stdout.readlines():
+            logging.debug(l.decode().rstrip())
 
         rett = tarp.wait()
         if rett != 0:
-            print(tarpath + " returned with exit status " + str(rett) + ":")
+            for l in tarp.stderr.readlines():
+                logfile.error( l.decode().strip().rstrip() )
+            sys.stderr.write( tarp.stderr.read().decode() )
+            logfile.error(tarpath + " returned with exit status " + str(rett) + ".")
 
 
     def backup(self, epoch=None, mode=None):
@@ -275,25 +304,38 @@ class BackupManager:
         if epoch == None:
             epoch = self.getDesiredEpoch(oldbackups, now)
         if epoch == None:
-            print("No backup planned.")
+            logging.info("No backup planned.")
             return
 
         # Get mode of backup
         if mode == None:
             mode = self.conf.epochmodes[epoch]
-        print("Making a backup. Epoch: " + epoch + ", mode: " + mode)
+        logging.info("Making a backup. Epoch: " + epoch + ", mode: " + mode)
 
         oldfullbackups = [ b for b in oldbackups if b.mode == "full" ]
 
         # No old full backups existing
         if mode != "full" and len(oldfullbackups)==0:
-            print("No full backups existing. Making a full backup.")
+            logging.info("No full backups existing. Making a full backup.")
 
         # Checksum changed -> self.config file changed
-        if self.conf.checksum != self.conf.lastchecksum:
-            print("Config file changed since last time.")
-            if mode != "full":
-                print("** Warning: full backup recommended!")
+        if self.conf.checksum != self.conf.lastchecksum and mode != "full":
+            logging.warning("Full backup recommended as config file has changed.")
+
+
+        # If we have a full backup, we backup everything
+        since = None
+        if mode == "diff":
+            since = sorted(oldfullbackups, key=lambda b: b.date)[-1].date
+        elif mode == "incr":
+            since = sorted(oldbackups, key=lambda b: b.date)[-1].date
+
+        if since != None:
+            logging.debug("Making backup relative to " + since.ctime())
+
+        yesno = self.ask_user_yesno("Proceed? [Y, n] ")
+        if yesno == "n":
+            return
 
         # Create new target directory
         basedir = self.conf.directory
@@ -302,20 +344,21 @@ class BackupManager:
         targetdir = os.path.join(basedir, tmpdirname)
         os.mkdir( targetdir )
 
-        # If we have a full backup, we backup everything
-        since = None
 
-        # Get latest full backup time
-        if mode == "diff":
-            since = sorted(oldfullbackups, key=lambda b: b.date)[-1].date
-        # Get latest backup time
-        elif mode == "incr":
-            since = sorted(oldbackups, key=lambda b: b.date)[-1].date
+        # Add file logger
+        logfile = logging.getLogger("backuplog")
+        fil = logging.FileHandler( os.path.join(targetdir, "log") )
+        fil.setLevel(logging.DEBUG)
+        logfile.addHandler(fil)
+
+        logfile.info("Started: " + now.ctime())
 
         # Backup all file sets
         for s in self.conf.sets:
             self.backupFileSet(s, targetdir, since)
 
+        logfile.info("Stopped: " + datetime.datetime.now().ctime())
+
         # Rename backup directory to final name
         os.rename( targetdir, os.path.join(basedir, dirname) )
 
@@ -326,35 +369,60 @@ class BackupManager:
             f.close()
 
 
+
     def prune(self):
         """Prune old backup files"""
 
+        allDirs = sorted(self.listAllDirs())
         # Collect all directories not matching backup name
-        dirs = [ d for d in self.listAllDirs() if not Backup.isBackupDir(d) ]
+        removeDirs = [ d for d in allDirs if not Backup.isBackupDir(d) ]
 
-        # Get all directories which are outdated
+        # Get all directories which are kept
         backups = self.listOldBackups()
+        keepdirs = []
         byepoch = { e : list(sorted( [ b for b in backups if b.epoch == e ], \
                 key=lambda b : b.date, reverse=True)) for e in RealEpoch }
         for e in byepoch:
             keep = self.conf.epochkeeps[e]
             old = byepoch[e][keep:]
-            dirs += [ Backup.getDirName(b.date, b.epoch, b.mode) for b in old]
+            removeDirs += [ Backup.getDirName(b.date, b.epoch, b.mode) for b in old]
 
-        if len(dirs) == 0:
-            print("No stale/outdated entries to remove.")
-            return
 
-        print("List of stale/outdated entries:")
-        for d in dirs:
-            print("  " + d)
+        logging.info("List of stale/outdated entries:")
+        for d in allDirs:
+            msg = ""
+            if d in removeDirs:
+                msg = "[*]  "
+            else:
+                msg = "[ ]  "
+
+            if Backup.isBackupDir(d):
+                msg += Backup.fromDirName(d).colAlignedString()
+            else:
+                msg += d
+
+            logging.info(msg)
+
+        # Check that dirs to be removed is in list of all dirs
+        for d in removeDirs:
+            assert( d in allDirs )
+
+        if len(removeDirs) == 0:
+            logging.info("No stale/outdated entries to remove.")
+            return
 
         basedir = self.conf.directory
-        yesno = input("Remove listed entries? [y, N] ")
+        yesno = self.ask_user_yesno("Remove entries marked by '*'? [y, N] ")
         if yesno == "y":
-            for d in dirs:
+            for d in removeDirs:
                 shutil.rmtree(os.path.join(basedir, d))
 
+    def ask_user_yesno(self, question):
+        if LogConf.con.level <= logging.INFO:
+            return input(question)
+        else:
+            return "y"
+
 
 def printUsage():
     """Print --help text"""
@@ -377,10 +445,35 @@ def printUsage():
     print("  -e, --epoch <epoch>        force to create backup for given epoch:")
     print("                             year, month, week, day, hour, sporadic")
     print("  -m, --mode <mode>          override mode: full, diff, or incr")
+    print("  -v, --verbose              be more verbose and interact with user")
+    print("  --verbosity LEVEL          set verbosity to LEVEL, which can be")
+    print("                             warning, info, debug")
+    print("  -V, --version              print version info")
+
+
+
+class LogConf:
+    """Encapsulates logging configuration"""
+
+    con = logging.StreamHandler(sys.stderr)
+
+    @classmethod
+    def setup(cls):
+        """Setup logging system"""
+        conlog = logging.getLogger()
+        conlog.setLevel(logging.DEBUG)
+
+        cls.con.setLevel(logging.WARNING)
+        conlog.addHandler(cls.con)
+
+        fillog = logging.getLogger("backuplog")
+        fillog.setLevel(logging.DEBUG)
 
 
 if __name__ == "__main__":
 
+    LogConf.setup()
+
     conffn = "/etc/shbackup.conf"
     cmd = "list"
     mode = None
@@ -399,18 +492,33 @@ if __name__ == "__main__":
             i += 1
             conffn = sys.argv[i]
 
+        elif opt in ["-V", "--version"]:
+            print("shbackup " + __version__)
+            exit(0)
+
+        elif opt in ["-v", "--verbose"]:
+            LogConf.con.setLevel(logging.INFO)
+
+        elif opt in ["--verbosity"]:
+            i += 1
+            level = sys.argv[i]
+            numlevel = getattr(logging, level.upper(), None)
+            if not isinstance(numlevel, int):
+                raise ValueError('Invalid verbosity level: %s' % level)
+            LogConf.con.setLevel(numlevel)
+
         elif opt in ["-m", "--mode"]:
             i += 1
             mode = sys.argv[i]
             if not mode in Mode:
-                print("Unknown mode '" + mode + "'.")
+                logging.error("Unknown mode '" + mode + "'.")
                 exit(1)
 
         elif opt in ["-e", "--epoch"]:
             i += 1
             epoch = sys.argv[i]
             if not epoch in Epoch:
-                print("Unknown epoch '" + epoch + "'.")
+                logging.error("Unknown epoch '" + epoch + "'.")
                 exit(1)
 
 
@@ -418,7 +526,7 @@ if __name__ == "__main__":
             cmd = opt
 
         else:
-            print("Unknown option: " + opt)
+            logging.error("Unknown option: " + opt)
             exit(1)
 
     try:
@@ -429,14 +537,13 @@ if __name__ == "__main__":
 
         if cmd == "list":
             for b in sorted(man.listOldBackups(), key=lambda b: b.date):
-                print(b.date.strftime("%Y-%m-%d %H:%M") + \
-                        "\t" + b.epoch + "\t" + b.mode)
+                print(b.colAlignedString())
 
         if cmd == "prune":
             man.prune()
 
     except (Config.ReadError, configparser.DuplicateOptionError) as e:
-        print("Error reading config file: " + e.message)
+        logging.error("Error reading config file: " + e.message)