diff --git a/src/Appwrite/Platform/Modules/Functions/Workers/Builds.php b/src/Appwrite/Platform/Modules/Functions/Workers/Builds.php index 5aa95d3bf2..1d4a8dd689 100644 --- a/src/Appwrite/Platform/Modules/Functions/Workers/Builds.php +++ b/src/Appwrite/Platform/Modules/Functions/Workers/Builds.php @@ -104,8 +104,6 @@ class Builds extends Action Executor $executor, array $plan ): void { - Console::log('Build action started'); - $payload = $message->getPayload(); if (empty($payload)) { @@ -113,6 +111,8 @@ class Builds extends Action } $type = $payload['type'] ?? ''; + Span::add('build.type', $type); + $resource = new Document($payload['resource'] ?? []); $deployment = new Document($payload['deployment'] ?? []); $template = new Document($payload['template'] ?? []); @@ -124,7 +124,6 @@ class Builds extends Action switch ($type) { case BUILD_TYPE_DEPLOYMENT: case BUILD_TYPE_RETRY: - Console::info('Creating build for deployment: ' . $deployment->getId()); $github = new GitHub($cache); $this->buildDeployment( $deviceForFunctions, @@ -193,8 +192,6 @@ class Builds extends Action Span::add('deployment.id', $deployment->getId()); Span::add('build.timeout', $timeout); - Console::info('Deployment action started'); - $startTime = DateTime::now(); $durationStart = \microtime(true); @@ -268,7 +265,7 @@ class Builds extends Action $resource = $dbForProject->updateDocument($resource->getCollection(), $resource->getId(), new Document(['latestDeploymentStatus' => $deployment->getAttribute('status', '')])); } - Console::log('Status marked as processing'); + Span::add('deployment.status', 'processing'); $queueForRealtime ->setPayload($deployment->getArrayCopy()) @@ -359,7 +356,7 @@ class Builds extends Action ->setPayload($deployment->getArrayCopy()) ->trigger(); - Console::log('Template cloned'); + Span::add('build.source_size', $deployment->getAttribute('sourceSize')); } } elseif ($isVcsEnabled) { // VCS and VCS+Temaplte @@ -403,8 +400,6 @@ class Builds extends Action throw new \Exception('Unable to clone code repository: ' . $stderr); } - Console::log('Git repository cloned'); - // Local refactoring for function folder with spaces if (str_contains($rootDirectory, ' ')) { $rootDirectoryWithoutSpaces = str_replace(' ', '', $rootDirectory); @@ -478,8 +473,6 @@ class Builds extends Action $queueForRealtime ->setPayload($deployment->getArrayCopy()) ->trigger(); - - Console::log('Git template pushed'); } $tmpPath = '/tmp/builds/' . $deploymentId; @@ -531,18 +524,17 @@ class Builds extends Action ->setPayload($deployment->getArrayCopy()) ->trigger(); - Console::log('Git source uploaded'); + Span::add('build.source_size', $deployment->getAttribute('sourceSize')); $this->runGitAction('processing', $github, $providerCommitHash, $owner, $repositoryName, $project, $resource, $deployment->getId(), $dbForProject, $dbForPlatform, $queueForRealtime, $platform); } - Console::log('Status marked as building'); - /** Request the executor to build the code... */ $deployment->setAttribute('status', 'building'); $deployment = $dbForProject->updateDocument('deployments', $deployment->getId(), new Document([ 'status' => 'building', ])); + Span::add('deployment.status', 'building'); if ($deployment->getSequence() === $resource->getAttribute('latestDeploymentInternalId', '')) { $resource = $dbForProject->updateDocument($resource->getCollection(), $resource->getId(), new Document(['latestDeploymentStatus' => $deployment->getAttribute('status', '')])); @@ -687,11 +679,10 @@ class Builds extends Action } $isCanceled = false; - - Console::log('Runtime creation started'); + $span = Span::current(); Co::join([ - Co\go(function () use ($executor, &$response, $project, $deployment, $source, $resource, $runtime, $vars, $command, $cpus, $memory, $timeout, &$err, $version) { + Co\go(function () use ($executor, &$response, $project, $deployment, $source, $resource, $runtime, $vars, $command, $cpus, $memory, $timeout, &$err, $version, $span) { try { if ($version === 'v2') { $command = 'tar -zxf /tmp/code.tar.gz -C /usr/code && cd /usr/local/src/ && ./build.sh'; @@ -739,16 +730,18 @@ class Builds extends Action outputDirectory: $outputDirectory ?? '' ); - Console::log('createRuntime finished'); } catch (ExecutorTimeout $error) { - Console::warning('createRuntime timed out'); + $span?->set('build.runtime.timed_out', true); + $span?->set('build.runtime.error_type', $error::class); + $span?->set('build.runtime.error_message', $error->getMessage()); $err = new AppwriteException(AppwriteException::BUILD_TIMEOUT, previous: $error); } catch (\Throwable $error) { - Console::warning('createRuntime failed'); + $span?->set('build.runtime.error_type', $error::class); + $span?->set('build.runtime.error_message', $error->getMessage()); $err = $error; } }), - Co\go(function () use ($executor, $project, &$deployment, &$response, $dbForProject, $timeout, &$err, $queueForRealtime, &$isCanceled) { + Co\go(function () use ($executor, $project, &$deployment, &$response, $dbForProject, $timeout, &$err, $queueForRealtime, &$isCanceled, $span) { try { $insideSeparation = false; @@ -756,7 +749,7 @@ class Builds extends Action deploymentId: $deployment->getId(), projectId: $project->getId(), timeout: $timeout, - callback: function ($logs) use (&$response, &$err, $dbForProject, &$isCanceled, &$deployment, $queueForRealtime, &$insideSeparation) { + callback: function ($logs) use (&$response, &$err, $dbForProject, &$isCanceled, &$deployment, $queueForRealtime, &$insideSeparation, $span) { if ($isCanceled) { return; } @@ -767,7 +760,7 @@ class Builds extends Action if ($deployment->getAttribute('status') === 'canceled') { $isCanceled = true; - Console::info('Ignoring realtime logs because build has been canceled'); + $span?->set('build.logs.ignored_reason', 'canceled'); return; } @@ -836,9 +829,10 @@ class Builds extends Action } } ); - Console::warning('listLogs finished'); + $span?->set('build.logs.finished', true); } catch (\Throwable $error) { - Console::warning('listLogs failed'); + $span?->set('build.logs.error_type', $error::class); + $span?->set('build.logs.error_message', $error->getMessage()); if (empty($err)) { $err = $error; } @@ -846,8 +840,6 @@ class Builds extends Action }), ]); - Console::log('Runtime creation finished'); - $latestDeployment = $dbForProject->getDocument('deployments', $deploymentId); if ($latestDeployment->getAttribute('status') === 'canceled') { $this->cancelDeployment($deployment->getId(), $dbForProject, $queueForRealtime); @@ -870,6 +862,8 @@ class Builds extends Action $deployment->setAttribute('buildPath', $response['path']); $deployment->setAttribute('buildSize', $response['size']); $deployment->setAttribute('totalSize', $deployment->getAttribute('buildSize', 0) + $deployment->getAttribute('sourceSize', 0)); + Span::add('build.size', $deployment->getAttribute('buildSize')); + Span::add('build.total_size', $deployment->getAttribute('totalSize')); $logs = ''; foreach ($response['output'] as $log) { @@ -908,8 +902,8 @@ class Builds extends Action $deployment->setAttribute('adapter', $detection->getName()); $deployment->setAttribute('fallbackFile', $detection->getFallbackFile() ?? ''); - - Console::log('Adapter detected'); + Span::add('build.adapter', $deployment->getAttribute('adapter')); + Span::add('build.fallback_file', $deployment->getAttribute('fallbackFile')); } elseif ($adapter === 'ssr' && $detection->getName() === 'static') { throw new \Exception('Adapter mismatch. Detected: ' . $detection->getName() . ' does not match with the set adapter: ' . $adapter); } @@ -927,8 +921,6 @@ class Builds extends Action ->setPayload($deployment->getArrayCopy()) ->trigger(); - Console::log('Build details stored'); - $this->afterBuildSuccess($queueForRealtime, $dbForProject, $deployment, $runtime, $adapter); $logs = $deployment->getAttribute('buildLogs', ''); @@ -942,8 +934,7 @@ class Builds extends Action 'buildLogs' => $deployment->getAttribute('buildLogs'), 'status' => 'ready', ])); - - Console::log('Status marked as ready'); + Span::add('deployment.status', 'ready'); if ($deployment->getSequence() === $resource->getAttribute('latestDeploymentInternalId', '')) { $resource = $dbForProject->updateDocument($resource->getCollection(), $resource->getId(), new Document(['latestDeploymentStatus' => $deployment->getAttribute('status', '')])); @@ -969,7 +960,7 @@ class Builds extends Action if ($currentActiveStartTime < $deploymentStartTime) { $activateBuild = true; } else { - Console::info('Skipping auto-activation as current deployment is more recent'); + Span::add('build.auto_activation.skipped_reason', 'current_deployment_newer'); } } } else { @@ -1031,7 +1022,7 @@ class Builds extends Action break; } - Console::log('Deployment activated'); + Span::add('build.activated', true); } $this->afterDeploymentSuccess( @@ -1099,7 +1090,7 @@ class Builds extends Action ])); }, $queries); - Console::log('Preview rule created'); + Span::add('build.preview_rule_created', true); } } @@ -1109,6 +1100,7 @@ class Builds extends Action 'buildEndedAt' => $endTime, 'buildDuration' => \intval(\ceil($durationEnd - $durationStart)), ])); + Span::add('build.duration', $deployment->getAttribute('buildDuration')); $queueForRealtime ->setPayload($deployment->getArrayCopy()) ->trigger(); @@ -1119,8 +1111,6 @@ class Builds extends Action return; } - Console::log('Build duration updated'); - /** Update function schedule */ // Inform scheduler if function is still active @@ -1144,23 +1134,21 @@ class Builds extends Action deploymentId: $deployment->getId(), )); - Console::log('Site screenshot queued'); + Span::add('build.screenshot_queued', true); } - - Console::info('Deployment action finished'); } catch (\Throwable $th) { - Console::warning('Build failed:'); - Console::error($th->getMessage()); - Console::error($th->getFile()); - Console::error($th->getLine()); - Console::error($th->getTraceAsString()); - if ($dbForProject->getDocument('deployments', $deploymentId)->getAttribute('status') === 'canceled') { $this->cancelDeployment($deployment->getId(), $dbForProject, $queueForRealtime); return; } + Span::add('build.error.stage', 'deployment'); + Span::add('build.error.type', $th::class); + Span::add('build.error.message', $th->getMessage()); + Span::add('build.error.file', $th->getFile()); + Span::add('build.error.line', $th->getLine()); + // Color message red $message = $th->getMessage(); if (! \str_contains($message, '')) { @@ -1182,6 +1170,8 @@ class Builds extends Action $deployment->setAttribute('buildEndedAt', $endTime); $deployment->setAttribute('buildDuration', \intval(\ceil($durationEnd - $durationStart))); $deployment->setAttribute('status', 'failed'); + Span::add('deployment.status', 'failed'); + Span::add('build.duration', $deployment->getAttribute('buildDuration')); $deployment->setAttribute('buildLogs', $message); $deployment = $dbForProject->updateDocument('deployments', $deploymentId, new Document([ @@ -1200,7 +1190,7 @@ class Builds extends Action ->trigger(); if ($isVcsEnabled) { - $this->runGitAction('failed', $github, $providerCommitHash, $owner, $repositoryName, $project, $resource, $deployment->getId(), $dbForProject, $dbForPlatform, $queueForRealtime, $platform); + $this->runGitAction('failed', $github, $providerCommitHash, $owner, $repositoryName, $project, $resource, $deployment->getId(), $dbForProject, $dbForPlatform, $queueForRealtime, $platform, true); } } finally { $queueForRealtime @@ -1360,7 +1350,8 @@ class Builds extends Action Database $dbForProject, Database $dbForPlatform, Realtime $queueForRealtime, - array $platform + array $platform, + bool $secondaryError = false ): void { $deployment = new Document(); @@ -1456,9 +1447,14 @@ class Builds extends Action } } } catch (\Throwable $th) { - Console::warning('Git action failed:'); - Console::warning($th->getMessage()); - Console::warning($th->getTraceAsString()); + $span = Span::current(); + $errorPrefix = $secondaryError ? 'build.error.secondary' : 'build.git_action.error'; + $span?->set("{$errorPrefix}.stage", 'git_action'); + $span?->set("{$errorPrefix}.status", $status); + $span?->set("{$errorPrefix}.type", $th::class); + $span?->set("{$errorPrefix}.message", $th->getMessage()); + $span?->set("{$errorPrefix}.file", $th->getFile()); + $span?->set("{$errorPrefix}.line", $th->getLine()); $logs = $deployment->getAttribute('buildLogs', ''); $date = \date('H:i:s'); @@ -1477,7 +1473,7 @@ class Builds extends Action private function cancelDeployment(string $deploymentId, Database $dbForProject, Realtime $queueForRealtime) { - Console::info('Build has been canceled'); + Span::add('deployment.status', 'canceled'); $deployment = $dbForProject->getDocument('deployments', $deploymentId);