diff --git a/hobo/agent/common/management/commands/hobo_notify.py b/hobo/agent/common/management/commands/hobo_notify.py
index f1fb731..ea62d29 100644
--- a/hobo/agent/common/management/commands/hobo_notify.py
+++ b/hobo/agent/common/management/commands/hobo_notify.py
@@ -15,6 +15,7 @@
# along with this program. If not, see .
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)(
diff --git a/hobo/multitenant/utils.py b/hobo/multitenant/utils.py
index b36d4f7..2e4f6ea 100644
--- a/hobo/multitenant/utils.py
+++ b/hobo/multitenant/utils.py
@@ -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)
diff --git a/hobo/provisionning/middleware.py b/hobo/provisionning/middleware.py
index 70c020a..b8e343b 100644
--- a/hobo/provisionning/middleware.py
+++ b/hobo/provisionning/middleware.py
@@ -15,6 +15,7 @@
# along with this program. If not, see .
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):
diff --git a/hobo/provisionning/utils.py b/hobo/provisionning/utils.py
index a5735c4..56cc87b 100644
--- a/hobo/provisionning/utils.py
+++ b/hobo/provisionning/utils.py
@@ -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):
diff --git a/tests_multitenant/test_hobo_notify.py b/tests_multitenant/test_hobo_notify.py
index 166df2b..a3c12a9 100644
--- a/tests_multitenant/test_hobo_notify.py
+++ b/tests_multitenant/test_hobo_notify.py
@@ -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