1
0
Fork 0
mirror of synced 2024-05-20 12:42:39 +12:00

Implemented logging for HTTP, Realtime, Workers

This commit is contained in:
Matej Baco 2021-11-23 15:24:25 +01:00
parent fc3d322773
commit 56402c78fe
20 changed files with 318 additions and 21 deletions

5
.env
View file

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

View file

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

View file

@ -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' => ''
]
],
],

View file

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

View file

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

View file

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

View file

@ -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' => [

View file

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

View file

@ -108,6 +108,7 @@ services:
- _APP_FUNCTIONS_RUNTIMES
- _APP_LOGGING_PROVIDER
- _APP_LOGGING_CONFIG
- _APP_LOGGING_SERVERNAME
appwrite-realtime:
image: <?php echo $organization; ?>/<?php echo $image; ?>:<?php echo $version."\n"; ?>

View file

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

View file

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

View file

@ -23,6 +23,10 @@ class DeletesV1 extends Worker
{
protected Database $consoleDB;
public function getWorkerName(): string {
return "deletes";
}
public function init(): void
{
}

View file

@ -101,6 +101,10 @@ class FunctionsV1 extends Worker
public array $allowed = [];
public function getWorkerName(): string {
return "functions";
}
public function init(): void
{
}

View file

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

View file

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

View file

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

View file

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

4
composer.lock generated
View file

@ -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",

View file

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

View file

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