diff --git a/CHANGELOG.md b/CHANGELOG.md index e337e762..ce6a0496 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,7 +6,7 @@ All notable changes to this project will be documented in this file, in reverse ### Added -- Nothing. +- [#164](https://github.com/scoutapp/scout-apm-php/pull/164) Added additional logging and testing around core-agent launching ### Changed diff --git a/src/Agent.php b/src/Agent.php index 549886ec..8d061931 100644 --- a/src/Agent.php +++ b/src/Agent.php @@ -20,6 +20,8 @@ use Scoutapm\Connector\SocketConnector; use Scoutapm\CoreAgent\AutomaticDownloadAndLaunchManager; use Scoutapm\CoreAgent\Downloader; +use Scoutapm\CoreAgent\Launcher; +use Scoutapm\CoreAgent\Verifier; use Scoutapm\Events\Metadata; use Scoutapm\Events\RegisterMessage; use Scoutapm\Events\Request\Request; @@ -190,15 +192,27 @@ public function connect() : void $this->config->get(ConfigKey::APPLICATION_NAME), $this->extensionVersion() )); - $manager = new AutomaticDownloadAndLaunchManager( + $coreAgentDownloadPath = $this->config->get(ConfigKey::CORE_AGENT_DIRECTORY) . '/' . $this->config->get(ConfigKey::CORE_AGENT_FULL_NAME); + $manager = new AutomaticDownloadAndLaunchManager( $this->config, $this->logger, new Downloader( - $this->config->get(ConfigKey::CORE_AGENT_DIRECTORY) . '/' . $this->config->get(ConfigKey::CORE_AGENT_FULL_NAME), + $coreAgentDownloadPath, $this->config->get(ConfigKey::CORE_AGENT_FULL_NAME), $this->logger, $this->config->get(ConfigKey::CORE_AGENT_DOWNLOAD_URL), $this->config->get(ConfigKey::CORE_AGENT_PERMISSIONS) + ), + new Launcher( + $this->logger, + $this->config->get(ConfigKey::CORE_AGENT_SOCKET_PATH), + $this->config->get(ConfigKey::CORE_AGENT_LOG_LEVEL), + $this->config->get(ConfigKey::CORE_AGENT_LOG_FILE), + $this->config->get(ConfigKey::CORE_AGENT_CONFIG_FILE) + ), + new Verifier( + $this->logger, + $coreAgentDownloadPath ) ); $manager->launch(); diff --git a/src/CoreAgent/AutomaticDownloadAndLaunchManager.php b/src/CoreAgent/AutomaticDownloadAndLaunchManager.php index 46675d24..883847f1 100644 --- a/src/CoreAgent/AutomaticDownloadAndLaunchManager.php +++ b/src/CoreAgent/AutomaticDownloadAndLaunchManager.php @@ -7,12 +7,6 @@ use Psr\Log\LoggerInterface; use Scoutapm\Config; use Scoutapm\Config\ConfigKey; -use Throwable; -use function array_map; -use function exec; -use function file_get_contents; -use function hash; -use function implode; use function sprintf; /** @internal */ @@ -20,26 +14,28 @@ final class AutomaticDownloadAndLaunchManager implements Manager { /** @var Config */ private $config; - /** @var LoggerInterface */ private $logger; - - /** @var string */ - private $coreAgentDir; - /** @var Downloader */ private $downloader; - - /** @var string|null */ - private $coreAgentBinPath; - - public function __construct(Config $config, LoggerInterface $logger, Downloader $downloader) - { - $this->config = $config; - $this->logger = $logger; - $this->coreAgentDir = $config->get(ConfigKey::CORE_AGENT_DIRECTORY) . '/' . $config->get(ConfigKey::CORE_AGENT_FULL_NAME); + /** @var Launcher */ + private $launcher; + /** @var Verifier */ + private $verifier; + + public function __construct( + Config $config, + LoggerInterface $logger, + Downloader $downloader, + Launcher $launcher, + Verifier $verifier + ) { + $this->config = $config; + $this->logger = $logger; $this->downloader = $downloader; + $this->launcher = $launcher; + $this->verifier = $verifier; } public function launch() : bool @@ -53,7 +49,8 @@ public function launch() : bool return false; } - if (! $this->verify()) { + $coreAgentBinPath = $this->verifier->verify(); + if ($coreAgentBinPath === null) { if (! $this->config->get(ConfigKey::CORE_AGENT_DOWNLOAD_ENABLED)) { $this->logger->debug(sprintf( "Not attempting to download Core Agent due to '%s' setting.", @@ -63,10 +60,11 @@ public function launch() : bool return false; } - $this->download(); + $this->downloader->download(); } - if (! $this->verify()) { + $coreAgentBinPath = $this->verifier->verify(); + if ($coreAgentBinPath === null) { $this->logger->debug( 'Failed to verify Core Agent. Not launching Core Agent.' ); @@ -74,89 +72,6 @@ public function launch() : bool return false; } - return $this->run(); - } - - /** - * Initiate download of the agent - */ - private function download() : void - { - $this->downloader->download(); - } - - private function verify() : bool - { - // Check for a well formed manifest - $manifest = new Manifest($this->coreAgentDir . '/manifest.json', $this->logger); - if (! $manifest->isValid()) { - $this->logger->debug('Core Agent verification failed: Manifest is not valid.'); - $this->coreAgentBinPath = null; - - return false; - } - - // Check that the hash matches - $binPath = $this->coreAgentDir . '/' . $manifest->binaryName(); - if (hash('sha256', file_get_contents($binPath)) === $manifest->hashOfBinary()) { - $this->coreAgentBinPath = $binPath; - - return true; - } - - $this->logger->debug('Core Agent verification failed: SHA mismatch.'); - $this->coreAgentBinPath = null; - - return false; - } - - private function run() : bool - { - $this->logger->debug('Core Agent Launch in Progress'); - try { - $logLevel = $this->config->get(ConfigKey::CORE_AGENT_LOG_LEVEL); - $logFile = $this->config->get(ConfigKey::CORE_AGENT_LOG_FILE); - $configFile = $this->config->get(ConfigKey::CORE_AGENT_CONFIG_FILE); - - if ($logFile === null) { - $logFile = '/dev/null'; - } - - $commandParts = [ - $this->coreAgentBinPath, - 'start', - '--daemonize', - 'true', - '--log-file', - $logFile, - ]; - - if ($logLevel !== null) { - $commandParts[] = '--log-level'; - $commandParts[] = $logLevel; - } - - if ($configFile !== null) { - $commandParts[] = '--config-file'; - $commandParts[] = $configFile; - } - - $commandParts[] = '--socket'; - $commandParts[] = $this->config->get(ConfigKey::CORE_AGENT_SOCKET_PATH); - - $escapedCommand = implode(' ', array_map('escapeshellarg', $commandParts)); - - $this->logger->debug(sprintf('Launching core agent with command: %s', $escapedCommand)); - exec($escapedCommand); - - return true; - } catch (Throwable $e) { - $this->logger->debug( - sprintf('Failed to launch core agent - exception %s', $e->getMessage()), - ['exception' => $e] - ); - - return false; - } + return $this->launcher->launch($coreAgentBinPath); } } diff --git a/src/CoreAgent/Launcher.php b/src/CoreAgent/Launcher.php new file mode 100644 index 00000000..8944118c --- /dev/null +++ b/src/CoreAgent/Launcher.php @@ -0,0 +1,132 @@ +logger = $logger; + $this->coreAgentSocketPath = $coreAgentSocketPath; + $this->coreAgentLogLevel = $coreAgentLogLevel; + $this->coreAgentConfigFile = $coreAgentConfigFile; + $this->coreAgentLogFile = $coreAgentLogFile ?? '/dev/null'; + } + + public function launch(string $coreAgentBinaryPath) : bool + { + if (! $this->phpCanExec()) { + return false; + } + + $this->logger->debug('Core Agent Launch in Progress'); + try { + $commandParts = [ + $coreAgentBinaryPath, + 'start', + '--daemonize', + 'true', + '--log-file', + $this->coreAgentLogFile, + ]; + + if ($this->coreAgentLogLevel !== null) { + $commandParts[] = '--log-level'; + $commandParts[] = $this->coreAgentLogLevel; + } + + if ($this->coreAgentConfigFile !== null) { + $commandParts[] = '--config-file'; + $commandParts[] = $this->coreAgentConfigFile; + } + + $commandParts[] = '--socket'; + $commandParts[] = $this->coreAgentSocketPath; + + $escapedCommand = implode(' ', array_map('escapeshellarg', $commandParts)); + + $this->logger->debug(sprintf('Launching core agent with command: %s', $escapedCommand)); + + exec($escapedCommand . ' 2>&1', $output, $exitStatus); + + $this->assertOutputDoesNotContainErrors(implode("\n", $output), $exitStatus); + + return true; + } catch (Throwable $e) { + $this->logger->debug( + sprintf('Failed to launch core agent - exception %s', $e->getMessage()), + ['exception' => $e] + ); + + return false; + } + } + + private function phpCanExec() : bool + { + if (! function_exists('exec')) { + $this->logger->warning('PHP function exec is not available'); + + return false; + } + + if (in_array('exec', array_map('trim', explode(',', ini_get('disable_functions'))))) { + $this->logger->warning('PHP function exec is in disabled_functions'); + + return false; + } + + if (exec('echo scoutapm') !== 'scoutapm') { + $this->logger->warning('PHP function exec did not return expected value'); + + return false; + } + + $this->logger->debug('exec is available'); + + return true; + } + + private function assertOutputDoesNotContainErrors(string $output, int $exitStatus) : void + { + if (stripos($output, "version `GLIBC_2.18' not found") !== false) { + throw new RuntimeException('core-agent currently needs at least glibc 2.18. Output: ' . $output); + } + + if ($exitStatus !== 0) { + throw new RuntimeException('core-agent exited with non-zero status. Output: ' . $output); + } + } +} diff --git a/src/CoreAgent/Verifier.php b/src/CoreAgent/Verifier.php new file mode 100644 index 00000000..94fcc953 --- /dev/null +++ b/src/CoreAgent/Verifier.php @@ -0,0 +1,46 @@ +logger = $logger; + $this->coreAgentDownloadPath = $coreAgentDownloadPath; + } + + public function verify() : ?string + { + // Check for a well formed manifest + $manifest = new Manifest($this->coreAgentDownloadPath . '/manifest.json', $this->logger); + if (! $manifest->isValid()) { + $this->logger->debug('Core Agent verification failed: Manifest is not valid.'); + + return null; + } + + // Check that the hash matches + $binPath = $this->coreAgentDownloadPath . '/' . $manifest->binaryName(); + if (hash_equals($manifest->hashOfBinary(), hash_file('sha256', $binPath))) { + return $binPath; + } + + $this->logger->debug('Core Agent verification failed: SHA mismatch.'); + + return null; + } +} diff --git a/tests/Unit/AgentTest.php b/tests/Unit/AgentTest.php index 7d356b28..0aa9af43 100644 --- a/tests/Unit/AgentTest.php +++ b/tests/Unit/AgentTest.php @@ -449,6 +449,8 @@ public function testRequestIsResetAfterCallingSend() : void ConfigKey::APPLICATION_NAME => 'My test app', ConfigKey::APPLICATION_KEY => uniqid('applicationKey', true), ConfigKey::MONITORING_ENABLED => true, + ConfigKey::CORE_AGENT_DOWNLOAD_ENABLED => false, + ConfigKey::CORE_AGENT_LAUNCH_ENABLED => false, ]); $requestBeforeSend = $agent->getRequest(); @@ -518,6 +520,7 @@ public function testAgentLogsWarningWhenFailingToConnectToSocket() : void ConfigKey::MONITORING_ENABLED => true, ConfigKey::CORE_AGENT_SOCKET_PATH => '/socket/path/should/not/exist', ConfigKey::CORE_AGENT_DOWNLOAD_ENABLED => false, + ConfigKey::CORE_AGENT_LAUNCH_ENABLED => false, ]), $this->logger, new DevNullCache() @@ -545,6 +548,7 @@ public function testAgentLogsDebugWhenConnectedToSocket() : void ConfigKey::APPLICATION_KEY => uniqid('applicationKey', true), ConfigKey::MONITORING_ENABLED => true, ConfigKey::CORE_AGENT_DOWNLOAD_ENABLED => false, + ConfigKey::CORE_AGENT_LAUNCH_ENABLED => false, ]); $agent->connect(); @@ -736,6 +740,8 @@ public function testOlderVersionsOfExtensionIsNotedInLogs() : void ConfigKey::APPLICATION_NAME => 'My test app', ConfigKey::APPLICATION_KEY => uniqid('applicationKey', true), ConfigKey::MONITORING_ENABLED => true, + ConfigKey::CORE_AGENT_DOWNLOAD_ENABLED => false, + ConfigKey::CORE_AGENT_LAUNCH_ENABLED => false, ]); $this->phpExtension @@ -755,6 +761,8 @@ public function testNewerVersionsOfExtensionIsNotLogged() : void ConfigKey::APPLICATION_NAME => 'My test app', ConfigKey::APPLICATION_KEY => uniqid('applicationKey', true), ConfigKey::MONITORING_ENABLED => true, + ConfigKey::CORE_AGENT_DOWNLOAD_ENABLED => false, + ConfigKey::CORE_AGENT_LAUNCH_ENABLED => false, ]); $this->phpExtension diff --git a/tests/Unit/CoreAgent/CoreAgentManagerTest.php b/tests/Unit/CoreAgent/CoreAgentManagerTest.php deleted file mode 100644 index 488855ca..00000000 --- a/tests/Unit/CoreAgent/CoreAgentManagerTest.php +++ /dev/null @@ -1,27 +0,0 @@ -createMock(LoggerInterface::class), - $this->createMock(Downloader::class) - ); - - // Provided by the DefaultConfig - self::assertNotNull($cam); - } -} diff --git a/tests/Unit/CoreAgent/LauncherTest.php b/tests/Unit/CoreAgent/LauncherTest.php new file mode 100644 index 00000000..e61ca013 --- /dev/null +++ b/tests/Unit/CoreAgent/LauncherTest.php @@ -0,0 +1,60 @@ +launch(__DIR__ . '/emulated-core-agent-glibc-error.sh')); + $logger->hasDebugThatContains('core-agent currently needs at least glibc 2.18'); + } + + public function testLaunchCoreAgentWithNonZeroExitCodeIsCaught() : void + { + $logger = new TestLogger(); + + $launcher = new Launcher( + $logger, + 'socket-path.sock', + null, + null, + null + ); + + self::assertFalse($launcher->launch(__DIR__ . '/emulated-unknown-error.sh')); + $logger->hasDebugThatContains('core-agent exited with non-zero status. Output: Something bad went wrong'); + } + + public function testCoreAgentCanBeLaunched() : void + { + $logger = new TestLogger(); + + $launcher = new Launcher( + $logger, + '/tmp/socket-path.sock', + 'TRACE', + '/tmp/core-agent.log', + '/tmp/core-agent-config.ini' + ); + + self::assertTrue($launcher->launch(__DIR__ . '/emulated-happy-path.sh')); + } +} diff --git a/tests/Unit/CoreAgent/emulated-core-agent-glibc-error.sh b/tests/Unit/CoreAgent/emulated-core-agent-glibc-error.sh new file mode 100755 index 00000000..88754c69 --- /dev/null +++ b/tests/Unit/CoreAgent/emulated-core-agent-glibc-error.sh @@ -0,0 +1,6 @@ +#!/usr/bin/env bash + +set -euo pipefail + +>&2 echo "/tmp/scout_apm_core/scout_apm_core-v1.2.7-x86_64-unknown-linux-gnu/core-agent: /lib64/libc.so.6: version \`GLIBC_2.18' not found (required by /tmp/scout_apm_core/scout_apm_core-v1.2.7-x86_64-unknown-linux-gnu/core-agent)" +exit 1 diff --git a/tests/Unit/CoreAgent/emulated-happy-path.sh b/tests/Unit/CoreAgent/emulated-happy-path.sh new file mode 100755 index 00000000..37520e1e --- /dev/null +++ b/tests/Unit/CoreAgent/emulated-happy-path.sh @@ -0,0 +1,13 @@ +#!/usr/bin/env bash + +set -euo pipefail + +EXPECTED_PARAMS="start --daemonize true --log-file /tmp/core-agent.log --log-level TRACE --config-file /tmp/core-agent-config.ini --socket /tmp/socket-path.sock" +ACTUAL_PARAMS=$* + +if [ "$ACTUAL_PARAMS" != "$EXPECTED_PARAMS" ]; then + >&2 printf "Script params did not match expectations.\n\nExpected: %s\nActual : %s\n" "$EXPECTED_PARAMS" "$ACTUAL_PARAMS" + exit 1 +fi + +exit 0 diff --git a/tests/Unit/CoreAgent/emulated-unknown-error.sh b/tests/Unit/CoreAgent/emulated-unknown-error.sh new file mode 100755 index 00000000..d0f31983 --- /dev/null +++ b/tests/Unit/CoreAgent/emulated-unknown-error.sh @@ -0,0 +1,6 @@ +#!/usr/bin/env bash + +set -euo pipefail + +>&2 echo "Something bad went wrong" +exit 1