Index: branches/5.2.x/core/units/helpers/deployment_helper.php =================================================================== --- branches/5.2.x/core/units/helpers/deployment_helper.php +++ branches/5.2.x/core/units/helpers/deployment_helper.php @@ -518,9 +518,11 @@ return true; } + $total_query_duration = 0; $this->out('Upgrading Database ... ', true); foreach ($this->revisionSqls as $revision => $sqls) { + $this->toLog(PHP_EOL . $this->revisionTitles[$revision]); echo PHP_EOL . $this->colorText($this->revisionTitles[$revision], 'gray', true) . PHP_EOL; // 'Processing DB Revision: #' . $revision . ' ... '; $sqls = str_replace("\r\n", "\n", $sqls); // convert to linux line endings @@ -538,20 +540,37 @@ continue; } elseif ( $sql ) { - $this->toLog($sql . ' ... ', false); + $this->toLog($sql . '; ... ', false); $escaped_sql = $this->isCommandLine ? $sql : kUtil::escape($sql); echo mb_substr(trim(preg_replace('/(\n|\t| )+/is', ' ', $escaped_sql)), 0, self::SQL_TRIM_LENGTH) . ' ... '; + $query_start_time = time(); $this->Conn->Query($sql); + $query_end_time = time(); + $query_duration = $query_end_time - $query_start_time; + $total_query_duration += $query_duration; + $formatted_query_duration = $this->formatDuration($query_duration); $this->toLog('OK (' . $this->Conn->getAffectedRows() . ')'); - $this->displayStatus('OK (' . $this->Conn->getAffectedRows() . ')'); + $this->toLog(sprintf( + 'Duration: %s (from %s to %s)', + $formatted_query_duration, + date('Y-m-d H:i:s', $query_start_time), + date('Y-m-d H:i:s', $query_end_time) + )); + + $this->displayStatus(sprintf( + 'OK (%s) %s', + $this->Conn->getAffectedRows(), + $this->applyColorByDuration('*Time*: ' . $formatted_query_duration, $query_duration) + )); } } } catch (Exception $e) { // consider revisions with errors applied $this->appliedRevisions[] = $revision; + $this->displaysDatabaseQueryExecutionTotals($total_query_duration); $this->out('========', true); $this->toLog('========'); @@ -579,12 +598,77 @@ $this->appliedRevisions[] = $revision; } - echo PHP_EOL; + $this->displaysDatabaseQueryExecutionTotals($total_query_duration); return true; } /** + * Displays database query execution totals. + * + * @param integer $total_query_duration Duration. + * + * @return void + */ + protected function displaysDatabaseQueryExecutionTotals($total_query_duration) + { + $formatted_total_query_duration = $this->formatDuration($total_query_duration); + + echo PHP_EOL; + echo $this->colorText('Total SQL Time: ' . $formatted_total_query_duration, 'red', true); + echo PHP_EOL; + + $this->toLog(PHP_EOL . 'Total SQL Duration: ' . $formatted_total_query_duration); + } + + /** + * Formats duration and applies color to it. + * + * @param string $text Text. + * @param integer $seconds Seconds. + * + * @return string + */ + protected function applyColorByDuration($text, $seconds) + { + // 1 minute. + if ( $seconds <= 60 ) { + return $text; + } + + // 5 minutes. + if ( $seconds <= 300 ) { + return $this->colorText($text, 'cyan', true); + } + + // Longer. + return $this->colorText($text, 'red', true); + } + + /** + * Formats duration. + * + * @param integer $seconds Seconds. + * + * @return string + */ + protected function formatDuration($seconds) + { + $real_seconds = $seconds % 60; + $minutes = $seconds - $real_seconds; + + $ret = array(); + + if ( $minutes ) { + $ret[] = ($minutes / 60) . 'm'; + } + + $ret[] = $real_seconds . 's'; + + return implode(' ', $ret); + } + + /** * Error handler for sql errors. * * @param integer $code Error code.