Merge lp:~akuzminsky/twindb-agent/restore into lp:twindb-agent

[Aleksandr Kuzminsky]

=== modified file 'twindb.py'
--- twindb.py	2015-03-16 02:16:03 +0000
+++ twindb.py	2015-04-07 16:22:26 +0000
@@ -2,31 +2,34 @@
 from __future__ import print_function
 from __future__ import unicode_literals
 from __future__ import absolute_import
+import ConfigParser
 from base64 import b64encode, b64decode
 from datetime import datetime
-import sys
-import time
+import errno
+import exceptions
 import getopt
+import httplib
+import json
+import logging.handlers
+import os
+import pwd
 import signal
-import traceback
-import exceptions
-import errno
+import shutil
 import socket
-import logging.handlers
-import os.path
 import subprocess
-import httplib
-import json
+import sys
+import tempfile
+import time
+import traceback
 import urllib
-
+import uuid
 
 try:
     import mysql.connector
 except ImportError:
+    # On CentOS 5 mysql.connector is in python 2.6 directory
     sys.path.insert(0, '/usr/lib/python2.6/site-packages')
     import mysql.connector
-import tempfile
-import uuid
 
 # global variables
 host = "dispatcher.twindb.com"
@@ -36,8 +39,8 @@
 debug_http = True
 debug_gpg = False
 init_config = "/etc/twindb.cfg"
-ssh_private_key = "/root/.ssh/twindb.key"
-ssh_public_key = "/root/.ssh/twindb.key.pub"
+ssh_private_key_file = "/root/.ssh/twindb.key"
+ssh_public_key_file = "/root/.ssh/twindb.key.pub"
 ssh_port = 4194
 gpg_homedir = "/root/.gnupg/"
 pid_file = "/var/run/twindb.pid"
@@ -45,9 +48,10 @@
 time_zone = "UTC"
 api_email = "[e-mail]"
 server_id = ""
-job_id = 0
-mysql_user = "root"
-mysql_password = ""
+job_id = None
+mysql_user = None
+mysql_password = None
+agent_version = "@@TWINDB_AGENT_VERSION@@"
 api_pub_key = """
 -----BEGIN PGP PUBLIC KEY BLOCK-----
 Version: GnuPG v1
@@ -102,24 +106,24 @@
 =62IM
 -----END PGP PUBLIC KEY BLOCK-----
 """
-agent_version = "@@TWINDB_AGENT_VERSION@@"
-
-
-# Logging handler that logs to remote TwiDB dispatcher
+
+
 class RlogHandler(logging.Handler):
+    """
+    Logging handler that logs to remote TwiDB dispatcher
+    """
+    log_flag = True
+
     def __init__(self):
         logging.Handler.__init__(self)
         self.log_flag = True
 
     def emit(self, record):
-        global server_id
-        global job_id
-        global debug
-
-        request = {}
-        request["type"] = "log"
-        request["params"] = {}
-        if job_id != 0:
+        request = {
+            "type": "log",
+            "params": {}
+        }
+        if job_id:
             request["params"]["job_id"] = job_id
         request["params"]["msg"] = record.getMessage()
         if self.log_flag and not debug:
@@ -128,83 +132,106 @@
             self.log_flag = True
 
 
+class JobError(Exception):
+    def __init__(self, value):
+        self.value = value
+
+    def __str__(self):
+        return self.value
+
+
+class JobTooSoonError(Exception):
+    def __init__(self, value):
+        self.value = value
+
+    def __str__(self):
+        return self.value
+
+
 def usage():
-    print("Usage:\n\
-twindb --start | --stop | --register <registration code> [-g] [-i interval]\n\
-       [-u user] [-p password]\n\
-\n\
-    --start                         Start TwinDB agent.\n\
-    --stop                          Stop TwinDB agent.\n\
-\n\
-    --register <code>               Register this server in TwinDB.\n\
-                                    <code> is string like 7b90ae21ac642f2f8fc0a285c4789147\n\
-                                    Get your code on https://console.twindb.com/?get_code\n\
-\n\
-    --unregister [--delete-backups] Unregister this server from TwinDB.\n\
-    --backup                        Start backup from this server immediately.\n\
-    --is-registered                 Checks whether the server is registered and prints YES or NO.\n\
-    -g                              Print debug message.\n\
-    -i interval                     Check for a job every interval seconds.\n\
-                                    Default 300.\n\
-                                    During registration TwinDB agent needs to get some information from MySQL,\n\
-                                    (master host etc)\n\
-                                    This is credentials to connect to local MySQL instance\n\
-    -u | --user username            MySQL user name\n\
-    -p | --password password        MySQL password")
+    print("""Usage:
+twindb --start | --stop | --register <registration code> [-g] [-i interval]
+       [-u user] [-p password]
+
+    --start                         Start TwinDB agent.
+    --stop                          Stop TwinDB agent.
+
+    --register <code>               Register this server in TwinDB.
+                                    <code> is string like 7b90ae21ac642f2f8fc0a285c4789147
+                                    Get your code on https://console.twindb.com/?get_code
+
+    --unregister [--delete-backups] Unregister this server from TwinDB.
+    --backup                        Start backup from this server immediately.
+    --is-registered                 Checks whether the server is registered and prints YES or NO.
+    -g                              Print debug message.
+    -i interval                     Check for a job every interval seconds.
+                                    Default {check_period}.
+                                    During registration TwinDB agent needs to get some information from MySQL,
+                                    (master host etc)
+                                    This is credentials to connect to local MySQL instance
+    -u | --user username            MySQL user name
+    -p | --password password        MySQL password""".format(check_period=check_period))
     return
 
 
 def get_mysql_connection(user=None, passwd=None):
-    global mysql_user
-    global mysql_password
-
+    """
+    Returns connection to the local MySQL instance.
+    If user is passed as an argument it'll be used to connect,
+    otherwise the second choice will be to use mysql_user.
+    If neither user names are set the function will try to use either of MySQL option files
+    (/etc/my.cnf, /etc/mysql/my.cnf, or /root/.my.cnf). If the option files don't exist
+    it'll try to connect as root w/o password.
+    """
     try:
-        if user is None:
-            user = mysql_user
-        if passwd is None:
-            passwd = mysql_password
-        mysql_option_files = []
         unix_socket = get_unix_socket()
-        conn = mysql.connector.connect()
-        if user is not None:
-            for f in ['/etc/mysql/my.cnf', '/etc/my.cnf', '/root/.my.cnf']:
-                if os.path.exists(f):
-                    mysql_option_files.append(f)
-            if mysql_option_files:
-                conn = mysql.connector.connect(option_files=mysql_option_files, unix_socket=unix_socket)
-                logger.debug(
-                    "Connected to MySQL as '%s'@'localhost' with options files %r" % (conn.user, mysql_option_files))
-        if not conn.is_connected():
-            conn = mysql.connector.connect(user=user, passwd=passwd, unix_socket=unix_socket)
-            logger.debug("Connected to MySQL as %s@localhost " % conn.user)
+        if not user:
+            if mysql_user:
+                logger.debug('Using MySQL user specified in the command line')
+                user = mysql_user
+                passwd = mysql_password
+            else:
+                for options_file in ["/etc/my.cnf", "/etc/mysql/my.cnf", "/usr/etc/my.cnf",
+                                     "/root/.my.cnf", "/root/.mylogin.cnf"]:
+                    if os.path.exists(options_file):
+                        config = ConfigParser.ConfigParser()
+                        config.read(options_file)
+                        for section in ["client", "twindb"]:
+                            if config.has_section(section):
+                                if config.has_option(section, "user"):
+                                    user = config.get(section, "user")
+                                if config.has_option(section, "password"):
+                                    passwd = config.get(section, "user")
+                # If user isn't set by the function argument, global mysql_user
+                # or MySQL options file connect as unix user w/ empty password
+                if not user:
+                    user = pwd.getpwuid(os.getuid()).pw_name
+                    passwd = ""
+                    logger.debug("Connecting to MySQL as unix user %s" % user)
+        conn = mysql.connector.connect(user=user, passwd=passwd, unix_socket=unix_socket)
+        logger.debug("Connected to MySQL as %s@localhost " % conn.user)
     except mysql.connector.Error as err:
         logger.error("Can not connect to local MySQL server")
         logger.error("MySQL said: %s" % err.msg)
         return None
-    except:
-        logger.error("Can not connect to local MySQL server")
-        logger.error("Unexpected error: %s,%s" % sys.exc_info()[:2]);
-        return None
     return conn
 
 
-# Checks if TwinDB API public key is installed
-# Returns
-# True    - if the key is installed
-# False   - if not
 def is_gpg_key_installed(email, key_type="public"):
-    global logger
-    global gpg_homedir
-    global debug_gpg
-
+    """
+    Checks if TwinDB API public key is installed
+    Returns
+    True    - if the key is installed
+    False   - if not
+    """
     result = False
-    if len(email) == 0:
+    if not email:
         logger.error("Can not check public key of an empty email")
         return False
     if debug_gpg:
         logger.debug("Checking if public key of %s is installed" % email)
+    gpg_cmd = ["gpg", "--homedir", gpg_homedir]
     try:
-        gpg_cmd = ["gpg", "--homedir", gpg_homedir]
         if key_type == "public":
             gpg_cmd.append("-k")
         else:
@@ -212,63 +239,51 @@
         gpg_cmd.append(email)
         if debug_gpg:
             logger.debug(gpg_cmd)
-        devnull = open('/dev/null', 'w')
+        devnull = open("/dev/null", "w")
         ret = subprocess.call(gpg_cmd, stdout=devnull, stderr=devnull)
-        file.close(devnull)
+        devnull.close()
         if ret != 0:
             if debug_gpg:
-                logger.debug("GPG returned %d" % ret);
+                logger.debug("GPG returned %d" % ret)
                 logger.debug(key_type + " key " + email + " is NOT installed")
             result = False
         else:
             if debug_gpg:
                 logger.debug(key_type + " key is already installed")
             result = True
-    except:
-        logger.error("Couldn't get " + key_type + " key of %s" % email)
-        exit_on_error(traceback.format_exc())
+    except OSError as err:
+        logger.error("Couldn't run command %r. %s" % (gpg_cmd, err))
+        exit_on_error("Couldn't get %s key of %s." % (key_type, email))
     return result
 
 
-# Installs TwinDB public key
-# Returns
-#   True    - if the key is successfully installed
-# Exits if the key wasn't installed
-
 def install_api_pub_key():
-    global logger
-    global api_pub_key
-    global gpg_homedir
-    global debug_gpg
-
+    """
+    Installs TwinDB public key
+    Returns
+      True    - if the key is successfully installed
+    Exits if the key wasn't installed
+    """
     logger.info("Installing twindb public key")
+    gpg_cmd = ["gpg", "--homedir", gpg_homedir, "--import"]
     try:
-        p1 = subprocess.Popen(["echo", api_pub_key], stdout=subprocess.PIPE)
-        p2 = subprocess.Popen(["gpg", "--homedir", gpg_homedir, "--import"],
-                              stdin=p1.stdout)
-        p1.stdout.close()
-    except:
-        logger.error("Couldn't install TwinDB public key")
-        exit_on_error(traceback.format_exc())
+        p = subprocess.Popen(gpg_cmd, stdin=subprocess.PIPE)
+        p.communicate(api_pub_key)
+    except OSError as err:
+        logger.error("Couldn't run command %r. %s" % (gpg_cmd, err))
+        exit_on_error("Couldn't install TwinDB public key")
     logger.info("Twindb public key successfully installed")
     return True
 
 
-# Checks if GPG environment is good to start TwinDB agent
-# Installs TwinDB public key if necessary
-# Returns
-#   True    - if the GPG environment good to proceed
-# Exits if GPG wasn't configured correctly
-
 def check_gpg():
-    global logger
-    global api_email
-    global api_pub_key
-    global gpg_homedir
-    global init_config
-    global server_id
-    global debug_gpg
-
+    """
+    Checks if GPG environment is good to start TwinDB agent
+    Installs TwinDB public key if necessary
+    Returns
+      True    - if the GPG environment good to proceed
+    Exits if GPG wasn't configured correctly
+    """
     if debug_gpg:
         logger.debug("Checking if GPG config is initialized")
     if os.path.exists(gpg_homedir):
@@ -282,13 +297,13 @@
         try:
             os.mkdir(gpg_homedir, 0700)
             install_api_pub_key()
-        except:
-            logger.error("Couldn't create directory " + gpg_homedir)
-            exit_on_error(traceback.format_exc())
-    if len(server_id) == 0:
+        except OSError as err:
+            logger.error("Failed to create directory %s. %s" % (gpg_homedir, err))
+            exit_on_error("Couldn't create directory " + gpg_homedir)
+    if not server_id:
         exit_on_error("Server id is neither read from config nor generated")
     email = "[e-mail]" % server_id
-    if not ( is_gpg_key_installed(email) and is_gpg_key_installed(email, "private")):
+    if not (is_gpg_key_installed(email) and is_gpg_key_installed(email, "private")):
         gen_entropy()
         gen_gpg_keypair("[e-mail]" % server_id)
     if debug_gpg:
@@ -296,13 +311,13 @@
     return True
 
 
-# Checks the environment if it's OK to start TwinDB agent
-# Returns
-#   True    - if the environment is OK
-# Exits if the environment is not OK
-
 def check_env():
-    global logger
+    """
+    Checks the environment if it's OK to start TwinDB agent
+    Returns
+      True    - if the environment is OK
+    Exits if the environment is not OK
+    """
     logger.debug("Checking environment")
     if os.getuid() != 0:
         exit_on_error("TwinDB agent must be run by root")
@@ -311,41 +326,24 @@
     return True
 
 
-# Checks how much entropy is available in the system
-# If not enough, does some disk activity to generate more
 def gen_entropy():
+    """
+    Checks how much entropy is available in the system
+    If not enough, does some disk activity to generate more
+    """
     # Do nothing until I find good way to generate entropy
     return
-    try:
-        f = open("/proc/sys/kernel/random/entropy_avail", "r")
-        entropy_avail = int(f.read())
-        f.close()
-        i = 0
-        while entropy_avail < 2048:
-            logger.info("Low entropy level %d. Will run 'find / -name file' to generate more")
-            cmd = ["find", "/", "-name", "file"]
-            p = subprocess.Popen(cmd)
-            p.wait()
-            f = open("/proc/sys/kernel/random/entropy_avail", "r")
-            entropy_avail = int(f.read())
-            f.close()
-            # Do not run find more than 10 times
-            if i > 10:
-                break
-            i = i + 1
-    except:
-        logger.error("Failed to generate entropy")
-    return
-
-
-# Formats bytes count to human readable form
-# Inputs:
-#   num         - bytes count
-#   decimals    - number of digits to save after point (Default 2)
-# Returns
-#   human-readable string like "20.33 MB"
+
 
 def h_size(num, decimals=2):
+    """
+    Formats bytes count to human readable form
+    Inputs:
+      num         - bytes count
+      decimals    - number of digits to save after point (Default 2)
+    Returns
+      human-readable string like "20.33 MB"
+    """
     fmt = "%3." + str(decimals) + "f %s"
     for x in ['bytes', 'kB', 'MB', 'GB', 'TB', 'PB']:
         if num < 1024.0:
@@ -353,30 +351,19 @@
         num /= 1024.0
 
 
-# Generates random string of bytes good for crypthography
-# Inputs
-#   n   - Number of bytes
-# Returns
-#   binary string of n bytes size
-
-def gen_key(n):
-    return os.urandom(n)
-
-
-# Generates GPG private and public keys for a given recipient
-# Inputs
-#   email   - recipient
-# Returns
-#   True on success or exits
-
 def gen_gpg_keypair(email):
-    global server_id
-    global gpg_homedir
-    global debug_gpg
-
-    if len(email) == 0:
+    """
+    Generates GPG private and public keys for a given recipient
+    Inputs
+      email   - recipient
+    Returns
+      True on success or exits
+    """
+    if not email:
         exit_on_error("Can not generate GPG keypair for an empty email")
+    gpg_cmd = ["gpg", "--homedir", gpg_homedir, "--batch", "--gen-key"]
     try:
+        logger.info("The agent needs to generate cryptographically strong keys.")
         logger.info("Generating GPG keys pair for %s" % email)
         logger.info("It may take really, really long time. Please be patient.")
         gen_entropy()
@@ -393,36 +380,25 @@
 %%commit
 %%echo done
 """ % (server_id, email)
-        p1 = subprocess.Popen(["echo", gpg_script], stdout=subprocess.PIPE)
-        p2 = subprocess.Popen(["gpg", "--homedir", gpg_homedir, "--batch",
-                               "--gen-key"], stdin=p1.stdout)
-        p1.stdout.close()
-        p2.wait()
-        del p1, p2
-    except:
-        logger.error("Failed to generate GPG keys pair")
-        exit_on_error(traceback.format_exc())
+
+        p = subprocess.Popen(gpg_cmd, stdin=subprocess.PIPE)
+        p.communicate(gpg_script)
+    except OSError as err:
+        logger.error("Failed to run command %r. %s" % (gpg_cmd, err))
+        exit_on_error("Failed to generate GPG keys pair")
     return True
 
 
-# Encrypts message with TwinDB public key
-# If server_id is non-zero (which means the server is registered) 
-# signs the message with the server's private key
-# Inputs
-#   msg - string to encrypt
-# Returns
-#   64-base encoded and encrypted message. To read - decrypt and 64-base decode
-#   EDIT: encrypted message
-#   None    - if error happens
-
 def encrypt(msg):
-    global logger
-    global api_email
-    global gpg_homedir
-    global server_id
-    global debug_gpg
-
-    if len(server_id) == 0:
+    """
+    Encrypts message with TwinDB public key
+    If server_id is non-zero (which means the server is registered)
+    signs the message with the server's private key
+    :param msg: string to encrypt
+    :return:  64-base encoded and encrypted message or None if error happens.
+    To read the encrypted message - decrypt and 64-base decode
+    """
+    if not server_id:
         exit_on_error("Trying to encrypt message while server_id is empty")
     server_email = "[e-mail]" % server_id
     if not is_gpg_key_installed(api_email):
@@ -433,12 +409,10 @@
         logger.debug("Public key of %s is not installed." % server_email)
         logger.debug("Will not encrypt message")
         return None
-    enc_cmd = ["gpg", "--homedir", gpg_homedir, "-r", api_email, "--batch",
-               "--trust-model", "always", "--armor"]
-    enc_cmd.append("--sign")
-    enc_cmd.append("--local-user")
-    enc_cmd.append(server_email)
-    enc_cmd.append("--encrypt")
+    enc_cmd = ["gpg", "--homedir", gpg_homedir, "-r", api_email, "--batch", "--trust-model", "always", "--armor",
+               "--sign", "--local-user", server_email, "--encrypt"]
+    cout = "No output"
+    cerr = "No output"
     try:
         if debug_gpg:
             logger.debug("Encrypting message:")
@@ -450,11 +424,14 @@
                              stdout=subprocess.PIPE,
                              stderr=subprocess.PIPE)
         cout, cerr = p.communicate(msg)
+        if p.returncode != 0:
+            raise OSError(p.returncode)
         ct = cout
         ct_64 = b64encode(ct)
         if debug_gpg:
             logger.debug("Encrypted message: " + ct_64)
-    except:
+    except OSError as err:
+        logger.error("Failed to run command %r. %s" % (enc_cmd, err))
         logger.error("Failed to encrypt message: " + msg)
         logger.error("STDOUT: " + cout)
         logger.error("STDERR: " + cerr)
@@ -462,52 +439,34 @@
     return ct_64
 
 
-# Decrypts message with local private key
-# Inputs
-#   msg - 64-base encoded and encrypted message. 
-#         Before encryption the message was 64-base encoded
-# Returns
-#   String  - Plain text message
-#   None    - if error happens
-
 def decrypt(msg_64):
-    global logger
-    global api_email
-    global gpg_homedir
-    global server_id
-    global debug_gpg
-
+    """
+    Decrypts message with local private key
+    :param msg_64: 64-base encoded and encrypted message. Before encryption the message was 64-base encoded
+    :return: Plain text message or None if error happens
+    """
     if not msg_64:
         logger.error("Will not decrypt empty message")
         return None
-
-    cout = None
-    cerr = None
-
+    cout = "No output"
+    cerr = "No output"
+    gpg_cmd = ["gpg", "--homedir", gpg_homedir, "-d", "-q"]
     try:
-        dec_cmd = ["gpg", "--homedir", gpg_homedir, "-d", "-q"]
-        debug_gpg = True
         if debug_gpg:
             logger.debug("Decrypting message:")
             logger.debug(msg_64)
             logger.debug("Decryptor command:")
-            logger.debug(dec_cmd)
-        p = subprocess.Popen(dec_cmd,
-                             stdin=subprocess.PIPE,
-                             stdout=subprocess.PIPE,
-                             stderr=subprocess.PIPE)
+            logger.debug(gpg_cmd)
+        p = subprocess.Popen(gpg_cmd, stdin=subprocess.PIPE, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
         msg = b64decode(msg_64)
         cout, cerr = p.communicate(msg)
-
         if p.returncode != 0:
             raise OSError(p.returncode)
-    except:
+    except OSError as err:
+        logger.error("Failed to run command %r. %s" % (gpg_cmd, err))
         logger.error("Failed to decrypt message: " + msg_64)
-        logger.error("Unexpected error: %s, %s" % sys.exc_info()[:2]);
-        if cout:
-            logger.error("STDOUT: " + cout)
-        if cerr:
-            logger.error("STDERR: " + cerr)
+        logger.error("STDOUT: " + cout)
+        logger.error("STDERR: " + cerr)
         return None
     if debug_gpg:
         logger.debug("Decrypted message:")
@@ -515,26 +474,20 @@
     return cout
 
 
-# Sends HTTP POST request to TwinDB dispatcher
-# It converts python data structure in "data" variable into JSON string,
-# then encrypts it and then sends as variable "data" in HTTP request
-# Inputs
-#   uri     - URI to send the request
-#   data    - Data structure with variables
-# Returns
-#   String with body of HTTP response
-#   None    - if error happened or empty response
-
 def get_response(request):
-    global logger
-    global host
-    global proto
-    global api_dir
-
+    """
+    Sends HTTP POST request to TwinDB dispatcher
+    It converts python data structure in "data" variable into JSON string,
+    then encrypts it and then sends as variable "data" in HTTP request
+    Inputs
+        uri     - URI to send the request
+        data    - Data structure with variables
+    Returns
+        String with body of HTTP response
+        None    - if error happened or empty response
+    """
     uri = "api.php"
     response_body = None
-    conn = None
-
     logger.debug("Enter get_response(uri=" + uri + ")")
     if proto == "http":
         conn = httplib.HTTPConnection(host)
@@ -542,8 +495,10 @@
         conn = httplib.HTTPSConnection(host)
     else:
         logger.error("Unsupported protocol " + proto)
+        return None
+    url = proto + "://" + host + "/" + api_dir + "/" + uri
+    http_response = "Empty response"
     try:
-        url = proto + "://" + host + "/" + api_dir + "/" + uri
         conn.connect()
         logger.debug("Sending to " + host + ": %s" % json.dumps(request, indent=4, sort_keys=True))
         data_json = json.dumps(request)
@@ -588,46 +543,38 @@
         logger.error("Please check that DNS server is reachable and works")
         return None
     except exceptions.KeyError as err:
-        logger.error("Failed to decode response from server %s" % http_response)
+        logger.error("Failed to decode response from server: %s" % http_response)
         logger.error("Could not find key %s" % err)
         return None
-    except:
-        logger.error("Couldn't make HTTP request " + url)
-        logger.error("Unexpected error: %s, %s" % sys.exc_info()[:2]);
-        logger.debug(traceback.format_exc())
-        return None
     finally:
         conn.close()
     return response_body
 
 
-# Replaces password from config with ********
-# Inputs
-#   config  - python dictionary with backup config
-# Returns
-#   Sanitized config
-
-def sanitize_config(c):
-    if not c:
+def sanitize_config(config):
+    """
+    Replaces password from config with ********
+    :param config: python dictionary with backup config
+    :return: Sanitized config
+    """
+    if not config:
         return None
-    cc = dict(c)
-    try:
-        cc["mysql_password"] = "********"
-    except:
-        logger.debug("Given config %r doesn't contain password" % c)
-    return cc
-
-
-# Gets backup config from TwinDB dispatcher
-# Returns
-#   Backup config
-#   None    - if error happened
+    sanitized_config = dict(config)
+    if "mysql_password" in config:
+        sanitized_config["mysql_password"] = "********"
+    else:
+        logger.debug("Given config %r doesn't contain password" % config)
+    return sanitized_config
+
 
 def get_config():
-    global logger
-    global server_id
-
+    """
+    Gets backup config from TwinDB dispatcher
+    :return: Backup config or None if error happened
+    """
     logger.debug("Getting config for server_id = %s" % server_id)
+    response_body = "Empty response"
+    config = None
     try:
         data = {
             "type": "get_config",
@@ -648,114 +595,87 @@
             if msg_pt["error"]:
                 logger.error(msg_pt["error"])
     except exceptions.KeyError as err:
-        logger.error("Failed to decode %s" % response_body);
-        logger.error(err);
-        return None
-    except:
-        logger.error("Couldn't get backup config")
-        logger.error("Unexpected error: %s,%s" % sys.exc_info()[:2]);
-        logger.debug(traceback.format_exc())
+        logger.error("Failed to decode %s" % response_body)
+        logger.error(err)
         return None
     return config
 
 
-# Reports slave status to TwinDB dispatcher
-def report_sss():
-    global logger
-    global server_id
-
+def report_sss(config):
+    """
+    Reports slave status to TwinDB dispatcher
+    :param config: server config received from the dispatcher
+    :return: nothing
+    """
     logger.debug("Reporting SHOW SLAVE STATUS for server_id = %s" % server_id)
-    try:
-        ss = get_slave_status()
-        data = {
-            "type": "report_sss",
-            "params": {
-                "server_id": server_id,
-                "mysql_server_id": ss["mysql_server_id"],
-                "mysql_master_server_id": ss["mysql_master_server_id"],
-                "mysql_master_host": ss["mysql_master_host"],
-                "mysql_seconds_behind_master": ss["mysql_seconds_behind_master"],
-                "mysql_slave_io_running": ss["mysql_slave_io_running"],
-                "mysql_slave_sql_running": ss["mysql_slave_sql_running"],
-            }
+    ss = get_slave_status(config["mysql_user"], config["mysql_password"])
+    data = {
+        "type": "report_sss",
+        "params": {
+            "server_id": server_id,
+            "mysql_server_id": ss["mysql_server_id"],
+            "mysql_master_server_id": ss["mysql_master_server_id"],
+            "mysql_master_host": ss["mysql_master_host"],
+            "mysql_seconds_behind_master": ss["mysql_seconds_behind_master"],
+            "mysql_slave_io_running": ss["mysql_slave_io_running"],
+            "mysql_slave_sql_running": ss["mysql_slave_sql_running"],
         }
-        response_body = get_response(data)
-    except:
-        logger.error("Couldn't get report SHOW SLAVE STATUS")
-        logger.error("Unexpected error: %s,%s" % sys.exc_info()[:2]);
-        logger.debug(traceback.format_exc())
-        return None
+    }
+    get_response(data)
     return
 
 
-# Reports what privileges are given to the agent
 def report_agent_privileges(config):
-    global logger
-    global server_id
-
+    """
+    Reports what privileges are given to the agent
+    :param config: server config received from the dispatcher
+    :return: nothing
+    """
     logger.debug("Reporting agent privileges for server_id = %s" % server_id)
-    try:
-        mysql_user = config["mysql_user"]
-        mysql_password = config["mysql_password"]
-    except:
-        logger.error("Failed to read config")
-        logger.error("Unexpected error: %s,%s" % sys.exc_info()[:2])
-        return
-    try:
-        con = get_mysql_connection(user=mysql_user, passwd=mysql_password)
-        cursor = con.cursor()
-        query = "SELECT PRIVILEGE_TYPE FROM information_schema.USER_PRIVILEGES"
-        logger.debug("Sending query : %s" % query)
-        cursor.execute(query)
-
-        privileges = dict()
-        privileges["Reload_priv"] = "N"
-        privileges["Lock_tables_priv"] = "N"
-        privileges["Repl_client_priv"] = "N"
-        privileges["Super_priv"] = "N"
-        privileges["Create_tablespace_priv"] = "N"
-
-        for (priv,) in cursor:
-            if priv == "RELOAD":
-                privileges["Reload_priv"] = "Y"
-            elif priv == "LOCK TABLES":
-                privileges["Lock_tables_priv"] = "Y"
-            elif priv == "REPLICATION CLIENT":
-                privileges["Repl_client_priv"] = "Y"
-            elif priv == "SUPER":
-                privileges["Super_priv"] = "Y"
-            elif priv == "CREATE TABLESPACE":
-                privileges["Create_tablespace_priv"] = "Y"
-        data = {
-            "type": "report_agent_privileges",
-            "params": {
-                "Reload_priv": privileges["Reload_priv"],
-                "Lock_tables_priv": privileges["Lock_tables_priv"],
-                "Repl_client_priv": privileges["Repl_client_priv"],
-                "Super_priv": privileges["Super_priv"],
-                "Create_tablespace_priv": privileges["Create_tablespace_priv"]
-            }
+    con = get_mysql_connection(user=config["mysql_user"], passwd=config["mysql_password"])
+    cursor = con.cursor()
+    query = "SELECT PRIVILEGE_TYPE FROM information_schema.USER_PRIVILEGES"
+    logger.debug("Sending query : %s" % query)
+    cursor.execute(query)
+
+    privileges = {
+        "Reload_priv": "N",
+        "Lock_tables_priv": "N",
+        "Repl_client_priv": "N",
+        "Super_priv": "N",
+        "Create_tablespace_priv": "N"
+    }
+    for (priv,) in cursor:
+        if priv == "RELOAD":
+            privileges["Reload_priv"] = "Y"
+        elif priv == "LOCK TABLES":
+            privileges["Lock_tables_priv"] = "Y"
+        elif priv == "REPLICATION CLIENT":
+            privileges["Repl_client_priv"] = "Y"
+        elif priv == "SUPER":
+            privileges["Super_priv"] = "Y"
+        elif priv == "CREATE TABLESPACE":
+            privileges["Create_tablespace_priv"] = "Y"
+    data = {
+        "type": "report_agent_privileges",
+        "params": {
+            "Reload_priv": privileges["Reload_priv"],
+            "Lock_tables_priv": privileges["Lock_tables_priv"],
+            "Repl_client_priv": privileges["Repl_client_priv"],
+            "Super_priv": privileges["Super_priv"],
+            "Create_tablespace_priv": privileges["Create_tablespace_priv"]
         }
-        get_response(data)
-    except:
-        logger.error("Couldn't get privileges granted to %s@localhost on server %s" % (mysql_user, server_id))
-        logger.error("Unexpected error: %s,%s" % sys.exc_info()[:2]);
-        logger.debug(traceback.format_exc())
-        return None
+    }
+    get_response(data)
     return
 
 
-# Gets job order from TwinDB dispatcher
-# Returns
-#   Job order in python dictionary
-#   None    - if error happened
-
 def get_job():
-    global logger
-    global server_id
-    global job_id
+    """
+    Gets job order from TwinDB dispatcher
+    :return: Job order in python dictionary or None if error happened
+    """
     job = None
-
     logger.debug("Getting job for server_id = %s" % server_id)
     try:
         d = json.JSONDecoder()
@@ -764,36 +684,41 @@
             "params": {}
         }
         response_body = get_response(data)
+        if not response_body:
+            raise JobError("Empty response from dispatcher")
         response_body_decoded = d.decode(response_body)
+        if "response" not in response_body_decoded:
+            raise JobError("There is no 'response' key in the response from dispatcher")
+        if "success" not in response_body_decoded:
+            raise JobError("There is no 'success' key in the response from dispatcher")
         msg_enc = response_body_decoded["response"]
-        if response_body_decoded["success"] == True:
+        if response_body_decoded["success"]:
             job_json = decrypt(msg_enc)
+            logger.debug("job_json = %s" % job_json)
+            if "data" not in job_json:
+                raise JobError("There is no 'data' in decrypted response %s" % job_json)
             job = d.decode(job_json)["data"]
-            job["params"] = d.decode(job["params"])
-            job_id = job["job_id"]
-            logger.info("Got job:\n%s" % json.dumps(job, indent=4, sort_keys=True))
+            if job and "params" in job and job["params"]:
+                job["params"] = d.decode(job["params"])
+                logger.info("Got job:\n%s" % json.dumps(job, indent=4, sort_keys=True))
         else:
             logger.error("Couldn't get job")
             job_json = decrypt(msg_enc)
             logger.error("Server said: %s" % d.decode(job_json)["error"])
-            logger.debug("Server said: %s" % d.decode(job_json)["debug"])
     except exceptions.TypeError as err:
+        logger.error("Failed to get a job: %s" % err)
         return None
-    except:
-        logger.error("Couldn't get job")
-        logger.error("Unexpected error: %s,%s" % sys.exc_info()[:2]);
+    except JobError as err:
+        logger.error(err)
         return None
     return job
 
 
-# Checks whether the server is registered or not
-# Returns
-#   True    - registered
-#   False   - not so much
 def is_registered():
-    global logger
-    global server_id
-
+    """
+    Checks whether the server is registered or not
+    :return: True if registered, False if not so much
+    """
     logger.debug("Getting registration status for server_id = %s" % server_id)
 
     twindb_email = "[e-mail]" % server_id
@@ -801,13 +726,13 @@
 
     enc_public_key = None
     # Reading the GPG key
+    gpg_cmd = ["gpg", "--homedir", gpg_homedir, "--armor", "--export", twindb_email]
     try:
-        p1 = subprocess.Popen(["gpg", "--homedir", gpg_homedir, "--armor", "--export", twindb_email],
-                              stdout = subprocess.PIPE)
-        enc_public_key = p1.stdout.read()
-    except:
-        logger.error("Failed to export GPG keys of %s from %s." % (twindb_email, gpg_homedir))
-        exit_on_error(traceback.format_exc())
+        p = subprocess.Popen(gpg_cmd, stdout=subprocess.PIPE)
+        enc_public_key = p.communicate()[0]
+    except OSError as err:
+        logger.error("Failed to run command %r. %s" % (gpg_cmd, err))
+        exit_on_error("Failed to export GPG keys of %s from %s." % (twindb_email, gpg_homedir))
 
     # Call the TwinDB api to check for server registration
     response_body = None
@@ -819,21 +744,17 @@
                 "enc_public_key": enc_public_key
             }
         }
-
         response_body = get_response(data)
         if not response_body:
-            return None
-        
+            return False
         json_decoder = json.JSONDecoder()
         response_body_decoded = json_decoder.decode(response_body)
-
         if response_body_decoded:
             if "response" in response_body_decoded:
                 msg_decrypted = decrypt(response_body_decoded["response"])
                 if msg_decrypted is None:
                     logger.debug("No valid response from dispatcher. Consider agent unregistered")
                     return False
-
                 msg_pt = json_decoder.decode(msg_decrypted)
                 registration_status = msg_pt["data"]
                 logger.debug("Got registration status:\n%s" % json.dumps(registration_status, indent=4, sort_keys=True))
@@ -844,216 +765,140 @@
             else:
                 logger.debug("No valid response from dispatcher. Consider agent unregistered")
                 return False
-    except exceptions.KeyError:
-        logger.error("Failed to decode %s" % response_body)
-        exit_on_error(traceback.format_exc())
-    except:
-        logger.error("Couldn't get backup config")
-        logger.error("Unexpected error: %s,%s" % sys.exc_info()[:2]);
-        exit_on_error(traceback.format_exc())
+    except exceptions.KeyError as err:
+        exit_on_error("Failed to decode response from dispatcher: %s. %s" % (response_body, err))
     return False
 
 
-# Gets name of initial full backup that corresponds to given incremental backup
-# Inputs
-#   f   - Valid name of incremental backup
-# Returns
-#   String with name of the initial full backup. 
-#   If full backup was given it will return the same name
-#   None    - if error happened
-
-def get_full_of(f):
-    global logger
-    global server_id
-
-    try:
-        logger.info("Getting full backup name of %s" % f)
-        d = json.JSONDecoder()
-        response = d.decode(get_response("get_full_of.php", {"backup_name": f}))
-        msg_enc = response["data"]
-        logger.debug("Reply from server %s" % msg_enc)
-        full = d.decode(decrypt(msg_enc))
-        logger.info("Got full backup name %s" % full["name"])
-    except:
-        logger.error("Couldn't get name of initial full backup of %s" % f)
-        logger.error(traceback.format_exc())
-        return None
-    return full["name"]
-
-
-# Gets name of child backup copy of the given backup name
-# Inputs
-#   f   - Valid name of incremental or full backup
-# Returns
-#   String with name of child backup copy of the given backup copy
-#   None    - if error happened
-
-def get_child_of(f):
-    global logger
-    global server_id
-
-    try:
-        logger.info("Getting child backup name of %s" % f)
-        d = json.JSONDecoder()
-        response = d.decode(get_response("get_child_of.php",
-                                         {"backup_name": f}))
-        msg_enc = response["data"]
-        logger.debug("Reply from server %s" % msg_enc)
-        child = d.decode(decrypt(msg_enc))
-        logger.info("Got child backup name %s" % child["name"])
-    except:
-        logger.error("Couldn't get name of child backup of %s" % f)
-        logger.error(traceback.format_exc())
-        return None
-    return child["name"]
-
-
-# Notifies a job event to TwinDB dispatcher
-# Inputs
-#   job_id  - id of a job in jobs table
-#   params  - { event: "start_job", job_id: job_id } or 
-#             { event: "stop_job", job_id: job_id, ret_code: ret }
-# Returns
-#   True    
-#   False    - if error happened
-
-def log_job_notify(job_id, params):
-    global logging
-    result = False
-
+def log_job_notify(params):
+    """
+    Notifies a job event to TwinDB dispatcher
+    :param params: { event: "start_job", job_id: job_id } or
+             { event: "stop_job", job_id: job_id, ret_code: ret }
+    :return: True of False if error happened
+    """
     logger.info("Sending event notification %s" % params["event"])
-    try:
-        data = {
-            "type": "notify",
-            "params": params
-        }
-        response_body = get_response(data)
-        d = json.JSONDecoder()
-        response_body_decoded = d.decode(response_body)
-        msg_enc = response_body_decoded["response"]
-        if response_body_decoded["success"] == True:
-            logger.debug("Dispatcher acknowledged job_id = %d start" % job_id)
-            result = True
-        else:
-            logger.error("Dispatcher didn't acknowledge job_id = %d start" % job_id)
-            result = False
-    except:
-        logger.error("Unexpected error: %s,%s" % sys.exc_info()[:2]);
+    data = {
+        "type": "notify",
+        "params": params
+    }
+    response_body = get_response(data)
+    d = json.JSONDecoder()
+    response_body_decoded = d.decode(response_body)
+    if response_body_decoded["success"]:
+        logger.debug("Dispatcher acknowledged job_id = %d notification" % job_id)
+        result = True
+    else:
+        logger.error("Dispatcher didn't acknowledge job_id = %d notification" % job_id)
+        result = False
     return result
 
 
-# Saves details about backup copy in TwinDB dispatcher
-# Inputs
-#   job_id      - id of a job in jobs table
-#   name        - name of backup
-#   size        - size of the backup in bytes
-#   lsn         - last LSN if it was incremental backup
-#   ancestor    - Ansector of the backup (not used now)
-# Returns
-#   JSON string with status of the request i.e. { "success": True }
-#   None    - if error happened
-
-def record_backup(job_id, name, volume_id, size, lsn=None, ancestor=0):
-    global logger
-
-    try:
-        logger.info("Saving information about backup:")
-        logger.info("File name : %s" % name)
-        logger.info("Volume id : %d" % int(volume_id))
-        logger.info("Size      : %d (%s)" % (int(size), h_size(size) ))
-        logger.info("Ancestor  : %d" % int(ancestor))
-        data = {
-            "type": "update_backup_data",
-            "params": {
-                "job_id": job_id,
-                "name": name,
-                "volume_id": volume_id,
-                "size": size,
-                "lsn": lsn,
-                "ancestor": ancestor
-            }
+def record_backup(name, volume_id, size, lsn=None, ancestor=0):
+    """
+    Saves details about backup copy in TwinDB dispatcher
+    :param name: name of backup
+    :param volume_id: id of a volume where the backup copy is saved
+    :param size: size of the backup in bytes
+    :param lsn: last LSN if it was incremental backup
+    :param ancestor: Ansector of the backup (not used now)
+    :return: JSON string with status of the request i.e. { "success": True } or None if error happened
+    """
+    logger.info("Saving information about backup:")
+    logger.info("File name : %s" % name)
+    logger.info("Volume id : %d" % int(volume_id))
+    logger.info("Size      : %d (%s)" % (int(size), h_size(size)))
+    logger.info("Ancestor  : %d" % int(ancestor))
+    data = {
+        "type": "update_backup_data",
+        "params": {
+            "job_id": job_id,
+            "name": name,
+            "volume_id": volume_id,
+            "size": size,
+            "lsn": lsn,
+            "ancestor": ancestor
         }
-        logger.debug("Saving a record %s" % data)
-        response = get_response(data)
-        if response <> None:
-            jd = json.JSONDecoder()
-            r = jd.decode(response)
-            logger.debug(r)
-            if r["success"]:
-                logger.info("Saved backup copy details")
-                return True
-            else:
-                logger.error("Failed to save backup copy details: "
-                             + jd.decode(decrypt(r["response"]))["error"])
-                return False
-            del jd
+    }
+    logger.debug("Saving a record %s" % data)
+    response = get_response(data)
+    if response:
+        jd = json.JSONDecoder()
+        r = jd.decode(response)
+        logger.debug(r)
+        if r["success"]:
+            logger.info("Saved backup copy details")
+            return True
         else:
-            logger.error("Empty response from server")
+            logger.error("Failed to save backup copy details: "
+                         + jd.decode(decrypt(r["response"]))["error"])
             return False
-    except:
-        logger.error("Failed to save backup copy details")
-        logger.error("Unexpected error: %s,%s" % sys.exc_info()[:2]);
+    else:
+        logger.error("Empty response from server")
         return False
-    return True
-
-
-# Reads config from /etc/twindb.cfg and sets server_id variable
-# Returns
-#   True    - if config was successfully read
-# Exits if error happened
+
 
 def read_config():
-    global init_config
+    """
+    Reads config from /etc/twindb.cfg and sets server_id variable
+    :return: True if config was successfully read
+    Exits if error happened
+    """
     global server_id
-
     try:
         if os.path.exists(init_config):
-            execfile(init_config)
+            ns = {}
+            execfile(init_config, ns)
+            if "server_id" in ns:
+                server_id = ns["server_id"]
         else:
-            exit_on_error("Config %s doesn't exist" % init_config)
-        if len(server_id) == 0:
+            print("Config %s doesn't exist" % init_config, file=sys.stderr)
+            return False
+        if not server_id:
             exit_on_error("Config %s doesn't set server_id" % init_config)
-    except:
-        logger.error(traceback.format_exc())
-        exit_on_error("Failed to read from config in %s" % init_config)
+    except IOError as err:
+        exit_on_error("Failed to read config file %s. %s" % (init_config, err))
     return True
 
 
-# Saves server_id variable in /etc/twindb.cfg
-# Returns
-#   True    - if config was successfully saved
-# Exits if error happened
-
-def save_config(server_id):
-    global init_config
-
+def save_config():
+    """
+    Saves server_id variable in file init_config (/etc/twindb.cfg)
+    :return: True    - if config was successfully saved
+    Exits if error happened
+    """
+    if not server_id:
+        exit_on_error("Can not save agent config file because server_id is empty")
     try:
-        f = open(init_config, 'w')
+        f = open(init_config, "w")
         f.write("server_id='%s'\n" % server_id)
         f.close()
-    except:
-        print("Failed to save new config in %s" % init_config)
-        sys.exit(2)
-    return
-
-
-def get_slave_status():
-    result = dict()
-    # Read master host
+    except IOError as err:
+        exit_on_error("Failed to save new config in %s. %s" % (init_config, err))
+    return True
+
+
+def get_slave_status(user=None, passwd=None):
+    """
+    Reads SHOW SLAVE STATUS from the local server
+    :param user: user to connect to MySQL
+    :param passwd: password to connect to MySQL
+    :return: dictionary with SHOW SLAVE STATUS result
+    """
+    conn = get_mysql_connection(user, passwd)
+    if conn:
+        cursor = conn.cursor(dictionary=True)
+    else:
+        return None
+    result = {
+        "mysql_server_id": None,
+        "mysql_master_server_id": None,
+        "mysql_master_host": None,
+        "mysql_seconds_behind_master": None,
+        "mysql_slave_io_running": None,
+        "mysql_slave_sql_running": None
+    }
     try:
-        conn = get_mysql_connection()
-        if conn:
-            cursor = conn.cursor(dictionary=True)
-        else:
-            return None
-
-        result["mysql_server_id"] = None
-        result["mysql_master_server_id"] = None
-        result["mysql_master_host"] = None
-        result["mysql_seconds_behind_master"] = None
-        result["mysql_slave_io_running"] = None
-        result["mysql_slave_sql_running"] = None
-
         cursor.execute("SHOW SLAVE STATUS")
         for row in cursor:
             result["mysql_master_server_id"] = row["Master_Server_Id"]
@@ -1061,35 +906,44 @@
             result["mysql_seconds_behind_master"] = row["Seconds_Behind_Master"]
             result["mysql_slave_io_running"] = row["Slave_IO_Running"]
             result["mysql_slave_sql_running"] = row["Slave_SQL_Running"]
-
+    except mysql.connector.Error as err:
+        logger.error("Could get SHOW SLAVE STATUS")
+        logger.error("MySQL Error: " % err)
+        return None
+    try:
         cursor.execute("SELECT @@server_id AS server_id")
         for row in cursor:
             result["mysql_server_id"] = row["server_id"]
-
         cursor.close()
         conn.close()
-    except:
-        logger.error("Could not read Master_host from MySQL")
-        logger.error("Unexpected error: %s,%s" % sys.exc_info()[:2]);
+    except mysql.connector.Error as err:
+        logger.error("Could not read server_id")
+        logger.error("MySQL Error: " % err)
         return None
     return result
 
 
 def has_mysql_access(username=None, password=None, grant_capability=True):
+    """
+    Reports if a user has all required MySQL privileges
+    :param username: MySQL user
+    :param password: MySQL password
+    :param grant_capability: TODO to
+    :return: a pair of a boolean that tells whether MySQL user has all required privileges
+    and a list of missing privileges
+    """
     has_required_grants = False
 
     # list of missing privileges
     missing_privileges = []
 
     try:
-        if username is None or password is None:
-            conn = get_mysql_connection()
-        else:
-            conn = get_mysql_connection(username, password)
+        conn = get_mysql_connection(username, password)
 
         if isinstance(conn, mysql.connector.MySQLConnection):
             cursor = conn.cursor(dictionary=True)
         else:
+            missing_privileges = ['RELOAD', 'SUPER', 'LOCK TABLES', 'REPLICATION CLIENT', 'CREATE TABLESPACE']
             return has_required_grants, missing_privileges
 
         # Fetch the current user and matching host part as it could either be
@@ -1149,95 +1003,84 @@
 
         cursor.close()
         conn.close()
-    except:
+    except mysql.connector.Error as err:
         logger.error("Could not read the grants information from MySQL")
-        logger.error("Unexpected error: %s,%s" % sys.exc_info()[:2])
-
+        logger.error("MySQL Error: %s" % err)
     return has_required_grants, missing_privileges
 
 
-# Registers this server in TwinDB dispatcher
-# Inputs
-#   code    - string with secret registration code
-# Returns
-#   True    - if server was successfully registered
-# Exits if error happened
 def action_handler_register(code):
-    global logger
-    global init_config
-    global ssh_private_key
-    global ssh_public_key
-    global gpg_homedir
-    global server_id
-    global mysql_user
-    global mysql_password
-
+    """
+    Registers this server in TwinDB dispatcher
+    Inputs
+      code    - string with secret registration code
+    Returns
+      True    - if server was successfully registered
+    Exits if error happened
+    """
     # Check early to see that the MySQL user passed to the agent has enough
     # privileges to create a separate MySQL user needed by TwinDB
     mysql_access_available, missing_mysql_privileges = has_mysql_access()
     if not mysql_access_available:
         logger.error("The MySQL user %s does not have enough privileges" % mysql_user)
-        if len(missing_mysql_privileges) > 0:
+        if missing_mysql_privileges:
             logger.error("Following privileges are missing: %s" % ','.join(missing_mysql_privileges))
-
         return False
 
     logger.info("Registering TwinDB agent with code %s" % code)
-    logger.info("The agent needs to generate cryptographically strong keys.")
-    logger.info("It may take really, really long time. Please be patient.")
     name = os.uname()[1].strip()  # un[1] is a hostname
 
     twindb_email = "[e-mail]" % server_id
 
-    # Generate GPG key
+    # Read GPG public key
     enc_public_key = None
+    cmd = ["gpg", "--homedir", gpg_homedir, "--armor", "--export", twindb_email]
     try:
         logger.debug("Reading GPG public key of %s." % twindb_email)
-        p1 = subprocess.Popen(["gpg", "--homedir", gpg_homedir,
-                               "--armor", "--export", twindb_email],
-                              stdout=subprocess.PIPE)
-        enc_public_key = p1.stdout.read()
-    except:
-        logger.error("Failed to export GPG keys of %s from %s."
-                     % (twindb_email, gpg_homedir))
-        exit_on_error(traceback.format_exc())
+        p1 = subprocess.Popen(cmd, stdout=subprocess.PIPE)
+        enc_public_key = p1.communicate()[0]
+    except OSError as err:
+        logger.error("Failed to run command %r. %s" % (cmd, err))
+        exit_on_error("Failed to export GPG keys of %s from %s." % (twindb_email, gpg_homedir))
 
-    # Generate SSH key
-    try:
-        if not os.path.isfile(ssh_private_key):
+    if not os.path.isfile(ssh_private_key_file):
+        try:
             logger.info("Generating SSH keys pair.")
-            subprocess.call(["ssh-keygen", "-N", "", "-f", ssh_private_key])
-    except:
-        logger.error("Failed to generate SSH keys.")
-        exit_on_error(traceback.format_exc())
-
+            subprocess.call(["ssh-keygen", "-N", "", "-f", ssh_private_key_file])
+        except OSError as err:
+            logger.error("Failed to run command %r. %s" % (cmd, err))
+            exit_on_error("Failed to generate SSH keys.")
+    ssh_public_key = None
     try:
-        logger.info("Reading SSH public key from %s." % ssh_public_key)
-        f = open(ssh_public_key, 'r')
+        logger.info("Reading SSH public key from %s." % ssh_public_key_file)
+        f = open(ssh_public_key_file, 'r')
         ssh_public_key = f.read()
         f.close()
-    except:
-        logger.error("Failed to read SSH keys.")
-        exit_on_error(traceback.format_exc())
+    except IOError as err:
+        logger.error("Failed to read from file %s. %s" % (ssh_public_key_file, err))
+        exit_on_error("Failed to read SSH keys.")
 
     # Read local ip addresses
     cmd = "ip addr"
     cmd += "| grep -w inet"
     cmd += "| awk '{ print $2}'"
     cmd += "| awk -F/ '{ print $1}'"
-    ss = get_slave_status()
-
-    if ss is None:
-        logger.error("Could not get slave status on this server")
-        exit_on_error()
-    p = subprocess.Popen(cmd, stdout=subprocess.PIPE, shell=True)
-
+    cout = None
+    logger.debug("Getting list of local IP addresses")
+    try:
+        logger.debug("Running: %s" % cmd)
+        p = subprocess.Popen(cmd, stdout=subprocess.PIPE, shell=True)
+        cout, cerr = p.communicate()
+        logger.debug("STDOUT: %s" % cout)
+        logger.debug("STDERR: %s" % cerr)
+    except OSError as err:
+        logger.error("Failed to run command %r. %s" % (cmd, err))
     local_ip = list()
-    for row in p.stdout:
-        row = row.rstrip('\n')
-        if row != "127.0.0.1":
+    for row in cout.split("\n"):
+        row = row.rstrip("\n")
+        if row and row != "127.0.0.1":
             local_ip.append(row)
-
+    ss = get_slave_status()
     data = {
         "type": "register",
         "params": {
@@ -1255,9 +1098,8 @@
             "local_ip": local_ip
         }
     }
-
     api_response = get_response(data)
-    if api_response is not None:
+    if api_response:
         json_decoder = json.JSONDecoder()
         response_decoded = json_decoder.decode(api_response)
         logger.debug(response_decoded)
@@ -1274,18 +1116,16 @@
             elif "errors" in response_decoded:
                 error_msg = response_decoded["errors"]["msg"]
 
-            logger.error("Failed to register the agent: %s" % error_msg)
-            sys.exit(2)
-        del json_decoder
+            exit_on_error("Failed to register the agent: %s" % error_msg)
     else:
         exit_on_error("Empty response from server")
     return True
 
 
 def create_agent_user():
-    global mysql_user
-    global mysql_password
-
+    """
+    Creates local MySQL user for twindb agent
+    """
     config = get_config()
     try:
         conn = get_mysql_connection()
@@ -1294,9 +1134,8 @@
         cursor = conn.cursor()
         cursor.execute(q, (config["mysql_user"], config["mysql_password"]))
     except mysql.connector.Error as err:
-        logger.error("Failed to create MySQL user %s@localhost for TwinDB agent" % config["mysql_user"])
-        logger.error("MySQL replied: %s" % err.msg)
-        exit_on_error(traceback.format_exc())
+        logger.error("MySQL replied: %s" % err)
+        exit_on_error("Failed to create MySQL user %s@localhost for TwinDB agent" % config["mysql_user"])
     logger.info("Created MySQL user %s@localhost for TwinDB agent" % config["mysql_user"])
     logger.info("Congratulations! The server is successfully registered in TwinDB.")
     logger.info("TwinDB will backup the server accordingly to the default config.")
@@ -1304,15 +1143,13 @@
     return True
 
 
-# Unregisters this server in TwinDB dispatcher
-# Returns
-#   True    - if server was successfully unregistered
-#   False   - if error happened
-
 def action_handler_unregister(delete_backups):
-    global logger
-    global init_config
-
+    """
+    Unregisters this server in TwinDB dispatcher
+    Returns
+      True    - if server was successfully unregistered
+      False   - if error happened
+    """
     data = {
         "type": "unregister",
         "params": {
@@ -1322,7 +1159,7 @@
     logger.debug("Unregistration request:")
     logger.debug(data)
     response = get_response(data)
-    if response <> None:
+    if response:
         jd = json.JSONDecoder()
         r = jd.decode(response)
         logger.debug(r)
@@ -1330,25 +1167,21 @@
             logger.info("The server is successfully unregistered")
             return True
         else:
-            logger.error("Failed to unregister the agent: "
-                         + jd.decode(decrypt(r["response"]))["error"])
-            sys.exit(2)
-        del jd
+            exit_on_error("Failed to unregister the agent: " + jd.decode(decrypt(r["response"]))["error"])
     else:
-        logger.error("Empty response from server")
-        sys.exit(2)
+        exit_on_error("Empty response from server")
     return False
 
 
-# Starts immediate backup job
 def action_handler_backup():
-    global logger
-
+    """
+    Starts immediate backup job
+    """
     if schedule_backup():
         config = get_config()
         job = get_job()
         if job:
-            if 0 == process_job(config, job):
+            if process_job(config, job) == 0:
                 return True
         else:
             logger.error("Didn't get any job from the dispatcher")
@@ -1359,10 +1192,10 @@
     return False
 
 
-# Asks dispatcher to schedule a job for this server
 def schedule_backup():
-    global logger
-
+    """
+    Asks dispatcher to schedule a job for this server
+    """
     data = {
         "type": "schedule_backup",
         "params": {
@@ -1371,7 +1204,7 @@
     logger.debug("Schedule backup request:")
     logger.debug(data)
     response = get_response(data)
-    if response <> None:
+    if response:
         jd = json.JSONDecoder()
         r = jd.decode(response)
         logger.debug(r)
@@ -1382,45 +1215,43 @@
             logger.error("Failed to schedule a job: "
                          + jd.decode(decrypt(r["response"]))["error"])
             return False
-        del jd
     else:
         exit_on_error("Empty response from server")
 
 
-# Checks if it's enough space in TwinDB storage
-# Inputs
-#   config  - backup config
-#   job     - job order
-# Returns always True
-
-def check_space(config, job_id):
+def check_space():
+    """
+    Checks if it's enough space in TwinDB storage
+    Inputs
+      config  - backup config
+      job     - job order
+    Returns always True
+    TODO: implement the fucntion
+    """
     return True
 
 
-# Checks if MySQL user from backup config has enough privileges to perform backup
-# Inputs
-#   config  - backup config
-#   job     - job order
-# Returns
-#   True    - if all necessary privileges are granted
-#   False   - if not all necessary privilegers are granted
-
 def check_mysql_permissions(config):
-    global logger
-
+    """
+    Checks if MySQL user from backup config has enough privileges to perform backup
+    Inputs
+      config  - backup config
+    Returns
+      True    - if all necessary privileges are granted
+      False   - if not all necessary privilegers are granted
+    """
     try:
         logger.info("Checking if '%s'@'localhost' has enough rights to backup MySQL" % config["mysql_user"])
-        result = False
         con = get_mysql_connection(user=config["mysql_user"], passwd=config["mysql_password"])
         required_priv = ["RELOAD", "LOCK TABLES", "REPLICATION CLIENT", "SUPER", "CREATE TABLESPACE"]
         for priv in required_priv:
             cursor = con.cursor()
             logger.debug("Checking if privilege %s is granted" % priv)
             query = """
-SELECT 
-    PRIVILEGE_TYPE 
-FROM information_schema.USER_PRIVILEGES 
-WHERE GRANTEE = '\'%s\'@\\\'localhost\\\'' AND PRIVILEGE_TYPE = %s"""
+            SELECT
+                PRIVILEGE_TYPE
+            FROM information_schema.USER_PRIVILEGES
+            WHERE GRANTEE = '\'%s\'@\\\'localhost\\\'' AND PRIVILEGE_TYPE = %s"""
             logger.debug("Sending query : %s" % query)
             cursor.execute(query, (config["mysql_user"], priv))
             cursor.fetchall()
@@ -1430,288 +1261,213 @@
                 logger.debug("Privilege %s is granted to %s@localhost" % (priv, config["mysql_user"]))
             else:
                 logger.info("%20s ... NOT GRANTED" % priv)
-                logger.error("Privilege %s is not granted to %s@localhost" % ( priv, config["mysql_user"]))
-                logger.info(
-                    "Please execute following SQL to grant %s to user %s@localhost:" % ( priv, config["mysql_user"]))
-                logger.info("GRANT %s ON *.* TO '%s'@'localhost';" % ( priv, config["mysql_user"]))
+                logger.error("Privilege %s is not granted to %s@localhost" % (priv, config["mysql_user"]))
+                logger.info("Please execute following SQL to grant %s to user %s@localhost:"
+                            % (priv, config["mysql_user"]))
+                logger.info("GRANT %s ON *.* TO '%s'@'localhost';" % (priv, config["mysql_user"]))
                 return False
             cursor.close()
         con.close()
-        result = True
-    except:
-        logger.error("Unexpected error: %s,%s" % sys.exc_info()[:2])
-        result = False
-    if result:
-        logger.debug("MySQL user %s@'localhost' has enough grants to take backup" % config["mysql_user"])
-    else:
-        logger.error("MySQL user %s@'localhost' doesn't have enough grants to take backup" % config["mysql_user"])
-    return result
-
-
-# Meta fuction that calls actual backup fucntion depending on tool in backup config
-# Inputs
-#   config  - backup config
-#   job     - job order
-# Returns what actual backup function returned or -1 if the tool is not supported
+    except mysql.connector.Error as err:
+        logger.error("MySQL Error: %s" % err)
+        return False
+    logger.debug("MySQL user %s@'localhost' has enough grants to take backup" % config["mysql_user"])
+    return True
+
 
 def take_backup(config, job):
-    global logger
-
+    """
+    Meta function that calls actual backup fucntion depending on tool in backup config
+    :param config: backup config
+    :param job: job order
+    :return: what actual backup function returned or -1 if the tool is not supported
+    """
     ret = -1
     logger.info("Starting backup job")
-    try:
-        job_id = int(job["job_id"])
-        notify_params = {"event": "start_job", "job_id": job_id}
-        if log_job_notify(job_id, notify_params):
-            ret = take_backup_xtrabackup(config, job)
-            notify_params = {"event": "stop_job", "job_id": job_id, "ret_code": ret}
-            log_job_notify(job_id, notify_params)
-            logger.info("Backup job is complete")
-        else:
-            logger.info("Backup job can not start")
-    except:
-        logger.error("Unexpected error: %s,%s" % sys.exc_info()[:2]);
-
+    notify_params = {"event": "start_job", "job_id": job["job_id"]}
+    if log_job_notify(notify_params):
+        ret = take_backup_xtrabackup(config, job)
+        notify_params = {"event": "stop_job", "job_id": job["job_id"], "ret_code": ret}
+        log_job_notify(notify_params)
+        logger.info("Backup job is complete")
+    else:
+        logger.info("Backup job can not start")
     return ret
 
 
-# Starts SSH process to TwinDB storage and saves input in file backup_name
-# Inputs
-#   config          - backup config
-#   backup_name     - file name to save input in
-#   stdin, stderr   - respective IO handlers
-# Returns what SSH process returns
-
 def start_ssh_cmd(config, job_params, backup_name, stdin, stderr):
-    global logger
-    global ssh_private_key
-    global ssh_port
-
-    p = None
+    """
+    Starts an SSH process to TwinDB storage and saves input in file backup_name
+    :param config: backup config
+    :param job_params: job parameters
+    :param backup_name: file name to save input in
+    :param stdin: respective IO handlers
+    :param stderr: respective IO handlers
+    :return: what SSH process returns
+    """
+    ssh_process = None
+    ssh_cmd = ["ssh", "-oStrictHostKeyChecking=no", "-i", ssh_private_key_file, "-p", str(ssh_port),
+               "user_id_%s@%s" % (config["user_id"], job_params["ip"]), "/bin/cat - > %s" % backup_name]
     try:
-        ssh_cmd = ["ssh", "-oStrictHostKeyChecking=no", "-i", ssh_private_key]
-        ssh_cmd.append("-p")
-        ssh_cmd.append(str(ssh_port))
-        ssh_cmd.append("user_id_%s@%s" % (config["user_id"], job_params["ip"]))
-        ssh_cmd.append("/bin/cat - > %s" % backup_name)
         logger.debug("Starting SSH process: %r" % ssh_cmd)
-        p = subprocess.Popen(ssh_cmd, stdin=stdin, stdout=subprocess.PIPE, stderr=stderr)
-    except:
-        logger.error(traceback.format_exc())
-    return p
-
-
-# Starts GPG process, encrypts STDIN and outputs in into STDOUT
-# Inputs
-#   config          - backup config
-#   stdin, stderr   - respective IO handlers
-# Returns what GPG process returns
-
-def start_gpg_cmd(config, stdin, stderr):
-    global logger
-    global ssh_private_key
-    global ssh_port
-    global server_id
-
-    p = None
+        ssh_process = subprocess.Popen(ssh_cmd, stdin=stdin, stdout=subprocess.PIPE, stderr=stderr)
+    except OSError as err:
+        logger.error("Failed to run command %r. %s" % (ssh_cmd, err))
+    return ssh_process
+
+
+def start_gpg_cmd(stdin, stderr):
+    """
+    Starts GPG process, encrypts STDIN and outputs in into STDOUT
+    :param stdin: respective IO handlers
+    :param stderr: respective IO handlers
+    :return: what GPG process returns
+    """
+    gpg_process = None
+    gpg_cmd = ["gpg", "--encrypt", "--yes", "--batch", "--no-permission-warning", "--quiet", "--recipient", server_id]
     try:
-        gpg_cmd = ["gpg", "--encrypt", "--yes", "--batch", "--no-permission-warning", "--quiet"]
-        gpg_cmd.append("--recipient")
-        gpg_cmd.append("%s" % (server_id))
-
         logger.debug("Starting GPG process: %r" % gpg_cmd)
-        p = subprocess.Popen(gpg_cmd, stdin=stdin, stdout=subprocess.PIPE, stderr=stderr)
-    except:
-        logger.error(traceback.format_exc())
-    return p
-
-
-# Takes backup copy with XtraBackup
-# Inputs
-#   config  - backup config
-#   job     - job order
-# Returns
-#   True    - if backup successfully taken
-#   False   - if backup failed
+        gpg_process = subprocess.Popen(gpg_cmd, stdin=stdin, stdout=subprocess.PIPE, stderr=stderr)
+    except OSError as err:
+        logger.error("Failed to run command %r. %s" % (gpg_cmd, err))
+    return gpg_process
+
 
 def take_backup_xtrabackup(config, job):
-    global logger
-    global server_id
-
-    suffix = "tar"
+    """
+    # Takes backup copy with XtraBackup
+    :param config: backup config
+    :param job: job order
+    :return: True if backup was successfully taken or False if it has failed
+    """
+    suffix = "xbstream"
     backup_name = "server_id_%s_%s.%s.gpg" % (server_id, datetime.now().isoformat(), suffix)
-    extra_config = ""
     ret_code = 0
-
+    if "params" not in job:
+        logger.error("There are no params in the job order")
+        return -1
+    # Check that job order has all required parameters
+    mandatory_params = ["ancestor", "backup_type", "ip", "lsn", "type", "volume_id"]
+    for param in mandatory_params:
+        if param not in job["params"]:
+            logger.error("There is no %s in the job order" % param)
+            return -1
+    backup_type = job["params"]["backup_type"]
+    xtrabackup_cmd = [
+        "innobackupex",
+        "--stream=xbstream",
+        "--user=%s" % config["mysql_user"],
+        "--password=%s" % config["mysql_password"],
+        "--socket=%s" % get_unix_socket(),
+        "--slave-info",
+        "--safe-slave-backup",
+        "--safe-slave-backup-timeout=3600"]
+    if backup_type == 'incremental':
+        last_lsn = job["params"]["lsn"]
+        xtrabackup_cmd.append("--incremental")
+        xtrabackup_cmd.append(".")
+        xtrabackup_cmd.append("--incremental-lsn=%s" % last_lsn)
+    else:
+        xtrabackup_cmd.append(".")
+    extra_config = gen_extra_config(config)
+    if extra_config:
+        xtrabackup_cmd.append("--defaults-extra-file=%s" % extra_config)
+    err_descriptors = dict()
+    for desc in ["gpg", "ssh", "xtrabackup"]:
+        desc_file = ("/tmp/twindb.%s.err" % desc)
+        try:
+            err_descriptors[desc] = open(desc_file, "w+")
+        except IOError as err:
+            logger.error("Failed to open file %s. %s" % (desc_file, err))
+            return -1
     try:
-        mysql_user = config["mysql_user"]
-        mysql_password = config["mysql_password"]
-        d = json.JSONDecoder()
-        backup_type = job["params"]["backup_type"]
-        xtrabackup_cmd = ["innobackupex"]
-        xtrabackup_cmd.append("--stream=xbstream")
-        xtrabackup_cmd.append("--user=%s" % mysql_user)
-        xtrabackup_cmd.append("--password=%s" % mysql_password)
-        xtrabackup_cmd.append("--socket=%s" % get_unix_socket())
-        xtrabackup_cmd.append("--slave-info")
-        xtrabackup_cmd.append("--safe-slave-backup")
-        xtrabackup_cmd.append("--safe-slave-backup-timeout=3600")
-        if backup_type == 'incremental':
-            last_lsn = job["params"]["lsn"]
-            xtrabackup_cmd.append("--incremental")
-            xtrabackup_cmd.append(".")
-            xtrabackup_cmd.append("--incremental-lsn=%s" % last_lsn)
-        else:
-            xtrabackup_cmd.append(".")
-        extra_config = gen_extra_config(config)
-        if extra_config:
-            xtrabackup_cmd.append("--defaults-extra-file=%s" % extra_config)
-
-        xtr_err = open('/tmp/twindb.xtrabackup.err', "w+")
-        gpg_err = open('/tmp/twindb.gpg.err', "w+")
-        ssh_err = open('/tmp/twindb.ssh.err', "w+")
-        p1 = subprocess.Popen(xtrabackup_cmd, stdout=subprocess.PIPE, stderr=xtr_err)
-        p2 = start_gpg_cmd(config, p1.stdout, gpg_err)
-        p3 = start_ssh_cmd(config, job["params"], backup_name, p2.stdout, ssh_err)
-
-        p1.stdout.close()
-        p2.stdout.close()
-        p3.communicate()
-
-        ret_code_ssh = p3.returncode
-        ret_code_gpg = p2.wait()
-        ret_code_xbk = p1.wait()
-
-        xtr_err.seek(0)
-        gpg_err.seek(0)
-        ssh_err.seek(0)
-
-        xtrabackup_stderr = xtr_err.read()
-        gpg_stderr = gpg_err.read()
-        ssh_stderr = ssh_err.read()
-
-        if len(xtrabackup_stderr) == 0:
-            xtrabackup_stderr = "no output"
-        if len(gpg_stderr) == 0:
-            gpg_stderr = "no output"
-        if len(ssh_stderr) == 0:
-            ssh_stderr = "no output"
-
-        logger.info("XtraBackup stderr: " + xtrabackup_stderr)
-        logger.info("GPG stderr: " + gpg_stderr)
-        logger.info("SSH stderr: " + ssh_stderr)
-        ancestor = 0
-
-        if ret_code_xbk == 0 and ret_code_gpg == 0 and ret_code_ssh == 0:
-            lsn = grep_lsn(xtrabackup_stderr)
-            if lsn == None:
-                logger.error("Could not find LSN in XtrabBackup output")
-                return -1
-            file_size = get_backup_size(config, job["params"], backup_name)
-            if file_size == 0:
-                logger.error("Backup copy size must not be zero")
-                return -1
-            job_id = job["job_id"]
-            volume_id = job["params"]["volume_id"]
-            ancestor = job["params"]["ancestor"]
-            if not record_backup(job_id, backup_name, volume_id, file_size, lsn, ancestor):
-                logger.error("Failed to save backup copy details")
-                return -1
-        else:
-            logger.error("Failed to take backup")
-            ret_code = -1
-    except:
+        logger.debug("Starting XtraBackup process: %r" % xtrabackup_cmd)
+        xbk_proc = subprocess.Popen(xtrabackup_cmd, stdout=subprocess.PIPE, stderr=err_descriptors["xtrabackup"])
+    except OSError as err:
+        logger.error("Failed to run command %r. %s" % (xtrabackup_cmd, err))
+        return -1
+    gpg_proc = start_gpg_cmd(xbk_proc.stdout, err_descriptors["gpg"])
+    ssh_proc = start_ssh_cmd(config, job["params"], backup_name, gpg_proc.stdout, err_descriptors["ssh"])
+
+    ssh_proc.wait()
+    xbk_proc.wait()
+    gpg_proc.wait()
+
+    ret_code_ssh = ssh_proc.returncode
+    ret_code_gpg = gpg_proc.returncode
+    ret_code_xbk = xbk_proc.returncode
+
+    err_str = dict()
+    for desc in ["gpg", "ssh", "xtrabackup"]:
+        err_descriptors[desc].seek(0)
+        err_str[desc] = err_descriptors[desc].read()
+        if not err_str[desc]:
+            err_str[desc] = "no output"
+
+    logger.info("XtraBackup stderr: " + err_str["xtrabackup"])
+    logger.info("GPG stderr: " + err_str["gpg"])
+    logger.info("SSH stderr: " + err_str["ssh"])
+
+    if ret_code_xbk == 0 and ret_code_gpg == 0 and ret_code_ssh == 0:
+        lsn = grep_lsn(err_str["xtrabackup"])
+        if not lsn:
+            logger.error("Could not find LSN in XtrabBackup output")
+            return -1
+        file_size = get_backup_size(config, job["params"], backup_name)
+        if not file_size:
+            logger.error("Backup copy size must not be zero")
+            return -1
+        volume_id = job["params"]["volume_id"]
+        ancestor = job["params"]["ancestor"]
+        if not record_backup(backup_name, volume_id, file_size, lsn, ancestor):
+            logger.error("Failed to save backup copy details")
+            return -1
+    else:
         logger.error("Failed to take backup")
-        logger.error(traceback.format_exc())
         return -1
-    finally:
-        for f in [extra_config,
-                  "/tmp/twindb.xtrabackup.err",
-                  "/tmp/twindb.gpg.err",
-                  "/tmp/twindb.ssh.err"]:
-            if os.path.isfile(f):
+    for f in [extra_config, "/tmp/twindb.xtrabackup.err", "/tmp/twindb.gpg.err", "/tmp/twindb.ssh.err"]:
+        if os.path.isfile(f):
+            try:
                 os.remove(f)
+            except IOError as err:
+                logger.error("Failed to remove file %s. %s" % (f, err))
     return ret_code
 
 
-# Generates MySQL config with datadir option
-# Inputs
-#   config  - backup config
-# Returns
-#   File name with MySQL config
-#   None    - if error happened
-
 def gen_extra_config(config):
-    global logger
-
-    extra_config = None
+    """
+    Generates MySQL config with datadir option
+    :param config: backup config
+    :return: File name with MySQL config or None if error happened
+    """
     try:
         f, extra_config = tempfile.mkstemp()
         os.write(f, "[mysqld]\n")
-        con = get_mysql_connection(
-            user=config["mysql_user"],
-            passwd=config["mysql_password"])
+        con = get_mysql_connection(config["mysql_user"], config["mysql_password"])
         cur = con.cursor()
         cur.execute("SELECT @@datadir")
         row = cur.fetchone()
         os.write(f, 'datadir="%s"\n' % row[0])
         cur.close()
         os.close(f)
-    except:
-        logger.error("Failed to generate extra defaults file")
-        logger.error(traceback.format_exc())
+    except IOError as err:
+        logger.error("Failed to generate extra defaults file. %s" % err)
         extra_config = None
     return extra_config
 
 
-# Checks if binary log is enabled in local MySQL
-# Inputs
-#   config  - backup config
-# Returns
-#   True    - binary log enabled
-#   False   - binary log disabled
-
-def is_binlog_enabled(config):
-    global logger
-
-    result = False
-    try:
-        con = MySQLdb.connect(user=config["mysql_user"], passwd=config["mysql_password"])
-        with con:
-            cur = con.cursor()
-            cur.execute("SELECT @@GLOBAL.log_bin")
-            row = cur.fetchone()
-            if row[0] == "1":
-                result = True
-            else:
-                result = False
-            cur.close()
-        del con
-    except:
-        logger.error("Failed to check if binlog is enabled")
-        logger.error(traceback.format_exc())
-    return result
-
-
-# Logs in to TwinDB storage and get size of backup
-# Inputs
-#   config      - backup config
-#   backup_name - file name with backup
-# Returns
-#   Size of backup in bytes
-#   Zero if error happened
-
 def get_backup_size(config, job_params, backup_name):
-    global logger
-    global ssh_private_key
-    global ssh_port
-    backup_size = 0
-
+    """
+    Logs in to TwinDB storage and get size of backup
+    :param config: backup config
+    :param job_params: job parameters
+    :param backup_name: file name with backup
+    :return: size of backup in bytes or zeor if error happened
+    """
     logger.debug("Getting size of %s" % backup_name)
+    ssh_cmd = ["ssh", "-oStrictHostKeyChecking=no", "-i", ssh_private_key_file, "-p", str(ssh_port),
+               "user_id_%s@%s" % (config["user_id"], job_params["ip"]), "/bin/du -b %s" % backup_name]
     try:
-        ssh_cmd = ["ssh", "-oStrictHostKeyChecking=no", "-i", ssh_private_key, "-p", str(ssh_port),
-                   "user_id_%s@%s" % (config["user_id"], job_params["ip"]), "/bin/du -b %s" % backup_name]
-
         process = subprocess.Popen(ssh_cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
         cout, cerr = process.communicate()
 
@@ -1726,30 +1482,28 @@
     except subprocess.CalledProcessError as e:
         logger.error("Failed to get size of backup %s" % backup_name)
         logger.error(str(e))
+        return 0
     except OSError as e:
         logger.error("Failed to get size of backup %s" % backup_name)
-        logger.error("Command execution failed: %s" % str(e))
-    except:
-        logger.error("Failed to get size of backup %s" % backup_name)
-        logger.error(traceback.format_exc())
-    else:
-        logger.debug("Size of %s = %d bytes (%s)" % (backup_name, backup_size, h_size(backup_size)))
-
+        logger.error("Failed to run command %r: %s" % (ssh_cmd, e))
+        return 0
+    logger.debug("Size of %s = %d bytes (%s)" % (backup_name, backup_size, h_size(backup_size)))
     return backup_size
 
 
-def handler_send_key(config, job):
+def handler_send_key(job):
     """
     Processes send_key job
     """
     # Get owner of the GPG key
+    cmd_1 = ["gpg", "--list-packets"]
     try:
         gpg_pub_key = job["params"]["gpg_pub_key"]
         if gpg_pub_key:
-            cmd_1 = ["gpg", "--list-packets"]
             logger.debug("Starting %r" % cmd_1)
             p1 = subprocess.Popen(cmd_1, stdin=subprocess.PIPE, stdout=subprocess.PIPE)
             cout, cerr = p1.communicate(gpg_pub_key)
+            keyid = "Unknown"
             for line in cout.split("\n"):
                 if "keyid:" in line:
                     keyid = line.replace("keyid:", "").strip()
@@ -1759,420 +1513,388 @@
             logger.error("Requestor public key is empty")
             return
     except OSError as err:
-        logger.error(err)
+        logger.error("Failed to run command %r: %s" % (cmd_1, err))
         return
     # Import public GPG key. It's a user public key sent by the dispatcher
     try:
         logger.debug("Importing requestor's key %s" % keyid)
         cmd_1 = ["gpg", "--import"]
-        p1 = subprocess.Popen(cmd_1, stdin=subprocess.PIPE, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
+        p1 = subprocess.Popen(cmd_1, stdin=subprocess.PIPE)
         p1.communicate(gpg_pub_key)
     except OSError as err:
-        logger.error(err)
+        logger.error("Failed to run command %r: %s" % (cmd_1, err))
         return
     # Get private key and encrypt it
-    try:
-        gpg_pub_key = job["params"]["gpg_pub_key"]
-        if gpg_pub_key:
-            logger.debug("Exporting private key of server %s" % server_id)
-            cmd_1 = ["gpg", "--armor", "--export-secret-key", server_id]
-            cmd_2 = ["gpg", "--armor", "--encrypt", "--sign", "--batch", "-r", keyid, "--local-user", server_id, "--trust-model", "always"]
+    gpg_pub_key = job["params"]["gpg_pub_key"]
+    if gpg_pub_key:
+        logger.debug("Exporting private key of server %s" % server_id)
+        cmd_1 = ["gpg", "--armor", "--export-secret-key", server_id]
+        cmd_2 = ["gpg", "--armor", "--encrypt", "--sign", "--batch", "-r", keyid, "--local-user", server_id,
+                 "--trust-model", "always"]
+        try:
             logger.debug("Starting %r" % cmd_1)
             p1 = subprocess.Popen(cmd_1, stdout=subprocess.PIPE)
+        except OSError as err:
+            logger.error("Failed to run command %r: %s" % (cmd_1, err))
+            return
+        try:
             logger.debug("Starting %r" % cmd_2)
             p2 = subprocess.Popen(cmd_2, stdin=p1.stdout, stdout=subprocess.PIPE)
             cout, cerr = p2.communicate()
             enc_private_key = cout
             logger.debug("Encrypted private key %s" % enc_private_key)
-    except OSError as err:
-        logger.error(err)
-        return
-    # Now send the private key to dispatcher
-    job_id = job["job_id"]
-    data = {
-        "type": "send_key",
-        "params": {
-            "enc_private_key": enc_private_key,
-            "job_id": job_id
+        except OSError as err:
+            logger.error("Failed to run command %r: %s" % (cmd_2, err))
+            return
+        # Now send the private key to dispatcher
+        data = {
+            "type": "send_key",
+            "params": {
+                "enc_private_key": enc_private_key,
+                "job_id": job_id
+            }
         }
-    }
-    get_response(data)
-
-# Check if directory is empty
-# Inputs
-#   dir - directory name
-# Returns
-#   True - directory is empty
-#   False - directory is not empty
-
-def is_dir_empty(dir):
-    return len(os.listdir(dir)) == 0
-
-
-# Meta fuction that calls actual restore fucntion depending on tool in backup config
-# Inputs
-#   config  - backup config
-#   job     - job order
-# Returns what actual restore function returned or -1 if the tool is not supported
+        get_response(data)
+    else:
+        logger.error("The job order requested send_key, but no public key was provided")
+
+
+def is_dir_empty(directory):
+    """
+    Checks if directory is empty
+    :param directory: directory name
+    :return: True if the directory is empty of False otherwise
+    """
+    return len(os.listdir(directory)) == 0
+
 
 def restore_backup(config, job):
-    global logger
-
-    ret = -1
-    logger.info("Starting restore job %r" % job)
-    log_start_job(int(job["job_id"]))
-
-    if config["tool"] == "xtrabackup":
+    """
+    Meta function that calls actual restore fucntion depending on tool in backup config
+    :param config: backup config
+    :param job: job order
+    :return: what actual restore function returned or -1 if the tool is not supported
+    """
+    ret = None
+    logger.info("Starting restore job: %s"
+                % json.dumps(job, indent=4, sort_keys=True))
+    notify_params = {"event": "start_job", "job_id": job["job_id"]}
+    if log_job_notify(notify_params):
         ret = restore_xtrabackup(config, job)
-    elif config["tool"] == "mysqldump":
-        ret = restore_mysqldump(config, job)
+        notify_params = {"event": "stop_job", "job_id": job["job_id"], "ret_code": ret}
+        log_job_notify(notify_params)
+        logger.info("Restore job is complete")
     else:
-        logger.error("Can't restore backup with unsupported tool %s" % config["tool"])
-        ret = -1
-    log_stop_job(int(job["job_id"]), ret)
-    logger.info("Restore job is complete")
+        logger.error("Restore job can not start")
     return ret
 
 
-# Extracts an Xtrabackup archive arc in  dst_dir
-# Inputs
-#   config  - backup config
-#   arc     - file name with archive to extract
-#   dst_dir - local destination directory
-# Returns
-#   True - if archive is successfully extracted
-#   False - if error happened
-
-def extract_archive(config, arc, dst_dir):
-    global logger
-    global ssh_private_key
-    global ssh_port
-
-    logger.info("Extracting %s in %s" % (arc, dst_dir))
-    try:
-        ssh_cmd = ["ssh", "-oStrictHostKeyChecking=no", "-i", ssh_private_key, "-p", str(ssh_port)]
-        ssh_cmd.append(config["username"] + "@" + config["dst_ip"])
-        ssh_cmd.append("/bin/cat %s" % arc)
-
-        gpg_cmd = ["gpg", "--decrypt"]
-
-        xb_cmd = ["xbstream", "-x"]
-
-        xb_err = open('/tmp/twindb.xb.err', "w+")
-        gpg_err = open('/tmp/twindb.gpg.err', "w+")
-        ssh_err = open('/tmp/twindb.ssh.err', "w+")
-        logger.info("Starting: %r" % ssh_cmd)
-        p1 = subprocess.Popen(ssh_cmd, stdout=subprocess.PIPE, stderr=ssh_err)
-        logger.info("Starting: %r" % gpg_cmd)
-        p2 = subprocess.Popen(gpg_cmd, stdin=p1.stdout, stdout=subprocess.PIPE, stderr=gpg_err)
-        logger.info("Starting: %r" % xb_cmd)
-        p3 = subprocess.Popen(xb_cmd, stdin=p2.stdout, stdout=subprocess.PIPE, stderr=mysql_err, cwd=dst_dir)
-        p1.stdout.close()
-        p2.stdout.close()
-        p3.wait()
-        xb_err.seek(0)
-        gpg_err.seek(0)
-        ssh_err.seek(0)
-        logger.info("SSH stderr: " + ssh_err.read())
-        logger.info("GPG stderr: " + gpg_err.read())
-        logger.info("xbstream stderr: " + xb_err.read())
-        if p3.returncode != 0:
-            logger.info("Failed to extract backup %s into %s" % (arc, dst_dir))
-            return False
-    except:
-        logger.info("Failed to extract backup %s into %s" % (arc, dst_dir))
-    finally:
-        todelete = ['/tmp/twindb.xb.err', '/tmp/twindb.gpg.err', '/tmp/twindb.ssh.err']
-        for f in todelete:
-            if os.path.isfile(f):
-                os.remove(f)
-    logger.info("Extracted successfully %s in %s" % (arc, dst_dir))
-    return True
-
-
-# Restores backup copy with XtraBackup
-# Inputs
-#   config  - backup config
-#   job     - job order
-# Returns
-#   True    - if backup successfully restored
-#   False   - if restore job failed
-
 def restore_xtrabackup(config, job):
-    global logger
-    global ssh_private_key
-    global ssh_port
-
-    backup_name = job["restore_backup_copy"]
-    backup_name_base = os.path.splitext(backup_name)
-    dst_dir = job["restore_dir"]
+    """
+    # Restores backup copy with XtraBackup
+    # Inputs
+    #   config  - backup config
+    #   job     - job order
+    # Returns
+    #   True    - if backup successfully restored
+    #   False   - if restore job failed
+    :param config: backup config received from the dispatcher
+    :param job: job order
+    :return:
+    """
+    if "params" not in job:
+        logger.error("There are no params in the job order")
+        return -1
+    # Check that job order has all required parameters
+    mandatory_params = ["backup_copy_id", "restore_dir", "server_id"]
+    for param in mandatory_params:
+        if param not in job["params"]:
+            logger.error("There is no %s in the job order" % param)
+            return -1
+    dst_dir = job["params"]["restore_dir"]
     try:
         if os.path.isdir(dst_dir):
             if is_dir_empty(dst_dir):
                 logger.info("Directory %s exists. But it's empty, so we can restore backup here" % dst_dir)
             else:
                 logger.error("Directory %s exists and isn't empty, so we can not restore backup here" % dst_dir)
-                return False
+                return -1
         else:
             os.makedirs(dst_dir)
-    except:
+    except IOError as err:
+        logger.error(err)
         logger.error("Can't use directory %s as destination for backup" % dst_dir)
-        logger.error(traceback.format_exc())
-        return False
-    full_copy = get_full_of(backup_name)
-    logger.info("Restoring backup %s in %s" % (backup_name, dst_dir))
+        return -1
+
+    full_copy = get_full_of(job["params"]["backup_copy_id"])
+    full_copy_id = int(full_copy["backup_copy_id"])
+    if not full_copy:
+        logger.error("Failed to get full copy parameters")
+        return -1
+    logger.info("Restoring full copy %s in %s" % (full_copy["name"], dst_dir))
     try:
-        extract_archive(config, full_copy, dst_dir)
+        if not extract_archive(config, full_copy, dst_dir):
+            raise JobError("Failed to extract %s" % full_copy["name"])
         # We restored last full backup in dst_dir
-        xb_err = open('/tmp/twindb.xb.err', "w+")
-        if full_copy == backup_name:
+        try:
+            xb_err = open('/tmp/twindb.xb.err', "w+")
+        except IOError as err:
+            raise JobError("Failed to open /tmp/twindb.xb.err: %s" % err)
+        if full_copy["backup_copy_id"] == job["params"]["backup_copy_id"]:
             xb_cmd = ["innobackupex", "--apply-log", dst_dir]
         else:
             xb_cmd = ["innobackupex", "--apply-log", "--redo-only", dst_dir]
-        p_xb = subprocess.Popen(xb_cmd, stdout=xb_err, stderr=xb_err)
-        p_xb.wait()
-        xb_err.seek(0)
-        logger.info("innobackupex stderr: " + xb_err.read())
-        os.remove('/tmp/twindb.xb.err')
+        try:
+            p_xb = subprocess.Popen(xb_cmd, stdout=xb_err, stderr=xb_err)
+            p_xb.communicate()
+        except OSError as err:
+            raise JobError("Failed to run %r: %s" % (xb_cmd, err))
+        finally:
+            xb_err.seek(0)
+            logger.info("innobackupex stderr: " + xb_err.read())
+            os.remove('/tmp/twindb.xb.err')
         if p_xb.returncode != 0:
-            logger.info("Failed to apply log on full copy %s" % (full_copy))
-            return False
+            raise JobError("Failed to apply log on full copy %s" % full_copy["name"])
         # if we restore full backup return now
-        if full_copy == backup_name:
-            logger.info("Successfully restored backup %s in %s" % (backup_name, dst_dir))
-            return True
+        if full_copy_id == job["params"]["backup_copy_id"]:
+            logger.info("Successfully restored backup %s in %s" % (full_copy["name"], dst_dir))
+            return 0
         # Now copy all incremental copies and apply then on dst_dir
-        inc_copy = full_copy
+        backup_copy = full_copy
+        backup_copy_id = full_copy_id
         while True:
-            inc_copy = get_child_of(full_copy)
+            backup_copy = get_child_of(backup_copy_id)
+            if not backup_copy:
+                raise JobError("Failed to get a child copy of backup_copy_id %d" % backup_copy_id)
+            backup_copy_id = int(backup_copy["backup_copy_id"])
             inc_dir = tempfile.mkdtemp()
-            extract_archive(config, inc_copy, inc_dir)
-
-            xb_err = open('/tmp/twindb.xb.err', "w+")
-            xb_cmd = ["innobackupex", '--apply-log']
-            if inc_copy != backup_name:
-                xb_cmd.append('--redo-only')
+            if not extract_archive(config, backup_copy, inc_dir):
+                raise JobError("Failed to extract %s in %s" % (backup_copy["name"], inc_dir))
+            try:
+                xb_err = open("/tmp/twindb.xb.err", "w+")
+            except IOError as err:
+                raise JobError("Failed to open /tmp/twindb.xb.err: %s" % err)
+            xb_cmd = ["innobackupex", "--apply-log"]
+            if backup_copy_id != job["params"]["backup_copy_id"]:
+                xb_cmd.append("--redo-only")
             xb_cmd.append('--incremental-dir=%s' % inc_dir)
             xb_cmd.append(dst_dir)
-            p_xb = subprocess.Popen(xb_cmd, stdout=xb_err, stderr=xb_err)
-            p_xb.wait()
-            xb_err.seek(0)
-            logger.info("innobackupex stderr: " + xb_err.read())
-            os.remove('/tmp/twindb.xb.err')
+            try:
+                p_xb = subprocess.Popen(xb_cmd, stdout=xb_err, stderr=xb_err)
+                p_xb.wait()
+            except OSError as err:
+                raise JobError("Failed to run %r: %s" % (xb_cmd, err))
+            finally:
+                xb_err.seek(0)
+                logger.info("innobackupex stderr: " + xb_err.read())
+                os.remove('/tmp/twindb.xb.err')
             if p_xb.returncode != 0:
-                logger.info("Failed to apply log on full copy %s" % (full_copy))
-                return False
-            os.removedirs(inc_dir)
-            if inc_copy == backup_name:
+                raise JobError("Failed to apply log on copy %s" % backup_copy["name"])
+            shutil.rmtree(inc_dir)
+            if backup_copy_id == job["params"]["backup_copy_id"]:
                 break
-        logger.info("Successfully restored backup %s in %s" % (backup_name, dst_dir))
-    except:
+        logger.info("Successfully restored backup %s in %s" % (backup_copy["name"], dst_dir))
+    except JobError as err:
+        logger.error(err)
         logger.error("Failed to restore backup")
-        logger.error(traceback.format_exc())
-        return False
+        return -1
     finally:
         for f in ["/tmp/twindb.xb.err", "/tmp/twindb.gpg.err", "/tmp/twindb.ssh.err"]:
             if os.path.isfile(f):
                 os.remove(f)
-    return True
-
-
-# Restores backup copy taken with mysqldump
-# Inputs
-#   config  - backup config
-#   job     - job order
-# Returns
-#   True    - if backup successfully restored
-#   False   - if restore job failed
-
-def restore_mysqldump(config, job):
-    global logger
-    global ssh_private_key
-    global ssh_port
-
-    ret = True
-    backup_name = job["restore_backup_copy"]
-    backup_name_base = os.path.splitext(backup_name)
-    dst_dir = job["restore_dir"]
-    try:
-        if os.path.isdir(dst_dir):
-            if is_dir_empty(dst_dir):
-                logger.info("Directory %s exists. But it's empty, so we can restore backup here" % dst_dir)
-            else:
-                logger.error("Directory %s exists and isn't empty, so we can not restore backup here" % dst_dir)
-                return False
-        else:
-            os.makedirs(dst_dir)
-    except:
-        logger.error("Can't use directory %s as destination for backup" % dst_dir)
-        logger.error(traceback.format_exc())
-        return False
-    full_copy = get_full_of(backup_name)
-    # Init mysql datadir
-    logger.info("Initializing MySQL datadir in %s" % dst_dir)
-    try:
-        mysql_socket = dst_dir + "/twindb.sock"
-        mysql_pid = dst_dir + "/mysqld.pid"
-        mysql_install_db_cmd = ["mysql_install_db", "--no-defaults"]
-        mysql_install_db_cmd.append("--datadir=%s" % dst_dir)
-        mysql_install_db_cmd.append("--user=root")
-        mysql_install_db_cmd.append("--skip-networking")
-        mysql_install_db_cmd.append("--log-error=/dev/stdout")
-        mysql_install_db_cmd.append("--pid-file=%s" % mysql_pid)
-        mysql_install_db_cmd.append("--socket=%s" % mysql_socket)
-        p = subprocess.Popen(mysql_install_db_cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
-        out, err = p.communicate()
-        ret = p.returncode
-        del p
-        if ret != 0:
-            logger.error("Couldn't init MySQL datadir in " + dst_dir)
-            logger.error("Command: %r" % mysql_install_db_cmd)
-            logger.error("STDOUT: %s" % out)
-            logger.error("STDERR: %s" % err)
+    return 0
+
+
+def extract_archive(config, arc, dst_dir):
+    """
+    Extracts an Xtrabackup archive arc in  dst_dir
+    :param config: backup config
+    :param arc: dictionary with archive to extract
+    :param dst_dir: local destination directory
+    :return:    True - if archive is successfully extracted.
+                False - if error happened
+    """
+    mandatory_params = ["backup_copy_id", "name", "ip"]
+    for param in mandatory_params:
+        if param not in arc:
+            logger.error("There is no %s in the archive parameters" % param)
             return False
-        else:
-            logger.info("MySQL datadir in %s is successfully created" % dst_dir)
-    except:
-        logger.error("Can't init MySQL datadir in " + dst_dir)
-        logger.error(traceback.format_exc())
-        return False
-    # Start MySQL instance
-    logger.info("Starting MySQL instance in %s" % dst_dir)
-    try:
-        mysqld_err = open('/tmp/twindb.mysqld.err', "w+")
-        mysqld_cmd = ["mysqld", "--no-defaults"]
-        mysqld_cmd.append("--datadir=%s" % dst_dir)
-        mysqld_cmd.append("--user=root")
-        mysqld_cmd.append("--skip-networking")
-        mysqld_cmd.append("--skip-grant-tables")
-        mysqld_cmd.append("--log-error=/dev/stdout")
-        mysqld_cmd.append("--pid-file=%s" % mysql_pid)
-        mysqld_cmd.append("--socket=%s" % mysql_socket)
-        mysqld_proc = subprocess.Popen(mysqld_cmd, stdout=mysqld_err, stderr=mysqld_err)
-        start_timeout = 5
-        while start_timeout >= 0:
-            if start_timeout == 0:
-                logger.error("Can't start MySQL instance in " + dst_dir)
-                try:
-                    mysqld_proc.terminate()
-                except:
-                    logger.info("MySQL process is already terminated")
-                finally:
-                    if os.path.isfile("/tmp/twindb.mysqld.err"):
-                        os.remove("/tmp/twindb.mysqld.err")
-                mysqld_err.seek(0)
-                logger.error("mysqld output: " + mysqld_err.read())
-                mysqld_err.close()
-                return False
-            try:
-                con = MySQLdb.connect(unix_socket=mysql_socket)
-                logger.info("Started MySQL instance in %s successfully" % dst_dir)
-                start_timeout = -1
-                del con
-            except:
-                start_timeout -= 1
-                time.sleep(1)
-    except:
-        mysqld_err.seek(0)
-        logger.error("Can't start MySQL instance in " + dst_dir)
-        logger.error("mysqld output: " + mysqld_err.read())
-        logger.error(traceback.format_exc())
-        mysqld_err.close()
-        try:
-            mysqld_proc.terminate()
-        except:
-            logger.info("MySQL process is already terminated")
-        finally:
-            if os.path.isfile("/tmp/twindb.mysqld.err"):
-                os.remove("/tmp/twindb.mysqld.err")
-        return False
-    # Copy, decrypt and restore a dump
-    logger.info("Restoring backup %s in %s" % (backup_name, dst_dir))
-    try:
-        ssh_cmd = ["ssh", "-oStrictHostKeyChecking=no", "-i", ssh_private_key, "-p", str(ssh_port)]
-        ssh_cmd.append(config["username"] + "@" + config["dst_ip"])
-        ssh_cmd.append("/bin/cat %s" % backup_name)
-
-        gpg_cmd = ["gpg", "--decrypt"]
-
-        mysql_cmd = ["mysql", "-S", mysql_socket]
-
-        mysql_err = open('/tmp/twindb.mysql.err', "w+")
-        gpg_err = open('/tmp/twindb.gpg.err', "w+")
-        ssh_err = open('/tmp/twindb.ssh.err', "w+")
-        logger.info("Starting: %r" % ssh_cmd)
-        p1 = subprocess.Popen(ssh_cmd, stdout=subprocess.PIPE, stderr=ssh_err)
-        logger.info("Starting: %r" % gpg_cmd)
-        p2 = subprocess.Popen(gpg_cmd, stdin=p1.stdout, stdout=subprocess.PIPE, stderr=gpg_err)
-        logger.info("Starting: %r" % mysql_cmd)
-        p3 = subprocess.Popen(mysql_cmd, stdin=p2.stdout, stdout=subprocess.PIPE, stderr=mysql_err)
-        p1.stdout.close()
-        p2.stdout.close()
-        out3 = p3.communicate()[0]
-        mysql_err.seek(0)
-        gpg_err.seek(0)
-        ssh_err.seek(0)
-        logger.info("SSH stderr: " + ssh_err.read())
-        logger.info("GPG stderr: " + gpg_err.read())
-        logger.info("mysql stderr: " + mysql_err.read())
-        logger.info("Successfully restored backup %s in %s" % (backup_name, dst_dir))
-        ret = p3.returncode
-        # Stop MySQL
-        mysqld_proc.terminate()
-    except:
-        logger.error("Failed to restore backup")
-        logger.error(traceback.format_exc())
-        return False
-    finally:
-        for f in ["/tmp/twindb.mysql.err", "/tmp/twindb.gpg.err", "/tmp/twindb.ssh.err"]:
-            if os.path.isfile(f):
-                os.remove(f)
-        try:
-            mysqld_proc.terminate()
-        except:
-            logger.info("MySQL process is already terminated")
+    logger.info("Extracting %s in %s" % (arc["name"], dst_dir))
+    ssh_cmd = [
+        "ssh",
+        "-oStrictHostKeyChecking=no",
+        "-i", ssh_private_key_file,
+        "-p", str(ssh_port),
+        "user_id_%s@%s" % (config["user_id"], arc["ip"]),
+        "/bin/cat %s" % arc["name"]
+    ]
+    gpg_cmd = ["gpg", "--decrypt"]
+    xb_cmd = ["xbstream", "-x"]
+
+    desc_file = None
+    try:
+        err_desc = dict()
+        for desc in ["xb", "gpg", "ssh"]:
+            desc_file = ("/tmp/twindb.%s.err" % desc)
+            err_desc[desc] = open(desc_file, "w+")
+    except IOError as err:
+        logger.error("Failed to open %s: %s" % (desc_file, err))
+        return False
+
+    logger.info("Starting: %r" % ssh_cmd)
+    p1 = subprocess.Popen(ssh_cmd, stdout=subprocess.PIPE, stderr=err_desc["ssh"])
+    logger.info("Starting: %r" % gpg_cmd)
+    p2 = subprocess.Popen(gpg_cmd, stdin=p1.stdout, stdout=subprocess.PIPE,
+                          stderr=err_desc["gpg"])
+    logger.info("Starting: %r" % xb_cmd)
+    p3 = subprocess.Popen(xb_cmd, stdin=p2.stdout, stdout=subprocess.PIPE,
+                          stderr=err_desc["xb"], cwd=dst_dir)
+    p1.wait()
+    p2.wait()
+    p3.wait()
+    for desc in ["xb", "gpg", "ssh"]:
+        err_desc[desc].seek(0)
+
+    logger.info("SSH stderr: " + err_desc["ssh"].read())
+    logger.info("GPG stderr: " + err_desc["gpg"].read())
+    logger.info("xbstream stderr: " + err_desc["xb"].read())
+    if p1.returncode != 0 or p2.returncode != 0 or p3.returncode != 0:
+        logger.info("Failed to extract backup %s in %s" % (arc["name"], dst_dir))
+        return False
+    desc_file = None
+    try:
+        for desc in ["xb", "gpg", "ssh"]:
+            desc_file = ("/tmp/twindb.%s.err" % desc)
+            if os.path.isfile(desc_file):
+                os.remove(desc_file)
+    except IOError as err:
+        logger.error("Failed to open %s: %s" % (desc_file, err))
+    logger.info("Extracted successfully %s in %s" % (arc["name"], dst_dir))
     return True
 
 
-# Finds LSN in XtraBackup output
-
-def grep_lsn(str):
+def get_full_of(backup_copy_id):
+    """
+    Gets full copy of a given backup_copy_id
+    :param backup_copy_id: backup_copy_id
+    :return: dictionary with full backup copy parameters:
+    {
+    "backup_copy_id": 188,
+    "name": "server_id_479a41b3-d22d-41a8-b7d3-4e40302622f6_2015-04-06T15:10:46.050984.tar.gp",
+    "ip": "127.0.0.1"
+    }
+    """
+    logger.debug("Getting full copy parameters of backup_copy_id %d" % backup_copy_id)
+    response_body = "Empty response"
+    full_copy = None
+    try:
+        data = {
+            "type": "get_full_copy_params",
+            "params": {
+                "backup_copy_id": backup_copy_id
+            }
+        }
+        response_body = get_response(data)
+        if not response_body:
+            logger.debug("Empty response from dispatcher")
+            return None
+        d = json.JSONDecoder()
+        response_body_decoded = d.decode(response_body)
+        if response_body_decoded:
+            msg_decrypted = decrypt(response_body_decoded["response"])
+            msg_pt = d.decode(msg_decrypted)
+            full_copy = msg_pt["data"]
+            logger.info("Got full copy params:\n%s"
+                        % json.dumps(full_copy, indent=4, sort_keys=True))
+            if msg_pt["error"]:
+                logger.error(msg_pt["error"])
+    except exceptions.KeyError as err:
+        logger.error("Failed to decode %s" % response_body)
+        logger.error(err)
+        return None
+    return full_copy
+
+
+def get_child_of(backup_copy_id):
+    """
+    Returns a child copy params of a given backup copy
+    :param backup_copy_id:
+    :return:
+    """
+    logger.debug("Getting child copy parameters of backup_copy_id %d" % backup_copy_id)
+    response_body = "Empty response"
+    child_copy = None
+    try:
+        data = {
+            "type": "get_child_copy_params",
+            "params": {
+                "backup_copy_id": backup_copy_id
+            }
+        }
+        response_body = get_response(data)
+        if not response_body:
+            return None
+        d = json.JSONDecoder()
+        response_body_decoded = d.decode(response_body)
+        if response_body_decoded:
+            msg_decrypted = decrypt(response_body_decoded["response"])
+            msg_pt = d.decode(msg_decrypted)
+            child_copy = msg_pt["data"]
+            logger.info("Got child copy params:\n%s"
+                        % json.dumps(child_copy, indent=4, sort_keys=True))
+            if msg_pt["error"]:
+                logger.error(msg_pt["error"])
+    except exceptions.KeyError as err:
+        logger.error("Failed to decode %s" % response_body)
+        logger.error(err)
+        return None
+    return child_copy
+
+
+def grep_lsn(output):
+    """
+    Finds LSN in XtraBackup output
+    :param output: string with Xtrabackup output
+    :return: LSN
+    """
     lsn = None
-    for line in str.split("\n"):
+    for line in output.split("\n"):
         if line.startswith("xtrabackup: The latest check point (for incremental):"):
             lsn = line.split("'")[1]
     return lsn
 
 
-# Finds MySQL socket
 def get_unix_socket():
-    socket = ""
+    """
+    Finds MySQL socket
+    :return: path to unix socket or None if not found
+    """
+    cmd = ["lsof", "-U", "-c", "/^mysqld$/", "-a", "-F", "n"]
     try:
-        cmd = [
-            "lsof", "-U", "-c", "/^mysqld$/", "-a", "-F", "n"
-        ]
         p = subprocess.Popen(cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
         cout, cerr = p.communicate()
         # Outputs socket in format
         # # lsof -U -c mysqld -a -F n
         # p11029
         # n/var/lib/mysql/mysql.sock
-        socket = cout.split()[1][1:]
-        if not os.path.exists(socket):
+        mysql_socket = cout.split()[1][1:]
+        if not os.path.exists(mysql_socket):
             return None
-    except:
+    except OSError as err:
+        logger.error("Failed to run command %r. %s" % (cmd, err))
         return None
-
-    return socket
+    return mysql_socket
 
 
 def pid_exists(pid):
-    """Check whether pid exists in the current process table."""
+    """
+    Checks whether pid exists in the current process table.
+    """
     if pid < 0:
         return False
     try:
         os.kill(pid, 0)
-    except OSError, e:
+    except OSError as e:
         return e.errno == errno.EPERM
     else:
         return True
@@ -2194,12 +1916,12 @@
     Raise TimeoutExpired on timeout expired (if specified).
     """
 
-    def check_timeout(delay):
+    def check_timeout(timeout_delay):
         if timeout is not None:
             if time.time() >= stop_at:
                 raise TimeoutExpired
-        time.sleep(delay)
-        return min(delay * 2, 0.04)
+        time.sleep(timeout_delay)
+        return min(timeout_delay * 2, 0.04)
 
     if timeout is not None:
         waitcall = lambda: os.waitpid(pid, os.WNOHANG)
@@ -2247,100 +1969,155 @@
                 raise RuntimeError("unknown process exit status")
 
 
-# Removes pid file
-# Exits if error happened
-
 def remove_pid():
-    global pid_file
-    try:
-        if os.path.isfile(pid_file):
+    """
+    Removes pid file
+    :return: nothing
+    Exits if error happened
+    """
+    if os.path.isfile(pid_file):
+        try:
             os.remove(pid_file)
-    except:
-        logger.error(traceback.format_exc())
-        sys.exit(2)
-
-
-# Cleans up when TwinDB agent exists
+        except IOError as err:
+            exit_on_error("Failed to remove file %s. %s" % (pid_file, err))
+
+
+def check_pid():
+    """
+    Checks if pid file already exists.
+    If it does it detects whether twindb agent is already running.
+    If the pid file is stale it removes it.
+    :return: True if pid file doesn't exist or was stale and it was removed.
+    False if twindb agent is running or error happened
+    """
+    if os.path.isfile(pid_file):
+        pid = read_pid()
+        if pid_exists(pid):
+            try:
+                f = open("/proc/%d/cmdline" % pid, "r")
+                cmdline = f.readline()
+                f.close()
+                if "twindb.py" in cmdline:
+                    # The process is a live twindb agent
+                    return False
+                else:
+                    # It's some other process, not a twindb agent
+                    return True
+            except IOError as err:
+                logger.error("Can't read from file /proc/%d/cmdline:%s " % (pid, err))
+                return False
+        else:
+            try:
+                os.remove(pid_file)
+                # It's a stale pid file
+                return True
+            except IOError as err:
+                logger.error("Can't remove file %s: %s" % (pid_file, err))
+                return False
+    else:
+        # pid file doesn't exist
+        return True
+
+
+def read_pid():
+    """
+    Read pid from pid_file
+    :return: pid or zero if pid file doesn't exist
+    """
+    try:
+        f = open(pid_file, 'r')
+        pid = int(f.readline())
+        f.close()
+    except IOError as err:
+        logger.error("Couldn't read from %s: %s" % (pid_file, err))
+        return 0
+    return int(pid)
+
+
+def write_pid():
+    """
+    Writes pid of the current process to the pid file
+    :return: nothing.
+    Exists if error happened
+    """
+    try:
+        f = open(pid_file, "w")
+        f.write(str(os.getpid()))
+        f.close()
+    except IOError as err:
+        logger.error("Couldn't save process id in " + pid_file)
+        exit_on_error(err)
+
 
 def cleanup(signum, frame):
-    global logger
-    global pid_file
+    """
+    Cleans up when TwinDB agent exists
+    :param signum:
+    :param frame:
+    :return:
+    """
 
     logger.info("Cleaning up on signal " + str(signum))
-    remove_pid()
+    logger.debug("Frame %r" % frame)
     logger.info("TwinDB agent is ready to exit")
     sys.exit(0)
 
 
-# Reports error removes pid and exits
-
-def exit_on_error(tb=None):
-    if tb is not None:
-        logger.debug(tb)
-    remove_pid()
+def exit_on_error(message):
+    """
+    Reports error removes pid and exits
+    :rtype : object
+    :param message: message to display
+    :return:
+    """
+    logger.error(message)
+    logger.debug(traceback.format_exc())
     sys.exit(2)
 
 
 # Stops TwinDB agent
 
 def stop():
-    global logger
-    global pid_file
+    """
+    Stops TwinDB agent
+    :return: nothing
+    """
 
     logger.info("Shutting down TwinDB agent")
 
     if not os.path.exists(pid_file):
         logger.info("Pid file %s does not exist. Probably twindb agent isn't running" % pid_file)
         sys.exit(0)
-
+    pid = None
     try:
         f = open(pid_file, 'r')
         pid = int(f.readline())
         os.kill(pid, signal.SIGTERM)
         wait_pid(pid, 300)
         f.close()
+        remove_pid()
     except OSError as err:
         logger.error("Couldn't kill process %d" % pid)
-        logger.error(err)
-        exit_on_error(traceback.format_exc())
+        exit_on_error(err)
     except IOError as err:
         logger.error("Couldn't read from %s" % pid_file)
-        logger.error(err)
-        exit_on_error(traceback.format_exc())
-    except:
-        logger.error("Unexpected error: %s,%s" % sys.exc_info()[:2]);
-        exit_on_error(traceback.format_exc())
-    finally:
-        remove_pid()
+        exit_on_error(err)
     logger.info("TwinDB agent successfully shut down")
     sys.exit(0)
 
 
-# Starts TwinDB agent
-
 def start():
-    global logger
-    global pid_file
-    global check_period
-
+    """
+    Starts TwinDB agent
+    :return: nothing
+    """
+    global job_id
     logger.info("Starting TwinDB agent")
 
-    if os.path.isfile(pid_file):
-        logger.error("PID file " + pid_file + " exists");
-        logger.error("Check if TwinDB agent is already running");
-        logger.error("If not, remove file " + pid_file + " manually and restart the agent");
-        sys.exit(2)
-    try:
-        f = open(pid_file, 'w')
-        f.write(str(os.getpid()))
-        f.close()
-    except IOError as err:
-        logger.error("Couldn't save process id in " + pid_file)
-        logger.error(err)
-        exit_on_error(traceback.format_exc())
-    except:
-        logger.error("Unexpected error: %s,%s" % sys.exc_info()[:2]);
-        exit_on_error(traceback.format_exc())
+    if check_pid():
+        write_pid()
+    else:
+        exit_on_error("Another instance of TwinDB agent is running. Exiting")
     try:
         while True:
             read_config()
@@ -2348,7 +2125,7 @@
             if not config:
                 time.sleep(check_period)
                 continue
-            report_sss()
+            report_sss(config)
             report_agent_privileges(config)
             job = get_job()
             if job:
@@ -2356,130 +2133,111 @@
             time.sleep(check_period)
     except SystemExit:
         remove_pid()
-    except:
-        exit_on_error(traceback.format_exc())
     sys.exit(0)
 
 
-# Processes job
-# Inputs
-#   config  - backup config
-#   job     - job order
-# Returns what respective job function returns or False if error happens
 def process_job(config, job):
-    global logger
+    """
+    Processes job
+    :param config: backup config
+    :param job: job order
+    :return: what respective job function returns or False if error happens
+    """
     global job_id
+    # Check to see that the twindb_agent MySQL user has enough privileges
+    username = config["mysql_user"]
+    password = config["mysql_password"]
+
+    job_id = int(job["job_id"])
 
     try:
-        # Check to see that the twindb_agent MySQL user has enough privileges
-        username = config["mysql_user"]
-        password = config["mysql_password"]
-
         mysql_access_available, missing_mysql_privileges = has_mysql_access(username, password, grant_capability=False)
         if not mysql_access_available:
             logger.error("The MySQL user %s does not have all the required privileges." % username)
-            if len(missing_mysql_privileges) > 0:
-                logger.error("You can grant the required privileges by executing the following SQL: "
-                             "GRANT %s ON *.* TO '%s'@'localhost'" % (','.join(missing_mysql_privileges), username))
-
-            return False
-
-        if job["start_scheduled"] == None:
-            logger.error("Job start time isn't set")
-            return False
-
+            if missing_mysql_privileges:
+                raise JobError("You can grant the required privileges by executing the following SQL: "
+                               "GRANT %s ON *.* TO '%s'@'localhost'" % (','.join(missing_mysql_privileges), username))
+        if not job["start_scheduled"]:
+            raise JobError("Job start time isn't set")
         start_scheduled = int(job["start_scheduled"])
         now = int(time.time())
         if now < start_scheduled:
-            logger.info("Job is scheduled on %s, now %s"
-                        % (time.ctime(start_scheduled), time.ctime(now)))
-            return False
-
+            raise JobTooSoonError("Job is scheduled on %s, now %s"
+                                  % (time.ctime(start_scheduled), time.ctime(now)))
         logger.info("Processing job_id = %d", int(job_id))
         if job["type"] == "backup":
             return take_backup(config, job)
         elif job["type"] == "restore":
-            #return restore_backup(config, job)
-            return False
+            return restore_backup(config, job)
         elif job["type"] == "send_key":
-            return handler_send_key(config, job)
+            return handler_send_key(job)
         else:
-            logger.error("Unsupported job type " + job["type"])
-            return False
-    except:
-        logger.error("Unexpected error: %s,%s" % sys.exc_info()[:2])
+            raise JobError("Unsupported job type " + job["type"])
+    except JobError as err:
+        logger.error("Job error: %s", err)
+        return False
+    except JobTooSoonError as err:
+        logger.debug(err)
         return False
     finally:
         job_id = 0
-    return False
 
 
 def setup_logging():
+    """
+    Setups logging handlers, formats
+    :return:
+    """
     global logger
 
-    ch = logging.StreamHandler()
-    sh = logging.handlers.SysLogHandler()
-    rh = RlogHandler()
+    console_handler = logging.StreamHandler()
+    remote_handler = RlogHandler()
+
     fmt_str = '%(name)s: %(levelname)s: %(funcName)s():%(lineno)d: %(message)s'
-    sfmt = logging.Formatter(fmt_str)
-    cfmt = logging.Formatter("%(asctime)s: " + fmt_str)
-    ch.setFormatter(cfmt)
-    sh.setFormatter(sfmt)
-    rh.setFormatter(sfmt)
-    logger.addHandler(sh)
-    logger.addHandler(ch)
-    logger.addHandler(rh)
+    remote_format = logging.Formatter(fmt_str)
+    console_format = logging.Formatter("%(asctime)s: " + fmt_str)
+
+    console_handler.setFormatter(console_format)
+    remote_handler.setFormatter(remote_format)
+
+    logger.addHandler(console_handler)
+    logger.addHandler(remote_handler)
     logger.setLevel(logging.INFO)
-    # syslog handler shouldn't log DEBUG messages
-    sh.setLevel(logging.INFO)
-
-
-# Main function
-# Parses options, creates log class etc
+
 
 def main():
+    """
+    Main function
+    Parses options, creates log class etc
+    :return:
+    """
+    global server_id
+    global check_period
+    global host
+    global mysql_user
+    global mysql_password
+    global debug
+    global logger
+
+    setup_logging()
+    read_config()
     # before we do *anything* we must ensure server_id is generated or read from config
-    global host
-    global init_config
-    global server_id
-    global check_period
-    global logger
-    global mysql_user
-    global mysql_password
-    global debug
-
     # Read or generate server id
-    if os.path.exists(init_config):
-        try:
-            execfile(init_config, globals())
-            if len(server_id) == 0:
-                print("Error: Config %s doesn't set server_id"
-                      % init_config, file=sys.stderr)
-                sys.exit(2)
-        except:
-            print(traceback.format_exc())
-            print("Error: Failed to read from config in %s"
-                  % init_config, file=sys.stderr)
-            sys.exit(2)
-    else:
+    if not server_id:
         server_id = str(uuid.uuid4())
-        save_config(server_id)
+        save_config()
 
     # At this point server_id must be set
-    if len(server_id) == 0:
-        print("Error: Server id is empty. Can not continue operation",
-              file=sys.stderr)
+    if not server_id:
+        print("Error: Server id is empty. Can not continue operation", file=sys.stderr)
         sys.exit(2)
-
-    setup_logging()
-
     # Signal handlers
     signal.signal(signal.SIGTERM, cleanup)
     signal.signal(signal.SIGINT, cleanup)
 
     # Not clear why I ignore SIGCHLD.
     # it make subprocess.call throw exception, so I comment it out so far
-    #signal.signal(signal.SIGCHLD, signal.SIG_IGN)
+    # signal.signal(signal.SIGCHLD, signal.SIG_IGN)
 
     opts = []
     try:
@@ -2489,15 +2247,11 @@
                                     "unregister", "delete-backups", "backup", "is-registered"])
     except getopt.GetoptError as err:
         logger.error(err)
-        exit_on_error(traceback.format_exc())
-    except:
-        logger.error("Unexpected error: %s,%s" % sys.exc_info()[:2]);
-        usage()
-        exit_on_error(traceback.format_exc())
 
     # Set options first
     action = None
     delete_backups = False
+    regcode = None
     for opt, arg in opts:
         if opt == '-i':
             check_period = int(arg)
@@ -2547,29 +2301,32 @@
         check_period = 1
 
     if action == "start":
-        if is_registered():
-            start()
-        else:
-            logger.error(
-                "The server must be registered first. Run following command:\n\ntwindb --register <registration code>\n")
-            logger.error("Get your code on https://console.twindb.com/?get_code")
-            sys.exit(2)
+        while True:
+            # It'll keep checking until the agent is registered
+            # Then it starts
+            if is_registered():
+                start()
+            else:
+                logger.error("The server must be registered first. Run following command:\n\n"
+                             "twindb --register <registration code>\n")
+                logger.error("Get your code on https://console.twindb.com/?get_code")
+            time.sleep(check_period)
     elif action == "stop":
         stop()
     elif action == "register":
         action_handler_register(regcode)
     elif action == "unregister":
         if not is_registered():
-            logger.error(
-                "The server must be registered first. Run following command:\n\ntwindb --register <registration code>\n")
+            logger.error("The server must be registered first. Run following command:"
+                         "\n\ntwindb --register <registration code>\n")
             logger.error("Get your code on https://console.twindb.com/?get_code")
             sys.exit(2)
         if action_handler_unregister(delete_backups):
             stop()
     elif action == "backup":
         if not is_registered():
-            logger.error(
-                "The server must be registered first. Run following command:\n\ntwindb --register <registration code>\n")
+            logger.error("The server must be registered first. Run following command:"
+                         "\n\ntwindb --register <registration code>\n")
             logger.error("Get your code on https://console.twindb.com/?get_code")
             sys.exit(2)
         if not action_handler_backup():
@@ -2583,9 +2340,8 @@
         sys.exit(0)
     else:
         # If we got there print usage() and exit
-        logger.error("Neither --start nor --stop nor --register is specified")
+        logger.error("Failed to parse command line options")
         usage()
-        remove_pid()
         sys.exit(2)