public function formatMessage(MougrimLogger $logger, $level, $message, \Exception $throwable = null)
{
$prefix = '';
$mdc = LoggerMDC::getMap();
if ($this->logUserInfo) {
foreach (['ip', 'userId', 'sessionId'] as $key) {
$context = isset($mdc[$key]) ? $mdc[$key] : null;
$context = LoggerRender::render($context);
$prefix .= '[' . $context . ']';
unset($mdc[$key]);
}
}
$level = MougrimLogger::getLevelName($level);
$formatted = date('Y-m-d H:i:s') . ' ' . $prefix . '[' . $level . '][' . $logger->getName() . ']';
$ndcString = '';
if ($ndcStack = LoggerNDC::getStack()) {
$ndcString = implode(' ', $ndcStack);
}
$formatted .= '[' . $ndcString . ']';
$mdcString = '';
foreach ($mdc as $key => $context) {
$mdcString .= $key . '=' . $context . ' ';
}
$formatted .= '[' . trim($mdcString) . ']';
$formatted .= ' ' . LoggerRender::render($message);
if ($throwable) {
$formatted .= ' ' . LoggerRender::render($throwable);
}
return $formatted . PHP_EOL;
}
public function render(Logger $logger, $level, $message, \Exception $throwable = null)
{
$ndc = LoggerNDC::getStack();
if (!$ndc) {
return '';
}
return implode(' ', $ndc);
}
public function testLoggerNDC()
{
$logger = new Logger('testLogger');
$layout = new LayoutSimple();
$this->assertSame('testLogger [INFO] - test message' . PHP_EOL, $layout->formatMessage($logger, Logger::INFO, 'test message'));
LoggerNDC::push('stack1');
$this->assertSame('testLogger [INFO] stack1 - test message' . PHP_EOL, $layout->formatMessage($logger, Logger::INFO, 'test message'));
LoggerNDC::push('stack2');
$this->assertSame('testLogger [INFO] stack1 stack2 - test message' . PHP_EOL, $layout->formatMessage($logger, Logger::INFO, 'test message'));
LoggerNDC::pop();
$this->assertSame('testLogger [INFO] stack1 - test message' . PHP_EOL, $layout->formatMessage($logger, Logger::INFO, 'test message'));
LoggerNDC::pop();
$this->assertSame('testLogger [INFO] - test message' . PHP_EOL, $layout->formatMessage($logger, Logger::INFO, 'test message'));
}
public function formatMessage(Logger $logger, $level, $message, \Exception $throwable = null)
{
$formatted = $logger->getName() . ' [' . Logger::getLevelName($level) . '] ';
if ($ndc = LoggerNDC::getStack()) {
$formatted .= implode(' ', $ndc) . ' ';
}
if ($mdc = LoggerMDC::getMap()) {
foreach ($mdc as $key => $context) {
$formatted .= $key . '=' . $context . ' ';
}
}
$formatted .= '- ' . LoggerRender::render($message);
if ($throwable) {
$formatted .= ' ' . LoggerRender::render($throwable);
}
return $formatted . PHP_EOL;
}
/**
* @dataProvider dataProviderFormatMessage
*
* @param boolean $isLogUserInfo
* @param array $mdc
* @param array $ndc
* @param string $result
*/
public function testFormatMessage($isLogUserInfo, array $mdc, array $ndc, $result)
{
LoggerMDC::clear();
LoggerNDC::clear();
foreach ($mdc as $key => $context) {
LoggerMDC::put($key, $context);
}
foreach ($ndc as $context) {
LoggerNDC::push($context);
}
/** @var \PHPUnit_Framework_MockObject_MockObject|MougrimLogger $logger */
$logger = $this->getMockBuilder(MougrimLogger::class)->disableOriginalConstructor()->getMock();
$logger->expects(static::any())->method('getName')->will(static::returnValue('name'));
$layout = new Layout();
$layout->setLogUserInfo($isLogUserInfo);
$message = $layout->formatMessage($logger, MougrimLogger::INFO, 'message', new LayoutTestException());
$datePrefixPattern = '/^\\d{4}-\\d{2}-\\d{2} \\d{2}:\\d{2}:\\d{2} /';
static::assertRegExp($datePrefixPattern, $message);
$message = preg_replace($datePrefixPattern, 'datetime ', $message);
static::assertSame($result, $message);
}
public function run()
{
$this->reinit();
$processorPid = posix_getpid();
$this->childrenInfo = [];
try {
Logger::getLogger('queue')->info('Begin');
$this->beforeRun();
$this->workersQty = 0;
$this->freeWorkersNumbers = range(0, $this->maxWorkersQty - 1);
$lastReinitTime = time();
$waitPidAttemptQty = 0;
while (true) {
$this->getSignalHandler()->dispatch();
if ($lastReinitTime + 15 < time()) {
$this->reinit();
$lastReinitTime = time();
}
$this->changeStatusFile();
if ($this->workersQty) {
$this->processSignalChild();
}
if ($this->terminate) {
$this->terminate(array_keys($this->childrenInfo));
break;
}
if ($this->workersQty >= $this->maxWorkersQty) {
// логируем не на каждый шаг в цикле
if ($waitPidAttemptQty % 100 === 0) {
Logger::getLogger('queue')->debug('workersQty is max, wait');
}
usleep(10000);
++$waitPidAttemptQty;
continue;
}
$waitPidAttemptQty = 0;
if ($this->queuesEmpty($this->queues)) {
Logger::getLogger('queue')->info('Tasks not found, sleep');
usleep(2000000);
continue;
}
$queueNick = $this->getNextQueueNick();
if ($queueNick === null) {
usleep(10000);
continue;
}
Logger::getLogger('queue')->debug("queue nick for next worker: {$queueNick}");
$queue = $this->queues[$queueNick];
$tasksForWorker = $queue->sliceTasksForWorker();
Logger::getLogger('queue')->trace('Count tasks for worker: ' . count($tasksForWorker));
$workerNumber = array_pop($this->freeWorkersNumbers);
$pid = $this->fork();
if ($pid) {
$this->childrenInfo[$pid] = ['workerNumber' => $workerNumber, 'queueNick' => $queueNick];
++$this->workersQty;
++$this->queuesInfo[$queueNick]['activeWorkersQty'];
Logger::getLogger('queue')->debug("worker running, workersQty={$this->workersQty},queue={$queueNick},activeWorkersQty={$this->queuesInfo[$queueNick]['activeWorkersQty']}");
} else {
LoggerMDC::put('queueNick', $queueNick);
LoggerMDC::put('processorPid', $processorPid);
LoggerMDC::put('workerPid', posix_getpid());
LoggerNDC::push('worker');
$code = 0;
try {
$worker = $queue->getWorker();
$worker->setNumber($workerNumber);
$worker->run($tasksForWorker);
} catch (Exception $exception) {
Logger::getLogger('queue')->error('Exception in worker', $exception);
$code = 255;
}
LoggerNDC::pop();
$this->end($code);
}
}
} catch (Exception $exception) {
Logger::getLogger('queue')->error('Exception in processor', $exception);
$this->terminate(array_keys($this->childrenInfo));
throw $exception;
}
}
/**
* Reset all loggers, appenders, etc.
*/
public static function reset()
{
self::$hierarchy = new LoggerHierarchy();
self::$isConfigured = false;
LoggerNDC::clear();
LoggerMDC::clear();
LoggerRender::reset();
LoggerPolicy::reset();
}
