Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
10.0(EOL), 10.1(EOL)
-
None
-
10.0.23
Description
Initially reported on the mailing list: https://lists.launchpad.net/maria-discuss/msg02495.html .
Stage: 1 of 72 'altering table' 350% of stage done.
|
Reproducible as described.
Dataset: salaries table in the employees sample database.
Statements that exhibit the incorrect behaviour:
ALTER TABLE salaries ENGINE = Innodb; |
ALTER TABLE salaries ADD id INT NULL; |
ALTER TABLE salaries DROP id; |
ALTER TABLE salaries ROW_FORMAT = COMPRESSED; |
I also saw the mentioned 350% and some other values, e.g.
MariaDB [employees]> ALTER TABLE salaries ADD id INT NULL;
|
Stage: 1 of 85 'altering table' 200% of stage done
|
MyISAM looks reasonable (2 stages, below 100% progress).
Not reproducible on 5.5.
10.0 has a different problem – progress for InnoDB tables is not reported at all.
Attachments
Issue Links
- links to
Activity
I experienced this (InnoDB, 71 stages, up to 900%) on 10.0.21 as well.
I am hitting this bug on 10.0.21 but with another additional issue : The progress on the CLI starts but after few seconds get stuck and the "STAGE", "MAX_STAGE" and "PROGRESS" columns of "I_S.PROCESSLIST" are all showing 0 for the alter query.
Happened with an INDEX creation on an InnoDB table and on a "ALTER TABLE xxx KEY_BLOCK_SIZE=0" (on a table that had "ROW_FORMAT=DYNAMIC" and "KEY_BLOCK_SIZE=8").
Still seeing this on 10.1.8:
MariaDB [music]> ALTER TABLE items ADD INDEX (datePriceChanged);
|
Stage: 1 of 207 'altering table' 5.77% of stage done
|
Stage: 1 of 207 'altering table' 15.4% of stage done
|
Stage: 1 of 207 'altering table' 38.5% of stage done
|
Stage: 1 of 207 'altering table' 85.7% of stage done
|
Stage: 1 of 207 'altering table' 175% of stage done
|
Stage: 1 of 207 'altering table' 400% of stage done
|
|
|
Same problem with MariaDB 10.0.22 on Gentoo Linux (amd64).
MariaDB [db]> optimize table tbl;
Stage: 1 of 69 'altering table' 650% of stage done
MariaDB [db]> optimize table tbl;
Stage: 1 of 69 'altering table' 1.4e+03% of stage done
10.1: storage/[xtradb|innobase]/row/row0merge.cc function row_merge_sort line 254 there is thd_progress_init(trx->mysql_thd, num_runs); maybe should make sure that num_runs is correct here. This could be naturally be some other bug...
jplindst, please review fix for this bug. Even though it fixes described problem, I'd say InnoDB progress report is still misleading: e.g. for given queries row merge takes just ~20 seconds of ~10 minutes, so that one can watch "Stage: 1 of 1 'altering table' 98.7% of stage done" for about 9 remaining minutes.
What InnoDB or something else is doing those remaining 9 minutes ?
After
MDEV-8179it showed on 10.0.20 today:optimize table sazky;Stage: 1 of 149 'altering table' 1.33% of stage doneStage: 1 of 149 'altering table' 15.8% of stage doneStage: 1 of 149 'altering table' 100% of stage done-- until here tmp file has stable size of 320K, and only after getting to 100% it started to grow by some MB per secondStage: 1 of 149 'altering table' 350% of stage doneStage: 1 of 149 'altering table' 800% of stage doneStage: 1 of 14 'altering table' 14.3% of stage doneStage: 1 of 10 'altering table' 20% of stage doneStage: 1 of 14 'altering table' 14.3% of stage doneStage: 1 of 15 'altering table' 12.5% of stage doneStage: 1 of 11 'altering table' 16.7% of stage doneStage: 1 of 9 'altering table' 20% of stage doneStage: 1 of 12 'altering table' 16.7% of stage doneStage: 1 of 18 'altering table' 11.1% of stage doneStage: 1 of 8 'altering table' 25% of stage done+----------------+----------+----------+-------------------------------------------------------------------+| Table | Op | Msg_type | Msg_text |+----------------+----------+----------+-------------------------------------------------------------------+| vic_main.sazky | optimize | note | Table does not support optimize, doing recreate + analyze instead || vic_main.sazky | optimize | status | OK |+----------------+----------+----------+-------------------------------------------------------------------+2 rows in set (3 min 1.22 sec)show table status like 'sazky'\G*************************** 1. row ***************************Name: sazkyEngine: InnoDBVersion: 10Row_format: CompactRows: 1138155Avg_row_length: 153Data_length: 174800896Max_data_length: 0Index_length: 246022144Data_free: 0...