From fe8f0e00454919e3ee1150a2e75badb55a273c3a Mon Sep 17 00:00:00 2001 From: Philipp Holzer Date: Sun, 30 Dec 2018 21:42:56 +0100 Subject: [PATCH] Add Monolog --- bin/auth_ejabberd.php | 5 +- bin/console.php | 6 +- bin/daemon.php | 16 ++- bin/worker.php | 5 +- composer.json | 3 +- composer.lock | 195 +++++++++++++++++++-------- include/api.php | 75 ++++++----- index.php | 8 +- mod/acl.php | 2 +- src/App.php | 29 +++- src/App/FriendicaLoggerProcessor.php | 48 +++++++ src/BaseObject.php | 7 +- src/Core/Logger.php | 69 ++++++++-- tests/src/BaseObjectTest.php | 4 +- update.php | 12 +- 15 files changed, 363 insertions(+), 121 deletions(-) create mode 100644 src/App/FriendicaLoggerProcessor.php diff --git a/bin/auth_ejabberd.php b/bin/auth_ejabberd.php index e8a7b4963f..dcc4b19591 100755 --- a/bin/auth_ejabberd.php +++ b/bin/auth_ejabberd.php @@ -33,6 +33,7 @@ */ use Friendica\App; +use Friendica\Core\Logger; use Friendica\Util\ExAuth; if (sizeof($_SERVER["argv"]) == 0) { @@ -51,7 +52,9 @@ chdir($directory); require dirname(__DIR__) . '/vendor/autoload.php'; -$a = new App(dirname(__DIR__)); +$logger = Logger::create('ejabberd'); + +$a = new App(dirname(__DIR__), $logger); if ($a->getMode()->isNormal()) { $oAuth = new ExAuth(); diff --git a/bin/console.php b/bin/console.php index c39df953f2..d783e1159f 100755 --- a/bin/console.php +++ b/bin/console.php @@ -3,7 +3,11 @@ require dirname(__DIR__) . '/vendor/autoload.php'; -$a = new Friendica\App(dirname(__DIR__)); +use Friendica\Core\Logger; + +$logger = Logger::create('console'); + +$a = new Friendica\App(dirname(__DIR__), $logger); \Friendica\BaseObject::setApp($a); (new Friendica\Core\Console($argv))->execute(); diff --git a/bin/daemon.php b/bin/daemon.php index e60e32b19e..a65502f796 100755 --- a/bin/daemon.php +++ b/bin/daemon.php @@ -32,7 +32,9 @@ if (!file_exists("boot.php") && (sizeof($_SERVER["argv"]) != 0)) { require dirname(__DIR__) . '/vendor/autoload.php'; -$a = new App(dirname(__DIR__)); +$logger = Logger::create('daemon'); + +$a = new App(dirname(__DIR__), $logger); if ($a->getMode()->isInstall()) { die("Friendica isn't properly installed yet.\n"); @@ -102,7 +104,7 @@ if ($mode == "stop") { unlink($pidfile); - Logger::log("Worker daemon process $pid was killed.", Logger::DEBUG); + $logger->notice("Worker daemon process was killed", ["pid" => $pid]); Config::set('system', 'worker_daemon_mode', false); die("Worker daemon process $pid was killed.\n"); @@ -112,7 +114,7 @@ if (!empty($pid) && posix_kill($pid, 0)) { die("Daemon process $pid is already running.\n"); } -Logger::log('Starting worker daemon.', Logger::DEBUG); +$logger->notice('Starting worker daemon.', ["pid" => $pid]); if (!$foreground) { echo "Starting worker daemon.\n"; @@ -160,7 +162,7 @@ $last_cron = 0; // Now running as a daemon. while (true) { if (!$do_cron && ($last_cron + $wait_interval) < time()) { - Logger::log('Forcing cron worker call.', Logger::DEBUG); + $logger->info('Forcing cron worker call.', ["pid" => $pid]); $do_cron = true; } @@ -174,7 +176,7 @@ while (true) { $last_cron = time(); } - Logger::log("Sleeping", Logger::DEBUG); + $logger->info("Sleeping", ["pid" => $pid]); $start = time(); do { $seconds = (time() - $start); @@ -191,10 +193,10 @@ while (true) { if ($timeout) { $do_cron = true; - Logger::log("Woke up after $wait_interval seconds.", Logger::DEBUG); + $logger->info("Woke up after $wait_interval seconds.", ["pid" => $pid, 'sleep' => $wait_interval]); } else { $do_cron = false; - Logger::log("Worker jobs are calling to be forked.", Logger::DEBUG); + $logger->info("Worker jobs are calling to be forked.", ["pid" => $pid]); } } diff --git a/bin/worker.php b/bin/worker.php index 78b7a58a05..5b5e949757 100755 --- a/bin/worker.php +++ b/bin/worker.php @@ -6,6 +6,7 @@ */ use Friendica\App; use Friendica\Core\Config; +use Friendica\Core\Logger; use Friendica\Core\Worker; use Friendica\Core\Update; @@ -28,7 +29,9 @@ if (!file_exists("boot.php") && (sizeof($_SERVER["argv"]) != 0)) { require dirname(__DIR__) . '/vendor/autoload.php'; -$a = new App(dirname(__DIR__)); +$logger = Logger::create('worker'); + +$a = new App(dirname(__DIR__), $logger); // Check the database structure and possibly fixes it Update::check(true); diff --git a/composer.json b/composer.json index 8ac4c37724..2f254877de 100644 --- a/composer.json +++ b/composer.json @@ -42,7 +42,8 @@ "npm-asset/jgrowl": "^1.4", "npm-asset/fullcalendar": "^3.0.1", "npm-asset/cropperjs": "1.2.2", - "npm-asset/imagesloaded": "4.1.4" + "npm-asset/imagesloaded": "4.1.4", + "monolog/monolog": "^1.24" }, "repositories": [ { diff --git a/composer.lock b/composer.lock index 759ef65778..96a244b7d7 100644 --- a/composer.lock +++ b/composer.lock @@ -4,7 +4,7 @@ "Read more about it at https://getcomposer.org/doc/01-basic-usage.md#installing-dependencies", "This file is @generated automatically" ], - "content-hash": "51f7b3ab622038d7ef62ed03c06b48d0", + "content-hash": "8cf7268fbcae8a22a518b9e7727eab84", "packages": [ { "name": "asika/simple-console", @@ -809,6 +809,84 @@ ], "time": "2018-09-01T15:05:15+00:00" }, + { + "name": "monolog/monolog", + "version": "1.24.0", + "source": { + "type": "git", + "url": "https://github.com/Seldaek/monolog.git", + "reference": "bfc9ebb28f97e7a24c45bdc3f0ff482e47bb0266" + }, + "dist": { + "type": "zip", + "url": "https://api.github.com/repos/Seldaek/monolog/zipball/bfc9ebb28f97e7a24c45bdc3f0ff482e47bb0266", + "reference": "bfc9ebb28f97e7a24c45bdc3f0ff482e47bb0266", + "shasum": "" + }, + "require": { + "php": ">=5.3.0", + "psr/log": "~1.0" + }, + "provide": { + "psr/log-implementation": "1.0.0" + }, + "require-dev": { + "aws/aws-sdk-php": "^2.4.9 || ^3.0", + "doctrine/couchdb": "~1.0@dev", + "graylog2/gelf-php": "~1.0", + "jakub-onderka/php-parallel-lint": "0.9", + "php-amqplib/php-amqplib": "~2.4", + "php-console/php-console": "^3.1.3", + "phpunit/phpunit": "~4.5", + "phpunit/phpunit-mock-objects": "2.3.0", + "ruflin/elastica": ">=0.90 <3.0", + "sentry/sentry": "^0.13", + "swiftmailer/swiftmailer": "^5.3|^6.0" + }, + "suggest": { + "aws/aws-sdk-php": "Allow sending log messages to AWS services like DynamoDB", + "doctrine/couchdb": "Allow sending log messages to a CouchDB server", + "ext-amqp": "Allow sending log messages to an AMQP server (1.0+ required)", + "ext-mongo": "Allow sending log messages to a MongoDB server", + "graylog2/gelf-php": "Allow sending log messages to a GrayLog2 server", + "mongodb/mongodb": "Allow sending log messages to a MongoDB server via PHP Driver", + "php-amqplib/php-amqplib": "Allow sending log messages to an AMQP server using php-amqplib", + "php-console/php-console": "Allow sending log messages to Google Chrome", + "rollbar/rollbar": "Allow sending log messages to Rollbar", + "ruflin/elastica": "Allow sending log messages to an Elastic Search server", + "sentry/sentry": "Allow sending log messages to a Sentry server" + }, + "type": "library", + "extra": { + "branch-alias": { + "dev-master": "2.0.x-dev" + } + }, + "autoload": { + "psr-4": { + "Monolog\\": "src/Monolog" + } + }, + "notification-url": "https://packagist.org/downloads/", + "license": [ + "MIT" + ], + "authors": [ + { + "name": "Jordi Boggiano", + "email": "j.boggiano@seld.be", + "homepage": "http://seld.be" + } + ], + "description": "Sends your logs to files, sockets, inboxes, databases and various web services", + "homepage": "http://github.com/Seldaek/monolog", + "keywords": [ + "log", + "logging", + "psr-3" + ], + "time": "2018-11-05T09:00:11+00:00" + }, { "name": "npm-asset/cropperjs", "version": "1.2.2", @@ -1019,22 +1097,6 @@ "require": { "npm-asset/ev-emitter": ">=1.0.0,<2.0.0" }, - "require-dev": { - "npm-asset/chalk": ">=1.1.1,<2.0.0", - "npm-asset/cheerio": ">=0.19.0,<0.20.0", - "npm-asset/gulp": ">=3.9.0,<4.0.0", - "npm-asset/gulp-jshint": ">=1.11.2,<2.0.0", - "npm-asset/gulp-json-lint": ">=0.1.0,<0.2.0", - "npm-asset/gulp-rename": ">=1.2.2,<2.0.0", - "npm-asset/gulp-replace": ">=0.5.4,<0.6.0", - "npm-asset/gulp-requirejs-optimize": "dev-github:metafizzy/gulp-requirejs-optimize", - "npm-asset/gulp-uglify": ">=1.4.2,<2.0.0", - "npm-asset/gulp-util": ">=3.0.7,<4.0.0", - "npm-asset/highlight.js": ">=8.9.1,<9.0.0", - "npm-asset/marked": ">=0.3.5,<0.4.0", - "npm-asset/minimist": ">=1.2.0,<2.0.0", - "npm-asset/transfob": ">=1.0.0,<2.0.0" - }, "type": "npm-asset-library", "extra": { "npm-asset-bugs": { @@ -1080,14 +1142,6 @@ "reference": null, "shasum": "2736e332aaee73ccf0a14a5f0066391a0a13f4a3" }, - "require-dev": { - "npm-asset/grunt": "~0.4.2", - "npm-asset/grunt-contrib-cssmin": "~0.9.0", - "npm-asset/grunt-contrib-jshint": "~0.6.3", - "npm-asset/grunt-contrib-less": "~0.11.0", - "npm-asset/grunt-contrib-uglify": "~0.4.0", - "npm-asset/grunt-contrib-watch": "~0.6.1" - }, "type": "npm-asset-library", "extra": { "npm-asset-bugs": { @@ -1121,32 +1175,6 @@ "reference": null, "shasum": "2c89d6889b5eac522a7eea32c14521559c6cbf02" }, - "require-dev": { - "npm-asset/commitplease": "2.0.0", - "npm-asset/core-js": "0.9.17", - "npm-asset/grunt": "0.4.5", - "npm-asset/grunt-babel": "5.0.1", - "npm-asset/grunt-cli": "0.1.13", - "npm-asset/grunt-compare-size": "0.4.0", - "npm-asset/grunt-contrib-jshint": "0.11.2", - "npm-asset/grunt-contrib-uglify": "0.9.2", - "npm-asset/grunt-contrib-watch": "0.6.1", - "npm-asset/grunt-git-authors": "2.0.1", - "npm-asset/grunt-jscs": "2.1.0", - "npm-asset/grunt-jsonlint": "1.0.4", - "npm-asset/grunt-npmcopy": "0.1.0", - "npm-asset/gzip-js": "0.3.2", - "npm-asset/jsdom": "5.6.1", - "npm-asset/load-grunt-tasks": "1.0.0", - "npm-asset/qunit-assert-step": "1.0.3", - "npm-asset/qunitjs": "1.17.1", - "npm-asset/requirejs": "2.1.17", - "npm-asset/sinon": "1.10.3", - "npm-asset/sizzle": "2.2.1", - "npm-asset/strip-json-comments": "1.0.3", - "npm-asset/testswarm": "1.1.0", - "npm-asset/win-spawn": "2.0.0" - }, "type": "npm-asset-library", "extra": { "npm-asset-bugs": { @@ -1244,6 +1272,18 @@ "npm-asset/jquery-mousewheel": ">=3.1.13", "npm-asset/php-date-formatter": ">=1.3.4,<2.0.0" }, + "require-dev": { + "npm-asset/chai": ">=4.1.2,<5.0.0", + "npm-asset/concat": "dev-github:azer/concat", + "npm-asset/concat-cli": ">=4.0.0,<5.0.0", + "npm-asset/karma": ">=2.0.0,<3.0.0", + "npm-asset/karma-chai": ">=0.1.0,<0.2.0", + "npm-asset/karma-firefox-launcher": ">=1.1.0,<2.0.0", + "npm-asset/karma-mocha": ">=1.3.0,<2.0.0", + "npm-asset/mocha": ">=5.0.4,<6.0.0", + "npm-asset/uglifycss": ">=0.0.27,<0.0.28", + "npm-asset/uglifyjs": ">=2.4.10,<3.0.0" + }, "type": "npm-asset-library", "extra": { "npm-asset-bugs": { @@ -1297,12 +1337,6 @@ "reference": null, "shasum": "06f0335f16e353a695e7206bf50503cb523a6ee5" }, - "require-dev": { - "npm-asset/grunt": "~0.4.1", - "npm-asset/grunt-contrib-connect": "~0.5.0", - "npm-asset/grunt-contrib-jshint": "~0.7.1", - "npm-asset/grunt-contrib-uglify": "~0.2.7" - }, "type": "npm-asset-library", "extra": { "npm-asset-bugs": { @@ -1854,6 +1888,53 @@ ], "time": "2016-08-06T14:39:51+00:00" }, + { + "name": "psr/log", + "version": "1.1.0", + "source": { + "type": "git", + "url": "https://github.com/php-fig/log.git", + "reference": "6c001f1daafa3a3ac1d8ff69ee4db8e799a654dd" + }, + "dist": { + "type": "zip", + "url": "https://api.github.com/repos/php-fig/log/zipball/6c001f1daafa3a3ac1d8ff69ee4db8e799a654dd", + "reference": "6c001f1daafa3a3ac1d8ff69ee4db8e799a654dd", + "shasum": "" + }, + "require": { + "php": ">=5.3.0" + }, + "type": "library", + "extra": { + "branch-alias": { + "dev-master": "1.0.x-dev" + } + }, + "autoload": { + "psr-4": { + "Psr\\Log\\": "Psr/Log/" + } + }, + "notification-url": "https://packagist.org/downloads/", + "license": [ + "MIT" + ], + "authors": [ + { + "name": "PHP-FIG", + "homepage": "http://www.php-fig.org/" + } + ], + "description": "Common interface for logging libraries", + "homepage": "https://github.com/php-fig/log", + "keywords": [ + "log", + "psr", + "psr-3" + ], + "time": "2018-11-20T15:27:04+00:00" + }, { "name": "seld/cli-prompt", "version": "1.0.3", diff --git a/include/api.php b/include/api.php index f28f182532..2085c801b8 100644 --- a/include/api.php +++ b/include/api.php @@ -181,7 +181,7 @@ function api_login(App $a) var_dump($consumer, $token); die(); } catch (Exception $e) { - Logger::log($e); + $a->getLogger()->warning('API login: error', ['module' => 'api', 'action' => 'login', 'exception' => $e->getMessage()]); } // workaround for HTTP-auth in CGI mode @@ -195,7 +195,7 @@ function api_login(App $a) } if (empty($_SERVER['PHP_AUTH_USER'])) { - Logger::log('API_login: ' . print_r($_SERVER, true), Logger::DEBUG); + $a->getLogger()->debug('API login: failed', ['module' => 'api', 'action' => 'login', 'parameters' => $_SERVER]); header('WWW-Authenticate: Basic realm="Friendica"'); throw new UnauthorizedException("This API requires login"); } @@ -236,7 +236,7 @@ function api_login(App $a) } if (!DBA::isResult($record)) { - Logger::log('API_login failure: ' . print_r($_SERVER, true), Logger::DEBUG); + $a->getLogger()->debug('API login: failed', ['module' => 'api', 'action' => 'login', 'parameters' => $_SERVER]); header('WWW-Authenticate: Basic realm="Friendica"'); //header('HTTP/1.0 401 Unauthorized'); //die('This api requires login'); @@ -309,33 +309,35 @@ function api_call(App $a) api_login($a); } - Logger::log('API call for ' . $a->user['username'] . ': ' . $a->query_string); - Logger::log('API parameters: ' . print_r($_REQUEST, true)); + $a->getLogger()->info('API call', ['module' => 'api', 'action' => 'call', 'username' => $a->user['username']]); + $a->getLogger()->debug('API parameters', ['module' => 'api', 'action' => 'call', 'parameters' => $_REQUEST]); $stamp = microtime(true); $return = call_user_func($info['func'], $type); $duration = (float) (microtime(true) - $stamp); - Logger::log("API call duration: " . round($duration, 2) . "\t" . $a->query_string, Logger::DEBUG); + + $a->getLogger()->info('API call', ['module' => 'api', 'action' => 'call', 'username' => $a->user['username'], 'duration' => round($duration, 2)]); if (Config::get("system", "profiler")) { $duration = microtime(true)-$a->performance["start"]; /// @TODO round() really everywhere? - Logger::log( - parse_url($a->query_string, PHP_URL_PATH) . ": " . sprintf( - "Database: %s/%s, Cache %s/%s, Network: %s, I/O: %s, Other: %s, Total: %s", - round($a->performance["database"] - $a->performance["database_write"], 3), - round($a->performance["database_write"], 3), - round($a->performance["cache"], 3), - round($a->performance["cache_write"], 3), - round($a->performance["network"], 2), - round($a->performance["file"], 2), - round($duration - ($a->performance["database"] - + $a->performance["cache"] + $a->performance["cache_write"] - + $a->performance["network"] + $a->performance["file"]), 2), - round($duration, 2) - ), - Logger::DEBUG + $a->getLogger()->debug( + 'API call performance', + [ + 'module' => 'api', + 'action' => 'performance', + 'database_read' => round($a->performance["database"] - $a->performance["database_write"], 3), + 'database_write' => round($a->performance["database_write"], 3), + 'cache_read' => round($a->performance["cache"], 3), + 'cache_write' => round($a->performance["cache_write"], 3), + 'network_io' => round($a->performance["network"], 2), + 'file_io' => round($a->performance["file"], 2), + 'other_io' => round($duration - ($a->performance["database"] + + $a->performance["cache"] + $a->performance["cache_write"] + + $a->performance["network"] + $a->performance["file"]), 2), + 'total' => round($duration, 2) + ] ); if (Config::get("rendertime", "callstack")) { @@ -376,7 +378,7 @@ function api_call(App $a) $o .= $func . ": " . $time . "\n"; } } - Logger::log($o, Logger::DEBUG); + $a->getLogger()->debug($o, ['module' => 'api', 'action' => 'performance']); } } @@ -413,7 +415,7 @@ function api_call(App $a) } } - Logger::log('API call not implemented: ' . $a->query_string); + $a->getLogger()->warning('API call not implemented'); throw new NotImplementedException(); } catch (HTTPException $e) { header("HTTP/1.1 {$e->httpcode} {$e->httpdesc}"); @@ -522,7 +524,7 @@ function api_get_user(App $a, $contact_id = null) $extra_query = ""; $url = ""; - Logger::log("api_get_user: Fetching user data for user ".$contact_id, Logger::DEBUG); + $a->getLogger()->info('api_get_user: Fetching user data', ['module' => 'api', 'action' => 'get_user', 'user' => $contact_id]); // Searching for contact URL if (!is_null($contact_id) && (intval($contact_id) == 0)) { @@ -606,7 +608,7 @@ function api_get_user(App $a, $contact_id = null) } } - Logger::log("api_get_user: user ".$user, Logger::DEBUG); + $a->getLogger()->info('api_get_user: getting user', ['module' => 'api', 'action' => 'get_user', 'user' => $user]); if (!$user) { if (api_user() === false) { @@ -618,7 +620,7 @@ function api_get_user(App $a, $contact_id = null) } } - Logger::log('api_user: ' . $extra_query . ', user: ' . $user); + $a->getLogger()->info('api_get_user: found user', ['module' => 'api', 'action' => 'get_user', 'user' => $user, 'extra_query' => $extra_query]); // user info $uinfo = q( @@ -1937,7 +1939,7 @@ function api_conversation_show($type) $id = intval(defaults($a->argv, 4, 0)); } - Logger::log('API: api_conversation_show: '.$id); + $a->getLogger()->info('API: api_conversation_show', ['module' => 'api', 'action' => 'conversation', 'id' => $id]); // try to fetch the item for the local user - or the public item, if there is no local one $item = Item::selectFirst(['parent-uri'], ['id' => $id]); @@ -2331,7 +2333,7 @@ function api_favorites($type) // in friendica starred item are private // return favorites only for self - Logger::log('api_favorites: self:' . $user_info['self']); + $a->getLogger()->info('API: api_favorites', ['module' => 'api', 'action' => 'favorites', 'self' => $user_info['self']]); if ($user_info['self'] == 0) { $ret = []; @@ -3686,6 +3688,7 @@ api_register_func('api/direct_messages/destroy', 'api_direct_messages_destroy', function api_friendships_destroy($type) { $uid = api_user(); + $a = get_app(); if ($uid === false) { throw new ForbiddenException(); @@ -3694,7 +3697,7 @@ function api_friendships_destroy($type) $contact_id = defaults($_REQUEST, 'user_id'); if (empty($contact_id)) { - Logger::log("No user_id specified", Logger::DEBUG); + $a->getLogger()->notice('No user_id specified', ['module' => 'api', 'action' => 'friendships_destroy']); throw new BadRequestException("no user_id specified"); } @@ -3702,7 +3705,7 @@ function api_friendships_destroy($type) $contact = DBA::selectFirst('contact', ['url'], ['id' => $contact_id, 'uid' => 0, 'self' => false]); if(!DBA::isResult($contact)) { - Logger::log("No contact found for ID" . $contact_id, Logger::DEBUG); + $a->getLogger()->notice('No contact found for ID', ['module' => 'api', 'action' => 'friendships_destroy', 'contact' => $contact_id]); throw new NotFoundException("no contact found to given ID"); } @@ -3714,12 +3717,12 @@ function api_friendships_destroy($type) $contact = DBA::selectFirst('contact', [], $condition); if (!DBA::isResult($contact)) { - Logger::log("Not following Contact", Logger::DEBUG); + $a->getLogger()->notice('Not following contact', ['module' => 'api', 'action' => 'friendships_destroy']); throw new NotFoundException("Not following Contact"); } if (!in_array($contact['network'], Protocol::NATIVE_SUPPORT)) { - Logger::log("Not supported", Logger::DEBUG); + $a->getLogger()->notice('Not supported', ['module' => 'api', 'action' => 'friendships_destroy', 'network' => $contact['network']]); throw new ExpectationFailedException("Not supported"); } @@ -3730,7 +3733,7 @@ function api_friendships_destroy($type) Contact::terminateFriendship($owner, $contact, $dissolve); } else { - Logger::log("No owner found", Logger::DEBUG); + $a->getLogger()->notice('No owner found', ['module' => 'api', 'action' => 'friendships_destroy', 'uid' => $uid]); throw new NotFoundException("Error Processing Request"); } @@ -4837,7 +4840,8 @@ function api_friendica_remoteauth() 'sec' => $sec, 'expire' => time() + 45]; DBA::insert('profile_check', $fields); - Logger::log($contact['name'] . ' ' . $sec, Logger::DEBUG); + $a = get_app(); + $a->getLogger()->info('API: friendica_remoteauth', ['module' => 'api', 'action' => 'remoteauth', 'contact' => $contact['name'], 'hey' => $sec]); $dest = ($url ? '&destination_url=' . $url : ''); System::externalRedirect( @@ -5086,7 +5090,8 @@ function api_in_reply_to($item) // https://github.com/friendica/friendica/issues/1010 // This is a bugfix for that. if (intval($in_reply_to['status_id']) == intval($item['id'])) { - Logger::log('this message should never appear: id: '.$item['id'].' similar to reply-to: '.$in_reply_to['status_id'], Logger::DEBUG); + $a = get_app(); + $a->getLogger()->warning('ID is similar to reply-to', ['module' => 'api', 'action' => 'in_reply_to', 'id' => $item['id'], 'reply-to' => $in_reply_to['status_id']]); $in_reply_to['status_id'] = null; $in_reply_to['user_id'] = null; $in_reply_to['status_id_str'] = null; diff --git a/index.php b/index.php index b5b66da794..d4480549d7 100644 --- a/index.php +++ b/index.php @@ -4,15 +4,19 @@ * Friendica */ +use Friendica\App; +use Friendica\Core\Logger; + if (!file_exists(__DIR__ . '/vendor/autoload.php')) { die('Vendor path not found. Please execute "bin/composer.phar --no-dev install" on the command line in the web root.'); } require __DIR__ . '/vendor/autoload.php'; +$logger = Logger::create('app'); + // We assume that the index.php is called by a frontend process // The value is set to "true" by default in App -$a = new Friendica\App(__DIR__, false); +$a = new App(__DIR__, $logger, false); $a->runFrontend(); - diff --git a/mod/acl.php b/mod/acl.php index fc67556739..e7445a995b 100644 --- a/mod/acl.php +++ b/mod/acl.php @@ -34,7 +34,7 @@ function acl_content(App $a) $search = $_REQUEST['query']; } - Logger::log("Searching for ".$search." - type ".$type." conversation ".$conv_id, Logger::DEBUG); + $a->getLogger()->info("Searching for " . $search . " - type " . $type . " conversation " . $conv_id); if ($search != '') { $sql_extra = "AND `name` LIKE '%%" . DBA::escape($search) . "%%'"; diff --git a/src/App.php b/src/App.php index df350542ad..793590bae4 100644 --- a/src/App.php +++ b/src/App.php @@ -8,8 +8,10 @@ use Detection\MobileDetect; use DOMDocument; use DOMXPath; use Exception; +use Friendica\Core\Logger; use Friendica\Database\DBA; use Friendica\Network\HTTPException\InternalServerErrorException; +use Monolog; /** * @@ -106,6 +108,11 @@ class App */ public $mobileDetect; + /** + * @var Monolog\Logger The current logger of this App + */ + private $logger; + /** * Register a stylesheet file path to be included in the tag of every page. * Inclusion is done in App->initHead(). @@ -147,12 +154,15 @@ class App * @brief App constructor. * * @param string $basePath Path to the app base folder + * @param Monolog\Logger Logger of this application * @param bool $isBackend Whether it is used for backend or frontend (Default true=backend) * * @throws Exception if the Basepath is not usable */ - public function __construct($basePath, $isBackend = true) + public function __construct($basePath, $logger, $isBackend = true) { + $this->logger = $logger; + if (!static::isDirectoryUsable($basePath, false)) { throw new Exception('Basepath ' . $basePath . ' isn\'t usable.'); } @@ -301,6 +311,21 @@ class App return $this->mode; } + /** + * Returns the Logger of the Application + * + * @return Monolog\Logger The Logger + * @throws InternalServerErrorException when the logger isn't created + */ + public function getLogger() + { + if (empty($this->logger)) { + throw new InternalServerErrorException('Logger of the Application is not defined'); + } + + return $this->logger; + } + /** * Reloads the whole app instance */ @@ -328,6 +353,8 @@ class App Core\L10n::init(); $this->process_id = Core\System::processID('log'); + + Logger::loadDefaultHandler($this->logger, $this); } /** diff --git a/src/App/FriendicaLoggerProcessor.php b/src/App/FriendicaLoggerProcessor.php new file mode 100644 index 0000000000..bb359c9945 --- /dev/null +++ b/src/App/FriendicaLoggerProcessor.php @@ -0,0 +1,48 @@ +process_id" + * + * @package Friendica\App + */ +class FriendicaLoggerProcessor implements ProcessorInterface +{ + /** + * @var string the ID of the current Friendica process + */ + private $processId = null; + + /** + * Set the process id based on the Application instance + * + * @param string $processId the process id + */ + public function setProcessId($processId) + { + if (!isset($this->processId) || $this->processId == '') + { + $this->processId = $processId; + } + } + + public function __construct() + { + $this->processId = session_id(); + } + + public function __invoke(array $records) + { + $records['extra'] = array_merge( + $records['extra'], + [ + 'app_id' => $this->processId, + ] + ); + + return $records; + } +} diff --git a/src/BaseObject.php b/src/BaseObject.php index 33ed677546..d8d36e37b9 100644 --- a/src/BaseObject.php +++ b/src/BaseObject.php @@ -4,6 +4,10 @@ */ namespace Friendica; +require_once 'boot.php'; + +use Friendica\Core\Logger; + /** * Basic object * @@ -23,7 +27,8 @@ class BaseObject public static function getApp() { if (empty(self::$app)) { - self::$app = new App(dirname(__DIR__)); + $logger = Logger::create('app'); + self::$app = new App(dirname(__DIR__), $logger); } return self::$app; diff --git a/src/Core/Logger.php b/src/Core/Logger.php index f9cb8cde01..3d5d9fb50a 100644 --- a/src/Core/Logger.php +++ b/src/Core/Logger.php @@ -4,23 +4,72 @@ */ namespace Friendica\Core; +use Friendica\App; use Friendica\BaseObject; -use Friendica\Core\Config; +use Monolog; use Friendica\Util\DateTimeFormat; -use ReflectionClass; /** * @brief Logger functions */ class Logger extends BaseObject { + /** + * Creates a basic Monolog instance for logging. + * + * @param string $application the current application name (index, daemon, ...) + * + * @return Monolog\Logger The Logger instance + */ + public static function create($application) + { + $logger = new Monolog\Logger($application); + + $logger->pushProcessor(new Monolog\Processor\IntrospectionProcessor()); + $logger->pushProcessor(new Monolog\Processor\ProcessIdProcessor()); + $logger->pushProcessor(new Monolog\Processor\WebProcessor()); + $logger->pushProcessor(new App\FriendicaLoggerProcessor()); + + return $logger; + } + + /** + * Sets the default Logging handler for this instance. + * Can be combined with other handlers too if necessary. + * + * @param Monolog\Logger $logger The Logger instance of this Application + * @param App $app The Friendica Application + */ + public static function loadDefaultHandler($logger, $app) + { + foreach ($logger->getProcessors() as $processor) { + if ($processor instanceof App\FriendicaLoggerProcessor) { + $processor->setProcessId($app->process_id); + } + } + + $debugging = Config::get('system', 'debugging'); + $logfile = Config::get('system', 'logfile'); + $loglevel = intval(Config::get('system', 'loglevel')); + + if (!$debugging || !$logfile) { + return; + } + + $fileHandler = new Monolog\Handler\StreamHandler($logfile . ".1", $loglevel); + $logger->pushHandler($fileHandler); + } + // Log levels: - const WARNING = 0; - const INFO = 1; - const TRACE = 2; - const DEBUG = 3; - const DATA = 4; - const ALL = 5; + //EMERGENCY + //ALERT + //CRITICAL + const WARNING = 0; //ERROR + const INFO = 1; //WARNING + const TRACE = 2; //NOTICE(default) + const DEBUG = 3; //INFO + const DATA = 4; //INFO + const ALL = 5; //DEBUG public static $levels = [ self::WARNING => 'Warning', @@ -36,6 +85,8 @@ class Logger extends BaseObject * * @param string $msg * @param int $level + * + * @deprecated since 2019.03 - use App->getLogger() instead */ public static function log($msg, $level = self::INFO) { @@ -90,6 +141,8 @@ class Logger extends BaseObject * personally without background noise * * @param string $msg + * + * * @deprecated since 2019.03 - never used */ public static function devLog($msg) { diff --git a/tests/src/BaseObjectTest.php b/tests/src/BaseObjectTest.php index f8542f7b38..9bee2fb8e5 100644 --- a/tests/src/BaseObjectTest.php +++ b/tests/src/BaseObjectTest.php @@ -7,6 +7,7 @@ namespace Friendica\Test; use Friendica\App; use Friendica\BaseObject; +use Monolog\Logger; use PHPUnit\Framework\TestCase; /** @@ -38,7 +39,8 @@ class BaseObjectTest extends TestCase */ public function testSetApp() { - $app = new App(__DIR__ . '/../../'); + $logger = Logger::create('test', 'baseobject'); + $app = new App(__DIR__ . '/../../', $logger); $this->assertNull($this->baseObject->setApp($app)); $this->assertEquals($app, $this->baseObject->getApp()); } diff --git a/update.php b/update.php index 2663da21f0..dfda259797 100644 --- a/update.php +++ b/update.php @@ -1,9 +1,9 @@ $key], ['id' => $data['id']]); - logger::log('Updated contact ' . $data['id'] . " to $translateKey " . $key . - ' (was: ' . $data[$translateKey] . ')'); + BaseObject::getApp() + ->getLogger() + ->notice('Updated contact', ['action' => 'update', 'contact' => $data['id'], "$translateKey" => $key, + 'was' => $data[$translateKey]]); Worker::add(PRIORITY_LOW, 'ProfileUpdate', $data['id']); Contact::updateSelfFromUserID($data['id']); GContact::updateForUser($data['id']); @@ -342,7 +344,9 @@ function update_1298() } } - Logger::log($translateKey . " fix completed. Success: $success. Fail: $fail"); + BaseObject::getApp() + ->getLogger() + ->notice($translateKey . " fix completed", ['action' => 'update', 'translateKey' => $translateKey, 'Success' => $success, 'Fail' => $fail ]); } return Update::SUCCESS; }