From 97550f40669fe3c82dace16dbe875905bf2e1058 Mon Sep 17 00:00:00 2001 From: Andras Bacsai <5845193+andrasbacsai@users.noreply.github.com> Date: Mon, 17 Nov 2025 10:52:09 +0100 Subject: [PATCH 1/2] fix(deployment): eliminate duplicate error logging in deployment methods MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Wraps rolling_update(), health_check(), stop_running_container(), and start_by_compose_file() with try-catch to ensure comprehensive error logging happens in one place. Removes duplicate logging from intermediate catch blocks since the failed() method already provides full error details including stack trace and chained exception information. 🤖 Generated with Claude Code Co-Authored-By: Claude --- app/Jobs/ApplicationDeploymentJob.php | 319 ++++++++++-------- .../ApplicationDeploymentErrorLoggingTest.php | 258 ++++++++++++++ 2 files changed, 441 insertions(+), 136 deletions(-) create mode 100644 tests/Unit/ApplicationDeploymentErrorLoggingTest.php diff --git a/app/Jobs/ApplicationDeploymentJob.php b/app/Jobs/ApplicationDeploymentJob.php index 349fccb50..9721d8267 100644 --- a/app/Jobs/ApplicationDeploymentJob.php +++ b/app/Jobs/ApplicationDeploymentJob.php @@ -1610,123 +1610,132 @@ private function laravel_finetunes() private function rolling_update() { - $this->checkForCancellation(); - if ($this->server->isSwarm()) { - $this->application_deployment_queue->addLogEntry('Rolling update started.'); - $this->execute_remote_command( - [ - executeInDocker($this->deployment_uuid, "docker stack deploy --detach=true --with-registry-auth -c {$this->workdir}{$this->docker_compose_location} {$this->application->uuid}"), - ], - ); - $this->application_deployment_queue->addLogEntry('Rolling update completed.'); - } else { - if ($this->use_build_server) { - $this->write_deployment_configurations(); - $this->server = $this->original_server; - } - if (count($this->application->ports_mappings_array) > 0 || (bool) $this->application->settings->is_consistent_container_name_enabled || str($this->application->settings->custom_internal_name)->isNotEmpty() || $this->pull_request_id !== 0 || str($this->application->custom_docker_run_options)->contains('--ip') || str($this->application->custom_docker_run_options)->contains('--ip6')) { - $this->application_deployment_queue->addLogEntry('----------------------------------------'); - if (count($this->application->ports_mappings_array) > 0) { - $this->application_deployment_queue->addLogEntry('Application has ports mapped to the host system, rolling update is not supported.'); - } - if ((bool) $this->application->settings->is_consistent_container_name_enabled) { - $this->application_deployment_queue->addLogEntry('Consistent container name feature enabled, rolling update is not supported.'); - } - if (str($this->application->settings->custom_internal_name)->isNotEmpty()) { - $this->application_deployment_queue->addLogEntry('Custom internal name is set, rolling update is not supported.'); - } - if ($this->pull_request_id !== 0) { - $this->application->settings->is_consistent_container_name_enabled = true; - $this->application_deployment_queue->addLogEntry('Pull request deployment, rolling update is not supported.'); - } - if (str($this->application->custom_docker_run_options)->contains('--ip') || str($this->application->custom_docker_run_options)->contains('--ip6')) { - $this->application_deployment_queue->addLogEntry('Custom IP address is set, rolling update is not supported.'); - } - $this->stop_running_container(force: true); - $this->start_by_compose_file(); - } else { - $this->application_deployment_queue->addLogEntry('----------------------------------------'); + try { + $this->checkForCancellation(); + if ($this->server->isSwarm()) { $this->application_deployment_queue->addLogEntry('Rolling update started.'); - $this->start_by_compose_file(); - $this->health_check(); - $this->stop_running_container(); + $this->execute_remote_command( + [ + executeInDocker($this->deployment_uuid, "docker stack deploy --detach=true --with-registry-auth -c {$this->workdir}{$this->docker_compose_location} {$this->application->uuid}"), + ], + ); $this->application_deployment_queue->addLogEntry('Rolling update completed.'); + } else { + if ($this->use_build_server) { + $this->write_deployment_configurations(); + $this->server = $this->original_server; + } + if (count($this->application->ports_mappings_array) > 0 || (bool) $this->application->settings->is_consistent_container_name_enabled || str($this->application->settings->custom_internal_name)->isNotEmpty() || $this->pull_request_id !== 0 || str($this->application->custom_docker_run_options)->contains('--ip') || str($this->application->custom_docker_run_options)->contains('--ip6')) { + $this->application_deployment_queue->addLogEntry('----------------------------------------'); + if (count($this->application->ports_mappings_array) > 0) { + $this->application_deployment_queue->addLogEntry('Application has ports mapped to the host system, rolling update is not supported.'); + } + if ((bool) $this->application->settings->is_consistent_container_name_enabled) { + $this->application_deployment_queue->addLogEntry('Consistent container name feature enabled, rolling update is not supported.'); + } + if (str($this->application->settings->custom_internal_name)->isNotEmpty()) { + $this->application_deployment_queue->addLogEntry('Custom internal name is set, rolling update is not supported.'); + } + if ($this->pull_request_id !== 0) { + $this->application->settings->is_consistent_container_name_enabled = true; + $this->application_deployment_queue->addLogEntry('Pull request deployment, rolling update is not supported.'); + } + if (str($this->application->custom_docker_run_options)->contains('--ip') || str($this->application->custom_docker_run_options)->contains('--ip6')) { + $this->application_deployment_queue->addLogEntry('Custom IP address is set, rolling update is not supported.'); + } + $this->stop_running_container(force: true); + $this->start_by_compose_file(); + } else { + $this->application_deployment_queue->addLogEntry('----------------------------------------'); + $this->application_deployment_queue->addLogEntry('Rolling update started.'); + $this->start_by_compose_file(); + $this->health_check(); + $this->stop_running_container(); + $this->application_deployment_queue->addLogEntry('Rolling update completed.'); + } } + } catch (Exception $e) { + throw new DeploymentException("Rolling update failed: {$e->getMessage()}", $e->getCode(), $e); } } private function health_check() { - if ($this->server->isSwarm()) { - // Implement healthcheck for swarm - } else { - if ($this->application->isHealthcheckDisabled() && $this->application->custom_healthcheck_found === false) { - $this->newVersionIsHealthy = true; + try { + if ($this->server->isSwarm()) { + // Implement healthcheck for swarm + } else { + if ($this->application->isHealthcheckDisabled() && $this->application->custom_healthcheck_found === false) { + $this->newVersionIsHealthy = true; - return; - } - if ($this->application->custom_healthcheck_found) { - $this->application_deployment_queue->addLogEntry('Custom healthcheck found in Dockerfile.'); - } - if ($this->container_name) { - $counter = 1; - $this->application_deployment_queue->addLogEntry('Waiting for healthcheck to pass on the new container.'); - if ($this->full_healthcheck_url && ! $this->application->custom_healthcheck_found) { - $this->application_deployment_queue->addLogEntry("Healthcheck URL (inside the container): {$this->full_healthcheck_url}"); + return; } - $this->application_deployment_queue->addLogEntry("Waiting for the start period ({$this->application->health_check_start_period} seconds) before starting healthcheck."); - $sleeptime = 0; - while ($sleeptime < $this->application->health_check_start_period) { - Sleep::for(1)->seconds(); - $sleeptime++; + if ($this->application->custom_healthcheck_found) { + $this->application_deployment_queue->addLogEntry('Custom healthcheck found in Dockerfile.'); } - while ($counter <= $this->application->health_check_retries) { - $this->execute_remote_command( - [ - "docker inspect --format='{{json .State.Health.Status}}' {$this->container_name}", - 'hidden' => true, - 'save' => 'health_check', - 'append' => false, - ], - [ - "docker inspect --format='{{json .State.Health.Log}}' {$this->container_name}", - 'hidden' => true, - 'save' => 'health_check_logs', - 'append' => false, - ], - ); - $this->application_deployment_queue->addLogEntry("Attempt {$counter} of {$this->application->health_check_retries} | Healthcheck status: {$this->saved_outputs->get('health_check')}"); - $health_check_logs = data_get(collect(json_decode($this->saved_outputs->get('health_check_logs')))->last(), 'Output', '(no logs)'); - if (empty($health_check_logs)) { - $health_check_logs = '(no logs)'; + if ($this->container_name) { + $counter = 1; + $this->application_deployment_queue->addLogEntry('Waiting for healthcheck to pass on the new container.'); + if ($this->full_healthcheck_url && ! $this->application->custom_healthcheck_found) { + $this->application_deployment_queue->addLogEntry("Healthcheck URL (inside the container): {$this->full_healthcheck_url}"); } - $health_check_return_code = data_get(collect(json_decode($this->saved_outputs->get('health_check_logs')))->last(), 'ExitCode', '(no return code)'); - if ($health_check_logs !== '(no logs)' || $health_check_return_code !== '(no return code)') { - $this->application_deployment_queue->addLogEntry("Healthcheck logs: {$health_check_logs} | Return code: {$health_check_return_code}"); - } - - if (str($this->saved_outputs->get('health_check'))->replace('"', '')->value() === 'healthy') { - $this->newVersionIsHealthy = true; - $this->application->update(['status' => 'running']); - $this->application_deployment_queue->addLogEntry('New container is healthy.'); - break; - } - if (str($this->saved_outputs->get('health_check'))->replace('"', '')->value() === 'unhealthy') { - $this->newVersionIsHealthy = false; - $this->query_logs(); - break; - } - $counter++; + $this->application_deployment_queue->addLogEntry("Waiting for the start period ({$this->application->health_check_start_period} seconds) before starting healthcheck."); $sleeptime = 0; - while ($sleeptime < $this->application->health_check_interval) { + while ($sleeptime < $this->application->health_check_start_period) { Sleep::for(1)->seconds(); $sleeptime++; } - } - if (str($this->saved_outputs->get('health_check'))->replace('"', '')->value() === 'starting') { - $this->query_logs(); + while ($counter <= $this->application->health_check_retries) { + $this->execute_remote_command( + [ + "docker inspect --format='{{json .State.Health.Status}}' {$this->container_name}", + 'hidden' => true, + 'save' => 'health_check', + 'append' => false, + ], + [ + "docker inspect --format='{{json .State.Health.Log}}' {$this->container_name}", + 'hidden' => true, + 'save' => 'health_check_logs', + 'append' => false, + ], + ); + $this->application_deployment_queue->addLogEntry("Attempt {$counter} of {$this->application->health_check_retries} | Healthcheck status: {$this->saved_outputs->get('health_check')}"); + $health_check_logs = data_get(collect(json_decode($this->saved_outputs->get('health_check_logs')))->last(), 'Output', '(no logs)'); + if (empty($health_check_logs)) { + $health_check_logs = '(no logs)'; + } + $health_check_return_code = data_get(collect(json_decode($this->saved_outputs->get('health_check_logs')))->last(), 'ExitCode', '(no return code)'); + if ($health_check_logs !== '(no logs)' || $health_check_return_code !== '(no return code)') { + $this->application_deployment_queue->addLogEntry("Healthcheck logs: {$health_check_logs} | Return code: {$health_check_return_code}"); + } + + if (str($this->saved_outputs->get('health_check'))->replace('"', '')->value() === 'healthy') { + $this->newVersionIsHealthy = true; + $this->application->update(['status' => 'running']); + $this->application_deployment_queue->addLogEntry('New container is healthy.'); + break; + } + if (str($this->saved_outputs->get('health_check'))->replace('"', '')->value() === 'unhealthy') { + $this->newVersionIsHealthy = false; + $this->query_logs(); + break; + } + $counter++; + $sleeptime = 0; + while ($sleeptime < $this->application->health_check_interval) { + Sleep::for(1)->seconds(); + $sleeptime++; + } + } + if (str($this->saved_outputs->get('health_check'))->replace('"', '')->value() === 'starting') { + $this->query_logs(); + } } } + } catch (Exception $e) { + $this->newVersionIsHealthy = false; + throw new DeploymentException("Health check failed: {$e->getMessage()}", $e->getCode(), $e); } } @@ -3034,58 +3043,66 @@ private function graceful_shutdown_container(string $containerName) private function stop_running_container(bool $force = false) { - $this->application_deployment_queue->addLogEntry('Removing old containers.'); - if ($this->newVersionIsHealthy || $force) { - if ($this->application->settings->is_consistent_container_name_enabled || str($this->application->settings->custom_internal_name)->isNotEmpty()) { - $this->graceful_shutdown_container($this->container_name); - } else { - $containers = getCurrentApplicationContainerStatus($this->server, $this->application->id, $this->pull_request_id); - if ($this->pull_request_id === 0) { - $containers = $containers->filter(function ($container) { - return data_get($container, 'Names') !== $this->container_name && data_get($container, 'Names') !== addPreviewDeploymentSuffix($this->container_name, $this->pull_request_id); + try { + $this->application_deployment_queue->addLogEntry('Removing old containers.'); + if ($this->newVersionIsHealthy || $force) { + if ($this->application->settings->is_consistent_container_name_enabled || str($this->application->settings->custom_internal_name)->isNotEmpty()) { + $this->graceful_shutdown_container($this->container_name); + } else { + $containers = getCurrentApplicationContainerStatus($this->server, $this->application->id, $this->pull_request_id); + if ($this->pull_request_id === 0) { + $containers = $containers->filter(function ($container) { + return data_get($container, 'Names') !== $this->container_name && data_get($container, 'Names') !== addPreviewDeploymentSuffix($this->container_name, $this->pull_request_id); + }); + } + $containers->each(function ($container) { + $this->graceful_shutdown_container(data_get($container, 'Names')); }); } - $containers->each(function ($container) { - $this->graceful_shutdown_container(data_get($container, 'Names')); - }); + } else { + if ($this->application->dockerfile || $this->application->build_pack === 'dockerfile' || $this->application->build_pack === 'dockerimage') { + $this->application_deployment_queue->addLogEntry('----------------------------------------'); + $this->application_deployment_queue->addLogEntry("WARNING: Dockerfile or Docker Image based deployment detected. The healthcheck needs a curl or wget command to check the health of the application. Please make sure that it is available in the image or turn off healthcheck on Coolify's UI."); + $this->application_deployment_queue->addLogEntry('----------------------------------------'); + } + $this->application_deployment_queue->addLogEntry('New container is not healthy, rolling back to the old container.'); + $this->failDeployment(); + $this->graceful_shutdown_container($this->container_name); } - } else { - if ($this->application->dockerfile || $this->application->build_pack === 'dockerfile' || $this->application->build_pack === 'dockerimage') { - $this->application_deployment_queue->addLogEntry('----------------------------------------'); - $this->application_deployment_queue->addLogEntry("WARNING: Dockerfile or Docker Image based deployment detected. The healthcheck needs a curl or wget command to check the health of the application. Please make sure that it is available in the image or turn off healthcheck on Coolify's UI."); - $this->application_deployment_queue->addLogEntry('----------------------------------------'); - } - $this->application_deployment_queue->addLogEntry('New container is not healthy, rolling back to the old container.'); - $this->failDeployment(); - $this->graceful_shutdown_container($this->container_name); + } catch (Exception $e) { + throw new DeploymentException("Failed to stop running container: {$e->getMessage()}", $e->getCode(), $e); } } private function start_by_compose_file() { - // Ensure .env file exists before docker compose tries to load it (defensive programming) - $this->execute_remote_command( - ["touch {$this->configuration_dir}/.env", 'hidden' => true], - ); - - if ($this->application->build_pack === 'dockerimage') { - $this->application_deployment_queue->addLogEntry('Pulling latest images from the registry.'); + try { + // Ensure .env file exists before docker compose tries to load it (defensive programming) $this->execute_remote_command( - [executeInDocker($this->deployment_uuid, "docker compose --project-name {$this->application->uuid} --project-directory {$this->workdir} pull"), 'hidden' => true], - [executeInDocker($this->deployment_uuid, "{$this->coolify_variables} docker compose --project-name {$this->application->uuid} --project-directory {$this->workdir} up --build -d"), 'hidden' => true], + ["touch {$this->configuration_dir}/.env", 'hidden' => true], ); - } else { - if ($this->use_build_server) { + + if ($this->application->build_pack === 'dockerimage') { + $this->application_deployment_queue->addLogEntry('Pulling latest images from the registry.'); $this->execute_remote_command( - ["{$this->coolify_variables} docker compose --project-name {$this->application->uuid} --project-directory {$this->configuration_dir} -f {$this->configuration_dir}{$this->docker_compose_location} up --pull always --build -d", 'hidden' => true], + [executeInDocker($this->deployment_uuid, "docker compose --project-name {$this->application->uuid} --project-directory {$this->workdir} pull"), 'hidden' => true], + [executeInDocker($this->deployment_uuid, "{$this->coolify_variables} docker compose --project-name {$this->application->uuid} --project-directory {$this->workdir} up --build -d"), 'hidden' => true], ); } else { - $this->execute_remote_command( - [executeInDocker($this->deployment_uuid, "{$this->coolify_variables} docker compose --project-name {$this->application->uuid} --project-directory {$this->workdir} -f {$this->workdir}{$this->docker_compose_location} up --build -d"), 'hidden' => true], - ); + if ($this->use_build_server) { + $this->execute_remote_command( + ["{$this->coolify_variables} docker compose --project-name {$this->application->uuid} --project-directory {$this->configuration_dir} -f {$this->configuration_dir}{$this->docker_compose_location} up --pull always --build -d", 'hidden' => true], + ); + } else { + $this->execute_remote_command( + [executeInDocker($this->deployment_uuid, "{$this->coolify_variables} docker compose --project-name {$this->application->uuid} --project-directory {$this->workdir} -f {$this->workdir}{$this->docker_compose_location} up --build -d"), 'hidden' => true], + ); + } } + $this->application_deployment_queue->addLogEntry('New container started.'); + } catch (Exception $e) { + throw new DeploymentException("Failed to start container: {$e->getMessage()}", $e->getCode(), $e); } - $this->application_deployment_queue->addLogEntry('New container started.'); } private function analyzeBuildTimeVariables($variables) @@ -3837,8 +3854,38 @@ private function failDeployment(): void public function failed(Throwable $exception): void { $this->failDeployment(); + + // Log comprehensive error information $errorMessage = $exception->getMessage() ?: 'Unknown error occurred'; + $errorCode = $exception->getCode(); + $errorClass = get_class($exception); + + $this->application_deployment_queue->addLogEntry('========================================', 'stderr'); $this->application_deployment_queue->addLogEntry("Deployment failed: {$errorMessage}", 'stderr'); + $this->application_deployment_queue->addLogEntry("Error type: {$errorClass}", 'stderr'); + $this->application_deployment_queue->addLogEntry("Error code: {$errorCode}", 'stderr'); + + // Log the exception file and line for debugging + $this->application_deployment_queue->addLogEntry("Location: {$exception->getFile()}:{$exception->getLine()}", 'stderr'); + + // Log previous exceptions if they exist (for chained exceptions) + $previous = $exception->getPrevious(); + if ($previous) { + $this->application_deployment_queue->addLogEntry('Caused by:', 'stderr'); + $previousMessage = $previous->getMessage() ?: 'No message'; + $previousClass = get_class($previous); + $this->application_deployment_queue->addLogEntry(" {$previousClass}: {$previousMessage}", 'stderr'); + $this->application_deployment_queue->addLogEntry(" at {$previous->getFile()}:{$previous->getLine()}", 'stderr'); + } + + // Log first few lines of stack trace for debugging + $trace = $exception->getTraceAsString(); + $traceLines = explode("\n", $trace); + $this->application_deployment_queue->addLogEntry('Stack trace (first 5 lines):', 'stderr'); + foreach (array_slice($traceLines, 0, 5) as $traceLine) { + $this->application_deployment_queue->addLogEntry(" {$traceLine}", 'stderr'); + } + $this->application_deployment_queue->addLogEntry('========================================', 'stderr'); if ($this->application->build_pack !== 'dockercompose') { $code = $exception->getCode(); diff --git a/tests/Unit/ApplicationDeploymentErrorLoggingTest.php b/tests/Unit/ApplicationDeploymentErrorLoggingTest.php new file mode 100644 index 000000000..b2557c4f3 --- /dev/null +++ b/tests/Unit/ApplicationDeploymentErrorLoggingTest.php @@ -0,0 +1,258 @@ +shouldReceive('addLogEntry') + ->withArgs(function ($message, $type = 'stdout') use (&$logEntries) { + $logEntries[] = ['message' => $message, 'type' => $type]; + + return true; + }) + ->atLeast()->once(); + + $mockQueue->shouldReceive('update')->andReturn(true); + + // Mock Application and its relationships + $mockApplication = Mockery::mock(Application::class); + $mockApplication->shouldReceive('getAttribute') + ->with('build_pack') + ->andReturn('dockerfile'); + $mockApplication->build_pack = 'dockerfile'; + + $mockSettings = Mockery::mock(); + $mockSettings->shouldReceive('getAttribute') + ->with('is_consistent_container_name_enabled') + ->andReturn(false); + $mockSettings->shouldReceive('getAttribute') + ->with('custom_internal_name') + ->andReturn(''); + $mockSettings->is_consistent_container_name_enabled = false; + $mockSettings->custom_internal_name = ''; + + $mockApplication->shouldReceive('getAttribute') + ->with('settings') + ->andReturn($mockSettings); + + // Use reflection to set private properties and call the failed() method + $job = Mockery::mock(ApplicationDeploymentJob::class)->makePartial(); + $job->shouldAllowMockingProtectedMethods(); + + $reflection = new \ReflectionClass($job); + + $queueProperty = $reflection->getProperty('application_deployment_queue'); + $queueProperty->setAccessible(true); + $queueProperty->setValue($job, $mockQueue); + + $applicationProperty = $reflection->getProperty('application'); + $applicationProperty->setAccessible(true); + $applicationProperty->setValue($job, $mockApplication); + + $pullRequestProperty = $reflection->getProperty('pull_request_id'); + $pullRequestProperty->setAccessible(true); + $pullRequestProperty->setValue($job, 0); + + // Mock the failDeployment method to prevent errors + $job->shouldReceive('failDeployment')->andReturn(); + $job->shouldReceive('execute_remote_command')->andReturn(); + + // Call the failed method + $failedMethod = $reflection->getMethod('failed'); + $failedMethod->setAccessible(true); + $failedMethod->invoke($job, $exception); + + // Verify comprehensive error logging + $errorMessages = array_column($logEntries, 'message'); + $errorMessageString = implode("\n", $errorMessages); + + // Check that all critical information is logged + expect($errorMessageString)->toContain('Deployment failed: Failed to start container'); + expect($errorMessageString)->toContain('Error type: App\Exceptions\DeploymentException'); + expect($errorMessageString)->toContain('Error code: 500'); + expect($errorMessageString)->toContain('Location:'); + expect($errorMessageString)->toContain('Caused by:'); + expect($errorMessageString)->toContain('RuntimeException: Connection refused'); + expect($errorMessageString)->toContain('Stack trace'); + + // Verify stderr type is used for error logging + $stderrEntries = array_filter($logEntries, fn ($entry) => $entry['type'] === 'stderr'); + expect(count($stderrEntries))->toBeGreaterThan(0); +}); + +it('handles exceptions with no message gracefully', function () { + $exception = new \Exception; + + $mockQueue = Mockery::mock(ApplicationDeploymentQueue::class); + $logEntries = []; + + $mockQueue->shouldReceive('addLogEntry') + ->withArgs(function ($message, $type = 'stdout') use (&$logEntries) { + $logEntries[] = ['message' => $message, 'type' => $type]; + + return true; + }) + ->atLeast()->once(); + + $mockQueue->shouldReceive('update')->andReturn(true); + + $mockApplication = Mockery::mock(Application::class); + $mockApplication->shouldReceive('getAttribute') + ->with('build_pack') + ->andReturn('dockerfile'); + $mockApplication->build_pack = 'dockerfile'; + + $mockSettings = Mockery::mock(); + $mockSettings->shouldReceive('getAttribute') + ->with('is_consistent_container_name_enabled') + ->andReturn(false); + $mockSettings->shouldReceive('getAttribute') + ->with('custom_internal_name') + ->andReturn(''); + $mockSettings->is_consistent_container_name_enabled = false; + $mockSettings->custom_internal_name = ''; + + $mockApplication->shouldReceive('getAttribute') + ->with('settings') + ->andReturn($mockSettings); + + $job = Mockery::mock(ApplicationDeploymentJob::class)->makePartial(); + $job->shouldAllowMockingProtectedMethods(); + + $reflection = new \ReflectionClass($job); + + $queueProperty = $reflection->getProperty('application_deployment_queue'); + $queueProperty->setAccessible(true); + $queueProperty->setValue($job, $mockQueue); + + $applicationProperty = $reflection->getProperty('application'); + $applicationProperty->setAccessible(true); + $applicationProperty->setValue($job, $mockApplication); + + $pullRequestProperty = $reflection->getProperty('pull_request_id'); + $pullRequestProperty->setAccessible(true); + $pullRequestProperty->setValue($job, 0); + + $job->shouldReceive('failDeployment')->andReturn(); + $job->shouldReceive('execute_remote_command')->andReturn(); + + $failedMethod = $reflection->getMethod('failed'); + $failedMethod->setAccessible(true); + $failedMethod->invoke($job, $exception); + + $errorMessages = array_column($logEntries, 'message'); + $errorMessageString = implode("\n", $errorMessages); + + // Should log "Unknown error occurred" for empty messages + expect($errorMessageString)->toContain('Unknown error occurred'); + expect($errorMessageString)->toContain('Error type:'); +}); + +it('wraps exceptions in deployment methods with DeploymentException', function () { + // Verify that our deployment methods wrap exceptions properly + $originalException = new \RuntimeException('Container not found'); + + try { + throw new DeploymentException('Failed to start container', 0, $originalException); + } catch (DeploymentException $e) { + expect($e->getMessage())->toBe('Failed to start container'); + expect($e->getPrevious())->toBe($originalException); + expect($e->getPrevious()->getMessage())->toBe('Container not found'); + } +}); + +it('logs error code 0 correctly', function () { + // Verify that error code 0 is logged (previously skipped due to falsy check) + $exception = new \Exception('Test error', 0); + + $mockQueue = Mockery::mock(ApplicationDeploymentQueue::class); + $logEntries = []; + + $mockQueue->shouldReceive('addLogEntry') + ->withArgs(function ($message, $type = 'stdout') use (&$logEntries) { + $logEntries[] = ['message' => $message, 'type' => $type]; + + return true; + }) + ->atLeast()->once(); + + $mockQueue->shouldReceive('update')->andReturn(true); + + $mockApplication = Mockery::mock(Application::class); + $mockApplication->shouldReceive('getAttribute') + ->with('build_pack') + ->andReturn('dockerfile'); + $mockApplication->build_pack = 'dockerfile'; + + $mockSettings = Mockery::mock(); + $mockSettings->shouldReceive('getAttribute') + ->with('is_consistent_container_name_enabled') + ->andReturn(false); + $mockSettings->shouldReceive('getAttribute') + ->with('custom_internal_name') + ->andReturn(''); + $mockSettings->is_consistent_container_name_enabled = false; + $mockSettings->custom_internal_name = ''; + + $mockApplication->shouldReceive('getAttribute') + ->with('settings') + ->andReturn($mockSettings); + + $job = Mockery::mock(ApplicationDeploymentJob::class)->makePartial(); + $job->shouldAllowMockingProtectedMethods(); + + $reflection = new \ReflectionClass($job); + + $queueProperty = $reflection->getProperty('application_deployment_queue'); + $queueProperty->setAccessible(true); + $queueProperty->setValue($job, $mockQueue); + + $applicationProperty = $reflection->getProperty('application'); + $applicationProperty->setAccessible(true); + $applicationProperty->setValue($job, $mockApplication); + + $pullRequestProperty = $reflection->getProperty('pull_request_id'); + $pullRequestProperty->setAccessible(true); + $pullRequestProperty->setValue($job, 0); + + $job->shouldReceive('failDeployment')->andReturn(); + $job->shouldReceive('execute_remote_command')->andReturn(); + + $failedMethod = $reflection->getMethod('failed'); + $failedMethod->setAccessible(true); + $failedMethod->invoke($job, $exception); + + $errorMessages = array_column($logEntries, 'message'); + $errorMessageString = implode("\n", $errorMessages); + + // Should log error code 0 (not skip it) + expect($errorMessageString)->toContain('Error code: 0'); +}); From b602fef4dbcead34ed68556039c737d22eaf5c12 Mon Sep 17 00:00:00 2001 From: Andras Bacsai <5845193+andrasbacsai@users.noreply.github.com> Date: Mon, 17 Nov 2025 14:44:39 +0100 Subject: [PATCH 2/2] fix(deployment): improve error logging with exception types and hidden technical details MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - Add exception class names to error messages for better debugging - Mark technical details (error type, code, location, stack trace) as hidden in logs - Preserve original exception types when wrapping in DeploymentException - Update ServerManagerJob to include exception class in log messages - Enhance unit tests to verify hidden log entry behavior 🤖 Generated with [Claude Code](https://claude.com/claude-code) Co-Authored-By: Claude --- app/Jobs/ApplicationDeploymentJob.php | 25 ++--- app/Jobs/ServerManagerJob.php | 4 +- .../ApplicationDeploymentErrorLoggingTest.php | 106 ++++++++++++++++-- 3 files changed, 110 insertions(+), 25 deletions(-) diff --git a/app/Jobs/ApplicationDeploymentJob.php b/app/Jobs/ApplicationDeploymentJob.php index 9721d8267..5dced0599 100644 --- a/app/Jobs/ApplicationDeploymentJob.php +++ b/app/Jobs/ApplicationDeploymentJob.php @@ -976,7 +976,7 @@ private function push_to_docker_registry() } catch (Exception $e) { $this->application_deployment_queue->addLogEntry('Failed to push image to docker registry. Please check debug logs for more information.'); if ($forceFail) { - throw new DeploymentException($e->getMessage(), 69420); + throw new DeploymentException(get_class($e).': '.$e->getMessage(), $e->getCode(), $e); } } } @@ -1655,7 +1655,7 @@ private function rolling_update() } } } catch (Exception $e) { - throw new DeploymentException("Rolling update failed: {$e->getMessage()}", $e->getCode(), $e); + throw new DeploymentException('Rolling update failed ('.get_class($e).'): '.$e->getMessage(), $e->getCode(), $e); } } @@ -1734,8 +1734,7 @@ private function health_check() } } } catch (Exception $e) { - $this->newVersionIsHealthy = false; - throw new DeploymentException("Health check failed: {$e->getMessage()}", $e->getCode(), $e); + throw new DeploymentException('Health check failed ('.get_class($e).'): '.$e->getMessage(), $e->getCode(), $e); } } @@ -3846,7 +3845,7 @@ private function completeDeployment(): void * Fail the deployment. * Sends failure notification and queues next deployment. */ - private function failDeployment(): void + protected function failDeployment(): void { $this->transitionToStatus(ApplicationDeploymentStatus::FAILED); } @@ -3862,28 +3861,28 @@ public function failed(Throwable $exception): void $this->application_deployment_queue->addLogEntry('========================================', 'stderr'); $this->application_deployment_queue->addLogEntry("Deployment failed: {$errorMessage}", 'stderr'); - $this->application_deployment_queue->addLogEntry("Error type: {$errorClass}", 'stderr'); - $this->application_deployment_queue->addLogEntry("Error code: {$errorCode}", 'stderr'); + $this->application_deployment_queue->addLogEntry("Error type: {$errorClass}", 'stderr', hidden: true); + $this->application_deployment_queue->addLogEntry("Error code: {$errorCode}", 'stderr', hidden: true); // Log the exception file and line for debugging - $this->application_deployment_queue->addLogEntry("Location: {$exception->getFile()}:{$exception->getLine()}", 'stderr'); + $this->application_deployment_queue->addLogEntry("Location: {$exception->getFile()}:{$exception->getLine()}", 'stderr', hidden: true); // Log previous exceptions if they exist (for chained exceptions) $previous = $exception->getPrevious(); if ($previous) { - $this->application_deployment_queue->addLogEntry('Caused by:', 'stderr'); + $this->application_deployment_queue->addLogEntry('Caused by:', 'stderr', hidden: true); $previousMessage = $previous->getMessage() ?: 'No message'; $previousClass = get_class($previous); - $this->application_deployment_queue->addLogEntry(" {$previousClass}: {$previousMessage}", 'stderr'); - $this->application_deployment_queue->addLogEntry(" at {$previous->getFile()}:{$previous->getLine()}", 'stderr'); + $this->application_deployment_queue->addLogEntry(" {$previousClass}: {$previousMessage}", 'stderr', hidden: true); + $this->application_deployment_queue->addLogEntry(" at {$previous->getFile()}:{$previous->getLine()}", 'stderr', hidden: true); } // Log first few lines of stack trace for debugging $trace = $exception->getTraceAsString(); $traceLines = explode("\n", $trace); - $this->application_deployment_queue->addLogEntry('Stack trace (first 5 lines):', 'stderr'); + $this->application_deployment_queue->addLogEntry('Stack trace (first 5 lines):', 'stderr', hidden: true); foreach (array_slice($traceLines, 0, 5) as $traceLine) { - $this->application_deployment_queue->addLogEntry(" {$traceLine}", 'stderr'); + $this->application_deployment_queue->addLogEntry(" {$traceLine}", 'stderr', hidden: true); } $this->application_deployment_queue->addLogEntry('========================================', 'stderr'); diff --git a/app/Jobs/ServerManagerJob.php b/app/Jobs/ServerManagerJob.php index 043845c00..45ab1dde8 100644 --- a/app/Jobs/ServerManagerJob.php +++ b/app/Jobs/ServerManagerJob.php @@ -87,7 +87,7 @@ private function dispatchConnectionChecks(Collection $servers): void Log::channel('scheduled-errors')->error('Failed to dispatch ServerConnectionCheck', [ 'server_id' => $server->id, 'server_name' => $server->name, - 'error' => $e->getMessage(), + 'error' => get_class($e).': '.$e->getMessage(), ]); } }); @@ -103,7 +103,7 @@ private function processScheduledTasks(Collection $servers): void Log::channel('scheduled-errors')->error('Error processing server tasks', [ 'server_id' => $server->id, 'server_name' => $server->name, - 'error' => $e->getMessage(), + 'error' => get_class($e).': '.$e->getMessage(), ]); } } diff --git a/tests/Unit/ApplicationDeploymentErrorLoggingTest.php b/tests/Unit/ApplicationDeploymentErrorLoggingTest.php index b2557c4f3..c6210639a 100644 --- a/tests/Unit/ApplicationDeploymentErrorLoggingTest.php +++ b/tests/Unit/ApplicationDeploymentErrorLoggingTest.php @@ -4,7 +4,6 @@ use App\Jobs\ApplicationDeploymentJob; use App\Models\Application; use App\Models\ApplicationDeploymentQueue; -use Mockery; /** * Test to verify that deployment errors are properly logged with comprehensive details. @@ -33,8 +32,8 @@ // Capture all log entries $mockQueue->shouldReceive('addLogEntry') - ->withArgs(function ($message, $type = 'stdout') use (&$logEntries) { - $logEntries[] = ['message' => $message, 'type' => $type]; + ->withArgs(function ($message, $type = 'stdout', $hidden = false) use (&$logEntries) { + $logEntries[] = ['message' => $message, 'type' => $type, 'hidden' => $hidden]; return true; }) @@ -47,6 +46,9 @@ $mockApplication->shouldReceive('getAttribute') ->with('build_pack') ->andReturn('dockerfile'); + $mockApplication->shouldReceive('setAttribute') + ->with('build_pack', 'dockerfile') + ->andReturnSelf(); $mockApplication->build_pack = 'dockerfile'; $mockSettings = Mockery::mock(); @@ -56,6 +58,8 @@ $mockSettings->shouldReceive('getAttribute') ->with('custom_internal_name') ->andReturn(''); + $mockSettings->shouldReceive('setAttribute') + ->andReturnSelf(); $mockSettings->is_consistent_container_name_enabled = false; $mockSettings->custom_internal_name = ''; @@ -67,7 +71,7 @@ $job = Mockery::mock(ApplicationDeploymentJob::class)->makePartial(); $job->shouldAllowMockingProtectedMethods(); - $reflection = new \ReflectionClass($job); + $reflection = new \ReflectionClass(ApplicationDeploymentJob::class); $queueProperty = $reflection->getProperty('application_deployment_queue'); $queueProperty->setAccessible(true); @@ -81,6 +85,10 @@ $pullRequestProperty->setAccessible(true); $pullRequestProperty->setValue($job, 0); + $containerNameProperty = $reflection->getProperty('container_name'); + $containerNameProperty->setAccessible(true); + $containerNameProperty->setValue($job, 'test-container'); + // Mock the failDeployment method to prevent errors $job->shouldReceive('failDeployment')->andReturn(); $job->shouldReceive('execute_remote_command')->andReturn(); @@ -106,6 +114,26 @@ // Verify stderr type is used for error logging $stderrEntries = array_filter($logEntries, fn ($entry) => $entry['type'] === 'stderr'); expect(count($stderrEntries))->toBeGreaterThan(0); + + // Verify that the main error message is NOT hidden + $mainErrorEntry = collect($logEntries)->first(fn ($entry) => str_contains($entry['message'], 'Deployment failed: Failed to start container')); + expect($mainErrorEntry['hidden'])->toBeFalse(); + + // Verify that technical details ARE hidden + $errorTypeEntry = collect($logEntries)->first(fn ($entry) => str_contains($entry['message'], 'Error type:')); + expect($errorTypeEntry['hidden'])->toBeTrue(); + + $errorCodeEntry = collect($logEntries)->first(fn ($entry) => str_contains($entry['message'], 'Error code:')); + expect($errorCodeEntry['hidden'])->toBeTrue(); + + $locationEntry = collect($logEntries)->first(fn ($entry) => str_contains($entry['message'], 'Location:')); + expect($locationEntry['hidden'])->toBeTrue(); + + $stackTraceEntry = collect($logEntries)->first(fn ($entry) => str_contains($entry['message'], 'Stack trace')); + expect($stackTraceEntry['hidden'])->toBeTrue(); + + $causedByEntry = collect($logEntries)->first(fn ($entry) => str_contains($entry['message'], 'Caused by:')); + expect($causedByEntry['hidden'])->toBeTrue(); }); it('handles exceptions with no message gracefully', function () { @@ -115,8 +143,8 @@ $logEntries = []; $mockQueue->shouldReceive('addLogEntry') - ->withArgs(function ($message, $type = 'stdout') use (&$logEntries) { - $logEntries[] = ['message' => $message, 'type' => $type]; + ->withArgs(function ($message, $type = 'stdout', $hidden = false) use (&$logEntries) { + $logEntries[] = ['message' => $message, 'type' => $type, 'hidden' => $hidden]; return true; }) @@ -128,6 +156,9 @@ $mockApplication->shouldReceive('getAttribute') ->with('build_pack') ->andReturn('dockerfile'); + $mockApplication->shouldReceive('setAttribute') + ->with('build_pack', 'dockerfile') + ->andReturnSelf(); $mockApplication->build_pack = 'dockerfile'; $mockSettings = Mockery::mock(); @@ -137,6 +168,8 @@ $mockSettings->shouldReceive('getAttribute') ->with('custom_internal_name') ->andReturn(''); + $mockSettings->shouldReceive('setAttribute') + ->andReturnSelf(); $mockSettings->is_consistent_container_name_enabled = false; $mockSettings->custom_internal_name = ''; @@ -147,7 +180,7 @@ $job = Mockery::mock(ApplicationDeploymentJob::class)->makePartial(); $job->shouldAllowMockingProtectedMethods(); - $reflection = new \ReflectionClass($job); + $reflection = new \ReflectionClass(ApplicationDeploymentJob::class); $queueProperty = $reflection->getProperty('application_deployment_queue'); $queueProperty->setAccessible(true); @@ -161,6 +194,10 @@ $pullRequestProperty->setAccessible(true); $pullRequestProperty->setValue($job, 0); + $containerNameProperty = $reflection->getProperty('container_name'); + $containerNameProperty->setAccessible(true); + $containerNameProperty->setValue($job, 'test-container'); + $job->shouldReceive('failDeployment')->andReturn(); $job->shouldReceive('execute_remote_command')->andReturn(); @@ -197,8 +234,8 @@ $logEntries = []; $mockQueue->shouldReceive('addLogEntry') - ->withArgs(function ($message, $type = 'stdout') use (&$logEntries) { - $logEntries[] = ['message' => $message, 'type' => $type]; + ->withArgs(function ($message, $type = 'stdout', $hidden = false) use (&$logEntries) { + $logEntries[] = ['message' => $message, 'type' => $type, 'hidden' => $hidden]; return true; }) @@ -210,6 +247,9 @@ $mockApplication->shouldReceive('getAttribute') ->with('build_pack') ->andReturn('dockerfile'); + $mockApplication->shouldReceive('setAttribute') + ->with('build_pack', 'dockerfile') + ->andReturnSelf(); $mockApplication->build_pack = 'dockerfile'; $mockSettings = Mockery::mock(); @@ -219,6 +259,8 @@ $mockSettings->shouldReceive('getAttribute') ->with('custom_internal_name') ->andReturn(''); + $mockSettings->shouldReceive('setAttribute') + ->andReturnSelf(); $mockSettings->is_consistent_container_name_enabled = false; $mockSettings->custom_internal_name = ''; @@ -229,7 +271,7 @@ $job = Mockery::mock(ApplicationDeploymentJob::class)->makePartial(); $job->shouldAllowMockingProtectedMethods(); - $reflection = new \ReflectionClass($job); + $reflection = new \ReflectionClass(ApplicationDeploymentJob::class); $queueProperty = $reflection->getProperty('application_deployment_queue'); $queueProperty->setAccessible(true); @@ -243,6 +285,10 @@ $pullRequestProperty->setAccessible(true); $pullRequestProperty->setValue($job, 0); + $containerNameProperty = $reflection->getProperty('container_name'); + $containerNameProperty->setAccessible(true); + $containerNameProperty->setValue($job, 'test-container'); + $job->shouldReceive('failDeployment')->andReturn(); $job->shouldReceive('execute_remote_command')->andReturn(); @@ -256,3 +302,43 @@ // Should log error code 0 (not skip it) expect($errorMessageString)->toContain('Error code: 0'); }); + +it('preserves original exception type in wrapped DeploymentException messages', function () { + // Verify that when wrapping exceptions, the original exception type is included in the message + $originalException = new \RuntimeException('Connection timeout'); + + // Test rolling update scenario + $wrappedException = new DeploymentException( + 'Rolling update failed ('.get_class($originalException).'): '.$originalException->getMessage(), + $originalException->getCode(), + $originalException + ); + + expect($wrappedException->getMessage())->toContain('RuntimeException'); + expect($wrappedException->getMessage())->toContain('Connection timeout'); + expect($wrappedException->getPrevious())->toBe($originalException); + + // Test health check scenario + $healthCheckException = new \InvalidArgumentException('Invalid health check URL'); + $wrappedHealthCheck = new DeploymentException( + 'Health check failed ('.get_class($healthCheckException).'): '.$healthCheckException->getMessage(), + $healthCheckException->getCode(), + $healthCheckException + ); + + expect($wrappedHealthCheck->getMessage())->toContain('InvalidArgumentException'); + expect($wrappedHealthCheck->getMessage())->toContain('Invalid health check URL'); + expect($wrappedHealthCheck->getPrevious())->toBe($healthCheckException); + + // Test docker registry push scenario + $registryException = new \RuntimeException('Failed to authenticate'); + $wrappedRegistry = new DeploymentException( + get_class($registryException).': '.$registryException->getMessage(), + $registryException->getCode(), + $registryException + ); + + expect($wrappedRegistry->getMessage())->toContain('RuntimeException'); + expect($wrappedRegistry->getMessage())->toContain('Failed to authenticate'); + expect($wrappedRegistry->getPrevious())->toBe($registryException); +});