Compare commits

...
5 changed files with 145 additions and 2 deletions
+15 -2
View File
@@ -5,6 +5,7 @@ namespace Appwrite\Bus\Listeners;
use Appwrite\Bus\Events\ExecutionCompleted;
use Appwrite\Event\Message\Execution as ExecutionMessage;
use Appwrite\Event\Publisher\Execution as ExecutionPublisher;
use Appwrite\Extend\TraceFunctionExecution;
use Utopia\Bus\Listener;
use Utopia\Database\Document;
@@ -30,9 +31,21 @@ class Log extends Listener
public function handle(ExecutionCompleted $event, ExecutionPublisher $publisherForExecutions): void
{
$project = new Document($event->project);
$execution = new Document($event->execution);
if ($execution->getAttribute('resourceType', '') === 'functions') {
TraceFunctionExecution::log('v1_executions_enqueue', [
'projectId' => $project->getId(),
'functionId' => $execution->getAttribute('resourceId', ''),
'executionId' => $execution->getId(),
'deploymentId' => $execution->getAttribute('deploymentId', ''),
'status' => $execution->getAttribute('status', ''),
]);
}
$publisherForExecutions->enqueue(new ExecutionMessage(
project: new Document($event->project),
execution: new Document($event->execution),
project: $project,
execution: $execution,
));
}
}
@@ -0,0 +1,74 @@
<?php
namespace Appwrite\Extend;
use Utopia\Console;
use Utopia\Database\DateTime;
use Utopia\System\System;
/**
* Opt-in trace logging for a single project+function pair via env (development / debugging).
* Set both _APP_TRACE_PROJECT_ID and _APP_TRACE_FUNCTION_ID to enable.
*/
class TraceFunctionExecution
{
private static ?string $cachedProjectId = null;
private static ?string $cachedFunctionId = null;
public static function isEnabled(): bool
{
return self::traceProjectId() !== '' && self::traceFunctionId() !== '';
}
private static function traceProjectId(): string
{
if (self::$cachedProjectId === null) {
self::$cachedProjectId = System::getEnv('_APP_TRACE_PROJECT_ID', '69ddf60f001255461d5c');
}
return self::$cachedProjectId;
}
private static function traceFunctionId(): string
{
if (self::$cachedFunctionId === null) {
self::$cachedFunctionId = System::getEnv('_APP_TRACE_FUNCTION_ID', '69ddf6500032ee9f5b0f');
}
return self::$cachedFunctionId;
}
public static function matches(?string $projectId, ?string $functionId): bool
{
if (!self::isEnabled()) {
return false;
}
return (string) $projectId === self::traceProjectId()
&& (string) $functionId === self::traceFunctionId();
}
/**
* @param array<string, mixed> $context Must include projectId and functionId for filtering.
*/
public static function log(string $station, array $context = []): void
{
if (!self::isEnabled()) {
return;
}
$projectId = $context['projectId'] ?? null;
$functionId = $context['functionId'] ?? null;
if (!self::matches($projectId, $functionId)) {
return;
}
$payload = \array_merge([
'station' => $station,
'time' => DateTime::now(),
], $context);
Console::log('[execution-trace] ' . \json_encode($payload, JSON_UNESCAPED_SLASHES));
}
}
@@ -3,6 +3,7 @@
namespace Appwrite\Platform\Tasks;
use Appwrite\Event\Func;
use Appwrite\Extend\TraceFunctionExecution;
use Cron\CronExpression;
use Utopia\Console;
use Utopia\Database\Database;
@@ -97,6 +98,16 @@ class ScheduleFunctions extends ScheduleBase
$queueForFunctions = new Func($this->publisherFunctions);
$projectDoc = $schedule['project'];
$functionDoc = $schedule['resource'];
TraceFunctionExecution::log('v1_functions_enqueue', [
'projectId' => $projectDoc->getId(),
'functionId' => $functionDoc->getId(),
'scheduleId' => $schedule['$id'] ?? '',
'schedule' => $schedule['schedule'] ?? '',
]);
$queueForFunctions
->setType('schedule')
->setFunction($schedule['resource'])
@@ -3,6 +3,7 @@
namespace Appwrite\Platform\Workers;
use Appwrite\Event\Message\Execution;
use Appwrite\Extend\TraceFunctionExecution;
use Exception;
use Utopia\Database\Database;
use Utopia\Platform\Action;
@@ -39,6 +40,14 @@ class Executions extends Action
throw new Exception('Missing execution');
}
TraceFunctionExecution::log('executions_worker_upsert', [
'projectId' => $executionMessage->project->getId(),
'functionId' => $execution->getAttribute('resourceId', ''),
'executionId' => $execution->getId(),
'deploymentId' => $execution->getAttribute('deploymentId', ''),
'resourceType' => $execution->getAttribute('resourceType', ''),
]);
$dbForProject->upsertDocument('executions', $execution);
}
}
@@ -9,6 +9,7 @@ use Appwrite\Event\Func;
use Appwrite\Event\Realtime;
use Appwrite\Event\Webhook;
use Appwrite\Extend\Exception as AppwriteException;
use Appwrite\Extend\TraceFunctionExecution;
use Appwrite\Utopia\Response\Model\Execution;
use Executor\Executor;
use Utopia\Bus\Bus;
@@ -115,6 +116,17 @@ class Functions extends Action
$log->addTag('projectId', $project->getId());
$log->addTag('type', $type);
if (empty($events) && !$function->isEmpty()) {
TraceFunctionExecution::log('functions_worker_dequeue', [
'projectId' => $project->getId(),
'functionId' => $function->getId(),
'payloadType' => $type,
'queuePid' => $message->getPid(),
'queueName' => $message->getQueue(),
'messageTimestamp' => $message->getTimestamp(),
]);
}
if (!empty($events)) {
$limit = 100;
$sum = 100;
@@ -304,6 +316,15 @@ class Functions extends Action
'duration' => 0.0,
]);
TraceFunctionExecution::log('functions_worker_before_execution_completed_bus_fail', [
'projectId' => $project->getId(),
'functionId' => $function->getId(),
'executionId' => $execution->getId(),
'deploymentId' => $execution->getAttribute('deploymentId', ''),
'trigger' => $trigger,
'status' => $execution->getAttribute('status', ''),
]);
$bus->dispatch(new ExecutionCompleted(
execution: $execution->getArrayCopy(),
project: $project->getArrayCopy(),
@@ -522,6 +543,13 @@ class Functions extends Action
$source = $deployment->getAttribute('buildPath', '');
$extension = str_ends_with($source, '.tar') ? 'tar' : 'tar.gz';
$command = $version === 'v2' ? '' : "cp /tmp/code.$extension /mnt/code/code.$extension && nohup helpers/start.sh \"$command\"";
TraceFunctionExecution::log('functions_worker_before_executor', [
'projectId' => $project->getId(),
'functionId' => $functionId,
'executionId' => $executionId,
'deploymentId' => $deployment->getId(),
'trigger' => $trigger,
]);
$executionResponse = $executor->createExecution(
projectId: $project->getId(),
deploymentId: $deploymentId,
@@ -594,6 +622,14 @@ class Functions extends Action
$errorCode = $th->getCode();
} finally {
/** Persist final execution status and record usage */
TraceFunctionExecution::log('functions_worker_before_execution_completed_bus', [
'projectId' => $project->getId(),
'functionId' => $functionId,
'executionId' => $execution->getId(),
'deploymentId' => $execution->getAttribute('deploymentId', ''),
'status' => $execution->getAttribute('status', ''),
'trigger' => $trigger,
]);
$bus->dispatch(new ExecutionCompleted(
execution: $execution->getArrayCopy(),
project: $project->getArrayCopy(),