From cb83b38f6586314d51e23dad227047d126bd4b76 Mon Sep 17 00:00:00 2001 From: Thierry Parmentelat Date: Thu, 7 Oct 2010 18:15:18 +0200 Subject: [PATCH] review logging again; code that runs in client and/or server now logs in the right place --- sfa/client/sfi.py | 22 +++---- sfa/plc/api-dev.py | 2 +- sfa/plc/api.py | 2 +- sfa/plc/sfa-import-plc.py | 3 +- sfa/plc/sfa-nuke-plc.py | 6 +- sfa/plc/sfaImport.py | 32 ++++----- sfa/server/aggregate.py | 5 +- sfa/server/modpython/SfaAggregateModPython.py | 2 +- sfa/server/modpython/SfaRegistryModPython.py | 2 +- sfa/server/modpython/SfaSliceMgrModPython.py | 2 +- sfa/server/modpythonapi/ModPython.py | 2 +- sfa/server/registry.py | 4 +- sfa/server/sfa-server.py | 15 ++--- sfa/server/slicemgr.py | 3 +- sfa/trust/certificate.py | 16 +++-- sfa/trust/credential.py | 4 +- sfa/trust/gid.py | 2 +- sfa/trust/hierarchy.py | 6 +- sfa/util/PostgreSQL.py | 18 ++--- sfa/util/api.py | 2 +- sfa/util/componentserver.py | 2 +- sfa/util/method.py | 4 +- sfa/util/rspec.py | 4 +- sfa/util/server.py | 9 ++- sfa/util/sfalogging.py | 65 ++++++++++++++++--- sfa/util/xmlrpcprotocol.py | 8 +-- 26 files changed, 144 insertions(+), 98 deletions(-) diff --git a/sfa/client/sfi.py b/sfa/client/sfi.py index f7eecb3d..ab2119bc 100755 --- a/sfa/client/sfi.py +++ b/sfa/client/sfi.py @@ -15,8 +15,8 @@ from StringIO import StringIO from types import StringTypes, ListType from optparse import OptionParser import zlib -import logging +from sfa.util.sfalogging import sfa_logger,sfa_logger_goes_to_console from sfa.trust.certificate import Keypair, Certificate from sfa.trust.credential import Credential from sfa.util.sfaticket import SfaTicket @@ -25,7 +25,6 @@ from sfa.util.namespace import get_leaf, get_authority, hrn_to_urn from sfa.util.xmlrpcprotocol import ServerException import sfa.util.xmlrpcprotocol as xmlrpcprotocol from sfa.util.config import Config -from sfa.util.sfalogging import console_logger AGGREGATE_PORT=12346 @@ -128,7 +127,8 @@ class Sfi: self.authority = None self.options = None self.hashrequest = False - self.logger=console_logger + sfa_logger_goes_to_console() + self.logger=sfa_logger() def create_cmd_parser(self, command, additional_cmdargs=None): cmdargs = {"list": "name", @@ -231,14 +231,12 @@ class Sfi: help="user name", metavar="HRN", default=None) parser.add_option("-a", "--auth", dest="auth", help="authority name", metavar="HRN", default=None) - parser.add_option("-v", "--verbose", - action="store_true", dest="verbose", default=False, - help="verbose mode") + parser.add_option("-v", "--verbose", action="count", dest="verbose", default=0, + help="verbose mode - cumulative") parser.add_option("-D", "--debug", action="store_true", dest="debug", default=False, help="Debug (xml-rpc) protocol messages") - parser.add_option("-p", "--protocol", - dest="protocol", default="xmlrpc", + parser.add_option("-p", "--protocol", dest="protocol", default="xmlrpc", help="RPC protocol (xmlrpc or soap)") parser.add_option("-k", "--hashrequest", action="store_true", dest="hashrequest", default=False, @@ -258,7 +256,7 @@ class Sfi: except: self.logger.critical("Failed to read configuration file %s"%config_file) self.logger.info("Make sure to remove the export clauses and to add quotes") - if not self.options.verbose: + if self.options.verbose==0: self.logger.info("Re-run with -v for more details") else: self.logger.log_exc("Could not read config file %s"%config_file) @@ -313,8 +311,6 @@ class Sfi: self.key_file = key_file self.cert_file = cert_file self.cert = Certificate(filename=cert_file) - # instruct xmlrpcprotocol to redirect logs to console_logger - self.options.client=True # Establish connection to server(s) self.logger.info("Contacting Registry at: %s"%reg_url) self.registry = xmlrpcprotocol.get_server(reg_url, key_file, cert_file, self.options) @@ -931,7 +927,7 @@ class Sfi: (options, args) = parser.parse_args() self.options = options - if self.options.verbose: self.logger.setLevel(logging.DEBUG) + self.logger.setLevelFromOptVerbose(self.options.verbose) if options.hashrequest: self.hashrequest = True @@ -963,4 +959,4 @@ class Sfi: return if __name__ == "__main__": - Sfi().main() + Sfi().main() diff --git a/sfa/plc/api-dev.py b/sfa/plc/api-dev.py index 4a6d7a20..52411592 100644 --- a/sfa/plc/api-dev.py +++ b/sfa/plc/api-dev.py @@ -324,7 +324,7 @@ class SfaAPI(BaseAPI): self.hrn = self.config.SFA_INTERFACE_HRN self.time_format = "%Y-%m-%d %H:%M:%S" - self.logger=sfa_logger + self.logger=sfa_logger() def getPLCShell(self): self.plauth = {'Username': self.config.SFA_PLC_USER, diff --git a/sfa/plc/api.py b/sfa/plc/api.py index 8707405a..5a882918 100644 --- a/sfa/plc/api.py +++ b/sfa/plc/api.py @@ -106,7 +106,7 @@ class SfaAPI(BaseAPI): self.hrn = self.config.SFA_INTERFACE_HRN self.time_format = "%Y-%m-%d %H:%M:%S" - self.logger=sfa_logger + self.logger=sfa_logger() def getPLCShell(self): self.plauth = {'Username': self.config.SFA_PLC_USER, diff --git a/sfa/plc/sfa-import-plc.py b/sfa/plc/sfa-import-plc.py index 18727c6a..2b409c39 100755 --- a/sfa/plc/sfa-import-plc.py +++ b/sfa/plc/sfa-import-plc.py @@ -17,7 +17,6 @@ import getopt import sys import tempfile -import logging from sfa.util.record import * from sfa.util.table import SfaTable @@ -64,7 +63,7 @@ def main(): interface_hrn = config.SFA_INTERFACE_HRN keys_filename = config.config_path + os.sep + 'person_keys.py' sfaImporter = sfaImport() - if config.SFA_API_DEBUG: sfaImporter.logger.setLevel(logging.DEBUG) + if config.SFA_API_DEBUG: sfaImporter.logger.setLevelDebug() shell = sfaImporter.shell plc_auth = sfaImporter.plc_auth table = SfaTable() diff --git a/sfa/plc/sfa-nuke-plc.py b/sfa/plc/sfa-nuke-plc.py index 4bbf003b..bdc38925 100755 --- a/sfa/plc/sfa-nuke-plc.py +++ b/sfa/plc/sfa-nuke-plc.py @@ -13,7 +13,7 @@ import sys from sfa.trust.hierarchy import * from sfa.util.record import * from sfa.util.table import SfaTable -from sfa.util.sfalogging import sfa_import_logger +from sfa.util.sfalogging import sfa_logger_goes_to_import,sfa_logger def process_options(): @@ -24,8 +24,8 @@ def process_options(): def main(): process_options() - - sfa_import_logger.info("Purging SFA records from database") + sfa_logger_goes_to_import() + sfa_logger().info("Purging SFA records from database") table = SfaTable() table.sfa_records_purge() diff --git a/sfa/plc/sfaImport.py b/sfa/plc/sfaImport.py index 82dc17c4..80c1551f 100644 --- a/sfa/plc/sfaImport.py +++ b/sfa/plc/sfaImport.py @@ -12,7 +12,8 @@ import getopt import sys import tempfile -from sfa.util.sfalogging import sfa_import_logger +from sfa.util.sfalogging import sfa_logger_goes_to_import,sfa_logger + from sfa.util.record import * from sfa.util.table import SfaTable from sfa.util.namespace import * @@ -50,21 +51,22 @@ def _cleanup_string(str): class sfaImport: def __init__(self): - self.logger = sfa_import_logger - self.AuthHierarchy = Hierarchy() - self.config = Config() - self.TrustedRoots = TrustedRootList(Config.get_trustedroots_dir(self.config)) - self.plc_auth = self.config.get_plc_auth() - self.root_auth = self.config.SFA_REGISTRY_ROOT_AUTH + sfa_logger_goes_to_import() + self.logger = sfa_logger() + self.AuthHierarchy = Hierarchy() + self.config = Config() + self.TrustedRoots = TrustedRootList(Config.get_trustedroots_dir(self.config)) + self.plc_auth = self.config.get_plc_auth() + self.root_auth = self.config.SFA_REGISTRY_ROOT_AUTH - # connect to planetlab - self.shell = None - if "Url" in self.plc_auth: - from sfa.plc.remoteshell import RemoteShell - self.shell = RemoteShell(self.logger) - else: - import PLC.Shell - self.shell = PLC.Shell.Shell(globals = globals()) + # connect to planetlab + self.shell = None + if "Url" in self.plc_auth: + from sfa.plc.remoteshell import RemoteShell + self.shell = RemoteShell(self.logger) + else: + import PLC.Shell + self.shell = PLC.Shell.Shell(globals = globals()) def create_top_level_auth_records(self, hrn): diff --git a/sfa/server/aggregate.py b/sfa/server/aggregate.py index 81d87051..3dee1849 100644 --- a/sfa/server/aggregate.py +++ b/sfa/server/aggregate.py @@ -2,8 +2,8 @@ ### $URL$ -from sfa.util.server import SfaServer from sfa.util.faults import * +from sfa.util.server import SfaServer from sfa.util.namespace import hrn_to_urn from sfa.server.interface import Interfaces import sfa.util.xmlrpcprotocol as xmlrpcprotocol @@ -20,8 +20,7 @@ class Aggregate(SfaServer): # @param key_file private key filename of registry # @param cert_file certificate filename containing public key (could be a GID file) def __init__(self, ip, port, key_file, cert_file): - SfaServer.__init__(self, ip, port, key_file, cert_file) - self.server.interface = 'aggregate' + SfaServer.__init__(self, ip, port, key_file, cert_file,'aggregate') ## # Aggregates is a dictionary of aggregate connections keyed on the aggregate hrn diff --git a/sfa/server/modpython/SfaAggregateModPython.py b/sfa/server/modpython/SfaAggregateModPython.py index 502fea63..bb61bb77 100755 --- a/sfa/server/modpython/SfaAggregateModPython.py +++ b/sfa/server/modpython/SfaAggregateModPython.py @@ -53,5 +53,5 @@ def handler(req): except Exception, err: # Log error in /var/log/httpd/(ssl_)?error_log - sfa_logger.log_exc('%r'%err) + sfa_logger().log_exc('%r'%err) return apache.HTTP_INTERNAL_SERVER_ERROR diff --git a/sfa/server/modpython/SfaRegistryModPython.py b/sfa/server/modpython/SfaRegistryModPython.py index 276005e8..0c460842 100755 --- a/sfa/server/modpython/SfaRegistryModPython.py +++ b/sfa/server/modpython/SfaRegistryModPython.py @@ -53,5 +53,5 @@ def handler(req): except Exception, err: # Log error in /var/log/httpd/(ssl_)?error_log - sfa_logger.log_exc('%r'%err) + sfa_logger().log_exc('%r'%err) return apache.HTTP_INTERNAL_SERVER_ERROR diff --git a/sfa/server/modpython/SfaSliceMgrModPython.py b/sfa/server/modpython/SfaSliceMgrModPython.py index 1560c801..a28b002d 100755 --- a/sfa/server/modpython/SfaSliceMgrModPython.py +++ b/sfa/server/modpython/SfaSliceMgrModPython.py @@ -53,5 +53,5 @@ def handler(req): except Exception, err: # Log error in /var/log/httpd/(ssl_)?error_log - sfa_logger.log_exc('%r'%err) + sfa_logger().log_exc('%r'%err) return apache.HTTP_INTERNAL_SERVER_ERROR diff --git a/sfa/server/modpythonapi/ModPython.py b/sfa/server/modpythonapi/ModPython.py index 4e5f80a7..b5b12816 100755 --- a/sfa/server/modpythonapi/ModPython.py +++ b/sfa/server/modpythonapi/ModPython.py @@ -52,5 +52,5 @@ def handler(req): except Exception, err: # Log error in /var/log/httpd/(ssl_)?error_log - sfa_logger.log_exc("%r"%e) + sfa_logger().log_exc("%r"%e) return apache.HTTP_INTERNAL_SERVER_ERROR diff --git a/sfa/server/registry.py b/sfa/server/registry.py index fb4f0434..1dea183b 100644 --- a/sfa/server/registry.py +++ b/sfa/server/registry.py @@ -25,9 +25,7 @@ class Registry(SfaServer): # @param cert_file certificate filename containing public key (could be a GID file) def __init__(self, ip, port, key_file, cert_file): - SfaServer.__init__(self, ip, port, key_file, cert_file) - self.server.interface = 'registry' - + SfaServer.__init__(self, ip, port, key_file, cert_file,'registry') ## # Registries is a dictionary of registry connections keyed on the registry diff --git a/sfa/server/sfa-server.py b/sfa/server/sfa-server.py index e3ad1a29..ad9b4999 100755 --- a/sfa/server/sfa-server.py +++ b/sfa/server/sfa-server.py @@ -35,7 +35,6 @@ component_port=12346 import os, os.path import sys from optparse import OptionParser -import logging from sfa.util.sfalogging import sfa_logger from sfa.trust.trustedroot import TrustedRootList @@ -82,8 +81,8 @@ def init_server_key(server_key_file, server_cert_file, config, hierarchy): if not os.path.exists(key_file): # if it doesnt exist then this is probably a fresh interface # with no records. Generate a random keypair for now - sfa_logger.debug("server's public key not found in %s" % key_file) - sfa_logger.debug("generating a random server key pair") + sfa_logger().debug("server's public key not found in %s" % key_file) + sfa_logger().debug("generating a random server key pair") key = Keypair(create=True) key.save_to_file(server_key_file) cert = Certificate(subject=subject) @@ -170,15 +169,15 @@ def main(): help="run aggregate manager", default=False) parser.add_option("-c", "--component", dest="cm", action="store_true", help="run component server", default=False) - parser.add_option("-v", "--verbose", dest="verbose", action="store_true", - help="verbose mode", default=False) + parser.add_option("-v", "--verbose", action="count", dest="verbose", default=0, + help="verbose mode - cumulative") parser.add_option("-d", "--daemon", dest="daemon", action="store_true", help="Run as daemon.", default=False) (options, args) = parser.parse_args() - if options.verbose: sfa_logger.setLevel(logging.DEBUG) + sfa_logger().setLevelFromOptVerbose(options.verbose) config = Config() - if config.SFA_API_DEBUG: sfa_logger.setLevel(logging.DEBUG) + if config.SFA_API_DEBUG: sfa_logger().setLevelDebug() hierarchy = Hierarchy() server_key_file = os.path.join(hierarchy.basedir, "server.key") server_cert_file = os.path.join(hierarchy.basedir, "server.cert") @@ -216,4 +215,4 @@ if __name__ == "__main__": try: main() except: - sfa_logger.log_exc_critical("SFA server is exiting") + sfa_logger().log_exc_critical("SFA server is exiting") diff --git a/sfa/server/slicemgr.py b/sfa/server/slicemgr.py index 11948878..8842eaef 100644 --- a/sfa/server/slicemgr.py +++ b/sfa/server/slicemgr.py @@ -19,5 +19,4 @@ class SliceMgr(SfaServer): # @param cert_file certificate filename containing public key (could be a GID file) def __init__(self, ip, port, key_file, cert_file, config = "/etc/sfa/sfa_config"): - SfaServer.__init__(self, ip, port, key_file, cert_file) - self.server.interface = 'slicemgr' + SfaServer.__init__(self, ip, port, key_file, cert_file,'slicemgr') diff --git a/sfa/trust/certificate.py b/sfa/trust/certificate.py index 64ac865f..466cec89 100644 --- a/sfa/trust/certificate.py +++ b/sfa/trust/certificate.py @@ -79,7 +79,7 @@ def convert_public_key(key): try: k.load_pubkey_from_file(ssl_fn) except: - sfa_logger.log_exc("convert_public_key caught exception") + sfa_logger().log_exc("convert_public_key caught exception") k = None # remove the temporary files @@ -496,6 +496,7 @@ class Certificate: # Sign the certificate using the issuer private key and issuer subject previous set with set_issuer(). def sign(self): + sfa_logger().debug('certificate.sign') assert self.cert != None assert self.issuerSubject != None assert self.issuerKey != None @@ -535,6 +536,7 @@ class Certificate: # @param cert certificate object def is_signed_by_cert(self, cert): + print 'is_signed_by_cert' k = cert.get_pubkey() result = self.verify(k) return result @@ -580,29 +582,33 @@ class Certificate: # verify expiration time if self.cert.has_expired(): + sfa_logger().debug("verify_chain: our certificate has expired") raise CertExpired(self.get_subject(), "client cert") # if this cert is signed by a trusted_cert, then we are set for trusted_cert in trusted_certs: if self.is_signed_by_cert(trusted_cert): - sfa_logger.debug("Cert %s signed by trusted cert %s", self.get_subject(), trusted_cert.get_subject()) + sfa_logger().debug("verify_chain: cert %s signed by trusted cert %s"%( + self.get_subject(), trusted_cert.get_subject())) # verify expiration of trusted_cert ? if not trusted_cert.cert.has_expired(): return trusted_cert else: - sfa_logger.debug("Trusted cert %s is expired", trusted_cert.get_subject()) + sfa_logger().debug("verify_chain: cert %s is signed by trusted_cert %s, but this is expired..."%( + self.get_subject(),trusted_cert.get_subject())) # if there is no parent, then no way to verify the chain if not self.parent: - sfa_logger.debug("%r has no parent"%self.get_subject()) + sfa_logger().debug("verify_chain: %r has no parent"%self.get_subject()) raise CertMissingParent(self.get_subject()) # if it wasn't signed by the parent... if not self.is_signed_by_cert(self.parent): - sfa_logger.debug("%r is not signed by parent"%self.get_subject()) + sfa_logger().debug("verify_chain: %r is not signed by parent"%self.get_subject()) return CertNotSignedByParent(self.get_subject()) # if the parent isn't verified... + sfa_logger().debug("verify_chain: with subject=%r, referring to parent, subj=%r",self.get_subject(),self.parent.get_subject()) self.parent.verify_chain(trusted_certs) return diff --git a/sfa/trust/credential.py b/sfa/trust/credential.py index 4971cdd0..63233d2b 100644 --- a/sfa/trust/credential.py +++ b/sfa/trust/credential.py @@ -660,7 +660,7 @@ class Credential(object): trusted_cert_objects.append(GID(filename=f)) ok_trusted_certs.append(f) except Exception, exc: - sfa_logger.error("Failed to load trusted cert from %s: %r", f, exc) + sfa_logger().error("Failed to load trusted cert from %s: %r", f, exc) trusted_certs = ok_trusted_certs # Use legacy verification if this is a legacy credential @@ -743,7 +743,7 @@ class Credential(object): # Maybe should be (hrn, type) = urn_to_hrn(root_cred_signer.get_urn()) root_cred_signer_type = root_cred_signer.get_type() if (root_cred_signer_type == 'authority'): - #sfa_logger.debug('Cred signer is an authority') + #sfa_logger().debug('Cred signer is an authority') # signer is an authority, see if target is in authority's domain hrn = root_cred_signer.get_hrn() if root_target_gid.get_hrn().startswith(hrn): diff --git a/sfa/trust/gid.py b/sfa/trust/gid.py index 6adfec5f..a880b52d 100644 --- a/sfa/trust/gid.py +++ b/sfa/trust/gid.py @@ -82,7 +82,7 @@ class GID(Certificate): Certificate.__init__(self, create, subject, string, filename) if subject: - sfa_logger.debug("Creating GID for subject: %s" % subject) + sfa_logger().debug("Creating GID for subject: %s" % subject) if uuid: self.uuid = int(uuid) if hrn: diff --git a/sfa/trust/hierarchy.py b/sfa/trust/hierarchy.py index 1f8afcf0..93970df6 100644 --- a/sfa/trust/hierarchy.py +++ b/sfa/trust/hierarchy.py @@ -161,7 +161,7 @@ class Hierarchy: def create_auth(self, xrn, create_parents=False): hrn, type = urn_to_hrn(xrn) - sfa_logger.debug("Hierarchy: creating authority: " + hrn) + sfa_logger().debug("Hierarchy: creating authority: " + hrn) # create the parent authority if necessary parent_hrn = get_authority(hrn) @@ -181,7 +181,7 @@ class Hierarchy: pass if os.path.exists(privkey_filename): - sfa_logger.debug("using existing key %r for authority %r"%(privkey_filename,hrn)) + sfa_logger().debug("using existing key %r for authority %r"%(privkey_filename,hrn)) pkey = Keypair(filename = privkey_filename) else: pkey = Keypair(create = True) @@ -206,7 +206,7 @@ class Hierarchy: def get_auth_info(self, xrn): hrn, type = urn_to_hrn(xrn) - sfa_logger.debug("Hierarchy: xrn=%s, getting authority for hrn=%s"%(xrn,hrn)) + sfa_logger().debug("Hierarchy: xrn=%s, getting authority for hrn=%s"%(xrn,hrn)) if not self.auth_exists(hrn): raise MissingAuthority(hrn) diff --git a/sfa/util/PostgreSQL.py b/sfa/util/PostgreSQL.py index 7ae94426..f2c51bfd 100644 --- a/sfa/util/PostgreSQL.py +++ b/sfa/util/PostgreSQL.py @@ -179,21 +179,21 @@ class PostgreSQL: if not params: if self.debug: - sfa_logger.debug('execute0 %r'%query) + sfa_logger().debug('execute0 %r'%query) cursor.execute(query) elif isinstance(params,dict): if self.debug: - sfa_logger.debug('execute-dict: params=[%r] query=[%r]'%(params,query%params)) + sfa_logger().debug('execute-dict: params=[%r] query=[%r]'%(params,query%params)) cursor.execute(query,params) elif isinstance(params,tuple) and len(params)==1: if self.debug: - sfa_logger.debug('execute-tuple %r'%(query%params[0])) + sfa_logger().debug('execute-tuple %r'%(query%params[0])) cursor.execute(query,params[0]) else: param_seq=(params,) if self.debug: for params in param_seq: - sfa_logger.debug('executemany %r'%(query%params)) + sfa_logger().debug('executemany %r'%(query%params)) cursor.executemany(query, param_seq) (self.rowcount, self.description, self.lastrowid) = \ (cursor.rowcount, cursor.description, cursor.lastrowid) @@ -203,11 +203,11 @@ class PostgreSQL: except: pass uuid = commands.getoutput("uuidgen") - sfa_logger.error("Database error %s:" % uuid) - sfa_logger.error("Exception=%r"%e) - sfa_logger.error("Query=%r"%query) - sfa_logger.error("Params=%r"%pformat(params)) - sfa_logger.log_exc("PostgreSQL.execute caught exception") + sfa_logger().error("Database error %s:" % uuid) + sfa_logger().error("Exception=%r"%e) + sfa_logger().error("Query=%r"%query) + sfa_logger().error("Params=%r"%pformat(params)) + sfa_logger().log_exc("PostgreSQL.execute caught exception") raise SfaDBError("Please contact support: %s" % str(e)) return cursor diff --git a/sfa/util/api.py b/sfa/util/api.py index 1e131be4..28c5a30e 100644 --- a/sfa/util/api.py +++ b/sfa/util/api.py @@ -242,7 +242,7 @@ class BaseAPI: except SfaFault, fault: result = fault except Exception, fault: - sfa_logger.log_exc("BaseAPI.handle has caught Exception") + sfa_logger().log_exc("BaseAPI.handle has caught Exception") result = SfaAPIError(fault) diff --git a/sfa/util/componentserver.py b/sfa/util/componentserver.py index 50c312e0..c12104b2 100644 --- a/sfa/util/componentserver.py +++ b/sfa/util/componentserver.py @@ -74,7 +74,7 @@ class SecureXMLRpcRequestHandler(SimpleXMLRPCServer.SimpleXMLRPCRequestHandler): # internal error, report as HTTP server error self.send_response(500) self.end_headers() - sfa_logger.log_exc("componentserver.SecureXMLRpcRequestHandler.do_POST") + sfa_logger().log_exc("componentserver.SecureXMLRpcRequestHandler.do_POST") else: # got a valid XML RPC response self.send_response(200) diff --git a/sfa/util/method.py b/sfa/util/method.py index ec9440e5..125629d0 100644 --- a/sfa/util/method.py +++ b/sfa/util/method.py @@ -92,7 +92,7 @@ class Method (object): if self.api.config.SFA_API_DEBUG or hasattr(self, 'message'): msg=getattr(self,'message',"method %s completed in %02f s"%(methodname,runtime)) - sfa_logger.info(msg) + sfa_logger().debug(msg) return result @@ -103,7 +103,7 @@ class Method (object): # Prepend caller and method name to expected faults fault.faultString = caller + ": " + self.name + ": " + fault.faultString runtime = time.time() - start - sfa_logger.log_exc("Method %s raised an exception"%self.name) + sfa_logger().log_exc("Method %s raised an exception"%self.name) raise fault diff --git a/sfa/util/rspec.py b/sfa/util/rspec.py index aab5592e..486332c3 100644 --- a/sfa/util/rspec.py +++ b/sfa/util/rspec.py @@ -235,11 +235,11 @@ class RSpec: except Exception, e: # logging.debug("%s: web file not found" % xsdURI) # logging.debug("Using local file %s" % self.xsd") - sfa_logger.log_exc("rspec.parseXSD: can't find %s on the web. Continuing." % xsdURI) + sfa_logger().log_exc("rspec.parseXSD: can't find %s on the web. Continuing." % xsdURI) if not schemaDom: if os.path.exists(xsdURI): # logging.debug("using local copy.") - sfa_logger.debug("rspec.parseXSD: Using local %s" % xsdURI) + sfa_logger().debug("rspec.parseXSD: Using local %s" % xsdURI) schemaDom = minidom.parse(xsdURI) else: raise Exception("rspec.parseXSD: can't find xsd locally") diff --git a/sfa/util/server.py b/sfa/util/server.py index 2d8e13b2..c5c9841c 100644 --- a/sfa/util/server.py +++ b/sfa/util/server.py @@ -25,6 +25,8 @@ from sfa.trust.credential import * from sfa.util.faults import * from sfa.plc.api import SfaAPI from sfa.util.cache import Cache +from sfa.util.sfalogging import sfa_logger + ## # Verification callback for pyOpenSSL. We do our own checking of keys because # we have our own authentication spec. Thus we disable several of the normal @@ -133,6 +135,7 @@ class SecureXMLRPCServer(BaseHTTPServer.HTTPServer,SimpleXMLRPCServer.SimpleXMLR It it very similar to SimpleXMLRPCServer but it uses HTTPS for transporting XML data. """ + sfa_logger().debug("SecureXMLRPCServer.__init__, server_address=%s, cert_file=%s"%(server_address,cert_file)) self.logRequests = logRequests self.interface = None self.key_file = key_file @@ -165,6 +168,7 @@ class SecureXMLRPCServer(BaseHTTPServer.HTTPServer,SimpleXMLRPCServer.SimpleXMLR # the client. def _dispatch(self, method, params): + sfa_logger().debug("SecureXMLRPCServer._dispatch, method=%s"%method) try: return SimpleXMLRPCServer.SimpleXMLRPCDispatcher._dispatch(self, method, params) except: @@ -245,15 +249,16 @@ class SfaServer(threading.Thread): # @param cert_file certificate filename containing public key # (could be a GID file) - def __init__(self, ip, port, key_file, cert_file): + def __init__(self, ip, port, key_file, cert_file,interface): threading.Thread.__init__(self) self.key = Keypair(filename = key_file) self.cert = Certificate(filename = cert_file) #self.server = SecureXMLRPCServer((ip, port), SecureXMLRpcRequestHandler, key_file, cert_file) self.server = ThreadedServer((ip, port), SecureXMLRpcRequestHandler, key_file, cert_file) + self.server.interface=interface self.trusted_cert_list = None self.register_functions() - + sfa_logger().info("Starting SfaServer, interface=%s"%interface) ## # Register functions that will be served by the XMLRPC server. This diff --git a/sfa/util/sfalogging.py b/sfa/util/sfalogging.py index 720e57d3..60b159db 100755 --- a/sfa/util/sfalogging.py +++ b/sfa/util/sfalogging.py @@ -1,9 +1,15 @@ #!/usr/bin/python -import os +import os, sys import traceback import logging, logging.handlers +CRITICAL=logging.CRITICAL +ERROR=logging.ERROR +WARNING=logging.WARNING +INFO=logging.INFO +DEBUG=logging.DEBUG + # a logger that can handle tracebacks class _SfaLogger: def __init__ (self,logfile=None,loggername=None,level=logging.INFO): @@ -11,7 +17,7 @@ class _SfaLogger: if not logfile: loggername='console' handler=logging.StreamHandler() - handler.setFormatter(logging.Formatter("%(message)s")) + handler.setFormatter(logging.Formatter("%(levelname)s %(message)s")) else: if not loggername: loggername=os.path.basename(logfile) @@ -27,10 +33,26 @@ class _SfaLogger: self.logger=logging.getLogger(loggername) self.logger.setLevel(level) self.logger.addHandler(handler) + self.loggername=loggername def setLevel(self,level): self.logger.setLevel(level) + # shorthand to avoid having to import logging all over the place + def setLevelDebug(self): + self.logger.setLevel(logging.DEBUG) + + # define a verbose option with s/t like + # parser.add_option("-v", "--verbose", action="count", dest="verbose", default=0) + # and pass the coresponding options.verbose to this method to adjust level + def setLevelFromOptVerbose(self,verbose): + if verbose==0: + self.logger.setLevel(logging.WARNING) + elif verbose==1: + self.logger.setLevel(logging.INFO) + elif verbose==2: + self.logger.setLevel(logging.DEBUG) + #################### def wrap(fun): def wrapped(self,msg,*args,**kwds): @@ -65,9 +87,30 @@ class _SfaLogger: self.debug("%s BEG STACK"%message+"\n"+to_log) self.debug("%s END STACK"%message) -sfa_logger=_SfaLogger(logfile='/var/log/sfa.log') -sfa_import_logger=_SfaLogger(logfile='/var/log/sfa_import.log') -console_logger=_SfaLogger() +#################### +# import-related operations go in this file +_import_logger=_SfaLogger(logfile='/var/log/sfa_import.log') +# servers log into /var/log/sfa.log +_server_logger=_SfaLogger(logfile='/var/log/sfa.log') +# clients use the console +_console_logger=_SfaLogger() + +# default is to use the server-side logger +_the_logger=_server_logger + +# clients would change the default by issuing one of these call +def sfa_logger_goes_to_console(): + current_module=sys.modules[globals()['__name__']] + current_module._the_logger=_console_logger + +# clients would change the default by issuing one of these call +def sfa_logger_goes_to_import(): + current_module=sys.modules[globals()['__name__']] + current_module._logger=_sfa_import_logger + +# this is how to retrieve the 'right' logger +def sfa_logger(): + return _the_logger ######################################## import time @@ -105,12 +148,16 @@ if __name__ == '__main__': logger.setLevel(logging.DEBUG) logger.debug("logger.debug again") - @profile(console_logger) + sfa_logger_goes_to_console() + my_logger=sfa_logger() + my_logger.info("redirected to console") + + @profile(my_logger) def sleep(seconds = 1): time.sleep(seconds) - - console_logger.info('console.info') + my_logger.info('console.info') sleep(0.5) - console_logger.setLevel(logging.DEBUG) + my_logger.setLevel(logging.DEBUG) sleep(0.25) + diff --git a/sfa/util/xmlrpcprotocol.py b/sfa/util/xmlrpcprotocol.py index d1fbe1e4..43c957af 100644 --- a/sfa/util/xmlrpcprotocol.py +++ b/sfa/util/xmlrpcprotocol.py @@ -2,7 +2,7 @@ import xmlrpclib -from sfa.util.sfalogging import sfa_logger, console_logger +from sfa.util.sfalogging import sfa_logger ## # ServerException, ExceptionUnmarshaller @@ -53,14 +53,10 @@ class XMLRPCServerProxy(xmlrpclib.ServerProxy): verbose = False if self.options and self.options.debug: verbose = True - if self.options and hasattr(self.options,'client'): - XMLRPCServerProxy.logger=console_logger - else: - XMLRPCServerProxy.logger=sfa_logger xmlrpclib.ServerProxy.__init__(self, url, transport, allow_none=allow_none, verbose=verbose) def __getattr__(self, attr): - XMLRPCServerProxy.logger.debug("Calling xml-rpc method:%s"%attr) + sfa_logger().debug("Calling xml-rpc method:%s"%attr) return xmlrpclib.ServerProxy.__getattr__(self, attr) -- 2.43.0