Sync Blender ID badge as soon as user logs in

This adds a new Blinker signal `user_logged_in` that is only sent when
the user logs in via the web interface (and not on every token
authentication and every API call).

pillar/api/utils/authentication.py

@@ -189,7 +189,7 @@ def validate_this_token(token, oauth_subclient=None):
         return None
 
     g.current_user = UserClass.construct(token, db_user)
-    user_authenticated.send(sender=g.current_user)
+    user_authenticated.send(g.current_user)
 
     return db_user
 

pillar/auth/__init__.py

@@ -14,6 +14,7 @@ from pillar import current_app
 
 # The sender is the user that was just authenticated.
 user_authenticated = blinker.Signal('Sent whenever a user was authenticated')
+user_logged_in = blinker.Signal('Sent whenever a user logged in on the web')
 
 log = logging.getLogger(__name__)
 
@@ -227,7 +228,8 @@ def login_user_object(user: UserClass):
     """Log in the given user."""
     flask_login.login_user(user, remember=True)
     g.current_user = user
-    user_authenticated.send(sender=user)
+    user_authenticated.send(user)
+    user_logged_in.send(user)
 
 
 def logout_user():

pillar/badge_sync.py

@@ -7,7 +7,7 @@ from urllib.parse import urljoin
 import bson
 import requests
 
-from pillar import current_app
+from pillar import current_app, auth
 from pillar.api.utils import utcnow
 
 SyncUser = collections.namedtuple('SyncUser', 'user_id token bid_user_id')
@@ -23,6 +23,41 @@ class StopRefreshing(Exception):
     """
 
 
+def find_user_to_sync(user_id: bson.ObjectId) -> typing.Optional[SyncUser]:
+    """Return user information for syncing badges for a specific user.
+
+    Returns None if the user cannot be synced (no 'badge' scope on a token,
+    or no Blender ID user_id known).
+    """
+    my_log = log.getChild('refresh_single_user')
+
+    now = utcnow()
+    tokens_coll = current_app.db('tokens')
+    users_coll = current_app.db('users')
+
+    token_info = tokens_coll.find_one({
+        'user': user_id,
+        'token': {'$exists': True},
+        'oauth_scopes': 'badge',
+        'expire_time': {'$gt': now},
+    })
+    if not token_info:
+        my_log.debug('No token with scope "badge" for user %s', user_id)
+        return None
+
+    user_info = users_coll.find_one({'_id': user_id})
+    # TODO(Sybren): do this filtering in the MongoDB query:
+    bid_user_ids = [auth_info.get('user_id')
+                    for auth_info in user_info.get('auth', [])
+                    if auth_info.get('provider', '') == 'blender-id' and auth_info.get('user_id')]
+    if not bid_user_ids:
+        my_log.debug('No Blender ID user_id for user %s', user_id)
+        return None
+
+    bid_user_id = bid_user_ids[0]
+    return SyncUser(user_id=user_id, token=token_info['token'], bid_user_id=bid_user_id)
+
+
 def find_users_to_sync() -> typing.Iterable[SyncUser]:
     """Return user information of syncable users with badges."""
 
@@ -33,7 +68,8 @@ def find_users_to_sync() -> typing.Iterable[SyncUser]:
         {'$match': {
             'token': {'$exists': True},
             'oauth_scopes': 'badge',
-            'expire_time': {'$gt': now},  # TODO(Sybren): save real token expiry time but keep checking tokens hourly when they are used!
+            'expire_time': {'$gt': now},
+            # TODO(Sybren): save real token expiry time but keep checking tokens hourly when they are used!
         }},
         {'$lookup': {
             'from': 'users',
@@ -133,18 +169,14 @@ def refresh_all_badges(only_user_id: typing.Optional[bson.ObjectId] = None, *,
         jobs to run without overlapping, even when the number fo badges to refresh
         becomes larger than possible within the period of the cron job.
     """
-    from requests.adapters import HTTPAdapter
-    my_log = log.getChild('fetch_badge_html')
+    my_log = log.getChild('refresh_all_badges')
 
     # Test the config before we start looping over the world.
     badge_expiry = badge_expiry_config()
     if not badge_expiry or not isinstance(badge_expiry, datetime.timedelta):
         raise ValueError('BLENDER_ID_BADGE_EXPIRY not configured properly, should be a timedelta')
 
-    session = requests.Session()
-    session.mount('https://', HTTPAdapter(max_retries=5))
-    users_coll = current_app.db('users')
-
+    session = _get_requests_session()
     deadline = utcnow() + timelimit
 
     num_updates = 0
@@ -164,20 +196,71 @@ def refresh_all_badges(only_user_id: typing.Optional[bson.ObjectId] = None, *,
                          user_info)
             break
 
+        num_updates += 1
+        update_badges(user_info, badge_html, badge_expiry, dry_run=dry_run)
+    my_log.info('Updated badges of %d users%s', num_updates, ' (dry-run)' if dry_run else '')
+
+
+def _get_requests_session() -> requests.Session:
+    from requests.adapters import HTTPAdapter
+    session = requests.Session()
+    session.mount('https://', HTTPAdapter(max_retries=5))
+    return session
+
+
+def refresh_single_user(user_id: bson.ObjectId):
+    """Refresh badges for a single user."""
+    my_log = log.getChild('refresh_single_user')
+
+    badge_expiry = badge_expiry_config()
+    if not badge_expiry:
+        my_log.warning('Skipping badge fetching, BLENDER_ID_BADGE_EXPIRY not configured')
+
+    my_log.debug('Fetching badges for user %s', user_id)
+    session = _get_requests_session()
+    user_info = find_user_to_sync(user_id)
+    if not user_info:
+        return
+
+    try:
+        badge_html = fetch_badge_html(session, user_info, 's')
+    except StopRefreshing:
+        my_log.error('Blender ID has internal problems, stopping badge refreshing at user %s',
+                     user_info)
+        return
+
+    update_badges(user_info, badge_html, badge_expiry, dry_run=False)
+    my_log.info('Updated badges of user %s', user_id)
+
+
+def update_badges(user_info: SyncUser, badge_html: str, badge_expiry: datetime.timedelta,
+                  *, dry_run: bool):
+    my_log = log.getChild('update_badges')
+    users_coll = current_app.db('users')
+
     update = {'badges': {
         'html': badge_html,
         'expires': utcnow() + badge_expiry,
     }}
-        num_updates += 1
     my_log.info('Updating badges HTML for Blender ID %s, user %s',
                 user_info.bid_user_id, user_info.user_id)
-        if not dry_run:
+
+    if dry_run:
+        return
+
     result = users_coll.update_one({'_id': user_info.user_id},
                                    {'$set': update})
     if result.matched_count != 1:
         my_log.warning('Unable to update badges for user %s', user_info.user_id)
-    my_log.info('Updated badges of %d users%s', num_updates, ' (dry-run)' if dry_run else '')
 
 
 def badge_expiry_config() -> datetime.timedelta:
     return current_app.config.get('BLENDER_ID_BADGE_EXPIRY')
+
+
+@auth.user_logged_in.connect
+def sync_badge_upon_login(sender: auth.UserClass, **kwargs):
+    """Auto-sync badges when a user logs in."""
+
+    log.info('Refreshing badge of %s because they logged in', sender.user_id)
+    refresh_single_user(sender.user_id)

tests/test_badge_sync.py

@@ -109,6 +109,46 @@ class FindUsersToSyncTest(AbstractSyncTest):
         self.assertEqual([], found)
 
 
+class FindUserSyncInfoTest(AbstractSyncTest):
+    def test_no_badge_fetched_yet(self):
+        from pillar import badge_sync
+
+        with self.app.app_context():
+            found1 = badge_sync.find_user_to_sync(self.uid1)
+            found2 = badge_sync.find_user_to_sync(self.uid2)
+        self.assertEqual(self.sync_user1, found1)
+        self.assertEqual(self.sync_user2, found2)
+
+    def test_badge_fetched_recently(self):
+        # This should be the same for all cases, as a single user
+        # is always refreshed.
+        from pillar import badge_sync
+
+        # Badges of user1 expired, user2 didn't yet.
+        with self.app.app_context():
+            self._update_badge_expiry(-5, 5)
+            found1 = badge_sync.find_user_to_sync(self.uid1)
+            found2 = badge_sync.find_user_to_sync(self.uid2)
+        self.assertEqual(self.sync_user1, found1)
+        self.assertEqual(self.sync_user2, found2)
+
+        # Badges of both users expired, but user2 expired longer ago.
+        with self.app.app_context():
+            self._update_badge_expiry(-5, -10)
+            found1 = badge_sync.find_user_to_sync(self.uid1)
+            found2 = badge_sync.find_user_to_sync(self.uid2)
+        self.assertEqual(self.sync_user1, found1)
+        self.assertEqual(self.sync_user2, found2)
+
+        # Badges of both not expired yet.
+        with self.app.app_context():
+            self._update_badge_expiry(2, 3)
+            found1 = badge_sync.find_user_to_sync(self.uid1)
+            found2 = badge_sync.find_user_to_sync(self.uid2)
+        self.assertEqual(self.sync_user1, found1)
+        self.assertEqual(self.sync_user2, found2)
+
+
 class FetchHTMLTest(AbstractSyncTest):
     @httpmock.activate
     def test_happy(self):
@@ -215,3 +255,21 @@ class RefreshAllTest(AbstractSyncTest):
         margin = datetime.timedelta(minutes=1)
         self.assertLess(expected_expire - margin, db_user1['badges']['expires'])
         self.assertGreater(expected_expire + margin, db_user1['badges']['expires'])
+
+
+class RefreshSingleTest(AbstractSyncTest):
+    @httpmock.activate
+    def test_happy(self):
+        from pillar import badge_sync
+
+        httpmock.add('GET', 'http://id.local:8001/api/badges/1947/html/s',
+                     body='badges for Agent 47')
+
+        db_user1 = self.get('/api/users/me', auth_token=self.sync_user1.token).json
+        self.assertNotIn('badges', db_user1)
+
+        with self.app.app_context():
+            badge_sync.refresh_single_user(self.uid1)
+
+        db_user1 = self.get('/api/users/me', auth_token=self.sync_user1.token).json
+        self.assertEqual('badges for Agent 47', db_user1['badges']['html'])