[PR #6005] Improve functional test query logger #9811

Open
opened 2026-01-22 16:05:29 +01:00 by admin · 0 comments
Owner

Original Pull Request: https://github.com/doctrine/orm/pull/6005

State: closed
Merged: Yes


The onNotSuccessfulTest method in OrmFunctionalTestCase prints out the actual queries that were executed during a failed test, but currently it does not show the last query at all.

This is because the DebugStack that is used to record the queries starts it's index from 1, but the code that iterates them assumes it starts from 0.

So I changed the iteration to use foreach instead of a for loop and transform the array beforehand to only contain the last 25 queries in reverse order.

Also, the way query params is currently handeled fails on array types with the following message:

Array to string conversion
 doctrine2/tests/Doctrine/Tests/OrmFunctionalTestCase.php:756

I have used var_export to overcome this issue and print out the array values.

Example output:

4. SQL: 'INSERT INTO company_employees (id, salary, departments, startDate) VALUES (?, ?, ?, ?)' Params: 1, 666, array (
  0 => 'Sales',
  1 => 'Marketing',
), NULL

The downside is that it breaks it into multiple lines, but I think it's OK. It could be further improved to output something like [0 => 'Sales', 1 => 'Marketing'] if that is a problem. But at least it's better than an error.

By using var_export instead of plain string concatenation we also get better insight into the types of the parameters, as it shows numeric values without quotes, boolean values as true and false (instead of '1' and '') and null values as NULL (instead of '').

Below is a more detailed example of the output before and after the changes.

Before:
With queries:
12. SQL: 'SELECT COUNT(*) FROM company_contract_managers t WHERE t.employee_id = ?' Params: '1'
11. SQL: 'SELECT t2.id AS id_3, t2.name AS name_4, t1.salary AS salary_5, t1.department AS department_6, t1.startDate AS startDate_7, t0.title AS title_8, t2.spouse_id AS spouse_id_9, t0.car_id AS car_id_10, t2.discr FROM company_managers t0 INNER JOIN company_employees t1 ON t0.id = t1.id INNER JOIN company_persons t2 ON t0.id = t2.id WHERE t2.id = ?' Params: '1'
10. SQL: '"COMMIT"' Params: 
9. SQL: 'INSERT INTO company_contract_managers (contract_id, employee_id) VALUES (?, ?)' Params: '2', '1'
8. SQL: 'INSERT INTO company_contract_managers (contract_id, employee_id) VALUES (?, ?)' Params: '1', '1'
7. SQL: 'INSERT INTO company_contracts (completed, salesPerson_id, hoursWorked, pricePerHour, discr) VALUES (?, ?, ?, ?, ?)' Params: '', '', '0', '0', 'flexible'
6. SQL: 'INSERT INTO company_contracts (completed, salesPerson_id, hoursWorked, pricePerHour, discr) VALUES (?, ?, ?, ?, ?)' Params: '1', '', '0', '0', 'flexible'
5. SQL: 'INSERT INTO company_employees (id, salary, department, startDate) VALUES (?, ?, ?, ?)' Params: '1', '666', 'Marketing', ''
4. SQL: 'INSERT INTO company_managers (id, title, car_id) VALUES (?, ?, ?)' Params: '1', 'Boss', ''
3. SQL: 'INSERT INTO company_persons (name, spouse_id, discr) VALUES (?, ?, ?)' Params: 'Gandalf', '', 'manager'
2. SQL: '"START TRANSACTION"' Params: 

After:

With queries:
12. SQL: 'SELECT te.id AS id, te.completed AS completed, te.hoursWorked AS hoursWorked, te.pricePerHour AS pricePerHour, te.salesPerson_id AS salesPerson_id FROM company_contracts te JOIN company_contract_managers t ON t.contract_id = te.id WHERE t.employee_id = ? AND te.completed = ?' Params: 1, true
11. SQL: 'SELECT COUNT(*) FROM company_contract_managers t WHERE t.employee_id = ?' Params: 1
10. SQL: 'SELECT t2.id AS id_3, t2.name AS name_4, t1.salary AS salary_5, t1.department AS department_6, t1.startDate AS startDate_7, t0.title AS title_8, t2.spouse_id AS spouse_id_9, t0.car_id AS car_id_10, t2.discr FROM company_managers t0 INNER JOIN company_employees t1 ON t0.id = t1.id INNER JOIN company_persons t2 ON t0.id = t2.id WHERE t2.id = ?' Params: 1
9. SQL: '"COMMIT"' Params: 
8. SQL: 'INSERT INTO company_contract_managers (contract_id, employee_id) VALUES (?, ?)' Params: 2, 1
7. SQL: 'INSERT INTO company_contract_managers (contract_id, employee_id) VALUES (?, ?)' Params: 1, 1
6. SQL: 'INSERT INTO company_contracts (completed, salesPerson_id, hoursWorked, pricePerHour, discr) VALUES (?, ?, ?, ?, ?)' Params: false, NULL, 0, 0, 'flexible'
5. SQL: 'INSERT INTO company_contracts (completed, salesPerson_id, hoursWorked, pricePerHour, discr) VALUES (?, ?, ?, ?, ?)' Params: true, NULL, 0, 0, 'flexible'
4. SQL: 'INSERT INTO company_employees (id, salary, department, startDate) VALUES (?, ?, ?, ?)' Params: 1, 666, 'Marketing', NULL
3. SQL: 'INSERT INTO company_managers (id, title, car_id) VALUES (?, ?, ?)' Params: 1, 'Boss', NULL
2. SQL: 'INSERT INTO company_persons (name, spouse_id, discr) VALUES (?, ?, ?)' Params: 'Gandalf', NULL, 'manager'
1. SQL: '"START TRANSACTION"' Params:
**Original Pull Request:** https://github.com/doctrine/orm/pull/6005 **State:** closed **Merged:** Yes --- The `onNotSuccessfulTest` method in `OrmFunctionalTestCase` prints out the actual queries that were executed during a failed test, but currently it does not show the last query at all. This is because the `DebugStack` that is used to record the queries starts it's index from 1, but the code that iterates them assumes it starts from 0. So I changed the iteration to use `foreach` instead of a `for` loop and transform the array beforehand to only contain the last 25 queries in reverse order. Also, the way query params is currently handeled fails on array types with the following message: ``` Array to string conversion doctrine2/tests/Doctrine/Tests/OrmFunctionalTestCase.php:756 ``` I have used `var_export` to overcome this issue and print out the array values. Example output: ``` 4. SQL: 'INSERT INTO company_employees (id, salary, departments, startDate) VALUES (?, ?, ?, ?)' Params: 1, 666, array ( 0 => 'Sales', 1 => 'Marketing', ), NULL ``` The downside is that it breaks it into multiple lines, but I think it's OK. It could be further improved to output something like `[0 => 'Sales', 1 => 'Marketing']` if that is a problem. But at least it's better than an error. By using `var_export` instead of plain string concatenation we also get better insight into the types of the parameters, as it shows numeric values without quotes, boolean values as `true` and `false` (instead of `'1'` and `''`) and null values as `NULL` (instead of `''`). Below is a more detailed example of the output before and after the changes. <details> Before: ``` With queries: 12. SQL: 'SELECT COUNT(*) FROM company_contract_managers t WHERE t.employee_id = ?' Params: '1' 11. SQL: 'SELECT t2.id AS id_3, t2.name AS name_4, t1.salary AS salary_5, t1.department AS department_6, t1.startDate AS startDate_7, t0.title AS title_8, t2.spouse_id AS spouse_id_9, t0.car_id AS car_id_10, t2.discr FROM company_managers t0 INNER JOIN company_employees t1 ON t0.id = t1.id INNER JOIN company_persons t2 ON t0.id = t2.id WHERE t2.id = ?' Params: '1' 10. SQL: '"COMMIT"' Params: 9. SQL: 'INSERT INTO company_contract_managers (contract_id, employee_id) VALUES (?, ?)' Params: '2', '1' 8. SQL: 'INSERT INTO company_contract_managers (contract_id, employee_id) VALUES (?, ?)' Params: '1', '1' 7. SQL: 'INSERT INTO company_contracts (completed, salesPerson_id, hoursWorked, pricePerHour, discr) VALUES (?, ?, ?, ?, ?)' Params: '', '', '0', '0', 'flexible' 6. SQL: 'INSERT INTO company_contracts (completed, salesPerson_id, hoursWorked, pricePerHour, discr) VALUES (?, ?, ?, ?, ?)' Params: '1', '', '0', '0', 'flexible' 5. SQL: 'INSERT INTO company_employees (id, salary, department, startDate) VALUES (?, ?, ?, ?)' Params: '1', '666', 'Marketing', '' 4. SQL: 'INSERT INTO company_managers (id, title, car_id) VALUES (?, ?, ?)' Params: '1', 'Boss', '' 3. SQL: 'INSERT INTO company_persons (name, spouse_id, discr) VALUES (?, ?, ?)' Params: 'Gandalf', '', 'manager' 2. SQL: '"START TRANSACTION"' Params: ``` After: ``` With queries: 12. SQL: 'SELECT te.id AS id, te.completed AS completed, te.hoursWorked AS hoursWorked, te.pricePerHour AS pricePerHour, te.salesPerson_id AS salesPerson_id FROM company_contracts te JOIN company_contract_managers t ON t.contract_id = te.id WHERE t.employee_id = ? AND te.completed = ?' Params: 1, true 11. SQL: 'SELECT COUNT(*) FROM company_contract_managers t WHERE t.employee_id = ?' Params: 1 10. SQL: 'SELECT t2.id AS id_3, t2.name AS name_4, t1.salary AS salary_5, t1.department AS department_6, t1.startDate AS startDate_7, t0.title AS title_8, t2.spouse_id AS spouse_id_9, t0.car_id AS car_id_10, t2.discr FROM company_managers t0 INNER JOIN company_employees t1 ON t0.id = t1.id INNER JOIN company_persons t2 ON t0.id = t2.id WHERE t2.id = ?' Params: 1 9. SQL: '"COMMIT"' Params: 8. SQL: 'INSERT INTO company_contract_managers (contract_id, employee_id) VALUES (?, ?)' Params: 2, 1 7. SQL: 'INSERT INTO company_contract_managers (contract_id, employee_id) VALUES (?, ?)' Params: 1, 1 6. SQL: 'INSERT INTO company_contracts (completed, salesPerson_id, hoursWorked, pricePerHour, discr) VALUES (?, ?, ?, ?, ?)' Params: false, NULL, 0, 0, 'flexible' 5. SQL: 'INSERT INTO company_contracts (completed, salesPerson_id, hoursWorked, pricePerHour, discr) VALUES (?, ?, ?, ?, ?)' Params: true, NULL, 0, 0, 'flexible' 4. SQL: 'INSERT INTO company_employees (id, salary, department, startDate) VALUES (?, ?, ?, ?)' Params: 1, 666, 'Marketing', NULL 3. SQL: 'INSERT INTO company_managers (id, title, car_id) VALUES (?, ?, ?)' Params: 1, 'Boss', NULL 2. SQL: 'INSERT INTO company_persons (name, spouse_id, discr) VALUES (?, ?, ?)' Params: 'Gandalf', NULL, 'manager' 1. SQL: '"START TRANSACTION"' Params: ``` </details>
admin added the pull-request label 2026-01-22 16:05:29 +01:00
Sign in to join this conversation.
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: doctrine/archived-orm#9811