rumba: log: Added logging support, migrated from print to logging.

+ Added logging, migrated, default logging configuration is to stdout.
+ Minor PEP8 adjustments all-around

4 files changed, 96 insertions, 64 deletions

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