Replace Logger with DI::logger() in OnePoll Worker classes

This commit is contained in:
Art4 2025-01-13 13:21:19 +00:00
parent 90a76ec60b
commit abe6bf7947

View file

@ -7,7 +7,6 @@
namespace Friendica\Worker; namespace Friendica\Worker;
use Friendica\Core\Logger;
use Friendica\Core\Protocol; use Friendica\Core\Protocol;
use Friendica\Core\System; use Friendica\Core\System;
use Friendica\Database\DBA; use Friendica\Database\DBA;
@ -21,7 +20,6 @@ use Friendica\Network\HTTPClient\Client\HttpClientAccept;
use Friendica\Network\HTTPClient\Client\HttpClientOptions; use Friendica\Network\HTTPClient\Client\HttpClientOptions;
use Friendica\Network\HTTPClient\Client\HttpClientRequest; use Friendica\Network\HTTPClient\Client\HttpClientRequest;
use Friendica\Protocol\Activity; use Friendica\Protocol\Activity;
use Friendica\Protocol\ActivityPub;
use Friendica\Protocol\Email; use Friendica\Protocol\Email;
use Friendica\Protocol\Feed; use Friendica\Protocol\Feed;
use Friendica\Util\DateTimeFormat; use Friendica\Util\DateTimeFormat;
@ -32,18 +30,18 @@ class OnePoll
{ {
public static function execute(int $contact_id = 0, string $command = '') public static function execute(int $contact_id = 0, string $command = '')
{ {
Logger::notice('Start polling/probing contact', ['id' => $contact_id, 'command' => $command]); DI::logger()->notice('Start polling/probing contact', ['id' => $contact_id, 'command' => $command]);
$force = ($command == 'force'); $force = ($command == 'force');
if (empty($contact_id)) { if (empty($contact_id)) {
Logger::notice('no contact provided'); DI::logger()->notice('no contact provided');
return; return;
} }
$contact = DBA::selectFirst('contact', [], ['id' => $contact_id]); $contact = DBA::selectFirst('contact', [], ['id' => $contact_id]);
if (!DBA::isResult($contact)) { if (!DBA::isResult($contact)) {
Logger::warning('Contact not found', ['id' => $contact_id]); DI::logger()->warning('Contact not found', ['id' => $contact_id]);
return; return;
} }
@ -65,14 +63,14 @@ class OnePoll
&& in_array($contact['network'], [Protocol::FEED, Protocol::MAIL])) { && in_array($contact['network'], [Protocol::FEED, Protocol::MAIL])) {
$importer = User::getOwnerDataById($importer_uid); $importer = User::getOwnerDataById($importer_uid);
if (empty($importer)) { if (empty($importer)) {
Logger::warning('No self contact for user', ['uid' => $importer_uid]); DI::logger()->warning('No self contact for user', ['uid' => $importer_uid]);
// set the last-update so we don't keep polling // set the last-update so we don't keep polling
Contact::update(['last-update' => $updated], ['id' => $contact['id']]); Contact::update(['last-update' => $updated], ['id' => $contact['id']]);
return; return;
} }
Logger::info('Start polling/subscribing', ['protocol' => $contact['network'], 'id' => $contact['id']]); DI::logger()->info('Start polling/subscribing', ['protocol' => $contact['network'], 'id' => $contact['id']]);
if ($contact['network'] === Protocol::FEED) { if ($contact['network'] === Protocol::FEED) {
$success = self::pollFeed($contact, $importer); $success = self::pollFeed($contact, $importer);
} elseif ($contact['network'] === Protocol::MAIL) { } elseif ($contact['network'] === Protocol::MAIL) {
@ -81,7 +79,7 @@ class OnePoll
$success = self::subscribeToHub($contact['url'], $importer, $contact, $contact['blocked'] ? 'unsubscribe' : 'subscribe'); $success = self::subscribeToHub($contact['url'], $importer, $contact, $contact['blocked'] ? 'unsubscribe' : 'subscribe');
} }
if (!$success) { if (!$success) {
Logger::notice('Probing had been successful, polling/subscribing failed', ['protocol' => $contact['network'], 'id' => $contact['id'], 'url' => $contact['url']]); DI::logger()->notice('Probing had been successful, polling/subscribing failed', ['protocol' => $contact['network'], 'id' => $contact['id'], 'url' => $contact['url']]);
} }
} }
@ -93,7 +91,7 @@ class OnePoll
Contact::markForArchival($contact); Contact::markForArchival($contact);
} }
Logger::notice('End'); DI::logger()->notice('End');
return; return;
} }
@ -136,12 +134,12 @@ class OnePoll
{ {
// Are we allowed to import from this person? // Are we allowed to import from this person?
if ($contact['rel'] == Contact::FOLLOWER || $contact['blocked']) { if ($contact['rel'] == Contact::FOLLOWER || $contact['blocked']) {
Logger::notice('Contact is blocked or only a follower'); DI::logger()->notice('Contact is blocked or only a follower');
return false; return false;
} }
if (!Network::isValidHttpUrl($contact['poll'])) { if (!Network::isValidHttpUrl($contact['poll'])) {
Logger::warning('Poll address is not valid', ['id' => $contact['id'], 'uid' => $contact['uid'], 'url' => $contact['url'], 'poll' => $contact['poll']]); DI::logger()->warning('Poll address is not valid', ['id' => $contact['id'], 'uid' => $contact['uid'], 'url' => $contact['url'], 'poll' => $contact['poll']]);
return false; return false;
} }
@ -150,25 +148,25 @@ class OnePoll
try { try {
$curlResult = DI::httpClient()->get($contact['poll'], HttpClientAccept::FEED_XML, [HttpClientOptions::COOKIEJAR => $cookiejar, HttpClientOptions::REQUEST => HttpClientRequest::FEEDFETCHER]); $curlResult = DI::httpClient()->get($contact['poll'], HttpClientAccept::FEED_XML, [HttpClientOptions::COOKIEJAR => $cookiejar, HttpClientOptions::REQUEST => HttpClientRequest::FEEDFETCHER]);
} catch (\Throwable $th) { } 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 false; return false;
} }
unlink($cookiejar); unlink($cookiejar);
Logger::debug('Polled feed', ['url' => $contact['poll'], 'http-code' => $curlResult->getReturnCode(), 'redirect-url' => $curlResult->getRedirectUrl()]); DI::logger()->debug('Polled feed', ['url' => $contact['poll'], 'http-code' => $curlResult->getReturnCode(), 'redirect-url' => $curlResult->getRedirectUrl()]);
if ($curlResult->isTimeout()) { if ($curlResult->isTimeout()) {
Logger::notice('Polling timed out', ['id' => $contact['id'], 'url' => $contact['poll']]); DI::logger()->notice('Polling timed out', ['id' => $contact['id'], 'url' => $contact['poll']]);
return false; return false;
} }
if ($curlResult->isGone()) { if ($curlResult->isGone()) {
Logger::notice('URL is permanently gone', ['id' => $contact['id'], 'url' => $contact['poll']]); DI::logger()->notice('URL is permanently gone', ['id' => $contact['id'], 'url' => $contact['poll']]);
Contact::remove($contact['id']); Contact::remove($contact['id']);
return false; return false;
} }
if ($curlResult->redirectIsPermanent()) { if ($curlResult->redirectIsPermanent()) {
Logger::notice('Poll address permanently changed', [ DI::logger()->notice('Poll address permanently changed', [
'id' => $contact['id'], 'id' => $contact['id'],
'uid' => $contact['uid'], 'uid' => $contact['uid'],
'old' => $contact['poll'], 'old' => $contact['poll'],
@ -179,21 +177,21 @@ class OnePoll
$xml = $curlResult->getBodyString(); $xml = $curlResult->getBodyString();
if (empty($xml)) { if (empty($xml)) {
Logger::notice('Empty content', ['id' => $contact['id'], 'url' => $contact['poll']]); DI::logger()->notice('Empty content', ['id' => $contact['id'], 'url' => $contact['poll']]);
return false; return false;
} }
if (strpos($curlResult->getContentType(), 'xml') === false) { if (strpos($curlResult->getContentType(), 'xml') === false) {
Logger::notice('Unexpected content type.', ['id' => $contact['id'], 'url' => $contact['poll'], 'content-type' => $curlResult->getContentType()]); DI::logger()->notice('Unexpected content type.', ['id' => $contact['id'], 'url' => $contact['poll'], 'content-type' => $curlResult->getContentType()]);
return false; return false;
} }
if (!strstr($xml, '<')) { if (!strstr($xml, '<')) {
Logger::notice('response did not contain XML.', ['id' => $contact['id'], 'url' => $contact['poll']]); DI::logger()->notice('response did not contain XML.', ['id' => $contact['id'], 'url' => $contact['poll']]);
return false; return false;
} }
Logger::notice('Consume feed of contact', ['id' => $contact['id'], 'url' => $contact['poll'], 'Content-Type' => $curlResult->getHeader('Content-Type')]); DI::logger()->notice('Consume feed of contact', ['id' => $contact['id'], 'url' => $contact['poll'], 'Content-Type' => $curlResult->getHeader('Content-Type')]);
return !empty(Feed::import($xml, $importer, $contact)); return !empty(Feed::import($xml, $importer, $contact));
} }
@ -210,15 +208,15 @@ class OnePoll
*/ */
private static function pollMail(array $contact, int $importer_uid, string $updated): bool private static function pollMail(array $contact, int $importer_uid, string $updated): bool
{ {
Logger::info('Fetching mails', ['addr' => $contact['addr']]); DI::logger()->info('Fetching mails', ['addr' => $contact['addr']]);
$mail_disabled = ((function_exists('imap_open') && !DI::config()->get('system', 'imap_disabled')) ? 0 : 1); $mail_disabled = ((function_exists('imap_open') && !DI::config()->get('system', 'imap_disabled')) ? 0 : 1);
if ($mail_disabled) { if ($mail_disabled) {
Logger::notice('Mail is disabled'); DI::logger()->notice('Mail is disabled');
return false; return false;
} }
Logger::info('Mail is enabled'); DI::logger()->info('Mail is enabled');
$mbox = false; $mbox = false;
$user = DBA::selectFirst('user', ['prvkey'], ['uid' => $importer_uid]); $user = DBA::selectFirst('user', ['prvkey'], ['uid' => $importer_uid]);
@ -231,16 +229,16 @@ class OnePoll
openssl_private_decrypt(hex2bin($mailconf['pass']), $password, $user['prvkey']); openssl_private_decrypt(hex2bin($mailconf['pass']), $password, $user['prvkey']);
$mbox = Email::connect($mailbox, $mailconf['user'], $password); $mbox = Email::connect($mailbox, $mailconf['user'], $password);
unset($password); unset($password);
Logger::notice('Connect', ['user' => $mailconf['user']]); DI::logger()->notice('Connect', ['user' => $mailconf['user']]);
if ($mbox === false) { if ($mbox === false) {
Logger::notice('Connection error', ['user' => $mailconf['user'], 'error' => imap_errors()]); DI::logger()->notice('Connection error', ['user' => $mailconf['user'], 'error' => imap_errors()]);
return false; return false;
} }
$fields = ['last_check' => $updated]; $fields = ['last_check' => $updated];
DBA::update('mailacct', $fields, ['id' => $mailconf['id']]); DBA::update('mailacct', $fields, ['id' => $mailconf['id']]);
Logger::notice('Connected', ['user' => $mailconf['user']]); DI::logger()->notice('Connected', ['user' => $mailconf['user']]);
} }
if ($mbox === false) { if ($mbox === false) {
@ -250,12 +248,12 @@ class OnePoll
$msgs = Email::poll($mbox, $contact['addr']); $msgs = Email::poll($mbox, $contact['addr']);
if (count($msgs)) { if (count($msgs)) {
Logger::info('Parsing mails', ['count' => count($msgs), 'addr' => $contact['addr'], 'user' => $mailconf['user']]); DI::logger()->info('Parsing mails', ['count' => count($msgs), 'addr' => $contact['addr'], 'user' => $mailconf['user']]);
$metas = Email::messageMeta($mbox, implode(',', $msgs)); $metas = Email::messageMeta($mbox, implode(',', $msgs));
if (count($metas) != count($msgs)) { if (count($metas) != count($msgs)) {
Logger::info("for " . $mailconf['user'] . " there are ". count($msgs) . " messages but received " . count($metas) . " metas"); DI::logger()->info("for " . $mailconf['user'] . " there are ". count($msgs) . " messages but received " . count($metas) . " metas");
} else { } else {
$msgs = array_combine($msgs, $metas); $msgs = array_combine($msgs, $metas);
@ -264,7 +262,7 @@ class OnePoll
continue; continue;
} }
Logger::info('Parsing mail', ['message-uid' => $msg_uid]); DI::logger()->info('Parsing mail', ['message-uid' => $msg_uid]);
$datarray = [ $datarray = [
'uid' => $importer_uid, 'uid' => $importer_uid,
@ -284,7 +282,7 @@ class OnePoll
$condition = ['uid' => $importer_uid, 'uri' => $datarray['uri']]; $condition = ['uid' => $importer_uid, 'uri' => $datarray['uri']];
$item = Post::selectFirst($fields, $condition); $item = Post::selectFirst($fields, $condition);
if (DBA::isResult($item)) { if (DBA::isResult($item)) {
Logger::info('Mail: Seen before ' . $msg_uid . ' for ' . $mailconf['user'] . ' UID: ' . $importer_uid . ' URI: ' . $datarray['uri']); DI::logger()->info('Mail: Seen before ' . $msg_uid . ' for ' . $mailconf['user'] . ' UID: ' . $importer_uid . ' URI: ' . $datarray['uri']);
// Only delete when mails aren't automatically moved or deleted // Only delete when mails aren't automatically moved or deleted
if (($mailconf['action'] != 1) && ($mailconf['action'] != 3)) if (($mailconf['action'] != 1) && ($mailconf['action'] != 3))
@ -295,21 +293,21 @@ class OnePoll
switch ($mailconf['action']) { switch ($mailconf['action']) {
case 0: case 0:
Logger::info('Mail: Seen before ' . $msg_uid . ' for ' . $mailconf['user'] . '. Doing nothing.'); DI::logger()->info('Mail: Seen before ' . $msg_uid . ' for ' . $mailconf['user'] . '. Doing nothing.');
break; break;
case 1: case 1:
Logger::notice('Mail: Deleting ' . $msg_uid . ' for ' . $mailconf['user']); DI::logger()->notice('Mail: Deleting ' . $msg_uid . ' for ' . $mailconf['user']);
imap_delete($mbox, $msg_uid, FT_UID); imap_delete($mbox, $msg_uid, FT_UID);
break; break;
case 2: case 2:
Logger::notice('Mail: Mark as seen ' . $msg_uid . ' for ' . $mailconf['user']); DI::logger()->notice('Mail: Mark as seen ' . $msg_uid . ' for ' . $mailconf['user']);
imap_setflag_full($mbox, $msg_uid, "\\Seen", ST_UID); imap_setflag_full($mbox, $msg_uid, "\\Seen", ST_UID);
break; break;
case 3: case 3:
Logger::notice('Mail: Moving ' . $msg_uid . ' to ' . $mailconf['movetofolder'] . ' for ' . $mailconf['user']); DI::logger()->notice('Mail: Moving ' . $msg_uid . ' to ' . $mailconf['movetofolder'] . ' for ' . $mailconf['user']);
imap_setflag_full($mbox, $msg_uid, "\\Seen", ST_UID); imap_setflag_full($mbox, $msg_uid, "\\Seen", ST_UID);
if ($mailconf['movetofolder'] != '') { if ($mailconf['movetofolder'] != '') {
imap_mail_move($mbox, $msg_uid, $mailconf['movetofolder'], FT_UID); imap_mail_move($mbox, $msg_uid, $mailconf['movetofolder'], FT_UID);
@ -421,31 +419,31 @@ class OnePoll
$datarray = Email::getMessage($mbox, $msg_uid, $reply, $datarray); $datarray = Email::getMessage($mbox, $msg_uid, $reply, $datarray);
if (empty($datarray['body'])) { if (empty($datarray['body'])) {
Logger::warning('Cannot fetch mail', ['msg-id' => $msg_uid, 'uid' => $mailconf['user']]); DI::logger()->warning('Cannot fetch mail', ['msg-id' => $msg_uid, 'uid' => $mailconf['user']]);
continue; continue;
} }
Logger::notice('Mail: Importing ' . $msg_uid . ' for ' . $mailconf['user']); DI::logger()->notice('Mail: Importing ' . $msg_uid . ' for ' . $mailconf['user']);
Item::insert($datarray); Item::insert($datarray);
switch ($mailconf['action']) { switch ($mailconf['action']) {
case 0: case 0:
Logger::info('Mail: Seen before ' . $msg_uid . ' for ' . $mailconf['user'] . '. Doing nothing.'); DI::logger()->info('Mail: Seen before ' . $msg_uid . ' for ' . $mailconf['user'] . '. Doing nothing.');
break; break;
case 1: case 1:
Logger::notice('Mail: Deleting ' . $msg_uid . ' for ' . $mailconf['user']); DI::logger()->notice('Mail: Deleting ' . $msg_uid . ' for ' . $mailconf['user']);
imap_delete($mbox, $msg_uid, FT_UID); imap_delete($mbox, $msg_uid, FT_UID);
break; break;
case 2: case 2:
Logger::notice('Mail: Mark as seen ' . $msg_uid . ' for ' . $mailconf['user']); DI::logger()->notice('Mail: Mark as seen ' . $msg_uid . ' for ' . $mailconf['user']);
imap_setflag_full($mbox, $msg_uid, "\\Seen", ST_UID); imap_setflag_full($mbox, $msg_uid, "\\Seen", ST_UID);
break; break;
case 3: case 3:
Logger::notice('Mail: Moving ' . $msg_uid . ' to ' . $mailconf['movetofolder'] . ' for ' . $mailconf['user']); DI::logger()->notice('Mail: Moving ' . $msg_uid . ' to ' . $mailconf['movetofolder'] . ' for ' . $mailconf['user']);
imap_setflag_full($mbox, $msg_uid, "\\Seen", ST_UID); imap_setflag_full($mbox, $msg_uid, "\\Seen", ST_UID);
if ($mailconf['movetofolder'] != '') { if ($mailconf['movetofolder'] != '') {
imap_mail_move($mbox, $msg_uid, $mailconf['movetofolder'], FT_UID); imap_mail_move($mbox, $msg_uid, $mailconf['movetofolder'], FT_UID);
@ -455,11 +453,11 @@ class OnePoll
} }
} }
} else { } else {
Logger::notice('No mails', ['user' => $mailconf['user']]); DI::logger()->notice('No mails', ['user' => $mailconf['user']]);
} }
Logger::info('Closing connection', ['user' => $mailconf['user']]); DI::logger()->info('Closing connection', ['user' => $mailconf['user']]);
imap_close($mbox); imap_close($mbox);
return true; return true;
@ -492,7 +490,7 @@ class OnePoll
$params = 'hub.mode=' . $hubmode . '&hub.callback=' . urlencode($push_url) . '&hub.topic=' . urlencode($contact['poll']) . '&hub.verify=async&hub.verify_token=' . $verify_token; $params = 'hub.mode=' . $hubmode . '&hub.callback=' . urlencode($push_url) . '&hub.topic=' . urlencode($contact['poll']) . '&hub.verify=async&hub.verify_token=' . $verify_token;
Logger::info('Hub subscription start', ['mode' => $hubmode, 'name' => $contact['name'], 'hub' => $url, 'endpoint' => $push_url, 'verifier' => $verify_token]); DI::logger()->info('Hub subscription start', ['mode' => $hubmode, 'name' => $contact['name'], 'hub' => $url, 'endpoint' => $push_url, 'verifier' => $verify_token]);
if (!strlen($contact['hub-verify']) || ($contact['hub-verify'] != $verify_token)) { if (!strlen($contact['hub-verify']) || ($contact['hub-verify'] != $verify_token)) {
Contact::update(['hub-verify' => $verify_token], ['id' => $contact['id']]); Contact::update(['hub-verify' => $verify_token], ['id' => $contact['id']]);
@ -501,11 +499,11 @@ class OnePoll
try { try {
$postResult = DI::httpClient()->post($url, $params, [], 0, HttpClientRequest::PUBSUB); $postResult = DI::httpClient()->post($url, $params, [], 0, HttpClientRequest::PUBSUB);
} catch (\Throwable $th) { } 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 false; return false;
} }
Logger::info('Hub subscription done', ['result' => $postResult->getReturnCode()]); DI::logger()->info('Hub subscription done', ['result' => $postResult->getReturnCode()]);
return $postResult->isSuccess(); return $postResult->isSuccess();
} }