expects the 'interfaces' key in GetSlivers - review logs to always mention module

diff --git a/accounts.py b/accounts.py
index 039160d..f07cb19 100644 (file)
--- a/accounts.py
+++ b/accounts.py
@@ -72,7 +72,7 @@ def get(name):
 
 class Account:
     def __init__(self, rec):
-        logger.verbose('Initing account %s'%rec['name'])
+        logger.verbose('accounts: Initing account %s'%rec['name'])
         self.name = rec['name']
         self.keys = ''
         self.initscriptchanged = False
@@ -85,7 +85,7 @@ class Account:
 
     def configure(self, rec):
         """Write <rec['keys']> to my authorized_keys file."""
-        logger.verbose('%s: in accounts:configure'%self.name)
+        logger.verbose('accounts: configuring %s'%self.name)
         new_keys = rec['keys']
         if new_keys != self.keys:
             # get the unix account info
@@ -99,7 +99,7 @@ class Account:
             dot_ssh = os.path.join(pw_dir,'.ssh')
             if not os.path.isdir(dot_ssh):
                 if not os.path.isdir(pw_dir):
-                    logger.verbose('WARNING: homedir %s does not exist for %s!'%(pw_dir,self.name))
+                    logger.verbose('accounts: WARNING: homedir %s does not exist for %s!'%(pw_dir,self.name))
                     os.mkdir(pw_dir)
                     os.chown(pw_dir, uid, gid)
                 os.mkdir(dot_ssh)
@@ -116,7 +116,7 @@ class Account:
             # set self.keys to new_keys only when all of the above ops succeed
             self.keys = new_keys
 
-            logger.log('%s: installed ssh keys' % self.name)
+            logger.log('accounts: %s: installed ssh keys' % self.name)
 
     def start(self, delay=0): pass
     def stop(self): pass
@@ -158,7 +158,7 @@ class Worker:
             status = True
         else:
             status = False
-            logger.verbose("Worker(%s): is not running" % self.name)
+            logger.verbose("accounts: Worker(%s): is not running" % self.name)
         return status
 
     def _destroy(self, curr_class):

diff --git a/api.py b/api.py
index 221e606..ef279b8 100644 (file)
--- a/api.py
+++ b/api.py
@@ -24,11 +24,12 @@ import sys
 
 import accounts
 import database
-import logger
 import sliver_vs
 import ticket
 import tools
 from api_calls import *
+import logger
+
 try:
     sys.path.append("/etc/planetlab")
     from plc_config import *

diff --git a/api_calls.py b/api_calls.py
index 84e29ca..5b99a08 100644 (file)
--- a/api_calls.py
+++ b/api_calls.py
@@ -32,7 +32,7 @@ import accounts
 import logger
 
 # TODO: These try/excepts are a hack to allow doc/DocBookLocal.py to 
-# import this file in order to extrac the documentation from each 
+# import this file in order to extract the documentation from each 
 # exported function.  A better approach will involve more extensive code
 # splitting, I think.
 try: import database
@@ -119,7 +119,7 @@ def Ticket(ticket):
         name = data['slivers'][0]['name']
         if data != None:
             deliver_ticket(data)
-        logger.log('Ticket delivered for %s' % name)
+        logger.log('api_calls: Ticket delivered for %s' % name)
         Create(database.db.get(name))
     except Exception, err:
         raise xmlrpclib.Fault(102, 'Ticket error: ' + str(err))
@@ -136,7 +136,7 @@ def AdminTicket(ticket):
         name = data['slivers'][0]['name']
         if data != None:
             deliver_ticket(data)
-        logger.log('Admin Ticket delivered for %s' % name)
+        logger.log('api_calls: Admin Ticket delivered for %s' % name)
         Create(database.db.get(name))
     except Exception, err:
         raise xmlrpclib.Fault(102, 'Ticket error: ' + str(err))
@@ -170,8 +170,11 @@ def GetSSHKeys():
 def Create(sliver_name):
     """Create a non-PLC-instantiated sliver"""
     rec = sliver_name
-    if rec['instantiation'] == 'delegated': accounts.get(rec['name']).ensure_created(rec)
-    else: raise Exception, "Only PLC can create non delegated slivers."
+    if rec['instantiation'] == 'delegated': 
+        accounts.get(rec['name']).ensure_created(rec)
+        logger.log("api_calls: Create %s"%rec['name'])
+    else: 
+        raise Exception, "Only PLC can create non delegated slivers."
 
 
 @export_to_docbook(roles=['nm-controller', 'self'], 
@@ -181,8 +184,11 @@ def Create(sliver_name):
 def Destroy(sliver_name):
     """Destroy a non-PLC-instantiated sliver"""
     rec = sliver_name 
-    if rec['instantiation'] == 'delegated': accounts.get(rec['name']).ensure_destroyed()
-    else: raise Exception, "Only PLC can destroy non delegated slivers."
+    if rec['instantiation'] == 'delegated': 
+        accounts.get(rec['name']).ensure_destroyed()
+        logger.log("api_calls: Destroy %s"%rec['name'])
+    else: 
+        raise Exception, "Only PLC can destroy non delegated slivers."
 
 
 @export_to_docbook(roles=['nm-controller', 'self'], 
@@ -193,6 +199,7 @@ def Start(sliver_name):
     """Configure and start sliver."""
     rec = sliver_name
     accounts.get(rec['name']).start(rec)
+    logger.log("api_calls: Start %s"%rec['name'])
 
 
 @export_to_docbook(roles=['nm-controller', 'self'], 
@@ -203,6 +210,7 @@ def Stop(sliver_name):
     """Kill all processes belonging to the specified sliver"""
     rec = sliver_name
     accounts.get(rec['name']).stop()
+    logger.log("api_calls: Stop %s"%rec['name'])
 
 
 @export_to_docbook(roles=['nm-controller', 'self'], 
@@ -215,7 +223,7 @@ def ReCreate(sliver_name):
     accounts.get(rec['name']).stop()
     accounts.get(rec['name']).ensure_created(rec)
     accounts.get(rec['name']).start(rec)
-
+    logger.log("api_calls: ReCreate %s"%rec['name'])
 
 @export_to_docbook(roles=['nm-controller', 'self'], 
                     accepts=[Parameter(str, 'A sliver/slice name.')], 

diff --git a/bwmon.py b/bwmon.py
index 85e7d63..2b13d6f 100644 (file)
--- a/bwmon.py
+++ b/bwmon.py
@@ -17,19 +17,17 @@
 # Faiyaz Ahmed <faiyaza@cs.princeton.edu>
 # Copyright (C) 2004-2008 The Trustees of Princeton University
 #
-# $Id$
-#
 
 import os
 import sys
 import time
 import pickle
 import socket
-import logger
 import copy
 import threading
-import tools
 
+import logger
+import tools
 import bwlimit
 import database
 
@@ -582,7 +580,7 @@ def sync(nmdbcopy):
         if newslice != None and live[newslice].has_key('_rspec') == True:
             # Check to see if we recently deleted this slice.
             if live[newslice]['name'] not in deaddb.keys():
-                logger.log( "bwmon: New Slice %s" % live[newslice]['name'] )
+                logger.log( "bwmon: new slice %s" % live[newslice]['name'] )
                 # _rspec is the computed rspec:  NM retrieved data from PLC, computed loans
                 # and made a dict of computed values.
                 slices[newslice] = Slice(newslice, live[newslice]['name'], live[newslice]['_rspec'])
@@ -690,7 +688,7 @@ def allOff():
     default_xid = bwlimit.get_xid("default")
     kernelhtbs = gethtbs(root_xid, default_xid)
     if len(kernelhtbs):
-        logger.log("bwlimit:  Disabling all running HTBs.")
+        logger.log("bwmon:  Disabling all running HTBs.")
         for htb in kernelhtbs.keys(): bwlimit.off(htb) 
 
 
@@ -719,5 +717,5 @@ def start(*args):
     tools.as_daemon_thread(run)
 
 def GetSlivers(*args):
-    logger.verbose ("triggering dummy bwmon.GetSlivers") 
+    logger.verbose ("bwmon: triggering dummy GetSlivers") 
     pass

diff --git a/conf_files.py b/conf_files.py
index 9e2c257..f3d1eb9 100644 (file)
--- a/conf_files.py
+++ b/conf_files.py
@@ -56,9 +56,9 @@ class conf_files:
             else:                url += '?'
             url += "node_id=%d"%tools.node_id()
         else:
-            logger.log('%s -- WARNING, cannot add node_id to request'%dest)
+            logger.log('conf_files: %s -- WARNING, cannot add node_id to request'%dest)
         try:
-            logger.verbose("retrieving URL=%s"%url)
+            logger.verbose("conf_files: retrieving URL=%s"%url)
             contents = curlwrapper.retrieve(url, self.config.cacert)
         except xmlrpclib.ProtocolError,e:
             logger.log('conf_files: failed to retrieve %s from %s, skipping' % (dest, url))
@@ -78,7 +78,7 @@ class conf_files:
         if data.has_key("conf_files"):
             for f in data['conf_files']:
                 try: self.update_conf_file(f)
-                except: logger.log_exc("failed to update conf_file")
+                except: logger.log_exc("conf_files: failed to update conf_file")
         else: 
             logger.log_missing_data("conf_files.run_once",'conf_files')
 

diff --git a/controller.py b/controller.py
index b754e6a..2f2bc0c 100644 (file)
--- a/controller.py
+++ b/controller.py
@@ -23,7 +23,7 @@ class Controller(accounts.Account):
     def destroy(name): logger.log_call('/usr/sbin/userdel', '-r', name)
 
     def is_running(self):
-        logger.verbose("Delegate:  %s" % self.name)
+        logger.verbose("controller: is_running:  %s" % self.name)
         return getpwnam(self.name)[6] == self.SHELL
     
 

diff --git a/curlwrapper.py b/curlwrapper.py
index 8ab597f..81c9c14 100644 (file)
--- a/curlwrapper.py
+++ b/curlwrapper.py
@@ -33,7 +33,7 @@ def retrieve(url, cacert=None, postdata=None, timeout=90):
     rc = p.wait()
     if rc != 0: 
         # when this triggers, the error sometimes doesn't get printed
-        logger.log ("in curlwrapper.retrieve, got stderr <%s>"%err)
+        logger.log ("curlwrapper: retrieve, got stderr <%s>"%err)
         raise xmlrpclib.ProtocolError(url, rc, err, postdata)
     else: 
         return data

diff --git a/database.py b/database.py
index 171739e..ab40824 100644 (file)
--- a/database.py
+++ b/database.py
@@ -100,34 +100,34 @@ class Database(dict):
         self._compute_effective_rspecs()
 
         # create and destroy accounts as needed
-        logger.verbose("database:sync : fetching accounts")
+        logger.verbose("database: sync : fetching accounts")
         existing_acct_names = accounts.all()
         for name in existing_acct_names:
             if name not in self: 
-                logger.verbose("database:sync : ensure_destroy'ing %s"%name)
+                logger.verbose("database: sync : ensure_destroy'ing %s"%name)
                 accounts.get(name).ensure_destroyed()
         for name, rec in self.iteritems():
             # protect this; if anything fails for a given sliver 
             # we still need the other ones to be handled
             try:
                 sliver = accounts.get(name)
-                logger.verbose("database:sync : looping on %s (shell account class from pwd %s)" %(name,sliver._get_class()))
+                logger.verbose("database: sync : looping on %s (shell account class from pwd %s)" %(name,sliver._get_class()))
                 # Make sure we refresh accounts that are running
                 if rec['instantiation'] == 'plc-instantiated': 
-                    logger.verbose ("database.sync : ensure_create'ing 'instantiation' sliver %s"%name)
+                    logger.verbose ("database: sync : ensure_create'ing 'instantiation' sliver %s"%name)
                     sliver.ensure_created(rec)
                 elif rec['instantiation'] == 'nm-controller': 
-                    logger.verbose ("database.sync : ensure_create'ing 'nm-controller' sliver %s"%name)
+                    logger.verbose ("database: sync : ensure_create'ing 'nm-controller' sliver %s"%name)
                     sliver.ensure_created(rec)
                 # Back door to ensure PLC overrides Ticket in delegation.
                 elif rec['instantiation'] == 'delegated' and sliver._get_class() != None:
                     # if the ticket has been delivered and the nm-contoroller started the slice
                     # update rspecs and keep them up to date.
                     if sliver.is_running(): 
-                        logger.verbose ("database.sync : ensure_create'ing 'delegated' sliver %s"%name)
+                        logger.verbose ("database: sync : ensure_create'ing 'delegated' sliver %s"%name)
                         sliver.ensure_created(rec)
             except:
-                logger.log_exc("database.sync failed to handle sliver",name=name)
+                logger.log_exc("database: sync failed to handle sliver",name=name)
 
         # Wake up bwmom to update limits.
         bwmon.lock.set()
@@ -147,13 +147,16 @@ def start():
             dump_requested = False
             db_lock.release()
             try: tools.write_file(DB_FILE, lambda f: f.write(db_pickle))
-            except: logger.log_exc("failed in database.start.run")
+            except: logger.log_exc("database: failed in database.start.run")
     global db
     try:
         f = open(DB_FILE)
         try: db = cPickle.load(f)
         finally: f.close()
+    except IOError:
+        logger.log ("database: Could not load %s -- starting from a fresh database"%DB_FILE)
+        db = Database()
     except:
-        logger.log_exc("failed in database.start")
+        logger.log_exc("database: failed in start")
         db = Database()
     tools.as_daemon_thread(run)

diff --git a/iptables.py b/iptables.py
index 4380d78..3bcd252 100644 (file)
--- a/iptables.py
+++ b/iptables.py
@@ -7,7 +7,6 @@
 # $Id$
 
 import os
-import logger
 import subprocess
 
 class IPTables:

diff --git a/net.py b/net.py
index f451f69..45dee4b 100644 (file)
--- a/net.py
+++ b/net.py
@@ -15,16 +15,19 @@ import bwlimit, logger, iptables, tools
 dev_default = tools.get_default_if()
 
 def start(options, conf):
-    logger.log("net plugin starting up...")
+    logger.log("net: plugin starting up...")
 
 def GetSlivers(data, config, plc):
-    logger.verbose("net:GetSlivers called.")
-    InitInterfaces(plc, data) # writes sysconfig files.
+    logger.verbose("net: GetSlivers called.")
+    if not 'interfaces' in data: 
+        logger.log_missing_data('net.GetSlivers','interfaces')
+        return
+    plnet.InitInterfaces(logger, plc, data)
     if 'OVERRIDES' in dir(config): 
         if config.OVERRIDES.get('net_max_rate') == '-1':
             logger.log("net: Slice and node BW Limits disabled.")
             if len(bwlimit.tc("class show dev %s" % dev_default)): 
-                logger.verbose("*** DISABLING NODE BW LIMITS ***")
+                logger.verbose("net: *** DISABLING NODE BW LIMITS ***")
                 bwlimit.stop()
         else:
             InitNodeLimit(data)
@@ -36,7 +39,6 @@ def GetSlivers(data, config, plc):
 
 
 def InitNodeLimit(data):
-    if not 'networks' in data: return
 
     # query running network interfaces
     devs = sioc.gifconf()
@@ -45,17 +47,17 @@ def InitNodeLimit(data):
     for dev in devs:
         macs[sioc.gifhwaddr(dev).lower()] = dev
 
-    for network in data['networks']:
+    for interface in data['interfaces']:
         # Get interface name preferably from MAC address, falling
         # back on IP address.
-        hwaddr=network['mac']
+        hwaddr=interface['mac']
         if hwaddr <> None: hwaddr=hwaddr.lower()
         if hwaddr in macs:
-            dev = macs[network['mac']]
-        elif network['ip'] in ips:
-            dev = ips[network['ip']]
+            dev = macs[interface['mac']]
+        elif interface['ip'] in ips:
+            dev = ips[interface['ip']]
         else:
-            logger.log('%s: no such interface with address %s/%s' % (network['hostname'], network['ip'], network['mac']))
+            logger.log('net: %s: no such interface with address %s/%s' % (interface['hostname'], interface['ip'], interface['mac']))
             continue
 
         # Get current node cap
@@ -65,10 +67,10 @@ def InitNodeLimit(data):
             old_bwlimit = None
 
         # Get desired node cap
-        if network['bwlimit'] is None or network['bwlimit'] < 0:
+        if interface['bwlimit'] is None or interface['bwlimit'] < 0:
             new_bwlimit = bwlimit.bwmax
         else:
-            new_bwlimit = network['bwlimit']
+            new_bwlimit = interface['bwlimit']
 
         if old_bwlimit != new_bwlimit:
             # Reinitialize bandwidth limits
@@ -82,7 +84,7 @@ def InitI2(plc, data):
     if not 'groups' in data: return
 
     if "Internet2" in data['groups']:
-        logger.log("This is an Internet2 node.  Setting rules.")
+        logger.log("net: This is an Internet2 node.  Setting rules.")
         i2nodes = []
         i2nodeids = plc.GetNodeGroups(["Internet2"])[0]['node_ids']
         for node in plc.GetInterfaces({"node_id": i2nodeids}, ["ip"]):
@@ -104,7 +106,6 @@ def InitI2(plc, data):
             os.popen("/sbin/iptables -t mangle " + cmd)
 
 def InitNAT(plc, data):
-    if not 'networks' in data: return
     
     # query running network interfaces
     devs = sioc.gifconf()
@@ -114,21 +115,21 @@ def InitNAT(plc, data):
         macs[sioc.gifhwaddr(dev).lower()] = dev
 
     ipt = iptables.IPTables()
-    for network in data['networks']:
+    for interface in data['interfaces']:
         # Get interface name preferably from MAC address, falling
         # back on IP address.
-        hwaddr=network['mac']
+        hwaddr=interface['mac']
         if hwaddr <> None: hwaddr=hwaddr.lower()
         if hwaddr in macs:
-            dev = macs[network['mac']]
-        elif network['ip'] in ips:
-            dev = ips[network['ip']]
+            dev = macs[interface['mac']]
+        elif interface['ip'] in ips:
+            dev = ips[interface['ip']]
         else:
-            logger.log('%s: no such interface with address %s/%s' % (network['hostname'], network['ip'], network['mac']))
+            logger.log('net: %s: no such interface with address %s/%s' % (interface['hostname'], interface['ip'], interface['mac']))
             continue
 
         try:
-            settings = plc.GetInterfaceTags({'interface_tag_id': network['interface_tag_ids']})
+            settings = plc.GetInterfaceTags({'interface_tag_id': interface['interface_tag_ids']})
         except:
             continue
 
@@ -153,9 +154,5 @@ def InitNAT(plc, data):
                     ipt.add_pf(fields)
     ipt.commit()
 
-def InitInterfaces(plc, data):
-    if not 'networks' in data: return
-    plnet.InitInterfaces(logger, plc, data)
-
 def start(options, config):
     pass

diff --git a/nm.py b/nm.py
index 4a561da..abc05bb 100755 (executable)
--- a/nm.py
+++ b/nm.py
@@ -64,7 +64,7 @@ modules = []
 def GetSlivers(config, plc):
     '''Run call backs defined in modules'''
     try: 
-        logger.log("Syncing w/ PLC")
+        logger.log("nm: Syncing w/ PLC")
         # retrieve GetSlivers from PLC
         data = plc.GetSlivers()
         # use the magic 'default' slice to retrieve system-wide defaults
@@ -75,9 +75,9 @@ def GetSlivers(config, plc):
         # used to be done only in verbose; very helpful though, and tedious to obtain,
         # so let's dump this unconditionnally
         logger.log_slivers(data)
-        logger.verbose("Sync w/ PLC done (3)")
+        logger.verbose("nm: Sync w/ PLC done")
     except: 
-        logger.log_exc("failed in nm.GetSlivers")
+        logger.log_exc("nm: failed in GetSlivers")
         #  XXX So some modules can at least boostrap.
         logger.log("nm:  Can't contact PLC to GetSlivers().  Continuing.")
         data = {}
@@ -86,7 +86,7 @@ def GetSlivers(config, plc):
         try:        
             callback = getattr(module, 'GetSlivers')
             callback(data, config, plc)
-        except: logger.log_exc("nm.GetSlivers failed to run callback for module %r"%module)
+        except: logger.log_exc("nm: GetSlivers failed to run callback for module %r"%module)
 
 
 def getPLCDefaults(data, config):
@@ -98,7 +98,7 @@ def getPLCDefaults(data, config):
             attr_dict = {}
             for attr in slice.get('attributes'): attr_dict[attr['tagname']] = attr['value'] 
             if len(attr_dict):
-                logger.verbose("Found default slice overrides.\n %s" % attr_dict)
+                logger.verbose("nm: Found default slice overrides.\n %s" % attr_dict)
                 config.OVERRIDES = attr_dict
                 return
     # NOTE: if an _default slice existed, it would have been found above and
@@ -122,7 +122,7 @@ def setSliversVref (data):
                     continue
             sliver['attributes'].append({ 'tagname':'vref','value':slicefamily})
         except:
-            logger.log_exc("Could not overwrite 'vref' attribute from 'GetSliceFamily'",name=sliver['name'])
+            logger.log_exc("nm: Could not overwrite 'vref' attribute from 'GetSliceFamily'",name=sliver['name'])
     
 
 def run():
@@ -148,7 +148,7 @@ def run():
         if options.module:
             assert options.module in known_modules
             running_modules=[options.module]
-            logger.verbose('Running single module %s'%options.module)
+            logger.verbose('nm: Running single module %s'%options.module)
         else:
             running_modules=known_modules
         for module in running_modules:
@@ -171,25 +171,25 @@ def run():
         plc = PLCAPI(config.plc_api_uri, config.cacert, session, timeout=iperiod/2)
 
         #check auth
-        logger.log("Checking Auth.")
+        logger.log("nm: Checking Auth.")
         while plc.check_authentication() != True:
             try:
                 plc.update_session()
-                logger.log("Authentication Failure. Retrying")
+                logger.log("nm: Authentication Failure. Retrying")
             except:
-                logger.log("Retry Failed. Waiting")
+                logger.log("nm: Retry Failed. Waiting")
             time.sleep(iperiod)
-        logger.log("Authentication Succeeded!")
+        logger.log("nm: Authentication Succeeded!")
 
 
         while True:
         # Main NM Loop
-            logger.verbose('mainloop - nm:getSlivers - period=%d random=%d'%(iperiod,irandom))
+            logger.verbose('nm: mainloop - calling GetSlivers - period=%d random=%d'%(iperiod,irandom))
             GetSlivers(config, plc)
             delay=iperiod + random.randrange(0,irandom)
-            logger.verbose('mainloop - sleeping for %d s'%delay)
+            logger.verbose('nm: mainloop - sleeping for %d s'%delay)
             time.sleep(delay)
-    except: logger.log_exc("failed in nm.run")
+    except: logger.log_exc("nm: failed in run")
 
 
 if __name__ == '__main__':

diff --git a/plcapi.py b/plcapi.py
index 4e6daaa..a2d31cb 100644 (file)
--- a/plcapi.py
+++ b/plcapi.py
@@ -56,7 +56,7 @@ class PLCAPI:
             try: 
                 authstatus = self.AuthCheck()
             except: 
-                logger.log_exc("failed in plcapi.check_authentication")
+                logger.log_exc("plcapi: failed in plcapi.check_authentication")
         return authstatus
 
 

diff --git a/plugins/codemux.py b/plugins/codemux.py
index 731b74d..471f269 100644 (file)
--- a/plugins/codemux.py
+++ b/plugins/codemux.py
@@ -12,7 +12,7 @@ from config import Config
 CODEMUXCONF="/etc/codemux/codemux.conf"
 
 def start(options, conf):
-    logger.log("codemux plugin starting up...")
+    logger.log("codemux: plugin starting up...")
 
 def GetSlivers(data, config, plc = None):
     """

diff --git a/plugins/rawdisk.py b/plugins/rawdisk.py
index 641bc69..e7b1006 100644 (file)
--- a/plugins/rawdisk.py
+++ b/plugins/rawdisk.py
@@ -22,7 +22,7 @@ import logger
 import tools
 
 def start(options, config):
-    logger.log("rawdisk plugin starting up...")
+    logger.log("rawdisk: plugin starting up...")
 
 def get_unused_devices():
     devices = []
@@ -66,7 +66,7 @@ def GetSlivers(data, config=None, plc=None):
                         # should check whether its the proper type of device
                         continue
                     
-                    logger.log("Copying %s to %s" % (i, path))
+                    logger.log("rawdisk: Copying %s to %s" % (i, path))
                     try:
                         if os.path.exists(path):
                             os.unlink(path)

diff --git a/plugins/sliverauth.py b/plugins/sliverauth.py
index 634d648..ce17b0c 100644 (file)
--- a/plugins/sliverauth.py
+++ b/plugins/sliverauth.py
@@ -22,7 +22,7 @@ import logger
 import tools
 
 def start(options, conf):
-    logger.log("sliverauth plugin starting up...")
+    logger.log("sliverauth: plugin starting up...")
 
 def SetSliverTag(plc, slice, tagname, value):
     node_id = tools.node_id()
@@ -33,7 +33,7 @@ def SetSliverTag(plc, slice, tagname, value):
         try:
             slivertag_id=plc.AddSliceTag(slice,tagname,value,node_id)
         except:
-            logger.log ("SetSliverTag - CAUGHT exception for (probably delegated) slice=%(slice)s tag=%(tagname)s node_id=%(node_id)d"%locals())
+            logger.log ("sliverauth: SetSliverTag - CAUGHT exception for (probably delegated) slice=%(slice)s tag=%(tagname)s node_id=%(node_id)d"%locals())
             pass
     else:
         slivertag_id=slivertags[0]['slice_tag_id']
@@ -72,7 +72,7 @@ def GetSlivers(data, config, plc):
             d = [random.choice(string.letters) for x in xrange(32)]
             hmac = "".join(d)
             SetSliverTag(plc,sliver['name'],'hmac',hmac)
-            logger.log("sliverauth setting %s hmac" % sliver['name'])
+            logger.log("sliverauth: setting %s hmac" % sliver['name'])
 
         path = '/vservers/%s/etc/planetlab' % sliver['name']
         if os.path.exists(path):
@@ -91,7 +91,7 @@ def GetSlivers(data, config, plc):
                 if os.path.exists(keyfile):
                     os.unlink(keyfile)
                 os.rename(name,keyfile)
-                logger.log("sliverauth writing hmac to %s " % keyfile)
+                logger.log("sliverauth: writing hmac to %s " % keyfile)
 
             os.chmod(keyfile,0400)
 

diff --git a/plugins/specialaccounts.py b/plugins/specialaccounts.py
index cef877e..1fa15e1 100644 (file)
--- a/plugins/specialaccounts.py
+++ b/plugins/specialaccounts.py
@@ -23,7 +23,7 @@ import logger
 import tools
 
 def start(options, conf):
-    logger.log("personkeys plugin starting up...")
+    logger.log("personkeys: plugin starting up...")
 
 def GetSlivers(data, conf = None, plc = None):
     if 'accounts' not in data: 
@@ -45,7 +45,7 @@ def GetSlivers(data, conf = None, plc = None):
         if not os.access(dot_ssh, os.F_OK): os.mkdir(dot_ssh)
         auth_keys = os.path.join(dot_ssh,'authorized_keys')
 
-        logger.log("new keys = %s" % auth_keys)
+        logger.log("specialaccounts: new keys = %s" % auth_keys)
         fd, fname = tempfile.mkstemp('','authorized_keys',dot_ssh)
 
         for key in new_keys:

diff --git a/plugins/vsys.py b/plugins/vsys.py
index ef2ab34..ee806e7 100644 (file)
--- a/plugins/vsys.py
+++ b/plugins/vsys.py
@@ -11,7 +11,7 @@ VSYSCONF="/etc/vsys.conf"
 VSYSBKEND="/vsys"
 
 def start(options, conf):
-    logger.log("vsys plugin starting up...")
+    logger.log("vsys: plugin starting up...")
 
 def GetSlivers(data, config=None, plc=None):
     """For each sliver with the vsys attribute, set the script ACL, create the vsys directory in the slice, and restart vsys."""
@@ -145,5 +145,5 @@ def parseConf():
             (path, slice) = line.split()
             slicesinconf.append(slice)
         f.close()
-    except: logger.log_exc("failed vsys.parseConf")
+    except: logger.log_exc("vsys: failed parseConf")
     return slicesinconf

diff --git a/plugins/vsys_privs.py b/plugins/vsys_privs.py
index 62b84a0..1a3e4b2 100755 (executable)
--- a/plugins/vsys_privs.py
+++ b/plugins/vsys_privs.py
@@ -14,10 +14,10 @@ from sets import Set
 VSYS_PRIV_DIR = "/etc/planetlab/vsys-attributes"
 
 def start(options, conf):
-    logger.log("vsys_privs plugin v0.1")
+    logger.log("vsys_privs: plugin starting")
     if (not os.path.exists(VSYS_PRIV_DIR)):
         os.makedirs(VSYS_PRIV_DIR)
-        logger.log("Created vsys attributes dir")
+        logger.log("vsys_privs: Created vsys attributes dir")
 
 def GetSlivers(data, config=None, plc=None):
 
@@ -97,7 +97,7 @@ def write_privs(cur_privs,privs):
                 data = '\n'.join(v)
                 f.write(data)
                 f.close()
-                logger.log("Added vsys attribute %s for %s"%(k,slice))
+                logger.log("vsys_privs: added vsys attribute %s for %s"%(k,slice))
 
     # Remove files and directories 
     # that are invalid

diff --git a/sliver_vs.py b/sliver_vs.py
index f86dad9..5d487f6 100644 (file)
--- a/sliver_vs.py
+++ b/sliver_vs.py
@@ -54,18 +54,18 @@ class Sliver_VS(accounts.Account, vserver.VServer):
 
     def __init__(self, rec):
         name=rec['name']
-        logger.verbose ('%s: initing Sliver_VS'%name)
+        logger.verbose ('sliver_vs: %s init'%name)
         try:
-            logger.log("%s: first chance..."%name)
+            logger.log("sliver_vs: %s: first chance..."%name)
             vserver.VServer.__init__(self, name,logfile='/var/log/nm')
         except Exception, err:
             if not isinstance(err, vserver.NoSuchVServer):
                 # Probably a bad vserver or vserver configuration file
-                logger.log_exc("sliver_vs.__init__ (1) %s",name=name)
-                logger.log('%s: recreating bad vserver' % name)
+                logger.log_exc("sliver_vs:__init__ (first chance) %s",name=name)
+                logger.log('sliver_vs: %s: recreating bad vserver' % name)
                 self.destroy(name)
             self.create(name, rec['vref'])
-            logger.log("%s: second chance..."%name)
+            logger.log("sliver_vs: %s: second chance..."%name)
             vserver.VServer.__init__(self, name,logfile='/var/log/nm')
 
         self.keys = ''
@@ -79,9 +79,9 @@ class Sliver_VS(accounts.Account, vserver.VServer):
 
     @staticmethod
     def create(name, vref = None):
-        logger.verbose('Sliver_VS:create - name=%s'%name)
+        logger.verbose('sliver_vs: %s: create'%name)
         if vref is None:
-            logger.log("%s: ERROR - no vref attached, this is unexpected"%name)
+            logger.log("sliver_vs: %s: ERROR - no vref attached, this is unexpected"%(name))
             return
         # used to look in /etc/planetlab/family, 
         # now relies on the 'GetSliceFamily' extra attribute in GetSlivers()
@@ -89,7 +89,7 @@ class Sliver_VS(accounts.Account, vserver.VServer):
         
         # check the template exists -- there's probably a better way..
         if not os.path.isdir ("/vservers/.vref/%s"%vref):
-            logger.log ("%s: ERROR Could not create sliver - vreference image %s not found"%(name,vref))
+            logger.log ("sliver_vs: %s: ERROR Could not create sliver - vreference image %s not found"%(name,vref))
             return
 
         # guess arch
@@ -113,7 +113,7 @@ class Sliver_VS(accounts.Account, vserver.VServer):
         # set personality: only if needed (if arch's differ)
         if tools.root_context_arch() != arch:
             file('/etc/vservers/%s/personality' % name, 'w').write(personality(arch))
-            logger.log('%s: set personality to %s'%(name,personality(arch)))
+            logger.log('sliver_vs: %s: set personality to %s'%(name,personality(arch)))
 
     @staticmethod
     def destroy(name): logger.log_call('/usr/sbin/vuserdel', name)
@@ -133,14 +133,14 @@ class Sliver_VS(accounts.Account, vserver.VServer):
 
     def start(self, delay=0):
         if self.rspec['enabled'] > 0:
-            logger.log('%s: starting in %d seconds' % (self.name, delay))
+            logger.log('sliver_vs: %s: starting in %d seconds' % (self.name, delay))
             time.sleep(delay)
             # VServer.start calls fork() internally, 
             # so just close the nonstandard fds and fork once to avoid creating zombies
             child_pid = os.fork()
             if child_pid == 0:
                 if self.initscriptchanged:
-                    logger.log('%s: installing initscript' % self.name)
+                    logger.log('sliver_vs: %s: installing initscript' % self.name)
                     def install_initscript():
                         flags = os.O_WRONLY | os.O_CREAT | os.O_TRUNC
                         fd = os.open('/etc/rc.vinit', flags, 0755)
@@ -148,17 +148,17 @@ class Sliver_VS(accounts.Account, vserver.VServer):
                         os.close(fd)
                     try:
                         self.chroot_call(install_initscript)
-                    except: logger.log_exc("sliver_vs.start",name=self.name)
+                    except: logger.log_exc("sliver_vs: start",name=self.name)
                 tools.close_nonstandard_fds()
                 vserver.VServer.start(self)
                 os._exit(0)
             else: 
                 os.waitpid(child_pid, 0)
                 self.initscriptchanged = False
-        else: logger.log('not starting, is not enabled', name=self.name)
+        else: logger.log('sliver_vs: not starting, is not enabled', name=self.name)
 
     def stop(self):
-        logger.log('%s: stopping' % self.name)
+        logger.log('sliver_vs: %s: stopping' % self.name)
         vserver.VServer.stop(self)
 
     def is_running(self): 
@@ -166,19 +166,19 @@ class Sliver_VS(accounts.Account, vserver.VServer):
 
     def set_resources(self,setup=False):
         disk_max = self.rspec['disk_max']
-        logger.log('%s: setting max disk usage to %d KiB' % (self.name, disk_max))
+        logger.log('sliver_vs: %s: setting max disk usage to %d KiB' % (self.name, disk_max))
         try:  # if the sliver is over quota, .set_disk_limit will throw an exception
             if not self.disk_usage_initialized:
                 self.vm_running = False
                 Sliver_VS._init_disk_info_sem.acquire()
-                logger.log('%s: computing disk usage: beginning' % self.name)
+                logger.log('sliver_vs: %s: computing disk usage: beginning' % self.name)
                 try: self.init_disk_info()
                 finally: Sliver_VS._init_disk_info_sem.release()
-                logger.log('%s: computing disk usage: ended' % self.name)
+                logger.log('sliver_vs: %s: computing disk usage: ended' % self.name)
                 self.disk_usage_initialized = True
             vserver.VServer.set_disklimit(self, max(disk_max, self.disk_blocks))
         except:
-            logger.log_exc('failed to set max disk usage',name=self.name)
+            logger.log_exc('sliver_vs: failed to set max disk usage',name=self.name)
 
         # get/set the min/soft/hard values for all of the vserver
         # related RLIMITS.  Note that vserver currently only
@@ -190,12 +190,12 @@ class Sliver_VS(accounts.Account, vserver.VServer):
             hard = self.rspec['%s_hard'%type]
             update = self.set_rlimit(limit, hard, soft, minimum)
             if update:
-                logger.log('%s: setting rlimit %s to (%d, %d, %d)'
+                logger.log('sliver_vs: %s: setting rlimit %s to (%d, %d, %d)'
                            % (self.name, type, hard, soft, minimum))
 
         self.set_capabilities_config(self.rspec['capabilities'])
         if self.rspec['capabilities']:
-            logger.log('%s: setting capabilities to %s' % (self.name, self.rspec['capabilities']))
+            logger.log('sliver_vs: %s: setting capabilities to %s' % (self.name, self.rspec['capabilities']))
 
         cpu_pct = self.rspec['cpu_pct']
         cpu_share = self.rspec['cpu_share']
@@ -206,42 +206,42 @@ class Sliver_VS(accounts.Account, vserver.VServer):
                     sysctl=key.split('.')
                     try:
                         path="/proc/sys/%s" % ("/".join(sysctl[1:]))
-                        logger.log("%s: opening %s"%(self.name,path))
+                        logger.log("sliver_vs: %s: opening %s"%(self.name,path))
                         flags = os.O_WRONLY
                         fd = os.open(path, flags)
-                        logger.log("%s: writing %s=%s"%(self.name,key,self.rspec[key]))
+                        logger.log("sliver_vs: %s: writing %s=%s"%(self.name,key,self.rspec[key]))
                         os.write(fd,self.rspec[key])
                         os.close(fd)
                     except IOError, e:
-                        logger.log("%s: could not set %s=%s"%(self.name,key,self.rspec[key]))
-                        logger.log("%s: error = %s"%(self.name,e))
+                        logger.log("sliver_vs: %s: could not set %s=%s"%(self.name,key,self.rspec[key]))
+                        logger.log("sliver_vs: %s: error = %s"%(self.name,e))
 
 
         if self.rspec['enabled'] > 0:
             if cpu_pct > 0:
-                logger.log('%s: setting cpu reservation to %d%%' % (self.name, cpu_pct))
+                logger.log('sliver_vs: %s: setting cpu reservation to %d%%' % (self.name, cpu_pct))
             else:
                 cpu_pct = 0
 
             if cpu_share > 0:
-                logger.log('%s: setting cpu share to %d' % (self.name, cpu_share))
+                logger.log('sliver_vs: %s: setting cpu share to %d' % (self.name, cpu_share))
             else:
                 cpu_share = 0
 
             self.set_sched_config(cpu_pct, cpu_share)
             # if IP address isn't set (even to 0.0.0.0), sliver won't be able to use network
             if self.rspec['ip_addresses'] != '0.0.0.0':
-                logger.log('%s: setting IP address(es) to %s' % \
+                logger.log('sliver_vs: %s: setting IP address(es) to %s' % \
                 (self.name, self.rspec['ip_addresses']))
             self.set_ipaddresses_config(self.rspec['ip_addresses'])
 
             if self.is_running():
-                logger.log("%s: Setting name to %s" % (self.name, self.slice_id)) 
+                logger.log("sliver_vs: %s: Setting name to %s" % (self.name, self.slice_id)) 
                 self.setname(self.slice_id) 
                 ### Sapan's change needs more work 
                 # raise IOException, file does not get created
                 # might be that /etc/vservers is not available here, are we in the chroot ?
-                #logger.log("%s: Storing slice id of %s for PlanetFlow" % (self.name, self.slice_id))
+                #logger.log("sliver_vs: %s: Storing slice id of %s for PlanetFlow" % (self.name, self.slice_id))
                 #file('/etc/vservers/%s/slice_id' % self.name, 'w').write(self.slice_id)
 
             if self.enabled == False:
@@ -250,7 +250,7 @@ class Sliver_VS(accounts.Account, vserver.VServer):
  
             if False: # Does not work properly yet.
                 if self.have_limits_changed():
-                    logger.log('%s: limits have changed --- restarting' % self.name)
+                    logger.log('sliver_vs: %s: limits have changed --- restarting' % self.name)
                     stopcount = 10
                     while self.is_running() and stopcount > 0:
                         self.stop()
@@ -260,7 +260,7 @@ class Sliver_VS(accounts.Account, vserver.VServer):
                     self.start()
 
         else:  # tell vsh to disable remote login by setting CPULIMIT to 0
-            logger.log('%s: disabling remote login' % self.name)
+            logger.log('sliver_vs: %s: disabling remote login' % self.name)
             self.set_sched_config(0, 0)
             self.enabled = False
             self.stop()

diff --git a/sm.py b/sm.py
index 8c04760..6192ba1 100644 (file)
--- a/sm.py
+++ b/sm.py
@@ -63,16 +63,16 @@ def GetSlivers(data, config = None, plc=None, fullupdate=True):
     in, use the GetSlivers() heartbeat as a cue to scan for expired
     slivers."""
 
-    logger.verbose("Entering sm:GetSlivers with fullupdate=%r"%fullupdate)
+    logger.verbose("sm: Entering GetSlivers with fullupdate=%r"%fullupdate)
     for key in data.keys():
-        logger.verbose('GetSlivers key : ' + key)
+        logger.verbose('sm: GetSlivers key : ' + key)
 
     node_id = None
     try:
         f = open('/etc/planetlab/node_id')
         try: node_id = int(f.read())
         finally: f.close()
-    except: logger.log_exc("sm.GetSlivers failed to read /etc/planetlab/node_id")
+    except: logger.log_exc("sm: GetSlivers failed to read /etc/planetlab/node_id")
 
     if data.has_key('node_id') and data['node_id'] != node_id: return
 
@@ -87,11 +87,11 @@ def GetSlivers(data, config = None, plc=None, fullupdate=True):
         return
     initscripts = {}
     for is_rec in data['initscripts']:
-        logger.verbose("initscript: %s" % is_rec['name'])
+        logger.verbose("sm: initscript: %s" % is_rec['name'])
         initscripts[str(is_rec['name'])] = is_rec['script']
 
     for sliver in data['slivers']:
-        logger.verbose("%s: sm:GetSlivers in slivers loop"%sliver['name'])
+        logger.verbose("sm: %s: sm:GetSlivers in slivers loop"%sliver['name'])
         rec = sliver.copy()
         rec.setdefault('timestamp', data['timestamp'])
 

diff --git a/tools.py b/tools.py
index 0acf035..267ec31 100644 (file)
--- a/tools.py
+++ b/tools.py
@@ -81,7 +81,7 @@ def fork_as(su, function, *args):
         except:
             os.seteuid(os.getuid())  # undo su so we can write the log file
             os.setegid(os.getgid())
-            logger.log_exc("tools.fork_as")
+            logger.log_exc("tools: fork_as")
         os._exit(0)
     else: os.waitpid(child_pid, 0)
 
@@ -138,7 +138,7 @@ def root_context_arch():
 
 class NMLock:
     def __init__(self, file):
-        logger.log("Lock %s initialized." % file, 2)
+        logger.log("tools: Lock %s initialized." % file, 2)
         self.fd = os.open(file, os.O_RDWR|os.O_CREAT, 0600)
         flags = fcntl.fcntl(self.fd, fcntl.F_GETFD)
         flags |= fcntl.FD_CLOEXEC
@@ -146,8 +146,8 @@ class NMLock:
     def __del__(self):
         os.close(self.fd)
     def acquire(self):
-        logger.log("Lock acquired.", 2)
+        logger.log("tools: Lock acquired.", 2)
         fcntl.lockf(self.fd, fcntl.LOCK_SH)
     def release(self):
-        logger.log("Lock released.", 2)
+        logger.log("tools: Lock released.", 2)
         fcntl.lockf(self.fd, fcntl.LOCK_UN)