Improve logging

plasma-agent/btrfs.py

@@ -3,6 +3,9 @@
 import subprocess
 import os
 
+import logging; log = logging.getLogger(__name__)
+
+
 class StrategyBtrfsSnapshot(Strategy):
  """
  StrategyBtrfsSnapshot makes a read-only btrfs snapshot before archiving
@@ -21,23 +24,26 @@ def can_execute(self):
  def execute(self):
  try:
  os.stat("/@snapshot")
- print("Deleting existing snapshot")
+ log.info("Deleting existing snapshot")
  result = subprocess.run(["btrfs", "subvolume", "delete", "--commit-after", "/@snapshot"])
  if result.returncode != 0:
  return "Failed to delete existing snapshot"
  except:
  pass
 
+ log.info("Creating read-only snapshot at /@snapshot")
  result = subprocess.run(["btrfs", "subvolume", "snapshot", "-r", "/", "/@snapshot"])
  if result.returncode != 0:
  return "Failed to create snapshot"
 
+ log.info("Running tar")
  folders = list(map(lambda x: "/@snapshot"+x, self.targetFolders))
  args = ['tar', '--create', '--file', self.outputPath] + folders
  # args = ['tar', '--create', '--file', self.outputPath, '-v'] + folders
  result = subprocess.run(args)
  #return (result.returncode == 0)
 
+ log.info("Removing snapshot")
  result = subprocess.run(["btrfs", "subvolume", "delete", "--commit-after", "/@snapshot"])
  if result.returncode != 0:
- print("WARNING: failed to delete snapshot")
+ log.warning("Failed to delete snapshot, leaving it at /@snapshot")

plasma-agent/main.py

@@ -10,6 +10,8 @@
 import sys
 from datetime import datetime
 
+import logging; log = logging.getLogger(__name__)
+
 
 CONFIG_PATH = '/etc/plasma-agent.json'
 
@@ -30,6 +32,7 @@
 
 
 def main():
+ logging.basicConfig(level=logging.DEBUG, format='[%(levelname)s] %(name)s: %(message)s')
  splash()
 
  config = load_config()
@@ -46,20 +49,22 @@ def main():
  # Make the backup
 
  strategy = STRATEGIES[target_strategy](target_folders, temp_path, options)
+ log.debug('Checking if we can use this strategy: %s', target_strategy)
  if not strategy.can_execute():
  raise OSError("Cannot execute strategy")
 
  try:
+ log.debug('Checking for previous backup')
  os.stat(temp_path)
- print("Deleting previous backup")
+ log.info('Deleting previous backup')
  os.remove(temp_path)
  except FileNotFoundError:
  pass
 
- print("Executing strategy:", target_strategy)
+ log.info("Starting backup (using strategy: %s)", target_strategy)
  err = strategy.execute()
  if err != None:
- print("Failed to execute strategy:", err)
+ log.error("Failed to execute strategy: %s", err)
  sys.exit(1)
 
  # Upload file
@@ -73,28 +78,28 @@ def main():
  )
 
  scpArg = "%s@%s:%s/%s" % (ssh_login, ssh_host, remote_folder, filename)
- print("Uploading file to", scpArg)
+ log.info("Uploading file to %s", scpArg)
  result = subprocess.run(["scp", temp_path, scpArg])
  if result.returncode != 0:
- print("Upload failed")
+ log.error("Upload failed")
  sys.exit(1)
 
- print("Launching plasma-rotate on remote host")
+ log.info("Launching plasma-rotate on remote host")
  sshArg = "%s@%s" % (ssh_login, ssh_host)
  result = subprocess.run(["ssh", sshArg, "plasma-rotate", remote_folder])
  if result.returncode != 0:
- print("WARNING: plasma-rotate failed, old backups were not deleted")
+ log.warning("plasma-rotate failed, old backups were not deleted")
  sys.exit(1)
 
  # Glad it's done
- print("Everything's fine, exiting.")
+ log.info("Everything's fine, exiting.")
 
 
 def load_config():
  with open(CONFIG_PATH) as f:
  s = f.read()
  config = json.loads(s)
- print("Loaded config from", CONFIG_PATH)
+ log.debug("Loaded config from %s", CONFIG_PATH)
  return config
 
 

plasma-agent/noop.py

@@ -2,6 +2,8 @@
 
 import os
 
+import logging; log = logging.getLogger(__name__)
+
 
 class StrategyNoop(Strategy):
  """
@@ -12,6 +14,7 @@ def can_execute(self):
  return True
 
  def execute(self):
+ log.debug("Creating empty file %s", self.outputPath)
  fd = os.open(self.outputPath, os.O_CREAT | os.O_WRONLY)
  os.close(fd)
  return

plasma-agent/tar.py

@@ -3,6 +3,8 @@
 import os
 import subprocess
 
+import logging; log = logging.getLogger(__name__)
+
 
 class StrategySimpleTar(Strategy):
  """
@@ -14,6 +16,7 @@ def can_execute(self):
  return (result.returncode == 0)
 
  def execute(self):
+ log.info("Creating tar archive: %s", self.outputPath)
  args = ['tar', '--create', '--file', self.outputPath] + self.targetFolders
  # args = ['tar', '--create', '--file', self.outputPath, '-v'] + self.targetFolders
  result = subprocess.run(args)