From bc53c9b2082acacace58cc79c535e236610cc3b5 Mon Sep 17 00:00:00 2001 From: Art4 Date: Mon, 13 Jan 2025 12:45:38 +0000 Subject: [PATCH] Replace Logger with DI::logger() in ActivityPub Protocol classes --- src/Protocol/ActivityPub.php | 17 +- src/Protocol/ActivityPub/ClientToServer.php | 17 +- src/Protocol/ActivityPub/Delivery.php | 17 +- src/Protocol/ActivityPub/Fetch.php | 10 +- src/Protocol/ActivityPub/Processor.php | 275 ++++++++++---------- src/Protocol/ActivityPub/Queue.php | 21 +- src/Protocol/ActivityPub/Receiver.php | 141 +++++----- src/Protocol/ActivityPub/Transmitter.php | 61 +++-- 8 files changed, 276 insertions(+), 283 deletions(-) diff --git a/src/Protocol/ActivityPub.php b/src/Protocol/ActivityPub.php index 55ba315d83..9bef5479cd 100644 --- a/src/Protocol/ActivityPub.php +++ b/src/Protocol/ActivityPub.php @@ -7,7 +7,6 @@ namespace Friendica\Protocol; -use Friendica\Core\Logger; use Friendica\Core\Protocol; use Friendica\Core\System; use Friendica\DI; @@ -87,12 +86,12 @@ class ActivityPub { header('Vary: Accept', false); if (stristr($_SERVER['HTTP_ACCEPT'] ?? '', 'application/activity+json') || stristr($_SERVER['HTTP_ACCEPT'] ?? '', 'application/ld+json')) { - Logger::debug('Is AP request', ['accept' => $_SERVER['HTTP_ACCEPT'], 'agent' => $_SERVER['HTTP_USER_AGENT'] ?? '']); + DI::logger()->debug('Is AP request', ['accept' => $_SERVER['HTTP_ACCEPT'], 'agent' => $_SERVER['HTTP_USER_AGENT'] ?? '']); return true; } if (stristr($_SERVER['HTTP_ACCEPT'] ?? '', 'application/json')) { - Logger::debug('Is JSON request', ['accept' => $_SERVER['HTTP_ACCEPT'], 'agent' => $_SERVER['HTTP_USER_AGENT'] ?? '']); + DI::logger()->debug('Is JSON request', ['accept' => $_SERVER['HTTP_ACCEPT'], 'agent' => $_SERVER['HTTP_USER_AGENT'] ?? '']); return true; } @@ -232,7 +231,7 @@ class ActivityPub $start_timestamp = $start_timestamp ?: time(); if ((time() - $start_timestamp) > 60) { - Logger::info('Fetch time limit reached', ['url' => $url, 'uid' => $uid]); + DI::logger()->info('Fetch time limit reached', ['url' => $url, 'uid' => $uid]); return []; } @@ -284,24 +283,24 @@ class ActivityPub $signer = HTTPSignature::getSigner('', $_SERVER); if (!$signer) { - Logger::debug('No signer or invalid signature', ['uid' => $uid, 'agent' => $_SERVER['HTTP_USER_AGENT'] ?? '', 'called_by' => $called_by]); + DI::logger()->debug('No signer or invalid signature', ['uid' => $uid, 'agent' => $_SERVER['HTTP_USER_AGENT'] ?? '', 'called_by' => $called_by]); return false; } $apcontact = APContact::getByURL($signer); if (empty($apcontact)) { - Logger::info('APContact not found', ['uid' => $uid, 'handle' => $signer, 'called_by' => $called_by]); + DI::logger()->info('APContact not found', ['uid' => $uid, 'handle' => $signer, 'called_by' => $called_by]); return false; } if (empty($apcontact['gsid']) || empty($apcontact['baseurl'])) { - Logger::debug('No server found', ['uid' => $uid, 'signer' => $signer, 'called_by' => $called_by]); + DI::logger()->debug('No server found', ['uid' => $uid, 'signer' => $signer, 'called_by' => $called_by]); return false; } $contact = Contact::getByURL($signer, false, ['id', 'baseurl', 'gsid']); if (!empty($contact) && Contact\User::isBlocked($contact['id'], $uid)) { - Logger::info('Requesting contact is blocked', ['uid' => $uid, 'id' => $contact['id'], 'signer' => $signer, 'baseurl' => $contact['baseurl'], 'called_by' => $called_by]); + DI::logger()->info('Requesting contact is blocked', ['uid' => $uid, 'id' => $contact['id'], 'signer' => $signer, 'baseurl' => $contact['baseurl'], 'called_by' => $called_by]); return false; } @@ -318,7 +317,7 @@ class ActivityPub return false; } - Logger::debug('Server is an accepted requester', ['uid' => $uid, 'id' => $apcontact['gsid'], 'url' => $apcontact['baseurl'], 'signer' => $signer, 'called_by' => $called_by]); + DI::logger()->debug('Server is an accepted requester', ['uid' => $uid, 'id' => $apcontact['gsid'], 'url' => $apcontact['baseurl'], 'signer' => $signer, 'called_by' => $called_by]); return true; } diff --git a/src/Protocol/ActivityPub/ClientToServer.php b/src/Protocol/ActivityPub/ClientToServer.php index 989d12bea0..c95732d3b9 100644 --- a/src/Protocol/ActivityPub/ClientToServer.php +++ b/src/Protocol/ActivityPub/ClientToServer.php @@ -8,7 +8,6 @@ namespace Friendica\Protocol\ActivityPub; use Friendica\Content\Text\Markdown; -use Friendica\Core\Logger; use Friendica\Core\Protocol; use Friendica\Database\DBA; use Friendica\DI; @@ -39,24 +38,24 @@ class ClientToServer { $ldactivity = JsonLD::compact($activity); if (empty($ldactivity)) { - Logger::notice('Invalid activity', ['activity' => $activity, 'uid' => $uid]); + DI::logger()->notice('Invalid activity', ['activity' => $activity, 'uid' => $uid]); return []; } $type = JsonLD::fetchElement($ldactivity, '@type'); if (!$type) { - Logger::notice('Empty type', ['activity' => $ldactivity, 'uid' => $uid]); + DI::logger()->notice('Empty type', ['activity' => $ldactivity, 'uid' => $uid]); return []; } $object_id = JsonLD::fetchElement($ldactivity, 'as:object', '@id') ?? ''; $object_type = Receiver::fetchObjectType($ldactivity, $object_id, $uid); if (!$object_type && !$object_id) { - Logger::notice('Empty object type or id', ['activity' => $ldactivity, 'uid' => $uid]); + DI::logger()->notice('Empty object type or id', ['activity' => $ldactivity, 'uid' => $uid]); return []; } - Logger::debug('Processing activity', ['type' => $type, 'object_type' => $object_type, 'object_id' => $object_id, 'activity' => $ldactivity]); + DI::logger()->debug('Processing activity', ['type' => $type, 'object_type' => $object_type, 'object_id' => $object_id, 'activity' => $ldactivity]); return self::routeActivities($type, $object_type, $object_id, $uid, $application, $ldactivity); } @@ -105,7 +104,7 @@ class ClientToServer { $object_data = self::processObject($ldactivity['as:object']); $item = ClientToServer::processContent($object_data, $application, $uid); - Logger::debug('Got data', ['item' => $item, 'object' => $object_data]); + DI::logger()->debug('Got data', ['item' => $item, 'object' => $object_data]); $id = Item::insert($item, true); if (!empty($id)) { @@ -131,18 +130,18 @@ class ClientToServer $id = Item::fetchByLink($object_id, $uid, ActivityPub\Receiver::COMPLETION_ASYNC); $original_post = Post::selectFirst(['uri-id'], ['uid' => $uid, 'origin' => true, 'id' => $id]); if (empty($original_post)) { - Logger::debug('Item not found or does not belong to the user', ['id' => $id, 'uid' => $uid, 'object_id' => $object_id, 'activity' => $ldactivity]); + DI::logger()->debug('Item not found or does not belong to the user', ['id' => $id, 'uid' => $uid, 'object_id' => $object_id, 'activity' => $ldactivity]); return []; } $object_data = self::processObject($ldactivity['as:object']); $item = ClientToServer::processContent($object_data, $application, $uid); if (empty($item['title']) && empty($item['body'])) { - Logger::debug('Empty body and title', ['id' => $id, 'uid' => $uid, 'object_id' => $object_id, 'activity' => $ldactivity]); + DI::logger()->debug('Empty body and title', ['id' => $id, 'uid' => $uid, 'object_id' => $object_id, 'activity' => $ldactivity]); return []; } $post = ['title' => $item['title'], 'body' => $item['body']]; - Logger::debug('Got data', ['id' => $id, 'uid' => $uid, 'item' => $post]); + DI::logger()->debug('Got data', ['id' => $id, 'uid' => $uid, 'item' => $post]); Item::update($post, ['id' => $id]); Item::updateDisplayCache($original_post['uri-id']); diff --git a/src/Protocol/ActivityPub/Delivery.php b/src/Protocol/ActivityPub/Delivery.php index 5a1d851b38..865d962d4a 100644 --- a/src/Protocol/ActivityPub/Delivery.php +++ b/src/Protocol/ActivityPub/Delivery.php @@ -7,7 +7,6 @@ namespace Friendica\Protocol\ActivityPub; -use Friendica\Core\Logger; use Friendica\Core\Worker; use Friendica\Database\DBA; use Friendica\DI; @@ -50,7 +49,7 @@ class Delivery if ($result['serverfailure']) { // In a timeout situation we assume that every delivery to that inbox will time out. // So we set the flag and try all deliveries at a later time. - Logger::notice('Inbox delivery has a server failure', ['inbox' => $inbox]); + DI::logger()->notice('Inbox delivery has a server failure', ['inbox' => $inbox]); $serverfail = true; } Worker::coolDown(); @@ -61,7 +60,7 @@ class Delivery } } - Logger::debug('Inbox delivery done', ['inbox' => $inbox, 'posts' => count($posts), 'failed' => count($uri_ids), 'serverfailure' => $serverfail]); + DI::logger()->debug('Inbox delivery done', ['inbox' => $inbox, 'posts' => count($posts), 'failed' => count($uri_ids), 'serverfailure' => $serverfail]); return ['success' => empty($uri_ids), 'uri_ids' => $uri_ids]; } @@ -84,11 +83,11 @@ class Delivery if (empty($item_id) && !empty($uri_id) && !empty($uid)) { $item = Post::selectFirst(['id', 'parent', 'origin', 'gravity', 'verb'], ['uri-id' => $uri_id, 'uid' => [$uid, 0]], ['order' => ['uid' => true]]); if (empty($item['id'])) { - Logger::warning('Item not found, removing delivery', ['uri-id' => $uri_id, 'uid' => $uid, 'cmd' => $cmd, 'inbox' => $inbox]); + DI::logger()->warning('Item not found, removing delivery', ['uri-id' => $uri_id, 'uid' => $uid, 'cmd' => $cmd, 'inbox' => $inbox]); Post\Delivery::remove($uri_id, $inbox); return ['success' => true, 'serverfailure' => false, 'drop' => false]; } elseif (!DI::config()->get('system', 'redistribute_activities') && !$item['origin'] && ($item['gravity'] == Item::GRAVITY_ACTIVITY)) { - Logger::notice('Activities are not relayed, removing delivery', ['verb' => $item['verb'], 'uri-id' => $uri_id, 'uid' => $uid, 'cmd' => $cmd, 'inbox' => $inbox]); + DI::logger()->notice('Activities are not relayed, removing delivery', ['verb' => $item['verb'], 'uri-id' => $uri_id, 'uid' => $uid, 'cmd' => $cmd, 'inbox' => $inbox]); Post\Delivery::remove($uri_id, $inbox); return ['success' => true, 'serverfailure' => false, 'drop' => false]; } else { @@ -122,7 +121,7 @@ class Delivery $success = $response->isSuccess(); $serverfail = $response->isTimeout(); } catch (\Throwable $th) { - Logger::notice('Got exception', ['code' => $th->getCode(), 'message' => $th->getMessage()]); + DI::logger()->notice('Got exception', ['code' => $th->getCode(), 'message' => $th->getMessage()]); $response = null; $success = false; $serverfail = true; @@ -154,7 +153,7 @@ class Delivery $actor = self:: fetchActorForRelayInbox($inbox); if (!empty($actor)) { $drop = !ActivityPub\Transmitter::sendRelayFollow($actor); - Logger::notice('Resubscribed to relay', ['url' => $actor, 'success' => !$drop]); + DI::logger()->notice('Resubscribed to relay', ['url' => $actor, 'success' => !$drop]); } elseif ($cmd == ProtocolDelivery::DELETION) { // Remote systems not always accept our deletion requests, so we drop them if rejected. // Situation is: In Friendica we allow the thread owner to delete foreign comments to their thread. @@ -164,7 +163,7 @@ class Delivery } - Logger::notice('Delivery failed', ['retcode' => $response->getReturnCode() ?? 0, 'serverfailure' => $serverfail, 'drop' => $drop, 'runtime' => round($runtime, 3), 'uri-id' => $uri_id, 'uid' => $uid, 'item_id' => $item_id, 'cmd' => $cmd, 'inbox' => $inbox]); + DI::logger()->notice('Delivery failed', ['retcode' => $response->getReturnCode() ?? 0, 'serverfailure' => $serverfail, 'drop' => $drop, 'runtime' => round($runtime, 3), 'uri-id' => $uri_id, 'uid' => $uid, 'item_id' => $item_id, 'cmd' => $cmd, 'inbox' => $inbox]); } if ($uri_id) { if ($success) { @@ -180,7 +179,7 @@ class Delivery self::setSuccess($receivers, $success); - Logger::debug('Delivered', ['uri-id' => $uri_id, 'uid' => $uid, 'item_id' => $item_id, 'cmd' => $cmd, 'inbox' => $inbox, 'success' => $success, 'serverfailure' => $serverfail, 'drop' => $drop]); + DI::logger()->debug('Delivered', ['uri-id' => $uri_id, 'uid' => $uid, 'item_id' => $item_id, 'cmd' => $cmd, 'inbox' => $inbox, 'success' => $success, 'serverfailure' => $serverfail, 'drop' => $drop]); if (($success || $drop) && in_array($cmd, [ProtocolDelivery::POST])) { Post\DeliveryData::incrementQueueDone($uri_id, Post\DeliveryData::ACTIVITYPUB); diff --git a/src/Protocol/ActivityPub/Fetch.php b/src/Protocol/ActivityPub/Fetch.php index fa7b52996b..3c787981ab 100644 --- a/src/Protocol/ActivityPub/Fetch.php +++ b/src/Protocol/ActivityPub/Fetch.php @@ -7,9 +7,9 @@ namespace Friendica\Protocol\ActivityPub; -use Friendica\Core\Logger; use Friendica\Database\Database; use Friendica\Database\DBA; +use Friendica\DI; use Friendica\Util\DateTimeFormat; /** @@ -22,7 +22,7 @@ class Fetch DBA::insert('fetch-entry', ['url' => $url, 'created' => DateTimeFormat::utcNow()], Database::INSERT_IGNORE); $fetch = DBA::selectFirst('fetch-entry', ['id'], ['url' => $url]); - Logger::debug('Added fetch entry', ['url' => $url, 'fetch' => $fetch]); + DI::logger()->debug('Added fetch entry', ['url' => $url, 'fetch' => $fetch]); return $fetch['id'] ?? 0; } @@ -38,7 +38,7 @@ class Fetch } DBA::update('fetch-entry', ['wid' => $wid], ['url' => $url]); - Logger::debug('Worker id set', ['url' => $url, 'wid' => $wid]); + DI::logger()->debug('Worker id set', ['url' => $url, 'wid' => $wid]); } /** @@ -48,14 +48,14 @@ class Fetch { $fetch = DBA::selectFirst('fetch-entry', ['id', 'wid'], ['url' => $url]); if (empty($fetch['id'])) { - Logger::debug('No entry found for url', ['url' => $url]); + DI::logger()->debug('No entry found for url', ['url' => $url]); return false; } // We don't have a workerqueue id yet. So most likely is isn't assigned yet. // To avoid the ramping up of another fetch request we simply claim that there is a waiting worker. if (!empty($fetch['id']) && empty($fetch['wid'])) { - Logger::debug('Entry without worker found for url', ['url' => $url]); + DI::logger()->debug('Entry without worker found for url', ['url' => $url]); return true; } diff --git a/src/Protocol/ActivityPub/Processor.php b/src/Protocol/ActivityPub/Processor.php index b50397dc75..6cc401f05e 100644 --- a/src/Protocol/ActivityPub/Processor.php +++ b/src/Protocol/ActivityPub/Processor.php @@ -11,7 +11,6 @@ use Friendica\Content\Text\BBCode; use Friendica\Content\Text\HTML; use Friendica\Content\Text\Markdown; use Friendica\Core\Cache\Enum\Duration; -use Friendica\Core\Logger; use Friendica\Core\Protocol; use Friendica\Core\System; use Friendica\Core\Worker; @@ -204,7 +203,7 @@ class Processor Post\QuestionOption::update($item['uri-id'], $key, $option); } - Logger::debug('Storing incoming question', ['type' => $activity['type'], 'uri-id' => $item['uri-id'], 'question' => $activity['question']]); + DI::logger()->debug('Storing incoming question', ['type' => $activity['type'], 'uri-id' => $item['uri-id'], 'question' => $activity['question']]); } /** @@ -218,7 +217,7 @@ class Processor { $item = Post::selectFirst(['uri', 'uri-id', 'thr-parent', 'gravity', 'post-type', 'private'], ['uri' => $activity['id']]); if (!DBA::isResult($item)) { - Logger::notice('No existing item, item will be created', ['uri' => $activity['id']]); + DI::logger()->notice('No existing item, item will be created', ['uri' => $activity['id']]); $item = self::createItem($activity, false); if (empty($item)) { Queue::remove($activity); @@ -278,7 +277,7 @@ class Processor $event['nofinish'] = empty($event['finish']); $event['location'] = $activity['location']; - Logger::info('Updating event', ['uri' => $activity['id'], 'id' => $event_id]); + DI::logger()->info('Updating event', ['uri' => $activity['id'], 'id' => $event_id]); Event::store($event); } @@ -318,14 +317,14 @@ class Processor if (!empty($item['context'])) { $conversation = Post::selectFirstThread(['uri'], ['context' => $item['context']]); if (!empty($conversation)) { - Logger::debug('Got context', ['context' => $item['context'], 'parent' => $conversation]); + DI::logger()->debug('Got context', ['context' => $item['context'], 'parent' => $conversation]); $item['parent-uri'] = $conversation['uri']; $item['parent-uri-id'] = ItemURI::getIdByURI($item['parent-uri']); } } elseif (!empty($item['conversation'])) { $conversation = Post::selectFirstThread(['uri'], ['conversation' => $item['conversation']]); if (!empty($conversation)) { - Logger::debug('Got conversation', ['conversation' => $item['conversation'], 'parent' => $conversation]); + DI::logger()->debug('Got conversation', ['conversation' => $item['conversation'], 'parent' => $conversation]); $item['parent-uri'] = $conversation['uri']; $item['parent-uri-id'] = ItemURI::getIdByURI($item['parent-uri']); } @@ -333,9 +332,9 @@ class Processor $conversation = []; } - Logger::debug('Create Item', ['id' => $activity['id'], 'conversation' => $item['conversation'] ?? '']); + DI::logger()->debug('Create Item', ['id' => $activity['id'], 'conversation' => $item['conversation'] ?? '']); if (empty($activity['author']) && empty($activity['actor'])) { - Logger::notice('Missing author and actor. We quit here.', ['activity' => $activity]); + DI::logger()->notice('Missing author and actor. We quit here.', ['activity' => $activity]); Queue::remove($activity); return []; } @@ -354,7 +353,7 @@ class Processor $item['diaspora_signed_text'] = $activity['diaspora:comment'] ?? ''; if (empty($conversation) && empty($activity['directmessage']) && ($item['gravity'] != Item::GRAVITY_PARENT) && !Post::exists(['uri' => $item['thr-parent']])) { - Logger::notice('Parent not found, message will be discarded.', ['thr-parent' => $item['thr-parent']]); + DI::logger()->notice('Parent not found, message will be discarded.', ['thr-parent' => $item['thr-parent']]); if (!$fetch_parents) { Queue::remove($activity); } @@ -416,12 +415,12 @@ class Processor $actor = Contact::getById($activity['thread-completion'], ['url']); $item['causer-link'] = $actor['url']; $item['causer-id'] = $activity['thread-completion']; - Logger::info('Use inherited actor as causer.', ['id' => $item['owner-id'], 'activity' => $activity['thread-completion'], 'owner' => $item['owner-link'], 'actor' => $actor['url']]); + DI::logger()->info('Use inherited actor as causer.', ['id' => $item['owner-id'], 'activity' => $activity['thread-completion'], 'owner' => $item['owner-link'], 'actor' => $actor['url']]); } else { // Store the original actor in the "causer" fields to enable the check for ignored or blocked contacts $item['causer-link'] = $item['owner-link']; $item['causer-id'] = $item['owner-id']; - Logger::info('Use actor as causer.', ['id' => $item['owner-id'], 'actor' => $item['owner-link']]); + DI::logger()->info('Use actor as causer.', ['id' => $item['owner-id'], 'actor' => $item['owner-link']]); } $item['owner-link'] = $item['author-link']; @@ -432,7 +431,7 @@ class Processor foreach ($activity['receiver_urls']['as:audience'] as $audience) { $actor = APContact::getByURL($audience, false); if (($actor['type'] ?? 'Person') == 'Group') { - Logger::debug('Group post detected via audience.', ['audience' => $audience, 'actor' => $activity['actor'], 'author' => $activity['author']]); + DI::logger()->debug('Group post detected via audience.', ['audience' => $audience, 'actor' => $activity['actor'], 'author' => $activity['author']]); $item['isGroup'] = true; $item['group-link'] = $item['owner-link'] = $audience; $item['owner-id'] = Contact::getIdForURL($audience); @@ -444,7 +443,7 @@ class Processor } if (!$item['isGroup'] && (($owner['type'] ?? 'Person') == 'Group')) { - Logger::debug('Group post detected via owner.', ['actor' => $activity['actor'], 'author' => $activity['author']]); + DI::logger()->debug('Group post detected via owner.', ['actor' => $activity['actor'], 'author' => $activity['author']]); $item['isGroup'] = true; $item['group-link'] = $item['owner-link']; } elseif (!empty($item['causer-link'])) { @@ -452,7 +451,7 @@ class Processor } if (!$item['isGroup'] && (($causer['type'] ?? 'Person') == 'Group')) { - Logger::debug('Group post detected via causer.', ['actor' => $activity['actor'], 'author' => $activity['author'], 'causer' => $item['causer-link']]); + DI::logger()->debug('Group post detected via causer.', ['actor' => $activity['actor'], 'author' => $activity['author'], 'causer' => $item['causer-link']]); $item['isGroup'] = true; $item['group-link'] = $item['causer-link']; } @@ -476,7 +475,7 @@ class Processor $item['uri-id'] = ItemURI::insert(['uri' => $item['uri'], 'guid' => $item['guid']]); if (empty($item['uri-id'])) { - Logger::warning('Unable to get a uri-id for an item uri', ['uri' => $item['uri'], 'guid' => $item['guid']]); + DI::logger()->warning('Unable to get a uri-id for an item uri', ['uri' => $item['uri'], 'guid' => $item['guid']]); return []; } @@ -484,7 +483,7 @@ class Processor $item = self::processContent($activity, $item); if (empty($item)) { - Logger::info('Message was not processed'); + DI::logger()->info('Message was not processed'); Queue::remove($activity); return []; } @@ -554,12 +553,12 @@ class Processor $activity['callstack'] = self::addToCallstack($activity['callstack'] ?? []); if (self::isFetched($activity['reply-to-id'])) { - Logger::info('Id is already fetched', ['id' => $activity['reply-to-id']]); + DI::logger()->info('Id is already fetched', ['id' => $activity['reply-to-id']]); return ''; } if (in_array($activity['reply-to-id'], $activity['children'] ?? [])) { - Logger::notice('reply-to-id is already in the list of children', ['id' => $activity['reply-to-id'], 'children' => $activity['children'], 'depth' => count($activity['children'])]); + DI::logger()->notice('reply-to-id is already in the list of children', ['id' => $activity['reply-to-id'], 'children' => $activity['children'], 'depth' => count($activity['children'])]); return ''; } @@ -574,20 +573,20 @@ class Processor $recursion_depth = $activity['recursion-depth'] ?? 0; if (!$in_background && ($recursion_depth < DI::config()->get('system', 'max_recursion_depth'))) { - Logger::info('Parent not found. Try to refetch it.', ['completion' => $completion, 'recursion-depth' => $recursion_depth, 'parent' => $activity['reply-to-id']]); + DI::logger()->info('Parent not found. Try to refetch it.', ['completion' => $completion, 'recursion-depth' => $recursion_depth, 'parent' => $activity['reply-to-id']]); $result = self::fetchMissingActivity($activity['reply-to-id'], $activity, '', Receiver::COMPLETION_AUTO); if (empty($result) && self::isActivityGone($activity['reply-to-id'])) { - Logger::notice('The activity is gone, the queue entry will be deleted', ['parent' => $activity['reply-to-id']]); + DI::logger()->notice('The activity is gone, the queue entry will be deleted', ['parent' => $activity['reply-to-id']]); if (!empty($activity['entry-id'])) { Queue::deleteById($activity['entry-id']); } } elseif (!empty($result)) { $post = Post::selectFirstPost(['uri'], ['uri' => [$result, $activity['reply-to-id']]]); if (!empty($post['uri'])) { - Logger::info('The activity has been fetched and created.', ['result' => $result, 'uri' => $post['uri']]); + DI::logger()->info('The activity has been fetched and created.', ['result' => $result, 'uri' => $post['uri']]); return $post['uri']; } else { - Logger::notice('The activity exists but has not been created, the queue entry will be deleted.', ['parent' => $result]); + DI::logger()->notice('The activity exists but has not been created, the queue entry will be deleted.', ['parent' => $result]); if (!empty($activity['entry-id'])) { Queue::deleteById($activity['entry-id']); } @@ -595,7 +594,7 @@ class Processor } return ''; } elseif (self::isActivityGone($activity['reply-to-id'])) { - Logger::notice('The activity is gone. We will not spawn a worker. The queue entry will be deleted', ['parent' => $activity['reply-to-id']]); + DI::logger()->notice('The activity is gone. We will not spawn a worker. The queue entry will be deleted', ['parent' => $activity['reply-to-id']]); if ($in_background) { // fetching in background is done for all activities where we have got the conversation // There we only delete the single activity and not the whole thread since we can store the @@ -606,19 +605,19 @@ class Processor } return ''; } elseif ($in_background) { - Logger::notice('Fetching is done in the background.', ['parent' => $activity['reply-to-id']]); + DI::logger()->notice('Fetching is done in the background.', ['parent' => $activity['reply-to-id']]); } else { - Logger::notice('Recursion level is too high.', ['parent' => $activity['reply-to-id'], 'recursion-depth' => $recursion_depth]); + DI::logger()->notice('Recursion level is too high.', ['parent' => $activity['reply-to-id'], 'recursion-depth' => $recursion_depth]); } if (!Fetch::hasWorker($activity['reply-to-id'])) { - Logger::notice('Fetching is done by worker.', ['parent' => $activity['reply-to-id'], 'recursion-depth' => $recursion_depth]); + DI::logger()->notice('Fetching is done by worker.', ['parent' => $activity['reply-to-id'], 'recursion-depth' => $recursion_depth]); Fetch::add($activity['reply-to-id']); $activity['recursion-depth'] = 0; $wid = Worker::add(Worker::PRIORITY_HIGH, 'FetchMissingActivity', $activity['reply-to-id'], $activity, '', Receiver::COMPLETION_ASYNC); Fetch::setWorkerId($activity['reply-to-id'], $wid); } else { - Logger::debug('Activity will already be fetched via a worker.', ['url' => $activity['reply-to-id']]); + DI::logger()->debug('Activity will already be fetched via a worker.', ['url' => $activity['reply-to-id']]); } return ''; @@ -640,7 +639,7 @@ class Processor try { $curlResult = HTTPSignature::fetchRaw($url, 0); } catch (\Exception $exception) { - Logger::notice('Error fetching url', ['url' => $url, 'exception' => $exception]); + DI::logger()->notice('Error fetching url', ['url' => $url, 'exception' => $exception]); return true; } @@ -677,7 +676,7 @@ class Processor { $owner = Contact::getIdForURL($activity['actor']); - Logger::info('Deleting item', ['object' => $activity['object_id'], 'owner' => $owner]); + DI::logger()->info('Deleting item', ['object' => $activity['object_id'], 'owner' => $owner]); Item::markForDeletion(['uri' => $activity['object_id'], 'owner-id' => $owner]); Queue::remove($activity); } @@ -703,12 +702,12 @@ class Processor } if (($item['author-link'] != $activity['actor']) && !$item['origin']) { - Logger::info('Not origin, not from the author, skipping update', ['id' => $item['id'], 'author' => $item['author-link'], 'actor' => $activity['actor']]); + DI::logger()->info('Not origin, not from the author, skipping update', ['id' => $item['id'], 'author' => $item['author-link'], 'actor' => $activity['actor']]); continue; } Tag::store($item['uri-id'], Tag::HASHTAG, $activity['object_content'], $activity['object_id']); - Logger::info('Tagged item', ['id' => $item['id'], 'tag' => $activity['object_content'], 'uri' => $activity['target_id'], 'actor' => $activity['actor']]); + DI::logger()->info('Tagged item', ['id' => $item['id'], 'tag' => $activity['object_content'], 'uri' => $activity['target_id'], 'actor' => $activity['actor']]); } } @@ -725,7 +724,7 @@ class Processor $activity['reply-to-id'] = $activity['object_id']; $item = self::createItem($activity, false); if (empty($item)) { - Logger::debug('Activity was not prepared', ['id' => $activity['object_id']]); + DI::logger()->debug('Activity was not prepared', ['id' => $activity['object_id']]); return; } @@ -795,7 +794,7 @@ class Processor return; } - Logger::debug('Add post to featured collection', ['post' => $post]); + DI::logger()->debug('Add post to featured collection', ['post' => $post]); Post\Collection::add($post['uri-id'], Post\Collection::FEATURED, $post['author-id']); Queue::remove($activity); @@ -814,7 +813,7 @@ class Processor return; } - Logger::debug('Remove post from featured collection', ['post' => $post]); + DI::logger()->debug('Remove post from featured collection', ['post' => $post]); Post\Collection::remove($post['uri-id'], Post\Collection::FEATURED); Queue::remove($activity); @@ -860,7 +859,7 @@ class Processor $event_id = Event::store($event); - Logger::info('Event was stored', ['id' => $event_id]); + DI::logger()->info('Event was stored', ['id' => $event_id]); return $event_id; } @@ -907,15 +906,15 @@ class Processor if ($id) { $shared_item = Post::selectFirst(['uri-id'], ['id' => $id]); $item['quote-uri-id'] = $shared_item['uri-id']; - Logger::debug('Quote is found', ['guid' => $item['guid'], 'uri-id' => $item['uri-id'], 'quote' => $activity['quote-url'], 'quote-uri-id' => $item['quote-uri-id']]); + DI::logger()->debug('Quote is found', ['guid' => $item['guid'], 'uri-id' => $item['uri-id'], 'quote' => $activity['quote-url'], 'quote-uri-id' => $item['quote-uri-id']]); } elseif ($uri_id = ItemURI::getIdByURI($activity['quote-url'], false)) { - Logger::info('Quote was not fetched but the uri-id existed', ['guid' => $item['guid'], 'uri-id' => $item['uri-id'], 'quote' => $activity['quote-url'], 'quote-uri-id' => $uri_id]); + DI::logger()->info('Quote was not fetched but the uri-id existed', ['guid' => $item['guid'], 'uri-id' => $item['uri-id'], 'quote' => $activity['quote-url'], 'quote-uri-id' => $uri_id]); $item['quote-uri-id'] = $uri_id; } elseif (Queue::exists($activity['quote-url'], 'as:Create')) { $item['quote-uri-id'] = ItemURI::getIdByURI($activity['quote-url']); - Logger::info('Quote is queued but not processed yet', ['guid' => $item['guid'], 'uri-id' => $item['uri-id'], 'quote' => $activity['quote-url'], 'quote-uri-id' => $item['quote-uri-id']]); + DI::logger()->info('Quote is queued but not processed yet', ['guid' => $item['guid'], 'uri-id' => $item['uri-id'], 'quote' => $activity['quote-url'], 'quote-uri-id' => $item['quote-uri-id']]); } else { - Logger::notice('Quote was not fetched', ['guid' => $item['guid'], 'uri-id' => $item['uri-id'], 'quote' => $activity['quote-url']]); + DI::logger()->notice('Quote was not fetched', ['guid' => $item['guid'], 'uri-id' => $item['uri-id'], 'quote' => $activity['quote-url']]); } } @@ -934,7 +933,7 @@ class Processor if (empty($activity['directmessage']) && ($parent_uri != $item['uri']) && ($item['gravity'] == Item::GRAVITY_COMMENT)) { $parent = Post::selectFirst(['id', 'uri-id', 'private', 'author-link', 'alias'], ['uri' => $parent_uri]); if (!DBA::isResult($parent)) { - Logger::warning('Unknown parent item.', ['uri' => $parent_uri]); + DI::logger()->warning('Unknown parent item.', ['uri' => $parent_uri]); return false; } $content = self::removeImplicitMentionsFromBody($content, $parent); @@ -946,7 +945,7 @@ class Processor foreach (Tag::getFromBody($item['body'], Tag::TAG_CHARACTER[Tag::EXCLUSIVE_MENTION]) as $tag) { $actor = APContact::getByURL($tag[2], false); if (($actor['type'] ?? 'Person') == 'Group') { - Logger::debug('Group post detected via exclusive mention.', ['mention' => $actor['url'], 'actor' => $activity['actor'], 'author' => $activity['author']]); + DI::logger()->debug('Group post detected via exclusive mention.', ['mention' => $actor['url'], 'actor' => $activity['actor'], 'author' => $activity['author']]); $item['isGroup'] = true; $item['group-link'] = $item['owner-link'] = $actor['url']; $item['owner-id'] = Contact::getIdForURL($actor['url']); @@ -1042,38 +1041,38 @@ class Processor // The checks are split to improve the support when searching why a message was accepted. if (count($activity['receiver']) != 1) { // The message has more than one receiver, so it is wanted. - Logger::debug('Message has got several receivers - accepted', ['uri-id' => $item['uri-id'], 'guid' => $item['guid'], 'url' => $item['uri']]); + DI::logger()->debug('Message has got several receivers - accepted', ['uri-id' => $item['uri-id'], 'guid' => $item['guid'], 'url' => $item['uri']]); return true; } if ($item['private'] == Item::PRIVATE) { // We only look at public posts here. Private posts are expected to be intentionally posted to the single receiver. - Logger::debug('Message is private - accepted', ['uri-id' => $item['uri-id'], 'guid' => $item['guid'], 'url' => $item['uri']]); + DI::logger()->debug('Message is private - accepted', ['uri-id' => $item['uri-id'], 'guid' => $item['guid'], 'url' => $item['uri']]); return true; } if (!empty($activity['from-relay'])) { // We check relay posts at another place. When it arrived here, the message is already checked. - Logger::debug('Message is a relay post that is already checked - accepted', ['uri-id' => $item['uri-id'], 'guid' => $item['guid'], 'url' => $item['uri']]); + DI::logger()->debug('Message is a relay post that is already checked - accepted', ['uri-id' => $item['uri-id'], 'guid' => $item['guid'], 'url' => $item['uri']]); return true; } if (in_array($activity['completion-mode'] ?? Receiver::COMPLETION_NONE, [Receiver::COMPLETION_MANUAL, Receiver::COMPLETION_ANNOUNCE])) { // Manual completions and completions caused by reshares are allowed without any further checks. - Logger::debug('Message is in completion mode - accepted', ['mode' => $activity['completion-mode'], 'uri-id' => $item['uri-id'], 'guid' => $item['guid'], 'url' => $item['uri']]); + DI::logger()->debug('Message is in completion mode - accepted', ['mode' => $activity['completion-mode'], 'uri-id' => $item['uri-id'], 'guid' => $item['guid'], 'url' => $item['uri']]); return true; } if ($item['gravity'] != Item::GRAVITY_PARENT) { // We cannot reliably check at this point if a comment or activity belongs to an accepted post or needs to be fetched // This can possibly be improved in the future. - Logger::debug('Message is no parent - accepted', ['uri-id' => $item['uri-id'], 'guid' => $item['guid'], 'url' => $item['uri']]); + DI::logger()->debug('Message is no parent - accepted', ['uri-id' => $item['uri-id'], 'guid' => $item['guid'], 'url' => $item['uri']]); return true; } $tags = array_column(Tag::getByURIId($item['uri-id'], [Tag::HASHTAG]), 'name'); if (Relay::isSolicitedPost($tags, $item['title'] . ' ' . ($item['content-warning'] ?? '') . ' ' . $item['body'], $item['author-id'], $item['uri'], Protocol::ACTIVITYPUB, $activity['thread-completion'] ?? 0)) { - Logger::debug('Post is accepted because of the relay settings', ['uri-id' => $item['uri-id'], 'guid' => $item['guid'], 'url' => $item['uri']]); + DI::logger()->debug('Post is accepted because of the relay settings', ['uri-id' => $item['uri-id'], 'guid' => $item['guid'], 'url' => $item['uri']]); return true; } else { return false; @@ -1164,7 +1163,7 @@ class Processor } elseif (($item['post-reason'] == Item::PR_FOLLOWER) && !empty($activity['from-relay'])) { // When a post arrives via a relay and we follow the author, we have to override the causer. // Otherwise the system assumes that we follow the relay. (See "addRowInformation") - Logger::debug('Relay post for follower', ['receiver' => $receiver, 'guid' => $item['guid'], 'relay' => $activity['from-relay']]); + DI::logger()->debug('Relay post for follower', ['receiver' => $receiver, 'guid' => $item['guid'], 'relay' => $activity['from-relay']]); $item['causer-id'] = ($item['gravity'] == Item::GRAVITY_PARENT) ? $item['owner-id'] : $item['author-id']; } @@ -1189,13 +1188,13 @@ class Processor if (($receiver != 0) && ($item['gravity'] == Item::GRAVITY_PARENT) && !in_array($item['post-reason'], [Item::PR_FOLLOWER, Item::PR_TAG, Item::PR_TO, Item::PR_CC, Item::PR_AUDIENCE])) { if (!$item['isGroup']) { if ($item['post-reason'] == Item::PR_BCC) { - Logger::info('Top level post via BCC from a non sharer, ignoring', ['uid' => $receiver, 'contact' => $item['contact-id'], 'url' => $item['uri']]); + DI::logger()->info('Top level post via BCC from a non sharer, ignoring', ['uid' => $receiver, 'contact' => $item['contact-id'], 'url' => $item['uri']]); continue; } if ((DI::pConfig()->get($receiver, 'system', 'accept_only_sharer') != Item::COMPLETION_LIKE) && in_array($activity['thread-children-type'] ?? '', Receiver::ACTIVITY_TYPES)) { - Logger::info('Top level post from thread completion from a non sharer had been initiated via an activity, ignoring', + DI::logger()->info('Top level post from thread completion from a non sharer had been initiated via an activity, ignoring', ['type' => $activity['thread-children-type'], 'user' => $item['uid'], 'causer' => $item['causer-link'], 'author' => $activity['author'], 'url' => $item['uri']]); continue; } @@ -1210,11 +1209,11 @@ class Processor if ((DI::pConfig()->get($receiver, 'system', 'accept_only_sharer') == Item::COMPLETION_NONE) && ((!$isGroup && !$item['isGroup'] && ($activity['type'] != 'as:Announce')) || !Contact::isSharingByURL($activity['actor'], $receiver))) { - Logger::info('Actor is a non sharer, is no group or it is no announce', ['uid' => $receiver, 'actor' => $activity['actor'], 'url' => $item['uri'], 'type' => $activity['type']]); + DI::logger()->info('Actor is a non sharer, is no group or it is no announce', ['uid' => $receiver, 'actor' => $activity['actor'], 'url' => $item['uri'], 'type' => $activity['type']]); continue; } - Logger::info('Accepting post', ['uid' => $receiver, 'url' => $item['uri']]); + DI::logger()->info('Accepting post', ['uid' => $receiver, 'url' => $item['uri']]); } if (!self::hasParents($item, $receiver)) { @@ -1229,12 +1228,12 @@ class Processor $item_id = Item::insert($item); if ($item_id) { - Logger::info('Item insertion successful', ['user' => $item['uid'], 'item_id' => $item_id]); + DI::logger()->info('Item insertion successful', ['user' => $item['uid'], 'item_id' => $item_id]); $success = true; } else { - Logger::notice('Item insertion aborted', ['uri' => $item['uri'], 'uid' => $item['uid']]); + DI::logger()->notice('Item insertion aborted', ['uri' => $item['uri'], 'uid' => $item['uid']]); if (($item['uid'] == 0) && (count($activity['receiver']) > 1)) { - Logger::info('Public item was aborted. We skip for all users.', ['uri' => $item['uri']]); + DI::logger()->info('Public item was aborted. We skip for all users.', ['uri' => $item['uri']]); break; } } @@ -1255,7 +1254,7 @@ class Processor $author = APContact::getByURL($item['owner-link'], false); // We send automatic follow requests for reshared messages. (We don't need though for group posts) if ($author['type'] != 'Group') { - Logger::info('Send follow request', ['uri' => $item['uri'], 'stored' => $stored, 'to' => $item['author-link']]); + DI::logger()->info('Send follow request', ['uri' => $item['uri'], 'stored' => $stored, 'to' => $item['author-link']]); ActivityPub\Transmitter::sendFollowObject($item['uri'], $item['author-link']); } } @@ -1314,15 +1313,15 @@ class Processor $stored = Item::storeForUserByUriId($item['parent-uri-id'], $receiver, $fields); $has_parents = (bool)$stored; if ($stored) { - Logger::notice('Inserted missing parent post', ['stored' => $stored, 'uid' => $receiver, 'parent' => $item['parent-uri']]); + DI::logger()->notice('Inserted missing parent post', ['stored' => $stored, 'uid' => $receiver, 'parent' => $item['parent-uri']]); } else { - Logger::notice('Parent could not be added.', ['uid' => $receiver, 'uri' => $item['uri'], 'parent' => $item['parent-uri']]); + DI::logger()->notice('Parent could not be added.', ['uid' => $receiver, 'uri' => $item['uri'], 'parent' => $item['parent-uri']]); return false; } } elseif ($add_parent) { - Logger::debug('Parent does not exist.', ['uid' => $receiver, 'uri' => $item['uri'], 'parent' => $item['parent-uri']]); + DI::logger()->debug('Parent does not exist.', ['uid' => $receiver, 'uri' => $item['uri'], 'parent' => $item['parent-uri']]); } else { - Logger::debug('Parent should not be added.', ['uid' => $receiver, 'gravity' => $item['gravity'], 'verb' => $item['verb'], 'guid' => $item['guid'], 'uri' => $item['uri'], 'parent' => $item['parent-uri']]); + DI::logger()->debug('Parent should not be added.', ['uid' => $receiver, 'gravity' => $item['gravity'], 'verb' => $item['verb'], 'guid' => $item['guid'], 'uri' => $item['uri'], 'parent' => $item['parent-uri']]); } } @@ -1333,14 +1332,14 @@ class Processor $stored = Item::storeForUserByUriId($item['thr-parent-id'], $receiver, $fields); $has_parents = $has_parents || (bool)$stored; if ($stored) { - Logger::notice('Inserted missing thread parent post', ['stored' => $stored, 'uid' => $receiver, 'thread-parent' => $item['thr-parent']]); + DI::logger()->notice('Inserted missing thread parent post', ['stored' => $stored, 'uid' => $receiver, 'thread-parent' => $item['thr-parent']]); } else { - Logger::notice('Thread parent could not be added.', ['uid' => $receiver, 'uri' => $item['uri'], 'thread-parent' => $item['thr-parent']]); + DI::logger()->notice('Thread parent could not be added.', ['uid' => $receiver, 'uri' => $item['uri'], 'thread-parent' => $item['thr-parent']]); } } elseif ($add_parent) { - Logger::debug('Thread parent does not exist.', ['uid' => $receiver, 'uri' => $item['uri'], 'thread-parent' => $item['thr-parent']]); + DI::logger()->debug('Thread parent does not exist.', ['uid' => $receiver, 'uri' => $item['uri'], 'thread-parent' => $item['thr-parent']]); } else { - Logger::debug('Thread parent should not be added.', ['uid' => $receiver, 'gravity' => $item['gravity'], 'verb' => $item['verb'], 'guid' => $item['guid'], 'uri' => $item['uri'], 'thread-parent' => $item['thr-parent']]); + DI::logger()->debug('Thread parent should not be added.', ['uid' => $receiver, 'gravity' => $item['gravity'], 'verb' => $item['verb'], 'guid' => $item['guid'], 'uri' => $item['uri'], 'thread-parent' => $item['thr-parent']]); } } @@ -1403,12 +1402,12 @@ class Processor } elseif ($host = parse_url($receiver, PHP_URL_HOST)) { $name = $host; } else { - Logger::warning('Unable to coerce name from receiver', ['element' => $element, 'type' => $type, 'receiver' => $receiver]); + DI::logger()->warning('Unable to coerce name from receiver', ['element' => $element, 'type' => $type, 'receiver' => $receiver]); $name = ''; } $target = Tag::getTargetType($receiver); - Logger::debug('Got target type', ['type' => $target, 'url' => $receiver]); + DI::logger()->debug('Got target type', ['type' => $target, 'url' => $receiver]); Tag::store($uriid, $type, $name, $receiver, $target); } } @@ -1429,7 +1428,7 @@ class Processor } elseif ($host = parse_url($capability, PHP_URL_HOST)) { $name = $host; } else { - Logger::warning('Unable to coerce name from capability', ['element' => $element, 'type' => $type, 'capability' => $capability]); + DI::logger()->warning('Unable to coerce name from capability', ['element' => $element, 'type' => $type, 'capability' => $capability]); $name = ''; } $restricted = false; @@ -1452,16 +1451,16 @@ class Processor private static function postMail(array $item) { if (($item['gravity'] != Item::GRAVITY_PARENT) && !DBA::exists('mail', ['uri' => $item['thr-parent'], 'uid' => $item['uid']])) { - Logger::info('Parent not found, mail will be discarded.', ['uid' => $item['uid'], 'uri' => $item['thr-parent']]); + DI::logger()->info('Parent not found, mail will be discarded.', ['uid' => $item['uid'], 'uri' => $item['thr-parent']]); return false; } if (!Contact::isFollower($item['contact-id'], $item['uid']) && !Contact::isSharing($item['contact-id'], $item['uid'])) { - Logger::info('Contact is not a sharer or follower, mail will be discarded.', ['item' => $item]); + DI::logger()->info('Contact is not a sharer or follower, mail will be discarded.', ['item' => $item]); return false; } - Logger::info('Direct Message', $item); + DI::logger()->info('Direct Message', $item); $msg = []; $msg['uid'] = $item['uid']; @@ -1517,17 +1516,17 @@ class Processor */ public static function fetchFeaturedPosts(string $url) { - Logger::info('Fetch featured posts', ['contact' => $url]); + DI::logger()->info('Fetch featured posts', ['contact' => $url]); $apcontact = APContact::getByURL($url); if (empty($apcontact['featured'])) { - Logger::info('Contact does not have a featured collection', ['contact' => $url]); + DI::logger()->info('Contact does not have a featured collection', ['contact' => $url]); return; } $pcid = Contact::getIdForURL($url, 0, false); if (empty($pcid)) { - Logger::notice('Contact not found', ['contact' => $url]); + DI::logger()->notice('Contact not found', ['contact' => $url]); return; } @@ -1540,11 +1539,11 @@ class Processor $featured = ActivityPub::fetchItems($apcontact['featured']); if (empty($featured)) { - Logger::info('Contact does not have featured posts', ['contact' => $url]); + DI::logger()->info('Contact does not have featured posts', ['contact' => $url]); foreach ($old_featured as $uri_id) { Post\Collection::remove($uri_id, Post\Collection::FEATURED); - Logger::debug('Removed no longer featured post', ['uri-id' => $uri_id, 'contact' => $url]); + DI::logger()->debug('Removed no longer featured post', ['uri-id' => $uri_id, 'contact' => $url]); } return; } @@ -1562,10 +1561,10 @@ class Processor if (!empty($item['uri-id'])) { if (!$item['featured']) { Post\Collection::add($item['uri-id'], Post\Collection::FEATURED, $item['author-id']); - Logger::debug('Added featured post', ['uri-id' => $item['uri-id'], 'contact' => $url]); + DI::logger()->debug('Added featured post', ['uri-id' => $item['uri-id'], 'contact' => $url]); $new++; } else { - Logger::debug('Post already had been featured', ['uri-id' => $item['uri-id'], 'contact' => $url]); + DI::logger()->debug('Post already had been featured', ['uri-id' => $item['uri-id'], 'contact' => $url]); $old++; } @@ -1579,10 +1578,10 @@ class Processor foreach ($old_featured as $uri_id) { Post\Collection::remove($uri_id, Post\Collection::FEATURED); - Logger::debug('Removed no longer featured post', ['uri-id' => $uri_id, 'contact' => $url]); + DI::logger()->debug('Removed no longer featured post', ['uri-id' => $uri_id, 'contact' => $url]); } - Logger::info('Fetched featured posts', ['new' => $new, 'old' => $old, 'contact' => $url]); + DI::logger()->info('Fetched featured posts', ['new' => $new, 'old' => $old, 'contact' => $url]); } public static function fetchCachedActivity(string $url, int $uid): array @@ -1592,9 +1591,9 @@ class Processor if (!is_null($object)) { if (!empty($object)) { - Logger::debug('Fetch from cache', ['url' => $url, 'uid' => $uid]); + DI::logger()->debug('Fetch from cache', ['url' => $url, 'uid' => $uid]); } else { - Logger::debug('Fetch from negative cache', ['url' => $url, 'uid' => $uid]); + DI::logger()->debug('Fetch from negative cache', ['url' => $url, 'uid' => $uid]); } return $object; } @@ -1606,14 +1605,14 @@ class Processor } if (empty($object)) { - Logger::notice('Activity was not fetchable, aborting.', ['url' => $url, 'uid' => $uid]); + DI::logger()->notice('Activity was not fetchable, aborting.', ['url' => $url, 'uid' => $uid]); // We perform negative caching. DI::cache()->set($cachekey, [], Duration::FIVE_MINUTES); return []; } if (empty($object['id'])) { - Logger::notice('Activity has got not id, aborting. ', ['url' => $url, 'object' => $object]); + DI::logger()->notice('Activity has got not id, aborting. ', ['url' => $url, 'object' => $object]); return []; } @@ -1623,7 +1622,7 @@ class Processor DI::cache()->set($cachekey, $object, Duration::FIVE_MINUTES); - Logger::debug('Activity was fetched successfully', ['url' => $url, 'uid' => $uid]); + DI::logger()->debug('Activity was fetched successfully', ['url' => $url, 'uid' => $uid]); return $object; } @@ -1647,14 +1646,14 @@ class Processor } if (!empty($child['children']) && in_array($url, $child['children'])) { - Logger::notice('id is already in the list of children', ['depth' => count($child['children']), 'children' => $child['children'], 'id' => $url]); + DI::logger()->notice('id is already in the list of children', ['depth' => count($child['children']), 'children' => $child['children'], 'id' => $url]); return null; } try { $curlResult = HTTPSignature::fetchRaw($url, $uid); } catch (\Exception $exception) { - Logger::notice('Error fetching url', ['url' => $url, 'exception' => $exception]); + DI::logger()->notice('Error fetching url', ['url' => $url, 'exception' => $exception]); return ''; } @@ -1673,7 +1672,7 @@ class Processor } if (empty($object) || !is_array($object)) { - Logger::notice('Invalid JSON data', ['url' => $url, 'content-type' => $curlResult->getContentType()]); + DI::logger()->notice('Invalid JSON data', ['url' => $url, 'content-type' => $curlResult->getContentType()]); return null; } @@ -1724,7 +1723,7 @@ class Processor if (Item::searchByLink($object_id)) { return $object_id; } - Logger::debug('Fetch announced activity', ['type' => $type, 'id' => $object_id, 'actor' => $relay_actor, 'signer' => $signer]); + DI::logger()->debug('Fetch announced activity', ['type' => $type, 'id' => $object_id, 'actor' => $relay_actor, 'signer' => $signer]); if (!self::alreadyKnown($object_id, $child['id'] ?? '')) { $child['callstack'] = self::addToCallstack($child['callstack'] ?? []); @@ -1745,7 +1744,7 @@ class Processor $ldactivity['callstack'] = $child['callstack'] ?? []; // This check is mostly superfluous, since there are similar checks before. This covers the case, when the fetched id doesn't match the url if (in_array($activity['id'], $ldactivity['children'])) { - Logger::notice('Fetched id is already in the list of children. It will not be processed.', ['id' => $activity['id'], 'children' => $ldactivity['children'], 'depth' => count($ldactivity['children'])]); + DI::logger()->notice('Fetched id is already in the list of children. It will not be processed.', ['id' => $activity['id'], 'children' => $ldactivity['children'], 'depth' => count($ldactivity['children'])]); return null; } if (!empty($child['id'])) { @@ -1783,11 +1782,11 @@ class Processor } if (($completion == Receiver::COMPLETION_RELAY) && Queue::exists($url, 'as:Create')) { - Logger::info('Activity has already been queued.', ['url' => $url, 'object' => $activity['id']]); + DI::logger()->info('Activity has already been queued.', ['url' => $url, 'object' => $activity['id']]); } elseif (ActivityPub\Receiver::processActivity($ldactivity, json_encode($activity), $uid, true, false, $signer, '', $completion)) { - Logger::info('Activity had been fetched and processed.', ['url' => $url, 'entry' => $child['entry-id'] ?? 0, 'completion' => $completion, 'object' => $activity['id']]); + DI::logger()->info('Activity had been fetched and processed.', ['url' => $url, 'entry' => $child['entry-id'] ?? 0, 'completion' => $completion, 'object' => $activity['id']]); } else { - Logger::info('Activity had been fetched and will be processed later.', ['url' => $url, 'entry' => $child['entry-id'] ?? 0, 'completion' => $completion, 'object' => $activity['id']]); + DI::logger()->info('Activity had been fetched and will be processed later.', ['url' => $url, 'entry' => $child['entry-id'] ?? 0, 'completion' => $completion, 'object' => $activity['id']]); } return $activity['id']; @@ -1812,7 +1811,7 @@ class Processor $maximum_fetchreplies_depth = DI::config()->get('system', 'max_fetchreplies_depth'); if (max($callstack_count, $system_count) == $maximum_fetchreplies_depth) { - Logger::notice('Maximum callstack depth reached', ['max' => $maximum_fetchreplies_depth, 'count' => $callstack_count, 'system-count' => $system_count, 'replies' => $url, 'callstack' => $child['callstack'] ?? [], 'system' => $callstack]); + DI::logger()->notice('Maximum callstack depth reached', ['max' => $maximum_fetchreplies_depth, 'count' => $callstack_count, 'system-count' => $system_count, 'replies' => $url, 'callstack' => $child['callstack'] ?? [], 'system' => $callstack]); return; } @@ -1820,10 +1819,10 @@ class Processor $replies = ActivityPub::fetchItems($url); if (empty($replies)) { - Logger::notice('No replies', ['replies' => $url]); + DI::logger()->notice('No replies', ['replies' => $url]); return; } - Logger::notice('Fetch replies - start', ['replies' => $url, 'callstack' => $child['callstack'], 'system' => $callstack]); + DI::logger()->notice('Fetch replies - start', ['replies' => $url, 'callstack' => $child['callstack'], 'system' => $callstack]); $fetched = 0; foreach ($replies as $reply) { $id = ''; @@ -1835,11 +1834,11 @@ class Processor continue; } if (!empty($child['children']) && in_array($id, $child['children'])) { - Logger::debug('Replies id is already in the list of children', ['depth' => count($child['children']), 'children' => $child['children'], 'id' => $id]); + DI::logger()->debug('Replies id is already in the list of children', ['depth' => count($child['children']), 'children' => $child['children'], 'id' => $id]); continue; } if (parse_url($id, PHP_URL_HOST) == parse_url($url, PHP_URL_HOST)) { - Logger::debug('Incluced activity will be processed', ['replies' => $url, 'id' => $id]); + DI::logger()->debug('Incluced activity will be processed', ['replies' => $url, 'id' => $id]); self::processActivity($reply, $id, $child, '', Receiver::COMPLETION_REPLIES); ++$fetched; continue; @@ -1852,22 +1851,22 @@ class Processor ++$fetched; } } - Logger::notice('Fetch replies - done', ['fetched' => $fetched, 'total' => count($replies), 'replies' => $url]); + DI::logger()->notice('Fetch replies - done', ['fetched' => $fetched, 'total' => count($replies), 'replies' => $url]); } public static function alreadyKnown(string $id, string $child): bool { if ($id == $child) { - Logger::debug('Activity is currently processed', ['id' => $id, 'child' => $child]); + DI::logger()->debug('Activity is currently processed', ['id' => $id, 'child' => $child]); return true; } elseif (Item::searchByLink($id)) { - Logger::debug('Activity already exists', ['id' => $id, 'child' => $child]); + DI::logger()->debug('Activity already exists', ['id' => $id, 'child' => $child]); return true; } elseif (Queue::exists($id, 'as:Create')) { - Logger::debug('Activity is already queued', ['id' => $id, 'child' => $child]); + DI::logger()->debug('Activity is already queued', ['id' => $id, 'child' => $child]); return true; } - Logger::debug('Activity is unknown', ['id' => $id, 'child' => $child]); + DI::logger()->debug('Activity is unknown', ['id' => $id, 'child' => $child]); return false; } @@ -1875,13 +1874,13 @@ class Processor { $ldobject = JsonLD::compact($object); if (empty($ldobject)) { - Logger::info('Invalid object', ['url' => $url]); + DI::logger()->info('Invalid object', ['url' => $url]); return $object; } $id = JsonLD::fetchElement($ldobject, '@id'); if (empty($id)) { - Logger::info('No id found in object', ['url' => $url, 'object' => $object]); + DI::logger()->info('No id found in object', ['url' => $url, 'object' => $object]); return $object; } @@ -1892,7 +1891,7 @@ class Processor return $object; } - Logger::notice('Refetch activity because of a host mismatch between requested and received id', ['url-host' => $url_host, 'id-host' => $id_host, 'url' => $url, 'id' => $id]); + DI::logger()->notice('Refetch activity because of a host mismatch between requested and received id', ['url-host' => $url_host, 'id-host' => $id_host, 'url' => $url, 'id' => $id]); return HTTPSignature::fetch($id); } @@ -1900,13 +1899,13 @@ class Processor { $ldobject = JsonLD::compact($object); if (empty($ldobject)) { - Logger::info('Invalid object'); + DI::logger()->info('Invalid object'); return false; } $id = JsonLD::fetchElement($ldobject, '@id'); if (empty($id)) { - Logger::info('No id found in object'); + DI::logger()->info('No id found in object'); return false; } @@ -1921,7 +1920,7 @@ class Processor if (!empty($actor) && !in_array($type, Receiver::CONTENT_TYPES) && !empty($object_id)) { $actor_host = parse_url($actor, PHP_URL_HOST); if ($actor_host != $id_host) { - Logger::notice('Host mismatch between received id and actor', ['id-host' => $id_host, 'actor-host' => $actor_host, 'id' => $id, 'type' => $type, 'object-id' => $object_id, 'object_type' => $object_type, 'actor' => $actor, 'attributed_to' => $attributed_to]); + DI::logger()->notice('Host mismatch between received id and actor', ['id-host' => $id_host, 'actor-host' => $actor_host, 'id' => $id, 'type' => $type, 'object-id' => $object_id, 'object_type' => $object_type, 'actor' => $actor, 'attributed_to' => $attributed_to]); return false; } if (!empty($object_type)) { @@ -1929,14 +1928,14 @@ class Processor $attributed_to_host = parse_url($object_attributed_to, PHP_URL_HOST); $object_id_host = parse_url($object_id, PHP_URL_HOST); if (!empty($attributed_to_host) && ($attributed_to_host != $object_id_host)) { - Logger::notice('Host mismatch between received object id and attributed actor', ['id-object-host' => $object_id_host, 'attributed-host' => $attributed_to_host, 'id' => $id, 'type' => $type, 'object-id' => $object_id, 'object_type' => $object_type, 'actor' => $actor, 'object_attributed_to' => $object_attributed_to]); + DI::logger()->notice('Host mismatch between received object id and attributed actor', ['id-object-host' => $object_id_host, 'attributed-host' => $attributed_to_host, 'id' => $id, 'type' => $type, 'object-id' => $object_id, 'object_type' => $object_type, 'actor' => $actor, 'object_attributed_to' => $object_attributed_to]); return false; } } } elseif (!empty($attributed_to)) { $attributed_to_host = parse_url($attributed_to, PHP_URL_HOST); if ($attributed_to_host != $id_host) { - Logger::notice('Host mismatch between received id and attributed actor', ['id-host' => $id_host, 'attributed-host' => $attributed_to_host, 'id' => $id, 'type' => $type, 'object-id' => $object_id, 'object_type' => $object_type, 'actor' => $actor, 'attributed_to' => $attributed_to]); + DI::logger()->notice('Host mismatch between received id and attributed actor', ['id-host' => $id_host, 'attributed-host' => $attributed_to_host, 'id' => $id, 'type' => $type, 'object-id' => $object_id, 'object_type' => $object_type, 'actor' => $actor, 'attributed_to' => $attributed_to]); return false; } } @@ -1977,7 +1976,7 @@ class Processor { if (empty($activity['as:object'])) { $id = JsonLD::fetchElement($activity, '@id'); - Logger::info('No object field in activity - accepted', ['id' => $id]); + DI::logger()->info('No object field in activity - accepted', ['id' => $id]); return true; } @@ -1986,7 +1985,7 @@ class Processor $replyto = JsonLD::fetchElement($activity['as:object'], 'as:inReplyTo', '@id'); $uriid = ItemURI::getIdByURI($replyto ?? ''); if (Post::exists(['uri-id' => $uriid])) { - Logger::info('Post is a reply to an existing post - accepted', ['id' => $id, 'uri-id' => $uriid, 'replyto' => $replyto]); + DI::logger()->info('Post is a reply to an existing post - accepted', ['id' => $id, 'uri-id' => $uriid, 'replyto' => $replyto]); return true; } @@ -2121,7 +2120,7 @@ class Processor Contact::update(['hub-verify' => $activity['id'], 'protocol' => Protocol::ACTIVITYPUB], ['id' => $cid]); - Logger::notice('Follow user ' . $uid . ' from contact ' . $cid . ' with id ' . $activity['id']); + DI::logger()->notice('Follow user ' . $uid . ' from contact ' . $cid . ' with id ' . $activity['id']); Queue::remove($activity); } @@ -2164,7 +2163,7 @@ class Processor return; } - Logger::info('Updating profile', ['object' => $activity['object_id']]); + DI::logger()->info('Updating profile', ['object' => $activity['object_id']]); Contact::updateFromProbeByURL($activity['object_id']); Queue::remove($activity); } @@ -2179,13 +2178,13 @@ class Processor public static function deletePerson(array $activity) { if (empty($activity['object_id']) || empty($activity['actor'])) { - Logger::info('Empty object id or actor.'); + DI::logger()->info('Empty object id or actor.'); Queue::remove($activity); return; } if ($activity['object_id'] != $activity['actor']) { - Logger::info('Object id does not match actor.'); + DI::logger()->info('Object id does not match actor.'); Queue::remove($activity); return; } @@ -2196,7 +2195,7 @@ class Processor } DBA::close($contacts); - Logger::info('Deleted contact', ['object' => $activity['object_id']]); + DI::logger()->info('Deleted contact', ['object' => $activity['object_id']]); Queue::remove($activity); } @@ -2215,14 +2214,14 @@ class Processor } if ($activity['object_id'] != $activity['actor']) { - Logger::notice('Object is not the actor', ['activity' => $activity]); + DI::logger()->notice('Object is not the actor', ['activity' => $activity]); Queue::remove($activity); return; } $from = Contact::getByURL($activity['object_id'], false, ['uri-id']); if (empty($from['uri-id'])) { - Logger::info('Object not found', ['activity' => $activity]); + DI::logger()->info('Object not found', ['activity' => $activity]); Queue::remove($activity); return; } @@ -2230,7 +2229,7 @@ class Processor $contacts = DBA::select('contact', ['uid', 'url'], ["`uri-id` = ? AND `uid` != ? AND `rel` IN (?, ?)", $from['uri-id'], 0, Contact::FRIEND, Contact::SHARING]); while ($from_contact = DBA::fetch($contacts)) { $result = Contact::createFromProbeForUser($from_contact['uid'], $activity['target_id']); - Logger::debug('Follower added', ['from' => $from_contact, 'result' => $result]); + DI::logger()->debug('Follower added', ['from' => $from_contact, 'result' => $result]); } DBA::close($contacts); Queue::remove($activity); @@ -2257,7 +2256,7 @@ class Processor Contact\User::setIsBlocked($cid, $uid, true); - Logger::info('Contact blocked user', ['contact' => $cid, 'user' => $uid]); + DI::logger()->info('Contact blocked user', ['contact' => $cid, 'user' => $uid]); Queue::remove($activity); } @@ -2282,7 +2281,7 @@ class Processor Contact\User::setIsBlocked($cid, $uid, false); - Logger::info('Contact unblocked user', ['contact' => $cid, 'user' => $uid]); + DI::logger()->info('Contact unblocked user', ['contact' => $cid, 'user' => $uid]); Queue::remove($activity); } @@ -2297,14 +2296,14 @@ class Processor { $account = Contact::getByURL($activity['object_id'], null, ['id', 'gsid']); if (empty($account)) { - Logger::info('Unknown account', ['activity' => $activity]); + DI::logger()->info('Unknown account', ['activity' => $activity]); Queue::remove($activity); return; } $reporter_id = Contact::getIdForURL($activity['actor']); if (empty($reporter_id)) { - Logger::info('Unknown actor', ['activity' => $activity]); + DI::logger()->info('Unknown actor', ['activity' => $activity]); Queue::remove($activity); return; } @@ -2320,7 +2319,7 @@ class Processor $report = DI::reportFactory()->createFromReportsRequest(System::getRules(true), $reporter_id, $account['id'], $account['gsid'], $activity['content'], 'other', false, $uri_ids); DI::report()->save($report); - Logger::info('Stored report', ['reporter' => $reporter_id, 'account' => $account, 'comment' => $activity['content'], 'object_ids' => $activity['object_ids']]); + DI::logger()->info('Stored report', ['reporter' => $reporter_id, 'account' => $account, 'comment' => $activity['content'], 'object_ids' => $activity['object_ids']]); } /** @@ -2342,23 +2341,23 @@ class Processor } if (empty($uid)) { - Logger::notice('User could not be detected', ['activity' => $activity]); + DI::logger()->notice('User could not be detected', ['activity' => $activity]); Queue::remove($activity); return; } $cid = Contact::getIdForURL($activity['actor'], $uid); if (empty($cid)) { - Logger::notice('No contact found', ['actor' => $activity['actor']]); + DI::logger()->notice('No contact found', ['actor' => $activity['actor']]); Queue::remove($activity); return; } $id = Transmitter::activityIDFromContact($cid); if ($id == $activity['object_id']) { - Logger::info('Successful id check', ['uid' => $uid, 'cid' => $cid]); + DI::logger()->info('Successful id check', ['uid' => $uid, 'cid' => $cid]); } else { - Logger::info('Unsuccessful id check', ['uid' => $uid, 'cid' => $cid, 'id' => $id, 'object_id' => $activity['object_id']]); + DI::logger()->info('Unsuccessful id check', ['uid' => $uid, 'cid' => $cid, 'id' => $id, 'object_id' => $activity['object_id']]); if ($check_id) { Queue::remove($activity); return; @@ -2376,7 +2375,7 @@ class Processor $condition = ['id' => $cid]; Contact::update($fields, $condition); - Logger::info('Accept contact request', ['contact' => $cid, 'user' => $uid]); + DI::logger()->info('Accept contact request', ['contact' => $cid, 'user' => $uid]); Queue::remove($activity); } @@ -2396,7 +2395,7 @@ class Processor $cid = Contact::getIdForURL($activity['actor'], $uid); if (empty($cid)) { - Logger::info('No contact found', ['actor' => $activity['actor']]); + DI::logger()->info('No contact found', ['actor' => $activity['actor']]); return; } @@ -2405,11 +2404,11 @@ class Processor $contact = Contact::getById($cid, ['rel']); if ($contact['rel'] == Contact::SHARING) { Contact::remove($cid); - Logger::info('Rejected contact request - contact removed', ['contact' => $cid, 'user' => $uid]); + DI::logger()->info('Rejected contact request - contact removed', ['contact' => $cid, 'user' => $uid]); } elseif ($contact['rel'] == Contact::FRIEND) { Contact::update(['rel' => Contact::FOLLOWER], ['id' => $cid]); } else { - Logger::info('Rejected contact request', ['contact' => $cid, 'user' => $uid]); + DI::logger()->info('Rejected contact request', ['contact' => $cid, 'user' => $uid]); } Queue::remove($activity); } @@ -2461,7 +2460,7 @@ class Processor $cid = Contact::getIdForURL($activity['actor'], $uid); if (empty($cid)) { - Logger::info('No contact found', ['actor' => $activity['actor']]); + DI::logger()->info('No contact found', ['actor' => $activity['actor']]); return; } @@ -2473,7 +2472,7 @@ class Processor } Contact::removeFollower($contact); - Logger::info('Undo following request', ['contact' => $cid, 'user' => $uid]); + DI::logger()->info('Undo following request', ['contact' => $cid, 'user' => $uid]); Queue::remove($activity); } @@ -2491,7 +2490,7 @@ class Processor return; } - Logger::info('Change existing contact', ['cid' => $cid, 'previous' => $contact['network']]); + DI::logger()->info('Change existing contact', ['cid' => $cid, 'previous' => $contact['network']]); Contact::updateFromProbe($cid); } @@ -2512,7 +2511,7 @@ class Processor $implicit_mentions = []; if (empty($parent_author['url'])) { - Logger::notice('Author public contact unknown.', ['author-link' => $parent['author-link'], 'parent-id' => $parent['id']]); + DI::logger()->notice('Author public contact unknown.', ['author-link' => $parent['author-link'], 'parent-id' => $parent['id']]); } else { $implicit_mentions[] = $parent_author['url']; $implicit_mentions[] = $parent_author['nurl']; @@ -2616,7 +2615,7 @@ class Processor $function = array_shift($functions); if (in_array($function, $callstack)) { - Logger::notice('Callstack already contains "' . $function . '"', ['callstack' => $callstack]); + DI::logger()->notice('Callstack already contains "' . $function . '"', ['callstack' => $callstack]); } $callstack[] = $function; diff --git a/src/Protocol/ActivityPub/Queue.php b/src/Protocol/ActivityPub/Queue.php index 8d78620c3e..bf89363de7 100644 --- a/src/Protocol/ActivityPub/Queue.php +++ b/src/Protocol/ActivityPub/Queue.php @@ -7,7 +7,6 @@ namespace Friendica\Protocol\ActivityPub; -use Friendica\Core\Logger; use Friendica\Core\Worker; use Friendica\Database\Database; use Friendica\Database\DBA; @@ -129,7 +128,7 @@ class Queue return; } - Logger::debug('Delete inbox-entry', ['id' => $entry['id']]); + DI::logger()->debug('Delete inbox-entry', ['id' => $entry['id']]); DBA::delete('inbox-entry', ['id' => $entry['id']]); @@ -187,7 +186,7 @@ class Queue } if (!self::isProcessable($id)) { - Logger::debug('Other queue entries need to be processed first.', ['id' => $id]); + DI::logger()->debug('Other queue entries need to be processed first.', ['id' => $id]); return false; } @@ -197,13 +196,13 @@ class Queue if ($entry['wid'] != $wid) { $workerqueue = DBA::selectFirst('workerqueue', ['pid'], ['id' => $entry['wid'], 'done' => false]); if (!empty($workerqueue['pid']) && posix_kill($workerqueue['pid'], 0)) { - Logger::notice('Entry is already processed via another process.', ['current' => $wid, 'processor' => $entry['wid']]); + DI::logger()->notice('Entry is already processed via another process.', ['current' => $wid, 'processor' => $entry['wid']]); return false; } } } - Logger::debug('Processing queue entry', ['id' => $entry['id'], 'type' => $entry['type'], 'object-type' => $entry['object-type'], 'uri' => $entry['object-id'], 'in-reply-to' => $entry['in-reply-to-id']]); + DI::logger()->debug('Processing queue entry', ['id' => $entry['id'], 'type' => $entry['type'], 'object-type' => $entry['object-type'], 'uri' => $entry['object-id'], 'in-reply-to' => $entry['in-reply-to-id']]); $activity = json_decode($entry['activity'], true); $type = $entry['type']; @@ -259,16 +258,16 @@ class Queue if (!$entry['trust'] || !self::isProcessable($entry['id'])) { continue; } - Logger::debug('Process leftover entry', $entry); + DI::logger()->debug('Process leftover entry', $entry); self::process($entry['id'], false); } DBA::close($entries); // Optimizing this table only last seconds if (DI::config()->get('system', 'optimize_tables')) { - Logger::info('Optimize start'); + DI::logger()->info('Optimize start'); DBA::optimizeTable('inbox-entry'); - Logger::info('Optimize end'); + DI::logger()->info('Optimize end'); } } @@ -316,14 +315,14 @@ class Queue if (!Processor::alreadyKnown($entry['in-reply-to-id'], '')) { // This entry belongs to some other entry that need to be fetched first if (Fetch::hasWorker($entry['in-reply-to-id'])) { - Logger::debug('Fetching of the activity is already queued', ['id' => $entry['activity-id'], 'reply-to-id' => $entry['in-reply-to-id']]); + DI::logger()->debug('Fetching of the activity is already queued', ['id' => $entry['activity-id'], 'reply-to-id' => $entry['in-reply-to-id']]); self::retrial($id); return false; } Fetch::add($entry['in-reply-to-id']); $activity = json_decode($entry['activity'], true); if (in_array($entry['in-reply-to-id'], $activity['children'] ?? [])) { - Logger::notice('reply-to-id is already in the list of children', ['id' => $entry['in-reply-to-id'], 'children' => $activity['children'], 'depth' => count($activity['children'])]); + DI::logger()->notice('reply-to-id is already in the list of children', ['id' => $entry['in-reply-to-id'], 'children' => $activity['children'], 'depth' => count($activity['children'])]); self::retrial($id); return false; } @@ -331,7 +330,7 @@ class Queue $activity['callstack'] = Processor::addToCallstack($activity['callstack'] ?? []); $wid = Worker::add(Worker::PRIORITY_HIGH, 'FetchMissingActivity', $entry['in-reply-to-id'], $activity, '', Receiver::COMPLETION_ASYNC); Fetch::setWorkerId($entry['in-reply-to-id'], $wid); - Logger::debug('Fetch missing activity', ['wid' => $wid, 'id' => $entry['activity-id'], 'reply-to-id' => $entry['in-reply-to-id']]); + DI::logger()->debug('Fetch missing activity', ['wid' => $wid, 'id' => $entry['activity-id'], 'reply-to-id' => $entry['in-reply-to-id']]); self::retrial($id); return false; } diff --git a/src/Protocol/ActivityPub/Receiver.php b/src/Protocol/ActivityPub/Receiver.php index d5a12b5218..34732022b5 100644 --- a/src/Protocol/ActivityPub/Receiver.php +++ b/src/Protocol/ActivityPub/Receiver.php @@ -11,7 +11,6 @@ use Friendica\Content\Text\BBCode; use Friendica\Database\DBA; use Friendica\Content\Text\HTML; use Friendica\Content\Text\Markdown; -use Friendica\Core\Logger; use Friendica\Core\Protocol; use Friendica\Core\System; use Friendica\Core\Worker; @@ -83,7 +82,7 @@ class Receiver { $activity = json_decode($body, true); if (empty($activity)) { - Logger::warning('Invalid body.'); + DI::logger()->warning('Invalid body.'); return; } @@ -94,7 +93,7 @@ class Receiver $apcontact = APContact::getByURL($actor); if (empty($apcontact)) { - Logger::notice('Unable to retrieve AP contact for actor - message is discarded', ['actor' => $actor]); + DI::logger()->notice('Unable to retrieve AP contact for actor - message is discarded', ['actor' => $actor]); return; } elseif (APContact::isRelay($apcontact) && self::isRelayPost($ldactivity)) { self::processRelayPost($ldactivity, $actor); @@ -105,52 +104,52 @@ class Receiver $sig_contact = HTTPSignature::getKeyIdContact($header); if (APContact::isRelay($sig_contact) && self::isRelayPost($ldactivity)) { - Logger::info('Message from a relay', ['url' => $sig_contact['url']]); + DI::logger()->info('Message from a relay', ['url' => $sig_contact['url']]); self::processRelayPost($ldactivity, $sig_contact['url']); return; } $http_signer = HTTPSignature::getSigner($body, $header); if ($http_signer === false) { - Logger::notice('Invalid HTTP signature, message will not be trusted.', ['uid' => $uid, 'actor' => $actor, 'header' => $header, 'body' => $body]); + DI::logger()->notice('Invalid HTTP signature, message will not be trusted.', ['uid' => $uid, 'actor' => $actor, 'header' => $header, 'body' => $body]); $signer = []; } elseif (empty($http_signer)) { - Logger::info('Signer is a tombstone. The message will be discarded, the signer account is deleted.'); + DI::logger()->info('Signer is a tombstone. The message will be discarded, the signer account is deleted.'); return; } else { - Logger::info('Valid HTTP signature', ['signer' => $http_signer]); + DI::logger()->info('Valid HTTP signature', ['signer' => $http_signer]); $signer = [$http_signer]; } - Logger::info('Message for user ' . $uid . ' is from actor ' . $actor); + DI::logger()->info('Message for user ' . $uid . ' is from actor ' . $actor); if ($http_signer === false) { $trust_source = false; } elseif (LDSignature::isSigned($activity)) { $ld_signer = LDSignature::getSigner($activity); if (empty($ld_signer)) { - Logger::info('Invalid JSON-LD signature from ' . $actor); + DI::logger()->info('Invalid JSON-LD signature from ' . $actor); } elseif ($ld_signer != $http_signer) { $signer[] = $ld_signer; } if (!empty($ld_signer && ($actor == $http_signer))) { - Logger::info('The HTTP and the JSON-LD signature belong to ' . $ld_signer); + DI::logger()->info('The HTTP and the JSON-LD signature belong to ' . $ld_signer); $trust_source = true; } elseif (!empty($ld_signer)) { - Logger::info('JSON-LD signature is signed by ' . $ld_signer); + DI::logger()->info('JSON-LD signature is signed by ' . $ld_signer); $trust_source = true; } elseif ($actor == $http_signer) { - Logger::info('Bad JSON-LD signature, but HTTP signer fits the actor.'); + DI::logger()->info('Bad JSON-LD signature, but HTTP signer fits the actor.'); $trust_source = true; } else { - Logger::info('Invalid JSON-LD signature and the HTTP signer is different.'); + DI::logger()->info('Invalid JSON-LD signature and the HTTP signer is different.'); $trust_source = false; } } elseif ($actor == $http_signer) { - Logger::info('Trusting post without JSON-LD signature, The actor fits the HTTP signer.'); + DI::logger()->info('Trusting post without JSON-LD signature, The actor fits the HTTP signer.'); $trust_source = true; } else { - Logger::info('No JSON-LD signature, different actor.'); + DI::logger()->info('No JSON-LD signature, different actor.'); $trust_source = false; } @@ -196,7 +195,7 @@ class Receiver { $type = JsonLD::fetchElement($activity, '@type'); if (!$type) { - Logger::notice('Empty type', ['activity' => $activity, 'actor' => $actor]); + DI::logger()->notice('Empty type', ['activity' => $activity, 'actor' => $actor]); return; } @@ -204,43 +203,43 @@ class Receiver $object_id = JsonLD::fetchElement($activity, 'as:object', '@id'); if (empty($object_id)) { - Logger::notice('No object id found', ['type' => $type, 'object_type' => $object_type, 'actor' => $actor, 'activity' => $activity]); + DI::logger()->notice('No object id found', ['type' => $type, 'object_type' => $object_type, 'actor' => $actor, 'activity' => $activity]); return; } $contact = Contact::getByURL($actor); if (empty($contact)) { - Logger::info('Relay contact not found', ['actor' => $actor]); + DI::logger()->info('Relay contact not found', ['actor' => $actor]); return; } if (!in_array($contact['rel'], [Contact::SHARING, Contact::FRIEND])) { - Logger::notice('Relay is no sharer', ['actor' => $actor]); + DI::logger()->notice('Relay is no sharer', ['actor' => $actor]); return; } - Logger::debug('Process post from relay server', ['type' => $type, 'object_type' => $object_type, 'object_id' => $object_id, 'actor' => $actor]); + DI::logger()->debug('Process post from relay server', ['type' => $type, 'object_type' => $object_type, 'object_id' => $object_id, 'actor' => $actor]); $item_id = Item::searchByLink($object_id); if ($item_id) { - Logger::info('Relayed message already exists', ['id' => $object_id, 'item' => $item_id, 'actor' => $actor]); + DI::logger()->info('Relayed message already exists', ['id' => $object_id, 'item' => $item_id, 'actor' => $actor]); return; } if (!DI::config()->get('system', 'decoupled_receiver')) { $id = Processor::fetchMissingActivity($object_id, [], $actor, self::COMPLETION_RELAY); if (!empty($id)) { - Logger::notice('Relayed message is fetched', ['result' => $id, 'id' => $object_id, 'actor' => $actor]); + DI::logger()->notice('Relayed message is fetched', ['result' => $id, 'id' => $object_id, 'actor' => $actor]); } else { - Logger::notice('Relayed message had not been fetched', ['id' => $object_id, 'actor' => $actor, 'activity' => $activity]); + DI::logger()->notice('Relayed message had not been fetched', ['id' => $object_id, 'actor' => $actor, 'activity' => $activity]); } } elseif (!Fetch::hasWorker($object_id)) { - Logger::notice('Fetching is done by worker.', ['id' => $object_id]); + DI::logger()->notice('Fetching is done by worker.', ['id' => $object_id]); Fetch::add($object_id); $wid = Worker::add(Worker::PRIORITY_HIGH, 'FetchMissingActivity', $object_id, [], $actor, self::COMPLETION_RELAY); Fetch::setWorkerId($object_id, $wid); } else { - Logger::debug('Activity will already be fetched via a worker.', ['url' => $object_id]); + DI::logger()->debug('Activity will already be fetched via a worker.', ['url' => $object_id]); } } @@ -334,25 +333,25 @@ class Receiver $fetched_type = JsonLD::fetchElement($object, '@type'); if (($fetched_id == $id) && !empty($fetched_type) && ($fetched_type == $type)) { - Logger::info('Activity had been fetched successfully', ['id' => $id]); + DI::logger()->info('Activity had been fetched successfully', ['id' => $id]); $trust_source = true; $activity = $object; } elseif (($fetched_id == $object_id) && !empty($fetched_type) && ($fetched_type == $object_type)) { - Logger::info('Fetched data is the object instead of the activity', ['id' => $id]); + DI::logger()->info('Fetched data is the object instead of the activity', ['id' => $id]); $trust_source = true; unset($object['@context']); $activity['as:object'] = $object; } else { - Logger::info('Activity id is not equal', ['id' => $id, 'fetched' => $fetched_id]); + DI::logger()->info('Activity id is not equal', ['id' => $id, 'fetched' => $fetched_id]); } } else { - Logger::info('Activity could not been fetched', ['id' => $id]); + DI::logger()->info('Activity could not been fetched', ['id' => $id]); } } $actor = JsonLD::fetchElement($activity, 'as:actor', '@id'); if (empty($actor)) { - Logger::info('Empty actor', ['activity' => $activity]); + DI::logger()->info('Empty actor', ['activity' => $activity]); return []; } @@ -388,12 +387,12 @@ class Receiver $object_id = JsonLD::fetchElement($activity, 'as:object', '@id'); if (empty($object_id)) { - Logger::info('No object found'); + DI::logger()->info('No object found'); return []; } if (!is_string($object_id)) { - Logger::info('Invalid object id', ['object' => $object_id]); + DI::logger()->info('Invalid object id', ['object' => $object_id]); return []; } @@ -424,7 +423,7 @@ class Receiver // We can receive "#emojiReaction" when fetching content from Hubzilla systems $object_data = self::fetchObject($object_id, $activity['as:object'], $trust_source, $fetch_uid); if (empty($object_data)) { - Logger::info("Object data couldn't be processed"); + DI::logger()->info("Object data couldn't be processed"); return []; } @@ -498,7 +497,7 @@ class Receiver $account = Contact::selectFirstAccount(['platform'], ['nurl' => Strings::normaliseLink($actor)]); $platform = $account['platform'] ?? ''; - Logger::info('Processing', ['type' => $object_data['type'], 'object_type' => $object_data['object_type'], 'id' => $object_data['id'], 'actor' => $actor, 'platform' => $platform]); + DI::logger()->info('Processing', ['type' => $object_data['type'], 'object_type' => $object_data['object_type'], 'id' => $object_data['id'], 'actor' => $actor, 'platform' => $platform]); return $object_data; } @@ -571,7 +570,7 @@ class Receiver } $object_data['directmessage'] = true; - Logger::debug('Got Misskey Chat'); + DI::logger()->debug('Got Misskey Chat'); return $object_data; } @@ -612,23 +611,23 @@ class Receiver { $type = JsonLD::fetchElement($activity, '@type'); if (!$type) { - Logger::info('Empty type', ['activity' => $activity]); + DI::logger()->info('Empty type', ['activity' => $activity]); return true; } if (!DI::config()->get('system', 'process_view') && ($type == 'as:View')) { - Logger::info('View activities are ignored.', ['signer' => $signer, 'http_signer' => $http_signer]); + DI::logger()->info('View activities are ignored.', ['signer' => $signer, 'http_signer' => $http_signer]); return true; } if (!JsonLD::fetchElement($activity, 'as:object', '@id')) { - Logger::info('Empty object', ['activity' => $activity]); + DI::logger()->info('Empty object', ['activity' => $activity]); return true; } $actor = JsonLD::fetchElement($activity, 'as:actor', '@id'); if ($actor === null || $actor === '') { - Logger::info('Empty actor', ['activity' => $activity]); + DI::logger()->info('Empty actor', ['activity' => $activity]); return true; } @@ -641,7 +640,7 @@ class Receiver if (!empty($published) && $object_id !== null && in_array($type, ['as:Create', 'as:Update']) && in_array($object_type, self::CONTENT_TYPES) && ($push || ($completion != self::COMPLETION_MANUAL)) && DI::contentItem()->isTooOld($published) && !Post::exists(['uri' => $object_id])) { - Logger::debug('Activity is too old. It will not be processed', ['push' => $push, 'completion' => $completion, 'type' => $type, 'object-type' => $object_type, 'published' => $published, 'id' => $id, 'object-id' => $object_id]); + DI::logger()->debug('Activity is too old. It will not be processed', ['push' => $push, 'completion' => $completion, 'type' => $type, 'object-type' => $object_type, 'published' => $published, 'id' => $id, 'object-id' => $object_id]); return true; } } else { @@ -665,22 +664,22 @@ class Receiver if (($type == 'as:Announce') && !empty($object_type) && !in_array($object_type, self::CONTENT_TYPES) && self::isGroup($actor)) { $object_object_type = JsonLD::fetchElement($activity['as:object']['as:object'] ?? [], '@type'); if (in_array($object_type, ['as:Create']) && in_array($object_object_type, self::CONTENT_TYPES)) { - Logger::debug('Replace "create" activity with inner object', ['type' => $object_type, 'object_type' => $object_object_type]); + DI::logger()->debug('Replace "create" activity with inner object', ['type' => $object_type, 'object_type' => $object_object_type]); $activity['as:object'] = $activity['as:object']['as:object']; } elseif (in_array($object_type, array_merge(self::ACTIVITY_TYPES, ['as:Delete', 'as:Undo', 'as:Update']))) { - Logger::debug('Change announced activity to activity', ['type' => $object_type]); + DI::logger()->debug('Change announced activity to activity', ['type' => $object_type]); $original_actor = $actor; $type = $object_type; $activity = $activity['as:object']; } else { - Logger::info('Unhandled announced activity', ['type' => $object_type, 'object_type' => $object_object_type]); + DI::logger()->info('Unhandled announced activity', ['type' => $object_type, 'object_type' => $object_object_type]); } } // $trust_source is called by reference and is set to true if the content was retrieved successfully $object_data = self::prepareObjectData($activity, $uid, $push, $trust_source, $original_actor); if (empty($object_data)) { - Logger::info('No object data found', ['activity' => $activity]); + DI::logger()->info('No object data found', ['activity' => $activity]); return true; } @@ -712,13 +711,13 @@ class Receiver if (($type == 'as:Create') && $trust_source && !in_array($completion, [self::COMPLETION_MANUAL, self::COMPLETION_ANNOUNCE])) { if (self::hasArrived($object_data['object_id'])) { - Logger::info('The activity already arrived.', ['id' => $object_data['object_id']]); + DI::logger()->info('The activity already arrived.', ['id' => $object_data['object_id']]); return true; } self::addArrivedId($object_data['object_id']); if (Queue::exists($object_data['object_id'], $type)) { - Logger::info('The activity is already added.', ['id' => $object_data['object_id']]); + DI::logger()->info('The activity is already added.', ['id' => $object_data['object_id']]); return true; } } elseif (($type == 'as:Create') && $trust_source && !self::hasArrived($object_data['object_id'])) { @@ -735,7 +734,7 @@ class Receiver } if (!$trust_source) { - Logger::info('Activity trust could not be achieved.', ['id' => $object_data['object_id'], 'type' => $type, 'signer' => $signer, 'actor' => $actor, 'attributedTo' => $attributed_to]); + DI::logger()->info('Activity trust could not be achieved.', ['id' => $object_data['object_id'], 'type' => $type, 'signer' => $signer, 'actor' => $actor, 'attributedTo' => $attributed_to]); return true; } @@ -743,11 +742,11 @@ class Receiver if (Queue::isProcessable($object_data['entry-id'])) { // We delay by 5 seconds to allow to accumulate all receivers $delayed = date(DateTimeFormat::MYSQL, time() + 5); - Logger::debug('Initiate processing', ['id' => $object_data['entry-id'], 'uri' => $object_data['object_id']]); + DI::logger()->debug('Initiate processing', ['id' => $object_data['entry-id'], 'uri' => $object_data['object_id']]); $wid = Worker::add(['priority' => Worker::PRIORITY_HIGH, 'delayed' => $delayed], 'ProcessQueue', $object_data['entry-id']); Queue::setWorkerId($object_data['entry-id'], $wid); } else { - Logger::debug('Other queue entries need to be processed first.', ['id' => $object_data['entry-id']]); + DI::logger()->debug('Other queue entries need to be processed first.', ['id' => $object_data['entry-id']]); } return false; } @@ -829,15 +828,15 @@ class Receiver if (in_array($object_data['object_type'], self::CONTENT_TYPES)) { if (!Processor::alreadyKnown($object_data['object_id'], '')) { if (ActivityPub\Processor::fetchMissingActivity($object_data['object_id'], [], $object_data['actor'], self::COMPLETION_ANNOUNCE, $uid)) { - Logger::debug('Created announced id', ['uid' => $uid, 'id' => $object_data['object_id']]); + DI::logger()->debug('Created announced id', ['uid' => $uid, 'id' => $object_data['object_id']]); Queue::remove($object_data); } else { - Logger::debug('Announced id was not created', ['uid' => $uid, 'id' => $object_data['object_id']]); + DI::logger()->debug('Announced id was not created', ['uid' => $uid, 'id' => $object_data['object_id']]); Queue::remove($object_data); return true; } } else { - Logger::info('Announced id already exists', ['uid' => $uid, 'id' => $object_data['object_id']]); + DI::logger()->info('Announced id already exists', ['uid' => $uid, 'id' => $object_data['object_id']]); Queue::remove($object_data); } @@ -957,7 +956,7 @@ class Receiver if (!empty($object_data['object_actor'])) { ActivityPub\Processor::acceptFollowUser($object_data); } else { - Logger::notice('Unhandled "accept follow" message.', ['object_data' => $object_data]); + DI::logger()->notice('Unhandled "accept follow" message.', ['object_data' => $object_data]); } } elseif (in_array($object_data['object_type'], self::CONTENT_TYPES)) { ActivityPub\Processor::createActivity($object_data, Activity::ATTEND); @@ -1047,7 +1046,7 @@ class Receiver break; default: - Logger::info('Unknown activity: ' . $type . ' ' . $object_data['object_type']); + DI::logger()->info('Unknown activity: ' . $type . ' ' . $object_data['object_type']); return false; } return true; @@ -1085,7 +1084,7 @@ class Receiver $tempfile = tempnam(System::getTempPath(), $file); file_put_contents($tempfile, json_encode(['activity' => $activity, 'body' => $body, 'uid' => $uid, 'trust_source' => $trust_source, 'push' => $push, 'signer' => $signer, 'object_data' => $object_data], JSON_UNESCAPED_SLASHES | JSON_UNESCAPED_UNICODE | JSON_PRETTY_PRINT)); - Logger::notice('Unknown activity stored', ['type' => $type, 'object_type' => $object_data['object_type'], 'object_object_type' => $object_data['object_object_type'] ?? '', 'file' => $tempfile]); + DI::logger()->notice('Unknown activity stored', ['type' => $type, 'object_type' => $object_data['object_type'], 'object_object_type' => $object_data['object_object_type'] ?? '', 'file' => $tempfile]); } /** @@ -1135,7 +1134,7 @@ class Receiver foreach ($receiver_list as $receiver) { if ($receiver == 'Public') { - Logger::warning('Not compacted public collection found', ['activity' => $activity]); + DI::logger()->warning('Not compacted public collection found', ['activity' => $activity]); $receiver = ActivityPub::PUBLIC_COLLECTION; } if ($receiver == self::PUBLIC_COLLECTION) { @@ -1186,9 +1185,9 @@ class Receiver $profile = APContact::getByURL($actor); $followers = $profile['followers'] ?? ''; $isGroup = ($profile['type'] ?? '') == 'Group'; - Logger::info('Got actor and followers', ['actor' => $actor, 'followers' => $followers]); + DI::logger()->info('Got actor and followers', ['actor' => $actor, 'followers' => $followers]); } else { - Logger::info('Empty actor', ['activity' => $activity]); + DI::logger()->info('Empty actor', ['activity' => $activity]); $followers = ''; $isGroup = false; } @@ -1307,11 +1306,11 @@ class Receiver if (empty($receivers) && $fetch_unlisted && Contact::isPlatform($actor, 'birdsitelive')) { $receivers[0] = ['uid' => 0, 'type' => self::TARGET_GLOBAL]; $receivers[-1] = ['uid' => -1, 'type' => self::TARGET_GLOBAL]; - Logger::notice('Post from "birdsitelive" is set to "unlisted"', ['id' => JsonLD::fetchElement($activity, '@id')]); + DI::logger()->notice('Post from "birdsitelive" is set to "unlisted"', ['id' => JsonLD::fetchElement($activity, '@id')]); } elseif (empty($receivers) && in_array($activity_type, ['as:Delete', 'as:Undo'])) { $receivers[0] = ['uid' => 0, 'type' => self::TARGET_GLOBAL]; } elseif (empty($receivers)) { - Logger::notice('Post has got no receivers', ['fetch_unlisted' => $fetch_unlisted, 'actor' => $actor, 'id' => JsonLD::fetchElement($activity, '@id'), 'type' => $activity_type]); + DI::logger()->notice('Post has got no receivers', ['fetch_unlisted' => $fetch_unlisted, 'actor' => $actor, 'id' => JsonLD::fetchElement($activity, '@id'), 'type' => $activity_type]); } return $receivers; @@ -1408,7 +1407,7 @@ class Receiver // Some systems (e.g. GNU Social) don't reply to the "id" field but the "uri" field. $objectId = Item::getURIByLink($object_data['object_id']); if (!empty($objectId) && ($object_data['object_id'] != $objectId)) { - Logger::notice('Fix wrong object-id', ['received' => $object_data['object_id'], 'correct' => $objectId]); + DI::logger()->notice('Fix wrong object-id', ['received' => $object_data['object_id'], 'correct' => $objectId]); $object_data['object_id'] = $objectId; } } @@ -1437,37 +1436,37 @@ class Receiver $data = Processor::fetchCachedActivity($object_id, $uid); if (!empty($data)) { $object = JsonLD::compact($data); - Logger::info('Fetched content for ' . $object_id); + DI::logger()->info('Fetched content for ' . $object_id); } else { - Logger::info('Empty content for ' . $object_id . ', check if content is available locally.'); + DI::logger()->info('Empty content for ' . $object_id . ', check if content is available locally.'); $item = Post::selectFirst(Item::DELIVER_FIELDLIST, ['uri' => $object_id]); if (!DBA::isResult($item)) { - Logger::info('Object with url ' . $object_id . ' was not found locally.'); + DI::logger()->info('Object with url ' . $object_id . ' was not found locally.'); return false; } - Logger::info('Using already stored item for url ' . $object_id); + DI::logger()->info('Using already stored item for url ' . $object_id); $data = ActivityPub\Transmitter::createNote($item); $object = JsonLD::compact($data); } $id = JsonLD::fetchElement($object, '@id'); if (empty($id)) { - Logger::info('Empty id'); + DI::logger()->info('Empty id'); return false; } if ($id != $object_id) { - Logger::info('Fetched id differs from provided id', ['provided' => $object_id, 'fetched' => $id]); + DI::logger()->info('Fetched id differs from provided id', ['provided' => $object_id, 'fetched' => $id]); return false; } } else { - Logger::info('Using original object for url ' . $object_id); + DI::logger()->info('Using original object for url ' . $object_id); } $type = JsonLD::fetchElement($object, '@type'); if (empty($type)) { - Logger::info('Empty type'); + DI::logger()->info('Empty type'); return false; } @@ -1481,7 +1480,7 @@ class Receiver return $object_data; } - Logger::info('Unhandled object type: ' . $type); + DI::logger()->info('Unhandled object type: ' . $type); return false; } @@ -1965,7 +1964,7 @@ class Receiver // Some systems (e.g. GNU Social) don't reply to the "id" field but the "uri" field. $replyToId = Item::getURIByLink($object_data['reply-to-id']); if (!empty($replyToId) && ($object_data['reply-to-id'] != $replyToId)) { - Logger::notice('Fix wrong reply-to', ['received' => $object_data['reply-to-id'], 'correct' => $replyToId]); + DI::logger()->notice('Fix wrong reply-to', ['received' => $object_data['reply-to-id'], 'correct' => $replyToId]); $object_data['reply-to-id'] = $replyToId; } } diff --git a/src/Protocol/ActivityPub/Transmitter.php b/src/Protocol/ActivityPub/Transmitter.php index 1f03bd2118..c183b5313b 100644 --- a/src/Protocol/ActivityPub/Transmitter.php +++ b/src/Protocol/ActivityPub/Transmitter.php @@ -12,7 +12,6 @@ use Friendica\Content\Feature; use Friendica\Content\Smilies; use Friendica\Content\Text\BBCode; use Friendica\Core\Cache\Enum\Duration; -use Friendica\Core\Logger; use Friendica\Core\Protocol; use Friendica\Core\System; use Friendica\Database\DBA; @@ -908,14 +907,14 @@ class Transmitter { $tags = Tag::getByURIId($uri_id, [Tag::TO, Tag::CC, Tag::BTO, Tag::BCC, Tag::AUDIENCE]); if (empty($tags)) { - Logger::debug('No receivers found', ['uri-id' => $uri_id]); + DI::logger()->debug('No receivers found', ['uri-id' => $uri_id]); $post = Post::selectFirst(Item::DELIVER_FIELDLIST, ['uri-id' => $uri_id, 'origin' => true]); if (!empty($post)) { ActivityPub\Transmitter::storeReceiversForItem($post); $tags = Tag::getByURIId($uri_id, [Tag::TO, Tag::CC, Tag::BTO, Tag::BCC, Tag::AUDIENCE]); - Logger::debug('Receivers are created', ['uri-id' => $uri_id, 'receivers' => count($tags)]); + DI::logger()->debug('Receivers are created', ['uri-id' => $uri_id, 'receivers' => count($tags)]); } else { - Logger::debug('Origin item not found', ['uri-id' => $uri_id]); + DI::logger()->debug('Origin item not found', ['uri-id' => $uri_id]); } } @@ -1328,7 +1327,7 @@ class Transmitter if (!$api_mode) { $condition['parent-network'] = Protocol::NATIVE_SUPPORT; } - Logger::info('Fetching activity', $condition); + DI::logger()->info('Fetching activity', $condition); $item = Post::selectFirst(Item::DELIVER_FIELDLIST, $condition); if (!DBA::isResult($item)) { return false; @@ -1351,7 +1350,7 @@ class Transmitter if (!$api_mode) { $condition['parent-network'] = Protocol::NATIVE_SUPPORT; } - Logger::info('Fetching activity', $condition); + DI::logger()->info('Fetching activity', $condition); $item = Post::selectFirst(Item::DELIVER_FIELDLIST, $condition, ['order' => ['uid' => true]]); if (!DBA::isResult($item)) { return false; @@ -1375,17 +1374,17 @@ class Transmitter $data = Post\Activity::getByURIId($item['uri-id']); if (!$item['origin'] && !empty($data)) { if (!$object_mode) { - Logger::info('Return stored conversation', ['item' => $item['id']]); + DI::logger()->info('Return stored conversation', ['item' => $item['id']]); return $data; } elseif (!empty($data['object'])) { - Logger::info('Return stored conversation object', ['item' => $item['id']]); + DI::logger()->info('Return stored conversation object', ['item' => $item['id']]); return $data['object']; } } } if (!$api_mode && !$item['deleted'] && !$item['origin']) { - Logger::debug('Post is not ours and is not stored', ['id' => $item['id'], 'uri-id' => $item['uri-id']]); + DI::logger()->debug('Post is not ours and is not stored', ['id' => $item['id'], 'uri-id' => $item['uri-id']]); return false; } @@ -1467,7 +1466,7 @@ class Transmitter $uid = $item['uid']; } - Logger::info('Fetched activity', ['item' => $item['id'], 'uid' => $uid]); + DI::logger()->info('Fetched activity', ['item' => $item['id'], 'uid' => $uid]); // We only sign our own activities if (!$api_mode && !$object_mode && $item['origin']) { @@ -2118,7 +2117,7 @@ class Transmitter $signed = LDSignature::sign($data, $owner); - Logger::info('Deliver profile deletion for user ' . $owner['uid'] . ' to ' . $inbox . ' via ActivityPub'); + DI::logger()->info('Deliver profile deletion for user ' . $owner['uid'] . ' to ' . $inbox . ' via ActivityPub'); return HTTPSignature::transmit($signed, $inbox, $owner); } @@ -2146,7 +2145,7 @@ class Transmitter $signed = LDSignature::sign($data, $owner); - Logger::info('Deliver profile relocation for user ' . $owner['uid'] . ' to ' . $inbox . ' via ActivityPub'); + DI::logger()->info('Deliver profile relocation for user ' . $owner['uid'] . ' to ' . $inbox . ' via ActivityPub'); return HTTPSignature::transmit($signed, $inbox, $owner); } @@ -2161,7 +2160,7 @@ class Transmitter public static function sendProfileDeletion(array $owner, string $inbox): bool { if (empty($owner['uprvkey'])) { - Logger::error('No private key for owner found, the deletion message cannot be processed.', ['user' => $owner['uid']]); + DI::logger()->error('No private key for owner found, the deletion message cannot be processed.', ['user' => $owner['uid']]); return false; } @@ -2179,7 +2178,7 @@ class Transmitter $signed = LDSignature::sign($data, $owner); - Logger::info('Deliver profile deletion for user ' . $owner['uid'] . ' to ' . $inbox . ' via ActivityPub'); + DI::logger()->info('Deliver profile deletion for user ' . $owner['uid'] . ' to ' . $inbox . ' via ActivityPub'); return HTTPSignature::transmit($signed, $inbox, $owner); } @@ -2211,7 +2210,7 @@ class Transmitter $signed = LDSignature::sign($data, $owner); - Logger::info('Deliver profile update for user ' . $owner['uid'] . ' to ' . $inbox . ' via ActivityPub'); + DI::logger()->info('Deliver profile update for user ' . $owner['uid'] . ' to ' . $inbox . ' via ActivityPub'); return HTTPSignature::transmit($signed, $inbox, $owner); } @@ -2231,13 +2230,13 @@ class Transmitter { $profile = APContact::getByURL($target); if (empty($profile['inbox'])) { - Logger::warning('No inbox found for target', ['target' => $target, 'profile' => $profile]); + DI::logger()->warning('No inbox found for target', ['target' => $target, 'profile' => $profile]); return false; } $owner = User::getOwnerDataById($uid); if (empty($owner)) { - Logger::warning('No user found for actor, aborting', ['uid' => $uid]); + DI::logger()->warning('No user found for actor, aborting', ['uid' => $uid]); return false; } @@ -2255,7 +2254,7 @@ class Transmitter 'to' => [$profile['url']], ]; - Logger::info('Sending activity ' . $activity . ' to ' . $target . ' for user ' . $uid); + DI::logger()->info('Sending activity ' . $activity . ' to ' . $target . ' for user ' . $uid); $signed = LDSignature::sign($data, $owner); return HTTPSignature::transmit($signed, $profile['inbox'], $owner); @@ -2277,7 +2276,7 @@ class Transmitter { $profile = APContact::getByURL($target); if (empty($profile['inbox'])) { - Logger::warning('No inbox found for target', ['target' => $target, 'profile' => $profile]); + DI::logger()->warning('No inbox found for target', ['target' => $target, 'profile' => $profile]); return false; } @@ -2285,7 +2284,7 @@ class Transmitter // We need to use some user as a sender. It doesn't care who it will send. We will use an administrator account. $admin = User::getFirstAdmin(['uid']); if (!$admin) { - Logger::warning('No available admin user for transmission', ['target' => $target]); + DI::logger()->warning('No available admin user for transmission', ['target' => $target]); return false; } @@ -2297,7 +2296,7 @@ class Transmitter 'author-id' => Contact::getPublicIdByUserId($uid) ]; if (Post::exists($condition)) { - Logger::info('Follow for ' . $object . ' for user ' . $uid . ' does already exist.'); + DI::logger()->info('Follow for ' . $object . ' for user ' . $uid . ' does already exist.'); return false; } @@ -2313,7 +2312,7 @@ class Transmitter 'to' => [$profile['url']], ]; - Logger::info('Sending follow ' . $object . ' to ' . $target . ' for user ' . $uid); + DI::logger()->info('Sending follow ' . $object . ' to ' . $target . ' for user ' . $uid); $signed = LDSignature::sign($data, $owner); return HTTPSignature::transmit($signed, $profile['inbox'], $owner); @@ -2333,13 +2332,13 @@ class Transmitter { $profile = APContact::getByURL($target); if (empty($profile['inbox'])) { - Logger::warning('No inbox found for target', ['target' => $target, 'profile' => $profile]); + DI::logger()->warning('No inbox found for target', ['target' => $target, 'profile' => $profile]); return; } $owner = User::getOwnerDataById($uid); if (!$owner) { - Logger::notice('No user found for actor', ['uid' => $uid]); + DI::logger()->notice('No user found for actor', ['uid' => $uid]); return; } @@ -2358,7 +2357,7 @@ class Transmitter 'to' => [$profile['url']], ]; - Logger::debug('Sending accept to ' . $target . ' for user ' . $uid . ' with id ' . $id); + DI::logger()->debug('Sending accept to ' . $target . ' for user ' . $uid . ' with id ' . $id); $signed = LDSignature::sign($data, $owner); HTTPSignature::transmit($signed, $profile['inbox'], $owner); @@ -2378,7 +2377,7 @@ class Transmitter { $profile = APContact::getByURL($target); if (empty($profile['inbox'])) { - Logger::warning('No inbox found for target', ['target' => $target, 'profile' => $profile]); + DI::logger()->warning('No inbox found for target', ['target' => $target, 'profile' => $profile]); return false; } @@ -2397,7 +2396,7 @@ class Transmitter 'to' => [$profile['url']], ]; - Logger::debug('Sending reject to ' . $target . ' for user ' . $owner['uid'] . ' with id ' . $objectId); + DI::logger()->debug('Sending reject to ' . $target . ' for user ' . $owner['uid'] . ' with id ' . $objectId); $signed = LDSignature::sign($data, $owner); return HTTPSignature::transmit($signed, $profile['inbox'], $owner); @@ -2418,7 +2417,7 @@ class Transmitter { $profile = APContact::getByURL($target); if (empty($profile['inbox'])) { - Logger::warning('No inbox found for target', ['target' => $target, 'profile' => $profile]); + DI::logger()->warning('No inbox found for target', ['target' => $target, 'profile' => $profile]); return false; } @@ -2444,7 +2443,7 @@ class Transmitter 'to' => [$profile['url']], ]; - Logger::info('Sending undo to ' . $target . ' for user ' . $owner['uid'] . ' with id ' . $objectId); + DI::logger()->info('Sending undo to ' . $target . ' for user ' . $owner['uid'] . ' with id ' . $objectId); $signed = LDSignature::sign($data, $owner); return HTTPSignature::transmit($signed, $profile['inbox'], $owner); @@ -2465,7 +2464,7 @@ class Transmitter { $profile = APContact::getByURL($target); if (empty($profile['inbox'])) { - Logger::warning('No inbox found for target', ['target' => $target, 'profile' => $profile]); + DI::logger()->warning('No inbox found for target', ['target' => $target, 'profile' => $profile]); return false; } @@ -2491,7 +2490,7 @@ class Transmitter 'to' => [$profile['url']], ]; - Logger::info('Sending undo to ' . $target . ' for user ' . $owner['uid'] . ' with id ' . $objectId); + DI::logger()->info('Sending undo to ' . $target . ' for user ' . $owner['uid'] . ' with id ' . $objectId); $signed = LDSignature::sign($data, $owner); return HTTPSignature::transmit($signed, $profile['inbox'], $owner);