Hi I'm experiencing very strange innodb behavior. I'm testing the following DB structure: stn|dt|par1|par2|par3 , where stn is 1 to N, dt 1 to M, par1, par2, par3, par4, par5, par6 are any values and stn+dt is a primary key. So create statement looks like CREATE TABLE t3 (stn SMALLINT UNSIGNED NOT NULL, dt BIGINT UNSIGNED NOT NULL, par1 TINYINT, par2 TINYINT, par3 TINYINT, par4 TINYINT, par5 TINYINT, par6 TINYINT, PRIMARY KEY (stn, dt)) TYPE=INNODB
The table looks like that: 1 1 9 9 9 9 9 9 1 2 9 9 9 9 9 9 ............................. 2 1 9 9 9 9 9 9 2 2 9 9 9 9 9 9 ............................. N M-1 9 9 9 9 9 9 N M 9 9 9 9 9 9 I'm testing it for N=(4000, 8000) and M=(1500, 3000, 6000, 12000, 24000). Test consits of writing down the file for current N and M, loading it in table via 'LOAD DATA INFILE', commiting changes and then testing speed of 500 random selects from the table. For N=4000 all is loking good, but when N=8000 loading time is droping down drastically when M reaches 3000 or so. I'm talking about 50 times slower insertion here. So I simplified the test, lefting just the loading data in table and run it for N=4000, M=12000 and then for N=8000, M=6000. Notice the data and index length for this cases are the same. The first test was finished in a hour, the second was terminated by me after 12 hour work and it did not even inserted half the rows. If this helps the following are outputs of innodb monitor for this tests. Typical output for N=4000, M=12000: ===================================== 020923 3:44:12 INNODB MONITOR OUTPUT ===================================== ---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 1858, signal count 1858 Mutex spin waits 1868, rounds 19710, OS waits 132 RW-shared spins 248, OS waits 124; RW-excl spins 9149, OS waits 1602 ------------ TRANSACTIONS ------------ Trx id counter 0 1287 Purge done for trx's n:o < 0 0 undo n:o < 0 0 Total number of lock structs in row lock hash table 0 ---TRANSACTION 0 1286, OS thread id 441071616 inserting, active, runs or sleeps, has 1 lock struct(s), undo log entries 11479793 MySQL thread id 1, query id 16 localhost admin LOAD DATA INFILE '/db/tmp/df.dat' INTO TABLE t3 FIELDS TERMINATED BY ',' LINES TERMINATED BY ' ' -------- FILE I/O -------- I/O thread 0 state: waiting for i/o request I/O thread 1 state: waiting for i/o request I/O thread 2 state: waiting for i/o request I/O thread 3 state: waiting for i/o request Pending normal aio reads: 0, aio writes: 0, ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0 Pending flushes (fsync) log: 0; buffer pool: 0 42975 OS file reads, 18554 OS file writes, 3895 OS fsyncs 0.00 reads/s, 5.88 writes/s, 2.06 fsyncs/s ------------- INSERT BUFFER ------------- Ibuf for space 0: size 1, free list len 0, seg size 2, 0 inserts, 0 merged recs, 0 merges --- LOG --- Log sequence number 0 671108249 Log flushed up to 0 670978039 Last checkpoint at 0 540000962 0 pending log writes, 0 pending chkp writes 1360 log i/o's done, 1.56 log i/o's/second ---------------------- BUFFER POOL AND MEMORY ---------------------- Total memory allocated 246403343; in additional pool allocated 205696 Free list length 0 LRU list length 8187 Flush list length 8001 Buffer pool size 8192 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages read 61069, created 55116, written 108019 0.00 reads/s, 23.81 creates/s, 16.56 writes/s Buffer pool hit rate 1000 / 1000 -------------- ROW OPERATIONS -------------- 1 queries inside InnoDB, 0 queries in queue; main thread: sleeping Number of rows inserted 11879792, updated 0, deleted 0, read 0 17659.81 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s ---------------------------- END OF INNODB MONITOR OUTPUT ============================ 17659.81 inserts/s. Pretty good I guess. While for N=8000, M=6000 at the beginning monitor output looks the same, after ~2600000 rows insert speed begins falling down, and very fast. And the typical output of monitor becomes like this ===================================== 020923 5:04:24 INNODB MONITOR OUTPUT ===================================== ---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 1671, signal count 1670 --Thread 441090048 has waited at btr0cur.c line 357 for 0.00 seconds the semaphore: X-lock on RW-latch at 12bcee78 created in file buf0buf.c line 348 a writer (thread id 441090048) has reserved it in mode exclusive number of readers 0, waiters flag 1 Last time read locked in file buf0flu.c line 466 Last time write locked in file buf0buf.c line 1246 Mutex spin waits 416, rounds 4470, OS waits 42 RW-shared spins 60, OS waits 30; RW-excl spins 4163, OS waits 1599 ------------ TRANSACTIONS ------------ Trx id counter 0 1800 Purge done for trx's n:o < 0 0 undo n:o < 0 0 Total number of lock structs in row lock hash table 0 ---TRANSACTION 0 1799, OS thread id 441071616, not started, runs or sleeps MySQL thread id 3, query id 19 localhost admin ---TRANSACTION 0 1797, OS thread id 441090048 inserting, active, runs or sleeps, has 1 lock struct(s), undo log entries 2699476 MySQL thread id 2, query id 12 localhost admin LOAD DATA INFILE '/db/tmp/df.dat' INTO TABLE t3 FIELDS TERMINATED BY ',' LINES TERMINATED BY ' ' -------- FILE I/O -------- I/O thread 0 state: waiting for i/o request I/O thread 1 state: waiting for i/o request I/O thread 2 state: simulated aio handle I/O thread 3 state: waiting for i/o request Pending normal aio reads: 23, aio writes: 0, ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0 Pending flushes (fsync) log: 0; buffer pool: 0 29716 OS file reads, 7689 OS file writes, 1903 OS fsyncs 203.25 reads/s, 54.94 writes/s, 9.06 fsyncs/s ------------- INSERT BUFFER ------------- Ibuf for space 0: size 1, free list len 0, seg size 2, 0 inserts, 0 merged recs, 0 merges --- LOG --- Log sequence number 0 177711869 Log flushed up to 0 177687660 Last checkpoint at 0 61910279 0 pending log writes, 0 pending chkp writes 452 log i/o's done, 1.00 log i/o's/second ---------------------- BUFFER POOL AND MEMORY ---------------------- Total memory allocated 246403343; in additional pool allocated 206336 Free list length 55 LRU list length 8134 Flush list length 7712 Buffer pool size 8192 Pending reads 23 Pending writes: LRU 0, flush list 0, single page 0 Pages read 57235, created 16547, written 64991 348.81 reads/s, 9.00 creates/s, 335.56 writes/s Buffer pool hit rate 853 / 1000 -------------- ROW OPERATIONS -------------- 1 queries inside InnoDB, 0 queries in queue; main thread: sleeping Number of rows inserted 2699476, updated 0, deleted 0, read 0 417.12 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s ---------------------------- END OF INNODB MONITOR OUTPUT ============================ It's 42 times slower than the first case. How could it be when length of data and index are the same beyond my understanding. About test system. FreeBSD 4.2, MySQL 3.23.49, my.cnf innodb settings: =============== # Uncomment the following if you are using Innobase tables innodb_data_file_path = ibdata1:20000M innodb_data_home_dir = /db/mysql/ innodb_log_group_home_dir = /db/mysql/ innodb_log_arch_dir = /db/mysql/ set-variable = innodb_mirrored_log_groups=1 set-variable = innodb_log_files_in_group=3 set-variable = innodb_log_file_size=128M set-variable = innodb_log_buffer_size=64M innodb_flush_log_at_trx_commit=1 innodb_log_archive=0 set-variable = innodb_buffer_pool_size=128M set-variable = innodb_additional_mem_pool_size=16M set-variable = innodb_file_io_threads=4 ==================== Thanks for reading so far :) Hope someone out here can explain this puzzle... --------------------------------------------------------------------- Before posting, please check: http://www.mysql.com/manual.php (the manual) http://lists.mysql.com/ (the list archive) To request this thread, e-mail <[EMAIL PROTECTED]> To unsubscribe, e-mail <[EMAIL PROTECTED]> Trouble unsubscribing? Try: http://lists.mysql.com/php/unsubscribe.php