1<?php 2 3namespace FPM; 4 5class LogTool 6{ 7 const P_TIME = '\[\d\d-\w\w\w-\d{4} \d\d:\d\d:\d\d\]'; 8 const P_PREFIX = '\[pool unconfined\] child \d+ said into stderr: '; 9 const FINAL_SUFFIX = ', pipe is closed'; 10 11 /** 12 * @var string 13 */ 14 private $message; 15 16 /** 17 * @var string 18 */ 19 private $level; 20 21 /** 22 * @var int 23 */ 24 private $position; 25 26 /** 27 * @var int 28 */ 29 private $suffixPosition; 30 31 /** 32 * @var int 33 */ 34 private $limit; 35 36 /** 37 * @var string 38 */ 39 private $pattern; 40 41 /** 42 * @var string 43 */ 44 private $error; 45 46 /** 47 * @param string $message 48 * @param int $limit 49 * @param int $repeat 50 */ 51 public function setExpectedMessage(string $message, int $limit, int $repeat = 0) 52 { 53 $this->message = ($repeat > 0) ? str_repeat($message, $repeat) : $message; 54 $this->limit = $limit; 55 $this->position = 0; 56 } 57 58 /** 59 * @param string $level 60 * @return int 61 */ 62 public function setExpectedLevel(string $level) 63 { 64 return $this->level = $level; 65 } 66 67 /** 68 * @return string 69 */ 70 public function getExpectedLevel(): string 71 { 72 return $this->level ?: 'WARNING'; 73 } 74 75 /** 76 * @param string $line 77 * @return bool 78 */ 79 public function checkTruncatedMessage(string $line) 80 { 81 if ($this->message === null) { 82 throw new \LogicException('The message has not been set'); 83 } 84 $lineLen = strlen($line); 85 if (!$this->checkLineLength($line)) { 86 return false; 87 } 88 $this->pattern = '/^PHP message: (.*?)(\.\.\.)?$/'; 89 if (preg_match($this->pattern, $line, $matches) === 0) { 90 return $this->error("Unexpected truncated message: {$line}"); 91 } 92 93 if ($lineLen === $this->limit) { 94 if (!isset($matches[2])) { 95 return $this->error("The truncated line is not ended with '...'"); 96 } 97 if (!$this->checkMessage($matches[1])) { 98 return false; 99 } 100 } else { 101 if (isset($matches[2])) { 102 // this is expecting that the expected message does not end with '...' 103 // which should not be an issue for the test purpose. 104 return $this->error("The line is complete and should not end with '...'"); 105 } 106 if (!$this->checkMessage($matches[1], -1)) { 107 return false; 108 } 109 } 110 111 return true; 112 } 113 114 /** 115 * @param array $lines 116 * @param bool $terminated 117 * @param bool $decorated 118 * @return bool 119 */ 120 public function checkWrappedMessage(array $lines, bool $terminated = true, bool $decorated = true) 121 { 122 if ($this->message === null) { 123 throw new \LogicException('The message has not been set'); 124 } 125 if ($decorated) { 126 $this->pattern = sprintf( 127 '/^(%s %s: %s)"([^"]*)"(.*)?$/', 128 self::P_TIME, 129 $this->getExpectedLevel(), 130 self::P_PREFIX 131 ); 132 } else { 133 $this->pattern = null; 134 } 135 136 $idx = 0; 137 foreach ($lines as $idx => $line) { 138 if (!$this->checkLine($line)) { 139 break; 140 } 141 } 142 143 if ($this->suffixPosition > 0) { 144 $suffixPattern = sprintf( 145 '/^%s %s: %s(.*)$/', 146 self::P_TIME, $this->getExpectedLevel(), 147 self::P_PREFIX 148 ); 149 $line = $lines[++$idx]; 150 if (preg_match($suffixPattern, $line, $matches) === 0) { 151 return $this->error("Unexpected line: $line"); 152 } 153 if ($matches[1] !== substr(self::FINAL_SUFFIX, $this->suffixPosition)) { 154 return $this->error( 155 "The suffix has not been finished from position $this->suffixPosition in line: $line" 156 ); 157 } 158 } 159 160 if ($terminated) { 161 return $this->expectTerminatorLines($lines, $idx); 162 } 163 164 return true; 165 } 166 167 /** 168 * @param string $line 169 * @return bool 170 */ 171 private function checkLine(string $line) 172 { 173 if ($this->pattern === null) { 174 // plain (not decorated) output 175 $out = rtrim($line); 176 $finalSuffix = null; 177 } elseif (($res = preg_match($this->pattern, $line, $matches)) > 0) { 178 $out = $matches[2]; 179 $finalSuffix = $matches[3] ?? false; 180 } else { 181 return $this->error("Unexpected line: $line"); 182 } 183 184 $rem = strlen($this->message) - $this->position; 185 $lineLen = strlen($line); 186 if (!$this->checkLineLength($line, $lineLen)) { 187 return false; 188 } 189 if (!$this->checkMessage($out, $this->position)) { 190 return false; 191 } 192 $outLen = strlen($out); 193 if ($rem > $outLen) { // continuous line 194 if ($lineLen !== $this->limit) { 195 if ($lineLen + ($rem - $outLen) < $this->limit) { 196 return $this->error("Printed less than the message len"); 197 } 198 return $this->error( 199 "The continuous line length is $lineLen but it should equal to limit $this->limit" 200 ); 201 } 202 $this->position += $outLen; 203 return true; 204 } 205 if ($rem !== $outLen) { 206 return $this->error("Printed more than the message len"); 207 } 208 if ($finalSuffix === null || $finalSuffix === "") { 209 return false; 210 } 211 if ($finalSuffix === false) { 212 return $this->error("No final suffix"); 213 } 214 if (strpos(self::FINAL_SUFFIX, $finalSuffix) === false) { 215 return $this->error("The final suffix has to be equal to ', pipe is closed'"); 216 } 217 if (self::FINAL_SUFFIX !== $finalSuffix) { 218 $this->suffixPosition = strlen($finalSuffix); 219 } 220 // complete final suffix printed 221 return false; 222 } 223 224 /** 225 * @param string $line 226 * @param int $lineLen 227 * @return bool 228 */ 229 private function checkLineLength(string $line, $lineLen = null) { 230 $lineLen = $lineLen ?: strlen($line); 231 if ($lineLen > $this->limit) { 232 return $this->error( 233 "The line length is $lineLen which is higher than limit $this->limit" 234 ); 235 } 236 237 return true; 238 } 239 240 /** 241 * @param string $matchedMessage 242 * @param int $expectedMessageStart 243 * @return bool 244 */ 245 private function checkMessage(string $matchedMessage, int $expectedMessageStart = 0) 246 { 247 if ($expectedMessageStart < 0) { 248 $expectedMessage = $this->message; 249 } else { 250 $expectedMessage = substr($this->message, $expectedMessageStart, strlen($matchedMessage)); 251 } 252 if ($expectedMessage !== $matchedMessage) { 253 return $this->error( 254 sprintf( 255 "The actual string(%d) does not match expected string(%d):\n", 256 strlen($matchedMessage), 257 strlen($expectedMessage) 258 ) . 259 "- EXPECT: '$expectedMessage'\n" . 260 "- ACTUAL: '$matchedMessage'" 261 ); 262 } 263 264 return true; 265 } 266 267 /** 268 * @param array $lines 269 * @return bool 270 */ 271 public function expectStartingLines(array $lines) 272 { 273 if ($this->getError()) { 274 return false; 275 } 276 277 if (count($lines) < 2) { 278 return $this->error("No starting lines"); 279 } 280 281 return ( 282 $this->expectNotice($lines[0], 'fpm is running, pid \d+') && 283 $this->expectNotice($lines[1], 'ready to handle connections') 284 ); 285 } 286 287 /** 288 * @param array $lines 289 * @param int $idx 290 * @return bool 291 */ 292 public function expectTerminatorLines(array $lines, int $idx = -1) 293 { 294 if ($this->getError()) { 295 return false; 296 } 297 298 if (count($lines) - $idx < 3) { 299 return $this->error("No terminating lines"); 300 } 301 302 return ( 303 $this->expectNotice($lines[++$idx], 'Terminating ...') && 304 $this->expectNotice($lines[++$idx], 'exiting, bye-bye!') 305 ); 306 } 307 308 /** 309 * @param string $type 310 * @param string $line 311 * @param string $expectedMessage 312 * @param string|null $pool 313 * @return bool 314 */ 315 public function expectEntry(string $type, string $line, string $expectedMessage, $pool = null) 316 { 317 if ($this->getError()) { 318 return false; 319 } 320 if ($pool !== null) { 321 $expectedMessage = '\[pool ' . $pool . '\] ' . $expectedMessage; 322 } 323 324 $line = rtrim($line); 325 $pattern = sprintf('/^%s %s: %s$/', self::P_TIME, $type, $expectedMessage); 326 327 if (preg_match($pattern, $line, $matches) === 0) { 328 return $this->error( 329 "The $type does not match expected message:\n" . 330 "- PATTERN: $pattern\n" . 331 "- MESSAGE: $line\n" . 332 "- EXPECT: '$expectedMessage'\n" . 333 "- ACTUAL: '" . substr($line, strpos($line, $type) + strlen($type) + 2) . "'" 334 ); 335 } 336 337 return true; 338 } 339 340 /** 341 * @param string $line 342 * @param string $expectedMessage 343 * @param string|null $pool 344 * @return bool 345 */ 346 public function expectDebug(string $line, string $expectedMessage, $pool = null) 347 { 348 return $this->expectEntry('DEBUG', $line, $expectedMessage, $pool); 349 } 350 351 /** 352 * @param string $line 353 * @param string $expectedMessage 354 * @param string|null $pool 355 * @return bool 356 */ 357 public function expectNotice(string $line, string $expectedMessage, $pool = null) 358 { 359 return $this->expectEntry('NOTICE', $line, $expectedMessage, $pool); 360 } 361 362 /** 363 * @param string $line 364 * @param string $expectedMessage 365 * @param string|null $pool 366 * @return bool 367 */ 368 public function expectWarning(string $line, string $expectedMessage, $pool = null) 369 { 370 return $this->expectEntry('WARNING', $line, $expectedMessage, $pool); 371 } 372 373 /** 374 * @param string $line 375 * @param string $expectedMessage 376 * @param string|null $pool 377 * @return bool 378 */ 379 public function expectError(string $line, string $expectedMessage, $pool = null) 380 { 381 return $this->expectEntry('ERROR', $line, $expectedMessage, $pool); 382 } 383 384 /** 385 * @param string $line 386 * @param string $expectedMessage 387 * @param string|null $pool 388 * @return bool 389 */ 390 public function expectAlert(string $line, string $expectedMessage, $pool = null) 391 { 392 return $this->expectEntry('ALERT', $line, $expectedMessage, $pool); 393 } 394 395 396 /** 397 * @param string $msg 398 * @return bool 399 */ 400 private function error(string $msg) 401 { 402 $this->error = $msg; 403 echo "ERROR: $msg\n"; 404 return false; 405 } 406 407 /** 408 * @return string 409 */ 410 public function getError() 411 { 412 return $this->error; 413 } 414} 415 416if (isset($argv[1]) && $argv[1] === 'logtool-selftest') { 417 $cases = [ 418 [ 419 'limit' => 1050, 420 'lines' => [ 421 '[08-Oct-2017 19:53:50] WARNING: [pool unconfined] child 23183 said into stderr: "' . 422 str_repeat('a', 968) . '"', 423 '[08-Oct-2017 19:53:50] WARNING: [pool unconfined] child 23183 said into stderr: "' . 424 str_repeat('a', 968) . '"', 425 '[08-Oct-2017 19:53:50] WARNING: [pool unconfined] child 23183 said into stderr: "' . 426 str_repeat('a', 112) . '", pipe is closed', 427 '[08-Oct-2017 19:53:55] NOTICE: Terminating ...', 428 '[08-Oct-2017 19:53:55] NOTICE: exiting, bye-bye!', 429 ], 430 'message' => str_repeat('a', 2048), 431 'type' => 'stdio', 432 ], 433 [ 434 'limit' => 1050, 435 'lines' => [ 436 '[08-Oct-2017 19:53:50] WARNING: [pool unconfined] child 23183 said into stderr: "' . 437 str_repeat('a', 968) . '"', 438 '[08-Oct-2017 19:53:50] WARNING: [pool unconfined] child 23183 said into stderr: "' . 439 str_repeat('a', 968) . '"', 440 '[08-Oct-2017 19:53:50] WARNING: [pool unconfined] child 23183 said into stderr: "' . 441 str_repeat('a', 964) . '", pi', 442 '[08-Oct-2017 19:53:50] WARNING: [pool unconfined] child 23183 said into stderr: pe is closed', 443 '[08-Oct-2017 19:53:55] NOTICE: Terminating ...', 444 '[08-Oct-2017 19:53:55] NOTICE: exiting, bye-bye!', 445 ], 446 'message' => str_repeat('a', 2900), 447 'type' => 'stdio', 448 ], 449 [ 450 'limit' => 1024, 451 'line' => '[08-Oct-2017 19:53:50] WARNING: ' . str_repeat('a',989) . '...', 452 'message' => str_repeat('a', 2900), 453 'type' => 'message', 454 ], 455 [ 456 'limit' => 1024, 457 'line' => '[08-Oct-2017 19:53:50] WARNING: ' . str_repeat('a',20), 458 'message' => str_repeat('a', 20), 459 'type' => 'message', 460 ], 461 ]; 462 foreach ($cases as $case) { 463 printf("Test message with len %d and limit %d: ", strlen($case['message']), $case['limit']); 464 $logTool = new LogTool(); 465 $logTool->setExpectedMessage($case['message'], $case['limit']); 466 if ($case['type'] === 'stdio') { 467 $logTool->checkWrappedMessage($case['lines']); 468 } else { 469 $logTool->checkTruncatedMessage($case['line']); 470 } 471 if (!$logTool->getError()) { 472 echo "OK\n"; 473 } 474 } 475 echo "Done\n"; 476} 477
