diff --git a/activitypub.py b/activitypub.py index e092f04..75c71bf 100644 --- a/activitypub.py +++ b/activitypub.py @@ -118,7 +118,7 @@ def inbox(domain=None): seen_ids[id] = True if already_seen or Object.get_by_id(id): msg = f'Already handled this activity {id}' - logging.info(msg) + logger.info(msg) return msg, 200 activity_as1 = as2.to_as1(activity) @@ -151,7 +151,6 @@ def inbox(domain=None): if not obj_id: error("Couldn't find obj_id of object to update") - logger.info(f'updating Object {obj_id}') obj = Object.get_by_id(obj_id) or Object(id=obj_id) obj.populate( as2=json_dumps(obj_as2), @@ -212,13 +211,13 @@ def inbox(domain=None): # not Like, Follow, or other activity types, since Mastodon doesn't # currently mark those as explicitly public. if not as2.is_public(activity_unwrapped): - logging.info('Dropping non-public activity') + logger.info('Dropping non-public activity') return '' if actor: actor_id = actor.get('id') if actor_id: - logging.info(f'Finding followers of {actor_id}') + logger.info(f'Finding followers of {actor_id}') activity_obj.domains = [ f.src for f in Follower.query(Follower.dest == actor_id, projection=[Follower.src]).fetch()] @@ -227,7 +226,6 @@ def inbox(domain=None): activity_obj.as1 = activity_as1_str activity_obj.labels = ['feed', 'activity'] activity_obj.put() - logging.info(f'Wrote Object {id} for {len(activity_obj.domains)} followers') return 'OK' @@ -314,7 +312,6 @@ def undo_follow(undo_unwrapped): user_domain = util.domain_from_link(followee, minimize=False) follower_obj = Follower.get_by_id(Follower._id(dest=user_domain, src=follower)) if follower_obj: - logger.info(f'Marking {follower_obj.key} as inactive') follower_obj.status = 'inactive' follower_obj.put() else: diff --git a/common.py b/common.py index 50e2ecb..dca5593 100644 --- a/common.py +++ b/common.py @@ -134,12 +134,12 @@ def get_object(id, user=None): obj = Object.get_by_id(id) if obj: if obj.as2: - logging.info(f'Got Object from datastore: {id}') + logger.info(f'Got Object from datastore: {id}') return obj else: obj = Object(id=id) - logging.info(f'Object not in datastore or has no as2: {id}') + logger.info(f'Object not in datastore or has no as2: {id}') obj_as2 = get_as2(id, user=user).json() obj.populate(as2=json_dumps(obj_as2), as1=json_dumps(as2.to_as1(obj_as2)), @@ -179,7 +179,7 @@ def signed_request(fn, url, user, data=None, log_data=True, headers=None, **kwar if data: if log_data: - logging.info(f'Sending AS2 object: {json_dumps(data, indent=2)}') + logger.info(f'Sending AS2 object: {json_dumps(data, indent=2)}') data = json_dumps(data).encode() headers = copy.deepcopy(headers) @@ -359,7 +359,6 @@ def send_webmentions(activity_wrapped, proxy=None, **object_props): if activity.get('objectType') == 'activity': obj.labels.append('activity') obj.put() - logging.info(f'Created Object {source}') while obj.undelivered: target = obj.undelivered.pop() @@ -394,7 +393,6 @@ def send_webmentions(activity_wrapped, proxy=None, **object_props): obj.status = 'complete' if obj.delivered else 'failed' if obj.failed else 'ignored' obj.put() - logging.info(f'Finalized Object {source} as {obj.status}') if errors: msg = 'Errors: ' + ', '.join(f'{code} {body}' for code, body in errors) diff --git a/follow.py b/follow.py index 143395b..a101f7c 100644 --- a/follow.py +++ b/follow.py @@ -173,7 +173,6 @@ class FollowCallback(indieauth.Callback): source_protocol='ui', status='complete', as2=follow_json, as1=json_dumps(as2.to_as1(follow_as2), sort_keys=True), ).put() - logging.info(f'Wrote Object {follow_id}') link = common.pretty_link(util.get_url(followee) or id, text=addr) flash(f'Followed {link}.') @@ -243,7 +242,6 @@ class UnfollowCallback(indieauth.Callback): as2=json_dumps(unfollow_as2, sort_keys=True), as1=json_dumps(as2.to_as1(unfollow_as2), sort_keys=True), ).put() - logging.info(f'Wrote Object {unfollow_id}') link = common.pretty_link(util.get_url(followee) or followee_id) flash(f'Unfollowed {link}.') diff --git a/models.py b/models.py index 92e01fc..46e335d 100644 --- a/models.py +++ b/models.py @@ -78,6 +78,9 @@ class User(StringIdModel): def _get_kind(cls): return 'MagicKey' + def _post_put_hook(self, future): + logger.info(f'Wrote User {self.key.id()}') + @classmethod def get_by_id(cls, id): """Override Model.get_by_id to follow the use_instead property.""" @@ -199,7 +202,7 @@ class User(StringIdModel): try: resp = util.requests_get(root_site, gateway=False) if resp.ok and self.is_homepage(resp.url): - logging.info(f'{root_site} redirects to {resp.url} ; using {root} instead') + logger.info(f'{root_site} redirects to {resp.url} ; using {root} instead') root_user = User.get_or_create(root) self.use_instead = root_user.key self.put() @@ -305,6 +308,7 @@ class Object(StringIdModel): def _post_put_hook(self, future): """Update :func:`common.get_object` cache.""" # TODO: assert that as1 id is same as key id? in pre put hook? + logger.info(f'Wrote Object {self.key.id()} {self.type} {self.status or ""} {self.labels} for {len(self.domains)} users') if self.type != 'activity': key = common.get_object.cache_key(self.key.id()) common.get_object.cache[key] = self @@ -365,6 +369,9 @@ class Follower(StringIdModel): created = ndb.DateTimeProperty(auto_now_add=True) updated = ndb.DateTimeProperty(auto_now=True) + def _post_put_hook(self, future): + logger.info(f'Wrote Follower {self.key.id()} {self.status}') + @classmethod def _id(cls, dest, src): assert src @@ -373,7 +380,6 @@ class Follower(StringIdModel): @classmethod def get_or_create(cls, dest, src, **kwargs): - logger.info(f'new Follower from {src} to {dest}') follower = cls.get_or_insert(cls._id(dest, src), src=src, dest=dest, **kwargs) follower.dest = dest follower.src = src diff --git a/webmention.py b/webmention.py index 80fa433..8a47d5d 100644 --- a/webmention.py +++ b/webmention.py @@ -143,12 +143,12 @@ class Webmention(View): changed = False if obj: - logging.info(f'Resuming existing {obj}') + logger.info(f'Resuming existing {obj}') obj.failed = [] seen = [t.uri for t in obj.delivered + obj.undelivered + obj.failed] new_inboxes = [i for i in inboxes_to_targets.keys() if i not in seen] if new_inboxes: - logging.info(f'Adding new inboxes: {new_inboxes}') + logger.info(f'Adding new inboxes: {new_inboxes}') obj.undelivered += [Target(uri=uri, protocol='activitypub') for uri in new_inboxes] if type in ('note', 'article', 'comment'): @@ -163,7 +163,6 @@ class Webmention(View): undelivered=[Target(uri=uri, protocol='activitypub') for uri in inboxes_to_targets.keys()], status='in progress') - logging.info(f'Storing new Object {self.source_url}') obj.domains = [self.source_domain] obj.source_protocol = 'webmention' @@ -183,7 +182,7 @@ class Webmention(View): if inbox in inboxes_to_targets: target_as2 = inboxes_to_targets[inbox] else: - logging.warning(f'Missing target_as2 for inbox {inbox}!') + logger.warning(f'Missing target_as2 for inbox {inbox}!') target_as2 = None if not self.source_as2: @@ -330,7 +329,7 @@ class Webmention(View): if not inbox_url: # TODO: probably need a way to surface errors like this - logging.error('Target actor has no inbox') + logger.error('Target actor has no inbox') continue inbox_url = urllib.parse.urljoin(target, inbox_url)