database_cleaner-active_record icon indicating copy to clipboard operation
database_cleaner-active_record copied to clipboard

Truncation takes longer and longer

Open georgeu2000 opened this issue 10 years ago • 5 comments

I had noticed that my specs are getting very slow, and started investigating strategies. Apparently the more you truncate, the longer it takes. This behavior seems very strange:

irb(main):009:0> t = Time.now; 10.times{ DatabaseCleaner.clean_with :truncation }; Time.now - t=> 1.023764
irb(main):010:0> t = Time.now; 10.times{ DatabaseCleaner.clean_with :truncation }; Time.now - t
=> 0.793042
irb(main):011:0> t = Time.now; 10.times{ DatabaseCleaner.clean_with :truncation }; Time.now - t
=> 0.829454
irb(main):012:0> t = Time.now; 10.times{ DatabaseCleaner.clean_with :truncation }; Time.now - t
=> 0.870453
irb(main):013:0> t = Time.now; 10.times{ DatabaseCleaner.clean_with :truncation }; Time.now - t
=> 0.940325
irb(main):014:0> t = Time.now; 10.times{ DatabaseCleaner.clean_with :truncation }; Time.now - t
=> 1.03202
irb(main):015:0> t = Time.now; 10.times{ DatabaseCleaner.clean_with :truncation }; Time.now - t
=> 2.176829
irb(main):016:0> t = Time.now; 10.times{ DatabaseCleaner.clean_with :truncation }; Time.now - t
=> 2.466992
irb(main):017:0> t = Time.now; 10.times{ DatabaseCleaner.clean_with :truncation }; Time.now - t
=> 2.341618
irb(main):018:0> t = Time.now; 10.times{ DatabaseCleaner.clean_with :truncation }; Time.now - t
=> 2.4591
irb(main):019:0> t = Time.now; 10.times{ DatabaseCleaner.clean_with :truncation }; Time.now - t
=> 3.078432
irb(main):020:0> t = Time.now; 10.times{ DatabaseCleaner.clean_with :truncation }; Time.now - t
=> 3.056646
irb(main):021:0> t = Time.now; 10.times{ DatabaseCleaner.clean_with :truncation }; Time.now - t
=> 3.314674
irb(main):022:0> t = Time.now; 10.times{ DatabaseCleaner.clean_with :truncation }; Time.now - t
=> 3.514017
irb(main):023:0> t = Time.now; 10.times{ DatabaseCleaner.clean_with :truncation }; Time.now - t
=> 3.822936
irb(main):024:0> t = Time.now; 10.times{ DatabaseCleaner.clean_with :truncation }; Time.now - t
=> 4.109673

georgeu2000 avatar Jun 23 '15 22:06 georgeu2000

I tried this on another app, and saw the same behavior.

georgeu2000 avatar Jun 23 '15 22:06 georgeu2000

What database are you using?

shamil614 avatar Jun 25 '15 14:06 shamil614

How did you discover this? Did you see it materialize in your tests? I ask because this issue could explain some of the problems I'm finding in my tests.

shamil614 avatar Jun 25 '15 14:06 shamil614

Using PostgreSQL.

I noticed that truncation was much slower than transaction. So, I started benchmarking truncation, transaction and deletion.

georgeu2000 avatar Jun 25 '15 15:06 georgeu2000

Hmmm I'm using MySQL and we're getting odd test failures with parallel_tests on cucumber integration specs.

shamil614 avatar Jun 25 '15 16:06 shamil614