Skip to content

Commit

Permalink
ProcessJobExecutor: log unexpected stderr instead of throwing an exce…
Browse files Browse the repository at this point in the history
…ption
  • Loading branch information
mabar committed Mar 21, 2024
1 parent f25fd6a commit c92429a
Show file tree
Hide file tree
Showing 6 changed files with 51 additions and 51 deletions.
1 change: 1 addition & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@ and this project adheres to [Semantic Versioning](http://semver.org/spec/v2.0.0.
- `ProcessJobExecutor`
- subprocess errors include exit code
- logs unexpected stdout instead of triggering E_USER_NOTICE (via optional logger)
- logs unexpected stderr instead of throwing an exception (via optional logger)

### Fixed

Expand Down
4 changes: 3 additions & 1 deletion docs/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -376,7 +376,9 @@ $scheduler = new SimpleScheduler(null, null, null, null, $logger);

If you use [process job executor](#parallelization-and-process-isolation), then also these situations are logged:

- Subprocess running the job produced unexpected stdout output. Job should never echo or write directly to stdout.
- Subprocess running the job produced unexpected *stdout* output. Job should never echo or write directly to stdout.
- Subprocess running the job produced unexpected *stderr* output. This may happen just due to deprecation notices but may
also be caused by more serious problem occurring in CLI.

```php
use Orisai\Scheduler\SimpleScheduler;
Expand Down
36 changes: 17 additions & 19 deletions src/Executor/ProcessJobExecutor.php
Original file line number Diff line number Diff line change
Expand Up @@ -101,17 +101,17 @@ public function runJobs(

unset($jobExecutions[$i]);

$output = trim($execution->getOutput());
$errorOutput = trim($execution->getErrorOutput());
$stdout = trim($execution->getOutput());
$stderr = trim($execution->getErrorOutput());

try {
$decoded = json_decode($output, true, 512, JSON_THROW_ON_ERROR);
$decoded = json_decode($stdout, true, 512, JSON_THROW_ON_ERROR);
assert(is_array($decoded));
} catch (JsonException $e) {
$suppressedExceptions[] = $this->createSubprocessFail(
$execution,
$output,
$errorOutput,
$stdout,
$stderr,
);

continue;
Expand All @@ -122,11 +122,8 @@ public function runJobs(
$this->logUnexpectedStdout($execution, $jobId, $unexpectedStdout);
}

if ($errorOutput !== '') {
$suppressedExceptions[] = $this->createStderrFail(
$execution,
$errorOutput,
);
if ($stderr !== '') {
$this->logUnexpectedStderr($execution, $jobId, $stderr);
}

yield $jobSummaries[] = $this->createSummary($decoded, $jobSchedule->getExpression());
Expand Down Expand Up @@ -208,16 +205,17 @@ private function createSubprocessFail(Process $execution, string $output, string
->withMessage($message);
}

private function createStderrFail(Process $execution, string $errorOutput): JobProcessFailure
/**
* @param int|string $jobId
*/
private function logUnexpectedStderr(Process $execution, $jobId, string $stderr): void
{
$message = Message::create()
->withContext("Running job via command {$execution->getCommandLine()}")
->withProblem('Job subprocess produced stderr output.')
->with('Exit code', (string) $execution->getExitCode())
->with('stderr', $errorOutput);

return JobProcessFailure::create()
->withMessage($message);
$this->logger->warning("Subprocess running job '$jobId' produced unexpected stderr output.", [
'id' => $jobId,
'command' => $execution->getCommandLine(),
'exitCode' => $execution->getExitCode(),
'stderr' => $stderr,
]);
}

/**
Expand Down
12 changes: 9 additions & 3 deletions tests/Unit/SchedulerProcessSetup.php
Original file line number Diff line number Diff line change
Expand Up @@ -84,11 +84,15 @@ public static function createWithStderr(): ManagedScheduler
return new ManagedScheduler($jobManager, null, null, $executor, $clock);
}

public static function createWithStderrJob(): ManagedScheduler
/**
* @return array{ManagedScheduler, TestLogger}
*/
public static function createWithStderrJob(): array
{
$jobManager = new SimpleJobManager();
$clock = new FrozenClock(1);
$executor = new ProcessJobExecutor($clock);
$logger = new TestLogger();
$executor = new ProcessJobExecutor($clock, $logger);
$executor->setExecutable(__DIR__ . '/scheduler-process-binary-with-stderr-job.php');

$jobManager->addJob(
Expand All @@ -98,7 +102,9 @@ public static function createWithStderrJob(): ManagedScheduler
new CronExpression('* * * * *'),
);

return new ManagedScheduler($jobManager, null, null, $executor, $clock);
$scheduler = new ManagedScheduler($jobManager, null, null, $executor, $clock, $logger);

return [$scheduler, $logger];
}

/**
Expand Down
47 changes: 20 additions & 27 deletions tests/Unit/SimpleSchedulerTest.php
Original file line number Diff line number Diff line change
Expand Up @@ -1174,37 +1174,30 @@ public function testProcessStderr(): void

public function testProcessJobStderr(): void
{
$scheduler = SchedulerProcessSetup::createWithStderrJob();
[$scheduler, $logger] = SchedulerProcessSetup::createWithStderrJob();
$summary = $scheduler->run();

$e = null;
try {
$scheduler->run();
} catch (RunFailure $e) {
// Handled bellow
foreach ($logger->logs as &$log) {
self::assertIsString($log[2]['command']);
// Can't easily assert
unset($log[2]['command']);
}

self::assertNotNull($e);
self::assertStringStartsWith(
<<<'MSG'
Run failed
Suppressed errors:
MSG,
$e->getMessage(),
self::assertCount(1, $summary->getJobSummaries());
self::assertSame(
[
[
'warning',
"Subprocess running job '0' produced unexpected stderr output.",
[
'id' => 0,
'exitCode' => 0,
'stderr' => 'job error',
],
],
],
$logger->logs,
);

self::assertNotSame([], $e->getSuppressed());
foreach ($e->getSuppressed() as $suppressed) {
self::assertInstanceOf(JobProcessFailure::class, $suppressed);
self::assertStringMatchesFormat(
<<<'MSG'
Context: Running job via command %a
Problem: Job subprocess produced stderr output.
Exit code: 0
stderr: job error
MSG,
rtrim($suppressed->getMessage()),
);
}
}

/**
Expand Down
2 changes: 1 addition & 1 deletion tests/Unit/scheduler-process-binary-with-stderr-job.php
Original file line number Diff line number Diff line change
Expand Up @@ -7,7 +7,7 @@
require_once __DIR__ . '/../../vendor/autoload.php';

$application = new Application();
$scheduler = SchedulerProcessSetup::createWithStderrJob();
[$scheduler] = SchedulerProcessSetup::createWithStderrJob();

$command = new RunJobCommand($scheduler);

Expand Down

0 comments on commit c92429a

Please sign in to comment.