Friendica/friendica-github
1
0
Fork 0
mirror of https://github.com/friendica/friendica synced 2025-05-12 07:44:09 +02:00
Code Issues Projects Releases Packages Wiki Activity

Merge pull request #14688 from Art4/refactor-logger-class-with-logger-object

Browse source 
Replace Logger class with LoggerInterface implementation
This commit is contained in:
Michael Vogel 2025-01-22 07:20:26 +01:00 • committed by GitHub
commit bb252e326f
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
157 changed files with 1807 additions and 1948 deletions
Download patch file Download diff file Expand all files Collapse all files

17
src/Protocol/ActivityPub.php
View file

@ -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;
}

17
src/Protocol/ActivityPub/ClientToServer.php
View file

@ -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']);

17
src/Protocol/ActivityPub/Delivery.php
View file

@ -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);

10
src/Protocol/ActivityPub/Fetch.php
View file

@ -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;
}

275
src/Protocol/ActivityPub/Processor.php
View file

@ -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;

21
src/Protocol/ActivityPub/Queue.php
View file

@ -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;
}

141
src/Protocol/ActivityPub/Receiver.php
View file

@ -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;
}
}

61
src/Protocol/ActivityPub/Transmitter.php
View file

@ -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);

111
src/Protocol/DFRN.php
View file

@ -13,7 +13,6 @@ use DOMNode;
use DOMXPath;
use Friendica\App;
use Friendica\Content\Text\BBCode;
use Friendica\Core\Logger;
use Friendica\Core\Protocol;
use Friendica\Database\DBA;
use Friendica\DI;
@ -716,7 +715,7 @@ class DFRN
$mentioned = [];
if (!$item['parent']) {
Logger::warning('Item without parent found.', ['type' => $type, 'item' => $item]);
DI::logger()->warning('Item without parent found.', ['type' => $type, 'item' => $item]);
return null;
}
@ -938,14 +937,14 @@ class DFRN
{
if (!$public_batch) {
if (empty($contact['addr'])) {
Logger::notice('Empty contact handle for ' . $contact['id'] . ' - ' . $contact['url'] . ' - trying to update it.');
DI::logger()->notice('Empty contact handle for ' . $contact['id'] . ' - ' . $contact['url'] . ' - trying to update it.');
if (Contact::updateFromProbe($contact['id'])) {
$new_contact = DBA::selectFirst('contact', ['addr'], ['id' => $contact['id']]);
$contact['addr'] = $new_contact['addr'];
}
if (empty($contact['addr'])) {
Logger::notice('Unable to find contact handle for ' . $contact['id'] . ' - ' . $contact['url']);
DI::logger()->notice('Unable to find contact handle for ' . $contact['id'] . ' - ' . $contact['url']);
return -21;
}
}
@ -953,7 +952,7 @@ class DFRN
try {
$pubkey = DI::dsprContact()->getByAddr(WebFingerUri::fromString($contact['addr']))->pubKey;
} catch (HTTPException\NotFoundException|\InvalidArgumentException $e) {
Logger::notice('Unable to find contact details for ' . $contact['id'] . ' - ' . $contact['addr']);
DI::logger()->notice('Unable to find contact details for ' . $contact['id'] . ' - ' . $contact['addr']);
return -22;
}
} else {
@ -974,7 +973,7 @@ class DFRN
$dest_url = ($public_batch ? $contact['batch'] : $contact['notify']);
if (empty($dest_url)) {
Logger::info('Empty destination', ['public' => $public_batch, 'contact' => $contact]);
DI::logger()->info('Empty destination', ['public' => $public_batch, 'contact' => $contact]);
return -24;
}
@ -983,7 +982,7 @@ class DFRN
try {
$postResult = DI::httpClient()->post($dest_url, $envelope, ['Content-Type' => $content_type], 0, HttpClientRequest::DFRN);
} catch (\Throwable $th) {
Logger::notice('Got exception', ['code' => $th->getCode(), 'message' => $th->getMessage()]);
DI::logger()->notice('Got exception', ['code' => $th->getCode(), 'message' => $th->getMessage()]);
return -25;
}
@ -995,7 +994,7 @@ class DFRN
}
if (empty($curl_stat) || empty($xml)) {
Logger::notice('Empty answer from ' . $contact['id'] . ' - ' . $dest_url);
DI::logger()->notice('Empty answer from ' . $contact['id'] . ' - ' . $dest_url);
return -9; // timed out
}
@ -1004,8 +1003,8 @@ class DFRN
}
if (strpos($xml, '<?xml') === false) {
Logger::notice('No valid XML returned from ' . $contact['id'] . ' - ' . $dest_url);
Logger::debug('Returned XML: ' . $xml);
DI::logger()->notice('No valid XML returned from ' . $contact['id'] . ' - ' . $dest_url);
DI::logger()->debug('Returned XML: ' . $xml);
return 3;
}
@ -1021,7 +1020,7 @@ class DFRN
}
if (!empty($res->message)) {
Logger::info('Transmit to ' . $dest_url . ' returned status '.$res->status.' - '.$res->message);
DI::logger()->info('Transmit to ' . $dest_url . ' returned status '.$res->status.' - '.$res->message);
}
return intval($res->status);
@ -1063,7 +1062,7 @@ class DFRN
$author["contact-id"] = $contact_old["id"];
$author["network"] = $contact_old["network"];
} else {
Logger::info('Contact not found', ['condition' => $condition]);
DI::logger()->info('Contact not found', ['condition' => $condition]);
$author["contact-unknown"] = true;
$contact = Contact::getByURL($author["link"], null, ["id", "network"]);
@ -1112,12 +1111,12 @@ class DFRN
}
if (empty($author['avatar'])) {
Logger::notice('Empty author: ' . $xml);
DI::logger()->notice('Empty author: ' . $xml);
$author['avatar'] = '';
}
if (DBA::isResult($contact_old) && !$onlyfetch) {
Logger::info("Check if contact details for contact " . $contact_old["id"] . " (" . $contact_old["nick"] . ") have to be updated.");
DI::logger()->info("Check if contact details for contact " . $contact_old["id"] . " (" . $contact_old["nick"] . ") have to be updated.");
$poco = ["url" => $contact_old["url"], "network" => $contact_old["network"]];
@ -1178,7 +1177,7 @@ class DFRN
// If the "hide" element is present then the profile isn't searchable.
$hide = intval(XML::getFirstNodeValue($xpath, $element . "/dfrn:hide/text()", $context) == "true");
Logger::info("Hidden status for contact " . $contact_old["url"] . ": " . $hide);
DI::logger()->info("Hidden status for contact " . $contact_old["url"] . ": " . $hide);
// If the contact isn't searchable then set the contact to "hidden".
// Problem: This can be manually overridden by the user.
@ -1318,7 +1317,7 @@ class DFRN
*/
private static function processMail(DOMXPath $xpath, DOMNode $mail, array $importer)
{
Logger::info("Processing mails");
DI::logger()->info("Processing mails");
$msg = [];
$msg['uid'] = $importer['importer_uid'];
@ -1346,7 +1345,7 @@ class DFRN
*/
private static function processSuggestion(DOMXPath $xpath, DOMNode $suggestion, array $importer)
{
Logger::info('Processing suggestions');
DI::logger()->info('Processing suggestions');
$url = $xpath->evaluate('string(dfrn:url[1]/text())', $suggestion);
$cid = Contact::getIdForURL($url);
@ -1422,7 +1421,7 @@ class DFRN
*/
private static function processRelocation(DOMXPath $xpath, DOMNode $relocation, array $importer): bool
{
Logger::info("Processing relocations");
DI::logger()->info("Processing relocations");
/// @TODO Rewrite this to one statement
$relocate = [];
@ -1452,7 +1451,7 @@ class DFRN
// update contact
$old = Contact::selectFirst(['photo', 'url'], ['id' => $importer['id'], 'uid' => $importer['importer_uid']]);
if (!DBA::isResult($old)) {
Logger::warning('Existing contact had not been fetched', ['id' => $importer['id']]);
DI::logger()->warning('Existing contact had not been fetched', ['id' => $importer['id']]);
return false;
}
@ -1475,7 +1474,7 @@ class DFRN
Contact::updateAvatar($importer['id'], $relocate['avatar'], true);
Logger::info('Contacts are updated.');
DI::logger()->info('Contacts are updated.');
/// @TODO
/// merge with current record, current contents have priority
@ -1558,7 +1557,7 @@ class DFRN
*/
private static function processVerbs(int $entrytype, array $importer, array &$item)
{
Logger::info('Process verb ' . $item['verb'] . ' and object-type ' . $item['object-type'] . ' for entrytype ' . $entrytype);
DI::logger()->info('Process verb ' . $item['verb'] . ' and object-type ' . $item['object-type'] . ' for entrytype ' . $entrytype);
if (($entrytype == self::TOP_LEVEL) && !empty($importer['id'])) {
// The filling of the "contact" variable is done for legacy reasons
@ -1570,22 +1569,22 @@ class DFRN
// Big question: Do we need these functions? They were part of the "consume_feed" function.
// This function once was responsible for DFRN and OStatus.
if ($activity->match($item['verb'], Activity::FOLLOW)) {
Logger::info("New follower");
DI::logger()->info("New follower");
Contact::addRelationship($importer, $contact, $item);
return false;
}
if ($activity->match($item['verb'], Activity::UNFOLLOW)) {
Logger::info("Lost follower");
DI::logger()->info("Lost follower");
Contact::removeFollower($contact);
return false;
}
if ($activity->match($item['verb'], Activity::REQ_FRIEND)) {
Logger::info("New friend request");
DI::logger()->info("New friend request");
Contact::addRelationship($importer, $contact, $item, true);
return false;
}
if ($activity->match($item['verb'], Activity::UNFRIEND)) {
Logger::info("Lost sharer");
DI::logger()->info("Lost sharer");
Contact::removeSharer($contact);
return false;
}
@ -1631,7 +1630,7 @@ class DFRN
if ($xt->type == Activity\ObjectType::NOTE) {
$item_tag = Post::selectFirst(['id', 'uri-id'], ['uri' => $xt->id, 'uid' => $importer['importer_uid']]);
if (!DBA::isResult($item_tag)) {
Logger::warning('Post had not been fetched', ['uri' => $xt->id, 'uid' => $importer['importer_uid']]);
DI::logger()->warning('Post had not been fetched', ['uri' => $xt->id, 'uid' => $importer['importer_uid']]);
return false;
}
@ -1696,23 +1695,23 @@ class DFRN
{
if (DBA::exists('contact', ["`nurl` = ? AND `uid` != ? AND `rel` IN (?, ?)",
Strings::normaliseLink($item["author-link"]), 0, Contact::FRIEND, Contact::SHARING])) {
Logger::debug('Author has got followers - accepted', ['uri-id' => $item['uri-id'], 'guid' => $item['guid'], 'url' => $item['uri'], 'author' => $item["author-link"]]);
DI::logger()->debug('Author has got followers - accepted', ['uri-id' => $item['uri-id'], 'guid' => $item['guid'], 'url' => $item['uri'], 'author' => $item["author-link"]]);
return true;
}
if ($importer['importer_uid'] != 0) {
Logger::debug('Message is directed to a user - accepted', ['uri-id' => $item['uri-id'], 'guid' => $item['guid'], 'url' => $item['uri'], 'importer' => $importer['importer_uid']]);
DI::logger()->debug('Message is directed to a user - accepted', ['uri-id' => $item['uri-id'], 'guid' => $item['guid'], 'url' => $item['uri'], 'importer' => $importer['importer_uid']]);
return true;
}
if ($item['uri'] != $item['thr-parent']) {
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['body'], $item['author-id'], $item['uri'], Protocol::DFRN)) {
Logger::debug('Post is accepted because of the relay settings', ['uri-id' => $item['uri-id'], 'guid' => $item['guid'], 'url' => $item['uri'], 'author' => $item["author-link"]]);
DI::logger()->debug('Post is accepted because of the relay settings', ['uri-id' => $item['uri-id'], 'guid' => $item['guid'], 'url' => $item['uri'], 'author' => $item["author-link"]]);
return true;
} else {
return false;
@ -1735,7 +1734,7 @@ class DFRN
*/
private static function processEntry(array $header, DOMXPath $xpath, DOMNode $entry, array $importer, string $xml, int $protocol)
{
Logger::info("Processing entries");
DI::logger()->info("Processing entries");
$item = $header;
@ -1751,7 +1750,7 @@ class DFRN
);
// Is there an existing item?
if (DBA::isResult($current) && !self::isEditedTimestampNewer($current, $item)) {
Logger::info("Item " . $item['uri'] . " (" . $item['edited'] . ") already existed.");
DI::logger()->info("Item " . $item['uri'] . " (" . $item['edited'] . ") already existed.");
return;
}
@ -1961,10 +1960,10 @@ class DFRN
// Is it an event?
if (($item['object-type'] == Activity\ObjectType::EVENT) && !$owner_unknown) {
Logger::info("Item " . $item['uri'] . " seems to contain an event.");
DI::logger()->info("Item " . $item['uri'] . " seems to contain an event.");
$ev = Event::fromBBCode($item['body']);
if ((!empty($ev['desc']) || !empty($ev['summary'])) && !empty($ev['start'])) {
Logger::info("Event in item " . $item['uri'] . " was found.");
DI::logger()->info("Event in item " . $item['uri'] . " was found.");
$ev['cid'] = $importer['id'];
$ev['uid'] = $importer['importer_uid'];
$ev['uri'] = $item['uri'];
@ -1984,7 +1983,7 @@ class DFRN
}
$event_id = Event::store($ev);
Logger::info('Event was stored', ['id' => $event_id]);
DI::logger()->info('Event was stored', ['id' => $event_id]);
$item = Event::getItemArrayForImportedId($event_id, $item);
}
@ -1992,13 +1991,13 @@ class DFRN
}
if (!self::processVerbs($entrytype, $importer, $item)) {
Logger::info("Exiting because 'processVerbs' told us so");
DI::logger()->info("Exiting because 'processVerbs' told us so");
return;
}
// This check is done here to be able to receive connection requests in "processVerbs"
if (($entrytype == self::TOP_LEVEL) && $owner_unknown) {
Logger::info("Item won't be stored because user " . $importer['importer_uid'] . " doesn't follow " . $item['owner-link'] . ".");
DI::logger()->info("Item won't be stored because user " . $importer['importer_uid'] . " doesn't follow " . $item['owner-link'] . ".");
return;
}
@ -2006,9 +2005,9 @@ class DFRN
// Update content if 'updated' changes
if (DBA::isResult($current)) {
if (self::updateContent($current, $item, $importer, $entrytype)) {
Logger::info("Item " . $item['uri'] . " was updated.");
DI::logger()->info("Item " . $item['uri'] . " was updated.");
} else {
Logger::info("Item " . $item['uri'] . " already existed.");
DI::logger()->info("Item " . $item['uri'] . " already existed.");
}
return;
}
@ -2016,20 +2015,20 @@ class DFRN
if (in_array($entrytype, [self::REPLY, self::REPLY_RC])) {
if (($item['uid'] != 0) && !Post::exists(['uid' => $item['uid'], 'uri' => $item['thr-parent']])) {
if (DI::pConfig()->get($item['uid'], 'system', 'accept_only_sharer') == Item::COMPLETION_NONE) {
Logger::info('Completion is set to "none", so we stop here.', ['uid' => $item['uid'], 'owner-id' => $item['owner-id'], 'author-id' => $item['author-id'], 'gravity' => $item['gravity'], 'uri' => $item['uri']]);
DI::logger()->info('Completion is set to "none", so we stop here.', ['uid' => $item['uid'], 'owner-id' => $item['owner-id'], 'author-id' => $item['author-id'], 'gravity' => $item['gravity'], 'uri' => $item['uri']]);
return;
}
if (!Contact::isSharing($item['owner-id'], $item['uid']) && !Contact::isSharing($item['author-id'], $item['uid'])) {
Logger::info('Contact is not sharing with the user', ['uid' => $item['uid'], 'owner-id' => $item['owner-id'], 'author-id' => $item['author-id'], 'gravity' => $item['gravity'], 'uri' => $item['uri']]);
DI::logger()->info('Contact is not sharing with the user', ['uid' => $item['uid'], 'owner-id' => $item['owner-id'], 'author-id' => $item['author-id'], 'gravity' => $item['gravity'], 'uri' => $item['uri']]);
return;
}
if (($item['gravity'] == Item::GRAVITY_ACTIVITY) && DI::pConfig()->get($item['uid'], 'system', 'accept_only_sharer') == Item::COMPLETION_COMMENT) {
Logger::info('Completion is set to "comment", but this is an activity. so we stop here.', ['uid' => $item['uid'], 'owner-id' => $item['owner-id'], 'author-id' => $item['author-id'], 'gravity' => $item['gravity'], 'uri' => $item['uri']]);
DI::logger()->info('Completion is set to "comment", but this is an activity. so we stop here.', ['uid' => $item['uid'], 'owner-id' => $item['owner-id'], 'author-id' => $item['author-id'], 'gravity' => $item['gravity'], 'uri' => $item['uri']]);
return;
}
Logger::debug('Post is accepted.', ['uid' => $item['uid'], 'owner-id' => $item['owner-id'], 'author-id' => $item['author-id'], 'gravity' => $item['gravity'], 'uri' => $item['uri']]);
DI::logger()->debug('Post is accepted.', ['uid' => $item['uid'], 'owner-id' => $item['owner-id'], 'author-id' => $item['author-id'], 'gravity' => $item['gravity'], 'uri' => $item['uri']]);
} else {
Logger::debug('Thread parent exists.', ['uid' => $item['uid'], 'owner-id' => $item['owner-id'], 'author-id' => $item['author-id'], 'gravity' => $item['gravity'], 'uri' => $item['uri']]);
DI::logger()->debug('Thread parent exists.', ['uid' => $item['uid'], 'owner-id' => $item['owner-id'], 'author-id' => $item['author-id'], 'gravity' => $item['gravity'], 'uri' => $item['uri']]);
}
// Will be overwritten for sharing accounts in Item::insert
@ -2039,7 +2038,7 @@ class DFRN
$posted_id = Item::insert($item);
if ($posted_id) {
Logger::info("Reply from contact " . $item['contact-id'] . " was stored with id " . $posted_id);
DI::logger()->info("Reply from contact " . $item['contact-id'] . " was stored with id " . $posted_id);
if ($item['uid'] == 0) {
Item::distribute($posted_id);
@ -2049,7 +2048,7 @@ class DFRN
}
} else { // $entrytype == self::TOP_LEVEL
if (($item['uid'] != 0) && !Contact::isSharing($item['owner-id'], $item['uid']) && !Contact::isSharing($item['author-id'], $item['uid'])) {
Logger::info('Contact is not sharing with the user', ['uid' => $item['uid'], 'owner-id' => $item['owner-id'], 'author-id' => $item['author-id'], 'gravity' => $item['gravity'], 'uri' => $item['uri']]);
DI::logger()->info('Contact is not sharing with the user', ['uid' => $item['uid'], 'owner-id' => $item['owner-id'], 'author-id' => $item['author-id'], 'gravity' => $item['gravity'], 'uri' => $item['uri']]);
return;
}
@ -2064,7 +2063,7 @@ class DFRN
$posted_id = $notify;
}
Logger::info("Item was stored with id " . $posted_id);
DI::logger()->info("Item was stored with id " . $posted_id);
if ($item['uid'] == 0) {
Item::distribute($posted_id);
@ -2083,7 +2082,7 @@ class DFRN
*/
private static function processDeletion(DOMXPath $xpath, DOMNode $deletion, array $importer)
{
Logger::info("Processing deletions");
DI::logger()->info("Processing deletions");
$uri = null;
foreach ($deletion->attributes as $attributes) {
@ -2099,18 +2098,18 @@ class DFRN
$condition = ['uri' => $uri, 'uid' => $importer['importer_uid']];
$item = Post::selectFirst(['id', 'parent', 'contact-id', 'uri-id', 'deleted', 'gravity'], $condition);
if (!DBA::isResult($item)) {
Logger::info('Item with URI ' . $uri . ' for user ' . $importer['importer_uid'] . ' was not found.');
DI::logger()->info('Item with URI ' . $uri . ' for user ' . $importer['importer_uid'] . ' was not found.');
return;
}
if (DBA::exists('post-category', ['uri-id' => $item['uri-id'], 'uid' => $importer['importer_uid'], 'type' => Post\Category::FILE])) {
Logger::notice('Item is filed. It will not be deleted.', ['uri' => $uri, 'uri-id' => $item['uri_id'], 'uid' => $importer['importer_uid']]);
DI::logger()->notice('Item is filed. It will not be deleted.', ['uri' => $uri, 'uri-id' => $item['uri_id'], 'uid' => $importer['importer_uid']]);
return;
}
// When it is a starting post it has to belong to the person that wants to delete it
if (($item['gravity'] == Item::GRAVITY_PARENT) && ($item['contact-id'] != $importer['id'])) {
Logger::info('Item with URI ' . $uri . ' do not belong to contact ' . $importer['id'] . ' - ignoring deletion.');
DI::logger()->info('Item with URI ' . $uri . ' do not belong to contact ' . $importer['id'] . ' - ignoring deletion.');
return;
}
@ -2118,7 +2117,7 @@ class DFRN
if (($item['gravity'] != Item::GRAVITY_PARENT) && ($item['contact-id'] != $importer['id'])) {
$condition = ['id' => $item['parent'], 'contact-id' => $importer['id']];
if (!Post::exists($condition)) {
Logger::info('Item with URI ' . $uri . ' was not found or must not be deleted by contact ' . $importer['id'] . ' - ignoring deletion.');
DI::logger()->info('Item with URI ' . $uri . ' was not found or must not be deleted by contact ' . $importer['id'] . ' - ignoring deletion.');
return;
}
}
@ -2127,7 +2126,7 @@ class DFRN
return;
}
Logger::info('deleting item '.$item['id'].' uri='.$uri);
DI::logger()->info('deleting item '.$item['id'].' uri='.$uri);
Item::markForDeletion(['id' => $item['id']]);
}
@ -2190,7 +2189,7 @@ class DFRN
self::fetchauthor($xpath, $doc->firstChild, $importer, 'dfrn:owner', false, $xml);
}
Logger::info("Import DFRN message for user " . $importer['importer_uid'] . " from contact " . $importer['id']);
DI::logger()->info("Import DFRN message for user " . $importer['importer_uid'] . " from contact " . $importer['id']);
if (!empty($importer['gsid']) && ($protocol == Conversation::PARCEL_DIASPORA_DFRN)) {
GServer::setProtocol($importer['gsid'], Post\DeliveryData::DFRN);
@ -2263,7 +2262,7 @@ class DFRN
self::processDeletion($xpath, $deletion, $importer);
}
if (count($deletions) > 0) {
Logger::info(count($deletions) . ' deletions had been processed');
DI::logger()->info(count($deletions) . ' deletions had been processed');
return 200;
}
}
@ -2273,7 +2272,7 @@ class DFRN
self::processEntry($header, $xpath, $entry, $importer, $xml, $protocol);
}
Logger::info("Import done for user " . $importer['importer_uid'] . " from contact " . $importer['id']);
DI::logger()->info("Import done for user " . $importer['importer_uid'] . " from contact " . $importer['id']);
return 200;
}

57
src/Protocol/Delivery.php
View file

@ -9,7 +9,6 @@ namespace Friendica\Protocol;
use Friendica\Contact\FriendSuggest\Collection\FriendSuggests;
use Friendica\Contact\FriendSuggest\Exception\FriendSuggestNotFoundException;
use Friendica\Core\Logger;
use Friendica\Core\Protocol;
use Friendica\Core\Worker;
use Friendica\Database\DBA;
@ -42,7 +41,7 @@ class Delivery
*/
public static function deliver(string $cmd, int $post_uriid, int $contact_id, int $sender_uid = 0): bool
{
Logger::info('Invoked', ['cmd' => $cmd, 'target' => $post_uriid, 'sender_uid' => $sender_uid, 'contact' => $contact_id]);
DI::logger()->info('Invoked', ['cmd' => $cmd, 'target' => $post_uriid, 'sender_uid' => $sender_uid, 'contact' => $contact_id]);
$top_level = false;
$followup = false;
@ -71,7 +70,7 @@ class Delivery
} else {
$item = Post::selectFirst(['id', 'parent'], ['uri-id' => $post_uriid, 'uid' => $sender_uid]);
if (!DBA::isResult($item) || empty($item['parent'])) {
Logger::warning('Post not found', ['uri-id' => $post_uriid, 'uid' => $sender_uid]);
DI::logger()->warning('Post not found', ['uri-id' => $post_uriid, 'uid' => $sender_uid]);
return true;
}
$target_id = intval($item['id']);
@ -97,12 +96,12 @@ class Delivery
DBA::close($itemdata);
if (empty($target_item)) {
Logger::warning("No target item data. Quitting here.", ['id' => $target_id]);
DI::logger()->warning("No target item data. Quitting here.", ['id' => $target_id]);
return true;
}
if (empty($parent)) {
Logger::warning('Parent ' . $parent_id . ' for item ' . $target_id . "wasn't found. Quitting here.");
DI::logger()->warning('Parent ' . $parent_id . ' for item ' . $target_id . "wasn't found. Quitting here.");
self::setFailedQueue($cmd, $target_item);
return true;
}
@ -112,7 +111,7 @@ class Delivery
} elseif (!empty($target_item['uid'])) {
$uid = $target_item['uid'];
} else {
Logger::info('Only public users for item ' . $target_id);
DI::logger()->info('Only public users for item ' . $target_id);
self::setFailedQueue($cmd, $target_item);
return true;
}
@ -126,7 +125,7 @@ class Delivery
}
if (!empty($contact_id) && Contact::isArchived($contact_id)) {
Logger::info('Contact is archived', ['id' => $contact_id, 'cmd' => $cmd, 'item' => $target_item['id']]);
DI::logger()->info('Contact is archived', ['id' => $contact_id, 'cmd' => $cmd, 'item' => $target_item['id']]);
self::setFailedQueue($cmd, $target_item);
return true;
}
@ -161,7 +160,7 @@ class Delivery
*/
if (!$top_level && ($parent['wall'] == 0) && stristr($target_item['uri'], $localhost)) {
Logger::info('Followup ' . $target_item["guid"]);
DI::logger()->info('Followup ' . $target_item["guid"]);
// local followup to remote post
$followup = true;
}
@ -176,7 +175,7 @@ class Delivery
}
if (empty($items)) {
Logger::warning('No delivery data', ['command' => $cmd, 'uri-id' => $post_uriid, 'cid' => $contact_id]);
DI::logger()->warning('No delivery data', ['command' => $cmd, 'uri-id' => $post_uriid, 'cid' => $contact_id]);
}
$owner = User::getOwnerDataById($uid);
@ -206,11 +205,11 @@ class Delivery
// This is done since the uri wouldn't match (Diaspora doesn't transmit it)
// Also transmit relayed posts from Diaspora contacts via Diaspora.
if (($contact['network'] != Protocol::DIASPORA) && in_array(Protocol::DIASPORA, [$parent['network'] ?? '', $thr_parent['network'] ?? '', $target_item['network'] ?? ''])) {
Logger::info('Enforcing the Diaspora protocol', ['id' => $contact['id'], 'network' => $contact['network'], 'parent' => $parent['network'], 'thread-parent' => $thr_parent['network'], 'post' => $target_item['network']]);
DI::logger()->info('Enforcing the Diaspora protocol', ['id' => $contact['id'], 'network' => $contact['network'], 'parent' => $parent['network'], 'thread-parent' => $thr_parent['network'], 'post' => $target_item['network']]);
$contact['network'] = Protocol::DIASPORA;
}
Logger::notice('Delivering', ['cmd' => $cmd, 'uri-id' => $post_uriid, 'followup' => $followup, 'network' => $contact['network']]);
DI::logger()->notice('Delivering', ['cmd' => $cmd, 'uri-id' => $post_uriid, 'followup' => $followup, 'network' => $contact['network']]);
switch ($contact['network']) {
case Protocol::DFRN:
@ -273,11 +272,11 @@ class Delivery
// Transmit Diaspora reshares via Diaspora if the Friendica contact support Diaspora
if (Diaspora::getReshareDetails($target_item) && Diaspora::isSupportedByContactUrl($contact['addr'])) {
Logger::info('Reshare will be transmitted via Diaspora', ['url' => $contact['url'], 'guid' => $target_item_id]);
DI::logger()->info('Reshare will be transmitted via Diaspora', ['url' => $contact['url'], 'guid' => $target_item_id]);
return self::deliverDiaspora($cmd, $contact, $owner, $items, $target_item, $public_message, $top_level, $followup);
}
Logger::info('Deliver ' . ($target_item_id ?? 'relocation') . ' via DFRN to ' . ($contact['addr'] ?? '' ?: $contact['url']));
DI::logger()->info('Deliver ' . ($target_item_id ?? 'relocation') . ' via DFRN to ' . ($contact['addr'] ?? '' ?: $contact['url']));
if ($cmd == self::MAIL) {
$item = $target_item;
@ -309,7 +308,7 @@ class Delivery
$atom = DFRN::entries($msgitems, $owner);
}
Logger::debug('Notifier entry: ' . $contact['url'] . ' ' . ($target_item_id ?? 'relocation') . ' entry: ' . $atom);
DI::logger()->debug('Notifier entry: ' . $contact['url'] . ' ' . ($target_item_id ?? 'relocation') . ' entry: ' . $atom);
$protocol = Post\DeliveryData::DFRN;
@ -323,7 +322,7 @@ class Delivery
// We never spool failed relay deliveries
if ($public_dfrn) {
Logger::info('Relay delivery to ' . $contact['url'] . ' with guid ' . $target_item['guid'] . ' returns ' . $deliver_status);
DI::logger()->info('Relay delivery to ' . $contact['url'] . ' with guid ' . $target_item['guid'] . ' returns ' . $deliver_status);
$success = ($deliver_status >= 200) && ($deliver_status <= 299);
@ -345,7 +344,7 @@ class Delivery
$deliver_status = DFRN::transmit($owner, $contact, $atom);
}
Logger::info('DFRN Delivery', ['cmd' => $cmd, 'url' => $contact['url'], 'guid' => $target_item_id, 'return' => $deliver_status]);
DI::logger()->info('DFRN Delivery', ['cmd' => $cmd, 'url' => $contact['url'], 'guid' => $target_item_id, 'return' => $deliver_status]);
if (($deliver_status >= 200) && ($deliver_status <= 299)) {
// We successfully delivered a message, the contact is alive
@ -361,7 +360,7 @@ class Delivery
// The message could not be delivered. We mark the contact as "dead"
Contact::markForArchival($contact);
Logger::info('Delivery failed: defer message', ['id' => $target_item_id]);
DI::logger()->info('Delivery failed: defer message', ['id' => $target_item_id]);
if (!Worker::defer() && $cmd == Delivery::POST) {
Post\DeliveryData::incrementQueueFailed($target_item['uri-id']);
}
@ -397,7 +396,7 @@ class Delivery
$loc = $contact['addr'];
}
Logger::notice('Deliver via Diaspora', ['target' => $target_item['id'], 'guid' => $target_item['guid'], 'to' => $loc]);
DI::logger()->notice('Deliver via Diaspora', ['target' => $target_item['id'], 'guid' => $target_item['guid'], 'to' => $loc]);
if (!DI::config()->get('system', 'diaspora_enabled')) {
return true;
@ -420,22 +419,22 @@ class Delivery
$deliver_status = Diaspora::sendAccountMigration($owner, $contact, $owner['uid']);
} elseif ($target_item['deleted'] && (($target_item['uri'] === $target_item['parent-uri']) || $followup)) {
// top-level retraction
Logger::notice('diaspora retract: ' . $loc);
DI::logger()->notice('diaspora retract: ' . $loc);
$deliver_status = Diaspora::sendRetraction($target_item, $owner, $contact, $public_message);
} elseif ($followup) {
// send comments and likes to owner to relay
Logger::notice('diaspora followup: ' . $loc);
DI::logger()->notice('diaspora followup: ' . $loc);
$deliver_status = Diaspora::sendFollowup($target_item, $owner, $contact, $public_message);
} elseif ($target_item['uri'] !== $target_item['parent-uri']) {
// we are the relay - send comments, likes and relayable_retractions to our conversants
Logger::notice('diaspora relay: ' . $loc);
DI::logger()->notice('diaspora relay: ' . $loc);
$deliver_status = Diaspora::sendRelay($target_item, $owner, $contact, $public_message);
} elseif ($top_level && !$walltowall) {
// currently no workable solution for sending walltowall
Logger::notice('diaspora status: ' . $loc);
DI::logger()->notice('diaspora status: ' . $loc);
$deliver_status = Diaspora::sendStatus($target_item, $owner, $contact, $public_message);
} else {
Logger::warning('Unknown mode', ['command' => $cmd, 'target' => $loc]);
DI::logger()->warning('Unknown mode', ['command' => $cmd, 'target' => $loc]);
return true;
}
@ -459,7 +458,7 @@ class Delivery
}
if (empty($contact['contact-type']) || ($contact['contact-type'] != Contact::TYPE_RELAY)) {
Logger::info('Delivery failed: defer message', ['id' => ($target_item['guid'] ?? '') ?: $target_item['id']]);
DI::logger()->info('Delivery failed: defer message', ['id' => ($target_item['guid'] ?? '') ?: $target_item['id']]);
// defer message for redelivery
if (!Worker::defer() && $cmd == Delivery::POST) {
Post\DeliveryData::incrementQueueFailed($target_item['uri-id']);
@ -508,10 +507,10 @@ class Delivery
$data = json_decode($thr_parent['object'], true);
if (!empty($data['reply_to'])) {
$addr = $data['reply_to'][0]['mailbox'] . '@' . $data['reply_to'][0]['host'];
Logger::info('Use "reply-to" address of the thread parent', ['addr' => $addr]);
DI::logger()->info('Use "reply-to" address of the thread parent', ['addr' => $addr]);
} elseif (!empty($data['from'])) {
$addr = $data['from'][0]['mailbox'] . '@' . $data['from'][0]['host'];
Logger::info('Use "from" address of the thread parent', ['addr' => $addr]);
DI::logger()->info('Use "from" address of the thread parent', ['addr' => $addr]);
}
}
@ -520,7 +519,7 @@ class Delivery
return true;
}
Logger::info('About to deliver via mail', ['guid' => $target_item['guid'], 'to' => $addr]);
DI::logger()->info('About to deliver via mail', ['guid' => $target_item['guid'], 'to' => $addr]);
$reply_to = '';
$mailacct = DBA::selectFirst('mailacct', ['reply_to'], ['uid' => $owner['uid']]);
@ -583,10 +582,10 @@ class Delivery
if ($success) {
// Success
Post\DeliveryData::incrementQueueDone($target_item['uri-id'], Post\DeliveryData::MAIL);
Logger::info('Delivered via mail', ['guid' => $target_item['guid'], 'to' => $addr, 'subject' => $subject]);
DI::logger()->info('Delivered via mail', ['guid' => $target_item['guid'], 'to' => $addr, 'subject' => $subject]);
} else {
// Failed
Logger::warning('Delivery of mail has FAILED', ['to' => $addr, 'subject' => $subject, 'guid' => $target_item['guid']]);
DI::logger()->warning('Delivery of mail has FAILED', ['to' => $addr, 'subject' => $subject, 'guid' => $target_item['guid']]);
}
return $success;
}

331
src/Protocol/Diaspora.php
View file

File diff suppressed because it is too large Load diff

16
src/Protocol/Email.php
View file

@ -8,10 +8,10 @@
namespace Friendica\Protocol;
use Friendica\Core\Hook;
use Friendica\Core\Logger;
use Friendica\Content\Text\BBCode;
use Friendica\Content\Text\HTML;
use Friendica\Core\Protocol;
use Friendica\DI;
use Friendica\Model\Item;
use Friendica\Util\Strings;
use IMAP\Connection;
@ -38,12 +38,12 @@ class Email
$errors = imap_errors();
if (!empty($errors)) {
Logger::notice('IMAP Errors occurred', ['errors' => $errors]);
DI::logger()->notice('IMAP Errors occurred', ['errors' => $errors]);
}
$alerts = imap_alerts();
if (!empty($alerts)) {
Logger::notice('IMAP Alerts occurred: ', ['alerts' => $alerts]);
DI::logger()->notice('IMAP Alerts occurred: ', ['alerts' => $alerts]);
}
if (empty($errors) && empty($alerts)) {
@ -67,7 +67,7 @@ class Email
if (!$search1) {
$search1 = [];
} else {
Logger::debug("Found mails from ".$email_addr);
DI::logger()->debug("Found mails from ".$email_addr);
Item::incrementInbound(Protocol::MAIL);
}
@ -75,7 +75,7 @@ class Email
if (!$search2) {
$search2 = [];
} else {
Logger::debug("Found mails to ".$email_addr);
DI::logger()->debug("Found mails to ".$email_addr);
Item::incrementInbound(Protocol::MAIL);
}
@ -83,7 +83,7 @@ class Email
if (!$search3) {
$search3 = [];
} else {
Logger::debug("Found mails cc ".$email_addr);
DI::logger()->debug("Found mails cc ".$email_addr);
Item::incrementInbound(Protocol::MAIL);
}
@ -131,7 +131,7 @@ class Email
$struc = (($mbox && $uid) ? @imap_fetchstructure($mbox, $uid, FT_UID) : null);
if (!$struc) {
Logger::notice("IMAP structure couldn't be fetched", ['uid' => $uid]);
DI::logger()->notice("IMAP structure couldn't be fetched", ['uid' => $uid]);
return $ret;
}
@ -395,7 +395,7 @@ class Email
//$message = '<html><body>' . $html . '</body></html>';
//$message = html2plain($html);
Logger::notice('notifier: email delivery to ' . $addr);
DI::logger()->notice('notifier: email delivery to ' . $addr);
$success = mail($addr, $subject, $body, $headers);
if ($success) {
Item::incrementOutbound(Protocol::MAIL);

45
src/Protocol/Feed.php
View file

@ -15,7 +15,6 @@ use Friendica\Contact\LocalRelationship\Entity\LocalRelationship;
use Friendica\Content\PageInfo;
use Friendica\Content\Text\BBCode;
use Friendica\Content\Text\HTML;
use Friendica\Core\Logger;
use Friendica\Core\Protocol;
use Friendica\Core\Worker;
use Friendica\Database\DBA;
@ -56,15 +55,15 @@ class Feed
$dryRun = empty($importer) && empty($contact);
if ($dryRun) {
Logger::info("Test Atom/RSS feed");
DI::logger()->info("Test Atom/RSS feed");
} else {
Logger::info('Import Atom/RSS feed "' . $contact['name'] . '" (Contact ' . $contact['id'] . ') for user ' . $importer['uid']);
DI::logger()->info('Import Atom/RSS feed "' . $contact['name'] . '" (Contact ' . $contact['id'] . ') for user ' . $importer['uid']);
}
$xml = trim($xml);
if (empty($xml)) {
Logger::info('XML is empty.');
DI::logger()->info('XML is empty.');
return [];
}
@ -274,7 +273,7 @@ class Feed
$datarray['direction'] = Conversation::PULL;
if (!is_object($entries)) {
Logger::info("There are no entries in this feed.");
DI::logger()->info("There are no entries in this feed.");
return [];
}
@ -383,7 +382,7 @@ class Feed
try {
$item['plink'] = DI::httpClient()->finalUrl($item['plink']);
} catch (TransferException $exception) {
Logger::notice('Item URL couldn\'t get expanded', ['url' => $item['plink'], 'exception' => $exception]);
DI::logger()->notice('Item URL couldn\'t get expanded', ['url' => $item['plink'], 'exception' => $exception]);
}
}
@ -442,7 +441,7 @@ class Feed
if (DBA::isResult($previous)) {
// Use the creation date when the post had been stored. It can happen this date changes in the feed.
$creation_dates[] = $previous['created'];
Logger::info('Item with URI ' . $item['uri'] . ' for user ' . $importer['uid'] . ' already existed under id ' . $previous['id']);
DI::logger()->info('Item with URI ' . $item['uri'] . ' for user ' . $importer['uid'] . ' already existed under id ' . $previous['id']);
continue;
}
$creation_dates[] = DateTimeFormat::utc($item['created']);
@ -550,10 +549,10 @@ class Feed
$items[] = $item;
break;
} elseif (!Item::isValid($item)) {
Logger::info('Feed item is invalid', ['created' => $item['created'], 'uid' => $item['uid'], 'uri' => $item['uri']]);
DI::logger()->info('Feed item is invalid', ['created' => $item['created'], 'uid' => $item['uid'], 'uri' => $item['uri']]);
continue;
} elseif (DI::contentItem()->isTooOld($item['created'], $item['uid'])) {
Logger::info('Feed is too old', ['created' => $item['created'], 'uid' => $item['uid'], 'uri' => $item['uri']]);
DI::logger()->info('Feed is too old', ['created' => $item['created'], 'uid' => $item['uid'], 'uri' => $item['uri']]);
continue;
}
@ -673,7 +672,7 @@ class Feed
$item['post-type'] = Item::PT_NOTE;
}
Logger::info('Stored feed', ['item' => $item]);
DI::logger()->info('Stored feed', ['item' => $item]);
$notify = Item::isRemoteSelf($contact, $item);
$item['wall'] = (bool)$notify;
@ -702,7 +701,7 @@ class Feed
];
}
} else {
Logger::info('Post already created or exists in the delayed posts queue', ['uid' => $item['uid'], 'uri' => $item['uri']]);
DI::logger()->info('Post already created or exists in the delayed posts queue', ['uid' => $item['uid'], 'uri' => $item['uri']]);
}
}
@ -713,7 +712,7 @@ class Feed
// Posts shouldn't be delayed more than a day
$interval = min(1440, self::getPollInterval($contact));
$delay = max(round(($interval * 60) / $total), 60 * $min_posting);
Logger::info('Got posting delay', ['delay' => $delay, 'interval' => $interval, 'items' => $total, 'cid' => $contact['id'], 'url' => $contact['url']]);
DI::logger()->info('Got posting delay', ['delay' => $delay, 'interval' => $interval, 'items' => $total, 'cid' => $contact['id'], 'url' => $contact['url']]);
} else {
$delay = 0;
}
@ -790,7 +789,7 @@ class Feed
private static function adjustPollFrequency(array $contact, array $creation_dates)
{
if ($contact['network'] != Protocol::FEED) {
Logger::info('Contact is no feed, skip.', ['id' => $contact['id'], 'uid' => $contact['uid'], 'url' => $contact['url'], 'network' => $contact['network']]);
DI::logger()->info('Contact is no feed, skip.', ['id' => $contact['id'], 'uid' => $contact['uid'], 'url' => $contact['url'], 'network' => $contact['network']]);
return;
}
@ -831,22 +830,22 @@ class Feed
}
if (count($creation_dates) == 1) {
Logger::info('Feed had posted a single time, switching to daily polling', ['newest' => $newest_date, 'id' => $contact['id'], 'uid' => $contact['uid'], 'url' => $contact['url']]);
DI::logger()->info('Feed had posted a single time, switching to daily polling', ['newest' => $newest_date, 'id' => $contact['id'], 'uid' => $contact['uid'], 'url' => $contact['url']]);
$priority = 8; // Poll once a day
}
if (empty($priority) && (((time() / 86400) - $newest) > 730)) {
Logger::info('Feed had not posted for two years, switching to monthly polling', ['newest' => $newest_date, 'id' => $contact['id'], 'uid' => $contact['uid'], 'url' => $contact['url']]);
DI::logger()->info('Feed had not posted for two years, switching to monthly polling', ['newest' => $newest_date, 'id' => $contact['id'], 'uid' => $contact['uid'], 'url' => $contact['url']]);
$priority = 10; // Poll every month
}
if (empty($priority) && (((time() / 86400) - $newest) > 365)) {
Logger::info('Feed had not posted for a year, switching to weekly polling', ['newest' => $newest_date, 'id' => $contact['id'], 'uid' => $contact['uid'], 'url' => $contact['url']]);
DI::logger()->info('Feed had not posted for a year, switching to weekly polling', ['newest' => $newest_date, 'id' => $contact['id'], 'uid' => $contact['uid'], 'url' => $contact['url']]);
$priority = 9; // Poll every week
}
if (empty($priority) && empty($frequency)) {
Logger::info('Feed had not posted for at least a week, switching to daily polling', ['newest' => $newest_date, 'id' => $contact['id'], 'uid' => $contact['uid'], 'url' => $contact['url']]);
DI::logger()->info('Feed had not posted for at least a week, switching to daily polling', ['newest' => $newest_date, 'id' => $contact['id'], 'uid' => $contact['uid'], 'url' => $contact['url']]);
$priority = 8; // Poll once a day
}
@ -883,15 +882,15 @@ class Feed
} else {
$priority = 7; // Poll twice a day
}
Logger::info('Calculated priority by the posts per day', ['priority' => $priority, 'max' => round($max, 2), 'id' => $contact['id'], 'uid' => $contact['uid'], 'url' => $contact['url']]);
DI::logger()->info('Calculated priority by the posts per day', ['priority' => $priority, 'max' => round($max, 2), 'id' => $contact['id'], 'uid' => $contact['uid'], 'url' => $contact['url']]);
}
} else {
Logger::info('No posts, switching to daily polling', ['id' => $contact['id'], 'uid' => $contact['uid'], 'url' => $contact['url']]);
DI::logger()->info('No posts, switching to daily polling', ['id' => $contact['id'], 'uid' => $contact['uid'], 'url' => $contact['url']]);
$priority = 8; // Poll once a day
}
if ($contact['rating'] != $priority) {
Logger::notice('Adjusting priority', ['old' => $contact['rating'], 'new' => $priority, 'id' => $contact['id'], 'uid' => $contact['uid'], 'url' => $contact['url']]);
DI::logger()->notice('Adjusting priority', ['old' => $contact['rating'], 'new' => $priority, 'id' => $contact['id'], 'uid' => $contact['uid'], 'url' => $contact['url']]);
Contact::update(['rating' => $priority], ['id' => $contact['id']]);
}
}
@ -1066,7 +1065,7 @@ class Feed
$feeddata = trim($doc->saveXML());
Logger::info('Feed duration', ['seconds' => number_format(microtime(true) - $stamp, 3), 'nick' => $owner['nickname'], 'filter' => $filter, 'created' => $previous_created]);
DI::logger()->info('Feed duration', ['seconds' => number_format(microtime(true) - $stamp, 3), 'nick' => $owner['nickname'], 'filter' => $filter, 'created' => $previous_created]);
return $feeddata;
}
@ -1153,7 +1152,7 @@ class Feed
private static function noteEntry(DOMDocument $doc, array $item, array $owner): DOMElement
{
if (($item['gravity'] != Item::GRAVITY_PARENT) && (Strings::normaliseLink($item['author-link']) != Strings::normaliseLink($owner['url']))) {
Logger::info('Feed entry author does not match feed owner', ['owner' => $owner['url'], 'author' => $item['author-link']]);
DI::logger()->info('Feed entry author does not match feed owner', ['owner' => $owner['url'], 'author' => $item['author-link']]);
}
$entry = self::entryHeader($doc, $owner, $item, false);
@ -1307,7 +1306,7 @@ class Feed
if (!HTML::isHTML($body)) {
$html = BBCode::convert($body, false, BBCode::EXTERNAL);
if ($body != $html) {
Logger::debug('Body contained no HTML', ['original' => $body, 'converted' => $html]);
DI::logger()->debug('Body contained no HTML', ['original' => $body, 'converted' => $html]);
$body = $html;
}
}

47
src/Protocol/Relay.php
View file

@ -11,7 +11,6 @@ use Exception;
use Friendica\Content\Smilies;
use Friendica\Content\Text\BBCode;
use Friendica\Core\L10n;
use Friendica\Core\Logger;
use Friendica\Core\Protocol;
use Friendica\Database\DBA;
use Friendica\DI;
@ -54,24 +53,24 @@ class Relay
$config = DI::config();
if (Contact::hasFollowers($authorid)) {
Logger::info('Author has got followers on this server - accepted', ['network' => $network, 'url' => $url, 'author' => $authorid, 'tags' => $tags]);
DI::logger()->info('Author has got followers on this server - accepted', ['network' => $network, 'url' => $url, 'author' => $authorid, 'tags' => $tags]);
return true;
}
$scope = $config->get('system', 'relay_scope');
if ($scope == self::SCOPE_NONE) {
Logger::info('Server does not accept relay posts - rejected', ['network' => $network, 'url' => $url]);
DI::logger()->info('Server does not accept relay posts - rejected', ['network' => $network, 'url' => $url]);
return false;
}
if (Contact::isBlocked($authorid)) {
Logger::info('Author is blocked - rejected', ['author' => $authorid, 'network' => $network, 'url' => $url]);
DI::logger()->info('Author is blocked - rejected', ['author' => $authorid, 'network' => $network, 'url' => $url]);
return false;
}
if (Contact::isHidden($authorid)) {
Logger::info('Author is hidden - rejected', ['author' => $authorid, 'network' => $network, 'url' => $url]);
DI::logger()->info('Author is hidden - rejected', ['author' => $authorid, 'network' => $network, 'url' => $url]);
return false;
}
@ -101,7 +100,7 @@ class Relay
$content_cleaned = mb_strtolower(BBCode::toPlaintext($cleaned, false));
if (strlen($content_cleaned) < strlen($content) / 2) {
Logger::info('Possible hashtag spam detected - rejected', ['hashtags' => $tags, 'network' => $network, 'url' => $url, 'causer' => $causer, 'content' => $content]);
DI::logger()->info('Possible hashtag spam detected - rejected', ['hashtags' => $tags, 'network' => $network, 'url' => $url, 'causer' => $causer, 'content' => $content]);
return false;
}
}
@ -109,35 +108,35 @@ class Relay
foreach ($tags as $tag) {
$tag = mb_strtolower($tag);
if (in_array($tag, $denyTags)) {
Logger::info('Unwanted hashtag found - rejected', ['hashtag' => $tag, 'network' => $network, 'url' => $url, 'causer' => $causer]);
DI::logger()->info('Unwanted hashtag found - rejected', ['hashtag' => $tag, 'network' => $network, 'url' => $url, 'causer' => $causer]);
return false;
}
if (in_array($tag, $tagList)) {
Logger::info('Subscribed hashtag found - accepted', ['hashtag' => $tag, 'network' => $network, 'url' => $url, 'causer' => $causer]);
DI::logger()->info('Subscribed hashtag found - accepted', ['hashtag' => $tag, 'network' => $network, 'url' => $url, 'causer' => $causer]);
return true;
}
// We check with "strpos" for performance issues. Only when this is true, the regular expression check is used
// RegExp is taken from here: https://medium.com/@shiba1014/regex-word-boundaries-with-unicode-207794f6e7ed
if ((strpos($content, $tag) !== false) && preg_match('/(?<=[\s,.:;"\']|^)' . preg_quote($tag, '/') . '(?=[\s,.:;"\']|$)/', $content)) {
Logger::info('Subscribed hashtag found in content - accepted', ['hashtag' => $tag, 'network' => $network, 'url' => $url, 'causer' => $causer]);
DI::logger()->info('Subscribed hashtag found in content - accepted', ['hashtag' => $tag, 'network' => $network, 'url' => $url, 'causer' => $causer]);
return true;
}
}
}
if (!self::isWantedLanguage($body, 0, $authorid, $languages)) {
Logger::info('Unwanted or Undetected language found - rejected', ['network' => $network, 'url' => $url, 'causer' => $causer, 'tags' => $tags]);
DI::logger()->info('Unwanted or Undetected language found - rejected', ['network' => $network, 'url' => $url, 'causer' => $causer, 'tags' => $tags]);
return false;
}
if ($scope == self::SCOPE_ALL) {
Logger::info('Server accept all posts - accepted', ['network' => $network, 'url' => $url, 'causer' => $causer, 'tags' => $tags]);
DI::logger()->info('Server accept all posts - accepted', ['network' => $network, 'url' => $url, 'causer' => $causer, 'tags' => $tags]);
return true;
}
Logger::info('No matching hashtags found - rejected', ['network' => $network, 'url' => $url, 'causer' => $causer, 'tags' => $tags]);
DI::logger()->info('No matching hashtags found - rejected', ['network' => $network, 'url' => $url, 'causer' => $causer, 'tags' => $tags]);
return false;
}
@ -181,7 +180,7 @@ class Relay
}
if (empty($body) || Smilies::isEmojiPost($body)) {
Logger::debug('Empty body or only emojis', ['body' => $body]);
DI::logger()->debug('Empty body or only emojis', ['body' => $body]);
return true;
}
@ -189,17 +188,17 @@ class Relay
foreach ($detected as $language) {
if (in_array($language, $user_languages)) {
Logger::debug('Wanted language found in detected languages', ['language' => $language, 'detected' => $detected, 'userlang' => $user_languages, 'body' => $body]);
DI::logger()->debug('Wanted language found in detected languages', ['language' => $language, 'detected' => $detected, 'userlang' => $user_languages, 'body' => $body]);
return true;
}
}
foreach ($languages as $language) {
if (in_array($language, $user_languages)) {
Logger::debug('Wanted language found in defined languages', ['language' => $language, 'languages' => $languages, 'detected' => $detected, 'userlang' => $user_languages, 'body' => $body]);
DI::logger()->debug('Wanted language found in defined languages', ['language' => $language, 'languages' => $languages, 'detected' => $detected, 'userlang' => $user_languages, 'body' => $body]);
return true;
}
}
Logger::debug('No wanted language found', ['languages' => $languages, 'detected' => $detected, 'userlang' => $user_languages, 'body' => $body]);
DI::logger()->debug('No wanted language found', ['languages' => $languages, 'detected' => $detected, 'userlang' => $user_languages, 'body' => $body]);
return false;
}
@ -216,9 +215,9 @@ class Relay
if (in_array($gserver['network'], [Protocol::ACTIVITYPUB, Protocol::DFRN])) {
$system = APContact::getByURL($gserver['url'] . '/friendica');
if (!empty($system['sharedinbox'])) {
Logger::info('Successfully probed for relay contact', ['server' => $gserver['url']]);
DI::logger()->info('Successfully probed for relay contact', ['server' => $gserver['url']]);
$id = Contact::updateFromProbeByURL($system['url']);
Logger::info('Updated relay contact', ['server' => $gserver['url'], 'id' => $id]);
DI::logger()->info('Updated relay contact', ['server' => $gserver['url'], 'id' => $id]);
return;
}
}
@ -231,10 +230,10 @@ class Relay
if (DBA::isResult($old)) {
$fields['gsid'] = $gserver['id'];
$fields['contact-type'] = Contact::TYPE_RELAY;
Logger::info('Assigning missing data for relay contact', ['server' => $gserver['url'], 'id' => $old['id']]);
DI::logger()->info('Assigning missing data for relay contact', ['server' => $gserver['url'], 'id' => $old['id']]);
}
} elseif (empty($fields) && $old['unsearchable']) {
Logger::info('No content to update, quitting', ['server' => $gserver['url']]);
DI::logger()->info('No content to update, quitting', ['server' => $gserver['url']]);
return;
}
@ -242,7 +241,7 @@ class Relay
$fields['updated'] = DateTimeFormat::utcNow();
$fields['unsearchable'] = true;
Logger::info('Update relay contact', ['server' => $gserver['url'], 'id' => $old['id'], 'fields' => $fields]);
DI::logger()->info('Update relay contact', ['server' => $gserver['url'], 'id' => $old['id'], 'fields' => $fields]);
Contact::update($fields, ['id' => $old['id']], $old);
} else {
$default = ['created' => DateTimeFormat::utcNow(),
@ -258,7 +257,7 @@ class Relay
$fields = array_merge($default, $fields);
Logger::info('Create relay contact', ['server' => $gserver['url'], 'fields' => $fields]);
DI::logger()->info('Create relay contact', ['server' => $gserver['url'], 'fields' => $fields]);
Contact::insert($fields);
}
}
@ -291,7 +290,7 @@ class Relay
}
if (!empty($relay_contact)) {
Logger::info('Relay contact will be marked for archival', ['id' => $relay_contact['id'], 'url' => $relay_contact['url']]);
DI::logger()->info('Relay contact will be marked for archival', ['id' => $relay_contact['id'], 'url' => $relay_contact['url']]);
Contact::markForArchival($relay_contact);
}
}
@ -421,7 +420,7 @@ class Relay
{
foreach (self::getList() as $server) {
$success = ActivityPub\Transmitter::sendRelayFollow($server['url']);
Logger::debug('Resubscribed', ['profile' => $server['url'], 'success' => $success]);
DI::logger()->debug('Resubscribed', ['profile' => $server['url'], 'success' => $success]);
}
}
}

3
src/Protocol/ZOT.php
View file

@ -9,7 +9,6 @@ namespace Friendica\Protocol;
use Friendica\App;
use Friendica\Core\Addon;
use Friendica\Core\Logger;
use Friendica\DI;
use Friendica\Module;
use Friendica\Module\Register;
@ -30,7 +29,7 @@ class ZOT
public static function isRequest(): bool
{
if (stristr($_SERVER['HTTP_ACCEPT'] ?? '', 'application/x-zot+json')) {
Logger::debug('Is ZOT request', ['accept' => $_SERVER['HTTP_ACCEPT'], 'agent' => $_SERVER['HTTP_USER_AGENT'] ?? '']);
DI::logger()->debug('Is ZOT request', ['accept' => $_SERVER['HTTP_ACCEPT'], 'agent' => $_SERVER['HTTP_USER_AGENT'] ?? '']);
return true;
}