diff --git a/.github/workflows/tests.yml b/.github/workflows/tests.yml index 9ea04f596c..9f85d55ea3 100644 --- a/.github/workflows/tests.yml +++ b/.github/workflows/tests.yml @@ -134,6 +134,14 @@ jobs: - name: Run General Tests run: docker compose exec -T appwrite test /usr/src/code/tests/e2e/General --debug + - name: Failure Logs + if: failure() + run: | + echo "=== Appwrite Worker Builds Logs ===" + docker compose logs appwrite-worker-builds + echo "=== OpenRuntimes Executor Logs ===" + docker compose logs openruntimes-executor + e2e_service_test: name: E2E Service Test runs-on: ubuntu-latest @@ -201,6 +209,14 @@ jobs: -e _APP_DATABASE_SHARED_TABLES_V1 \ appwrite test /usr/src/code/tests/e2e/Services/${{ matrix.service }} --debug --exclude-group devKeys,screenshots + - name: Failure Logs + if: failure() + run: | + echo "=== Appwrite Worker Builds Logs ===" + docker compose logs appwrite-worker-builds + echo "=== OpenRuntimes Executor Logs ===" + docker compose logs openruntimes-executor + e2e_shared_mode_test: name: E2E Shared Mode Service Test runs-on: ubuntu-latest @@ -280,6 +296,14 @@ jobs: -e _APP_DATABASE_SHARED_TABLES_V1 \ appwrite test /usr/src/code/tests/e2e/Services/${{ matrix.service }} --debug --exclude-group devKeys,screenshots + - name: Failure Logs + if: failure() + run: | + echo "=== Appwrite Worker Builds Logs ===" + docker compose logs appwrite-worker-builds + echo "=== OpenRuntimes Executor Logs ===" + docker compose logs openruntimes-executor + e2e_dev_keys: name: E2E Service Test (Dev Keys) runs-on: ubuntu-latest @@ -313,6 +337,14 @@ jobs: -e _APP_DATABASE_SHARED_TABLES_V1 \ appwrite test /usr/src/code/tests/e2e/Services/Projects --debug --group=devKeys + - name: Failure Logs + if: failure() + run: | + echo "=== Appwrite Worker Builds Logs ===" + docker compose logs appwrite-worker-builds + echo "=== OpenRuntimes Executor Logs ===" + docker compose logs openruntimes-executor + e2e_dev_keys_shared_mode: name: E2E Shared Mode Service Test (Dev Keys) runs-on: ubuntu-latest @@ -360,6 +392,14 @@ jobs: -e _APP_DATABASE_SHARED_TABLES_V1 \ appwrite test /usr/src/code/tests/e2e/Services/Projects --debug --group=devKeys + - name: Failure Logs + if: failure() + run: | + echo "=== Appwrite Worker Builds Logs ===" + docker compose logs appwrite-worker-builds + echo "=== OpenRuntimes Executor Logs ===" + docker compose logs openruntimes-executor + e2e_screenshots_keys: name: E2E Service Test (Site Screenshots) runs-on: ubuntu-latest @@ -394,6 +434,14 @@ jobs: -e _APP_DATABASE_SHARED_TABLES_V1 \ appwrite test /usr/src/code/tests/e2e/Services/Sites --debug --group=screenshots + - name: Failure Logs + if: failure() + run: | + echo "=== Appwrite Worker Builds Logs ===" + docker compose logs appwrite-worker-builds + echo "=== OpenRuntimes Executor Logs ===" + docker compose logs openruntimes-executor + e2e_screenshots_shared_mode: name: E2E Shared Mode Service Test (Site Screenshots) runs-on: ubuntu-latest @@ -441,3 +489,11 @@ jobs: -e _APP_DATABASE_SHARED_TABLES \ -e _APP_DATABASE_SHARED_TABLES_V1 \ appwrite test /usr/src/code/tests/e2e/Services/Sites --debug --group=screenshots + + - name: Failure Logs + if: failure() + run: | + echo "=== Appwrite Worker Builds Logs ===" + docker compose logs appwrite-worker-builds + echo "=== OpenRuntimes Executor Logs ===" + docker compose logs openruntimes-executor diff --git a/docker-compose.yml b/docker-compose.yml index 7b201f4ac4..c5301c2a4d 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -71,6 +71,9 @@ services: - traefik.http.routers.appwrite_api_https.service=appwrite_api - traefik.http.routers.appwrite_api_https.tls=true volumes: + - /var/run/docker.sock:/var/run/docker.sock # Only needed for tests + - ./docker-compose.yml:/usr/src/code/docker-compose.yml # Only needed for tests + - ./.env:/usr/src/code/.env # Only needed for tests - appwrite-uploads:/storage/uploads:rw - appwrite-imports:/storage/imports:rw - appwrite-cache:/storage/cache:rw diff --git a/src/Appwrite/Platform/Modules/Functions/Workers/Builds.php b/src/Appwrite/Platform/Modules/Functions/Workers/Builds.php index 67bea01a28..9547a752ef 100644 --- a/src/Appwrite/Platform/Modules/Functions/Workers/Builds.php +++ b/src/Appwrite/Platform/Modules/Functions/Workers/Builds.php @@ -117,6 +117,8 @@ class Builds extends Action Executor $executor, array $plan ): void { + Console::log('Build action started'); + $payload = $message->getPayload() ?? []; if (empty($payload)) { @@ -209,6 +211,8 @@ class Builds extends Action Executor $executor, array $plan ): void { + Console::info('Deployment action started'); + $startTime = DateTime::now(); $durationStart = \microtime(true); @@ -278,6 +282,8 @@ class Builds extends Action $resource = $dbForProject->updateDocument($resource->getCollection(), $resource->getId(), new Document(['latestDeploymentStatus' => $deployment->getAttribute('status', '')])); } + Console::log('Status marked as processing'); + $queueForRealtime ->setPayload($deployment->getArrayCopy()) ->trigger(); @@ -359,6 +365,8 @@ class Builds extends Action $queueForRealtime ->setPayload($deployment->getArrayCopy()) ->trigger(); + + Console::log('Template cloned'); } } elseif ($isVcsEnabled) { // VCS and VCS+Temaplte @@ -401,6 +409,8 @@ 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); @@ -469,6 +479,8 @@ class Builds extends Action $queueForRealtime ->setPayload($deployment->getArrayCopy()) ->trigger(); + + Console::log('Git template pushed'); } $tmpPath = '/tmp/builds/' . $deploymentId; @@ -516,9 +528,13 @@ class Builds extends Action ->setPayload($deployment->getArrayCopy()) ->trigger(); + Console::log('Git source uploaded'); + $this->runGitAction('processing', $github, $providerCommitHash, $owner, $repositoryName, $project, $resource, $deployment->getId(), $dbForProject, $dbForPlatform, $queueForRealtime); } + Console::log('Status marked as building'); + /** Request the executor to build the code... */ $deployment->setAttribute('status', 'building'); $deployment = $dbForProject->updateDocument('deployments', $deployment->getId(), $deployment); @@ -662,6 +678,8 @@ class Builds extends Action $isCanceled = false; + Console::log('Runtime creation started'); + Co::join([ Co\go(function () use ($executor, &$response, $project, $deployment, $source, $resource, $runtime, $vars, $command, $cpus, $memory, $timeout, &$err, $version) { try { @@ -709,7 +727,10 @@ class Builds extends Action command: $command, outputDirectory: $resource->getAttribute('outputDirectory', '') ); + + Console::log('createRuntime finished'); } catch (\Throwable $error) { + Console::warning('createRuntime failed'); $err = $error; } }), @@ -798,7 +819,9 @@ class Builds extends Action } } ); + Console::warning('listLogs finished'); } catch (\Throwable $error) { + Console::warning('listLogs failed'); if (empty($err)) { $err = $error; } @@ -806,6 +829,8 @@ class Builds extends Action }), ]); + Console::log('Runtime creation finished'); + if ($dbForProject->getDocument('deployments', $deploymentId)->getAttribute('status') === 'canceled') { $this->cancelDeployment($deployment->getId(), $dbForProject, $queueForRealtime); return; @@ -860,6 +885,8 @@ class Builds extends Action $deployment->setAttribute('adapter', $detection->getName()); $deployment->setAttribute('fallbackFile', $detection->getFallbackFile() ?? ''); + + Console::log('Adapter detected'); } elseif ($adapter === 'ssr' && $detection->getName() === 'static') { throw new \Exception('Adapter mismatch. Detected: ' . $detection->getName() . ' does not match with the set adapter: ' . $adapter); } @@ -870,10 +897,15 @@ class Builds extends Action ->setPayload($deployment->getArrayCopy()) ->trigger(); + Console::log('Build details stored'); + $this->afterBuildSuccess($queueForRealtime, $dbForProject, $deployment); $logs = $deployment->getAttribute('buildLogs', ''); + /** Screenshot site */ if ($resource->getCollection() === 'sites') { + Console::log('Site screenshot started'); + $date = \date('H:i:s'); $logs .= "[$date] [appwrite] Screenshot capturing started. \n"; $deployment->setAttribute('buildLogs', $logs); @@ -881,10 +913,7 @@ class Builds extends Action $queueForRealtime ->setPayload($deployment->getArrayCopy()) ->trigger(); - } - /** Screenshot site */ - if ($resource->getCollection() === 'sites') { try { $rule = Authorization::skip(fn () => $dbForPlatform->findOne('rules', [ Query::equal("projectInternalId", [$project->getSequence()]), @@ -1049,6 +1078,8 @@ class Builds extends Action $deployment->setAttribute('buildLogs', $logs); $deployment = $dbForProject->updateDocument('deployments', $deployment->getId(), $deployment); } + + Console::log('Site screenshot finished'); } $logs = $deployment->getAttribute('buildLogs', ''); @@ -1060,6 +1091,8 @@ class Builds extends Action $deployment->setAttribute('status', 'ready'); $deployment = $dbForProject->updateDocument('deployments', $deploymentId, $deployment); + Console::log('Status marked as ready'); + if ($deployment->getSequence() === $resource->getAttribute('latestDeploymentInternalId', '')) { $resource = $dbForProject->updateDocument($resource->getCollection(), $resource->getId(), new Document(['latestDeploymentStatus' => $deployment->getAttribute('status', '')])); } @@ -1072,8 +1105,6 @@ class Builds extends Action $this->runGitAction('ready', $github, $providerCommitHash, $owner, $repositoryName, $project, $resource, $deployment->getId(), $dbForProject, $dbForPlatform, $queueForRealtime); } - Console::success("Build id: $deploymentId created"); - /** Set auto deploy */ $activateBuild = false; if ($deployment->getAttribute('activate') === true) { @@ -1153,6 +1184,8 @@ class Builds extends Action break; } + + Console::log('Deployment activated'); } if ($resource->getCollection() === 'sites') { @@ -1211,6 +1244,8 @@ class Builds extends Action 'deploymentInternalId' => $deployment->getSequence(), ])); }, $queries); + + Console::log('Preview rule created'); } } @@ -1228,6 +1263,8 @@ class Builds extends Action return; } + Console::log('Build duration updated'); + /** Update function schedule */ // Inform scheduler if function is still active @@ -1239,6 +1276,8 @@ class Builds extends Action ->setAttribute('active', !empty($resource->getAttribute('schedule')) && !empty($resource->getAttribute('deploymentId'))); Authorization::skip(fn () => $dbForPlatform->updateDocument('schedules', $schedule->getId(), $schedule)); } + + Console::info('Deployment action finished'); } catch (\Throwable $th) { Console::warning('Build failed:'); Console::error($th->getMessage()); diff --git a/tests/e2e/Services/Sites/SitesBase.php b/tests/e2e/Services/Sites/SitesBase.php index 2054744863..93c55b82b7 100644 --- a/tests/e2e/Services/Sites/SitesBase.php +++ b/tests/e2e/Services/Sites/SitesBase.php @@ -3,6 +3,7 @@ namespace Tests\E2E\Services\Sites; use Appwrite\Tests\Async; +use Appwrite\Tests\Async\Exceptions\Critical; use CURLFile; use Tests\E2E\Client; use Utopia\CLI\Console; @@ -48,8 +49,23 @@ trait SitesBase 'x-appwrite-project' => $this->getProject()['$id'], 'x-appwrite-key' => $this->getProject()['apiKey'], ])); + + if ($deployment['body']['status'] === 'failed') { + throw new Critical('Deployment failed: ' . json_encode($deployment['body'], JSON_PRETTY_PRINT)); + } + + Console::execute("docker inspect openruntimes-executor --format='{{.State.ExitCode}}'", '', $this->stdout, $this->stderr); + if (\trim($this->stdout) !== '0') { + $msg = 'Executor has a problem: ' . $this->stderr . ' (' . $this->stdout . '), current status: '; + + Console::execute("docker compose logs openruntimes-executor", '', $this->stdout, $this->stderr); + $msg .= $this->stdout . ' (' . $this->stderr . ')'; + + throw new Critical($msg . json_encode($deployment['body'], JSON_PRETTY_PRINT)); + } + $this->assertEquals('ready', $deployment['body']['status'], 'Deployment status is not ready, deployment: ' . json_encode($deployment['body'], JSON_PRETTY_PRINT)); - }, 150000, 500); + }, 300000, 500); // Not === so multipart/form-data works fine too if (($params['activate'] ?? false) == true) { diff --git a/tests/e2e/Services/Sites/SitesCustomServerTest.php b/tests/e2e/Services/Sites/SitesCustomServerTest.php index 8680ca191c..f1550e3910 100644 --- a/tests/e2e/Services/Sites/SitesCustomServerTest.php +++ b/tests/e2e/Services/Sites/SitesCustomServerTest.php @@ -405,8 +405,10 @@ class SitesCustomServerTest extends Scope ]); $this->assertNotEmpty($deploymentId); - $site = $this->getSite($siteId); - $this->assertEquals('ssr', $site['body']['adapter']); + $this->assertEventually(function () use ($siteId, &$site) { + $site = $this->getSite($siteId); + $this->assertEquals('ssr', $site['body']['adapter']); + }); $proxyClient = new Client(); $proxyClient->setEndpoint('http://' . $domain); @@ -416,6 +418,7 @@ class SitesCustomServerTest extends Scope $this->cleanupSite($siteId); } + #[Retry(count: 3)] public function testAdapterDetectionAstroStatic(): void { $siteId = $this->setupSite([ @@ -1507,6 +1510,7 @@ class SitesCustomServerTest extends Scope $this->cleanupSite($siteId); } + #[Retry(count: 3)] public function testSiteTemplate(): void { $template = $this->getTemplate('playground-for-astro'); diff --git a/tests/extensions/Async/Eventually.php b/tests/extensions/Async/Eventually.php index 9840b1a114..10f6b41eee 100644 --- a/tests/extensions/Async/Eventually.php +++ b/tests/extensions/Async/Eventually.php @@ -2,6 +2,7 @@ namespace Appwrite\Tests\Async; +use Appwrite\Tests\Async\Exceptions\Critical; use PHPUnit\Framework\Constraint\Constraint; final class Eventually extends Constraint @@ -23,6 +24,8 @@ final class Eventually extends Constraint try { $probe(); return true; + } catch (Critical $exception) { + throw $exception; } catch (\Exception $exception) { $lastException = $exception; } diff --git a/tests/extensions/Async/Exceptions/Critical.php b/tests/extensions/Async/Exceptions/Critical.php new file mode 100644 index 0000000000..92b6feb97e --- /dev/null +++ b/tests/extensions/Async/Exceptions/Critical.php @@ -0,0 +1,7 @@ +