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]; } }