123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517 |
- <?php
- namespace FPM;
- class LogTool
- {
- const P_TIME = '\[\d\d-\w\w\w-\d{4} \d\d:\d\d:\d\d\]';
- const P_PREFIX = '\[pool unconfined\] child \d+ said into stderr: ';
- const P_PREFIX_STDOUT = '\[pool unconfined\] child \d+ said into stdout: ';
- const FINAL_SUFFIX = ', pipe is closed';
- const DEBUG = 'DEBUG';
- const NOTICE = 'NOTICE';
- const WARNING = 'WARNING';
- const ERROR = 'ERROR';
- const ALERT = 'ALERT';
-
- private $message;
-
- private $level;
-
- private $position;
-
- private $suffixPosition;
-
- private $limit;
-
- private $pattern;
-
- private $error;
-
- private $pipeClosed = false;
-
- public function setExpectedMessage(string $message, int $limit, int $repeat = 0)
- {
- $this->message = ($repeat > 0) ? str_repeat($message, $repeat) : $message;
- $this->limit = $limit;
- $this->position = 0;
- }
-
- public function setExpectedLevel(string $level)
- {
- return $this->level = $level;
- }
-
- public function getExpectedLevel(): string
- {
- return $this->level ?: 'WARNING';
- }
-
- public function setPipeClosed(bool $pipeClosed)
- {
- $this->pipeClosed = $pipeClosed;
- }
-
- public function checkTruncatedMessage(string $line)
- {
- if ($this->message === null) {
- throw new \LogicException('The message has not been set');
- }
- $lineLen = strlen($line);
- if (!$this->checkLineLength($line)) {
- return false;
- }
- $this->pattern = '/^PHP message: (.*?)(\.\.\.)?$/';
- if (preg_match($this->pattern, $line, $matches) === 0) {
- return $this->error("Unexpected truncated message: {$line}");
- }
- if ($lineLen === $this->limit - strlen('NOTICE: ') - 1) {
- if (!isset($matches[2])) {
- return $this->error("The truncated line is not ended with '...'");
- }
- if (!$this->checkMessage($matches[1])) {
- return false;
- }
- } else {
- if (isset($matches[2])) {
-
-
- return $this->error("The line is complete and should not end with '...'");
- }
- if (!$this->checkMessage($matches[1], -1)) {
- return false;
- }
- }
- return true;
- }
-
- public function checkWrappedMessage(array $lines, bool $terminated = true, bool $decorated = true, bool $is_stderr = true)
- {
- if ($this->message === null) {
- throw new \LogicException('The message has not been set');
- }
- if ($decorated) {
- $this->pattern = sprintf(
- '/^(%s %s: %s)"([^"]*)"(.*)?$/',
- self::P_TIME,
- $this->getExpectedLevel(),
- $is_stderr ? self::P_PREFIX : self::P_PREFIX_STDOUT
- );
- } else {
- $this->pattern = null;
- }
- $idx = 0;
- foreach ($lines as $idx => $line) {
- if (!$this->checkLine($line)) {
- break;
- }
- }
- if ($this->suffixPosition > 0) {
- $suffixPattern = sprintf(
- '/^%s %s: %s(.*)$/',
- self::P_TIME, $this->getExpectedLevel(),
- $is_stderr ? self::P_PREFIX : self::P_PREFIX_STDOUT
- );
- $line = $lines[++$idx];
- if (preg_match($suffixPattern, $line, $matches) === 0) {
- return $this->error("Unexpected line: $line");
- }
- if ($matches[1] !== substr(self::FINAL_SUFFIX, $this->suffixPosition)) {
- return $this->error(
- "The suffix has not been finished from position $this->suffixPosition in line: $line"
- );
- }
- }
- if ($terminated) {
- return $this->expectTerminatorLines($lines, $idx);
- }
- return true;
- }
-
- private function checkLine(string $line)
- {
- if ($this->pattern === null) {
-
- $out = rtrim($line);
- $finalSuffix = null;
- } elseif (($res = preg_match($this->pattern, $line, $matches)) > 0) {
- $out = $matches[2];
- $finalSuffix = $matches[3] ?? false;
- } else {
- return $this->error("Unexpected line: $line");
- }
- $rem = strlen($this->message) - $this->position;
- $lineLen = strlen($line);
- if (!$this->checkLineLength($line, $lineLen)) {
- return false;
- }
- if (!$this->checkMessage($out, $this->position)) {
- return false;
- }
- $outLen = strlen($out);
- if ($rem > $outLen) {
- if ($lineLen !== $this->limit) {
- if ($lineLen + ($rem - $outLen) < $this->limit) {
- return $this->error("Printed less than the message len");
- }
- return $this->error(
- "The continuous line length is $lineLen but it should equal to limit $this->limit"
- );
- }
- $this->position += $outLen;
- return true;
- }
- if ($rem !== $outLen) {
- return $this->error("Printed more than the message len");
- }
- if (!$this->pipeClosed || $finalSuffix === null) {
- return false;
- }
- if ($finalSuffix === false) {
- return $this->error("No final suffix");
- }
- if (empty($finalSuffix) || strpos(self::FINAL_SUFFIX, $finalSuffix) === false) {
- return $this->error("The final suffix has to be equal to ', pipe is closed'");
- }
- if (self::FINAL_SUFFIX !== $finalSuffix) {
- $this->suffixPosition = strlen($finalSuffix);
- }
-
- return false;
- }
-
- private function checkLineLength(string $line, $lineLen = null) {
- $lineLen = $lineLen ?: strlen($line);
- if ($lineLen > $this->limit) {
- return $this->error(
- "The line length is $lineLen which is higher than limit $this->limit"
- );
- }
- return true;
- }
-
- private function checkMessage(string $matchedMessage, int $expectedMessageStart = 0)
- {
- if ($expectedMessageStart < 0) {
- $expectedMessage = $this->message;
- } else {
- $expectedMessage = substr($this->message, $expectedMessageStart, strlen($matchedMessage));
- }
- if ($expectedMessage !== $matchedMessage) {
- return $this->error(
- sprintf(
- "The actual string(%d) does not match expected string(%d):\n",
- strlen($matchedMessage),
- strlen($expectedMessage)
- ) .
- "- EXPECT: '$expectedMessage'\n" .
- "- ACTUAL: '$matchedMessage'"
- );
- }
- return true;
- }
-
- public function expectReloadingLines(array $lines)
- {
- if (
- !$this->expectNotice($lines[0], 'Reloading in progress ...') ||
- !$this->expectNotice($lines[1], 'reloading: .*')
- ) {
- return false;
- }
- for ($i = 2; $i < count($lines) - 2; $i++) {
- if (!$this->expectNotice($lines[$i], 'using inherited socket fd=\d+, "[^"]+"')) {
- return false;
- }
- }
- return $this->expectStartingLines(array_splice($lines, $i));
- }
-
- public function expectStartingLines(array $lines)
- {
- if ($this->getError()) {
- return false;
- }
- if (count($lines) < 2) {
- return $this->error("No starting lines");
- }
- return (
- $this->expectNotice($lines[0], 'fpm is running, pid \d+') &&
- $this->expectNotice($lines[1], 'ready to handle connections')
- );
- }
-
- public function expectTerminatorLines(array $lines, int $idx = -1)
- {
- if ($this->getError()) {
- return false;
- }
- if (count($lines) - $idx < 3) {
- return $this->error("No terminating lines");
- }
- return (
- $this->expectNotice($lines[++$idx], 'Terminating ...') &&
- $this->expectNotice($lines[++$idx], 'exiting, bye-bye!')
- );
- }
-
- public function expectEntry(string $type, string $line, string $expectedMessage, $pool = null)
- {
- if ($this->getError()) {
- return false;
- }
- if ($pool !== null) {
- $expectedMessage = '\[pool ' . $pool . '\] ' . $expectedMessage;
- }
- $line = rtrim($line);
- $pattern = sprintf('/^(%s )?%s: %s$/', self::P_TIME, $type, $expectedMessage);
- if (preg_match($pattern, $line, $matches) === 0) {
- return $this->error(
- "The $type does not match expected message:\n" .
- "- PATTERN: $pattern\n" .
- "- MESSAGE: $line\n" .
- "- EXPECT: '$expectedMessage'\n" .
- "- ACTUAL: '" . substr($line, strpos($line, $type) + strlen($type) + 2) . "'"
- );
- }
- return true;
- }
-
- public function expectDebug(string $line, string $expectedMessage, $pool = null)
- {
- return $this->expectEntry(self::DEBUG, $line, $expectedMessage, $pool);
- }
-
- public function expectNotice(string $line, string $expectedMessage, $pool = null)
- {
- return $this->expectEntry(self::NOTICE, $line, $expectedMessage, $pool);
- }
-
- public function expectWarning(string $line, string $expectedMessage, $pool = null)
- {
- return $this->expectEntry(self::WARNING, $line, $expectedMessage, $pool);
- }
-
- public function expectError(string $line, string $expectedMessage, $pool = null)
- {
- return $this->expectEntry(self::ERROR, $line, $expectedMessage, $pool);
- }
-
- public function expectAlert(string $line, string $expectedMessage, $pool = null)
- {
- return $this->expectEntry(self::ALERT, $line, $expectedMessage, $pool);
- }
-
- private function error(string $msg)
- {
- $this->error = $msg;
- echo "ERROR: $msg\n";
- return false;
- }
-
- public function getError()
- {
- return $this->error;
- }
- }
- if (isset($argv[1]) && $argv[1] === 'logtool-selftest') {
- $cases = [
- [
- 'limit' => 1050,
- 'lines' => [
- '[08-Oct-2017 19:53:50] WARNING: [pool unconfined] child 23183 said into stderr: "' .
- str_repeat('a', 968) . '"',
- '[08-Oct-2017 19:53:50] WARNING: [pool unconfined] child 23183 said into stderr: "' .
- str_repeat('a', 968) . '"',
- '[08-Oct-2017 19:53:50] WARNING: [pool unconfined] child 23183 said into stderr: "' .
- str_repeat('a', 112) . '", pipe is closed',
- '[08-Oct-2017 19:53:55] NOTICE: Terminating ...',
- '[08-Oct-2017 19:53:55] NOTICE: exiting, bye-bye!',
- ],
- 'message' => str_repeat('a', 2048),
- 'type' => 'stdio',
- ],
- [
- 'limit' => 1050,
- 'lines' => [
- '[08-Oct-2017 19:53:50] WARNING: [pool unconfined] child 23183 said into stderr: "' .
- str_repeat('a', 968) . '"',
- '[08-Oct-2017 19:53:50] WARNING: [pool unconfined] child 23183 said into stderr: "' .
- str_repeat('a', 968) . '"',
- '[08-Oct-2017 19:53:50] WARNING: [pool unconfined] child 23183 said into stderr: "' .
- str_repeat('a', 964) . '", pi',
- '[08-Oct-2017 19:53:50] WARNING: [pool unconfined] child 23183 said into stderr: pe is closed',
- '[08-Oct-2017 19:53:55] NOTICE: Terminating ...',
- '[08-Oct-2017 19:53:55] NOTICE: exiting, bye-bye!',
- ],
- 'message' => str_repeat('a', 2900),
- 'type' => 'stdio',
- ],
- [
- 'limit' => 1024,
- 'line' => '[08-Oct-2017 19:53:50] WARNING: ' . str_repeat('a',989) . '...',
- 'message' => str_repeat('a', 2900),
- 'type' => 'message',
- ],
- [
- 'limit' => 1024,
- 'line' => '[08-Oct-2017 19:53:50] WARNING: ' . str_repeat('a',20),
- 'message' => str_repeat('a', 20),
- 'type' => 'message',
- ],
- ];
- foreach ($cases as $case) {
- printf("Test message with len %d and limit %d: ", strlen($case['message']), $case['limit']);
- $logTool = new LogTool();
- $logTool->setExpectedMessage($case['message'], $case['limit']);
- if ($case['type'] === 'stdio') {
- $logTool->checkWrappedMessage($case['lines']);
- } else {
- $logTool->checkTruncatedMessage($case['line']);
- }
- if (!$logTool->getError()) {
- echo "OK\n";
- }
- }
- echo "Done\n";
- }
|