diff --git a/melange/common/auth.py b/melange/common/auth.py index f79caa2f..bba885f7 100644 --- a/melange/common/auth.py +++ b/melange/common/auth.py @@ -17,28 +17,36 @@ import httplib2 import json +import logging import re import urlparse -from webob import exc +import webob.exc import wsgi +LOG = logging.getLogger("melange.common.auth") + + class AuthorizationMiddleware(wsgi.Middleware): def __init__(self, application, auth_providers, **local_config): self.auth_providers = auth_providers + LOG.debug("Auth middleware providers: %s" % auth_providers) super(AuthorizationMiddleware, self).__init__(application, **local_config) def process_request(self, request): roles = request.headers.get('X_ROLE', '').split(',') + LOG.debug("Processing auth request with roles: %s" % roles) tenant_id = request.headers.get('X_TENANT', None) + LOG.debug("Processing auth request with tenant_id: %s" % tenant_id) for provider in self.auth_providers: provider.authorize(request, tenant_id, roles) @classmethod def factory(cls, global_config, **local_config): def _factory(app): + LOG.debug("Created auth middleware with config: %s" % local_config) return cls(app, [TenantBasedAuth()], **local_config) return _factory @@ -50,10 +58,13 @@ class TenantBasedAuth(object): def authorize(self, request, tenant_id, roles): if 'admin' in [role.lower() for role in roles]: + LOG.debug("Authorized admin request: %s" % request) return True match_for_tenant = self.tenant_scoped_url.match(request.path_info) if (match_for_tenant and tenant_id == match_for_tenant.group('tenant_id')): + LOG.debug("Authorized tenant '%(tenant_id)s' request: " + "%(request)s" % locals()) return True - raise exc.HTTPForbidden(_("User with tenant id %s cannot access " - "this resource") % tenant_id) + raise webob.exc.HTTPForbidden(_("User with tenant id %s cannot " + "access this resource") % tenant_id) diff --git a/melange/common/messaging.py b/melange/common/messaging.py index 3ab06de6..831e5d4a 100644 --- a/melange/common/messaging.py +++ b/melange/common/messaging.py @@ -15,12 +15,17 @@ # License for the specific language governing permissions and limitations # under the License. +import logging + import kombu.connection from melange.common import config from melange.common import utils +LOG = logging.getLogger('melange.common.messaging') + + class Queue(object): def __init__(self, name): @@ -34,14 +39,18 @@ class Queue(object): self.close() def connect(self): - self.conn = kombu.connection.BrokerConnection( - **queue_connection_options("ipv4_queue")) + options = queue_connection_options("ipv4_queue") + LOG.info("Connecting to message queue.") + LOG.debug("Message queue connect options: %(options)s" % locals()) + self.conn = kombu.connection.BrokerConnection(**options) def put(self, msg): - queue = self.conn.SimpleQueue(self.name, no_ack=True) - queue.put(msg) + queue = self.conn.SimpleQueue(self.name, no_ack=True) + LOG.debug("Putting message '%(msg)s' on queue '%(queue)s'" % locals()) + queue.put(msg) def close(self): + LOG.info("Closing connection to message queue.") self.conn.close() diff --git a/melange/db/sqlalchemy/session.py b/melange/db/sqlalchemy/session.py index ef0e6be9..179abbd5 100644 --- a/melange/db/sqlalchemy/session.py +++ b/melange/db/sqlalchemy/session.py @@ -29,6 +29,9 @@ _ENGINE = None _MAKER = None +LOG = logging.getLogger('melange.db.sqlalchemy.session') + + def configure_db(options): configure_sqlalchemy_log(options) global _ENGINE @@ -48,9 +51,18 @@ def configure_sqlalchemy_log(options): def _create_engine(options): - timeout = config.get_option(options, 'sql_idle_timeout', type='int', - default=3600) - return create_engine(options['sql_connection'], pool_recycle=timeout) + engine_args = { + "pool_recycle": config.get_option(options, + 'sql_idle_timeout', + type='int', + default=3600), + "echo": config.get_option(options, + 'sql_query_log', + type='bool', + default=False), + } + LOG.info("Creating SQLAlchemy engine with args: %s" % engine_args) + return create_engine(options['sql_connection'], **engine_args) def get_session(autocommit=True, expire_on_commit=False): diff --git a/melange/ipam/models.py b/melange/ipam/models.py index 81e80551..4051c25f 100644 --- a/melange/ipam/models.py +++ b/melange/ipam/models.py @@ -75,6 +75,7 @@ class ModelBase(object): self._convert_columns_to_proper_type() self._before_save() self['updated_at'] = utils.utcnow() + LOG.debug("Saving %s: %s" % (self.__class__.__name__, self.__dict__)) return db.db_api.save(self) def delete(self): @@ -252,6 +253,7 @@ class IpBlock(ModelBase): @classmethod def delete_all_deallocated_ips(cls): + LOG.info("Deleting all deallocated IPs") for block in db.db_api.find_all_blocks_with_deallocated_ips(): block.delete_deallocated_ips() @@ -396,17 +398,21 @@ class IpBlock(ModelBase): return network in other_network or other_network in network def find_ip(self, **kwargs): + LOG.debug("Searching for IP block %r for IP matching " + "%s" % (self.id, kwargs)) return IpAddress.find_by(ip_block_id=self.id, **kwargs) def deallocate_ip(self, address): ip_address = IpAddress.find_by(ip_block_id=self.id, address=address) if ip_address != None: + LOG.debug("Deallocating IP: %s" % ip_address) ip_address.deallocate() def delete_deallocated_ips(self): self.update(is_full=False) for ip in db.db_api.find_deallocated_ips( deallocated_by=self._deallocated_by_date(), ip_block_id=self.id): + LOG.debug("Deleting deallocated IP: %s" % ip) ip.delete() def _deallocated_by_date(self): @@ -568,15 +574,18 @@ class IpAddress(ModelBase): @classmethod def find_all_by_network(cls, network_id, **conditions): + LOG.debug("Retrieving all IPs for network %s" % network_id) return db.db_query.find_all_ips_in_network(cls, network_id=network_id, **conditions) @classmethod def find_all_allocated_ips(cls, **conditions): + LOG.debug("Retrieving all allocated IPs.") return db.db_query.find_all_allocated_ips(cls, **conditions) def delete(self): + LOG.debug("Deleting IP address: %r" % self) if self._explicitly_allowed_on_interfaces(): return self.update(marked_for_deallocation=False, deallocated_at=None, @@ -606,11 +615,13 @@ class IpAddress(ModelBase): for local_address in ip_addresses]) def deallocate(self): + LOG.debug("Marking IP address for deallocation: %r" % self) self.update(marked_for_deallocation=True, deallocated_at=utils.utcnow(), interface_id=None) def restore(self): + LOG.debug("Restored IP address: %r" % self) self.update(marked_for_deallocation=False, deallocated_at=None) def inside_globals(self, **kwargs): diff --git a/melange/ipam/service.py b/melange/ipam/service.py index 92bacc37..31c587c6 100644 --- a/melange/ipam/service.py +++ b/melange/ipam/service.py @@ -15,6 +15,7 @@ # License for the specific language governing permissions and limitations # under the License. +import logging import routes import webob.exc @@ -26,6 +27,9 @@ from melange.ipam import models from melange.ipam import views +LOG = logging.getLogger('melange.ipam.service') + + class BaseController(wsgi.Controller): exclude_attr = [] @@ -93,19 +97,24 @@ class IpBlockController(BaseController, DeleteAction, ShowAction): return models.IpBlock.find_by(**kwargs) def index(self, request, tenant_id): + LOG.info("Listing all IP blocks for tenant '%s'" % tenant_id) type_dict = utils.filter_dict(request.params, 'type') all_blocks = models.IpBlock.find_all(tenant_id=tenant_id, **type_dict) return self._paginated_response('ip_blocks', all_blocks, request) def create(self, request, tenant_id, body=None): + LOG.info("Creating an IP block for tenant '%s'" % tenant_id) params = self._extract_required_params(body, 'ip_block') block = models.IpBlock.create(tenant_id=tenant_id, **params) + LOG.debug("New IP block parameters: %s" % params) return wsgi.Result(dict(ip_block=block.data()), 201) def update(self, request, id, tenant_id, body=None): + LOG.info("Updating IP block %(id)s for %(tenant_id)s" % locals()) ip_block = self._find_block(id=id, tenant_id=tenant_id) params = self._extract_required_params(body, 'ip_block') ip_block.update(**utils.exclude(params, 'cidr', 'type')) + LOG.debug("Updated IP block %(id)s parameters: %(params)s" % locals()) return wsgi.Result(dict(ip_block=ip_block.data()), 200) @@ -403,6 +412,7 @@ class InterfacesController(BaseController, ShowAction, DeleteAction): params = self._extract_required_params(body, 'interface') params['virtual_interface_id'] = params.pop('id', None) network_params = utils.stringify_keys(params.pop('network', None)) + LOG.debug("Creating interface with parameters: %s" % params) interface = models.Interface.create_and_configure(**params) if network_params: @@ -423,6 +433,7 @@ class InterfacesController(BaseController, ShowAction, DeleteAction): def delete(self, request, **kwargs): kwargs['vif_id_on_device'] = kwargs.pop('virtual_interface_id', None) + LOG.debug("Deleting interface (kwargs=%s)" % kwargs) self._model.find_by(**kwargs).delete() @@ -459,6 +470,7 @@ class InstanceInterfacesController(BaseController): return {'instance': {'interfaces': view_data}} def delete(self, request, device_id): + LOG.debug("Deleting instance interface (device_id=%s)" % device_id) models.Interface.delete_by(device_id=device_id) @@ -468,6 +480,7 @@ class MacAddressRangesController(BaseController, ShowAction, DeleteAction): def create(self, request, body=None): params = self._extract_required_params(body, 'mac_address_range') + LOG.info("Creating MAC address range: %s" % params) mac_range = models.MacAddressRange.create(**params) return wsgi.Result(dict(mac_address_range=mac_range.data()), 201)