/**
* @param StopwatchEvent $event
* @param $pusherName
*/
public function collectData(StopwatchEvent $event, $pusherName)
{
if (!isset($this->rawData[$pusherName])) {
$this->rawData[$pusherName] = [];
}
$this->rawData[$pusherName][] = $event->getDuration();
}
/**
* @return StorageApiEvent
*/
private function prepareEvent()
{
$event = new StorageApiEvent();
$event->setComponent(KeboolaOrchestratorBundle::SYRUP_COMPONENT_NAME)->setRunId($this->job->getRunId());
if ($this->stopwatchEvent) {
$event->setDuration($this->stopwatchEvent->stop()->getDuration() / 1000);
}
return $event;
}
public function addTimeEventInfo(StopwatchEvent $timeEvent = null)
{
if (!$timeEvent) {
return $this;
}
// Contiene i dati sui tempi di esecuzione
$timeInfoArray = array('exec_time' => new DbgInfoItem('exec_time', $timeEvent ? $timeEvent->getDuration() : 0, DbgInfoItem::TYPE_NUMERIC), 'memory_usage' => new DbgInfoItem('exec_mem', $timeEvent ? $timeEvent->getMemory() : 0, DbgInfoItem::TYPE_MEMSIZE));
return $this->add('system_info', new DbgInfoArrayItem('System usage info', $timeInfoArray, array('render_type' => 'list')));
}
/**
* @param $name
* @param $dialect
* @param StopwatchEvent $event
* @param $output
* @param $peakMemory
*/
public function __construct($name, $dialect, StopwatchEvent $event, $output, $peakMemory)
{
$this->name = $name;
$this->output = $output;
$this->duration = $event->getDuration();
$this->memory = $event->getMemory();
$this->peakMemory = $peakMemory;
$this->dialect = $dialect;
}
/**
* Set ending time of the call and write log.
*
* @param StopwatchEvent $event
* @param string $resource
*/
public function logCallDuration(StopwatchEvent $event, $resource)
{
if (static::IS_LOG_ACTIVE) {
$filePath = $this->logDir . static::LOG_FILE_NAME;
$duration = $event->getDuration() / 1000;
$duration = number_format($duration, 3);
$startTime = ($event->getOrigin() + $event->getStartTime()) / 1000;
$callStart = date(static::DATE_FORMAT, (int) $startTime);
$this->writeLog($filePath, $callStart, $resource, $duration);
}
}
/**
* Extract StopWatch data into an array.
*
* @param StopwatchEvent $stopWatchEvent
* @param OutputInterface|null $output
* @param array $extra
*
* @return array
*/
private function extractLog(StopwatchEvent $stopWatchEvent, OutputInterface $output = null, $extra = array())
{
$duration = $stopWatchEvent->getDuration() / 1000;
$end = time();
$start = $end - $duration;
$memory = $stopWatchEvent->getMemory() / 1048576;
// Returns the max memory usage of all periods
$log = array('start' => $start, 'end' => $end, 'duration' => $duration, 'memory' => $memory, 'extra' => json_encode($extra));
if (null !== $output) {
$output->writeln(sprintf("=== Start time : <info>%s</info>", date('d/m/Y H:i:s', $log['start'])));
$output->writeln(sprintf("=== End time : <info>%s</info>", date('d/m/Y H:i:s', $log['end'])));
$output->writeln(sprintf("=== Duration : <info>%s seconds</info>", $log['duration']));
$output->writeln(sprintf("=== Memory : <info>%s Mb</info>", $log['memory']));
}
return $log;
}
/**
* Command start time (without microseconds)
* @return \DateTime
*/
protected function getStartTime()
{
$date = \DateTime::createFromFormat('U', (int) ($this->stopWatchEvent->getOrigin() / 1000));
if (!$date) {
$this->logger->debug('getStartTime error', array('tag' => 'UNABLE_TO_CREATE_DATETIME', 'origin' => $this->stopWatchEvent->getOrigin(), 'originType' => gettype($this->stopWatchEvent->getOrigin())));
}
return $date;
}
public function onKernelResponse(FilterResponseEvent $event)
{
// Route is null here in test environment
$route = $event->getRequest()->get('_route');
if (null === $route) {
return;
}
if (null === $this->stopwatch) {
return;
}
$requestUri = $event->getRequest()->getUri();
// find out if this is a profiler request, if not don't analyze it
try {
$this->stopwatchEvent = $this->stopwatch->stop($requestUri);
} catch (\LogicException $e) {
// do nothing, we shouldn't be analyzing this controller
return false;
}
$duration = $this->stopwatchEvent->getDuration();
$requestMetric = new RequestMetric();
$requestMetric->setUri($requestUri)->setDuration($duration)->setRoute($route);
$this->requestMetricRepository->persistAndFlush($requestMetric);
}
public function testEndTime()
{
$event = new StopwatchEvent(microtime(true) * 1000);
$this->assertEquals(0, $event->getEndTime());
$event = new StopwatchEvent(microtime(true) * 1000);
$event->start();
$this->assertEquals(0, $event->getEndTime());
$event = new StopwatchEvent(microtime(true) * 1000);
$event->start();
usleep(100000);
$event->stop();
$event->start();
usleep(100000);
$event->stop();
$this->assertEquals(200, $event->getEndTime(), null, self::DELTA);
}
/**
* @param StopwatchEvent $event
*
* @return string
*/
private function formatStopwatchEvent(StopwatchEvent $event)
{
return sprintf('Time: %s, Memory: %s.', Helper::formatTime($event->getDuration() / 1000), Helper::formatMemory($event->getMemory()));
}
public function testHumanRepresentation()
{
$event = new StopwatchEvent(microtime(true) * 1000);
$this->assertEquals('default: 0.00 MiB - 0 ms', (string) $event);
$event->start();
$event->stop();
$this->assertEquals(1, preg_match('/default: [0-9\.]+ MiB - [0-9]+ ms/', (string) $event));
$event = new StopwatchEvent(microtime(true) * 1000, 'foo');
$this->assertEquals('foo: 0.00 MiB - 0 ms', (string) $event);
}
/**
* @param string $query
* @param StopwatchEvent $event
* @param string[] $parameters
* @param string $action
* @param string $mode
*/
protected function log($query, array $parameters, StopwatchEvent $event, $action, $mode)
{
$this->logger->debug($query, array('execution_time' => $event->getDuration(), 'real_memory_usage' => $event->getMemory(), 'parameters' => $parameters, 'action' => $action, 'mode' => $mode, 'backend_name' => $this->backendName));
}
/**
* Format duration.
*
* @param string $name Name of stop watch.
* @param StopwatchEvent $event Stopwatch event.
*
* @return string
*/
private function formatDuration($name, $event)
{
return 'Dom manipulation ' . $name . ' time: ' . $event->getDuration() . ' ms';
}
protected function formatStopwatchEvent($eventName, StopwatchEvent $event, OutputInterface $output, $withMemoryUsage = false)
{
$duration = new DateIntervalExtended('PT0S', $event->getDuration());
if ($eventName == 'total') {
$output->write('<info>Total (Full processing)</info> : ');
} else {
$output->write($eventName . ' : ');
}
$output->writeln('<comment>' . $duration->prettyFormat() . '</comment>');
if ($withMemoryUsage) {
$output->writeln('Memory usage : <comment>' . Memory::convert($event->getMemory()) . '</comment>');
}
}
/**
* Add a request to the history
*
* @param RequestInterface $request Request to add
* @param ResponseInterface $response Response of the request
* @param StopwatchEvent $event Request duration, in ms
*/
private function add(RequestInterface $request, ResponseInterface $response = null, StopwatchEvent $event = null)
{
$this->transactions[] = ['request' => $request, 'response' => $response, 'duration' => $event ? $event->getDuration() : 0];
if (count($this->transactions) > $this->limit) {
array_shift($this->transactions);
}
}
public function __construct($duration)
{
parent::__construct(0);
$this->duration = $duration;
}
public function testStartTime()
{
$event = new StopwatchEvent(microtime(true) * 1000);
$this->assertLessThanOrEqual(0.5, $event->getStartTime());
$event = new StopwatchEvent(microtime(true) * 1000);
$event->start();
$event->stop();
$this->assertLessThanOrEqual(1, $event->getStartTime());
$event = new StopwatchEvent(microtime(true) * 1000);
$event->start();
usleep(100000);
$event->stop();
$this->assertEquals(0, $event->getStartTime(), null, self::DELTA);
}
public function addTotalTimeEventInfo(StopwatchEvent $timeEvent = null)
{
$this->execInfos['total_exec_time'] = $timeEvent ? $timeEvent->getDuration() : -1;
$this->execInfos['total_exec_mem'] = $timeEvent ? $timeEvent->getMemory() : -1;
return true;
}
/**
* Stops the profiling
*
* @param StopwatchEvent $event A stopwatchEvent instance
*/
protected function stopProfiling(StopwatchEvent $event = null)
{
if ($this->stopwatch instanceof Stopwatch) {
$event->stop();
$values = array('duration' => $event->getDuration(), 'memory_end' => memory_get_usage(true), 'memory_peak' => memory_get_peak_usage(true));
$this->profiles[$this->counter] = array_merge($this->profiles[$this->counter], $values);
$this->counter++;
}
}
/**
* Get the duration of the soap call
* @return int ms
*/
public function getTiming()
{
return $this->timing->getDuration();
}
