mirror of
https://github.com/appwrite/appwrite.git
synced 2026-05-26 13:51:13 +00:00
Enhance function execution tracing by adding logging for function enqueueing and execution events across multiple components. This includes logging in Log, ScheduleFunctions, Executions, and Functions classes to capture relevant execution details for better monitoring and debugging.
This commit is contained in:
@@ -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(),
|
||||
|
||||
Reference in New Issue
Block a user