From 8c1db51a760dd60745c55592fd08dee03c2d8a52 Mon Sep 17 00:00:00 2001 From: Hypolite Petovan Date: Fri, 22 Feb 2019 23:00:16 -0500 Subject: [PATCH] Improve Logger calls - Replace various deprecated Logger::log calls - Reassign log level for verbose log calls --- include/enotify.php | 6 +++--- mod/item.php | 2 +- src/Database/DBA.php | 2 +- src/Model/Item.php | 17 ++++++++--------- src/Protocol/ActivityPub/Processor.php | 8 ++++++-- src/Protocol/ActivityPub/Receiver.php | 8 ++++---- src/Protocol/DFRN.php | 2 +- src/Protocol/Diaspora.php | 2 +- src/Util/XML.php | 6 ++++-- 9 files changed, 29 insertions(+), 24 deletions(-) diff --git a/include/enotify.php b/include/enotify.php index 58e1a75f00..db44b464de 100644 --- a/include/enotify.php +++ b/include/enotify.php @@ -33,8 +33,8 @@ function notification($params) $a = \get_app(); // Temporary logging for finding the origin - if (!isset($params['language']) || !isset($params['uid'])) { - Logger::log('Missing parameters.' . System::callstack()); + if (!isset($params['uid'])) { + Logger::notice('Missing parameters "uid".', ['params' => $params, 'callstack' => System::callstack()]); } // Ensure that the important fields are set at any time @@ -42,7 +42,7 @@ function notification($params) $user = DBA::selectFirst('user', $fields, ['uid' => $params['uid']]); if (!DBA::isResult($user)) { - Logger::log('Unknown user ' . $params['uid']); + Logger::error('Unknown user', ['uid' => $params['uid']]); return false; } diff --git a/mod/item.php b/mod/item.php index 40c01da20f..100205f1c4 100644 --- a/mod/item.php +++ b/mod/item.php @@ -131,7 +131,7 @@ function item_post(App $a) { } if ($parent) { - Logger::log('mod_item: item_post parent=' . $parent); + Logger::info('mod_item: item_post parent=' . $toplevel_item_id); } $post_id = intval(defaults($_REQUEST, 'post_id', 0)); diff --git a/src/Database/DBA.php b/src/Database/DBA.php index 897ab2e6ed..326fb0771d 100644 --- a/src/Database/DBA.php +++ b/src/Database/DBA.php @@ -425,7 +425,7 @@ class DBA if ((substr_count($sql, '?') != count($args)) && (count($args) > 0)) { // Question: Should we continue or stop the query here? - Logger::log('Parameter mismatch. Query "'.$sql.'" - Parameters '.print_r($args, true), Logger::DEBUG); + Logger::error('Parameter mismatch. Query "'.$sql.'" - Parameters '.print_r($args, true)); } $sql = self::cleanQuery($sql); diff --git a/src/Model/Item.php b/src/Model/Item.php index 475f9131fd..e4d18c9a74 100644 --- a/src/Model/Item.php +++ b/src/Model/Item.php @@ -1336,7 +1336,7 @@ class Item extends BaseObject $expire_date = time() - ($expire_interval * 86400); $created_date = strtotime($item['created']); if ($created_date < $expire_date) { - Logger::log('item-store: item created ('.date('c', $created_date).') before expiration time ('.date('c', $expire_date).'). ignored. ' . print_r($item,true), Logger::DEBUG); + Logger::notice('item-store: item created ('.date('c', $created_date).') before expiration time ('.date('c', $expire_date).'). ignored. ' . print_r($item,true)); return 0; } } @@ -1354,7 +1354,7 @@ class Item extends BaseObject if (DBA::isResult($existing)) { // We only log the entries with a different user id than 0. Otherwise we would have too many false positives if ($uid != 0) { - Logger::log("Item with uri ".$item['uri']." already existed for user ".$uid." with id ".$existing["id"]." target network ".$existing["network"]." - new network: ".$item['network']); + Logger::notice("Item with uri ".$item['uri']." already existed for user ".$uid." with id ".$existing["id"]." target network ".$existing["network"]." - new network: ".$item['network']); } return $existing["id"]; @@ -1405,7 +1405,7 @@ class Item extends BaseObject // When there is no content then we don't post it if ($item['body'].$item['title'] == '') { - Logger::log('No body, no title.'); + Logger::notice('No body, no title.'); return 0; } @@ -1432,7 +1432,7 @@ class Item extends BaseObject $item['author-id'] = defaults($item, 'author-id', Contact::getIdForURL($item["author-link"], 0, false, $default)); if (Contact::isBlocked($item["author-id"])) { - Logger::log('Contact '.$item["author-id"].' is blocked, item '.$item["uri"].' will not be stored'); + Logger::notice('Contact '.$item["author-id"].' is blocked, item '.$item["uri"].' will not be stored'); return 0; } @@ -1442,22 +1442,21 @@ class Item extends BaseObject $item['owner-id'] = defaults($item, 'owner-id', Contact::getIdForURL($item["owner-link"], 0, false, $default)); if (Contact::isBlocked($item["owner-id"])) { - Logger::log('Contact '.$item["owner-id"].' is blocked, item '.$item["uri"].' will not be stored'); + Logger::notice('Contact '.$item["owner-id"].' is blocked, item '.$item["uri"].' will not be stored'); return 0; } if ($item['network'] == Protocol::PHANTOM) { - Logger::log('Missing network. Called by: '.System::callstack(), Logger::DEBUG); + Logger::notice('Missing network. Called by: '.System::callstack(), Logger::DEBUG); $item['network'] = Protocol::DFRN; - Logger::log("Set network to " . $item["network"] . " for " . $item["uri"], Logger::DEBUG); + Logger::notice("Set network to " . $item["network"] . " for " . $item["uri"], Logger::DEBUG); } // Checking if there is already an item with the same guid - Logger::log('Checking for an item for user '.$item['uid'].' on network '.$item['network'].' with the guid '.$item['guid'], Logger::DEBUG); $condition = ['guid' => $item['guid'], 'network' => $item['network'], 'uid' => $item['uid']]; if (self::exists($condition)) { - Logger::log('found item with guid '.$item['guid'].' for user '.$item['uid'].' on network '.$item['network'], Logger::DEBUG); + Logger::notice('Found already existing item with guid '.$item['guid'].' for user '.$item['uid'].' on network '.$item['network']); return 0; } diff --git a/src/Protocol/ActivityPub/Processor.php b/src/Protocol/ActivityPub/Processor.php index f4befcd6f1..5899d7f25f 100644 --- a/src/Protocol/ActivityPub/Processor.php +++ b/src/Protocol/ActivityPub/Processor.php @@ -289,7 +289,7 @@ class Processor $item['owner-link'] = $activity['actor']; $item['owner-id'] = Contact::getIdForURL($activity['actor'], 0, true); } else { - Logger::log('Ignoring actor because of thread completion.', Logger::DEBUG); + Logger::info('Ignoring actor because of thread completion.'); $item['owner-link'] = $item['author-link']; $item['owner-id'] = $item['author-id']; } @@ -358,7 +358,11 @@ class Processor } $item_id = Item::insert($item); - Logger::log('Storing for user ' . $item['uid'] . ': ' . $item_id); + if ($item_id) { + Logger::info('Item insertion successful', ['user' => $item['uid'], 'item_id' => $item_id]); + } else { + Logger::notice('Item insertion aborted', ['user' => $item['uid']]); + } if ($item['uid'] == 0) { $stored = $item_id; diff --git a/src/Protocol/ActivityPub/Receiver.php b/src/Protocol/ActivityPub/Receiver.php index e0ee1f0f90..5ee81302f2 100644 --- a/src/Protocol/ActivityPub/Receiver.php +++ b/src/Protocol/ActivityPub/Receiver.php @@ -62,16 +62,16 @@ class Receiver { $http_signer = HTTPSignature::getSigner($body, $header); if (empty($http_signer)) { - Logger::log('Invalid HTTP signature, message will be discarded.', Logger::DEBUG); + Logger::warning('Invalid HTTP signature, message will be discarded.'); return; } else { - Logger::log('HTTP signature is signed by ' . $http_signer, Logger::DEBUG); + Logger::info('Valid HTTP signature', ['signer' => $http_signer]); } $activity = json_decode($body, true); if (empty($activity)) { - Logger::log('Invalid body.', Logger::DEBUG); + Logger::warning('Invalid body.'); return; } @@ -79,7 +79,7 @@ class Receiver $actor = JsonLD::fetchElement($ldactivity, 'as:actor'); - Logger::log('Message for user ' . $uid . ' is from actor ' . $actor, Logger::DEBUG); + Logger::info('Message for user ' . $uid . ' is from actor ' . $actor); if (LDSignature::isSigned($activity)) { $ld_signer = LDSignature::getSigner($activity); diff --git a/src/Protocol/DFRN.php b/src/Protocol/DFRN.php index e6524de965..39d982bb92 100644 --- a/src/Protocol/DFRN.php +++ b/src/Protocol/DFRN.php @@ -1546,7 +1546,7 @@ class DFRN $author["network"] = $contact_old["network"]; } else { if (!$onlyfetch) { - Logger::log("Contact ".$author["link"]." wasn't found for user ".$importer["importer_uid"]." XML: ".$xml, Logger::DEBUG); + Logger::debug("Contact ".$author["link"]." wasn't found for user ".$importer["importer_uid"]." XML: ".$xml); } $author["contact-unknown"] = true; diff --git a/src/Protocol/Diaspora.php b/src/Protocol/Diaspora.php index 77ad017044..3687fb9d4b 100644 --- a/src/Protocol/Diaspora.php +++ b/src/Protocol/Diaspora.php @@ -942,7 +942,7 @@ class Diaspora $person = DBA::selectFirst('fcontact', [], ['network' => Protocol::DIASPORA, 'addr' => $handle]); if (DBA::isResult($person)) { - Logger::log("In cache " . print_r($person, true), Logger::DEBUG); + Logger::debug("In cache " . print_r($person, true)); // update record occasionally so it doesn't get stale $d = strtotime($person["updated"]." +00:00"); diff --git a/src/Util/XML.php b/src/Util/XML.php index ba146ec7b8..4dd6d84ecb 100644 --- a/src/Util/XML.php +++ b/src/Util/XML.php @@ -6,6 +6,7 @@ namespace Friendica\Util; use Friendica\Core\Logger; use DOMXPath; +use Friendica\Core\System; use SimpleXMLElement; /** @@ -422,10 +423,11 @@ class XML $x = @simplexml_load_string($s); if (!$x) { - Logger::log('libxml: parse: error: ' . $s, Logger::DATA); + Logger::error('Error(s) while parsing XML string.', ['callstack' => System::callstack()]); foreach (libxml_get_errors() as $err) { - Logger::log('libxml: parse: ' . $err->code." at ".$err->line.":".$err->column." : ".$err->message, Logger::DATA); + Logger::info('libxml error', ['code' => $err->code, 'position' => $err->line . ":" . $err->column, 'message' => $err->message]); } + Logger::debug('Erroring XML string', ['xml' => $s]); libxml_clear_errors(); } return $x; -- 2.39.5