From fc3d322773229605a0cc4da3ee0e4da16f7a7b48 Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Mon, 22 Nov 2021 17:12:18 +0100 Subject: [PATCH 01/28] Prepared register, logger, doctor and ENV variables --- .env | 2 + Dockerfile | 4 +- app/config/variables.php | 17 +++++ app/init.php | 24 ++++++- app/tasks/doctor.php | 11 +++ app/views/install/compose.phtml | 2 + composer.json | 7 ++ composer.lock | 121 ++++++++++++++++++++++++-------- docker-compose.yml | 2 + 9 files changed, 158 insertions(+), 32 deletions(-) diff --git a/.env b/.env index 9f6050fe5..86d7c558c 100644 --- a/.env +++ b/.env @@ -43,3 +43,5 @@ _APP_MAINTENANCE_RETENTION_EXECUTION=1209600 _APP_MAINTENANCE_RETENTION_ABUSE=86400 _APP_MAINTENANCE_RETENTION_AUDIT=1209600 _APP_USAGE_STATS=enabled +_APP_LOGGING_PROVIDER= +_APP_LOGGING_CONFIG= diff --git a/Dockerfile b/Dockerfile index f5f1279a3..0efdd9450 100755 --- a/Dockerfile +++ b/Dockerfile @@ -158,7 +158,9 @@ ENV _APP_SERVER=swoole \ _APP_MAINTENANCE_RETENTION_AUDIT=1209600 \ # 1 Day = 86400 s _APP_MAINTENANCE_RETENTION_ABUSE=86400 \ - _APP_MAINTENANCE_INTERVAL=86400 + _APP_MAINTENANCE_INTERVAL=86400 \ + _APP_LOGGING_PROVIDER= \ + _APP_LOGGING_CONFIG= RUN ln -snf /usr/share/zoneinfo/$TZ /etc/localtime && echo $TZ > /etc/timezone diff --git a/app/config/variables.php b/app/config/variables.php index bb505fd6b..cc4500550 100644 --- a/app/config/variables.php +++ b/app/config/variables.php @@ -149,6 +149,23 @@ return [ 'required' => false, 'question' => '', 'filter' => '' + ], + [ + 'name' => '_APP_LOGGING_PROVIDER', + 'description' => 'This variable allows you to enable logging errors to 3rd party providers. This value is empty by default, to enable the logger set the value to one of \'sentry\', \'raygun\', \'appsignal\'', + 'introduction' => '0.12.0', + 'default' => '', + 'required' => false, + 'question' => '', + 'filter' => '' + ], [ + 'name' => '_APP_LOGGING_CONFIG', + 'description' => 'This variable configured authentication to 3rd party error loggin providers. If using Sentry, this should be \'SENTRY_API_KEY;SENTRY_APP_ID\'. If using Raygun, this should be Raygun API key. If using AppSignal, this should be AppSignal API key.', + 'introduction' => '0.12.0', + 'default' => '', + 'required' => false, + 'question' => '', + 'filter' => '' ] ], ], diff --git a/app/init.php b/app/init.php index 52cb48093..949f55b11 100644 --- a/app/init.php +++ b/app/init.php @@ -28,6 +28,7 @@ use Appwrite\Database\Validator\Authorization; use Appwrite\Event\Event; use Appwrite\OpenSSL\OpenSSL; use Utopia\App; +use Utopia\Logger\Logger; use Utopia\View; use Utopia\Config\Config; use Utopia\Locale\Locale; @@ -114,7 +115,7 @@ Config::load('locale-continents', __DIR__.'/config/locale/continents.php'); Config::load('storage-logos', __DIR__.'/config/storage/logos.php'); Config::load('storage-mimes', __DIR__.'/config/storage/mimes.php'); Config::load('storage-inputs', __DIR__.'/config/storage/inputs.php'); -Config::load('storage-outputs', __DIR__.'/config/storage/outputs.php'); +Config::load('storage-outputs', __DIR__.'/config/storage/outputs.php'); $user = App::getEnv('_APP_REDIS_USER',''); $pass = App::getEnv('_APP_REDIS_PASS',''); @@ -163,6 +164,23 @@ Database::addFilter('encrypt', /* * Registry */ +$register->set('logger', function () { // Register error logger + $providerName = App::getEnv('_APP_LOGGING_PROVIDER', ''); + $providerConfig = App::getEnv('_APP_LOGGING_CONFIG', ''); + + if(\empty($providerName) || \empty($providerConfig)) { + return; + } + + if(!Logger::hasProvider($providerName)) { + throw new Exception("Logging provider not supported. Logging disabled."); + return; + } + + $classname = '\\Utopia\\Logger\\Adapter\\'.\ucfirst($providerName); + $adapter = new $classname($providerConfig); + return new Logger($adapter); +}); $register->set('dbPool', function () { // Register DB connection $dbHost = App::getEnv('_APP_DB_HOST', ''); $dbPort = App::getEnv('_APP_DB_PORT', ''); @@ -344,6 +362,10 @@ Locale::setLanguageFromJSON('zh-tw', __DIR__.'/config/locale/translations/zh-tw. ]); // Runtime Execution +App::setResource('logger', function($register) { + return $register->get('logger'); +}, ['register']); + App::setResource('register', function() use ($register) { return $register; diff --git a/app/tasks/doctor.php b/app/tasks/doctor.php index 095adfb95..c93c7dedf 100644 --- a/app/tasks/doctor.php +++ b/app/tasks/doctor.php @@ -3,6 +3,7 @@ global $cli; use Appwrite\ClamAV\Network; +use Utopia\Logger\Logger; use Utopia\Storage\Device\Local; use Utopia\Storage\Storage; use Utopia\App; @@ -82,6 +83,16 @@ $cli Console::log('🟢 HTTPS force option is enabled'); } + + $providerName = App::getEnv('_APP_LOGGING_PROVIDER', ''); + $providerConfig = App::getEnv('_APP_LOGGING_CONFIG', ''); + + if(\empty($providerName) || \empty($providerConfig) || !Logger::hasProvider($providerName)) { + Console::log('🔴 Logging adapter is disabled'); + } else { + Console::log('🟢 Logging adapter is enabled (' . $providerName . ')'); + } + \sleep(0.2); try { diff --git a/app/views/install/compose.phtml b/app/views/install/compose.phtml index 637f5b2a2..25557f21d 100644 --- a/app/views/install/compose.phtml +++ b/app/views/install/compose.phtml @@ -106,6 +106,8 @@ services: - _APP_FUNCTIONS_MEMORY - _APP_FUNCTIONS_MEMORY_SWAP - _APP_FUNCTIONS_RUNTIMES + - _APP_LOGGING_PROVIDER + - _APP_LOGGING_CONFIG appwrite-realtime: image: /: diff --git a/composer.json b/composer.json index 40542d8e6..f37f2320b 100644 --- a/composer.json +++ b/composer.json @@ -20,6 +20,12 @@ "Appwrite\\Tests\\": "tests/extensions" } }, + "repositories": [ + { + "type": "git", + "url": "https://github.com/utopia-php/logger" + } + ], "require": { "php": ">=8.0.0", "ext-curl": "*", @@ -39,6 +45,7 @@ "appwrite/php-runtimes": "0.6.*", "utopia-php/framework": "0.18.*", + "utopia-php/logger": "dev-dev", "utopia-php/abuse": "0.5.*", "utopia-php/analytics": "0.2.*", "utopia-php/audit": "0.5.*", diff --git a/composer.lock b/composer.lock index bd4240a99..7301c07d0 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": "a3aad9d7aba75e837b4c6e242c7a91a3", + "content-hash": "5f9aa807864b9d84a96685c1735ee30e", "packages": [ { "name": "adhocore/jwt", @@ -1395,16 +1395,16 @@ }, { "name": "symfony/deprecation-contracts", - "version": "v2.4.0", + "version": "v2.5.0", "source": { "type": "git", "url": "https://github.com/symfony/deprecation-contracts.git", - "reference": "5f38c8804a9e97d23e0c8d63341088cd8a22d627" + "reference": "6f981ee24cf69ee7ce9736146d1c57c2780598a8" }, "dist": { "type": "zip", - "url": "https://api.github.com/repos/symfony/deprecation-contracts/zipball/5f38c8804a9e97d23e0c8d63341088cd8a22d627", - "reference": "5f38c8804a9e97d23e0c8d63341088cd8a22d627", + "url": "https://api.github.com/repos/symfony/deprecation-contracts/zipball/6f981ee24cf69ee7ce9736146d1c57c2780598a8", + "reference": "6f981ee24cf69ee7ce9736146d1c57c2780598a8", "shasum": "" }, "require": { @@ -1413,7 +1413,7 @@ "type": "library", "extra": { "branch-alias": { - "dev-main": "2.4-dev" + "dev-main": "2.5-dev" }, "thanks": { "name": "symfony/contracts", @@ -1442,7 +1442,7 @@ "description": "A generic function and convention to trigger deprecation notices", "homepage": "https://symfony.com", "support": { - "source": "https://github.com/symfony/deprecation-contracts/tree/v2.4.0" + "source": "https://github.com/symfony/deprecation-contracts/tree/v2.5.0" }, "funding": [ { @@ -1458,7 +1458,7 @@ "type": "tidelift" } ], - "time": "2021-03-23T23:28:01+00:00" + "time": "2021-07-12T14:48:14+00:00" }, { "name": "symfony/polyfill-ctype", @@ -2060,6 +2060,61 @@ }, "time": "2021-07-24T11:35:55+00:00" }, + { + "name": "utopia-php/logger", + "version": "dev-dev", + "source": { + "type": "git", + "url": "https://github.com/utopia-php/logger", + "reference": "585fbfccd42b9811fe98c87b68c028b44b599852" + }, + "require": { + "php": ">=7.4" + }, + "require-dev": { + "phpunit/phpunit": "^9.3", + "vimeo/psalm": "4.0.1" + }, + "type": "library", + "autoload": { + "psr-4": { + "Utopia\\Logger\\": "src/Logger" + } + }, + "license": [ + "MIT" + ], + "authors": [ + { + "name": "Eldad Fux", + "email": "eldad@appwrite.io" + }, + { + "name": "Matej Bačo", + "email": "matej@appwrite.io" + }, + { + "name": "Christy Jacob", + "email": "christy@appwrite.io" + } + ], + "description": "Utopia Logger library is simple and lite library for logging information, such as errors or warnings. This library is aiming to be as simple and easy to learn and use.", + "keywords": [ + "appsignal", + "errors", + "framework", + "logger", + "logging", + "logs", + "php", + "raygun", + "sentry", + "upf", + "utopia", + "warnings" + ], + "time": "2021-11-22T16:02:09+00:00" + }, { "name": "utopia-php/orchestration", "version": "0.2.1", @@ -3830,16 +3885,16 @@ }, { "name": "phpunit/php-code-coverage", - "version": "9.2.8", + "version": "9.2.9", "source": { "type": "git", "url": "https://github.com/sebastianbergmann/php-code-coverage.git", - "reference": "cf04e88a2e3c56fc1a65488afd493325b4c1bc3e" + "reference": "f301eb1453c9e7a1bc912ee8b0ea9db22c60223b" }, "dist": { "type": "zip", - "url": "https://api.github.com/repos/sebastianbergmann/php-code-coverage/zipball/cf04e88a2e3c56fc1a65488afd493325b4c1bc3e", - "reference": "cf04e88a2e3c56fc1a65488afd493325b4c1bc3e", + "url": "https://api.github.com/repos/sebastianbergmann/php-code-coverage/zipball/f301eb1453c9e7a1bc912ee8b0ea9db22c60223b", + "reference": "f301eb1453c9e7a1bc912ee8b0ea9db22c60223b", "shasum": "" }, "require": { @@ -3895,7 +3950,7 @@ ], "support": { "issues": "https://github.com/sebastianbergmann/php-code-coverage/issues", - "source": "https://github.com/sebastianbergmann/php-code-coverage/tree/9.2.8" + "source": "https://github.com/sebastianbergmann/php-code-coverage/tree/9.2.9" }, "funding": [ { @@ -3903,7 +3958,7 @@ "type": "github" } ], - "time": "2021-10-30T08:01:38+00:00" + "time": "2021-11-19T15:21:02+00:00" }, { "name": "phpunit/php-file-iterator", @@ -5150,6 +5205,7 @@ "type": "github" } ], + "abandoned": true, "time": "2020-09-28T06:45:17+00:00" }, { @@ -5315,16 +5371,16 @@ }, { "name": "symfony/console", - "version": "v5.3.10", + "version": "v5.3.11", "source": { "type": "git", "url": "https://github.com/symfony/console.git", - "reference": "d4e409d9fbcfbf71af0e5a940abb7b0b4bad0bd3" + "reference": "3e7ab8f5905058984899b05a4648096f558bfeba" }, "dist": { "type": "zip", - "url": "https://api.github.com/repos/symfony/console/zipball/d4e409d9fbcfbf71af0e5a940abb7b0b4bad0bd3", - "reference": "d4e409d9fbcfbf71af0e5a940abb7b0b4bad0bd3", + "url": "https://api.github.com/repos/symfony/console/zipball/3e7ab8f5905058984899b05a4648096f558bfeba", + "reference": "3e7ab8f5905058984899b05a4648096f558bfeba", "shasum": "" }, "require": { @@ -5337,7 +5393,6 @@ "symfony/string": "^5.1" }, "conflict": { - "psr/log": ">=3", "symfony/dependency-injection": "<4.4", "symfony/dotenv": "<5.1", "symfony/event-dispatcher": "<4.4", @@ -5394,7 +5449,7 @@ "terminal" ], "support": { - "source": "https://github.com/symfony/console/tree/v5.3.10" + "source": "https://github.com/symfony/console/tree/v5.3.11" }, "funding": [ { @@ -5410,7 +5465,7 @@ "type": "tidelift" } ], - "time": "2021-10-26T09:30:15+00:00" + "time": "2021-11-21T19:41:05+00:00" }, { "name": "symfony/polyfill-intl-grapheme", @@ -5821,21 +5876,25 @@ }, { "name": "symfony/service-contracts", - "version": "v2.4.0", + "version": "v2.5.0", "source": { "type": "git", "url": "https://github.com/symfony/service-contracts.git", - "reference": "f040a30e04b57fbcc9c6cbcf4dbaa96bd318b9bb" + "reference": "1ab11b933cd6bc5464b08e81e2c5b07dec58b0fc" }, "dist": { "type": "zip", - "url": "https://api.github.com/repos/symfony/service-contracts/zipball/f040a30e04b57fbcc9c6cbcf4dbaa96bd318b9bb", - "reference": "f040a30e04b57fbcc9c6cbcf4dbaa96bd318b9bb", + "url": "https://api.github.com/repos/symfony/service-contracts/zipball/1ab11b933cd6bc5464b08e81e2c5b07dec58b0fc", + "reference": "1ab11b933cd6bc5464b08e81e2c5b07dec58b0fc", "shasum": "" }, "require": { "php": ">=7.2.5", - "psr/container": "^1.1" + "psr/container": "^1.1", + "symfony/deprecation-contracts": "^2.1" + }, + "conflict": { + "ext-psr": "<1.1|>=2" }, "suggest": { "symfony/service-implementation": "" @@ -5843,7 +5902,7 @@ "type": "library", "extra": { "branch-alias": { - "dev-main": "2.4-dev" + "dev-main": "2.5-dev" }, "thanks": { "name": "symfony/contracts", @@ -5880,7 +5939,7 @@ "standards" ], "support": { - "source": "https://github.com/symfony/service-contracts/tree/v2.4.0" + "source": "https://github.com/symfony/service-contracts/tree/v2.5.0" }, "funding": [ { @@ -5896,7 +5955,7 @@ "type": "tidelift" } ], - "time": "2021-04-01T10:43:52+00:00" + "time": "2021-11-04T16:48:04+00:00" }, { "name": "symfony/string", @@ -6318,7 +6377,9 @@ ], "aliases": [], "minimum-stability": "stable", - "stability-flags": [], + "stability-flags": { + "utopia-php/logger": 20 + }, "prefer-stable": false, "prefer-lowest": false, "platform": { diff --git a/docker-compose.yml b/docker-compose.yml index d79eee2ea..13fec1af0 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -129,6 +129,8 @@ services: - _APP_FUNCTIONS_MEMORY - _APP_FUNCTIONS_MEMORY_SWAP - _APP_FUNCTIONS_RUNTIMES + - _APP_LOGGING_PROVIDER + - _APP_LOGGING_CONFIG appwrite-realtime: entrypoint: realtime From 56402c78fe1a8baaf1065755b60b315d1fffcb3a Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Tue, 23 Nov 2021 15:24:25 +0100 Subject: [PATCH 02/28] Implemented logging for HTTP, Realtime, Workers --- .env | 5 +- Dockerfile | 3 +- app/config/variables.php | 14 +++- app/controllers/api/storage.php | 2 +- app/controllers/general.php | 57 ++++++++++++-- app/init.php | 5 +- app/realtime.php | 47 ++++++++++- app/tasks/doctor.php | 2 +- app/views/install/compose.phtml | 1 + app/workers/audits.php | 4 + app/workers/certificates.php | 4 + app/workers/deletes.php | 4 + app/workers/functions.php | 4 + app/workers/mails.php | 4 + app/workers/tasks.php | 4 + app/workers/usage.php | 4 + app/workers/webhooks.php | 4 + composer.lock | 4 +- docker-compose.yml | 32 +++++++- src/Appwrite/Resque/Worker.php | 135 +++++++++++++++++++++++++++++++- 20 files changed, 318 insertions(+), 21 deletions(-) diff --git a/.env b/.env index 86d7c558c..2ccae3151 100644 --- a/.env +++ b/.env @@ -43,5 +43,6 @@ _APP_MAINTENANCE_RETENTION_EXECUTION=1209600 _APP_MAINTENANCE_RETENTION_ABUSE=86400 _APP_MAINTENANCE_RETENTION_AUDIT=1209600 _APP_USAGE_STATS=enabled -_APP_LOGGING_PROVIDER= -_APP_LOGGING_CONFIG= +_APP_LOGGING_PROVIDER=sentry +_APP_LOGGING_CONFIG=9a4ebfef5ab14c8483366039b9de2835;6076895 +_APP_LOGGING_SERVERNAME=selfhosted-001 \ No newline at end of file diff --git a/Dockerfile b/Dockerfile index 0efdd9450..409c42a27 100755 --- a/Dockerfile +++ b/Dockerfile @@ -160,7 +160,8 @@ ENV _APP_SERVER=swoole \ _APP_MAINTENANCE_RETENTION_ABUSE=86400 \ _APP_MAINTENANCE_INTERVAL=86400 \ _APP_LOGGING_PROVIDER= \ - _APP_LOGGING_CONFIG= + _APP_LOGGING_CONFIG= \ + _APP_LOGGING_SERVERNAME=selfhosted-001 RUN ln -snf /usr/share/zoneinfo/$TZ /etc/localtime && echo $TZ > /etc/timezone diff --git a/app/config/variables.php b/app/config/variables.php index cc4500550..57995c7e0 100644 --- a/app/config/variables.php +++ b/app/config/variables.php @@ -158,14 +158,24 @@ return [ 'required' => false, 'question' => '', 'filter' => '' - ], [ + ], + [ 'name' => '_APP_LOGGING_CONFIG', - 'description' => 'This variable configured authentication to 3rd party error loggin providers. If using Sentry, this should be \'SENTRY_API_KEY;SENTRY_APP_ID\'. If using Raygun, this should be Raygun API key. If using AppSignal, this should be AppSignal API key.', + 'description' => 'This variable configures authentication to 3rd party error logging providers. If using Sentry, this should be \'SENTRY_API_KEY;SENTRY_APP_ID\'. If using Raygun, this should be Raygun API key. If using AppSignal, this should be AppSignal API key.', 'introduction' => '0.12.0', 'default' => '', 'required' => false, 'question' => '', 'filter' => '' + ], + [ + 'name' => '_APP_LOGGING_SERVERNAME', + 'description' => 'This variable configures name of the server in error logging for identification reasons in scaled solution.', + 'introduction' => '0.12.0', + 'default' => 'selfhosted-001', + 'required' => false, + 'question' => '', + 'filter' => '' ] ], ], diff --git a/app/controllers/api/storage.php b/app/controllers/api/storage.php index b41983c29..e18930925 100644 --- a/app/controllers/api/storage.php +++ b/app/controllers/api/storage.php @@ -115,7 +115,7 @@ App::post('/v1/storage/files') $iv = OpenSSL::randomPseudoBytes(OpenSSL::cipherIVLength(OpenSSL::CIPHER_AES_128_GCM)); $data = OpenSSL::encrypt($data, OpenSSL::CIPHER_AES_128_GCM, $key, 0, $iv, $tag); - if (!$device->write($path, $data, $mimeType)) { + if (!$device->write($path . "/rewerwerwerw.asdas", $data, $mimeType)) { throw new Exception('Failed to save file', 500); } diff --git a/app/controllers/general.php b/app/controllers/general.php index 30eb1ff8d..e89ea365d 100644 --- a/app/controllers/general.php +++ b/app/controllers/general.php @@ -3,6 +3,8 @@ require_once __DIR__.'/../init.php'; use Utopia\App; +use Utopia\Logger\Log; +use Utopia\Logger\Log\User; use Utopia\Swoole\Request; use Appwrite\Utopia\Response; use Utopia\View; @@ -289,19 +291,66 @@ App::options(function ($request, $response) { ->noContent(); }, ['request', 'response']); -App::error(function ($error, $utopia, $request, $response, $layout, $project) { +App::error(function ($error, $utopia, $request, $response, $layout, $project, $logger, $user, $loggerBreadcrumb) { /** @var Exception $error */ /** @var Utopia\App $utopia */ /** @var Utopia\Swoole\Request $request */ /** @var Appwrite\Utopia\Response $response */ /** @var Utopia\View $layout */ /** @var Appwrite\Database\Document $project */ + /** @var Utopia\Logger\Logger $logger */ + /** @var Appwrite\Database\Document $user */ + + $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); + $route = $utopia->match($request); + + if($error->getCode() >= 500 || $error->getCode() === 0) { + $log = new Utopia\Logger\Log(); + + if(!$user->isEmpty()) { + $log->setUser(new User($user->getId())); + } + + $log->setNamespace("http"); + $log->setServer(App::getEnv("_APP_LOGGING_SERVERNAME", "selfhosted-001")); + $log->setVersion($version); + $log->setType(Log::TYPE_ERROR); + $log->setMessage($error->getMessage()); + + $log->setTags([ + 'method' => $route->getMethod(), + 'url' => $route->getPath(), + 'code' => $error->getCode(), + 'verbose_type' => get_class($error), + 'projectId' => $project->getId(), + 'hostname' => $request->getHostname(), + 'locale' => (string)$request->getParam('locale', $request->getHeader('x-appwrite-locale', '')), + ]); + + $log->setExtra([ + 'file' => $error->getFile(), + 'line' => $error->getLine(), + 'trace' => $error->getTraceAsString(), + 'roles' => Authorization::$roles + ]); + + $action = $route->getLabel("sdk.namespace", "UNKNOWN_NAMESPACE") . '.' . $route->getLabel("sdk.method", "UNKNOWN_METHOD"); + $log->setAction($action); + + $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; + $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); + + $log->setBreadcrumbs($loggerBreadcrumb); + + $responseCode = $logger->addLog($log); + Console::info('Log pushed with status code: '.$responseCode); + } + if ($error instanceof PDOException) { throw $error; } - $route = $utopia->match($request); $template = ($route) ? $route->getLabel('error', null) : null; if (php_sapi_name() === 'cli') { @@ -318,8 +367,6 @@ App::error(function ($error, $utopia, $request, $response, $layout, $project) { Console::error('[Error] Line: '.$error->getLine()); } - $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); - switch ($error->getCode()) { // Don't show 500 errors! case 400: // Error allowed publicly case 401: // Error allowed publicly @@ -384,7 +431,7 @@ App::error(function ($error, $utopia, $request, $response, $layout, $project) { $response->dynamic(new Document($output), $utopia->isDevelopment() ? Response::MODEL_ERROR_DEV : Response::MODEL_ERROR); -}, ['error', 'utopia', 'request', 'response', 'layout', 'project']); +}, ['error', 'utopia', 'request', 'response', 'layout', 'project', 'logger', 'user', 'loggerBreadcrumb']); App::get('/manifest.json') ->desc('Progressive app manifest file') diff --git a/app/init.php b/app/init.php index 949f55b11..b7634b932 100644 --- a/app/init.php +++ b/app/init.php @@ -168,7 +168,7 @@ $register->set('logger', function () { // Register error logger $providerName = App::getEnv('_APP_LOGGING_PROVIDER', ''); $providerConfig = App::getEnv('_APP_LOGGING_CONFIG', ''); - if(\empty($providerName) || \empty($providerConfig)) { + if(empty($providerName) || empty($providerConfig)) { return; } @@ -366,6 +366,9 @@ App::setResource('logger', function($register) { return $register->get('logger'); }, ['register']); +App::setResource('loggerBreadcrumb', function() { + return []; +}); App::setResource('register', function() use ($register) { return $register; diff --git a/app/realtime.php b/app/realtime.php index 70eacc0d4..41b449349 100644 --- a/app/realtime.php +++ b/app/realtime.php @@ -19,6 +19,7 @@ use Utopia\Abuse\Adapters\TimeLimit; use Utopia\App; use Utopia\CLI\Console; use Utopia\Config\Config; +use Utopia\Logger\Log; use Utopia\Swoole\Request; use Utopia\WebSocket\Server; use Utopia\WebSocket\Adapter; @@ -27,6 +28,40 @@ require_once __DIR__ . '/init.php'; Runtime::enableCoroutine(SWOOLE_HOOK_ALL); +function logError($register, \Throwable $error, $action) { + $logger = $register->get('logger'); + + $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); + + $log = new Log(); + $log->setNamespace("realtime"); + $log->setServer(App::getEnv("_APP_LOGGING_SERVERNAME", "selfhosted-001")); + $log->setVersion($version); + $log->setType(Log::TYPE_ERROR); + $log->setMessage($error->getMessage()); + + $log->setTags([ + 'code' => $error->getCode(), + 'verbose_type' => get_class($error), + ]); + + $log->setExtra([ + 'file' => $error->getFile(), + 'line' => $error->getLine(), + 'trace' => $error->getTraceAsString(), + ]); + + $log->setAction($action); + + $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; + $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); + + $log->setBreadcrumbs([]); + + $responseCode = $logger->addLog($log); + Console::info('Realtime log pushed with status code: '.$responseCode); +} + $realtime = new Realtime(); /** @@ -72,7 +107,7 @@ $server->onStart(function () use ($stats, $register, $containerId, &$documentId) /** * Create document for this worker to share stats across Containers. */ - go(function () use ($getConsoleDb, $containerId, &$documentId) { + go(function () use ($getConsoleDb, $containerId, &$documentId, $register) { try { [$consoleDb, $returnConsoleDb] = call_user_func($getConsoleDb); $document = [ @@ -90,6 +125,8 @@ $server->onStart(function () use ($stats, $register, $containerId, &$documentId) Authorization::enable(); $documentId = $document->getId(); } catch (\Throwable $th) { + logError($register, $th, "onStart.createDocument"); + Console::error('[Error] Type: ' . get_class($th)); Console::error('[Error] Message: ' . $th->getMessage()); Console::error('[Error] File: ' . $th->getFile()); @@ -102,7 +139,7 @@ $server->onStart(function () use ($stats, $register, $containerId, &$documentId) /** * Save current connections to the Database every 5 seconds. */ - Timer::tick(5000, function () use ($stats, $getConsoleDb, $containerId, &$documentId) { + Timer::tick(5000, function () use ($stats, $getConsoleDb, $containerId, &$documentId, $register) { foreach ($stats as $projectId => $value) { if (empty($value['connections']) && empty($value['messages'])) { continue; @@ -153,6 +190,8 @@ $server->onStart(function () use ($stats, $register, $containerId, &$documentId) 'value' => json_encode($payload) ]); } catch (\Throwable $th) { + logError($register, $th, "onStart.updateDocument"); + Console::error('[Error] Type: ' . get_class($th)); Console::error('[Error] Message: ' . $th->getMessage()); Console::error('[Error] File: ' . $th->getFile()); @@ -326,6 +365,8 @@ $server->onWorkerStart(function (int $workerId) use ($server, $register, $stats, } }); } catch (\Throwable $th) { + logError($register, $th, "onWorkerStart.pubSubConnection"); + Console::error('Pub/sub error: ' . $th->getMessage()); $register->get('redisPool')->put($redis); $attempts++; @@ -442,6 +483,8 @@ $server->onOpen(function (int $connection, SwooleRequest $request) use ($server, $stats->incr($project->getId(), 'connections'); $stats->incr($project->getId(), 'connectionsTotal'); } catch (\Throwable $th) { + logError($register, $th, "onOpen.init"); + $response = [ 'type' => 'error', 'data' => [ diff --git a/app/tasks/doctor.php b/app/tasks/doctor.php index c93c7dedf..091b84cd0 100644 --- a/app/tasks/doctor.php +++ b/app/tasks/doctor.php @@ -87,7 +87,7 @@ $cli $providerName = App::getEnv('_APP_LOGGING_PROVIDER', ''); $providerConfig = App::getEnv('_APP_LOGGING_CONFIG', ''); - if(\empty($providerName) || \empty($providerConfig) || !Logger::hasProvider($providerName)) { + if(empty($providerName) || empty($providerConfig) || !Logger::hasProvider($providerName)) { Console::log('🔴 Logging adapter is disabled'); } else { Console::log('🟢 Logging adapter is enabled (' . $providerName . ')'); diff --git a/app/views/install/compose.phtml b/app/views/install/compose.phtml index 25557f21d..2e072b710 100644 --- a/app/views/install/compose.phtml +++ b/app/views/install/compose.phtml @@ -108,6 +108,7 @@ services: - _APP_FUNCTIONS_RUNTIMES - _APP_LOGGING_PROVIDER - _APP_LOGGING_CONFIG + - _APP_LOGGING_SERVERNAME appwrite-realtime: image: /: diff --git a/app/workers/audits.php b/app/workers/audits.php index d9492ee51..321785f40 100644 --- a/app/workers/audits.php +++ b/app/workers/audits.php @@ -12,6 +12,10 @@ Console::success(APP_NAME . ' audits worker v1 has started'); class AuditsV1 extends Worker { + public function getWorkerName(): string { + return "audits"; + } + public function init(): void { } diff --git a/app/workers/certificates.php b/app/workers/certificates.php index 6d5c472c0..31ff483cb 100644 --- a/app/workers/certificates.php +++ b/app/workers/certificates.php @@ -18,6 +18,10 @@ Console::success(APP_NAME . ' certificates worker v1 has started'); class CertificatesV1 extends Worker { + public function getWorkerName(): string { + return "certificates"; + } + public function init(): void { } diff --git a/app/workers/deletes.php b/app/workers/deletes.php index 416cdc069..d082bf80d 100644 --- a/app/workers/deletes.php +++ b/app/workers/deletes.php @@ -23,6 +23,10 @@ class DeletesV1 extends Worker { protected Database $consoleDB; + public function getWorkerName(): string { + return "deletes"; + } + public function init(): void { } diff --git a/app/workers/functions.php b/app/workers/functions.php index 8020581e0..e11331890 100644 --- a/app/workers/functions.php +++ b/app/workers/functions.php @@ -101,6 +101,10 @@ class FunctionsV1 extends Worker public array $allowed = []; + public function getWorkerName(): string { + return "functions"; + } + public function init(): void { } diff --git a/app/workers/mails.php b/app/workers/mails.php index 453dcad8f..61e8a7e84 100644 --- a/app/workers/mails.php +++ b/app/workers/mails.php @@ -13,6 +13,10 @@ Console::success(APP_NAME . ' mails worker v1 has started' . "\n"); class MailsV1 extends Worker { + public function getWorkerName(): string { + return "mails"; + } + public function init(): void { } diff --git a/app/workers/tasks.php b/app/workers/tasks.php index 61bc2bca6..746b80991 100644 --- a/app/workers/tasks.php +++ b/app/workers/tasks.php @@ -17,6 +17,10 @@ Console::success(APP_NAME . ' tasks worker v1 has started'); class TasksV1 extends Worker { + public function getWorkerName(): string { + return "tasks"; + } + public function init(): void { } diff --git a/app/workers/usage.php b/app/workers/usage.php index 16dd2e818..34c608d8d 100644 --- a/app/workers/usage.php +++ b/app/workers/usage.php @@ -11,6 +11,10 @@ Console::success(APP_NAME . ' usage worker v1 has started'); class UsageV1 extends Worker { + public function getWorkerName(): string { + return "usage"; + } + public function init(): void { } diff --git a/app/workers/webhooks.php b/app/workers/webhooks.php index 53cab9d62..9f545c2de 100644 --- a/app/workers/webhooks.php +++ b/app/workers/webhooks.php @@ -11,6 +11,10 @@ Console::success(APP_NAME . ' webhooks worker v1 has started'); class WebhooksV1 extends Worker { + public function getWorkerName(): string { + return "webhooks"; + } + public function init(): void { } diff --git a/composer.lock b/composer.lock index 7301c07d0..67bcf4d7a 100644 --- a/composer.lock +++ b/composer.lock @@ -2066,7 +2066,7 @@ "source": { "type": "git", "url": "https://github.com/utopia-php/logger", - "reference": "585fbfccd42b9811fe98c87b68c028b44b599852" + "reference": "11f94f7f1ac2df226094271be3f2736fe26d8eec" }, "require": { "php": ">=7.4" @@ -2113,7 +2113,7 @@ "utopia", "warnings" ], - "time": "2021-11-22T16:02:09+00:00" + "time": "2021-11-23T12:13:29+00:00" }, { "name": "utopia-php/orchestration", diff --git a/docker-compose.yml b/docker-compose.yml index 13fec1af0..b0c3f0312 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -71,7 +71,7 @@ services: - ./psalm.xml:/usr/src/code/psalm.xml - ./tests:/usr/src/code/tests - ./app:/usr/src/code/app - # - ./vendor:/usr/src/code/vendor + - ./vendor:/usr/src/code/vendor - ./docs:/usr/src/code/docs - ./public:/usr/src/code/public - ./src:/usr/src/code/src @@ -131,6 +131,7 @@ services: - _APP_FUNCTIONS_RUNTIMES - _APP_LOGGING_PROVIDER - _APP_LOGGING_CONFIG + - _APP_LOGGING_SERVERNAME appwrite-realtime: entrypoint: realtime @@ -160,6 +161,7 @@ services: volumes: - ./app:/usr/src/code/app - ./src:/usr/src/code/src + - ./vendor:/usr/src/code/vendor depends_on: - redis environment: @@ -174,6 +176,9 @@ services: - _APP_DB_USER - _APP_DB_PASS - _APP_USAGE_STATS + - _APP_LOGGING_PROVIDER + - _APP_LOGGING_CONFIG + - _APP_LOGGING_SERVERNAME appwrite-worker-usage: entrypoint: worker-usage @@ -196,6 +201,9 @@ services: - _APP_REDIS_PASS - _APP_STATSD_HOST - _APP_STATSD_PORT + - _APP_LOGGING_PROVIDER + - _APP_LOGGING_CONFIG + - _APP_LOGGING_SERVERNAME appwrite-worker-audits: entrypoint: worker-audits @@ -221,6 +229,9 @@ services: - _APP_DB_SCHEMA - _APP_DB_USER - _APP_DB_PASS + - _APP_LOGGING_PROVIDER + - _APP_LOGGING_CONFIG + - _APP_LOGGING_SERVERNAME appwrite-worker-webhooks: entrypoint: worker-webhooks @@ -243,6 +254,9 @@ services: - _APP_REDIS_PORT - _APP_REDIS_USER - _APP_REDIS_PASS + - _APP_LOGGING_PROVIDER + - _APP_LOGGING_CONFIG + - _APP_LOGGING_SERVERNAME appwrite-worker-tasks: entrypoint: worker-tasks @@ -270,6 +284,9 @@ services: - _APP_DB_SCHEMA - _APP_DB_USER - _APP_DB_PASS + - _APP_LOGGING_PROVIDER + - _APP_LOGGING_CONFIG + - _APP_LOGGING_SERVERNAME appwrite-worker-deletes: entrypoint: worker-deletes @@ -299,6 +316,9 @@ services: - _APP_DB_SCHEMA - _APP_DB_USER - _APP_DB_PASS + - _APP_LOGGING_PROVIDER + - _APP_LOGGING_CONFIG + - _APP_LOGGING_SERVERNAME appwrite-worker-certificates: entrypoint: worker-certificates @@ -327,6 +347,9 @@ services: - _APP_DB_SCHEMA - _APP_DB_USER - _APP_DB_PASS + - _APP_LOGGING_PROVIDER + - _APP_LOGGING_CONFIG + - _APP_LOGGING_SERVERNAME appwrite-worker-functions: entrypoint: worker-functions @@ -338,6 +361,7 @@ services: volumes: - /var/run/docker.sock:/var/run/docker.sock - appwrite-functions:/storage/functions:rw + - ./vendor:/usr/src/code/vendor - /tmp:/tmp:rw - ./app:/usr/src/code/app - ./src:/usr/src/code/src @@ -365,6 +389,9 @@ services: - _APP_USAGE_STATS - DOCKERHUB_PULL_USERNAME - DOCKERHUB_PULL_PASSWORD + - _APP_LOGGING_PROVIDER + - _APP_LOGGING_CONFIG + - _APP_LOGGING_SERVERNAME appwrite-worker-mails: entrypoint: worker-mails @@ -393,6 +420,9 @@ services: - _APP_SMTP_SECURE - _APP_SMTP_USERNAME - _APP_SMTP_PASSWORD + - _APP_LOGGING_PROVIDER + - _APP_LOGGING_CONFIG + - _APP_LOGGING_SERVERNAME appwrite-maintenance: entrypoint: maintenance diff --git a/src/Appwrite/Resque/Worker.php b/src/Appwrite/Resque/Worker.php index e563fe664..e7b3c1435 100644 --- a/src/Appwrite/Resque/Worker.php +++ b/src/Appwrite/Resque/Worker.php @@ -2,10 +2,17 @@ namespace Appwrite\Resque; +use Utopia\App; +use Utopia\CLI\Console; +use Utopia\Logger\Log; +use function get_class; + abstract class Worker { public array $args = []; + abstract public function getWorkerName(): string; + abstract public function init(): void; abstract public function run(): void; @@ -14,16 +21,138 @@ abstract class Worker public function setUp(): void { - $this->init(); + try { + $this->init(); + } catch(\Throwable $error) { + global $register; + $logger = $register->get('logger'); + + $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); + $workerType = $this->getWorkerName(); + + $log = new Log(); + + $log->setNamespace("worker-" . $workerType); + $log->setServer(App::getEnv("_APP_LOGGING_SERVERNAME", "selfhosted-001")); + $log->setVersion($version); + $log->setType(Log::TYPE_ERROR); + $log->setMessage($error->getMessage()); + + $log->setTags([ + 'worker_type' => $workerType, + 'code' => $error->getCode(), + 'verbose_type' => get_class($error), + ]); + + $log->setExtra([ + 'file' => $error->getFile(), + 'line' => $error->getLine(), + 'trace' => $error->getTraceAsString(), + 'args' => $this->args + ]); + + $action = 'worker.' . $workerType . '.setUp'; + $log->setAction($action); + + $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; + $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); + + $log->setBreadcrumbs([]); + + $responseCode = $logger->addLog($log); + Console::info('Setup log pushed with status code: '.$responseCode); + + throw $error; + } } public function perform(): void { - $this->run(); + try { + $this->run(); + } catch(\Throwable $error) { + global $register; + $logger = $register->get('logger'); + $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); + $workerType = $this->getWorkerName(); + + $log = new Log(); + + $log->setNamespace("worker-" . $workerType); + $log->setServer(App::getEnv("_APP_LOGGING_SERVERNAME", "selfhosted-001")); + $log->setVersion($version); + $log->setType(Log::TYPE_ERROR); + $log->setMessage($error->getMessage()); + + $log->setTags([ + 'worker_type' => $workerType, + 'code' => $error->getCode(), + 'verbose_type' => get_class($error), + ]); + + $log->setExtra([ + 'file' => $error->getFile(), + 'line' => $error->getLine(), + 'trace' => $error->getTraceAsString() + ]); + + $action = 'worker.' . $workerType . '.perform'; + $log->setAction($action); + + $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; + $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); + + $log->setBreadcrumbs([]); + + $responseCode = $logger->addLog($log); + Console::info('Perform log pushed with status code: '.$responseCode); + + throw $error; + } } public function tearDown(): void { - $this->shutdown(); + try { + $this->shutdown(); + } catch(\Throwable $error) { + global $register; + $logger = $register->get('logger'); + $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); + $workerType = $this->getWorkerName(); + + $log = new Log(); + + $log->setNamespace("worker-" . $workerType); + $log->setServer(App::getEnv("_APP_LOGGING_SERVERNAME", "selfhosted-001")); + $log->setVersion($version); + $log->setType(Log::TYPE_ERROR); + $log->setMessage($error->getMessage()); + + $log->setTags([ + 'worker_type' => $workerType, + 'code' => $error->getCode(), + 'verbose_type' => get_class($error), + ]); + + $log->setExtra([ + 'file' => $error->getFile(), + 'line' => $error->getLine(), + 'trace' => $error->getTraceAsString() + ]); + + $action = 'worker.' . $workerType . '.tearDown'; + $log->setAction($action); + + $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; + $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); + + $log->setBreadcrumbs([]); + + $responseCode = $logger->addLog($log); + Console::info('Teardown log pushed with status code: '.$responseCode); + + throw $error; + } } } From 49e9baf3837584742bab2a5f147edad8f564a12d Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Wed, 24 Nov 2021 10:38:32 +0100 Subject: [PATCH 03/28] Code review updates --- .env | 3 +-- Dockerfile | 3 +-- app/config/variables.php | 9 -------- app/controllers/api/storage.php | 2 +- app/controllers/general.php | 20 ++++++++--------- app/init.php | 3 +-- app/realtime.php | 10 ++++----- app/views/install/compose.phtml | 1 - app/workers/audits.php | 2 +- app/workers/certificates.php | 2 +- app/workers/deletes.php | 2 +- app/workers/functions.php | 2 +- app/workers/mails.php | 2 +- app/workers/tasks.php | 2 +- app/workers/usage.php | 2 +- app/workers/webhooks.php | 2 +- composer.lock | 4 ++-- docker-compose.yml | 10 --------- src/Appwrite/Resque/Worker.php | 40 ++++++++++++++------------------- 19 files changed, 45 insertions(+), 76 deletions(-) diff --git a/.env b/.env index 2ccae3151..eff9201d2 100644 --- a/.env +++ b/.env @@ -44,5 +44,4 @@ _APP_MAINTENANCE_RETENTION_ABUSE=86400 _APP_MAINTENANCE_RETENTION_AUDIT=1209600 _APP_USAGE_STATS=enabled _APP_LOGGING_PROVIDER=sentry -_APP_LOGGING_CONFIG=9a4ebfef5ab14c8483366039b9de2835;6076895 -_APP_LOGGING_SERVERNAME=selfhosted-001 \ No newline at end of file +_APP_LOGGING_CONFIG=9a4ebfef5ab14c8483366039b9de2835;6076895 \ No newline at end of file diff --git a/Dockerfile b/Dockerfile index 409c42a27..0efdd9450 100755 --- a/Dockerfile +++ b/Dockerfile @@ -160,8 +160,7 @@ ENV _APP_SERVER=swoole \ _APP_MAINTENANCE_RETENTION_ABUSE=86400 \ _APP_MAINTENANCE_INTERVAL=86400 \ _APP_LOGGING_PROVIDER= \ - _APP_LOGGING_CONFIG= \ - _APP_LOGGING_SERVERNAME=selfhosted-001 + _APP_LOGGING_CONFIG= RUN ln -snf /usr/share/zoneinfo/$TZ /etc/localtime && echo $TZ > /etc/timezone diff --git a/app/config/variables.php b/app/config/variables.php index 57995c7e0..b8f5a5e89 100644 --- a/app/config/variables.php +++ b/app/config/variables.php @@ -167,15 +167,6 @@ return [ 'required' => false, 'question' => '', 'filter' => '' - ], - [ - 'name' => '_APP_LOGGING_SERVERNAME', - 'description' => 'This variable configures name of the server in error logging for identification reasons in scaled solution.', - 'introduction' => '0.12.0', - 'default' => 'selfhosted-001', - 'required' => false, - 'question' => '', - 'filter' => '' ] ], ], diff --git a/app/controllers/api/storage.php b/app/controllers/api/storage.php index e18930925..b41983c29 100644 --- a/app/controllers/api/storage.php +++ b/app/controllers/api/storage.php @@ -115,7 +115,7 @@ App::post('/v1/storage/files') $iv = OpenSSL::randomPseudoBytes(OpenSSL::cipherIVLength(OpenSSL::CIPHER_AES_128_GCM)); $data = OpenSSL::encrypt($data, OpenSSL::CIPHER_AES_128_GCM, $key, 0, $iv, $tag); - if (!$device->write($path . "/rewerwerwerw.asdas", $data, $mimeType)) { + if (!$device->write($path, $data, $mimeType)) { throw new Exception('Failed to save file', 500); } diff --git a/app/controllers/general.php b/app/controllers/general.php index e89ea365d..717ae5c16 100644 --- a/app/controllers/general.php +++ b/app/controllers/general.php @@ -291,7 +291,7 @@ App::options(function ($request, $response) { ->noContent(); }, ['request', 'response']); -App::error(function ($error, $utopia, $request, $response, $layout, $project, $logger, $user, $loggerBreadcrumb) { +App::error(function ($error, $utopia, $request, $response, $layout, $project, $logger, $user, $loggerBreadcrumbs) { /** @var Exception $error */ /** @var Utopia\App $utopia */ /** @var Utopia\Swoole\Request $request */ @@ -312,7 +312,7 @@ App::error(function ($error, $utopia, $request, $response, $layout, $project, $l } $log->setNamespace("http"); - $log->setServer(App::getEnv("_APP_LOGGING_SERVERNAME", "selfhosted-001")); + $log->setServer(\gethostname()); $log->setVersion($version); $log->setType(Log::TYPE_ERROR); $log->setMessage($error->getMessage()); @@ -327,12 +327,10 @@ App::error(function ($error, $utopia, $request, $response, $layout, $project, $l 'locale' => (string)$request->getParam('locale', $request->getHeader('x-appwrite-locale', '')), ]); - $log->setExtra([ - 'file' => $error->getFile(), - 'line' => $error->getLine(), - 'trace' => $error->getTraceAsString(), - 'roles' => Authorization::$roles - ]); + $log->addExtra('file', $error->getFile()); + $log->addExtra('line', $error->getLine()); + $log->addExtra('trace', $error->getTraceAsString()); + $log->addExtra('roles', Authorization::$roles); $action = $route->getLabel("sdk.namespace", "UNKNOWN_NAMESPACE") . '.' . $route->getLabel("sdk.method", "UNKNOWN_METHOD"); $log->setAction($action); @@ -340,7 +338,9 @@ App::error(function ($error, $utopia, $request, $response, $layout, $project, $l $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); - $log->setBreadcrumbs($loggerBreadcrumb); + foreach($loggerBreadcrumbs as $loggerBreadcrumb) { + $log->addBreadcrumb($loggerBreadcrumb); + } $responseCode = $logger->addLog($log); Console::info('Log pushed with status code: '.$responseCode); @@ -431,7 +431,7 @@ App::error(function ($error, $utopia, $request, $response, $layout, $project, $l $response->dynamic(new Document($output), $utopia->isDevelopment() ? Response::MODEL_ERROR_DEV : Response::MODEL_ERROR); -}, ['error', 'utopia', 'request', 'response', 'layout', 'project', 'logger', 'user', 'loggerBreadcrumb']); +}, ['error', 'utopia', 'request', 'response', 'layout', 'project', 'logger', 'user', 'loggerBreadcrumbs']); App::get('/manifest.json') ->desc('Progressive app manifest file') diff --git a/app/init.php b/app/init.php index b7634b932..0f3abe5fa 100644 --- a/app/init.php +++ b/app/init.php @@ -174,7 +174,6 @@ $register->set('logger', function () { // Register error logger if(!Logger::hasProvider($providerName)) { throw new Exception("Logging provider not supported. Logging disabled."); - return; } $classname = '\\Utopia\\Logger\\Adapter\\'.\ucfirst($providerName); @@ -366,7 +365,7 @@ App::setResource('logger', function($register) { return $register->get('logger'); }, ['register']); -App::setResource('loggerBreadcrumb', function() { +App::setResource('loggerBreadcrumbs', function() { return []; }); diff --git a/app/realtime.php b/app/realtime.php index 41b449349..fcb121f76 100644 --- a/app/realtime.php +++ b/app/realtime.php @@ -35,7 +35,7 @@ function logError($register, \Throwable $error, $action) { $log = new Log(); $log->setNamespace("realtime"); - $log->setServer(App::getEnv("_APP_LOGGING_SERVERNAME", "selfhosted-001")); + $log->setServer(\gethostname()); $log->setVersion($version); $log->setType(Log::TYPE_ERROR); $log->setMessage($error->getMessage()); @@ -45,11 +45,9 @@ function logError($register, \Throwable $error, $action) { 'verbose_type' => get_class($error), ]); - $log->setExtra([ - 'file' => $error->getFile(), - 'line' => $error->getLine(), - 'trace' => $error->getTraceAsString(), - ]); + $log->addExtra('file', $error->getFile()); + $log->addExtra('line', $error->getLine()); + $log->addExtra('trace', $error->getTraceAsString()); $log->setAction($action); diff --git a/app/views/install/compose.phtml b/app/views/install/compose.phtml index 2e072b710..25557f21d 100644 --- a/app/views/install/compose.phtml +++ b/app/views/install/compose.phtml @@ -108,7 +108,6 @@ services: - _APP_FUNCTIONS_RUNTIMES - _APP_LOGGING_PROVIDER - _APP_LOGGING_CONFIG - - _APP_LOGGING_SERVERNAME appwrite-realtime: image: /: diff --git a/app/workers/audits.php b/app/workers/audits.php index 321785f40..e185ada76 100644 --- a/app/workers/audits.php +++ b/app/workers/audits.php @@ -12,7 +12,7 @@ Console::success(APP_NAME . ' audits worker v1 has started'); class AuditsV1 extends Worker { - public function getWorkerName(): string { + public function getName(): string { return "audits"; } diff --git a/app/workers/certificates.php b/app/workers/certificates.php index 31ff483cb..eae739a21 100644 --- a/app/workers/certificates.php +++ b/app/workers/certificates.php @@ -18,7 +18,7 @@ Console::success(APP_NAME . ' certificates worker v1 has started'); class CertificatesV1 extends Worker { - public function getWorkerName(): string { + public function getName(): string { return "certificates"; } diff --git a/app/workers/deletes.php b/app/workers/deletes.php index d082bf80d..5a27c8767 100644 --- a/app/workers/deletes.php +++ b/app/workers/deletes.php @@ -23,7 +23,7 @@ class DeletesV1 extends Worker { protected Database $consoleDB; - public function getWorkerName(): string { + public function getName(): string { return "deletes"; } diff --git a/app/workers/functions.php b/app/workers/functions.php index e11331890..a9a196da9 100644 --- a/app/workers/functions.php +++ b/app/workers/functions.php @@ -101,7 +101,7 @@ class FunctionsV1 extends Worker public array $allowed = []; - public function getWorkerName(): string { + public function getName(): string { return "functions"; } diff --git a/app/workers/mails.php b/app/workers/mails.php index 61e8a7e84..418526f2e 100644 --- a/app/workers/mails.php +++ b/app/workers/mails.php @@ -13,7 +13,7 @@ Console::success(APP_NAME . ' mails worker v1 has started' . "\n"); class MailsV1 extends Worker { - public function getWorkerName(): string { + public function getName(): string { return "mails"; } diff --git a/app/workers/tasks.php b/app/workers/tasks.php index 746b80991..2a981ea3e 100644 --- a/app/workers/tasks.php +++ b/app/workers/tasks.php @@ -17,7 +17,7 @@ Console::success(APP_NAME . ' tasks worker v1 has started'); class TasksV1 extends Worker { - public function getWorkerName(): string { + public function getName(): string { return "tasks"; } diff --git a/app/workers/usage.php b/app/workers/usage.php index 34c608d8d..4258dd69d 100644 --- a/app/workers/usage.php +++ b/app/workers/usage.php @@ -11,7 +11,7 @@ Console::success(APP_NAME . ' usage worker v1 has started'); class UsageV1 extends Worker { - public function getWorkerName(): string { + public function getName(): string { return "usage"; } diff --git a/app/workers/webhooks.php b/app/workers/webhooks.php index 9f545c2de..d1f5cd44d 100644 --- a/app/workers/webhooks.php +++ b/app/workers/webhooks.php @@ -11,7 +11,7 @@ Console::success(APP_NAME . ' webhooks worker v1 has started'); class WebhooksV1 extends Worker { - public function getWorkerName(): string { + public function getName(): string { return "webhooks"; } diff --git a/composer.lock b/composer.lock index 67bcf4d7a..25a64b230 100644 --- a/composer.lock +++ b/composer.lock @@ -2066,7 +2066,7 @@ "source": { "type": "git", "url": "https://github.com/utopia-php/logger", - "reference": "11f94f7f1ac2df226094271be3f2736fe26d8eec" + "reference": "5d8cc1bbbfc738ae28ede0d438a1d5318011cf6a" }, "require": { "php": ">=7.4" @@ -2113,7 +2113,7 @@ "utopia", "warnings" ], - "time": "2021-11-23T12:13:29+00:00" + "time": "2021-11-24T09:10:10+00:00" }, { "name": "utopia-php/orchestration", diff --git a/docker-compose.yml b/docker-compose.yml index b0c3f0312..963e3af46 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -131,7 +131,6 @@ services: - _APP_FUNCTIONS_RUNTIMES - _APP_LOGGING_PROVIDER - _APP_LOGGING_CONFIG - - _APP_LOGGING_SERVERNAME appwrite-realtime: entrypoint: realtime @@ -178,7 +177,6 @@ services: - _APP_USAGE_STATS - _APP_LOGGING_PROVIDER - _APP_LOGGING_CONFIG - - _APP_LOGGING_SERVERNAME appwrite-worker-usage: entrypoint: worker-usage @@ -203,7 +201,6 @@ services: - _APP_STATSD_PORT - _APP_LOGGING_PROVIDER - _APP_LOGGING_CONFIG - - _APP_LOGGING_SERVERNAME appwrite-worker-audits: entrypoint: worker-audits @@ -231,7 +228,6 @@ services: - _APP_DB_PASS - _APP_LOGGING_PROVIDER - _APP_LOGGING_CONFIG - - _APP_LOGGING_SERVERNAME appwrite-worker-webhooks: entrypoint: worker-webhooks @@ -256,7 +252,6 @@ services: - _APP_REDIS_PASS - _APP_LOGGING_PROVIDER - _APP_LOGGING_CONFIG - - _APP_LOGGING_SERVERNAME appwrite-worker-tasks: entrypoint: worker-tasks @@ -286,7 +281,6 @@ services: - _APP_DB_PASS - _APP_LOGGING_PROVIDER - _APP_LOGGING_CONFIG - - _APP_LOGGING_SERVERNAME appwrite-worker-deletes: entrypoint: worker-deletes @@ -318,7 +312,6 @@ services: - _APP_DB_PASS - _APP_LOGGING_PROVIDER - _APP_LOGGING_CONFIG - - _APP_LOGGING_SERVERNAME appwrite-worker-certificates: entrypoint: worker-certificates @@ -349,7 +342,6 @@ services: - _APP_DB_PASS - _APP_LOGGING_PROVIDER - _APP_LOGGING_CONFIG - - _APP_LOGGING_SERVERNAME appwrite-worker-functions: entrypoint: worker-functions @@ -391,7 +383,6 @@ services: - DOCKERHUB_PULL_PASSWORD - _APP_LOGGING_PROVIDER - _APP_LOGGING_CONFIG - - _APP_LOGGING_SERVERNAME appwrite-worker-mails: entrypoint: worker-mails @@ -422,7 +413,6 @@ services: - _APP_SMTP_PASSWORD - _APP_LOGGING_PROVIDER - _APP_LOGGING_CONFIG - - _APP_LOGGING_SERVERNAME appwrite-maintenance: entrypoint: maintenance diff --git a/src/Appwrite/Resque/Worker.php b/src/Appwrite/Resque/Worker.php index e7b3c1435..9c03b9238 100644 --- a/src/Appwrite/Resque/Worker.php +++ b/src/Appwrite/Resque/Worker.php @@ -11,7 +11,7 @@ abstract class Worker { public array $args = []; - abstract public function getWorkerName(): string; + abstract public function getName(): string; abstract public function init(): void; @@ -28,12 +28,12 @@ abstract class Worker $logger = $register->get('logger'); $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); - $workerType = $this->getWorkerName(); + $workerType = $this->getName(); $log = new Log(); $log->setNamespace("worker-" . $workerType); - $log->setServer(App::getEnv("_APP_LOGGING_SERVERNAME", "selfhosted-001")); + $log->setServer(\gethostname()); $log->setVersion($version); $log->setType(Log::TYPE_ERROR); $log->setMessage($error->getMessage()); @@ -44,12 +44,10 @@ abstract class Worker 'verbose_type' => get_class($error), ]); - $log->setExtra([ - 'file' => $error->getFile(), - 'line' => $error->getLine(), - 'trace' => $error->getTraceAsString(), - 'args' => $this->args - ]); + $log->addExtra('file', $error->getFile()); + $log->addExtra('line', $error->getLine()); + $log->addExtra('trace', $error->getTraceAsString()); + $log->addExtra('args', $this->args); $action = 'worker.' . $workerType . '.setUp'; $log->setAction($action); @@ -74,12 +72,12 @@ abstract class Worker global $register; $logger = $register->get('logger'); $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); - $workerType = $this->getWorkerName(); + $workerType = $this->getName(); $log = new Log(); $log->setNamespace("worker-" . $workerType); - $log->setServer(App::getEnv("_APP_LOGGING_SERVERNAME", "selfhosted-001")); + $log->setServer(\gethostname()); $log->setVersion($version); $log->setType(Log::TYPE_ERROR); $log->setMessage($error->getMessage()); @@ -90,11 +88,9 @@ abstract class Worker 'verbose_type' => get_class($error), ]); - $log->setExtra([ - 'file' => $error->getFile(), - 'line' => $error->getLine(), - 'trace' => $error->getTraceAsString() - ]); + $log->addExtra('file', $error->getFile()); + $log->addExtra('line', $error->getLine()); + $log->addExtra('trace', $error->getTraceAsString()); $action = 'worker.' . $workerType . '.perform'; $log->setAction($action); @@ -119,12 +115,12 @@ abstract class Worker global $register; $logger = $register->get('logger'); $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); - $workerType = $this->getWorkerName(); + $workerType = $this->getName(); $log = new Log(); $log->setNamespace("worker-" . $workerType); - $log->setServer(App::getEnv("_APP_LOGGING_SERVERNAME", "selfhosted-001")); + $log->setServer(\gethostname()); $log->setVersion($version); $log->setType(Log::TYPE_ERROR); $log->setMessage($error->getMessage()); @@ -135,11 +131,9 @@ abstract class Worker 'verbose_type' => get_class($error), ]); - $log->setExtra([ - 'file' => $error->getFile(), - 'line' => $error->getLine(), - 'trace' => $error->getTraceAsString() - ]); + $log->addExtra('file', $error->getFile()); + $log->addExtra('line', $error->getLine()); + $log->addExtra('trace', $error->getTraceAsString()); $action = 'worker.' . $workerType . '.tearDown'; $log->setAction($action); From 5b08969133950736115c21d2c618be6ab7964cd6 Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Wed, 24 Nov 2021 11:09:04 +0100 Subject: [PATCH 04/28] Code review changes --- composer.json | 6 ------ docker-compose.yml | 4 +--- 2 files changed, 1 insertion(+), 9 deletions(-) diff --git a/composer.json b/composer.json index f37f2320b..ff42d5127 100644 --- a/composer.json +++ b/composer.json @@ -20,12 +20,6 @@ "Appwrite\\Tests\\": "tests/extensions" } }, - "repositories": [ - { - "type": "git", - "url": "https://github.com/utopia-php/logger" - } - ], "require": { "php": ">=8.0.0", "ext-curl": "*", diff --git a/docker-compose.yml b/docker-compose.yml index 963e3af46..f01d6c0b1 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -71,7 +71,7 @@ services: - ./psalm.xml:/usr/src/code/psalm.xml - ./tests:/usr/src/code/tests - ./app:/usr/src/code/app - - ./vendor:/usr/src/code/vendor + # - ./vendor:/usr/src/code/vendor - ./docs:/usr/src/code/docs - ./public:/usr/src/code/public - ./src:/usr/src/code/src @@ -160,7 +160,6 @@ services: volumes: - ./app:/usr/src/code/app - ./src:/usr/src/code/src - - ./vendor:/usr/src/code/vendor depends_on: - redis environment: @@ -353,7 +352,6 @@ services: volumes: - /var/run/docker.sock:/var/run/docker.sock - appwrite-functions:/storage/functions:rw - - ./vendor:/usr/src/code/vendor - /tmp:/tmp:rw - ./app:/usr/src/code/app - ./src:/usr/src/code/src From fd1dcae24709251695243d2a3bc31fb2fae288d6 Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Wed, 24 Nov 2021 11:09:10 +0100 Subject: [PATCH 05/28] Documented worker class --- src/Appwrite/Resque/Worker.php | 56 +++++++++++++++++++++++++++++++--- 1 file changed, 52 insertions(+), 4 deletions(-) diff --git a/src/Appwrite/Resque/Worker.php b/src/Appwrite/Resque/Worker.php index 9c03b9238..8e99b3708 100644 --- a/src/Appwrite/Resque/Worker.php +++ b/src/Appwrite/Resque/Worker.php @@ -5,20 +5,56 @@ namespace Appwrite\Resque; use Utopia\App; use Utopia\CLI\Console; use Utopia\Logger\Log; -use function get_class; abstract class Worker { + /** + * Named array holding all information passed into worker alongside a new task. + * + * @return array + */ public array $args = []; + /** + * Function for identifying the worker needs to be set to unique name + * + * @return string + */ abstract public function getName(): string; + /** + * Function executed before running first task. + * Can include any preparations, such as connecting to external services or loading files + * + * @return void + * @throws \Exception|\Throwable + */ abstract public function init(): void; + /** + * Function executed when new task requests is received. + * You can access $args here, it will contain event information + * + * @return void + * @throws \Exception|\Throwable + */ abstract public function run(): void; + /** + * Function executed just before shutting down the worker. + * You can do cleanup here, such as disconnecting from services or removing temp files + * + * @return void + * @throws \Exception|\Throwable + */ abstract public function shutdown(): void; + /** + * A wrapper around 'init' function with non-worker-specific code + * + * @return void + * @throws \Exception|\Throwable + */ public function setUp(): void { try { @@ -41,7 +77,7 @@ abstract class Worker $log->setTags([ 'worker_type' => $workerType, 'code' => $error->getCode(), - 'verbose_type' => get_class($error), + 'verbose_type' => \get_class($error), ]); $log->addExtra('file', $error->getFile()); @@ -64,6 +100,12 @@ abstract class Worker } } + /** + * A wrapper around 'run' function with non-worker-specific code + * + * @return void + * @throws \Exception|\Throwable + */ public function perform(): void { try { @@ -85,7 +127,7 @@ abstract class Worker $log->setTags([ 'worker_type' => $workerType, 'code' => $error->getCode(), - 'verbose_type' => get_class($error), + 'verbose_type' => \get_class($error), ]); $log->addExtra('file', $error->getFile()); @@ -107,6 +149,12 @@ abstract class Worker } } + /** + * A wrapper around 'shutdown' function with non-worker-specific code + * + * @return void + * @throws \Exception|\Throwable + */ public function tearDown(): void { try { @@ -128,7 +176,7 @@ abstract class Worker $log->setTags([ 'worker_type' => $workerType, 'code' => $error->getCode(), - 'verbose_type' => get_class($error), + 'verbose_type' => \get_class($error), ]); $log->addExtra('file', $error->getFile()); From 70c566669005e33be3389744034ae8e55742d039 Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Wed, 24 Nov 2021 12:06:47 +0100 Subject: [PATCH 06/28] Fixed logger import --- composer.json | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/composer.json b/composer.json index ff42d5127..f37f2320b 100644 --- a/composer.json +++ b/composer.json @@ -20,6 +20,12 @@ "Appwrite\\Tests\\": "tests/extensions" } }, + "repositories": [ + { + "type": "git", + "url": "https://github.com/utopia-php/logger" + } + ], "require": { "php": ">=8.0.0", "ext-curl": "*", From 276f521eb6f9078db32e4241a55e46fc164dc92b Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Thu, 25 Nov 2021 14:45:05 +0100 Subject: [PATCH 07/28] WIP: Realtime erro handler fix --- app/realtime.php | 44 +++++++++++++++++++++++--------------------- composer.json | 2 +- composer.lock | 17 +++++++++-------- 3 files changed, 33 insertions(+), 30 deletions(-) diff --git a/app/realtime.php b/app/realtime.php index fcb121f76..828a6b59b 100644 --- a/app/realtime.php +++ b/app/realtime.php @@ -28,7 +28,28 @@ require_once __DIR__ . '/init.php'; Runtime::enableCoroutine(SWOOLE_HOOK_ALL); -function logError($register, \Throwable $error, $action) { +$realtime = new Realtime(); + +/** + * Table for statistics across all workers. + */ +$stats = new Table(4096, 1); +$stats->column('projectId', Table::TYPE_STRING, 64); +$stats->column('teamId', Table::TYPE_STRING, 64); +$stats->column('connections', Table::TYPE_INT); +$stats->column('connectionsTotal', Table::TYPE_INT); +$stats->column('messages', Table::TYPE_INT); +$stats->create(); + +$containerId = uniqid(); +$documentId = null; + +$adapter = new Adapter\Swoole(port: App::getEnv('PORT', 80)); +$adapter->setPackageMaxLength(64000); // Default maximum Package Size (64kb) + +$server = new Server($adapter); + +function logError(Throwable $error, string $action) use ($register) { $logger = $register->get('logger'); $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); @@ -60,26 +81,7 @@ function logError($register, \Throwable $error, $action) { Console::info('Realtime log pushed with status code: '.$responseCode); } -$realtime = new Realtime(); - -/** - * Table for statistics across all workers. - */ -$stats = new Table(4096, 1); -$stats->column('projectId', Table::TYPE_STRING, 64); -$stats->column('teamId', Table::TYPE_STRING, 64); -$stats->column('connections', Table::TYPE_INT); -$stats->column('connectionsTotal', Table::TYPE_INT); -$stats->column('messages', Table::TYPE_INT); -$stats->create(); - -$containerId = uniqid(); -$documentId = null; - -$adapter = new Adapter\Swoole(port: App::getEnv('PORT', 80)); -$adapter->setPackageMaxLength(64000); // Default maximum Package Size (64kb) - -$server = new Server($adapter); +$server->onError(logError()); $server->onStart(function () use ($stats, $register, $containerId, &$documentId) { Console::success('Server started succefully'); diff --git a/composer.json b/composer.json index f37f2320b..a15a51bc5 100644 --- a/composer.json +++ b/composer.json @@ -59,7 +59,7 @@ "utopia-php/domains": "1.1.*", "utopia-php/swoole": "0.2.*", "utopia-php/storage": "0.5.*", - "utopia-php/websocket": "0.0.*", + "utopia-php/websocket": "dev-feat-onerror-callback", "utopia-php/image": "0.5.*", "resque/php-resque": "1.3.6", "matomo/device-detector": "4.3.1", diff --git a/composer.lock b/composer.lock index 25a64b230..a61ba2bca 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": "5f9aa807864b9d84a96685c1735ee30e", + "content-hash": "d16e7eb6e8b85d414f22270af7cfb314", "packages": [ { "name": "adhocore/jwt", @@ -2440,16 +2440,16 @@ }, { "name": "utopia-php/websocket", - "version": "0.0.1", + "version": "dev-feat-onerror-callback", "source": { "type": "git", "url": "https://github.com/utopia-php/websocket.git", - "reference": "808317ef4ea0683c2c82dee5d543b1c8378e2e1b" + "reference": "917f82f617bda5a0b63b4c94f32cada43acc7fb0" }, "dist": { "type": "zip", - "url": "https://api.github.com/repos/utopia-php/websocket/zipball/808317ef4ea0683c2c82dee5d543b1c8378e2e1b", - "reference": "808317ef4ea0683c2c82dee5d543b1c8378e2e1b", + "url": "https://api.github.com/repos/utopia-php/websocket/zipball/917f82f617bda5a0b63b4c94f32cada43acc7fb0", + "reference": "917f82f617bda5a0b63b4c94f32cada43acc7fb0", "shasum": "" }, "require": { @@ -2492,9 +2492,9 @@ ], "support": { "issues": "https://github.com/utopia-php/websocket/issues", - "source": "https://github.com/utopia-php/websocket/tree/0.0.1" + "source": "https://github.com/utopia-php/websocket/tree/feat-onerror-callback" }, - "time": "2021-07-11T13:09:44+00:00" + "time": "2021-11-24T12:04:35+00:00" }, { "name": "webmozart/assert", @@ -6378,7 +6378,8 @@ "aliases": [], "minimum-stability": "stable", "stability-flags": { - "utopia-php/logger": 20 + "utopia-php/logger": 20, + "utopia-php/websocket": 20 }, "prefer-stable": false, "prefer-lowest": false, From a8bf2a4f5921eb3df23caf4acede1cbd006a1547 Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Thu, 25 Nov 2021 15:13:14 +0100 Subject: [PATCH 08/28] FIxed realtime logging, upgraded code to new logger version --- .env | 4 +- app/controllers/general.php | 18 ++--- app/realtime.php | 25 +++--- composer.lock | 13 ++- src/Appwrite/Resque/Worker.php | 142 ++++++++++++++++----------------- 5 files changed, 100 insertions(+), 102 deletions(-) diff --git a/.env b/.env index eff9201d2..972024c34 100644 --- a/.env +++ b/.env @@ -43,5 +43,5 @@ _APP_MAINTENANCE_RETENTION_EXECUTION=1209600 _APP_MAINTENANCE_RETENTION_ABUSE=86400 _APP_MAINTENANCE_RETENTION_AUDIT=1209600 _APP_USAGE_STATS=enabled -_APP_LOGGING_PROVIDER=sentry -_APP_LOGGING_CONFIG=9a4ebfef5ab14c8483366039b9de2835;6076895 \ No newline at end of file +_APP_LOGGING_PROVIDER= +_APP_LOGGING_CONFIG= \ No newline at end of file diff --git a/app/controllers/general.php b/app/controllers/general.php index 717ae5c16..d88c987db 100644 --- a/app/controllers/general.php +++ b/app/controllers/general.php @@ -304,7 +304,7 @@ App::error(function ($error, $utopia, $request, $response, $layout, $project, $l $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); $route = $utopia->match($request); - if($error->getCode() >= 500 || $error->getCode() === 0) { + if($error->getCode() >= 500 || $error->getCode() === 0 && !$logger) { $log = new Utopia\Logger\Log(); if(!$user->isEmpty()) { @@ -317,15 +317,13 @@ App::error(function ($error, $utopia, $request, $response, $layout, $project, $l $log->setType(Log::TYPE_ERROR); $log->setMessage($error->getMessage()); - $log->setTags([ - 'method' => $route->getMethod(), - 'url' => $route->getPath(), - 'code' => $error->getCode(), - 'verbose_type' => get_class($error), - 'projectId' => $project->getId(), - 'hostname' => $request->getHostname(), - 'locale' => (string)$request->getParam('locale', $request->getHeader('x-appwrite-locale', '')), - ]); + $log->addTag('method', $route->getMethod()); + $log->addTag('url', $error->getCode()); + $log->addTag('code', get_class($error)); + $log->addTag('verbose_type', $route->getPath()); + $log->addTag('projectId', $project->getId()); + $log->addTag('hostname', $request->getHostname()); + $log->addTag('locale', (string)$request->getParam('locale', $request->getHeader('x-appwrite-locale', ''))); $log->addExtra('file', $error->getFile()); $log->addExtra('line', $error->getLine()); diff --git a/app/realtime.php b/app/realtime.php index 828a6b59b..2110b5593 100644 --- a/app/realtime.php +++ b/app/realtime.php @@ -49,9 +49,13 @@ $adapter->setPackageMaxLength(64000); // Default maximum Package Size (64kb) $server = new Server($adapter); -function logError(Throwable $error, string $action) use ($register) { +$logError = function(Throwable $error, string $action) use ($register) { $logger = $register->get('logger'); + if(!$logger) { + return; + } + $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); $log = new Log(); @@ -61,10 +65,8 @@ function logError(Throwable $error, string $action) use ($register) { $log->setType(Log::TYPE_ERROR); $log->setMessage($error->getMessage()); - $log->setTags([ - 'code' => $error->getCode(), - 'verbose_type' => get_class($error), - ]); + $log->addTag('code', $error->getCode()); + $log->addTag('verbose_type', get_class($error)); $log->addExtra('file', $error->getFile()); $log->addExtra('line', $error->getLine()); @@ -75,15 +77,13 @@ function logError(Throwable $error, string $action) use ($register) { $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); - $log->setBreadcrumbs([]); - $responseCode = $logger->addLog($log); Console::info('Realtime log pushed with status code: '.$responseCode); -} +}; -$server->onError(logError()); +$server->onError($logError); -$server->onStart(function () use ($stats, $register, $containerId, &$documentId) { +$server->onStart(function () use ($stats, $register, $containerId, &$documentId, $logError) { Console::success('Server started succefully'); $getConsoleDb = function () use ($register) { @@ -107,7 +107,7 @@ $server->onStart(function () use ($stats, $register, $containerId, &$documentId) /** * Create document for this worker to share stats across Containers. */ - go(function () use ($getConsoleDb, $containerId, &$documentId, $register) { + go(function () use ($getConsoleDb, $containerId, &$documentId, $register, $logError) { try { [$consoleDb, $returnConsoleDb] = call_user_func($getConsoleDb); $document = [ @@ -125,7 +125,8 @@ $server->onStart(function () use ($stats, $register, $containerId, &$documentId) Authorization::enable(); $documentId = $document->getId(); } catch (\Throwable $th) { - logError($register, $th, "onStart.createDocument"); + var_dump("Error starting"); + call_user_func($logError, $th, "onStart.createDocument"); Console::error('[Error] Type: ' . get_class($th)); Console::error('[Error] Message: ' . $th->getMessage()); diff --git a/composer.lock b/composer.lock index a61ba2bca..fe0012021 100644 --- a/composer.lock +++ b/composer.lock @@ -5205,7 +5205,6 @@ "type": "github" } ], - "abandoned": true, "time": "2020-09-28T06:45:17+00:00" }, { @@ -6141,16 +6140,16 @@ }, { "name": "twig/twig", - "version": "v2.14.7", + "version": "v2.14.8", "source": { "type": "git", "url": "https://github.com/twigphp/Twig.git", - "reference": "8e202327ee1ed863629de9b18a5ec70ac614d88f" + "reference": "06b450a2326aa879faa2061ff72fe1588b3ab043" }, "dist": { "type": "zip", - "url": "https://api.github.com/repos/twigphp/Twig/zipball/8e202327ee1ed863629de9b18a5ec70ac614d88f", - "reference": "8e202327ee1ed863629de9b18a5ec70ac614d88f", + "url": "https://api.github.com/repos/twigphp/Twig/zipball/06b450a2326aa879faa2061ff72fe1588b3ab043", + "reference": "06b450a2326aa879faa2061ff72fe1588b3ab043", "shasum": "" }, "require": { @@ -6204,7 +6203,7 @@ ], "support": { "issues": "https://github.com/twigphp/Twig/issues", - "source": "https://github.com/twigphp/Twig/tree/v2.14.7" + "source": "https://github.com/twigphp/Twig/tree/v2.14.8" }, "funding": [ { @@ -6216,7 +6215,7 @@ "type": "tidelift" } ], - "time": "2021-09-17T08:39:54+00:00" + "time": "2021-11-25T13:38:06+00:00" }, { "name": "vimeo/psalm", diff --git a/src/Appwrite/Resque/Worker.php b/src/Appwrite/Resque/Worker.php index 8e99b3708..094573a11 100644 --- a/src/Appwrite/Resque/Worker.php +++ b/src/Appwrite/Resque/Worker.php @@ -63,38 +63,36 @@ abstract class Worker global $register; $logger = $register->get('logger'); - $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); - $workerType = $this->getName(); + if($logger) { + $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); + $workerType = $this->getName(); - $log = new Log(); + $log = new Log(); - $log->setNamespace("worker-" . $workerType); - $log->setServer(\gethostname()); - $log->setVersion($version); - $log->setType(Log::TYPE_ERROR); - $log->setMessage($error->getMessage()); + $log->setNamespace("worker-" . $workerType); + $log->setServer(\gethostname()); + $log->setVersion($version); + $log->setType(Log::TYPE_ERROR); + $log->setMessage($error->getMessage()); - $log->setTags([ - 'worker_type' => $workerType, - 'code' => $error->getCode(), - 'verbose_type' => \get_class($error), - ]); + $log->addTag('worker_type', $workerType); + $log->addTag('code', $error->getCode()); + $log->addTag('verbose_type', \get_class($error)); - $log->addExtra('file', $error->getFile()); - $log->addExtra('line', $error->getLine()); - $log->addExtra('trace', $error->getTraceAsString()); - $log->addExtra('args', $this->args); + $log->addExtra('file', $error->getFile()); + $log->addExtra('line', $error->getLine()); + $log->addExtra('trace', $error->getTraceAsString()); + $log->addExtra('args', $this->args); - $action = 'worker.' . $workerType . '.setUp'; - $log->setAction($action); + $action = 'worker.' . $workerType . '.setUp'; + $log->setAction($action); - $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; - $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); + $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; + $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); - $log->setBreadcrumbs([]); - - $responseCode = $logger->addLog($log); - Console::info('Setup log pushed with status code: '.$responseCode); + $responseCode = $logger->addLog($log); + Console::info('Setup log pushed with status code: '.$responseCode); + } throw $error; } @@ -113,37 +111,38 @@ abstract class Worker } catch(\Throwable $error) { global $register; $logger = $register->get('logger'); - $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); - $workerType = $this->getName(); - $log = new Log(); + if($logger) { + $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); + $workerType = $this->getName(); - $log->setNamespace("worker-" . $workerType); - $log->setServer(\gethostname()); - $log->setVersion($version); - $log->setType(Log::TYPE_ERROR); - $log->setMessage($error->getMessage()); + $log = new Log(); - $log->setTags([ - 'worker_type' => $workerType, - 'code' => $error->getCode(), - 'verbose_type' => \get_class($error), - ]); + $log->setNamespace("worker-" . $workerType); + $log->setServer(\gethostname()); + $log->setVersion($version); + $log->setType(Log::TYPE_ERROR); + $log->setMessage($error->getMessage()); - $log->addExtra('file', $error->getFile()); - $log->addExtra('line', $error->getLine()); - $log->addExtra('trace', $error->getTraceAsString()); + $log->setTags([ + 'worker_type' => $workerType, + 'code' => $error->getCode(), + 'verbose_type' => \get_class($error), + ]); - $action = 'worker.' . $workerType . '.perform'; - $log->setAction($action); + $log->addExtra('file', $error->getFile()); + $log->addExtra('line', $error->getLine()); + $log->addExtra('trace', $error->getTraceAsString()); - $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; - $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); + $action = 'worker.' . $workerType . '.perform'; + $log->setAction($action); - $log->setBreadcrumbs([]); + $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; + $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); - $responseCode = $logger->addLog($log); - Console::info('Perform log pushed with status code: '.$responseCode); + $responseCode = $logger->addLog($log); + Console::info('Perform log pushed with status code: '.$responseCode); + } throw $error; } @@ -162,37 +161,38 @@ abstract class Worker } catch(\Throwable $error) { global $register; $logger = $register->get('logger'); - $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); - $workerType = $this->getName(); - $log = new Log(); + if($logger) { + $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); + $workerType = $this->getName(); - $log->setNamespace("worker-" . $workerType); - $log->setServer(\gethostname()); - $log->setVersion($version); - $log->setType(Log::TYPE_ERROR); - $log->setMessage($error->getMessage()); + $log = new Log(); - $log->setTags([ - 'worker_type' => $workerType, - 'code' => $error->getCode(), - 'verbose_type' => \get_class($error), - ]); + $log->setNamespace("worker-" . $workerType); + $log->setServer(\gethostname()); + $log->setVersion($version); + $log->setType(Log::TYPE_ERROR); + $log->setMessage($error->getMessage()); - $log->addExtra('file', $error->getFile()); - $log->addExtra('line', $error->getLine()); - $log->addExtra('trace', $error->getTraceAsString()); + $log->setTags([ + 'worker_type' => $workerType, + 'code' => $error->getCode(), + 'verbose_type' => \get_class($error), + ]); - $action = 'worker.' . $workerType . '.tearDown'; - $log->setAction($action); + $log->addExtra('file', $error->getFile()); + $log->addExtra('line', $error->getLine()); + $log->addExtra('trace', $error->getTraceAsString()); - $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; - $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); + $action = 'worker.' . $workerType . '.tearDown'; + $log->setAction($action); - $log->setBreadcrumbs([]); + $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; + $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); - $responseCode = $logger->addLog($log); - Console::info('Teardown log pushed with status code: '.$responseCode); + $responseCode = $logger->addLog($log); + Console::info('Teardown log pushed with status code: '.$responseCode); + } throw $error; } From 7bed9aed5b506aa8975a4066cabd7e9c59916bb9 Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Mon, 29 Nov 2021 13:52:18 +0100 Subject: [PATCH 09/28] Updated to new utopia logger, removed leftover --- app/realtime.php | 11 +++++------ composer.lock | 12 ++++++------ 2 files changed, 11 insertions(+), 12 deletions(-) diff --git a/app/realtime.php b/app/realtime.php index 2110b5593..a8a033b00 100644 --- a/app/realtime.php +++ b/app/realtime.php @@ -81,7 +81,7 @@ $logError = function(Throwable $error, string $action) use ($register) { Console::info('Realtime log pushed with status code: '.$responseCode); }; -$server->onError($logError); +$server->error($logError); $server->onStart(function () use ($stats, $register, $containerId, &$documentId, $logError) { Console::success('Server started succefully'); @@ -125,8 +125,7 @@ $server->onStart(function () use ($stats, $register, $containerId, &$documentId, Authorization::enable(); $documentId = $document->getId(); } catch (\Throwable $th) { - var_dump("Error starting"); - call_user_func($logError, $th, "onStart.createDocument"); + call_user_func($logError, $th, "createWorkerDocument"); Console::error('[Error] Type: ' . get_class($th)); Console::error('[Error] Message: ' . $th->getMessage()); @@ -191,7 +190,7 @@ $server->onStart(function () use ($stats, $register, $containerId, &$documentId, 'value' => json_encode($payload) ]); } catch (\Throwable $th) { - logError($register, $th, "onStart.updateDocument"); + logError($register, $th, "updateWorkerDocument"); Console::error('[Error] Type: ' . get_class($th)); Console::error('[Error] Message: ' . $th->getMessage()); @@ -366,7 +365,7 @@ $server->onWorkerStart(function (int $workerId) use ($server, $register, $stats, } }); } catch (\Throwable $th) { - logError($register, $th, "onWorkerStart.pubSubConnection"); + logError($register, $th, "pubSubConnection"); Console::error('Pub/sub error: ' . $th->getMessage()); $register->get('redisPool')->put($redis); @@ -484,7 +483,7 @@ $server->onOpen(function (int $connection, SwooleRequest $request) use ($server, $stats->incr($project->getId(), 'connections'); $stats->incr($project->getId(), 'connectionsTotal'); } catch (\Throwable $th) { - logError($register, $th, "onOpen.init"); + logError($register, $th, "initServer"); $response = [ 'type' => 'error', diff --git a/composer.lock b/composer.lock index fe0012021..39abde66d 100644 --- a/composer.lock +++ b/composer.lock @@ -2066,7 +2066,7 @@ "source": { "type": "git", "url": "https://github.com/utopia-php/logger", - "reference": "5d8cc1bbbfc738ae28ede0d438a1d5318011cf6a" + "reference": "572ada8fd774cb8c6c09aab9fe2d36cd807eee13" }, "require": { "php": ">=7.4" @@ -2113,7 +2113,7 @@ "utopia", "warnings" ], - "time": "2021-11-24T09:10:10+00:00" + "time": "2021-11-29T08:40:52+00:00" }, { "name": "utopia-php/orchestration", @@ -2444,12 +2444,12 @@ "source": { "type": "git", "url": "https://github.com/utopia-php/websocket.git", - "reference": "917f82f617bda5a0b63b4c94f32cada43acc7fb0" + "reference": "237eed7e9c54a514cfabac3e5726d24661254f2e" }, "dist": { "type": "zip", - "url": "https://api.github.com/repos/utopia-php/websocket/zipball/917f82f617bda5a0b63b4c94f32cada43acc7fb0", - "reference": "917f82f617bda5a0b63b4c94f32cada43acc7fb0", + "url": "https://api.github.com/repos/utopia-php/websocket/zipball/237eed7e9c54a514cfabac3e5726d24661254f2e", + "reference": "237eed7e9c54a514cfabac3e5726d24661254f2e", "shasum": "" }, "require": { @@ -2494,7 +2494,7 @@ "issues": "https://github.com/utopia-php/websocket/issues", "source": "https://github.com/utopia-php/websocket/tree/feat-onerror-callback" }, - "time": "2021-11-24T12:04:35+00:00" + "time": "2021-11-29T08:43:24+00:00" }, { "name": "webmozart/assert", From 970936c93d0c83b5ef9a32adc965e679dc3a8ec1 Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Tue, 30 Nov 2021 13:12:17 +0100 Subject: [PATCH 10/28] WIP: Better worker error logging --- src/Appwrite/Resque/Worker.php | 163 ++++++++++++--------------------- 1 file changed, 61 insertions(+), 102 deletions(-) diff --git a/src/Appwrite/Resque/Worker.php b/src/Appwrite/Resque/Worker.php index 094573a11..b6cb86851 100644 --- a/src/Appwrite/Resque/Worker.php +++ b/src/Appwrite/Resque/Worker.php @@ -2,12 +2,15 @@ namespace Appwrite\Resque; -use Utopia\App; -use Utopia\CLI\Console; -use Utopia\Logger\Log; - abstract class Worker { + /** + * Callbacks that will be executed when an error occurs + * + * @var array + */ + protected $errorCallbacks = []; + /** * Named array holding all information passed into worker alongside a new task. * @@ -60,38 +63,8 @@ abstract class Worker try { $this->init(); } catch(\Throwable $error) { - global $register; - $logger = $register->get('logger'); - - if($logger) { - $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); - $workerType = $this->getName(); - - $log = new Log(); - - $log->setNamespace("worker-" . $workerType); - $log->setServer(\gethostname()); - $log->setVersion($version); - $log->setType(Log::TYPE_ERROR); - $log->setMessage($error->getMessage()); - - $log->addTag('worker_type', $workerType); - $log->addTag('code', $error->getCode()); - $log->addTag('verbose_type', \get_class($error)); - - $log->addExtra('file', $error->getFile()); - $log->addExtra('line', $error->getLine()); - $log->addExtra('trace', $error->getTraceAsString()); - $log->addExtra('args', $this->args); - - $action = 'worker.' . $workerType . '.setUp'; - $log->setAction($action); - - $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; - $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); - - $responseCode = $logger->addLog($log); - Console::info('Setup log pushed with status code: '.$responseCode); + foreach ($this->errorCallbacks as $errorCallback) { + $errorCallback($error, "init"); } throw $error; @@ -109,39 +82,8 @@ abstract class Worker try { $this->run(); } catch(\Throwable $error) { - global $register; - $logger = $register->get('logger'); - - if($logger) { - $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); - $workerType = $this->getName(); - - $log = new Log(); - - $log->setNamespace("worker-" . $workerType); - $log->setServer(\gethostname()); - $log->setVersion($version); - $log->setType(Log::TYPE_ERROR); - $log->setMessage($error->getMessage()); - - $log->setTags([ - 'worker_type' => $workerType, - 'code' => $error->getCode(), - 'verbose_type' => \get_class($error), - ]); - - $log->addExtra('file', $error->getFile()); - $log->addExtra('line', $error->getLine()); - $log->addExtra('trace', $error->getTraceAsString()); - - $action = 'worker.' . $workerType . '.perform'; - $log->setAction($action); - - $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; - $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); - - $responseCode = $logger->addLog($log); - Console::info('Perform log pushed with status code: '.$responseCode); + foreach ($this->errorCallbacks as $errorCallback) { + $errorCallback($error, "run"); } throw $error; @@ -159,42 +101,59 @@ abstract class Worker try { $this->shutdown(); } catch(\Throwable $error) { - global $register; - $logger = $register->get('logger'); - - if($logger) { - $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); - $workerType = $this->getName(); - - $log = new Log(); - - $log->setNamespace("worker-" . $workerType); - $log->setServer(\gethostname()); - $log->setVersion($version); - $log->setType(Log::TYPE_ERROR); - $log->setMessage($error->getMessage()); - - $log->setTags([ - 'worker_type' => $workerType, - 'code' => $error->getCode(), - 'verbose_type' => \get_class($error), - ]); - - $log->addExtra('file', $error->getFile()); - $log->addExtra('line', $error->getLine()); - $log->addExtra('trace', $error->getTraceAsString()); - - $action = 'worker.' . $workerType . '.tearDown'; - $log->setAction($action); - - $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; - $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); - - $responseCode = $logger->addLog($log); - Console::info('Teardown log pushed with status code: '.$responseCode); + foreach ($this->errorCallbacks as $errorCallback) { + $errorCallback($error, "shutdown"); } throw $error; } } + + + /** + * Register callback. Will be executed when error occurs. + * @param callable $callback + * @param Throwable $error + * @return self + */ + public function error(callable $callback): self + { + \array_push($this->errorCallbacks, $callback); + return $this; + } + + // TODO: Implement this on init file using Worker->error(function() { HERE }) + //global $register; + //$logger = $register->get('logger'); + // + //if($logger) { + //$version = App::getEnv('_APP_VERSION', 'UNKNOWN'); + //$workerType = $this->getName(); + // + //$log = new Log(); + // + //$log->setNamespace("worker-" . $workerType); + //$log->setServer(\gethostname()); + //$log->setVersion($version); + //$log->setType(Log::TYPE_ERROR); + //$log->setMessage($error->getMessage()); + // + //$log->addTag('worker_type', $workerType); + //$log->addTag('code', $error->getCode()); + //$log->addTag('verbose_type', \get_class($error)); + // + //$log->addExtra('file', $error->getFile()); + //$log->addExtra('line', $error->getLine()); + //$log->addExtra('trace', $error->getTraceAsString()); + //$log->addExtra('args', $this->args); + // + //$action = 'worker.' . $workerType . '.setUp'; + //$log->setAction($action); + // + //$isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; + //$log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); + // + //$responseCode = $logger->addLog($log); + //Console::info('Setup log pushed with status code: '.$responseCode); + //} } From c057084bee4855d9cf06d56afc74ef69c5110a7b Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Wed, 1 Dec 2021 11:59:08 +0100 Subject: [PATCH 11/28] Log data update --- .env | 4 ++-- app/controllers/general.php | 6 +++--- app/realtime.php | 2 +- src/Appwrite/Resque/Worker.php | 4 ++-- 4 files changed, 8 insertions(+), 8 deletions(-) diff --git a/.env b/.env index 972024c34..c9fd64c8f 100644 --- a/.env +++ b/.env @@ -43,5 +43,5 @@ _APP_MAINTENANCE_RETENTION_EXECUTION=1209600 _APP_MAINTENANCE_RETENTION_ABUSE=86400 _APP_MAINTENANCE_RETENTION_AUDIT=1209600 _APP_USAGE_STATS=enabled -_APP_LOGGING_PROVIDER= -_APP_LOGGING_CONFIG= \ No newline at end of file +_APP_LOGGING_PROVIDER=raygun +_APP_LOGGING_CONFIG=4TzuEf7cZAnmBojWAPIm2Q diff --git a/app/controllers/general.php b/app/controllers/general.php index d88c987db..e70a80058 100644 --- a/app/controllers/general.php +++ b/app/controllers/general.php @@ -318,9 +318,9 @@ App::error(function ($error, $utopia, $request, $response, $layout, $project, $l $log->setMessage($error->getMessage()); $log->addTag('method', $route->getMethod()); - $log->addTag('url', $error->getCode()); - $log->addTag('code', get_class($error)); - $log->addTag('verbose_type', $route->getPath()); + $log->addTag('url', $route->getPath()); + $log->addTag('verboseType', get_class($error)); + $log->addTag('code', $error->getCode()); $log->addTag('projectId', $project->getId()); $log->addTag('hostname', $request->getHostname()); $log->addTag('locale', (string)$request->getParam('locale', $request->getHeader('x-appwrite-locale', ''))); diff --git a/app/realtime.php b/app/realtime.php index a8a033b00..c9b162615 100644 --- a/app/realtime.php +++ b/app/realtime.php @@ -66,7 +66,7 @@ $logError = function(Throwable $error, string $action) use ($register) { $log->setMessage($error->getMessage()); $log->addTag('code', $error->getCode()); - $log->addTag('verbose_type', get_class($error)); + $log->addTag('verboseType', get_class($error)); $log->addExtra('file', $error->getFile()); $log->addExtra('line', $error->getLine()); diff --git a/src/Appwrite/Resque/Worker.php b/src/Appwrite/Resque/Worker.php index b6cb86851..2e598cd26 100644 --- a/src/Appwrite/Resque/Worker.php +++ b/src/Appwrite/Resque/Worker.php @@ -138,9 +138,9 @@ abstract class Worker //$log->setType(Log::TYPE_ERROR); //$log->setMessage($error->getMessage()); // - //$log->addTag('worker_type', $workerType); + //$log->addTag('workerType', $workerType); //$log->addTag('code', $error->getCode()); - //$log->addTag('verbose_type', \get_class($error)); + //$log->addTag('verboseType', \get_class($error)); // //$log->addExtra('file', $error->getFile()); //$log->addExtra('line', $error->getLine()); From 67c15e9346e23c99b83fddb0c6aec6b05284b816 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Matej=20Ba=C4=8Do?= Date: Sun, 5 Dec 2021 12:08:08 +0100 Subject: [PATCH 12/28] Update src/Appwrite/Resque/Worker.php Co-authored-by: Christy Jacob --- src/Appwrite/Resque/Worker.php | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/Appwrite/Resque/Worker.php b/src/Appwrite/Resque/Worker.php index 2e598cd26..d2979fd25 100644 --- a/src/Appwrite/Resque/Worker.php +++ b/src/Appwrite/Resque/Worker.php @@ -12,7 +12,7 @@ abstract class Worker protected $errorCallbacks = []; /** - * Named array holding all information passed into worker alongside a new task. + * Associative array holding all information passed into the worker * * @return array */ From c6c555b76345daed178ff36556b872610de66149 Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Sun, 5 Dec 2021 14:07:45 +0100 Subject: [PATCH 13/28] Implemented worker error logging in a better way --- app/controllers/general.php | 1 + app/workers.php | 43 +++++++++++ composer.lock | 135 +++++++++++++++++---------------- docker-compose.yml | 3 +- src/Appwrite/Resque/Worker.php | 64 +++++----------- 5 files changed, 137 insertions(+), 109 deletions(-) diff --git a/app/controllers/general.php b/app/controllers/general.php index e70a80058..58331c3af 100644 --- a/app/controllers/general.php +++ b/app/controllers/general.php @@ -300,6 +300,7 @@ App::error(function ($error, $utopia, $request, $response, $layout, $project, $l /** @var Appwrite\Database\Document $project */ /** @var Utopia\Logger\Logger $logger */ /** @var Appwrite\Database\Document $user */ + /** @var Utopia\Logger\Log\Breadcrumb[] $loggerBreadcrumbs */ $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); $route = $utopia->match($request); diff --git a/app/workers.php b/app/workers.php index ff5ba1dbd..bfd03a6a6 100644 --- a/app/workers.php +++ b/app/workers.php @@ -2,6 +2,7 @@ use Appwrite\Extend\PDO; use Utopia\App; +use Appwrite\Resque\Worker; /** @var Utopia\Registry\Registry $register */ @@ -23,10 +24,52 @@ $register->set('db', function () { return $pdo; }); + $register->set('cache', function () { // Register cache connection $redis = new Redis(); $redis->pconnect(App::getEnv('_APP_REDIS_HOST', ''), App::getEnv('_APP_REDIS_PORT', '')); $redis->setOption(Redis::OPT_READ_TIMEOUT, -1); return $redis; +}); + +Worker::error(function ($error, $action) use ($register) { + /** @var Throwable|Exception $error */ + /** @var string $action */ + + $logger = $register->get('logger'); + + if($logger) { + $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); + + $className = \get_called_class(); + $workerType = $className; + + $log = new Log(); + + $log->setNamespace("worker-" . $workerType); + $log->setServer(\gethostname()); + $log->setVersion($version); + $log->setType(Log::TYPE_ERROR); + $log->setMessage($error->getMessage()); + + $log->addTag('workerType', $workerType); + $log->addTag('code', $error->getCode()); + $log->addTag('verboseType', \get_class($error)); + + $log->addExtra('file', $error->getFile()); + $log->addExtra('line', $error->getLine()); + $log->addExtra('trace', $error->getTraceAsString()); + // $log->addExtra('args', $this->args); + // TODO: Test worker error for get_called_class and if args are in trace. What about JWT in args? Other secrets? What about realtime/API? + + $action = 'worker.' . $workerType . '.' . $action; + $log->setAction($action); + + $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; + $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); + + $responseCode = $logger->addLog($log); + Console::info('Setup log pushed with status code: ' . $responseCode); + } }); \ No newline at end of file diff --git a/composer.lock b/composer.lock index 39abde66d..d4677b5da 100644 --- a/composer.lock +++ b/composer.lock @@ -2066,7 +2066,7 @@ "source": { "type": "git", "url": "https://github.com/utopia-php/logger", - "reference": "572ada8fd774cb8c6c09aab9fe2d36cd807eee13" + "reference": "c50b16a864857cfad381917b2e6f4991f1bccc3e" }, "require": { "php": ">=7.4" @@ -2113,7 +2113,7 @@ "utopia", "warnings" ], - "time": "2021-11-29T08:40:52+00:00" + "time": "2021-11-29T11:40:17+00:00" }, { "name": "utopia-php/orchestration", @@ -3438,16 +3438,16 @@ }, { "name": "nikic/php-parser", - "version": "v4.13.1", + "version": "v4.13.2", "source": { "type": "git", "url": "https://github.com/nikic/PHP-Parser.git", - "reference": "63a79e8daa781cac14e5195e63ed8ae231dd10fd" + "reference": "210577fe3cf7badcc5814d99455df46564f3c077" }, "dist": { "type": "zip", - "url": "https://api.github.com/repos/nikic/PHP-Parser/zipball/63a79e8daa781cac14e5195e63ed8ae231dd10fd", - "reference": "63a79e8daa781cac14e5195e63ed8ae231dd10fd", + "url": "https://api.github.com/repos/nikic/PHP-Parser/zipball/210577fe3cf7badcc5814d99455df46564f3c077", + "reference": "210577fe3cf7badcc5814d99455df46564f3c077", "shasum": "" }, "require": { @@ -3488,9 +3488,9 @@ ], "support": { "issues": "https://github.com/nikic/PHP-Parser/issues", - "source": "https://github.com/nikic/PHP-Parser/tree/v4.13.1" + "source": "https://github.com/nikic/PHP-Parser/tree/v4.13.2" }, - "time": "2021-11-03T20:52:16+00:00" + "time": "2021-11-30T19:35:32+00:00" }, { "name": "openlss/lib-array2xml", @@ -3885,16 +3885,16 @@ }, { "name": "phpunit/php-code-coverage", - "version": "9.2.9", + "version": "9.2.10", "source": { "type": "git", "url": "https://github.com/sebastianbergmann/php-code-coverage.git", - "reference": "f301eb1453c9e7a1bc912ee8b0ea9db22c60223b" + "reference": "d5850aaf931743067f4bfc1ae4cbd06468400687" }, "dist": { "type": "zip", - "url": "https://api.github.com/repos/sebastianbergmann/php-code-coverage/zipball/f301eb1453c9e7a1bc912ee8b0ea9db22c60223b", - "reference": "f301eb1453c9e7a1bc912ee8b0ea9db22c60223b", + "url": "https://api.github.com/repos/sebastianbergmann/php-code-coverage/zipball/d5850aaf931743067f4bfc1ae4cbd06468400687", + "reference": "d5850aaf931743067f4bfc1ae4cbd06468400687", "shasum": "" }, "require": { @@ -3950,7 +3950,7 @@ ], "support": { "issues": "https://github.com/sebastianbergmann/php-code-coverage/issues", - "source": "https://github.com/sebastianbergmann/php-code-coverage/tree/9.2.9" + "source": "https://github.com/sebastianbergmann/php-code-coverage/tree/9.2.10" }, "funding": [ { @@ -3958,20 +3958,20 @@ "type": "github" } ], - "time": "2021-11-19T15:21:02+00:00" + "time": "2021-12-05T09:12:13+00:00" }, { "name": "phpunit/php-file-iterator", - "version": "3.0.5", + "version": "3.0.6", "source": { "type": "git", "url": "https://github.com/sebastianbergmann/php-file-iterator.git", - "reference": "aa4be8575f26070b100fccb67faabb28f21f66f8" + "reference": "cf1c2e7c203ac650e352f4cc675a7021e7d1b3cf" }, "dist": { "type": "zip", - "url": "https://api.github.com/repos/sebastianbergmann/php-file-iterator/zipball/aa4be8575f26070b100fccb67faabb28f21f66f8", - "reference": "aa4be8575f26070b100fccb67faabb28f21f66f8", + "url": "https://api.github.com/repos/sebastianbergmann/php-file-iterator/zipball/cf1c2e7c203ac650e352f4cc675a7021e7d1b3cf", + "reference": "cf1c2e7c203ac650e352f4cc675a7021e7d1b3cf", "shasum": "" }, "require": { @@ -4010,7 +4010,7 @@ ], "support": { "issues": "https://github.com/sebastianbergmann/php-file-iterator/issues", - "source": "https://github.com/sebastianbergmann/php-file-iterator/tree/3.0.5" + "source": "https://github.com/sebastianbergmann/php-file-iterator/tree/3.0.6" }, "funding": [ { @@ -4018,7 +4018,7 @@ "type": "github" } ], - "time": "2020-09-28T05:57:25+00:00" + "time": "2021-12-02T12:48:52+00:00" }, { "name": "phpunit/php-invoker", @@ -4306,22 +4306,27 @@ }, { "name": "psr/container", - "version": "1.1.2", + "version": "2.0.2", "source": { "type": "git", "url": "https://github.com/php-fig/container.git", - "reference": "513e0666f7216c7459170d56df27dfcefe1689ea" + "reference": "c71ecc56dfe541dbd90c5360474fbc405f8d5963" }, "dist": { "type": "zip", - "url": "https://api.github.com/repos/php-fig/container/zipball/513e0666f7216c7459170d56df27dfcefe1689ea", - "reference": "513e0666f7216c7459170d56df27dfcefe1689ea", + "url": "https://api.github.com/repos/php-fig/container/zipball/c71ecc56dfe541dbd90c5360474fbc405f8d5963", + "reference": "c71ecc56dfe541dbd90c5360474fbc405f8d5963", "shasum": "" }, "require": { "php": ">=7.4.0" }, "type": "library", + "extra": { + "branch-alias": { + "dev-master": "2.0.x-dev" + } + }, "autoload": { "psr-4": { "Psr\\Container\\": "src/" @@ -4348,9 +4353,9 @@ ], "support": { "issues": "https://github.com/php-fig/container/issues", - "source": "https://github.com/php-fig/container/tree/1.1.2" + "source": "https://github.com/php-fig/container/tree/2.0.2" }, - "time": "2021-11-05T16:50:12+00:00" + "time": "2021-11-05T16:47:00+00:00" }, { "name": "sebastian/cli-parser", @@ -5370,28 +5375,29 @@ }, { "name": "symfony/console", - "version": "v5.3.11", + "version": "v5.4.0", "source": { "type": "git", "url": "https://github.com/symfony/console.git", - "reference": "3e7ab8f5905058984899b05a4648096f558bfeba" + "reference": "ec3661faca1d110d6c307e124b44f99ac54179e3" }, "dist": { "type": "zip", - "url": "https://api.github.com/repos/symfony/console/zipball/3e7ab8f5905058984899b05a4648096f558bfeba", - "reference": "3e7ab8f5905058984899b05a4648096f558bfeba", + "url": "https://api.github.com/repos/symfony/console/zipball/ec3661faca1d110d6c307e124b44f99ac54179e3", + "reference": "ec3661faca1d110d6c307e124b44f99ac54179e3", "shasum": "" }, "require": { "php": ">=7.2.5", - "symfony/deprecation-contracts": "^2.1", + "symfony/deprecation-contracts": "^2.1|^3", "symfony/polyfill-mbstring": "~1.0", "symfony/polyfill-php73": "^1.8", "symfony/polyfill-php80": "^1.16", - "symfony/service-contracts": "^1.1|^2", - "symfony/string": "^5.1" + "symfony/service-contracts": "^1.1|^2|^3", + "symfony/string": "^5.1|^6.0" }, "conflict": { + "psr/log": ">=3", "symfony/dependency-injection": "<4.4", "symfony/dotenv": "<5.1", "symfony/event-dispatcher": "<4.4", @@ -5403,12 +5409,12 @@ }, "require-dev": { "psr/log": "^1|^2", - "symfony/config": "^4.4|^5.0", - "symfony/dependency-injection": "^4.4|^5.0", - "symfony/event-dispatcher": "^4.4|^5.0", - "symfony/lock": "^4.4|^5.0", - "symfony/process": "^4.4|^5.0", - "symfony/var-dumper": "^4.4|^5.0" + "symfony/config": "^4.4|^5.0|^6.0", + "symfony/dependency-injection": "^4.4|^5.0|^6.0", + "symfony/event-dispatcher": "^4.4|^5.0|^6.0", + "symfony/lock": "^4.4|^5.0|^6.0", + "symfony/process": "^4.4|^5.0|^6.0", + "symfony/var-dumper": "^4.4|^5.0|^6.0" }, "suggest": { "psr/log": "For using the console logger", @@ -5448,7 +5454,7 @@ "terminal" ], "support": { - "source": "https://github.com/symfony/console/tree/v5.3.11" + "source": "https://github.com/symfony/console/tree/v5.4.0" }, "funding": [ { @@ -5464,7 +5470,7 @@ "type": "tidelift" } ], - "time": "2021-11-21T19:41:05+00:00" + "time": "2021-11-29T15:30:56+00:00" }, { "name": "symfony/polyfill-intl-grapheme", @@ -5875,22 +5881,21 @@ }, { "name": "symfony/service-contracts", - "version": "v2.5.0", + "version": "v3.0.0", "source": { "type": "git", "url": "https://github.com/symfony/service-contracts.git", - "reference": "1ab11b933cd6bc5464b08e81e2c5b07dec58b0fc" + "reference": "36715ebf9fb9db73db0cb24263c79077c6fe8603" }, "dist": { "type": "zip", - "url": "https://api.github.com/repos/symfony/service-contracts/zipball/1ab11b933cd6bc5464b08e81e2c5b07dec58b0fc", - "reference": "1ab11b933cd6bc5464b08e81e2c5b07dec58b0fc", + "url": "https://api.github.com/repos/symfony/service-contracts/zipball/36715ebf9fb9db73db0cb24263c79077c6fe8603", + "reference": "36715ebf9fb9db73db0cb24263c79077c6fe8603", "shasum": "" }, "require": { - "php": ">=7.2.5", - "psr/container": "^1.1", - "symfony/deprecation-contracts": "^2.1" + "php": ">=8.0.2", + "psr/container": "^2.0" }, "conflict": { "ext-psr": "<1.1|>=2" @@ -5901,7 +5906,7 @@ "type": "library", "extra": { "branch-alias": { - "dev-main": "2.5-dev" + "dev-main": "3.0-dev" }, "thanks": { "name": "symfony/contracts", @@ -5938,7 +5943,7 @@ "standards" ], "support": { - "source": "https://github.com/symfony/service-contracts/tree/v2.5.0" + "source": "https://github.com/symfony/service-contracts/tree/v3.0.0" }, "funding": [ { @@ -5954,35 +5959,37 @@ "type": "tidelift" } ], - "time": "2021-11-04T16:48:04+00:00" + "time": "2021-11-04T17:53:12+00:00" }, { "name": "symfony/string", - "version": "v5.3.10", + "version": "v6.0.0", "source": { "type": "git", "url": "https://github.com/symfony/string.git", - "reference": "d70c35bb20bbca71fc4ab7921e3c6bda1a82a60c" + "reference": "ba727797426af0f587f4800566300bdc0cda0777" }, "dist": { "type": "zip", - "url": "https://api.github.com/repos/symfony/string/zipball/d70c35bb20bbca71fc4ab7921e3c6bda1a82a60c", - "reference": "d70c35bb20bbca71fc4ab7921e3c6bda1a82a60c", + "url": "https://api.github.com/repos/symfony/string/zipball/ba727797426af0f587f4800566300bdc0cda0777", + "reference": "ba727797426af0f587f4800566300bdc0cda0777", "shasum": "" }, "require": { - "php": ">=7.2.5", + "php": ">=8.0.2", "symfony/polyfill-ctype": "~1.8", "symfony/polyfill-intl-grapheme": "~1.0", "symfony/polyfill-intl-normalizer": "~1.0", - "symfony/polyfill-mbstring": "~1.0", - "symfony/polyfill-php80": "~1.15" + "symfony/polyfill-mbstring": "~1.0" + }, + "conflict": { + "symfony/translation-contracts": "<2.0" }, "require-dev": { - "symfony/error-handler": "^4.4|^5.0", - "symfony/http-client": "^4.4|^5.0", - "symfony/translation-contracts": "^1.1|^2", - "symfony/var-exporter": "^4.4|^5.0" + "symfony/error-handler": "^5.4|^6.0", + "symfony/http-client": "^5.4|^6.0", + "symfony/translation-contracts": "^2.0|^3.0", + "symfony/var-exporter": "^5.4|^6.0" }, "type": "library", "autoload": { @@ -6021,7 +6028,7 @@ "utf8" ], "support": { - "source": "https://github.com/symfony/string/tree/v5.3.10" + "source": "https://github.com/symfony/string/tree/v6.0.0" }, "funding": [ { @@ -6037,7 +6044,7 @@ "type": "tidelift" } ], - "time": "2021-10-27T18:21:46+00:00" + "time": "2021-10-29T07:35:21+00:00" }, { "name": "textalk/websocket", diff --git a/docker-compose.yml b/docker-compose.yml index f01d6c0b1..d6aba1a22 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -71,7 +71,7 @@ services: - ./psalm.xml:/usr/src/code/psalm.xml - ./tests:/usr/src/code/tests - ./app:/usr/src/code/app - # - ./vendor:/usr/src/code/vendor + - ./vendor:/usr/src/code/vendor - ./docs:/usr/src/code/docs - ./public:/usr/src/code/public - ./src:/usr/src/code/src @@ -160,6 +160,7 @@ services: volumes: - ./app:/usr/src/code/app - ./src:/usr/src/code/src + - ./vendor:/usr/src/code/vendor depends_on: - redis environment: diff --git a/src/Appwrite/Resque/Worker.php b/src/Appwrite/Resque/Worker.php index d2979fd25..b9972ed24 100644 --- a/src/Appwrite/Resque/Worker.php +++ b/src/Appwrite/Resque/Worker.php @@ -2,14 +2,16 @@ namespace Appwrite\Resque; -abstract class Worker +use Exception; + +class Worker { /** * Callbacks that will be executed when an error occurs * * @var array */ - protected $errorCallbacks = []; + static protected array $errorCallbacks = []; /** * Associative array holding all information passed into the worker @@ -22,8 +24,12 @@ abstract class Worker * Function for identifying the worker needs to be set to unique name * * @return string + * @throws Exception */ - abstract public function getName(): string; + public function getName(): string + { + throw new Exception("Please implement getName method in worker"); + } /** * Function executed before running first task. @@ -32,7 +38,9 @@ abstract class Worker * @return void * @throws \Exception|\Throwable */ - abstract public function init(): void; + public function init() { + throw new Exception("Please implement getName method in worker"); + } /** * Function executed when new task requests is received. @@ -41,7 +49,9 @@ abstract class Worker * @return void * @throws \Exception|\Throwable */ - abstract public function run(): void; + public function run() { + throw new Exception("Please implement getName method in worker"); + } /** * Function executed just before shutting down the worker. @@ -50,7 +60,9 @@ abstract class Worker * @return void * @throws \Exception|\Throwable */ - abstract public function shutdown(): void; + public function shutdown() { + throw new Exception("Please implement getName method in worker"); + } /** * A wrapper around 'init' function with non-worker-specific code @@ -116,44 +128,8 @@ abstract class Worker * @param Throwable $error * @return self */ - public function error(callable $callback): self + public static function error(callable $callback): void { - \array_push($this->errorCallbacks, $callback); - return $this; + \array_push(self::$errorCallbacks, $callback); } - - // TODO: Implement this on init file using Worker->error(function() { HERE }) - //global $register; - //$logger = $register->get('logger'); - // - //if($logger) { - //$version = App::getEnv('_APP_VERSION', 'UNKNOWN'); - //$workerType = $this->getName(); - // - //$log = new Log(); - // - //$log->setNamespace("worker-" . $workerType); - //$log->setServer(\gethostname()); - //$log->setVersion($version); - //$log->setType(Log::TYPE_ERROR); - //$log->setMessage($error->getMessage()); - // - //$log->addTag('workerType', $workerType); - //$log->addTag('code', $error->getCode()); - //$log->addTag('verboseType', \get_class($error)); - // - //$log->addExtra('file', $error->getFile()); - //$log->addExtra('line', $error->getLine()); - //$log->addExtra('trace', $error->getTraceAsString()); - //$log->addExtra('args', $this->args); - // - //$action = 'worker.' . $workerType . '.setUp'; - //$log->setAction($action); - // - //$isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; - //$log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); - // - //$responseCode = $logger->addLog($log); - //Console::info('Setup log pushed with status code: '.$responseCode); - //} } From 4d8c2e3cdbaa27bf56acc0e593ed4cc522610370 Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Mon, 6 Dec 2021 13:55:59 +0100 Subject: [PATCH 14/28] Fixed worker logger --- app/workers.php | 14 ++++++++------ composer.lock | 6 +++--- src/Appwrite/Resque/Worker.php | 13 +++++++------ 3 files changed, 18 insertions(+), 15 deletions(-) diff --git a/app/workers.php b/app/workers.php index bfd03a6a6..9822834f8 100644 --- a/app/workers.php +++ b/app/workers.php @@ -2,6 +2,8 @@ use Appwrite\Extend\PDO; use Utopia\App; +use Utopia\CLI\Console; +use Utopia\Logger\Log; use Appwrite\Resque\Worker; /** @var Utopia\Registry\Registry $register */ @@ -33,18 +35,16 @@ $register->set('cache', function () { // Register cache connection return $redis; }); -Worker::error(function ($error, $action) use ($register) { +Worker::error(function ($error, $action, $workerType, $optionalExtras) use ($register) { /** @var Throwable|Exception $error */ /** @var string $action */ + /** @var string $workerType */ $logger = $register->get('logger'); if($logger) { $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); - $className = \get_called_class(); - $workerType = $className; - $log = new Log(); $log->setNamespace("worker-" . $workerType); @@ -60,8 +60,10 @@ Worker::error(function ($error, $action) use ($register) { $log->addExtra('file', $error->getFile()); $log->addExtra('line', $error->getLine()); $log->addExtra('trace', $error->getTraceAsString()); - // $log->addExtra('args', $this->args); - // TODO: Test worker error for get_called_class and if args are in trace. What about JWT in args? Other secrets? What about realtime/API? + + if($optionalExtras) { + $log->addExtra('args', $optionalExtras); + } $action = 'worker.' . $workerType . '.' . $action; $log->setAction($action); diff --git a/composer.lock b/composer.lock index d4677b5da..97d132ef7 100644 --- a/composer.lock +++ b/composer.lock @@ -2066,10 +2066,10 @@ "source": { "type": "git", "url": "https://github.com/utopia-php/logger", - "reference": "c50b16a864857cfad381917b2e6f4991f1bccc3e" + "reference": "e67eafc1edb8729c463275b81ff4e870eb30c314" }, "require": { - "php": ">=7.4" + "php": ">=8.0" }, "require-dev": { "phpunit/phpunit": "^9.3", @@ -2113,7 +2113,7 @@ "utopia", "warnings" ], - "time": "2021-11-29T11:40:17+00:00" + "time": "2021-12-06T11:18:07+00:00" }, { "name": "utopia-php/orchestration", diff --git a/src/Appwrite/Resque/Worker.php b/src/Appwrite/Resque/Worker.php index b9972ed24..49928479e 100644 --- a/src/Appwrite/Resque/Worker.php +++ b/src/Appwrite/Resque/Worker.php @@ -3,6 +3,7 @@ namespace Appwrite\Resque; use Exception; +use function var_dump; class Worker { @@ -75,8 +76,8 @@ class Worker try { $this->init(); } catch(\Throwable $error) { - foreach ($this->errorCallbacks as $errorCallback) { - $errorCallback($error, "init"); + foreach (self::$errorCallbacks as $errorCallback) { + $errorCallback($error, "init", $this->getName()); } throw $error; @@ -94,8 +95,8 @@ class Worker try { $this->run(); } catch(\Throwable $error) { - foreach ($this->errorCallbacks as $errorCallback) { - $errorCallback($error, "run"); + foreach (self::$errorCallbacks as $errorCallback) { + $errorCallback($error, "run", $this->getName(), $this->args); } throw $error; @@ -113,8 +114,8 @@ class Worker try { $this->shutdown(); } catch(\Throwable $error) { - foreach ($this->errorCallbacks as $errorCallback) { - $errorCallback($error, "shutdown"); + foreach (self::$errorCallbacks as $errorCallback) { + $errorCallback($error, "shutdown", $this->getName()); } throw $error; From 243dfbb9ca9ef9ef948543ffec93fc2e19af5661 Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Mon, 6 Dec 2021 14:14:55 +0100 Subject: [PATCH 15/28] PR review bug fix --- app/controllers/general.php | 75 +++++++++++++++++++------------------ app/init.php | 2 +- app/workers.php | 64 ++++++++++++++++--------------- 3 files changed, 72 insertions(+), 69 deletions(-) diff --git a/app/controllers/general.php b/app/controllers/general.php index 58331c3af..a0324ec04 100644 --- a/app/controllers/general.php +++ b/app/controllers/general.php @@ -305,47 +305,48 @@ App::error(function ($error, $utopia, $request, $response, $layout, $project, $l $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); $route = $utopia->match($request); - if($error->getCode() >= 500 || $error->getCode() === 0 && !$logger) { - $log = new Utopia\Logger\Log(); + if($logger) { + if($error->getCode() >= 500 || $error->getCode() === 0) { + $log = new Utopia\Logger\Log(); - if(!$user->isEmpty()) { - $log->setUser(new User($user->getId())); + if(!$user->isEmpty()) { + $log->setUser(new User($user->getId())); + } + + $log->setNamespace("http"); + $log->setServer(\gethostname()); + $log->setVersion($version); + $log->setType(Log::TYPE_ERROR); + $log->setMessage($error->getMessage()); + + $log->addTag('method', $route->getMethod()); + $log->addTag('url', $route->getPath()); + $log->addTag('verboseType', get_class($error)); + $log->addTag('code', $error->getCode()); + $log->addTag('projectId', $project->getId()); + $log->addTag('hostname', $request->getHostname()); + $log->addTag('locale', (string)$request->getParam('locale', $request->getHeader('x-appwrite-locale', ''))); + + $log->addExtra('file', $error->getFile()); + $log->addExtra('line', $error->getLine()); + $log->addExtra('trace', $error->getTraceAsString()); + $log->addExtra('roles', Authorization::$roles); + + $action = $route->getLabel("sdk.namespace", "UNKNOWN_NAMESPACE") . '.' . $route->getLabel("sdk.method", "UNKNOWN_METHOD"); + $log->setAction($action); + + $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; + $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); + + foreach($loggerBreadcrumbs as $loggerBreadcrumb) { + $log->addBreadcrumb($loggerBreadcrumb); + } + + $responseCode = $logger->addLog($log); + Console::info('Log pushed with status code: '.$responseCode); } - - $log->setNamespace("http"); - $log->setServer(\gethostname()); - $log->setVersion($version); - $log->setType(Log::TYPE_ERROR); - $log->setMessage($error->getMessage()); - - $log->addTag('method', $route->getMethod()); - $log->addTag('url', $route->getPath()); - $log->addTag('verboseType', get_class($error)); - $log->addTag('code', $error->getCode()); - $log->addTag('projectId', $project->getId()); - $log->addTag('hostname', $request->getHostname()); - $log->addTag('locale', (string)$request->getParam('locale', $request->getHeader('x-appwrite-locale', ''))); - - $log->addExtra('file', $error->getFile()); - $log->addExtra('line', $error->getLine()); - $log->addExtra('trace', $error->getTraceAsString()); - $log->addExtra('roles', Authorization::$roles); - - $action = $route->getLabel("sdk.namespace", "UNKNOWN_NAMESPACE") . '.' . $route->getLabel("sdk.method", "UNKNOWN_METHOD"); - $log->setAction($action); - - $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; - $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); - - foreach($loggerBreadcrumbs as $loggerBreadcrumb) { - $log->addBreadcrumb($loggerBreadcrumb); - } - - $responseCode = $logger->addLog($log); - Console::info('Log pushed with status code: '.$responseCode); } - if ($error instanceof PDOException) { throw $error; } diff --git a/app/init.php b/app/init.php index 0f3abe5fa..c2f43f325 100644 --- a/app/init.php +++ b/app/init.php @@ -169,7 +169,7 @@ $register->set('logger', function () { // Register error logger $providerConfig = App::getEnv('_APP_LOGGING_CONFIG', ''); if(empty($providerName) || empty($providerConfig)) { - return; + return null; } if(!Logger::hasProvider($providerName)) { diff --git a/app/workers.php b/app/workers.php index 9822834f8..4cb3af5f5 100644 --- a/app/workers.php +++ b/app/workers.php @@ -42,36 +42,38 @@ Worker::error(function ($error, $action, $workerType, $optionalExtras) use ($reg $logger = $register->get('logger'); - if($logger) { - $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); - - $log = new Log(); - - $log->setNamespace("worker-" . $workerType); - $log->setServer(\gethostname()); - $log->setVersion($version); - $log->setType(Log::TYPE_ERROR); - $log->setMessage($error->getMessage()); - - $log->addTag('workerType', $workerType); - $log->addTag('code', $error->getCode()); - $log->addTag('verboseType', \get_class($error)); - - $log->addExtra('file', $error->getFile()); - $log->addExtra('line', $error->getLine()); - $log->addExtra('trace', $error->getTraceAsString()); - - if($optionalExtras) { - $log->addExtra('args', $optionalExtras); - } - - $action = 'worker.' . $workerType . '.' . $action; - $log->setAction($action); - - $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; - $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); - - $responseCode = $logger->addLog($log); - Console::info('Setup log pushed with status code: ' . $responseCode); + if(!$logger) { + return; } + + $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); + + $log = new Log(); + + $log->setNamespace("worker-" . $workerType); + $log->setServer(\gethostname()); + $log->setVersion($version); + $log->setType(Log::TYPE_ERROR); + $log->setMessage($error->getMessage()); + + $log->addTag('workerType', $workerType); + $log->addTag('code', $error->getCode()); + $log->addTag('verboseType', \get_class($error)); + + $log->addExtra('file', $error->getFile()); + $log->addExtra('line', $error->getLine()); + $log->addExtra('trace', $error->getTraceAsString()); + + if($optionalExtras) { + $log->addExtra('args', $optionalExtras); + } + + $action = 'worker.' . $workerType . '.' . $action; + $log->setAction($action); + + $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; + $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); + + $responseCode = $logger->addLog($log); + Console::info('Setup log pushed with status code: ' . $responseCode); }); \ No newline at end of file From 399cd9e38e9b6d4bfa31c3d5d2ad480decedec0d Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Mon, 20 Dec 2021 16:26:58 +0100 Subject: [PATCH 16/28] Updated dependencies after logger library release --- composer.json | 8 +---- composer.lock | 84 ++++++++++++++++++++++++++++++++++++++++++++++----- 2 files changed, 77 insertions(+), 15 deletions(-) diff --git a/composer.json b/composer.json index 5c436e286..f3bb0a352 100644 --- a/composer.json +++ b/composer.json @@ -20,12 +20,6 @@ "Appwrite\\Tests\\": "tests/extensions" } }, - "repositories": [ - { - "type": "git", - "url": "https://github.com/utopia-php/logger" - } - ], "require": { "php": ">=8.0.0", "ext-curl": "*", @@ -45,7 +39,7 @@ "appwrite/php-runtimes": "0.6.*", "utopia-php/framework": "0.18.*", - "utopia-php/logger": "dev-dev", + "utopia-php/logger": "0.1.*", "utopia-php/abuse": "0.5.*", "utopia-php/analytics": "0.2.*", "utopia-php/audit": "0.5.*", diff --git a/composer.lock b/composer.lock index 3336f09ef..fb518e0b3 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": "c118448e0047bca33e037cb54fa4b3a0", + "content-hash": "269b7f80dd8bd8f7fd0e78432da13b12", "packages": [ { "name": "adhocore/jwt", @@ -2060,6 +2060,72 @@ }, "time": "2021-07-24T11:35:55+00:00" }, + { + "name": "utopia-php/logger", + "version": "0.1.0", + "source": { + "type": "git", + "url": "https://github.com/utopia-php/logger.git", + "reference": "a7d626e349e8736e46d4d75f5ba686b40e73c097" + }, + "dist": { + "type": "zip", + "url": "https://api.github.com/repos/utopia-php/logger/zipball/a7d626e349e8736e46d4d75f5ba686b40e73c097", + "reference": "a7d626e349e8736e46d4d75f5ba686b40e73c097", + "shasum": "" + }, + "require": { + "php": ">=8.0" + }, + "require-dev": { + "phpunit/phpunit": "^9.3", + "vimeo/psalm": "4.0.1" + }, + "type": "library", + "autoload": { + "psr-4": { + "Utopia\\Logger\\": "src/Logger" + } + }, + "notification-url": "https://packagist.org/downloads/", + "license": [ + "MIT" + ], + "authors": [ + { + "name": "Eldad Fux", + "email": "eldad@appwrite.io" + }, + { + "name": "Matej Bačo", + "email": "matej@appwrite.io" + }, + { + "name": "Christy Jacob", + "email": "christy@appwrite.io" + } + ], + "description": "Utopia Logger library is simple and lite library for logging information, such as errors or warnings. This library is aiming to be as simple and easy to learn and use.", + "keywords": [ + "appsignal", + "errors", + "framework", + "logger", + "logging", + "logs", + "php", + "raygun", + "sentry", + "upf", + "utopia", + "warnings" + ], + "support": { + "issues": "https://github.com/utopia-php/logger/issues", + "source": "https://github.com/utopia-php/logger/tree/0.1.0" + }, + "time": "2021-12-20T06:57:26+00:00" + }, { "name": "utopia-php/orchestration", "version": "0.2.1", @@ -2385,16 +2451,16 @@ }, { "name": "utopia-php/websocket", - "version": "0.0.1", + "version": "dev-feat-onerror-callback", "source": { "type": "git", "url": "https://github.com/utopia-php/websocket.git", - "reference": "808317ef4ea0683c2c82dee5d543b1c8378e2e1b" + "reference": "237eed7e9c54a514cfabac3e5726d24661254f2e" }, "dist": { "type": "zip", - "url": "https://api.github.com/repos/utopia-php/websocket/zipball/808317ef4ea0683c2c82dee5d543b1c8378e2e1b", - "reference": "808317ef4ea0683c2c82dee5d543b1c8378e2e1b", + "url": "https://api.github.com/repos/utopia-php/websocket/zipball/237eed7e9c54a514cfabac3e5726d24661254f2e", + "reference": "237eed7e9c54a514cfabac3e5726d24661254f2e", "shasum": "" }, "require": { @@ -2437,9 +2503,9 @@ ], "support": { "issues": "https://github.com/utopia-php/websocket/issues", - "source": "https://github.com/utopia-php/websocket/tree/0.0.1" + "source": "https://github.com/utopia-php/websocket/tree/feat-onerror-callback" }, - "time": "2021-07-11T13:09:44+00:00" + "time": "2021-11-29T08:43:24+00:00" }, { "name": "webmozart/assert", @@ -6401,7 +6467,9 @@ ], "aliases": [], "minimum-stability": "stable", - "stability-flags": [], + "stability-flags": { + "utopia-php/websocket": 20 + }, "prefer-stable": false, "prefer-lowest": false, "platform": { From cba3618c3533ebd72ff56be27788c4c4b1a61163 Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Tue, 21 Dec 2021 10:29:09 +0100 Subject: [PATCH 17/28] Tests fix --- app/http.php | 5 +++++ app/realtime.php | 14 +++++++------- composer.json | 2 +- composer.lock | 18 ++++++++---------- src/Appwrite/Resque/Worker.php | 1 - 5 files changed, 21 insertions(+), 19 deletions(-) diff --git a/app/http.php b/app/http.php index 9a3a5459d..51ad499d6 100644 --- a/app/http.php +++ b/app/http.php @@ -10,6 +10,8 @@ use Swoole\Http\Request as SwooleRequest; use Swoole\Http\Response as SwooleResponse; use Utopia\App; use Utopia\CLI\Console; +use Utopia\Logger\Log; +use Utopia\Logger\Log\User; use Utopia\Swoole\Files; use Utopia\Swoole\Request; @@ -99,6 +101,9 @@ $http->on('request', function (SwooleRequest $swooleRequest, SwooleResponse $swo Console::error('[Error] File: '.$th->getFile()); Console::error('[Error] Line: '.$th->getLine()); + $code = $th->getCode(); + $swooleResponse->setStatusCode($code); + /** * Reset Database connection if PDOException was thrown. */ diff --git a/app/realtime.php b/app/realtime.php index 4bb1bc247..16d478a66 100644 --- a/app/realtime.php +++ b/app/realtime.php @@ -139,7 +139,7 @@ $server->onStart(function () use ($stats, $register, $containerId, &$documentId, /** * Save current connections to the Database every 5 seconds. */ - Timer::tick(5000, function () use ($stats, $getConsoleDb, $containerId, &$documentId, $register) { + Timer::tick(5000, function () use ($stats, $getConsoleDb, $containerId, &$documentId, $register, $logError) { foreach ($stats as $projectId => $value) { if (empty($value['connections']) && empty($value['messages'])) { continue; @@ -190,7 +190,7 @@ $server->onStart(function () use ($stats, $register, $containerId, &$documentId, 'value' => json_encode($payload) ]); } catch (\Throwable $th) { - logError($register, $th, "updateWorkerDocument"); + call_user_func($logError, $th, "updateWorkerDocument"); Console::error('[Error] Type: ' . get_class($th)); Console::error('[Error] Message: ' . $th->getMessage()); @@ -202,13 +202,13 @@ $server->onStart(function () use ($stats, $register, $containerId, &$documentId, }); }); -$server->onWorkerStart(function (int $workerId) use ($server, $register, $stats, $realtime) { +$server->onWorkerStart(function (int $workerId) use ($server, $register, $stats, $realtime, $logError) { Console::success('Worker ' . $workerId . ' started succefully'); $attempts = 0; $start = time(); - Timer::tick(5000, function () use ($server, $register, $realtime, $stats) { + Timer::tick(5000, function () use ($server, $register, $realtime, $stats, $logError) { /** * Sending current connections to project channels on the console project every 5 seconds. */ @@ -365,7 +365,7 @@ $server->onWorkerStart(function (int $workerId) use ($server, $register, $stats, } }); } catch (\Throwable $th) { - logError($register, $th, "pubSubConnection"); + call_user_func($logError, $th, "pubSubConnection"); Console::error('Pub/sub error: ' . $th->getMessage()); $register->get('redisPool')->put($redis); @@ -379,7 +379,7 @@ $server->onWorkerStart(function (int $workerId) use ($server, $register, $stats, Console::error('Failed to restart pub/sub...'); }); -$server->onOpen(function (int $connection, SwooleRequest $request) use ($server, $register, $stats, &$realtime) { +$server->onOpen(function (int $connection, SwooleRequest $request) use ($server, $register, $stats, &$realtime, $logError) { $app = new App('UTC'); $request = new Request($request); $response = new Response(new SwooleResponse()); @@ -483,7 +483,7 @@ $server->onOpen(function (int $connection, SwooleRequest $request) use ($server, $stats->incr($project->getId(), 'connections'); $stats->incr($project->getId(), 'connectionsTotal'); } catch (\Throwable $th) { - logError($register, $th, "initServer"); + call_user_func($logError, $th, "initServer"); $response = [ 'type' => 'error', diff --git a/composer.json b/composer.json index f3bb0a352..084d5e330 100644 --- a/composer.json +++ b/composer.json @@ -53,7 +53,7 @@ "utopia-php/domains": "1.1.*", "utopia-php/swoole": "0.2.*", "utopia-php/storage": "0.5.*", - "utopia-php/websocket": "dev-feat-onerror-callback", + "utopia-php/websocket": "0.1.0", "utopia-php/image": "0.5.*", "resque/php-resque": "1.3.6", "matomo/device-detector": "4.3.1", diff --git a/composer.lock b/composer.lock index fb518e0b3..92f414167 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": "269b7f80dd8bd8f7fd0e78432da13b12", + "content-hash": "1a20aaab4a5e2858c4088865be641035", "packages": [ { "name": "adhocore/jwt", @@ -2451,16 +2451,16 @@ }, { "name": "utopia-php/websocket", - "version": "dev-feat-onerror-callback", + "version": "0.1.0", "source": { "type": "git", "url": "https://github.com/utopia-php/websocket.git", - "reference": "237eed7e9c54a514cfabac3e5726d24661254f2e" + "reference": "51fcb86171400d8aa40d76c54593481fd273dab5" }, "dist": { "type": "zip", - "url": "https://api.github.com/repos/utopia-php/websocket/zipball/237eed7e9c54a514cfabac3e5726d24661254f2e", - "reference": "237eed7e9c54a514cfabac3e5726d24661254f2e", + "url": "https://api.github.com/repos/utopia-php/websocket/zipball/51fcb86171400d8aa40d76c54593481fd273dab5", + "reference": "51fcb86171400d8aa40d76c54593481fd273dab5", "shasum": "" }, "require": { @@ -2503,9 +2503,9 @@ ], "support": { "issues": "https://github.com/utopia-php/websocket/issues", - "source": "https://github.com/utopia-php/websocket/tree/feat-onerror-callback" + "source": "https://github.com/utopia-php/websocket/tree/0.1.0" }, - "time": "2021-11-29T08:43:24+00:00" + "time": "2021-12-20T10:50:09+00:00" }, { "name": "webmozart/assert", @@ -6467,9 +6467,7 @@ ], "aliases": [], "minimum-stability": "stable", - "stability-flags": { - "utopia-php/websocket": 20 - }, + "stability-flags": [], "prefer-stable": false, "prefer-lowest": false, "platform": { diff --git a/src/Appwrite/Resque/Worker.php b/src/Appwrite/Resque/Worker.php index 49928479e..1e251f763 100644 --- a/src/Appwrite/Resque/Worker.php +++ b/src/Appwrite/Resque/Worker.php @@ -3,7 +3,6 @@ namespace Appwrite\Resque; use Exception; -use function var_dump; class Worker { From 195e721fbb0f141a0659dbf0059fa7cb3a15a012 Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Tue, 21 Dec 2021 11:42:58 +0100 Subject: [PATCH 18/28] Removed debug code --- app/http.php | 3 --- 1 file changed, 3 deletions(-) diff --git a/app/http.php b/app/http.php index 51ad499d6..6a409657d 100644 --- a/app/http.php +++ b/app/http.php @@ -101,9 +101,6 @@ $http->on('request', function (SwooleRequest $swooleRequest, SwooleResponse $swo Console::error('[Error] File: '.$th->getFile()); Console::error('[Error] Line: '.$th->getLine()); - $code = $th->getCode(); - $swooleResponse->setStatusCode($code); - /** * Reset Database connection if PDOException was thrown. */ From c82549cdf46abf1ad0885f1048a20a8c58dcbe75 Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Tue, 21 Dec 2021 11:47:06 +0100 Subject: [PATCH 19/28] Applied changes from PR into db-indexing solving unexpected errors returning 200 codes --- app/http.php | 2 ++ 1 file changed, 2 insertions(+) diff --git a/app/http.php b/app/http.php index 6a409657d..297b1ead8 100644 --- a/app/http.php +++ b/app/http.php @@ -108,6 +108,8 @@ $http->on('request', function (SwooleRequest $swooleRequest, SwooleResponse $swo $db = null; } + $swooleResponse->setStatusCode(500); + if(App::isDevelopment()) { $swooleResponse->end('error: '.$th->getMessage()); } From 9c0c28c3f82b436cdbcbcfedc20c1479a229d9a9 Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Tue, 21 Dec 2021 14:57:43 +0100 Subject: [PATCH 20/28] Fixed failing tests due to dependency exception looping --- app/controllers/general.php | 14 +++++++++++--- 1 file changed, 11 insertions(+), 3 deletions(-) diff --git a/app/controllers/general.php b/app/controllers/general.php index a0324ec04..9a52524bc 100644 --- a/app/controllers/general.php +++ b/app/controllers/general.php @@ -291,7 +291,7 @@ App::options(function ($request, $response) { ->noContent(); }, ['request', 'response']); -App::error(function ($error, $utopia, $request, $response, $layout, $project, $logger, $user, $loggerBreadcrumbs) { +App::error(function ($error, $utopia, $request, $response, $layout, $project, $logger, $loggerBreadcrumbs) { /** @var Exception $error */ /** @var Utopia\App $utopia */ /** @var Utopia\Swoole\Request $request */ @@ -299,9 +299,17 @@ App::error(function ($error, $utopia, $request, $response, $layout, $project, $l /** @var Utopia\View $layout */ /** @var Appwrite\Database\Document $project */ /** @var Utopia\Logger\Logger $logger */ - /** @var Appwrite\Database\Document $user */ /** @var Utopia\Logger\Log\Breadcrumb[] $loggerBreadcrumbs */ + $user = null; + /** @var Appwrite\Database\Document $user */ + + try { + $user = $utopia->getResource('user'); + } catch(\Throwable $th) { + // All good, user is optional information for logger + } + $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); $route = $utopia->match($request); @@ -431,7 +439,7 @@ App::error(function ($error, $utopia, $request, $response, $layout, $project, $l $response->dynamic(new Document($output), $utopia->isDevelopment() ? Response::MODEL_ERROR_DEV : Response::MODEL_ERROR); -}, ['error', 'utopia', 'request', 'response', 'layout', 'project', 'logger', 'user', 'loggerBreadcrumbs']); +}, ['error', 'utopia', 'request', 'response', 'layout', 'project', 'logger', 'loggerBreadcrumbs']); App::get('/manifest.json') ->desc('Progressive app manifest file') From 03fa483181012fd2dcad82dcb2e0b8d8eb34b227 Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Tue, 21 Dec 2021 15:22:18 +0100 Subject: [PATCH 21/28] Improved CI/CD logs --- .env | 2 -- .travis.yml | 1 + 2 files changed, 1 insertion(+), 2 deletions(-) diff --git a/.env b/.env index c9fd64c8f..9f6050fe5 100644 --- a/.env +++ b/.env @@ -43,5 +43,3 @@ _APP_MAINTENANCE_RETENTION_EXECUTION=1209600 _APP_MAINTENANCE_RETENTION_ABUSE=86400 _APP_MAINTENANCE_RETENTION_AUDIT=1209600 _APP_USAGE_STATS=enabled -_APP_LOGGING_PROVIDER=raygun -_APP_LOGGING_CONFIG=4TzuEf7cZAnmBojWAPIm2Q diff --git a/.travis.yml b/.travis.yml index a4faea5a3..9d9829c10 100644 --- a/.travis.yml +++ b/.travis.yml @@ -59,6 +59,7 @@ install: script: - docker ps - docker-compose logs appwrite +- docker-compose logs appwrite-realtime - docker-compose logs appwrite-worker-functions - docker-compose exec appwrite doctor - docker-compose exec appwrite vars From 5fcc5b9b388310b4aa349104886c557fdefb9339 Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Tue, 21 Dec 2021 15:41:58 +0100 Subject: [PATCH 22/28] Code cleanup --- .env | 2 ++ app/http.php | 2 -- docker-compose.yml | 2 +- 3 files changed, 3 insertions(+), 3 deletions(-) diff --git a/.env b/.env index 9f6050fe5..86d7c558c 100644 --- a/.env +++ b/.env @@ -43,3 +43,5 @@ _APP_MAINTENANCE_RETENTION_EXECUTION=1209600 _APP_MAINTENANCE_RETENTION_ABUSE=86400 _APP_MAINTENANCE_RETENTION_AUDIT=1209600 _APP_USAGE_STATS=enabled +_APP_LOGGING_PROVIDER= +_APP_LOGGING_CONFIG= diff --git a/app/http.php b/app/http.php index 297b1ead8..985cc7d56 100644 --- a/app/http.php +++ b/app/http.php @@ -10,8 +10,6 @@ use Swoole\Http\Request as SwooleRequest; use Swoole\Http\Response as SwooleResponse; use Utopia\App; use Utopia\CLI\Console; -use Utopia\Logger\Log; -use Utopia\Logger\Log\User; use Utopia\Swoole\Files; use Utopia\Swoole\Request; diff --git a/docker-compose.yml b/docker-compose.yml index 7997c212f..cb5fd6ec4 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -160,7 +160,7 @@ services: volumes: - ./app:/usr/src/code/app - ./src:/usr/src/code/src - - ./vendor:/usr/src/code/vendor + # - ./vendor:/usr/src/code/vendor depends_on: - redis environment: From f03ab69bf3a17119c587e9d8624d9b6e043b3acb Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Tue, 21 Dec 2021 16:01:40 +0100 Subject: [PATCH 23/28] Implemented logger in http server --- app/http.php | 76 +++++++++++++++++++++++++++++++++++++++++++++++----- 1 file changed, 70 insertions(+), 6 deletions(-) diff --git a/app/http.php b/app/http.php index 985cc7d56..0b4fa3c31 100644 --- a/app/http.php +++ b/app/http.php @@ -10,6 +10,8 @@ use Swoole\Http\Request as SwooleRequest; use Swoole\Http\Response as SwooleResponse; use Utopia\App; use Utopia\CLI\Console; +use Utopia\Logger\Log; +use Utopia\Logger\Log\User; use Utopia\Swoole\Files; use Utopia\Swoole\Request; @@ -94,6 +96,60 @@ $http->on('request', function (SwooleRequest $swooleRequest, SwooleResponse $swo $app->run($request, $response); } catch (\Throwable $th) { + $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); + + $user = null; + try { + $user = $app->getResource('user'); + } catch(\Throwable $th) { + // All good, user is optional information for logger + } + + $logger = $app->getResource("logger"); + if($logger) { + $loggerBreadcrumbs = $app->getResource("loggerBreadcrumbs"); + $project = $app->getResource("project"); + $route = $app->match($request); + + $log = new Utopia\Logger\Log(); + + if(!$user->isEmpty()) { + $log->setUser(new User($user->getId())); + } + + $log->setNamespace("http"); + $log->setServer(\gethostname()); + $log->setVersion($version); + $log->setType(Log::TYPE_ERROR); + $log->setMessage($th->getMessage()); + + $log->addTag('method', $route->getMethod()); + $log->addTag('url', $route->getPath()); + $log->addTag('verboseType', get_class($th)); + $log->addTag('code', $th->getCode()); + $log->addTag('projectId', $project->getId()); + $log->addTag('hostname', $request->getHostname()); + $log->addTag('locale', (string)$request->getParam('locale', $request->getHeader('x-appwrite-locale', ''))); + + $log->addExtra('file', $th->getFile()); + $log->addExtra('line', $th->getLine()); + $log->addExtra('trace', $th->getTraceAsString()); + $log->addExtra('roles', Authorization::$roles); + + $action = $route->getLabel("sdk.namespace", "UNKNOWN_NAMESPACE") . '.' . $route->getLabel("sdk.method", "UNKNOWN_METHOD"); + $log->setAction($action); + + $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; + $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); + + foreach($loggerBreadcrumbs as $loggerBreadcrumb) { + $log->addBreadcrumb($loggerBreadcrumb); + } + + $responseCode = $logger->addLog($log); + Console::info('Log pushed with status code: '.$responseCode); + } + Console::error('[Error] Type: '.get_class($th)); Console::error('[Error] Message: '.$th->getMessage()); Console::error('[Error] File: '.$th->getFile()); @@ -108,12 +164,20 @@ $http->on('request', function (SwooleRequest $swooleRequest, SwooleResponse $swo $swooleResponse->setStatusCode(500); - if(App::isDevelopment()) { - $swooleResponse->end('error: '.$th->getMessage()); - } - else { - $swooleResponse->end('500: Server Error'); - } + $output = ((App::isDevelopment())) ? [ + 'message' => 'Error: '. $th->getMessage(), + 'code' => 500, + 'file' => $th->getFile(), + 'line' => $th->getLine(), + 'trace' => $th->getTrace(), + 'version' => $version, + ] : [ + 'message' => 'Error: Server Error', + 'code' => 500, + 'version' => $version, + ]; + + $swooleResponse->end(\json_encode($output)); } finally { /** @var PDOPool $dbPool */ $dbPool = $register->get('dbPool'); From ac64cde0a228f9fdf160affb0f5019eab53d961c Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Tue, 21 Dec 2021 16:21:30 +0100 Subject: [PATCH 24/28] Error handler resources removed --- app/controllers/general.php | 2 +- app/http.php | 7 +++---- 2 files changed, 4 insertions(+), 5 deletions(-) diff --git a/app/controllers/general.php b/app/controllers/general.php index 9a52524bc..5567912e5 100644 --- a/app/controllers/general.php +++ b/app/controllers/general.php @@ -317,7 +317,7 @@ App::error(function ($error, $utopia, $request, $response, $layout, $project, $l if($error->getCode() >= 500 || $error->getCode() === 0) { $log = new Utopia\Logger\Log(); - if(!$user->isEmpty()) { + if($user !== null && !$user->isEmpty()) { $log->setUser(new User($user->getId())); } diff --git a/app/http.php b/app/http.php index 0b4fa3c31..cce4e8500 100644 --- a/app/http.php +++ b/app/http.php @@ -101,19 +101,18 @@ $http->on('request', function (SwooleRequest $swooleRequest, SwooleResponse $swo $user = null; try { $user = $app->getResource('user'); - } catch(\Throwable $th) { + } catch(\Throwable $_th) { // All good, user is optional information for logger } $logger = $app->getResource("logger"); if($logger) { $loggerBreadcrumbs = $app->getResource("loggerBreadcrumbs"); - $project = $app->getResource("project"); $route = $app->match($request); $log = new Utopia\Logger\Log(); - if(!$user->isEmpty()) { + if($user !== null && !$user->isEmpty()) { $log->setUser(new User($user->getId())); } @@ -127,7 +126,7 @@ $http->on('request', function (SwooleRequest $swooleRequest, SwooleResponse $swo $log->addTag('url', $route->getPath()); $log->addTag('verboseType', get_class($th)); $log->addTag('code', $th->getCode()); - $log->addTag('projectId', $project->getId()); + // $log->addTag('projectId', $project->getId()); // TODO: Figure out how to get ProjectID, if it becomes relevant $log->addTag('hostname', $request->getHostname()); $log->addTag('locale', (string)$request->getParam('locale', $request->getHeader('x-appwrite-locale', ''))); From bd9d777717415a853490c38d81a4a2e276182b53 Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Mon, 27 Dec 2021 11:35:51 +0100 Subject: [PATCH 25/28] PR review changes --- app/controllers/general.php | 18 ++++++++---------- app/http.php | 16 ++++++++-------- app/realtime.php | 15 +++++---------- 3 files changed, 21 insertions(+), 28 deletions(-) diff --git a/app/controllers/general.php b/app/controllers/general.php index 5567912e5..379b4f48f 100644 --- a/app/controllers/general.php +++ b/app/controllers/general.php @@ -301,23 +301,21 @@ App::error(function ($error, $utopia, $request, $response, $layout, $project, $l /** @var Utopia\Logger\Logger $logger */ /** @var Utopia\Logger\Log\Breadcrumb[] $loggerBreadcrumbs */ - $user = null; - /** @var Appwrite\Database\Document $user */ - - try { - $user = $utopia->getResource('user'); - } catch(\Throwable $th) { - // All good, user is optional information for logger - } - $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); $route = $utopia->match($request); if($logger) { if($error->getCode() >= 500 || $error->getCode() === 0) { + try { + $user = $utopia->getResource('user'); + /** @var Appwrite\Database\Document $user */ + } catch(\Throwable $th) { + // All good, user is optional information for logger + } + $log = new Utopia\Logger\Log(); - if($user !== null && !$user->isEmpty()) { + if(isset($user) && !$user->isEmpty()) { $log->setUser(new User($user->getId())); } diff --git a/app/http.php b/app/http.php index cce4e8500..c6afe73e5 100644 --- a/app/http.php +++ b/app/http.php @@ -98,21 +98,21 @@ $http->on('request', function (SwooleRequest $swooleRequest, SwooleResponse $swo } catch (\Throwable $th) { $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); - $user = null; - try { - $user = $app->getResource('user'); - } catch(\Throwable $_th) { - // All good, user is optional information for logger - } - $logger = $app->getResource("logger"); if($logger) { + try { + $user = $app->getResource('user'); + /** @var Appwrite\Database\Document $user */ + } catch(\Throwable $_th) { + // All good, user is optional information for logger + } + $loggerBreadcrumbs = $app->getResource("loggerBreadcrumbs"); $route = $app->match($request); $log = new Utopia\Logger\Log(); - if($user !== null && !$user->isEmpty()) { + if(isset($user) && !$user->isEmpty()) { $log->setUser(new User($user->getId())); } diff --git a/app/realtime.php b/app/realtime.php index 16d478a66..99ad56f48 100644 --- a/app/realtime.php +++ b/app/realtime.php @@ -79,6 +79,11 @@ $logError = function(Throwable $error, string $action) use ($register) { $responseCode = $logger->addLog($log); Console::info('Realtime log pushed with status code: '.$responseCode); + + Console::error('[Error] Type: ' . get_class($error)); + Console::error('[Error] Message: ' . $error->getMessage()); + Console::error('[Error] File: ' . $error->getFile()); + Console::error('[Error] Line: ' . $error->getLine()); }; $server->error($logError); @@ -126,11 +131,6 @@ $server->onStart(function () use ($stats, $register, $containerId, &$documentId, $documentId = $document->getId(); } catch (\Throwable $th) { call_user_func($logError, $th, "createWorkerDocument"); - - Console::error('[Error] Type: ' . get_class($th)); - Console::error('[Error] Message: ' . $th->getMessage()); - Console::error('[Error] File: ' . $th->getFile()); - Console::error('[Error] Line: ' . $th->getLine()); } finally { call_user_func($returnConsoleDb); } @@ -191,11 +191,6 @@ $server->onStart(function () use ($stats, $register, $containerId, &$documentId, ]); } catch (\Throwable $th) { call_user_func($logError, $th, "updateWorkerDocument"); - - Console::error('[Error] Type: ' . get_class($th)); - Console::error('[Error] Message: ' . $th->getMessage()); - Console::error('[Error] File: ' . $th->getFile()); - Console::error('[Error] Line: ' . $th->getLine()); } finally { call_user_func($returnConsoleDb); } From 2c56e5ea257b0839517ebcc07551d97cb7a877b1 Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Fri, 31 Dec 2021 14:44:22 +0100 Subject: [PATCH 26/28] Removed space after merge --- app/realtime.php | 1 - 1 file changed, 1 deletion(-) diff --git a/app/realtime.php b/app/realtime.php index 9c1801646..f0af0a5d4 100644 --- a/app/realtime.php +++ b/app/realtime.php @@ -92,7 +92,6 @@ $logError = function(Throwable $error, string $action) use ($register) { $server->error($logError); - function getDatabase(Registry &$register, string $namespace) { $db = $register->get('dbPool')->get(); From 71a546c9083a455ad62b5d0eaf1c8c7721c91bf1 Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Fri, 31 Dec 2021 15:19:29 +0100 Subject: [PATCH 27/28] Post-merge fixes --- app/init.php | 1 - composer.lock | 82 ++++++++++++++++++++++++++++++++++++++++++++++----- 2 files changed, 74 insertions(+), 9 deletions(-) diff --git a/app/init.php b/app/init.php index 0a363a4ab..89f2361d2 100644 --- a/app/init.php +++ b/app/init.php @@ -31,7 +31,6 @@ use Appwrite\Stats\Stats; use Appwrite\Utopia\View; use Utopia\App; use Utopia\Logger\Logger; -use Utopia\View; use Utopia\Config\Config; use Utopia\Locale\Locale; use Utopia\Registry\Registry; diff --git a/composer.lock b/composer.lock index 590d207c9..7fb2cd49a 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": "2b1ed15e618832ee86b69cff2dcdd6ac", + "content-hash": "e0243d2a276d074c4af4ac21f521c953", "packages": [ { "name": "adhocore/jwt", @@ -2405,6 +2405,72 @@ }, "time": "2021-07-24T11:35:55+00:00" }, + { + "name": "utopia-php/logger", + "version": "0.1.0", + "source": { + "type": "git", + "url": "https://github.com/utopia-php/logger.git", + "reference": "a7d626e349e8736e46d4d75f5ba686b40e73c097" + }, + "dist": { + "type": "zip", + "url": "https://api.github.com/repos/utopia-php/logger/zipball/a7d626e349e8736e46d4d75f5ba686b40e73c097", + "reference": "a7d626e349e8736e46d4d75f5ba686b40e73c097", + "shasum": "" + }, + "require": { + "php": ">=8.0" + }, + "require-dev": { + "phpunit/phpunit": "^9.3", + "vimeo/psalm": "4.0.1" + }, + "type": "library", + "autoload": { + "psr-4": { + "Utopia\\Logger\\": "src/Logger" + } + }, + "notification-url": "https://packagist.org/downloads/", + "license": [ + "MIT" + ], + "authors": [ + { + "name": "Eldad Fux", + "email": "eldad@appwrite.io" + }, + { + "name": "Matej Bačo", + "email": "matej@appwrite.io" + }, + { + "name": "Christy Jacob", + "email": "christy@appwrite.io" + } + ], + "description": "Utopia Logger library is simple and lite library for logging information, such as errors or warnings. This library is aiming to be as simple and easy to learn and use.", + "keywords": [ + "appsignal", + "errors", + "framework", + "logger", + "logging", + "logs", + "php", + "raygun", + "sentry", + "upf", + "utopia", + "warnings" + ], + "support": { + "issues": "https://github.com/utopia-php/logger/issues", + "source": "https://github.com/utopia-php/logger/tree/0.1.0" + }, + "time": "2021-12-20T06:57:26+00:00" + }, { "name": "utopia-php/orchestration", "version": "0.2.1", @@ -2730,16 +2796,16 @@ }, { "name": "utopia-php/websocket", - "version": "0.0.1", + "version": "0.1.0", "source": { "type": "git", "url": "https://github.com/utopia-php/websocket.git", - "reference": "808317ef4ea0683c2c82dee5d543b1c8378e2e1b" + "reference": "51fcb86171400d8aa40d76c54593481fd273dab5" }, "dist": { "type": "zip", - "url": "https://api.github.com/repos/utopia-php/websocket/zipball/808317ef4ea0683c2c82dee5d543b1c8378e2e1b", - "reference": "808317ef4ea0683c2c82dee5d543b1c8378e2e1b", + "url": "https://api.github.com/repos/utopia-php/websocket/zipball/51fcb86171400d8aa40d76c54593481fd273dab5", + "reference": "51fcb86171400d8aa40d76c54593481fd273dab5", "shasum": "" }, "require": { @@ -2782,9 +2848,9 @@ ], "support": { "issues": "https://github.com/utopia-php/websocket/issues", - "source": "https://github.com/utopia-php/websocket/tree/0.0.1" + "source": "https://github.com/utopia-php/websocket/tree/0.1.0" }, - "time": "2021-07-11T13:09:44+00:00" + "time": "2021-12-20T10:50:09+00:00" }, { "name": "webmozart/assert", @@ -6520,5 +6586,5 @@ "platform-overrides": { "php": "8.0" }, - "plugin-api-version": "2.0.0" + "plugin-api-version": "2.1.0" } From 62a90a302aa6d9d7ce51e89c38d858db4a53e49b Mon Sep 17 00:00:00 2001 From: Matej Baco Date: Fri, 31 Dec 2021 15:36:54 +0100 Subject: [PATCH 28/28] Fixed missing logs from realtime in CLI --- app/realtime.php | 50 +++++++++++++++++++++++------------------------- 1 file changed, 24 insertions(+), 26 deletions(-) diff --git a/app/realtime.php b/app/realtime.php index f0af0a5d4..aff6ec227 100644 --- a/app/realtime.php +++ b/app/realtime.php @@ -56,34 +56,32 @@ $server = new Server($adapter); $logError = function(Throwable $error, string $action) use ($register) { $logger = $register->get('logger'); - if(!$logger) { - return; + if($logger) { + $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); + + $log = new Log(); + $log->setNamespace("realtime"); + $log->setServer(\gethostname()); + $log->setVersion($version); + $log->setType(Log::TYPE_ERROR); + $log->setMessage($error->getMessage()); + + $log->addTag('code', $error->getCode()); + $log->addTag('verboseType', get_class($error)); + + $log->addExtra('file', $error->getFile()); + $log->addExtra('line', $error->getLine()); + $log->addExtra('trace', $error->getTraceAsString()); + + $log->setAction($action); + + $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; + $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); + + $responseCode = $logger->addLog($log); + Console::info('Realtime log pushed with status code: '.$responseCode); } - $version = App::getEnv('_APP_VERSION', 'UNKNOWN'); - - $log = new Log(); - $log->setNamespace("realtime"); - $log->setServer(\gethostname()); - $log->setVersion($version); - $log->setType(Log::TYPE_ERROR); - $log->setMessage($error->getMessage()); - - $log->addTag('code', $error->getCode()); - $log->addTag('verboseType', get_class($error)); - - $log->addExtra('file', $error->getFile()); - $log->addExtra('line', $error->getLine()); - $log->addExtra('trace', $error->getTraceAsString()); - - $log->setAction($action); - - $isProduction = App::getEnv('_APP_ENV', 'development') === 'production'; - $log->setEnvironment($isProduction ? Log::ENVIRONMENT_PRODUCTION : Log::ENVIRONMENT_STAGING); - - $responseCode = $logger->addLog($log); - Console::info('Realtime log pushed with status code: '.$responseCode); - Console::error('[Error] Type: ' . get_class($error)); Console::error('[Error] Message: ' . $error->getMessage()); Console::error('[Error] File: ' . $error->getFile());