From 26e3e22cd6ca6676b7b99624764f8e6f1ae1479d Mon Sep 17 00:00:00 2001
From: Marco Capitani <m.capitani@nextworks.it>
Date: Fri, 21 Apr 2017 15:58:56 +0200
Subject: rumba: log: Added logging support, migrated from print to logging.

+ Added logging, migrated, default logging configuration is to stdout.
+ Minor PEP8 adjustments all-around
---
 rumba/log.py                  | 50 +++++++++++++++++++++++++++++++++++++
 rumba/model.py                | 33 +++++++++++++------------
 rumba/prototypes/irati.py     | 41 +++++++++++++------------------
 rumba/prototypes/ouroboros.py | 31 +++++++++++++----------
 rumba/prototypes/rlite.py     | 38 +++++++++++++++++------------
 rumba/ssh_support.py          | 51 +++++++++++++++++++++-----------------
 rumba/testbeds/emulab.py      | 57 +++++++++++++++++++++++++------------------
 rumba/testbeds/faketestbed.py | 11 ++++++++-
 rumba/testbeds/jfed.py        | 39 +++++++++++++++++------------
 rumba/testbeds/qemu.py        | 53 ++++++++++++++++++++++------------------
 setup.py                      | 22 ++++++++---------
 11 files changed, 260 insertions(+), 166 deletions(-)
 create mode 100644 rumba/log.py

diff --git a/rumba/log.py b/rumba/log.py
new file mode 100644
index 0000000..c9c3c01
--- /dev/null
+++ b/rumba/log.py
@@ -0,0 +1,50 @@
+import logging
+
+import sys
+
+import multiprocessing
+
+
+config_lock = multiprocessing.Lock()
+
+
+class _LoggingConfigurator(object):
+
+    is_done = False
+
+    def setup(self):
+        with config_lock:
+            if not self.is_done:
+                # Double check, so we only configure once.
+                handler = logging.StreamHandler(sys.stdout)
+                handler.lock = multiprocessing.RLock()
+                logging.basicConfig(format='{asctime} | {levelname:8.8} | '
+                                           '{name:15.15} | {message}',
+                                    style='{',
+                                    handlers=[handler],
+                                    level=logging.DEBUG)
+                logging.getLogger('').setLevel(logging.ERROR)
+                global configurator
+                configurator = _SkipLoggingConfigurator()
+            else:
+                pass
+
+    def get_logger(self, name):
+        self.setup()
+        return logging.getLogger(name)
+
+
+class _SkipLoggingConfigurator(object):
+
+    @staticmethod
+    def get_logger(name):
+        return logging.getLogger(name)
+
+
+configurator = _LoggingConfigurator()
+
+
+def get_logger(name):
+    logger = configurator.get_logger(name.split('.')[-1])
+    logger.setLevel(logging.DEBUG)
+    return logger
diff --git a/rumba/model.py b/rumba/model.py
index 0d93fcd..4c3985d 100644
--- a/rumba/model.py
+++ b/rumba/model.py
@@ -21,6 +21,11 @@
 
 import abc
 
+import rumba.log as log
+
+
+logger = log.get_logger(__name__)
+
 
 # Represents generic testbed info
 #
@@ -42,7 +47,7 @@ class Testbed:
 
     @abc.abstractmethod
     def swap_out(self, experiment):
-        print("swap_out(): nothing to do")
+        logger.info("swap_out(): nothing to do")
 
 
 # Base class for DIFs
@@ -370,9 +375,6 @@ class Experiment:
             difsdeps_inc_cnt[dif] = len(difsdeps_inc[dif])
         del difsdeps_inc
 
-        # print(difsdeps_adj)
-        # print(difsdeps_inc_cnt)
-
         # Run Kahn's algorithm to compute topological
         # ordering on the DIFs graph.
         frontier = set()
@@ -398,7 +400,7 @@ class Experiment:
                             "circular dependencies, involving the following"
                             " DIFs: %s" % circular_set)
 
-        print("DIF topological ordering: %s" % self.dif_ordering)
+        logger.debug("DIF topological ordering: %s", self.dif_ordering)
 
     # Compute all the enrollments, to be called after compute_dif_ordering()
     def compute_enrollments(self):
@@ -444,13 +446,13 @@ class Experiment:
                     er.append("%s --[%s]--> %s" % (node.name,
                                                    edge[1].name,
                                                    edge[0].name))
-            print("DIF graph for %s: %s" % (dif, ', '.join(er)))
+            logger.debug("DIF graph for %s: %s", dif, ', '.join(er))
 
             if self.enrollment_strategy == 'minimal':
                 # To generate the list of enrollments, we simulate one,
                 # using breadth-first trasversal.
-                enrolled = set([first])
-                frontier = set([first])
+                enrolled = {first}
+                frontier = {first}
                 while len(frontier):
                     cur = frontier.pop()
                     for edge in dif_graphs[dif][cur]:
@@ -475,14 +477,15 @@ class Experiment:
                 # This is a bug
                 assert False
 
-        print("Enrollments:")
+        log_string = "Enrollments:\n"
         for el in self.enrollments:
             for e in el:
-                print("    [%s] %s --> %s through N-1-DIF %s" %
-                      (e['dif'],
-                       e['enrollee'].name,
-                       e['enroller'].name,
-                       e['lower_dif']))
+                log_string += ("    [%s] %s --> %s through N-1-DIF %s\n"
+                               % (e['dif'],
+                                  e['enrollee'].name,
+                                  e['enroller'].name,
+                                  e['lower_dif']))
+        logger.debug(log_string)
 
     def compute_ipcps(self):
         # For each node, compute the required IPCP instances, and associated
@@ -519,7 +522,7 @@ class Experiment:
                 node.ipcps.append(ipcp)
                 dif.ipcps.append(ipcp)
 
-            print("IPCP for node %s: %s" % (node.name, node.ipcps))
+            logger.info("IPCP for node %s: %s", node.name, node.ipcps)
 
     # Examine the nodes and DIFs, compute the registration and enrollment
     # order, the list of IPCPs to create, registrations, ...
diff --git a/rumba/prototypes/irati.py b/rumba/prototypes/irati.py
index 0d40580..fe9b052 100644
--- a/rumba/prototypes/irati.py
+++ b/rumba/prototypes/irati.py
@@ -28,12 +28,13 @@ import os
 import rumba.ssh_support as ssh
 import rumba.model as mod
 import rumba.prototypes.irati_templates as irati_templates
+import rumba.log as log
 
 
-# An experiment over the IRATI implementation
-from rumba import ssh_support
+logger = log.get_logger(__name__)
 
 
+# An experiment over the IRATI implementation
 class Experiment(mod.Experiment):
 
     @staticmethod
@@ -90,13 +91,13 @@ class Experiment(mod.Experiment):
         self.enroll_nodes()
 
     def run_prototype(self):
-        print("irati: setting up")
+        logger.info("irati: setting up")
         self.setup()
-        print("irati: software initialized on all nodes")
+        logger.info("irati: software initialized on all nodes")
         self.conf_files = self.write_conf()
-        print("irati: configuration files generated for all nodes")
+        logger.info("irati: configuration files generated for all nodes")
         self.bootstrap_network()
-        print("irati: IPCPs created and enrolled on all nodes")
+        logger.info("irati: IPCPs created and enrolled on all nodes")
 
     def process_node(self, node):
         """
@@ -111,8 +112,8 @@ class Experiment(mod.Experiment):
             if isinstance(ipcp, mod.ShimEthIPCP):
                 if_name = ipcp.ifname
                 vlan = self.shim2vlan[ipcp.dif.name]
-                ssh_support.setup_vlan(self.testbed, node,
-                                       vlan, if_name)
+                ssh.setup_vlan(self.testbed, node,
+                               vlan, if_name)
 
         gen_files_conf = self.conf_files[node] + ['da.map']
         dir_path = os.path.dirname(os.path.abspath(__file__))
@@ -154,23 +155,20 @@ class Experiment(mod.Experiment):
                            '-c /etc/%(name)s.ipcm.conf -l %(verb)s &> log &'
                            % format_args)]
 
-        print('DEBUG: sending node setup via ssh.')
-        # print('Credentials:')
-        # print(node.ssh_config.hostname, node.ssh_config.port,
-        #       self.testbed.username, self.testbed.password)
+        logger.info('Sending node setup via ssh.')
         ssh.execute_commands(self.testbed, node.ssh_config, cmds)
 
     def enroll_nodes(self):
         """Runs the enrollments one by one, respecting dependencies"""
         for enrollment_list in self.enrollments:
             for e in enrollment_list:
-                print(
+                logger.debug(
                     'I am going to enroll %s to DIF %s against neighbor %s,'
-                    ' through lower DIF %s'
-                    % (e['enrollee'].name,
-                       e['dif'].name,
-                       e['enroller'].name,
-                       e['lower_dif'].name))
+                    ' through lower DIF %s',
+                    e['enrollee'].name,
+                    e['dif'].name,
+                    e['enroller'].name,
+                    e['lower_dif'].name)
 
                 subprocess.check_call('sleep 2'. split())  # Important!
 
@@ -184,11 +182,7 @@ class Experiment(mod.Experiment):
                                 '--enrollee-name %(dif)s.%(name)s.IPCP '
                                 '--enroller-name %(dif)s.%(o_name)s.IPCP'
                                 % e_args)
-                print('DEBUG: sending enrollment operation via ssh.')
-                # print('Credentials:')
-                # print(e['enrollee'].ssh_config.hostname,
-                #       e['enrollee'].ssh_config.port,
-                #       self.testbed.username, self.testbed.password)
+                logger.info('Sending enrollment operation via ssh.')
                 ssh.execute_command(self.testbed,
                                     e['enrollee'].ssh_config,
                                     cmd)
@@ -293,7 +287,6 @@ class Experiment(mod.Experiment):
                         "difName": shim_name
                     })
 
-
                     template_file_name = self.conf_dir(
                         'shimeth.%s.%s.dif'
                         % (node.name, shim_name))
diff --git a/rumba/prototypes/ouroboros.py b/rumba/prototypes/ouroboros.py
index 4fdacd6..9776c5e 100644
--- a/rumba/prototypes/ouroboros.py
+++ b/rumba/prototypes/ouroboros.py
@@ -21,6 +21,11 @@
 import rumba.ssh_support as ssh
 import rumba.model as mod
 import time
+import rumba.log as log
+
+
+logger = log.get_logger(__name__)
+
 
 # An experiment over the Ouroboros implementation
 class Experiment(mod.Experiment):
@@ -48,7 +53,7 @@ class Experiment(mod.Experiment):
                 cmds.append("irm b ap " + ap + " n " + name)
 
             ssh.execute_commands(self.testbed, node.ssh_config,
-                                 cmds, time_out = None)
+                                 cmds, time_out=None)
 
     def reg_names(self):
         for node in self.nodes:
@@ -60,14 +65,14 @@ class Experiment(mod.Experiment):
                 cmds.append(cmd)
 
             ssh.execute_commands(self.testbed, node.ssh_config, cmds,
-                                 time_out = None)
+                                 time_out=None)
 
     def create_ipcps(self):
         for node in self.nodes:
             cmds = list()
             for ipcp in node.ipcps:
                 cmds2 = list()
-                if ipcp.dif_bootstrapper == True:
+                if ipcp.dif_bootstrapper:
                     cmd = "irm i b n " + ipcp.name
                 else:
                     cmd = "irm i c n " + ipcp.name
@@ -80,7 +85,7 @@ class Experiment(mod.Experiment):
                     cmd += " dif " + ipcp.dif.name
                 elif type(ipcp.dif) is mod.NormalDIF:
                     cmd += " type normal"
-                    if ipcp.dif_bootstrapper == True:
+                    if ipcp.dif_bootstrapper:
                         cmd += " dif " + ipcp.dif.name
                         cmd2 = "irm b i " + ipcp.name + " name " + ipcp.dif.name
                         cmds2.append(cmd2)
@@ -97,7 +102,7 @@ class Experiment(mod.Experiment):
                     cmd += " type shim-udp"
                     cmd += " dif " + ipcp.dif.name
                 else:
-                    print("Unsupported IPCP type")
+                    logger.error("Unsupported IPCP type")
                     continue
 
                 cmds.append(cmd)
@@ -105,7 +110,7 @@ class Experiment(mod.Experiment):
                     cmds.append(cmd)
 
             ssh.execute_commands(self.testbed, node.ssh_config, cmds,
-                                 time_out = None)
+                                 time_out=None)
 
     def enroll_ipcps(self):
         for el in self.enrollments:
@@ -128,18 +133,18 @@ class Experiment(mod.Experiment):
 
                         ssh.execute_commands(self.testbed,
                                              e['enrollee'].ssh_config,
-                                             cmds, time_out = None)
+                                             cmds, time_out=None)
                         time.sleep(2)
 
     def run_prototype(self):
-        print("Setting up Ouroboros...")
+        logger.info("Setting up Ouroboros...")
         self.setup_ouroboros()
-        print("Binding names...")
+        logger.info("Binding names...")
         self.bind_names()
-        print("Creating IPCPs")
+        logger.info("Creating IPCPs")
         self.create_ipcps()
-        print("Enrolling IPCPs...")
+        logger.info("Enrolling IPCPs...")
         self.enroll_ipcps()
-        print("Registering names...")
+        logger.info("Registering names...")
         self.reg_names()
-        print("All done, have fun!")
+        logger.info("All done, have fun!")
diff --git a/rumba/prototypes/rlite.py b/rumba/prototypes/rlite.py
index 9568d7e..feca5a4 100644
--- a/rumba/prototypes/rlite.py
+++ b/rumba/prototypes/rlite.py
@@ -20,7 +20,11 @@
 
 import rumba.ssh_support as ssh
 import rumba.model as mod
-import time
+import rumba.log as log
+
+
+logger = log.get_logger(__name__)
+
 
 # An experiment over the rlite implementation
 class Experiment(mod.Experiment):
@@ -35,14 +39,15 @@ class Experiment(mod.Experiment):
     def init(self):
         cmds = []
 
-        if False: # ubuntu
+        if False:  # ubuntu
             cmds.append("apt-get update")
             cmds.append("apt-get install g++ gcc cmake "
                         "linux-headers-$(uname -r) "
                         "protobuf-compiler libprotobuf-dev git --yes")
             cmds.append("rm -rf ~/rlite")
             cmds.append("cd ~; git clone https://github.com/vmaffione/rlite")
-            cmds.append("cd ~/rlite && ./configure && make && sudo make install")
+            cmds.append("cd ~/rlite && ./configure && make "
+                        "&& sudo make install")
 
         # Load kernel modules
         cmds.append("modprobe rlite")
@@ -70,19 +75,20 @@ class Experiment(mod.Experiment):
                 elif type(ipcp.dif) is mod.ShimUDPDIF:
                     ipcp_type = 'shim-udp4'
                 else:
-                    print("unknown type for DIF %s, default to loopback" \
-                            % ipcp.dif.name)
+                    logger.warning(
+                        "unknown type for DIF %s, default to loopback",
+                        ipcp.dif.name)
                     ipcp_type = 'shim-loopback'
 
-                cmds.append("rlite-ctl ipcp-create %s %s %s" % \
+                cmds.append("rlite-ctl ipcp-create %s %s %s" %
                             (ipcp.name, ipcp_type, ipcp.dif.name))
 
                 # Generate the command to configure the interface
                 # name for the shim-eth
                 if type(ipcp.dif) is mod.ShimEthDIF:
                     ipcp.ifname = 'eth1'
-                    cmds.append("rlite-ctl ipcp-config %s netdev %s" \
-                                    % (ipcp.name, ipcp.ifname))
+                    cmds.append("rlite-ctl ipcp-config %s netdev %s"
+                                % (ipcp.name, ipcp.ifname))
 
             self.execute_commands(node, cmds)
 
@@ -92,7 +98,7 @@ class Experiment(mod.Experiment):
 
             for ipcp in node.ipcps:
                 for lower in ipcp.registrations:
-                    cmds.append("rlite-ctl ipcp-register %s %s" \
+                    cmds.append("rlite-ctl ipcp-register %s %s"
                                 % (ipcp.name, lower.name))
 
             self.execute_commands(node, cmds)
@@ -104,18 +110,18 @@ class Experiment(mod.Experiment):
                      'dif': e['dif'].name,
                      'lower_dif': e['lower_dif'].name,
                      'enroller': e['enroller'].name
-                    }
+                     }
                 cmd = "rlite-ctl ipcp-enroll %(enrollee)s %(dif)s "\
-                        "%(lower_dif)s %(enroller)s" % d
+                      "%(lower_dif)s %(enroller)s" % d
                 self.execute_commands(e['enrollee'], [cmd])
 
     def run_prototype(self):
-        print("rlite: setting up")
+        logger.info("rlite: setting up")
         self.init()
-        print("rlite: software initialized on all nodes")
+        logger.info("rlite: software initialized on all nodes")
         self.create_ipcps()
-        print("rlite: IPCPs created on all nodes")
+        logger.info("rlite: IPCPs created on all nodes")
         self.register_ipcps()
-        print("rlite: IPCPs registered to their lower DIFs on all nodes")
+        logger.info("rlite: IPCPs registered to their lower DIFs on all nodes")
         self.enroll_ipcps()
-        print("rlite: enrollment completed in all DIFs")
+        logger.info("rlite: enrollment completed in all DIFs")
diff --git a/rumba/ssh_support.py b/rumba/ssh_support.py
index d41eacb..84ff607 100644
--- a/rumba/ssh_support.py
+++ b/rumba/ssh_support.py
@@ -20,6 +20,11 @@
 import os
 import paramiko
 
+import rumba.log as log
+
+
+logger = log.get_logger(__name__)
+
 
 def get_ssh_client():
     ssh_client = paramiko.SSHClient()
@@ -34,12 +39,12 @@ def _print_stream(stream):
         if o != "":
             o_array = o.split('\\n')
             for oi in o_array:
-                print(oi)
+                logger.debug(oi)
         return o
 
 
 def execute_commands(testbed, ssh_config, commands, time_out=3):
-    '''
+    """
     Remote execution of a list of shell command on hostname. By
     default this function will exit (timeout) after 3 seconds.
 
@@ -49,7 +54,7 @@ def execute_commands(testbed, ssh_config, commands, time_out=3):
     @param time_out: time_out value in seconds, error will be generated if
     no result received in given number of seconds, the value None can
     be used when no timeout is needed
-    '''
+    """
     ssh_client = get_ssh_client()
 
     if ssh_config.proxycommand is not None:
@@ -64,10 +69,10 @@ def execute_commands(testbed, ssh_config, commands, time_out=3):
                            sock=proxy)
         o = ""
         for command in commands:
-            print("%s@%s:%s >> %s" % (testbed.username,
-                                      ssh_config.hostname,
-                                      ssh_config.port,
-                                      command))
+            logger.debug("%s@%s:%s >> %s" % (testbed.username,
+                         ssh_config.hostname,
+                         ssh_config.port,
+                         command))
             envars = '. /etc/profile;'
             command = envars + ' ' + command
             stdin, stdout, stderr = ssh_client.exec_command(command)
@@ -77,12 +82,12 @@ def execute_commands(testbed, ssh_config, commands, time_out=3):
         return o
 
     except Exception as e:
-        print(str(e))
+        logger.error(str(e))
         return
 
 
 def execute_command(testbed, ssh_config, command, time_out=3):
-    '''
+    """
     Remote execution of a list of shell command on hostname. By
     default this function will exit (timeout) after 3 seconds.
 
@@ -94,14 +99,14 @@ def execute_command(testbed, ssh_config, command, time_out=3):
     be used when no timeout is needed
 
     @return: stdout resulting from the command
-    '''
+    """
     o = execute_commands(testbed, ssh_config, [command], time_out)
     if o is not None:
         return o
 
 
 def copy_file_to_testbed(testbed, ssh_config, text, file_name):
-    '''
+    """
     Write a string to a given remote file.
     Overwrite the complete file if it already exists!
 
@@ -109,7 +114,7 @@ def copy_file_to_testbed(testbed, ssh_config, text, file_name):
     @param ssh_config: ssh config of the node
     @param text: string to be written in file
     @param file_name: file name (including full path) on the host
-    '''
+    """
     ssh_client = get_ssh_client()
 
     if ssh_config.proxycommand is not None:
@@ -131,7 +136,7 @@ def copy_file_to_testbed(testbed, ssh_config, text, file_name):
         del stdin, stdout
         err = str(stderr.read()).strip('b\'\"\\n')
         if err != "":
-            print(err)
+            logger.error(err)
 
         sftp_client = ssh_client.open_sftp()
         remote_file = sftp_client.open(file_name, 'w')
@@ -140,11 +145,11 @@ def copy_file_to_testbed(testbed, ssh_config, text, file_name):
         remote_file.close()
 
     except Exception as e:
-        print(str(e))
+        logger.error(str(e))
 
 
 def copy_paths_to_testbed(testbed, ssh_config, paths, destination):
-    '''
+    """
     Write a string to a given remote file.
     Overwrite the complete file if it already exists!
 
@@ -152,7 +157,7 @@ def copy_paths_to_testbed(testbed, ssh_config, paths, destination):
     @param ssh_config: ssh config of the node
     @param paths: source paths (local) as an iterable
     @param destination: destination folder name (remote)
-    '''
+    """
     ssh_client = get_ssh_client()
 
     if destination is not '' and not destination.endswith('/'):
@@ -169,7 +174,7 @@ def copy_paths_to_testbed(testbed, ssh_config, paths, destination):
         for path in paths:
             file_name = os.path.basename(path)
             dest_file = destination + file_name
-            print("Copying %s to %s@%s:%s path %s" % (
+            logger.info("Copying %s to %s@%s:%s path %s" % (
                 path,
                 testbed.username,
                 ssh_config.hostname,
@@ -178,11 +183,11 @@ def copy_paths_to_testbed(testbed, ssh_config, paths, destination):
             sftp_client.put(path, dest_file)
 
     except Exception as e:
-        print(str(e))
+        logger.error(str(e))
 
 
 def copy_path_to_testbed(testbed, ssh_config, path, destination):
-    '''
+    """
     Write a string to a given remote file.
     Overwrite the complete file if it already exists!
 
@@ -190,19 +195,19 @@ def copy_path_to_testbed(testbed, ssh_config, path, destination):
     @param ssh_config: ssh config of the node
     @param path: source path (local)
     @param destination: destination folder name (remote)
-    '''
+    """
     copy_paths_to_testbed(testbed, ssh_config, [path], destination)
 
 
 def setup_vlan(testbed, node, vlan_id, int_name):
-    '''
+    """
     Gets the interface (ethx) to link mapping
 
     @param testbed: testbed info
     @param node: the node to create the VLAN on
     @param vlan_id: the VLAN id
     @param int_name: the name of the interface
-    '''
+    """
     if testbed.username == 'root':
         def sudo(s):
             return s
@@ -210,7 +215,7 @@ def setup_vlan(testbed, node, vlan_id, int_name):
         def sudo(s):
             return 'sudo ' + s
 
-    print("Setting up VLAN on node " + node.name)
+    logger.info("Setting up VLAN on node " + node.name)
 
     args = {'ifname': str(int_name), 'vlan': str(vlan_id)}
 
diff --git a/rumba/testbeds/emulab.py b/rumba/testbeds/emulab.py
index c031327..cc7ce76 100644
--- a/rumba/testbeds/emulab.py
+++ b/rumba/testbeds/emulab.py
@@ -27,9 +27,15 @@ import warnings
 
 import rumba.ssh_support as ssh
 import rumba.model as mod
+import rumba.log as log
+
+
+logger = log.get_logger(__name__)
+
 
 warnings.filterwarnings("ignore")
 
+
 # Represents an emulab testbed info
 #
 # @url [string] URL of the testbed
@@ -46,41 +52,41 @@ class Testbed(mod.Testbed):
         self.ops_ssh_config = mod.SSHConfig(self.ops_server())
 
     def ops_server(self):
-        '''
+        """
         Return server name of the ops-server (is testbed specific)
 
         @param self: testbed info
 
         @return: server name of the ops-server
-        '''
+        """
         return 'ops.' + self.url
 
     def full_name(self, node_name):
-        '''
+        """
         Return server name of a node
 
         @param node_name: name of the node
         @param self: testbed info
 
         @return: server name of the node
-        '''
+        """
         return node_name + '.' + self.exp_name + '.' + \
             self.proj_name + '.' + self.url
 
     def get_experiment_list(self, project_name=None):
-        '''
+        """
         Get list of made emulab experiments accessible with your credentials
 
         @param self: testbed info
         @param project_name: optional filter on project
 
         @return: list of created experiments (strings)
-        '''
+        """
         cmd = '/usr/testbed/bin/sslxmlrpc_client.py -m experiment getlist'
         out = ssh.execute_command(self, self.ops_ssh_config, cmd)
 
         try:
-            if project_name != None:
+            if project_name is not None:
                 return literal_eval(out)[project_name][project_name]
             else:
                 return literal_eval(out)
@@ -88,11 +94,11 @@ class Testbed(mod.Testbed):
             return {project_name: {project_name: []}}
 
     def swap_exp_in(self):
-        '''
+        """
         Swaps experiment in
 
         @param self: testbed info
-        '''
+        """
         cmd = '/usr/testbed/bin/sslxmlrpc_client.py swapexp proj=' + \
               self.proj_name + \
               ' exp=' + \
@@ -104,12 +110,12 @@ class Testbed(mod.Testbed):
         return output
 
     def _create_experiment(self, experiment):
-        '''
+        """
         Creates an emulab experiment
 
         @param self: testbed info
         @param experiment: the experiment
-        '''
+        """
         proj_name = self.proj_name
         exp_name = self.exp_name
 
@@ -117,13 +123,13 @@ class Testbed(mod.Testbed):
 
         try:
             if exp_name in exp_list[proj_name][proj_name]:
-                print("Experiment already exists.")
+                logger.info("Experiment already exists.")
                 return
         except:
-            print("First experiment to be created for that project.")
+            logger.info("First experiment to be created for that project.")
 
         ns = self.generate_ns_script(experiment)
-        dest_file_name = '/users/'+ self.username + \
+        dest_file_name = '/users/' + self.username + \
                          '/temp_ns_file.%s.ns' % os.getpid()
         ssh.copy_file_to_testbed(self, self.ops_ssh_config, ns, dest_file_name)
 
@@ -134,10 +140,10 @@ class Testbed(mod.Testbed):
 
         ssh.execute_command(self, self.ops_ssh_config, cmd, time_out=None)
         ssh.execute_command(self, self.ops_ssh_config, 'rm ' + dest_file_name)
-        print("New experiment succesfully created.")
+        logger.info("New experiment succesfully created.")
 
     def generate_ns_script(self, experiment):
-        '''
+        """
         Generate ns script based on network graph.
         Enables to customize default node image.
 
@@ -145,7 +151,7 @@ class Testbed(mod.Testbed):
         @param self: testbed info
 
         @return: ns2 script for Emulab experiment
-        '''
+        """
 
         ns2_script = "# ns script generated by Rumba\n"
         ns2_script += "set ns [new Simulator]\n"
@@ -170,12 +176,12 @@ class Testbed(mod.Testbed):
         return ns2_script
 
     def wait_until_nodes_up(self):
-        '''
+        """
         Checks if nodes are up
 
         @param self: testbed info
-        '''
-        print("Waiting until all nodes are up")
+        """
+        logger.info("Waiting until all nodes are up")
 
         cmd = '/usr/testbed/bin/script_wrapper.py expinfo -e' + \
               self.proj_name + \
@@ -187,20 +193,20 @@ class Testbed(mod.Testbed):
         active = False
         if res == "active":
             active = True
-        while active != True:
+        while not active:
             res = ssh.execute_command(self, self.ops_ssh_config, cmd)
             if res == "active":
                 active = True
-            print("Still waiting")
+            logger.info("Still waiting")
             time.sleep(5)
 
     def complete_experiment_graph(self, experiment):
-        '''
+        """
         Gets the interface (ethx) to link mapping
 
         @param self: testbed info
         @param experiment: the experiment
-        '''
+        """
 
         for node in experiment.nodes:
             node.ssh_config.hostname = self.full_name(node.name)
@@ -241,3 +247,6 @@ class Testbed(mod.Testbed):
         self.swap_exp_in()
         self.wait_until_nodes_up()
         self.complete_experiment_graph(experiment)
+
+    def swap_out(self, experiment):
+        pass
diff --git a/rumba/testbeds/faketestbed.py b/rumba/testbeds/faketestbed.py
index 85110b8..c1cd865 100644
--- a/rumba/testbeds/faketestbed.py
+++ b/rumba/testbeds/faketestbed.py
@@ -19,11 +19,20 @@
 # MA  02110-1301  USA
 
 import rumba.model as mod
+import rumba.log as log
+
+
+logger = log.get_logger(__name__)
+
 
 # Fake testbed, useful for testing
 class Testbed(mod.Testbed):
+
     def __init__(self, exp_name, username, proj_name="ARCFIRE", password=""):
         mod.Testbed.__init__(self, exp_name, username, password, proj_name)
 
     def swap_in(self, experiment):
-        print("[Fake testbed] experiment swapped in")
+        logger.info("[Fake testbed] experiment swapped in")
+
+    def swap_out(self, experiment):
+        pass
diff --git a/rumba/testbeds/jfed.py b/rumba/testbeds/jfed.py
index f51081c..1c0f992 100644
--- a/rumba/testbeds/jfed.py
+++ b/rumba/testbeds/jfed.py
@@ -26,8 +26,14 @@ import wget
 import tarfile
 
 import rumba.model as mod
+import rumba.log as log
+
+
+logger = log.get_logger(__name__)
+
 
 class Testbed(mod.Testbed):
+
     def __init__(self, exp_name, username, cert_file, exp_hours="2",
                  proj_name="ARCFIRE", authority="wall2.ilabt.iminds.be",
                  image=None):
@@ -47,18 +53,17 @@ class Testbed(mod.Testbed):
         else:
             self.image = None
 
-        if os.path.exists(self.jfed_jar) == False:
-            print("Couldn't find jFed CLI. Downloading.")
+        if not os.path.exists(self.jfed_jar):
+            logger.warning("Couldn't find jFed CLI. Downloading.")
             tarball = "jfed_cli.tar.gz"
             url = "http://jfed.iminds.be/downloads/stable/jar/" + tarball
             wget.download(url)
             tar = tarfile.open(tarball)
             tar.extractall()
             tar.close()
-            print("Extracted in current directory")
+            logger.info("Extracted in current directory")
             os.remove(tarball)
 
-
     def create_rspec(self, experiment):
         impl = xml.getDOMImplementation()
         doc = impl.createDocument(None, "rspec", None)
@@ -137,22 +142,23 @@ class Testbed(mod.Testbed):
 
         for node in experiment.nodes:
             auth_name_r = self.auth_name.replace(".", "-")
-            node.ssh_config.hostname = node.name + "." + self.exp_name + "." + \
-                                       auth_name_r + "." + self.auth_name
+            node.ssh_config.hostname = \
+                node.name + "." + self.exp_name + "." + \
+                auth_name_r + "." + self.auth_name
             node.ssh_config.proxycommand = "ssh -i '" + self.cert_file + \
                                            "' -o StrictHostKeyChecking=no " + \
                                            self.username + \
                                            "@bastion.test.iminds.be nc " + \
                                            node.ssh_config.hostname + " 22"
 
-        subprocess.call(["java", "-jar", self.jfed_jar, "create", "-S", \
-                         self.proj_name, "--rspec", \
-                         self.rspec, "-s", \
-                         self.exp_name, "-p", self.cert_file, "-k", \
-                         "usercert,userkeys,shareduserallkeys", \
-                         "--create-slice",\
+        subprocess.call(["java", "-jar", self.jfed_jar, "create", "-S",
+                         self.proj_name, "--rspec",
+                         self.rspec, "-s",
+                         self.exp_name, "-p", self.cert_file, "-k",
+                         "usercert,userkeys,shareduserallkeys",
+                         "--create-slice",
                          "--manifest", self.manifest,
-                         "-P", self.password, \
+                         "-P", self.password,
                          "-e", self.exp_hours])
 
         rspec = xml.parse(self.manifest)
@@ -175,5 +181,8 @@ class Testbed(mod.Testbed):
                             comp_id = intf.getAttribute("component_id")
                             comp_arr = comp_id.split(":")
                             ipcp.ifname = comp_arr[-1]
-                            #xml_ip = intf.getElementsByTagName("ip")
-                            #interface.ip = xml_ip[0].getAttribute("address")
+                            # xml_ip = intf.getElementsByTagName("ip")
+                            # interface.ip = xml_ip[0].getAttribute("address")
+
+    def swap_out(self, experiment):
+        pass
diff --git a/rumba/testbeds/qemu.py b/rumba/testbeds/qemu.py
index 40899d7..934038b 100644
--- a/rumba/testbeds/qemu.py
+++ b/rumba/testbeds/qemu.py
@@ -24,7 +24,11 @@ import subprocess
 import os
 
 import rumba.model as mod
-from rumba import ssh_support
+import rumba.log as log
+import rumba.ssh_support as ssh_support
+
+
+logger = log.get_logger(__name__)
 
 
 class Testbed(mod.Testbed):
@@ -62,7 +66,7 @@ class Testbed(mod.Testbed):
         for command in commands:
             if not error_queue.empty() and not ignore_errors:
                 break
-            print('qemu: executing >> %s' % command)
+            logger.debug('executing >> %s', command)
             try:
                 subprocess.check_call(command.split())
             except subprocess.CalledProcessError as e:
@@ -76,8 +80,6 @@ class Testbed(mod.Testbed):
             results_queue.put("Command chain ran with %d errors" % errors)
 
     def recover_if_names(self, experiment):
-        next_vlan = 10
-        assigned_vlan = {}
         for node in experiment.nodes:
             for ipcp in node.ipcps:
                 if isinstance(ipcp, mod.ShimEthIPCP):
@@ -88,8 +90,8 @@ class Testbed(mod.Testbed):
                     port_id = port['port_id']
                     vm_id = self.vms[node_name]['id']
                     mac = '00:0a:0a:0a:%02x:%02x' % (vm_id, port_id)
-                    print('qemu: recovering ifname for port: '
-                          + port['tap_id'] + '.')
+                    logger.info('Recovering ifname for port: %s.',
+                                port['tap_id'])
                     output = ssh_support.execute_command(
                         self,
                         node.ssh_config,
@@ -111,7 +113,7 @@ class Testbed(mod.Testbed):
             except subprocess.CalledProcessError:
                 raise Exception('Not authenticated')
 
-        print("qemu: swapping in")
+        logger.info("qemu: swapping in")
 
         # Building bridges and taps
         shim_processes = []
@@ -189,15 +191,15 @@ class Testbed(mod.Testbed):
             # Check for errors
             if not e_queue.empty():
                 error_str = str(e_queue.get())
-                print('qemu: Testbed instantiation failed: %s' % error_str)
+                logger.error('Testbed instantiation failed: %s', error_str)
                 raise Exception('Failure: %s' % error_str)
             try:
                 # Check for results
                 result = r_queue.get(timeout=1)
                 if result == "Command chain ran correctly.":
                     over_processes += 1
-                    print('qemu: %s of %s processes completed.'
-                          % (over_processes, total_processes))
+                    logger.debug('%s of %s processes completed.',
+                                 over_processes, total_processes)
             except:
                 max_waiting_time -= 1
 
@@ -270,16 +272,15 @@ class Testbed(mod.Testbed):
 
             booting_budget -= 1
             if booting_budget <= 0:
-
-                print('qemu: Sleeping %s secs waiting '
-                      'for the VMs to boot' % boot_backoff)
+                logger.debug('Sleeping %s secs waiting '
+                             'for the VMs to boot', boot_backoff)
 
                 time.sleep(boot_backoff)
                 booting_budget = boot_batch_size
 
             with open('%s/qemu_out_%s' % (self.qemu_logs_dir, vmid), 'w')\
                     as out_file:
-                print('qemu: executing >> %s' % command)
+                logger.debug('executing >> %s', command)
                 self.boot_processes.append(subprocess.Popen(command.split(),
                                                             stdout=out_file))
 
@@ -289,11 +290,13 @@ class Testbed(mod.Testbed):
         if booting_budget < boot_backoff:
             tsleep = boot_backoff * (boot_batch_size - booting_budget) / \
                                             boot_batch_size
-            print('qemu: Sleeping %s secs waiting for the last VMs to boot' % tsleep)
+            logger.info('Sleeping %s secs '
+                        'waiting for the last VMs to boot',
+                        tsleep)
             time.sleep(tsleep)
 
         # TODO: to be removed, we should loop in the ssh part
-        print('qemu: Sleeping 5 seconds, just to be on the safe side')
+        logger.info('qemu: Sleeping 5 seconds, just to be on the safe side')
         time.sleep(5)
 
         self.recover_if_names(experiment)
@@ -340,16 +343,17 @@ class Testbed(mod.Testbed):
         while max_waiting_time > 0 and over_processes < total_processes:
             # Check for errors
             if not error_queue.empty():
-                print('qemu:Failure while shutting down: %s'\
-                         % str(error_queue.get()))
+                logger.warning('Failure while shutting down: %s',
+                               str(error_queue.get()))
                 over_processes += 1
             try:
                 # Check for results
                 result = results_queue.get(timeout=1)
                 if result == "Command chain ran correctly.":
                     over_processes += 1
-                    print('qemu: %s of %s tear-down port processes completed.'
-                          % (over_processes, total_processes))
+                    logger.debug('qemu: %s of %s tear-down port '
+                                 'processes completed.',
+                                 over_processes, total_processes)
             except:
                 max_waiting_time -= 1
 
@@ -378,15 +382,16 @@ class Testbed(mod.Testbed):
         while max_waiting_time > 0 and over_processes < total_processes:
             # Check for errors
             if not error_queue.empty():
-                print('qemu: Failure while shutting down: %s'
-                      % str(error_queue.get()))
+                logger.warning('Failure while shutting down: %s'
+                               % str(error_queue.get()))
                 over_processes += 1
             try:
                 # Check for results
                 result = results_queue.get(timeout=1)
                 if result == "Command chain ran correctly.":
                     over_processes += 1
-                    print('qemu: %s of %s tear-down shim processes completed.'
-                          % (over_processes, total_processes))
+                    logger.debug('%s of %s tear-down shim '
+                                 'processes completed.'
+                                 % (over_processes, total_processes))
             except:
                 max_waiting_time -= 1
diff --git a/setup.py b/setup.py
index 33d6813..d60a7d4 100644
--- a/setup.py
+++ b/setup.py
@@ -8,15 +8,15 @@ with open(path.join(here, 'README.md'), encoding='utf-8') as f:
     long_description = f.read()
 
 setup(
-    name = "Rumba",
-    version = "0.1",
-    url = "https://gitlab.com/arcfire/rumba",
-    keywords = "rina measurement testbed",
-    author = "Sander Vrijders",
-    author_email = "sander.vrijders@intec.ugent.be",
-    license = "LGPL",
-    description = "Rumba measurement framework for RINA",
-    long_description = long_description,
-    packages = ["rumba", "rumba.testbeds", "rumba.prototypes"],
-    install_requires = ["paramiko", "wheel", "wget"]
+    name="Rumba",
+    version="0.1",
+    url="https://gitlab.com/arcfire/rumba",
+    keywords="rina measurement testbed",
+    author="Sander Vrijders",
+    author_email="sander.vrijders@intec.ugent.be",
+    license="LGPL",
+    description="Rumba measurement framework for RINA",
+    long_description=long_description,
+    packages=["rumba", "rumba.testbeds", "rumba.prototypes"],
+    install_requires=["paramiko", "wheel", "wget"]
 )
-- 
cgit v1.2.3