MDEV-39597: Remove save/restore of proc_info in free_tmp_table#5097
MDEV-39597: Remove save/restore of proc_info in free_tmp_table#5097ARaveala wants to merge 1 commit into
Conversation
There was a problem hiding this comment.
Code Review
This pull request introduces a new test case to verify that SHOW PROFILE does not report duplicate stages, such as 'Removing tmp table', during INSERT...SELECT operations. Feedback suggests improving the test's robustness by avoiding hardcoded query IDs and expanding the test coverage to include 'Creating sort index' scenarios for GROUP BY queries as mentioned in the PR description.
| LAG(STATE) OVER (ORDER BY SEQ) AS prev_status, | ||
| LEAD(STATE) OVER (ORDER BY SEQ) AS next_status | ||
| FROM information_schema.profiling | ||
| WHERE QUERY_ID = 1 |
There was a problem hiding this comment.
Hardcoding QUERY_ID = 1 makes the test fragile. If additional queries are added to the test file before profiling is enabled, or if the test is integrated into a larger suite where the connection is reused, the QUERY_ID for the target statement might not be 1. It is more robust to use a subquery to fetch the most recent QUERY_ID.
WHERE QUERY_ID = (SELECT MAX(QUERY_ID) FROM information_schema.profiling)
There was a problem hiding this comment.
QUERY_ID = 1 is intentional. SET profiling = 1 is not profiled, so the INSERT...SELECT is always query 1 in a fresh session. Using MAX(QUERY_ID) would be fragile here as subsequent queries in the test would become the MAX.
|
|
||
| # clean up | ||
| SET profiling = 0; | ||
| DROP TABLE profile_test; No newline at end of file |
There was a problem hiding this comment.
There was a problem hiding this comment.
GROUP BY with filesort is implicitly fixed by the same change but is out of scope for this ticket which specifically covers INSERT...SELECT. Happy to add one here or open a separate ticket based on reviewer preference.
23e3105 to
e814a04
Compare
gkodinov
left a comment
There was a problem hiding this comment.
Thank you for your contribution. This is a preliminary review.
First of all: this is a bug fix. Please clarify what is the lowest affected version still in production and rebase on that.
Also, please make sure the test actually tests what you are trying to fix. A good test should fail without the C++ change and pass with it.
|
|
||
| --echo # Check that no stage appears twice consecutivley around removing tmp table | ||
|
|
||
| SELECT COUNT(*) AS duplicate_stage_found |
There was a problem hiding this comment.
I do not get the effect described using the queries in the test neither in 10.11 nor in 13.1. In 13.1 I get:
MariaDB [test]> SELECT
-> STATE,
-> LAG(STATE) OVER (ORDER BY SEQ) AS prev_status,
-> LEAD(STATE) OVER (ORDER BY SEQ) AS next_status
-> FROM information_schema.profiling
-> WHERE QUERY_ID = 1;
+------------------------+-----------------+------------------------+
| STATE | prev_status | next_status |
+------------------------+-----------------+------------------------+
| Starting | NULL | Freeing items |
| Freeing items | Starting | Updating status |
| Updating status | Freeing items | Reset for next command |
| Reset for next command | Updating status | NULL |
+------------------------+-----------------+------------------------+
4 rows in set (0.006 sec)
And in 10.11 I get:
MariaDB [(none)]> SELECT
-> STATE,
-> LAG(STATE) OVER (ORDER BY SEQ) AS prev_status,
-> LEAD(STATE) OVER (ORDER BY SEQ) AS next_status
-> FROM information_schema.profiling
-> WHERE QUERY_ID = 1;
+------------------------+-----------------+------------------------+
| STATE | prev_status | next_status |
+------------------------+-----------------+------------------------+
| Starting | NULL | Freeing items |
| Freeing items | Starting | Updating status |
| Updating status | Freeing items | Reset for next command |
| Reset for next command | Updating status | NULL |
+------------------------+-----------------+------------------------+
4 rows in set (0.001 sec)
There was a problem hiding this comment.
Thank you for the review.
On reproducing the issue:
The profile output shown has only 4 stages "Starting", "Freeing items", "Updating status", "Reset for next command", which is consistent with a simple statement, not an INSERT...SELECT. An INSERT...SELECT would show stages including "Opening tables", "Creating tmp table", "Sending data". It appears the INSERT...SELECT from the test setup was not run before querying information_schema.profiling.
To reproduce, please run the full sequence in a fresh session:
CREATE TABLE profile_test (
id INT PRIMARY KEY AUTO_INCREMENT,
name VARCHAR(100),
value INT
);
INSERT INTO profile_test (name, value) VALUES
('alpha',1),('beta',2),('gamma',3),('delta',4),('epsilon',5),
('zeta',6),('eta',7),('theta',8),('iota',9),('kappa',10);
SET profiling = 1;
INSERT INTO profile_test (name, value)
SELECT name, value FROM profile_test LIMIT 5;
SHOW PROFILE;
SET profiling = 1 is not itself profiled, so the INSERT...SELECT becomes QUERY_ID = 1.
The table creation and data insertion are setup steps required to trigger the tmp table code path, without them the duplicate will not appear.
On the test:
The test was confirmed to fail on unpatched code and pass with the fix applied locally. The trailing newline has been added.
On the lowest affected version:
The same save/restore pattern exists in 10.11. I will confirm the bug reproduces there and rebase accordingly once we confirm the reproduce steps work for you.
There was a problem hiding this comment.
my bad: I missed the INSERT part when trying. It does indeed fail when not patched.
|
|
||
| # clean up | ||
| SET profiling = 0; | ||
| DROP TABLE profile_test; No newline at end of file |
There was a problem hiding this comment.
please always terminate the last line with a unix new line (LF).
…he_info Do not run the test if query_cache_info is missing Fixes test on appveyor (which does not build any loadable plugins) MDEV-39597: Remove save/restore of proc_info in free_tmp_table SHOW PROFILE reports duplicate stage entries for INSERT...SELECT caused by a save/restore pattern in free_tmp_table that blindly restores the previouse stage name after tmp table removal. The fix removes the save/restore. The 'Removing tmp table' stage now remians active untill the caller sets the next stage. fixup: adjust test for PS2 protocol. Test uses --disable_ps2_protocol following the pattern in show_profile.test to ensure consistent QUERY_ID in PS protocol mode. fixup: add trailing newline to test file
e814a04 to
99ed572
Compare
gkodinov
left a comment
There was a problem hiding this comment.
If it indeed reproduces in 10.11, that's where it needs to go. Thanks for your work on this!
|
|
||
| --echo # Check that no stage appears twice consecutivley around removing tmp table | ||
|
|
||
| SELECT COUNT(*) AS duplicate_stage_found |
There was a problem hiding this comment.
my bad: I missed the INSERT part when trying. It does indeed fail when not patched.
There was a problem hiding this comment.
hmm, why the diff? this is present in my copy of this file. Please double-check you did the merges correctly.
There was a problem hiding this comment.
Confirmed reproduced on 10.11. I have created a branch targeting 10.11 and will update the PR shortly. Currently building and running MTR tests on 10.11 before updating.
The query_cache diff was caused by not rebasing after the upstream fix, now resolved.
MDEV-39597: Remove save/restore of proc_info in free_tmp_table
Problem
SHOW PROFILEreports duplicate stage entries forINSERT...SELECTqueries. The duplicate appears immediately after "Removing tmp table" and is caused by a save/restore pattern infree_tmp_tablethat blindly restores the previous stage name on exit, regardless of whether that stage is still accurate.The same pattern implicitly also caused a duplicate "Creating sort index" entry in
GROUP BYwith filesort queries.Fix
Removed the save and restore of proc_info in
free_tmp_table. The "Removing tmp table" stage now remains active until the caller sets the next stage.Trade-off
"Removing tmp table" will now appear slightly longer in profiles as it remains active briefly after the function returns. This is considered less misleading than restoring an incorrect stage name.
Scope
free_tmp_tableis called from multiple files. A broader audit of all call sites is out of scope for this fix:Further investigation
The same save/restore pattern appears in other locations in the codebase. I intend to investigate these separately, any guidance on what to prioritise or test would be welcome.
SHOW PROFILE results abbreviated:
Before (INSERT...SELECT)
| Sending data | 0.002404 |
| Removing tmp table | 0.000098 |
| Sending data | 0.000079 | ← duplicate
| End of update loop | 0.000074 |
After
| Sending data | 0.002482 |
| Removing tmp table | 0.000172 |
| End of update loop | 0.000077 |
Provided under BSD New 3 Clause License.