Open
Description
Bug Report
Q | A |
---|---|
BC Break | no |
Version | 3.8.2 |
Summary
The time taken for each query shown via --query-time
is incorrect.
Current behavior
Currently the migrator measures the cumulative time taken for all queries but presents it as the time taken for each individual query.
How to reproduce
Write a simple migration like:
$this->addSql('SELECT 1');
$this->addSql('SELECT SLEEP(1)');
$this->addSql('SELECT 1');
$this->addSql('SELECT SLEEP(1)');
$this->addSql('SELECT 1');
$this->addSql('SELECT SLEEP(1)');
$this->addSql('SELECT 1');
Execute with bin/console doctrine:migrations:migrate --query-time
.
You'll see all but the first SELECT 1
queries are shown taking seconds to complete rather than the actual sub-millisecond runtime.
notice] Migrating up to Migrations\Version20250203131759
[notice] SELECT 1
[notice] Query took 0.3ms
[notice] SELECT SLEEP(1)
[notice] Query took 1000.8ms
[notice] SELECT 1
[notice] Query took 1001.4ms
[notice] SELECT SLEEP(1)
[notice] Query took 2002ms
[notice] SELECT 1
[notice] Query took 2003ms
[notice] SELECT SLEEP(1)
[notice] Query took 3004.2ms
[notice] SELECT 1
[notice] Query took 3005.2ms
[notice] finished in 3022.9ms, used 26M memory, 1 migrations executed, 7 sql queries
Expected behavior
Something like:
notice] Migrating up to Migrations\Version20250203131759
[notice] SELECT 1
[notice] Query took 0.3ms
[notice] SELECT SLEEP(1)
[notice] Query took 1000.8ms
[notice] SELECT 1
[notice] Query took 0.4ms
[notice] SELECT SLEEP(1)
[notice] Query took 1002ms
[notice] SELECT 1
[notice] Query took 0.5ms
[notice] SELECT SLEEP(1)
[notice] Query took 1004.2ms
[notice] SELECT 1
[notice] Query took 0.2ms
[notice] finished in 3022.9ms, used 26M memory, 1 migrations executed, 7 sql queries
Alternatively if this behaviour is desired Query took
should be adapted to something like Queries have taken
Metadata
Metadata
Assignees
Labels
No labels
Activity