provisionning: log received provisionning messages and actions (#56907)
This commit is contained in:
parent
96ce1fb02f
commit
add04ecadb
|
@ -15,6 +15,7 @@
|
|||
# along with this program. If not, see <http://www.gnu.org/licenses/>.
|
||||
|
||||
import json
|
||||
import logging
|
||||
import os
|
||||
import sys
|
||||
|
||||
|
@ -24,6 +25,8 @@ from tenant_schemas.utils import tenant_context
|
|||
from hobo.multitenant.middleware import TenantMiddleware
|
||||
from hobo.provisionning.utils import NotificationProcessing, TryAgain
|
||||
|
||||
logger = logging.getLogger(__name__)
|
||||
|
||||
|
||||
class Command(BaseCommand, NotificationProcessing):
|
||||
requires_system_checks = False
|
||||
|
@ -60,6 +63,8 @@ class Command(BaseCommand, NotificationProcessing):
|
|||
if entity_id not in audience:
|
||||
return
|
||||
object_type = notification['objects']['@type']
|
||||
msg = 'received request for %sing %%d %%s objects (Celery)' % action
|
||||
logger.info(msg, len(notification['objects']['data']), object_type)
|
||||
for i in range(20):
|
||||
try:
|
||||
getattr(cls, 'provision_' + object_type)(
|
||||
|
|
|
@ -13,9 +13,13 @@ def provision_user_groups(user, uuids):
|
|||
logger = logging.getLogger(__name__)
|
||||
|
||||
existing_pks = user.groups.values_list('pk', flat=True)
|
||||
not_found = set(uuids)
|
||||
for role in Role.objects.filter(uuid__in=uuids).exclude(pk__in=existing_pks):
|
||||
not_found.discard(role.uuid)
|
||||
if role.pk in existing_pks:
|
||||
continue
|
||||
user.groups.through.objects.get_or_create(group=role, user=user)
|
||||
logger.info(u'adding role %s to %s (%s)', role, user, user.pk)
|
||||
logger.info('adding role %s to %s (%s)', role, user, user.pk)
|
||||
qs = user.groups.through.objects.filter(user=user, group__role__isnull=False).exclude(
|
||||
group__role__uuid__in=uuids
|
||||
)
|
||||
|
@ -26,4 +30,6 @@ def provision_user_groups(user, uuids):
|
|||
except DatabaseError:
|
||||
pass
|
||||
else:
|
||||
logger.info(u'removed role %s from %s (%s)', rel.group, user, user.pk)
|
||||
logger.info('removed role %s from %s (%s)', rel.group, user, user.pk)
|
||||
for uuid in not_found:
|
||||
logger.warning('role %s of user %s does not exist', uuid, user)
|
||||
|
|
|
@ -15,6 +15,7 @@
|
|||
# along with this program. If not, see <http://www.gnu.org/licenses/>.
|
||||
|
||||
import json
|
||||
import logging
|
||||
import sys
|
||||
|
||||
from django.conf import settings
|
||||
|
@ -27,6 +28,8 @@ from django.utils.six.moves.urllib.parse import urlparse
|
|||
from hobo.provisionning.utils import NotificationProcessing
|
||||
from hobo.rest_authentication import PublikAuthentication, PublikAuthenticationFailed
|
||||
|
||||
logger = logging.getLogger(__name__)
|
||||
|
||||
|
||||
class ProvisionningMiddleware(MiddlewareMixin, NotificationProcessing):
|
||||
def process_request(self, request):
|
||||
|
@ -54,6 +57,8 @@ class ProvisionningMiddleware(MiddlewareMixin, NotificationProcessing):
|
|||
full = notification['full'] if 'full' in notification else False
|
||||
data = notification['objects']['data']
|
||||
|
||||
msg = 'received request for %sing %%d %%s objects (HTTP)' % action
|
||||
logger.info(msg, len(notification['objects']['data']), object_type)
|
||||
if 'uwsgi' in sys.modules and 'sync' not in request.GET:
|
||||
from hobo.provisionning.spooler import provision
|
||||
|
||||
|
@ -75,7 +80,6 @@ class ProvisionningMiddleware(MiddlewareMixin, NotificationProcessing):
|
|||
)
|
||||
else:
|
||||
self.provision(object_type=object_type, issuer=issuer, action=action, data=data, full=full)
|
||||
|
||||
return JsonResponse({'err': 0})
|
||||
|
||||
def hobo_specific_setup(self):
|
||||
|
|
|
@ -16,7 +16,6 @@
|
|||
|
||||
import hashlib
|
||||
import logging
|
||||
import random
|
||||
|
||||
from django.contrib.auth.models import Group
|
||||
from django.db import IntegrityError
|
||||
|
@ -26,11 +25,31 @@ from django.db.transaction import atomic
|
|||
from hobo.agent.common.models import Role
|
||||
from hobo.multitenant.utils import provision_user_groups
|
||||
|
||||
logger = logging.getLogger(__name__)
|
||||
|
||||
|
||||
class TryAgain(Exception):
|
||||
pass
|
||||
|
||||
|
||||
def user_str(user):
|
||||
'''Compute a string representation of user'''
|
||||
s = ''
|
||||
if user.first_name or user.last_name:
|
||||
s += '"'
|
||||
if user.first_name:
|
||||
s += user.first_name
|
||||
if user.first_name and user.last_name:
|
||||
s += ' '
|
||||
if user.last_name:
|
||||
s += user.last_name
|
||||
s += '" '
|
||||
if user.email:
|
||||
s += user.email + ' '
|
||||
s += user.username
|
||||
return s
|
||||
|
||||
|
||||
class NotificationProcessing:
|
||||
@classmethod
|
||||
def check_valid_notification(cls, notification):
|
||||
|
@ -72,6 +91,17 @@ class NotificationProcessing:
|
|||
try:
|
||||
with atomic():
|
||||
if action == 'provision':
|
||||
new = False
|
||||
updated = set()
|
||||
attributes = {
|
||||
'first_name': o['first_name'][:30],
|
||||
'last_name': o['last_name'][:150],
|
||||
'email': o['email'][:254],
|
||||
'username': o['uuid'][:150],
|
||||
'is_superuser': o['is_superuser'],
|
||||
'is_staff': o['is_superuser'],
|
||||
'is_active': o.get('is_active', True),
|
||||
}
|
||||
assert cls.check_valid_user(o)
|
||||
try:
|
||||
mellon_user = UserSAMLIdentifier.objects.get(
|
||||
|
@ -85,20 +115,22 @@ class NotificationProcessing:
|
|||
)
|
||||
except User.DoesNotExist:
|
||||
# temp user object
|
||||
random_uid = str(random.randint(1, 10000000000000))
|
||||
user = User.objects.create(username=random_uid)
|
||||
user = User.objects.create(**attributes)
|
||||
new = True
|
||||
saml_issuer, created = Issuer.objects.get_or_create(entity_id=issuer)
|
||||
mellon_user = UserSAMLIdentifier.objects.create(
|
||||
user=user, issuer=saml_issuer, name_id=o['uuid']
|
||||
)
|
||||
user.first_name = o['first_name'][:30]
|
||||
user.last_name = o['last_name'][:150]
|
||||
user.email = o['email'][:254]
|
||||
user.username = o['uuid'][:150]
|
||||
user.is_superuser = o['is_superuser']
|
||||
user.is_staff = o['is_superuser']
|
||||
user.is_active = o.get('is_active', True)
|
||||
user.save()
|
||||
if new:
|
||||
logger.info('provisionned new user %s', user_str(user))
|
||||
else:
|
||||
for key in attributes:
|
||||
if getattr(user, key) != attributes[key]:
|
||||
setattr(user, key, attributes[key])
|
||||
updated.add(key)
|
||||
if updated:
|
||||
user.save()
|
||||
logger.info('updated user %s(%s)', user_str(user), updated)
|
||||
role_uuids = [role['uuid'] for role in o.get('roles', [])]
|
||||
provision_user_groups(user, role_uuids)
|
||||
elif action == 'deprovision':
|
||||
|
@ -106,12 +138,16 @@ class NotificationProcessing:
|
|||
uuids.add(o['uuid'])
|
||||
except IntegrityError:
|
||||
raise TryAgain
|
||||
if full and action == 'provision':
|
||||
for usi in UserSAMLIdentifier.objects.exclude(name_id__in=uuids):
|
||||
usi.user.delete()
|
||||
elif action == 'deprovision':
|
||||
for user in User.objects.filter(saml_identifiers__name_id__in=uuids):
|
||||
user.delete()
|
||||
if (full and action == 'provision') or (action == 'deprovision'):
|
||||
if action == 'deprovision':
|
||||
qs = User.objects.filter(saml_identifiers__name_id__in=uuids)
|
||||
else:
|
||||
qs = User.objects.exclude(saml_identifiers__name_id__in=uuids)
|
||||
# retrieve users before deleting them
|
||||
qs = qs[:]
|
||||
qs.delete()
|
||||
for user in qs:
|
||||
logger.info('deprovisionning user %s', user_str(user))
|
||||
|
||||
group_name_max_length = Group._meta.get_field('name').max_length
|
||||
|
||||
|
@ -128,7 +164,6 @@ class NotificationProcessing:
|
|||
|
||||
@classmethod
|
||||
def provision_role(cls, issuer, action, data, full=False):
|
||||
logger = logging.getLogger(__name__)
|
||||
uuids = set()
|
||||
roles_by_uuid = dict()
|
||||
|
||||
|
@ -145,6 +180,8 @@ class NotificationProcessing:
|
|||
assert 'uuid' in o
|
||||
uuids.add(o['uuid'])
|
||||
if action == 'provision':
|
||||
created = False
|
||||
save = False
|
||||
assert cls.check_valid_role(o)
|
||||
role_name = cls.truncate_role_name(o['name'])
|
||||
try:
|
||||
|
@ -158,17 +195,16 @@ class NotificationProcessing:
|
|||
defaults={
|
||||
'uuid': o['uuid'],
|
||||
'description': o['description'],
|
||||
'details': o.get('details', u''),
|
||||
'details': o.get('details', ''),
|
||||
'emails': o.get('emails', []),
|
||||
'emails_to_members': o.get('emails_to_members', True),
|
||||
},
|
||||
)
|
||||
except IntegrityError:
|
||||
# Can happen if uuid and name already exist
|
||||
logger.error(u'cannot provision role "%s" (%s)', o['name'], o['uuid'])
|
||||
logger.error('cannot provision role "%s" (%s)', o['name'], o['uuid'])
|
||||
continue
|
||||
if not created:
|
||||
save = False
|
||||
if role.name != role_name:
|
||||
role.name = role_name
|
||||
save = True
|
||||
|
@ -178,8 +214,8 @@ class NotificationProcessing:
|
|||
if role.description != o['description']:
|
||||
role.description = o['description']
|
||||
save = True
|
||||
if role.details != o.get('details', u''):
|
||||
role.details = o.get('details', u'')
|
||||
if role.details != o.get('details', ''):
|
||||
role.details = o.get('details', '')
|
||||
save = True
|
||||
if role.emails != o.get('emails', []):
|
||||
role.emails = o.get('emails', [])
|
||||
|
@ -193,12 +229,28 @@ class NotificationProcessing:
|
|||
role.save()
|
||||
except IntegrityError:
|
||||
# Can happen if uuid and name already exist
|
||||
logger.error(u'cannot provision role "%s" (%s)', o['name'], o['uuid'])
|
||||
logger.error('cannot provision role "%s" (%s)', o['name'], o['uuid'])
|
||||
continue
|
||||
if created:
|
||||
logger.info('provisionned new role %s (%s)', o['name'], o['uuid'])
|
||||
if save:
|
||||
logger.info('updated role %s (%s)', o['name'], o['uuid'])
|
||||
if full and action == 'provision':
|
||||
Role.objects.exclude(uuid__in=uuids).delete()
|
||||
qs = Role.objects.exclude(uuid__in=uuids)
|
||||
logger.info(
|
||||
'deprovisionning roles %s',
|
||||
', '.join('%s (%s)' % (name, uuid) for name, uuid in qs.values_list('name', 'uuid')),
|
||||
)
|
||||
qs.delete()
|
||||
for role in qs:
|
||||
role.delete()
|
||||
elif action == 'deprovision':
|
||||
Role.objects.filter(uuid__in=uuids).delete()
|
||||
qs = Role.objects.filter(uuid__in=uuids)
|
||||
logger.info(
|
||||
'deprovisionning roles %s',
|
||||
', '.join('%s (%s)' % (name, uuid) for name, uuid in qs.values_list('name', 'uuid')),
|
||||
)
|
||||
qs.delete()
|
||||
|
||||
@classmethod
|
||||
def provision(cls, object_type, issuer, action, data, full):
|
||||
|
|
|
@ -2,9 +2,9 @@
|
|||
|
||||
import logging
|
||||
|
||||
import pytest
|
||||
from django.db import connection
|
||||
from django.test.utils import CaptureQueriesContext
|
||||
import pytest
|
||||
|
||||
pytestmark = pytest.mark.django_db
|
||||
|
||||
|
@ -268,7 +268,7 @@ def test_hobo_notify_roles_db_queries(caplog, tenants):
|
|||
}
|
||||
with CaptureQueriesContext(connection) as ctx:
|
||||
Command.process_notification(tenant, notification)
|
||||
assert len(ctx.captured_queries) == 33
|
||||
assert len(ctx.captured_queries) == 39
|
||||
assert Group.objects.count() == 1
|
||||
assert Role.objects.count() == 1
|
||||
|
||||
|
@ -338,7 +338,7 @@ def test_hobo_notify_roles_db_queries(caplog, tenants):
|
|||
}
|
||||
with CaptureQueriesContext(connection) as ctx:
|
||||
Command.process_notification(tenant, notification)
|
||||
assert len(ctx.captured_queries) == 15
|
||||
assert len(ctx.captured_queries) == 18
|
||||
|
||||
assert Group.objects.count() == 0
|
||||
assert Role.objects.count() == 0
|
||||
|
|
Loading…
Reference in New Issue