public function __invoke(array $record)
{
$record['extra']['time_ms'] = Timer::read(self::class);
if (isset(self::$logger)) {
$record['extra']['queries'] = count(self::$logger->get(self::class));
}
return $record;
}
/**
* Tests Timer::read() time accumulation accuracy across multiple restarts.
*
* @covers ::start
* @covers ::stop
* @covers ::read
*/
public function testTimer()
{
Timer::start('test');
usleep(5000);
$value = Timer::read('test');
usleep(5000);
$value2 = Timer::read('test');
usleep(5000);
$value3 = Timer::read('test');
usleep(5000);
$value4 = Timer::read('test');
// Although we sleep for 5 milliseconds, we should test that at least 4 ms
// have past because usleep() is not reliable on Windows. See
// http://php.net/manual/en/function.usleep.php for more information. The
// purpose of the test to validate that the Timer class can measure elapsed
// time not the granularity of usleep() on a particular OS.
$this->assertGreaterThanOrEqual(4, $value, 'Timer failed to measure at least 4 milliseconds of sleeping while running.');
$this->assertGreaterThanOrEqual($value + 4, $value2, 'Timer failed to measure at least 8 milliseconds of sleeping while running.');
$this->assertGreaterThanOrEqual($value2 + 4, $value3, 'Timer failed to measure at least 12 milliseconds of sleeping while running.');
$this->assertGreaterThanOrEqual($value3 + 4, $value4, 'Timer failed to measure at least 16 milliseconds of sleeping while running.');
// Stop the timer.
$value5 = Timer::stop('test');
$this->assertGreaterThanOrEqual($value4, $value5['time'], 'Timer measured after stopping was not greater than last measurement.');
// Read again.
$value6 = Timer::read('test');
$this->assertEquals($value5['time'], $value6, 'Timer measured after stopping was not equal to the stopped time.');
// Restart.
Timer::start('test');
usleep(5000);
$value7 = Timer::read('test');
$this->assertGreaterThanOrEqual($value6 + 4, $value7, 'Timer failed to measure at least 16 milliseconds of sleeping while running.');
// Stop again.
$value8 = Timer::stop('test');
$value9 = Timer::read('test');
$this->assertEquals($value8['time'], $value9, 'Timer measured after stopping not equal to stop time.');
}
/**
* Invokes any cron handlers implementing hook_cron.
*/
protected function invokeCronHandlers()
{
$module_previous = '';
// Iterate through the modules calling their cron handlers (if any):
foreach ($this->moduleHandler->getImplementations('cron') as $module) {
if (!$module_previous) {
$this->logger->notice('Starting execution of @module_cron().', ['@module' => $module]);
} else {
$this->logger->notice('Starting execution of @module_cron(), execution of @module_previous_cron() took @time.', ['@module' => $module, '@module_previous' => $module_previous, '@time' => Timer::read('cron_' . $module_previous) . 'ms']);
}
Timer::start('cron_' . $module);
// Do not let an exception thrown by one module disturb another.
try {
$this->moduleHandler->invoke($module, 'cron');
} catch (\Exception $e) {
watchdog_exception('cron', $e);
}
Timer::stop('cron_' . $module);
$module_previous = $module;
}
if ($module_previous) {
$this->logger->notice('Execution of @module_previous_cron() took @time.', ['@module_previous' => $module_previous, '@time' => Timer::read('cron_' . $module_previous) . 'ms']);
}
}
/**
* @param $operation
* Memcached operation. For example, 'get' or 'set'.
*
* @param $results
* Result of request to memcached.
*
* @param $memcached_keys
* Array which contains memcached key as an array keys and related
* Drupal cache id as an array values.
*
* @param $cache_bin
* Name of Drupal cache bin.
*
* @param $cluster_name
* Name of the memcached cluster defined in settings.
*/
public static function process($operation, $results, $memcached_keys, $cache_bin, $cluster_name)
{
$key = 'memcache_storage_' . self::$counter;
$used_time = Timer::read($key);
if (sizeof($memcached_keys) > 1) {
$operation .= 'Multi';
}
foreach ($memcached_keys as $memcached_key => $cache_key) {
$result = $results;
if (in_array($operation, ['get', 'getMulti'])) {
$result = isset($results[$memcached_key]) ? TRUE : FALSE;
}
self::$log[] = ['operation' => $operation, 'used_time' => $used_time, 'result' => $result, 'cache_bin' => $cache_bin, 'cache_key' => $cache_key, 'memcached_key' => $memcached_key, 'cluster_name' => $cluster_name];
}
}
