Performance regression in SQLbench

This log file shows the results of update_of_primary_key_many_keys and the time it is taking for each statement. Note that it takes 15-30 seconds to execute each statement at the beginning of the test but then around the 128th interation (of 256) the time drops back to less than a second as you would expect for a normal run.

From gprof output:

Each sample counts as 0.01 seconds.
  % cumulative self self total
 time seconds seconds calls s/call s/call name
 15.45 552.46 552.46 27114411 0.00 0.00 ut_delay
  4.02 696.25 143.79 3272349 0.00 0.00 ut_fold_binary
  3.20 810.55 114.30 44102878 0.00 0.00 ut_fold_ulint_pair
  2.21 889.59 79.04 831345644 0.00 0.00 rec_init_offsets
  1.82 954.62 65.04 551497076 0.00 0.00 cmp_dtuple_rec_with_match
  1.74 1016.68 62.06 489717086 0.00 0.00 rec_init_offsets_comp_ordinary
  1.64 1075.42 58.74 660522584 0.00 0.00 mutex_test_and_set
  1.55 1130.99 55.57 657174645 0.00 0.00 mutex_reset_lock_word
  1.53 1185.86 54.87 657806155 0.00 0.00 mutex_reset_lock_word
  1.46 1238.12 52.26 666143218 0.00 0.00 mutex_test_and_set 1.13 1278.64 40.53 408913870 0.00 0.00 mutex_reset_lock_word
  1.02 1315.04 36.40 403532715 0.00 0.00 mutex_test_and_set
  0.99 1350.53 35.49 351738694 0.00 0.00 mutex_reset_lock_word
  0.93 1383.90 33.37 351095354 0.00 0.00 mutex_test_and_set
  0.89 1415.81 31.91 152786797 0.00 0.00 row_search_for_mysql
  0.85 1446.31 30.50 1497905 0.00 0.00 DRIZZLEparse(void*)
  0.85 1476.57 30.26 270513565 0.00 0.00 ut_hash_ulint
  0.84 1506.69 30.12 256148447 0.00 0.00 buf_page_get_gen 0.80 1535.41 28.73 5863214 0.00 0.00 log_block_calc_checksum 0.78 1563.16 27.75 59763842 0.00 0.00 page_cur_search_with_match
  0.77 1590.70 27.54 4765010065 0.00 0.00 rec_offs_n_fields
  0.75 1617.34 26.64 824537621 0.00 0.00 rec_get_offsets_func
  0.54 1636.67 19.33 913521758 0.00 0.00 drizzled::my_tosort_utf8mb4(drizzled::unic
ase_info_st**, unsigned long*) 0.54 1655.83 19.16 5025418406 0.00 0.00 dict_field_get_col
  0.53 1674.85 19.02 1993897516 0.00 0.00 mach_read_from_2
  0.48 1692.14 17.29 240557957 0.00 0.00 buf_page_hash_get_low
  0.48 1709.31 17.17 262784916 0.00 0.00 buf_pool_get
  0.47 1726.20 16.89 1139915900 0.00 0.00 os_aio_array_get_nth_slot
  0.47 1742.90 16.70 37805489 0.00 0.00 btr_cur_search_to_nth_level

The complete log can be found on our intel 10105 machine at /home/drizzle/lee/1964/gprof.out

Other sqlbench tests which are foobar

delete_all_many_keys - normal was around 200-300 seconds, now goes to 1300-2200 seconds
delete_big_many_keys - normal was around 200-300 seconds, now goes to 1300-2200 seconds
insert_key - normal was around 150-300 seconds, now goes to 800-950 seconds
delete_all_many_keys - normal was around 200-300 seconds, now goes to 1300-2200 seconds
delete_big_many_keys - normal was around 200-300 seconds, now goes to 1300-2200 seconds

From "show create table bench1'

Table Create Table
bench1 CREATE TABLE `bench1` (
  `field1` INT NOT NULL,
  `field_search` INT NOT NULL,
  `field2` INT NOT NULL,
  `field3` INT NOT NULL,
  `field4` VARCHAR(16) COLLATE utf8_general_ci NOT NULL,
  `field5` INT NOT NULL,
  `field6` DOUBLE NOT NULL,
  `field7` DOUBLE NOT NULL,
  `field8` VARCHAR(6) COLLATE utf8_general_ci NOT NULL,
  `field9` VARCHAR(6) COLLATE utf8_general_ci NOT NULL,
  `field10` VARCHAR(6) COLLATE utf8_general_ci NOT NULL,
  `field11` VARCHAR(6) COLLATE utf8_general_ci NOT NULL,
  `field12` VARCHAR(6) COLLATE utf8_general_ci NOT NULL,
  `field13` VARCHAR(6) COLLATE utf8_general_ci NOT NULL,
  `field14` VARCHAR(6) COLLATE utf8_general_ci NOT NULL,
  `field15` VARCHAR(6) COLLATE utf8_general_ci NOT NULL,
  `field16` VARCHAR(6) COLLATE utf8_general_ci NOT NULL,
  PRIMARY KEY (`field1`,`field2`,`field3`,`field4`,`field5`,`field6`,`field7`,`field8`,`field9`,`field10`,`field11`,`field12`,`field13`,`field14`,`field15`,`field16`),
  KEY `index2` (`field_search`),
  KEY `index3` (`field3`),
  KEY `index4` (`field4`),
  KEY `index5` (`field5`),
  KEY `index6` (`field6`),
  KEY `index7` (`field7`),
  KEY `index8` (`field8`),
  KEY `index9` (`field9`),
  KEY `index10` (`field10`),
  KEY `index11` (`field11`),
  KEY `index12` (`field12`),
  KEY `index13` (`field13`),
  KEY `index14` (`field14`),
  KEY `index15` (`field15`),
  KEY `index16` (`field16`)
) ENGINE=InnoDB COLLATE = utf8_general_ci

I'm going to close this, as performance numbers since January 1st have now been consistent and reasonable.