Debug cleanups

Switch from print to logging.X() where sensible

Change-Id: Ic691c64c581f6c20b7b8a1d46d25783782dd762e

3 files changed, 67 insertions, 66 deletions

diff --git a/db/db.py b/db/db.py
index d944f0e..2c6d089 100644
--- a/db/db.py
+++ b/db/db.py
@@ -21,6 +21,7 @@
 import psycopg2
 import psycopg2.extras
 import datetime, os, sys
+import logging
 
 if __name__ == '__main__':
     vlandpath = os.path.abspath(os.path.normpath(os.path.dirname(sys.argv[0])))
@@ -35,7 +36,8 @@ class VlanDB:
             self.connection = psycopg2.connect(database=db_name, user=username)
             self.cursor = self.connection.cursor(cursor_factory=psycopg2.extras.NamedTupleCursor)
         except Exception as e:
-            print "Failed to access database: %s" % e
+            logging.error("Failed to access database: %s" % e)
+            raise
 
     def __del__(self):
         self.cursor.close()
@@ -349,7 +351,6 @@ class VlanDB:
     #
     # Returns None on failure.
     def get_port_by_switch_and_name(self, switch_id, name):
-        print "Looking for switch_id %s and name %s" % (switch_id, name)
         return self._get_element2("port_id", "port", "switch_id", int(switch_id), "name", name)
 
     # Simple lookup: look up a port by ID, and return the current VLAN
diff --git a/util.py b/util.py
index af75c9a..26421a1 100644
--- a/util.py
+++ b/util.py
@@ -17,8 +17,8 @@ class VlanUtil:
         config = state.config
         ret = {}
         for switch_name in sorted(config.switches):
-            print "Found switch %s:" % (switch_name)
-            print "  Probing..."
+            logging.debug("Found switch %s:" % (switch_name))
+            logging.debug("  Probing...")
 
             s = self.get_switch_driver(switch_name, config)
             s.switch_connect(config.switches[switch_name].username,
@@ -33,9 +33,9 @@ class VlanUtil:
 
     # Simple helper wrapper for all the read-only database queries
     def perform_db_query(self, state, command, data):
-        print 'perform_db_query'
-        print command
-        print data
+        logging.debug('perform_db_query')
+        logging.debug(command)
+        logging.debug(data)
         ret = {}
         db = state.db
         try:
@@ -88,9 +88,9 @@ class VlanUtil:
 
     # Simple helper wrapper for all the read-only daemon state queries
     def perform_daemon_query(self, state, command, data):
-        print 'perform_daemon_query'
-        print command
-        print data
+        logging.debug('perform_daemon_query')
+        logging.debug(command)
+        logging.debug(data)
         ret = {}
         try:
             if command == 'daemon.status':
@@ -120,9 +120,9 @@ class VlanUtil:
 
     # Helper wrapper for API functions modifying database state only
     def perform_db_update(self, state, command, data):
-        print 'perform_db_update'
-        print command
-        print data
+        logging.debug('perform_db_update')
+        logging.debug(command)
+        logging.debug(data)
         ret = {}
         db = state.db
         try:
@@ -154,9 +154,9 @@ class VlanUtil:
     # Helper wrapper for API functions that modify both database state
     # and on-switch VLAN state
     def perform_vlan_update(self, state, command, data):
-        print 'perform_vlan_update'
-        print command
-        print data
+        logging.debug('perform_vlan_update')
+        logging.debug(command)
+        logging.debug(data)
         ret = {}
 
         try:
@@ -178,7 +178,7 @@ class VlanUtil:
                 raise InputError("Unknown query command \"%s\"" % command)
 
         except InputError as e:
-            print 'got error %s' % e
+            logging.debug('got error %s' % e)
             raise
 
 #        except:
@@ -199,17 +199,17 @@ class VlanUtil:
     # switches then removing the VLAN in the DB.
     def create_vlan(self, state, name, tag, is_base_vlan):
 
-        print 'create_vlan'
+        logging.debug('create_vlan')
         db = state.db
         config = state.config
 
         # 1. Database record first
         try:
-            print 'Adding DB record first: name %s, tag %d, is_base_vlan %d' % (name, tag, is_base_vlan)
+            logging.debug('Adding DB record first: name %s, tag %d, is_base_vlan %d' % (name, tag, is_base_vlan))
             vlan_id = db.create_vlan(name, tag, is_base_vlan)
-            print 'Added VLAN tag %d, name %s to the database, created VLAN ID %d' % (tag, name, vlan_id)
+            logging.debug('Added VLAN tag %d, name %s to the database, created VLAN ID %d' % (tag, name, vlan_id))
         except InputError:
-            print 'DB creation failed'
+            logging.debug('DB creation failed')
             raise
 
         # Keep track of which switches we've configured, for later use
@@ -221,7 +221,7 @@ class VlanUtil:
                 trunk_ports = []
                 switch_name = switch.name
                 try:
-                    print 'Adding new VLAN to switch %s' % switch_name
+                    logging.debug('Adding new VLAN to switch %s' % switch_name)
                     # Get the right driver
                     s = self.get_switch_driver(switch_name, config)
                     s.switch_connect(config.switches[switch_name].username,
@@ -235,23 +235,23 @@ class VlanUtil:
                     # 2a. Create the VLAN on the switch
                     s.vlan_create(tag)
                     s.vlan_set_name(tag, name)
-                    print 'Added VLAN tag %d, name %s to switch %s' % (tag, name, switch_name)
+                    logging.debug('Added VLAN tag %d, name %s to switch %s' % (tag, name, switch_name))
 
                     # 2b. Do we need to worry about trunk ports on this switch?
                     if 'TrunkWildCardVlans' in s.switch_get_capabilities():
-                        print 'This switch does not need special trunk port handling'
+                        logging.debug('This switch does not need special trunk port handling')
                     else:
-                        print 'This switch needs special trunk port handling'
+                        logging.debug('This switch needs special trunk port handling')
                         trunk_ports = db.get_trunk_port_names_by_switch(switch.switch_id)
                         if trunk_ports is None:
-                            print "But it has no trunk ports defined"
+                            logging.debug("But it has no trunk ports defined")
                             trunk_ports = []
                         else:
-                            print 'Found %d trunk_ports that need adjusting' % len(trunk_ports)
+                            logging.debug('Found %d trunk_ports that need adjusting' % len(trunk_ports))
 
                     # Modify any trunk ports as needed
                     for port in trunk_ports:
-                        print 'Added VLAN tag %d, name %s to switch %s' % (tag, name, switch_name)
+                        logging.debug('Added VLAN tag %d, name %s to switch %s' % (tag, name, switch_name))
                         s.port_add_trunk_to_vlan(port, tag)
 
                     # And now we're done with this switch
@@ -275,7 +275,7 @@ class VlanUtil:
                 del s
 
             # Undo the database change
-            print 'Switch access failed. Deleting the new VLAN entry in the database'
+            logging.debug('Switch access failed. Deleting the new VLAN entry in the database')
             db.delete_vlan(vlan_id)
             raise
 
@@ -303,12 +303,12 @@ class VlanUtil:
     # If things fail, we attempt to roll back by rebooting switches.
     def delete_vlan(self, state, vlan_id):
 
-        print 'delete_vlan'
+        logging.debug('delete_vlan')
         db = state.db
         config = state.config
 
         # 1. Check for database records first
-        print 'Checking for ports using VLAN ID %d' % vlan_id
+        logging.debug('Checking for ports using VLAN ID %d' % vlan_id)
         vlan = db.get_vlan_by_id(vlan_id)
         if vlan is None:
             raise InputError("VLAN ID %d does not exist" % vlan_id)
@@ -343,25 +343,25 @@ class VlanUtil:
 
                     # 2a. Do we need to worry about trunk ports on this switch?
                     if 'TrunkWildCardVlans' in s.switch_get_capabilities():
-                        print 'This switch does not need special trunk port handling'
+                        logging.debug('This switch does not need special trunk port handling')
                     else:
-                        print 'This switch needs special trunk port handling'
+                        logging.debug('This switch needs special trunk port handling')
                         trunk_ports = db.get_trunk_port_names_by_switch(switch.switch_id)
                         if trunk_ports is None:
-                            print "But it has no trunk ports defined"
+                            logging.debug("But it has no trunk ports defined")
                             trunk_ports = []
                         else:
-                            print 'Found %d trunk_ports that need adjusting' % len(trunk_ports)
+                            logging.debug('Found %d trunk_ports that need adjusting' % len(trunk_ports))
 
                     # Modify any trunk ports as needed
                     for port in trunk_ports:
                         s.port_remove_trunk_from_vlan(port, vlan_tag)
-                        print 'Removed VLAN tag %d from switch %s port %s' % (vlan_tag, switch_name, port)
+                        logging.debug('Removed VLAN tag %d from switch %s port %s' % (vlan_tag, switch_name, port))
 
                     # 2b. Remove the VLAN from the switch
-                    print 'Removing VLAN tag %d from switch %s' % (vlan_tag, switch_name)
+                    logging.debug('Removing VLAN tag %d from switch %s' % (vlan_tag, switch_name))
                     s.vlan_destroy(vlan_tag)
-                    print 'Removed VLAN tag %d from switch %s' % (vlan_tag, switch_name)
+                    logging.debug('Removed VLAN tag %d from switch %s' % (vlan_tag, switch_name))
 
                     # And now we're done with this switch
                     s.switch_disconnect()
@@ -397,11 +397,11 @@ class VlanUtil:
 
         # 4. Finally, remove the VLAN in the DB
         try:
-            print 'Removing DB record: VLAN ID %d' % vlan_id
+            logging.debug('Removing DB record: VLAN ID %d' % vlan_id)
             vlan_id = db.delete_vlan(vlan_id)
-            print 'Removed VLAN ID %d from the database OK' % vlan_id
+            logging.debug('Removed VLAN ID %d from the database OK' % vlan_id)
         except InputError:
-            print 'DB deletion failed'
+            logging.debug('DB deletion failed')
             raise
 
         return vlan_id # If we're successful
@@ -421,7 +421,7 @@ class VlanUtil:
     # If things fail, we attempt to roll back by rebooting the switch
     def set_port_mode(self, state, port_id, mode):
 
-        print 'set_port_mode'
+        logging.debug('set_port_mode')
         db = state.db
         config = state.config
 
@@ -447,22 +447,22 @@ class VlanUtil:
                              config.switches[switch_name].password,
                              config.switches[switch_name].enable_password)
         except:
-            print 'Failed to talk to switch %s!' % switch_name
+            logging.debug('Failed to talk to switch %s!' % switch_name)
             raise
 
         try:
             if port.is_trunk:
                 # 2a. We're going from a trunk port to an access port
                 if 'TrunkWildCardVlans' in s.switch_get_capabilities():
-                    print 'This switch does not need special trunk port handling'
+                    logging.debug('This switch does not need special trunk port handling')
                 else:
-                    print 'This switch needs special trunk port handling'
+                    logging.debug('This switch needs special trunk port handling')
                     vlans = s.port_get_trunk_vlan_list(port.name)
                     if vlans is None:
-                        print "But it has no VLANs defined on port %s" % port.name
+                        logging.debug("But it has no VLANs defined on port %s" % port.name)
                         vlans = []
                     else:
-                        print 'Found %d vlans that may need dropping on port %s' % (len(vlans), port.name)
+                        logging.debug('Found %d vlans that may need dropping on port %s' % (len(vlans), port.name))
 
                     for vlan in vlans:
                         if vlan != state.config.vland.default_vlan_tag:
@@ -474,7 +474,7 @@ class VlanUtil:
                 s.port_set_access_vlan(port.name, base_vlan_tag)
                 s.port_set_mode(port.name, "trunk")
                 if 'TrunkWildCardVlans' in s.switch_get_capabilities():
-                    print 'This switch does not need special trunk port handling'
+                    logging.debug('This switch does not need special trunk port handling')
                 else:
                     vlans = db.all_vlans()
                     for vlan in vlans:
@@ -507,7 +507,7 @@ class VlanUtil:
     # If things fail, we attempt to roll back by rebooting the switch
     def set_current_vlan(self, state, port_id, vlan_id):
 
-        print 'set_current_vlan'
+        logging.debug('set_current_vlan')
         db = state.db
         config = state.config
 
@@ -534,7 +534,7 @@ class VlanUtil:
                              config.switches[switch_name].password,
                              config.switches[switch_name].enable_password)
         except:
-            print 'Failed to talk to switch %s!' % switch_name
+            logging.debug('Failed to talk to switch %s!' % switch_name)
             raise
 
         try:
@@ -566,7 +566,7 @@ class VlanUtil:
     # If things fail, we attempt to roll back by rebooting the switch
     def restore_base_vlan(self, state, port_id):
 
-        print 'restore_base_vlan'
+        logging.debug('restore_base_vlan')
         db = state.db
         config = state.config
 
@@ -596,7 +596,7 @@ class VlanUtil:
                              config.switches[switch_name].password,
                              config.switches[switch_name].enable_password)
         except:
-            print 'Failed to talk to switch %s!' % switch_name
+            logging.debug('Failed to talk to switch %s!' % switch_name)
             raise
 
         try:
@@ -628,7 +628,7 @@ class VlanUtil:
     #
     def auto_import_switch(self, state, switch_name):
 
-        print 'auto_import_switch'
+        logging.debug('auto_import_switch')
         db = state.db
         config = state.config
 
@@ -649,7 +649,7 @@ class VlanUtil:
                              config.switches[switch_name].password,
                              config.switches[switch_name].enable_password)
         except:
-            print 'Failed to talk to switch %s!' % switch_name
+            logging.debug('Failed to talk to switch %s!' % switch_name)
             raise
 
         # DON'T create the switch record in the DB first - we'll want
@@ -661,7 +661,7 @@ class VlanUtil:
         # Grab the VLANs defined on this switch
         vlan_tags = s.vlan_get_list()
 
-        print '  found %d vlans on the switch' % len(vlan_tags)
+        logging.debug('  found %d vlans on the switch' % len(vlan_tags))
 
         for vlan_tag in vlan_tags:
             vlan_name = s.vlan_get_name(vlan_tag)
@@ -704,9 +704,9 @@ class VlanUtil:
         # And now the ports
         trunk_ports = []
         ports = s.switch_get_port_names()
-        print '  found %d ports on the switch' % len(ports)
+        logging.debug('  found %d ports on the switch' % len(ports))
         for port_name in ports:
-            print '  trying to import port %s' % port_name
+            logging.debug('  trying to import port %s' % port_name)
             port_id = None
             port_mode = s.port_get_mode(port_name)
             if port_mode == 'access':
@@ -718,16 +718,16 @@ class VlanUtil:
                 port_vlan_id = db.get_vlan_id_by_tag(port_vlans[port_name][0])
                 port_id = db.create_port(switch_id, port_name,
                                          port_vlan_id, port_vlan_id)
-                print '    access port, VLAN %d' % int(port_vlans[port_name][0])
+                logging.debug('    access port, VLAN %d' % int(port_vlans[port_name][0]))
                 # Nothing further needed
             elif port_mode == 'trunk':
-                print '    trunk port, VLANs:'
+                logging.debug('    trunk port, VLANs:')
                 # Trunk ports are a little more involved. First,
                 # create the port in the DB, setting the VLANs to the
                 # first VLAN found on the trunk port. This will *also*
                 # be in access mode by default, and unlocked.
                 port_vlans[port_name] = s.port_get_trunk_vlan_list(port_name)
-                print port_vlans[port_name]
+                logging.debug(port_vlans[port_name])
                 if port_vlans[port_name] == [] or port_vlans[port_name] is None or 'ALL' in port_vlans[port_name]:
                     port_vlans[port_name] = (state.config.vland.default_vlan_tag,)
                 port_vlan_id = db.get_vlan_id_by_tag(port_vlans[port_name][0])
@@ -739,7 +739,7 @@ class VlanUtil:
             else:
                 raise CriticalError("Unrecognised port port mode %s???" % port_mode)
 
-            print "  Added port %s, got port ID %d" % (port_name, port_id)
+            logging.debug("  Added port %s, got port ID %d" % (port_name, port_id))
 
             db.set_port_mode(port_id, port_mode)
 
@@ -747,7 +747,7 @@ class VlanUtil:
         for vlan in db.all_vlans():
             if vlan.tag is not state.config.vland.default_vlan_tag:
                 if not vlan.tag in vlan_tags:
-                    print "Adding VLAN tag %d to this switch" % (vlan.tag)
+                    logging.debug("Adding VLAN tag %d to this switch" % (vlan.tag))
                     s.vlan_create(vlan.tag)
                     s.vlan_set_name(vlan.tag, vlan.name)
 
@@ -760,7 +760,7 @@ class VlanUtil:
                 for vlan in db.all_vlans():
                     if vlan.vlan_id is not state.default_vlan_id:
                         if not vlan.tag in port_vlans[port.name]:
-                            print "Adding allowed VLAN tag %d to trunk port %s" % (vlan.tag, port.name)
+                            logging.debug("Adding allowed VLAN tag %d to trunk port %s" % (vlan.tag, port.name))
                             s.port_add_trunk_to_vlan(port.name, vlan.tag)
 
         # Done with this switch \o/
diff --git a/vland.py b/vland.py
index e9e5ee8..49e7f36 100644
--- a/vland.py
+++ b/vland.py
@@ -92,13 +92,13 @@ while state.running:
         json_data = ipc.server_recv()
     except SocketError as e:
         print e
-        print 'Caught IPC error, ignoring'
+        logging.debug('Caught IPC error, ignoring')
         continue
     except:
         ipc.server_close()
         raise
 
-    print "client %s sent us:" % json_data['client_name']
+    logging.debug("client %s sent us:" % json_data['client_name'])
     print json_data
 
     response = {}
@@ -166,7 +166,7 @@ while state.running:
         response['response'] = 'ERROR'
         response['error'] = 'VLANd API not yet implemented...'
 
-    print "sending reply:"
+    logging.debug("sending reply:")
     print response
 
     ipc.server_reply(response)