database_cleaner icon indicating copy to clipboard operation
database_cleaner copied to clipboard

Highly variable duration of truncations (not a database_cleaner issue)

Open kriom opened this issue 1 year ago • 0 comments

I'm sorry to ask my question here, but as I can't find an explanation elsewhere, I'm asking you because I figure you must have a good grasp of the subject. When I use a DatabaseCleaner.clean_with(:truncation) before launching my rails tests, I get very variable execution times for each drop table query, even though my tables are almost empty. This varies from 30 to 400 ms, and the slow / fast requests follow each other, so it's as if the MySQL Server is going faster or slower. Do you have an explanation and a way of solving this problem?

$ tail -f log/test.log
D, [2023-10-12T09:17:39.404980 #25359] DEBUG -- :    (45.5ms)  TRUNCATE TABLE `table1`
D, [2023-10-12T09:17:39.438557 #25359] DEBUG -- :    (33.4ms)  TRUNCATE TABLE `table2`
D, [2023-10-12T09:17:39.473029 #25359] DEBUG -- :    (34.3ms)  TRUNCATE TABLE `table3`
D, [2023-10-12T09:17:39.514899 #25359] DEBUG -- :    (41.7ms)  TRUNCATE TABLE `table4`
D, [2023-10-12T09:17:39.631417 #25359] DEBUG -- :    (116.3ms)  TRUNCATE TABLE `table5`
D, [2023-10-12T09:17:39.685199 #25359] DEBUG -- :    (53.3ms)  TRUNCATE TABLE `table6`
D, [2023-10-12T09:17:39.738879 #25359] DEBUG -- :    (53.2ms)  TRUNCATE TABLE `table7`
D, [2023-10-12T09:17:39.809097 #25359] DEBUG -- :    (69.7ms)  TRUNCATE TABLE `table8`
D, [2023-10-12T09:17:39.889177 #25359] DEBUG -- :    (79.6ms)  TRUNCATE TABLE `table9`
D, [2023-10-12T09:17:39.933648 #25359] DEBUG -- :    (44.0ms)  TRUNCATE TABLE `table10`
D, [2023-10-12T09:17:39.992856 #25359] DEBUG -- :    (58.7ms)  TRUNCATE TABLE `table11`
D, [2023-10-12T09:17:40.299925 #25359] DEBUG -- :    (306.6ms)  TRUNCATE TABLE `table12`
D, [2023-10-12T09:17:40.454695 #25359] DEBUG -- :    (154.4ms)  TRUNCATE TABLE `table13`
D, [2023-10-12T09:17:40.590997 #25359] DEBUG -- :    (136.0ms)  TRUNCATE TABLE `table14`
D, [2023-10-12T09:17:40.718787 #25359] DEBUG -- :    (127.3ms)  TRUNCATE TABLE `table15`
D, [2023-10-12T09:17:40.925396 #25359] DEBUG -- :    (206.1ms)  TRUNCATE TABLE `table16`
D, [2023-10-12T09:17:41.103438 #25359] DEBUG -- :    (177.6ms)  TRUNCATE TABLE `table17`
D, [2023-10-12T09:17:41.305653 #25359] DEBUG -- :    (201.8ms)  TRUNCATE TABLE `table18`
D, [2023-10-12T09:17:41.509797 #25359] DEBUG -- :    (203.7ms)  TRUNCATE TABLE `table19`
D, [2023-10-12T09:17:41.756406 #25359] DEBUG -- :    (246.1ms)  TRUNCATE TABLE `table20`
D, [2023-10-12T09:17:42.136319 #25359] DEBUG -- :    (379.4ms)  TRUNCATE TABLE `table21`
D, [2023-10-12T09:17:42.322232 #25359] DEBUG -- :    (185.4ms)  TRUNCATE TABLE `table22`

Thank you for your time !

kriom avatar Oct 12 '23 07:10 kriom