Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Log the debuggers found via the logger instead of ConsoleOutput #1258

Open
wants to merge 18 commits into
base: master
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
36 changes: 23 additions & 13 deletions src/Command/RunCommand.php
Expand Up @@ -484,16 +484,22 @@ private function startUp(

$this->installTestFrameworkIfNeeded($container, $io);

// Check if the application needs a restart _after_ configuring the command or adding
// a missing test framework
XdebugHandler::check($logger);

$application = $this->getApplication();

$io->writeln($application->getHelp());
$io->newLine();
// Log the detected debuggers _before_ a restart to ensure xdebug is not left out; log it
// only once though
if (!XdebugHandler::hasBeenRestarted()) {
$io->writeln($application->getHelp());
$io->newLine();

$this->logRunningWithDebugger($consoleOutput);
$this->logRunningWithDebugger($logger);
} else {
$logger->notice('Xdebug has been disabled for the main process');
}

// Check if the application needs a restart _after_ configuring the command or adding
// a missing test framework
XdebugHandler::check($logger);

if (!$application->isAutoExitEnabled()) {
// When we're not in control of exit codes, that means it's the caller
Expand Down Expand Up @@ -555,14 +561,18 @@ private function includeUserBootstrap(Configuration $config): void
})($bootstrap);
}

private function logRunningWithDebugger(ConsoleOutput $consoleOutput): void
private function logRunningWithDebugger(LoggerInterface $logger): void
{
if (PHP_SAPI === 'phpdbg') {
$consoleOutput->logRunningWithDebugger(PHP_SAPI);
} elseif (extension_loaded('xdebug')) {
$consoleOutput->logRunningWithDebugger('Xdebug');
} elseif (extension_loaded('pcov')) {
$consoleOutput->logRunningWithDebugger('PCOV');
$logger->notice('phpdbg detected');
}

if (extension_loaded('pcov')) {
$logger->notice('pcov detected');
}

if (extension_loaded('xdebug')) {
$logger->notice('Xdebug detected');
}
}
}
6 changes: 0 additions & 6 deletions src/Console/ConsoleOutput.php
Expand Up @@ -46,7 +46,6 @@
*/
class ConsoleOutput
{
private const RUNNING_WITH_DEBUGGER_NOTE = 'You are running Infection with %s enabled.';
private const MIN_MSI_CAN_GET_INCREASED_NOTICE = 'The %s is %s%% percentage points over the required %s. Consider increasing the required %s percentage the next time you run Infection.';

private ConsoleLogger $logger;
Expand Down Expand Up @@ -106,11 +105,6 @@ public function logMinCoveredCodeMsiCanGetIncreasedNotice(float $minMsi, float $
);
}

public function logRunningWithDebugger(string $debugger): void
{
$this->logger->notice(sprintf(self::RUNNING_WITH_DEBUGGER_NOTE, $debugger));
}

public function logNotInControlOfExitCodes(): void
{
$this->logger->warning(
Expand Down
6 changes: 6 additions & 0 deletions src/Console/XdebugHandler.php
Expand Up @@ -35,6 +35,7 @@

namespace Infection\Console;

use function array_key_exists;
use Composer\XdebugHandler\XdebugHandler as ComposerXdebugHandler;
use Infection\CannotBeInstantiated;
use Psr\Log\LoggerInterface;
Expand All @@ -58,4 +59,9 @@ public static function check(LoggerInterface $logger): void
->check()
;
}

public static function hasBeenRestarted(): bool
{
return array_key_exists(self::PREFIX . ComposerXdebugHandler::SUFFIX_ALLOW, $_SERVER);
}
}
18 changes: 12 additions & 6 deletions src/Logger/ConsoleLogger.php
Expand Up @@ -108,26 +108,32 @@ public function log($level, $message, array $context = []): void
);

$output = $this->io->getOutput();
$verbosityLevel = self::VERBOSITY_LEVEL_MAP[$level];

// The if condition check isn't necessary per se – it's the same one that $output will do
// internally anyway. We only do it for efficiency here as the message formatting is
// relatively expensive
if ($output->getVerbosity() < self::VERBOSITY_LEVEL_MAP[$level]) {
if ($output->getVerbosity() < $verbosityLevel) {
return;
}

$interpolatedMessage = $this->interpolate($message, $context);

if (!isset($context['block'])) {
$output->writeln(
sprintf(
if ($level !== LogLevel::NOTICE) {
// If message is hidden with normal verbosity or is for an error level, we wrap
// the message in tags for a better color output
$message = sprintf(
'<%1$s>[%2$s] %3$s</%1$s>',
self::FORMAT_LEVEL_MAP[$level],
$level,
$interpolatedMessage
),
self::VERBOSITY_LEVEL_MAP[$level]
);
);
} else {
$message = $interpolatedMessage;
}

$output->writeln($message, $verbosityLevel);

return;
}
Expand Down
6 changes: 3 additions & 3 deletions src/Resource/Memory/MemoryLimiterEnvironment.php
Expand Up @@ -35,7 +35,7 @@

namespace Infection\Resource\Memory;

use Composer\XdebugHandler\XdebugHandler;
use Infection\Console\XdebugHandler;
use const PHP_SAPI;
use function Safe\ini_get;

Expand All @@ -55,7 +55,7 @@ public function hasMemoryLimitSet(): bool
public function isUsingSystemIni(): bool
{
// Under phpdbg we're using a system php.ini and we can't add a memory limit there. If there
// is no skipped version of xdebug handler we are also using the system php ini
return PHP_SAPI === 'phpdbg' || XdebugHandler::getSkippedVersion() === '';
// is no skipped version of Xdebug handler we are also using the system php ini
return PHP_SAPI === 'phpdbg' || !XdebugHandler::hasBeenRestarted();
}
}
14 changes: 0 additions & 14 deletions tests/phpunit/Console/ConsoleOutputTest.php
Expand Up @@ -99,20 +99,6 @@ public function test_log_unknown_verbosity_option(): void
! [NOTE] Running infection with an unknown log-verbosity option, falling back to default option


TXT
,
normalize_trailing_spaces($this->output->fetch())
);
}

public function test_log_running_with_debugger(): void
{
$this->consoleOutput->logRunningWithDebugger('foo');

$this->assertSame(
<<<'TXT'
[notice] You are running Infection with foo enabled.

TXT
,
normalize_trailing_spaces($this->output->fetch())
Expand Down
105 changes: 100 additions & 5 deletions tests/phpunit/Logger/ConsoleLoggerTest.php
Expand Up @@ -68,7 +68,7 @@ public function test_it_throws_a_friendly_error_on_invalid_log_level(): void
/**
* @dataProvider outputMappingProvider
*/
public function test_the_log_level_is_added_to_the_message(
public function test_the_logs_the_message_if_is_the_right_log_verbosity(
string $logLevel,
int $outputVerbosity,
bool $outputsMessage
Expand All @@ -80,7 +80,29 @@ public function test_the_log_level_is_added_to_the_message(

$logs = $output->fetch();

$this->assertSame($outputsMessage ? "[$logLevel] foo bar" . PHP_EOL : '', $logs);
if ($outputsMessage) {
$this->assertNotSame('', $logs);
} else {
$this->assertSame('', $logs);
}
}

/**
* @dataProvider logLevelProvider
*/
public function test_the_log_level_is_added_to_the_message(
string $logLevel,
string $message,
string $expectedMessage
): void {
$output = new BufferedOutput(OutputInterface::VERBOSITY_DEBUG);

$logger = new ConsoleLogger(new IO(new StringInput(''), $output));
$logger->log($logLevel, $message);

$logs = $output->fetch();

$this->assertSame($expectedMessage . PHP_EOL, $logs);
}

public function test_it_interpolates_the_message_with_the_context(): void
Expand Down Expand Up @@ -210,22 +232,95 @@ static function (): void {},

public static function outputMappingProvider(): iterable
{
yield [LogLevel::EMERGENCY, OutputInterface::VERBOSITY_QUIET, false];

yield [LogLevel::EMERGENCY, OutputInterface::VERBOSITY_NORMAL, true];

yield [LogLevel::ALERT, OutputInterface::VERBOSITY_QUIET, false];

yield [LogLevel::ALERT, OutputInterface::VERBOSITY_NORMAL, true];

yield [LogLevel::CRITICAL, OutputInterface::VERBOSITY_QUIET, false];

yield [LogLevel::CRITICAL, OutputInterface::VERBOSITY_NORMAL, true];

yield [LogLevel::ERROR, OutputInterface::VERBOSITY_QUIET, false];

yield [LogLevel::ERROR, OutputInterface::VERBOSITY_NORMAL, true];

yield [LogLevel::WARNING, OutputInterface::VERBOSITY_QUIET, false];

yield [LogLevel::WARNING, OutputInterface::VERBOSITY_NORMAL, true];

yield [LogLevel::NOTICE, OutputInterface::VERBOSITY_QUIET, false];

yield [LogLevel::NOTICE, OutputInterface::VERBOSITY_NORMAL, true];

yield [LogLevel::INFO, OutputInterface::VERBOSITY_QUIET, false];

yield [LogLevel::INFO, OutputInterface::VERBOSITY_NORMAL, false];

yield [LogLevel::INFO, OutputInterface::VERBOSITY_VERBOSE, true];

yield [LogLevel::DEBUG, OutputInterface::VERBOSITY_QUIET, false];

yield [LogLevel::DEBUG, OutputInterface::VERBOSITY_NORMAL, false];

yield [LogLevel::INFO, OutputInterface::VERBOSITY_VERBOSE, true];
yield [LogLevel::DEBUG, OutputInterface::VERBOSITY_VERBOSE, false];

yield [LogLevel::DEBUG, OutputInterface::VERBOSITY_VERY_VERBOSE, false];

yield [LogLevel::DEBUG, OutputInterface::VERBOSITY_DEBUG, true];
}

yield [LogLevel::ALERT, OutputInterface::VERBOSITY_QUIET, false];
public static function logLevelProvider(): iterable
{
yield [
LogLevel::EMERGENCY,
'message',
'[emergency] message',
];

yield [LogLevel::EMERGENCY, OutputInterface::VERBOSITY_QUIET, false];
yield [
LogLevel::ALERT,
'message',
'[alert] message',
];

yield [
LogLevel::CRITICAL,
'message',
'[critical] message',
];

yield [
LogLevel::ERROR,
'message',
'[error] message',
];

yield [
LogLevel::WARNING,
'message',
'[warning] message',
];

yield [
LogLevel::NOTICE,
'message',
'message',
];

yield [
LogLevel::INFO,
'message',
'[info] message',
];

yield [
LogLevel::DEBUG,
'message',
'[debug] message',
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

note that this test doesn't capture the formatter tags e.g. here the message that we write is <debug>[debug] message</debug> where the tags are handled by the output formatter. I'm don't know however how to test that...

];
}
}