Merge pull request #1 from TumTum/feature/measures_time

Feature/measures time
Cette révision appartient à :
Tobias Matthaiou 2019-10-01 12:58:50 +02:00 révisé par GitHub
révision 466bb61afc
Signature inconnue de Gitea
ID de la clé GPG: 4AEE18F83AFDEB23
12 fichiers modifiés avec 2180 ajouts et 1 suppressions

16
.travis.yml Fichier normal
Voir le fichier

@ -0,0 +1,16 @@
language: php
php:
- 7.0
cache:
directories:
- $HOME/.composer/cache
before_script:
- composer install
script:
- php ./vendor/bin/phpspec run --format=pretty --stop-on-failure --no-code-generation

Voir le fichier

@ -6,6 +6,11 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
## [Unreleased]
### Added
- Measures the sql execution time
- Testing framework [phpspec](https://www.phpspec.net/en/stable/manual/introduction.html)
## [1.0.0] - 2019-07-21
### Added

Voir le fichier

@ -1,6 +1,8 @@
Oxid eShop SQL Logger
---------------------
[![Build Status](https://travis-ci.org/TumTum/oxid-sql-logger.svg?branch=master)](https://travis-ci.org/TumTum/oxid-sql-logger)
Returns all SQL queries into console of a Browser.
## Install

Voir le fichier

@ -5,6 +5,11 @@
"require": {
"monolog/monolog": "^1"
},
"require-dev": {
"phpspec/phpspec": "^4",
"doctrine/dbal": "^2.5",
"bovigo/assert": "^2"
},
"license": "GPL-3.0",
"autoload": {
"psr-4": {

1802
composer.lock générée Fichier normal

Fichier diff supprimé car celui-ci est trop grand Voir la Diff

Fichier binaire non affiché.

Avant

Largeur:  |  Hauteur:  |  Taille: 754 KiB

Après

Largeur:  |  Hauteur:  |  Taille: 284 KiB

Fichier binaire non affiché.

Avant

Largeur:  |  Hauteur:  |  Taille: 50 KiB

Après

Largeur:  |  Hauteur:  |  Taille: 62 KiB

4
phpspec.yml Fichier normal
Voir le fichier

@ -0,0 +1,4 @@
suites:
default:
namespace: "tm\\oxid\\sql\\logger\\"
psr4_prefix: "tm\\oxid\\sql\\logger\\"

89
spec/OxidSQLLoggerSpec.php Fichier normal
Voir le fichier

@ -0,0 +1,89 @@
<?php
namespace spec\tm\oxid\sql\logger;
use PhpSpec\Exception\Example\FailureException;
use tm\oxid\sql\logger\OxidSQLLogger;
use PhpSpec\ObjectBehavior;
use Monolog;
use function bovigo\assert\predicate\hasKey;
use function bovigo\assert\predicate\isOfType;
use function bovigo\assert\predicate\isSameAs;
class OxidSQLLoggerSpec extends ObjectBehavior
{
/**
* @var Monolog\Handler\TestHandler
*/
private $testLogger = null;
public function let()
{
$this->testLogger = new Monolog\Handler\TestHandler();
Monolog\Registry::addLogger(
new Monolog\Logger('sql', [$this->testLogger]),
'sql',
true
);
}
public function it_is_initializable()
{
$this->shouldHaveType(OxidSQLLogger::class);
}
/**
* @throws FailureException
*/
public function it_should_log_the_sql_normally()
{
$this->startQuery('SELECT 1', ['param1'], ['master']);
for ($i = 0; $i <= 1000; $i++) @get_declared_classes();
$this->stopQuery();
$this->assertExpectLog();
$this->assertMatchMessage('/\[\d+ms\] SELECT 1/');
$this->assertContext('params', isSameAs(['param1']));
$this->assertContext('types', isSameAs(['master']));
$this->assertContext('time', isOfType('float'));
}
/**
* @throws FailureException
*/
public function it_should_log_without_time_specification()
{
$this->startQuery('SELECT 1');
$this->startQuery('SELECT 2');
$this->assertExpectLog();
$this->assertMatchMessage('/\[Statement canceled\] SELECT 1/');
$this->assertContext('time', isSameAs('Statement canceled'));
}
private function assertExpectLog()
{
if (!$this->testLogger->hasRecords(Monolog\Logger::DEBUG)) {
throw new FailureException("No log entry was made");
}
}
private function assertMatchMessage($regex)
{
if (!$this->testLogger->hasRecordThatMatches($regex, Monolog\Logger::DEBUG)) {
$message = $this->testLogger->getRecords()[0]['message'];
throw new FailureException("Expect message '{$regex}' got '{$message}'");
};
}
private function assertContext($param, $actual)
{
$record = $this->testLogger->getRecords()[0];
\bovigo\assert\assert($record['context'], hasKey($param), "Context '{$param}' not found");
\bovigo\assert\assert($record['context'][$param], $actual, "Context '{$param} is not same");
}
}

65
spec/SQLQuerySpec.php Fichier normal
Voir le fichier

@ -0,0 +1,65 @@
<?php
namespace spec\tm\oxid\sql\logger;
use tm\oxid\sql\logger\SQLQuery;
use PhpSpec\ObjectBehavior;
use Prophecy\Argument;
/**
* Class SQLQuerySpec
* @package spec\tm\oxid\sql\logger
*/
class SQLQuerySpec extends ObjectBehavior
{
public function it_is_initializable()
{
$this->shouldHaveType(SQLQuery::class);
}
public function it_hat_sql_setter_getter()
{
$this->setSQL('SELECT NOW()')->shouldHaveType(SQLQuery::class);
$this->getSQL()->shouldBe('SELECT NOW()');
}
public function it_hat_params_setter_getter()
{
$this->setParams(['param1', 'param2'])->shouldHaveType(SQLQuery::class);
$this->getParams()->shouldBe(['param1', 'param2']);
}
public function it_hat_type_setter_getter()
{
$this->setTypes(['type1'])->shouldHaveType(SQLQuery::class);
$this->getTypes()->shouldBe(['type1']);
}
public function it_should_indicate_an_aborted_time()
{
$this->setSql('SELECT 1');
$this->setCanceled()->shouldHaveType(SQLQuery::class);
$this->getElapsedTime()->shouldBe('Statement canceled');
}
public function it_should_display_with_a_readable_time()
{
$this->setSql('SELECT 1');
sleep(1);
$this->getReadableElapsedTime()->shouldMatch('/^1\.\d\d\ds/');
}
public function it_should_display_with_a_readable_time_in_ms()
{
$this->setSql('SELECT 1');
for ($i = 0; $i <= 1000; $i++) @get_declared_classes();
$this->getReadableElapsedTime()->shouldMatch('/^\d{1,3}ms/');
}
public function it_should_display_a_time_in_float()
{
$this->setSql('SELECT 1');
for ($i = 0; $i <= 1000; $i++) @get_declared_classes();
$this->getElapsedTime()->shouldBeFloat();
}
}

Voir le fichier

@ -16,6 +16,11 @@ use Monolog;
*/
class OxidSQLLogger implements SQLLogger
{
/**
* @var SQLQuery
*/
private $SQLQuery = null;
/**
* @inheritDoc
*/
@ -31,7 +36,14 @@ class OxidSQLLogger implements SQLLogger
*/
public function startQuery($sql, array $params = null, array $types = null)
{
Monolog\Registry::sql()->addDebug($sql, ['params' => $params, 'types' => $types]);
if ($this->SQLQuery) {
$this->SQLQuery->setCanceled();
$this->stopQuery();
}
$this->SQLQuery = (new SQLQuery()) ->setSql($sql)
->setParams($params)
->setTypes($types);
}
/**
@ -39,5 +51,17 @@ class OxidSQLLogger implements SQLLogger
*/
public function stopQuery()
{
if ($this->SQLQuery) {
Monolog\Registry::sql()->addDebug(
'['.$this->SQLQuery->getReadableElapsedTime().'] ' . $this->SQLQuery->getSql(),
[
'params' => $this->SQLQuery->getParams(),
'time' => $this->SQLQuery->getElapsedTime(),
'types' => $this->SQLQuery->getTypes(),
]
);
}
$this->SQLQuery = null;
}
}

167
src/SQLQuery.php Fichier normal
Voir le fichier

@ -0,0 +1,167 @@
<?php
/**
* Autor: Tobias Matthaiou <developer@tobimat.eu>
* Date: 2019-08-20
* Time: 21:56
*/
namespace tm\oxid\sql\logger;
/**
* Class SQLQuery
* @package tm\oxid\sql\logger
*/
class SQLQuery
{
/**
* @var float|null
*/
private $start_time = null;
/**
* @var float|null
*/
private $stop_time = null;
/**
* @var string
*/
private $sql = '';
/**
* @var null
*/
private $params = null;
/**
* @var null
*/
private $types = null;
/**
* @inheritDoc
*/
public function __construct()
{
$this->start_time = microtime(true);
}
/**
* @return string
*/
public function getSql()
{
return $this->sql;
}
/**
* @param string $sql
* @return SQLQuery
*/
public function setSql($sql)
{
$this->sql = $sql;
return $this;
}
/**
* @return null
*/
public function getParams()
{
return $this->params;
}
/**
* @param null $params
* @return SQLQuery
*/
public function setParams($params)
{
$this->params = $params;
return $this;
}
/**
* @return null
*/
public function getTypes()
{
return $this->types;
}
/**
* @param null $types
* @return SQLQuery
*/
public function setTypes($types)
{
$this->types = $types;
return $this;
}
/**
* Statement was cancelled prematurely, an error was thrown.
*
* @return $this
*/
public function setCanceled()
{
$this->start_time = null;
return $this;
}
/**
* Returns elapsed time
* @return float|string
*/
public function getElapsedTime()
{
if ($this->start_time === null) {
return 'Statement canceled';
}
if ($this->stop_time === null) {
$end_time = microtime(true);
$this->stop_time = $end_time - $this->start_time;
}
return (float)$this->stop_time;
}
/**
* Returns a human readable elapsed time
*
* @return string
*/
public function getReadableElapsedTime()
{
return $this->readableElapsedTime($this->getElapsedTime());
}
/**
* Returns a human readable elapsed time
*
* @param float $microtime
* @param string $format The format to display (printf format)
* @return string
*/
private function readableElapsedTime($microtime, $format = '%.3f%s', $round = 3)
{
if (is_string($microtime)) {
return $microtime;
}
if ($microtime >= 1) {
$unit = 's';
$time = round($microtime, $round);
} else {
$unit = 'ms';
$time = round($microtime*1000);
$format = preg_replace('/(%.[\d]+f)/', '%d', $format);
}
return sprintf($format, $time, $unit);
}
}