MySQL Forums
Forum List  »  General

Re: tables with 3,500,000 rows, indexed but still v slow
Posted by: Adam Hardy
Date: June 17, 2010 11:05AM

The explain in my first posts is for the query. Or did you realise that already?

Regarding the memory, I have had a Java app running continously over the last 10 days or so and it is probably hogging the memory, but I just set innodb_buffer_pool_size = 1G because I have 2G and this other stuff running, but unfortunately it made no difference to the time of the transaction.

I just did some more digging around now that I have time to look at the issue again: I am slightly worried that what I'm seeing is pretty much decent performance.

This one transaction now takes 15 mins and from a count in the logs, it does:

6771 selects
6627 inserts
6894 updates

A few of those selects and updates are the primary key table, but not many.

The updates surprised me - I think there is a probably with the ORM layer here that I can investigate with them. But still assuming they take up 1/3 of the time, 10 mins for the remainder is still a fairly substantial amount of time, isn't it?

More rooting around showed that the longest operation was this, which took 257 ms:

FINEST: <t 14375743, conn 4308745> executing prepstmnt 27138522 
INSERT INTO DOLLAR_RETURN (ID, MARKET_SYSTEM_ID, TRADE_ID, PROFIT, 
        OWNER_ID, VERSION, CREATED, MODIFIED) 
    VALUES (?, ?, ?, ?, ?, ?, ?, ?) 
[params=(long) 4366899, (long) 11450, (long) 4388863, (BigDecimal) -0.000740000000, (long) 1, (int) 1, (Timestamp) 2010-06-15 11:45:14.013, (Timestamp) 2010-06-15 11:47:19.031]
15-Jun-2010 11:47:30 org.apache.openjpa.lib.log.CommonsLogFactory$LogAdapter trace
FINEST: <t 14375743, conn 4308745> [279 ms] spent

However it does thousands of these at under 1ms each but there are some taking around 40ms. I guess this one must be allocating more disk space or something.

Then I have this one:
INSERT INTO MARKET_SYSTEM (ID, TEST_RUN_ID, AVG_TRUE_RANGE, UNIT_VALUE, 
        COMMISSION, AVG_SPREAD, AVG_SLIPPAGE, MAX_SLIPPAGE, CURRENCY, 
        OWNER_ID, VERSION, CREATED, MODIFIED) 
    VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) 
[params=(long) 11450, (long) 11650, (BigDecimal) 0.001000, (BigDecimal) 1.00, (BigDecimal) 0.000040, (BigDecimal) 0.000100, (BigDecimal) 0.000100, (BigDecimal) 0.001000, (String) USD, (long) 1, (int) 1, (Timestamp) 2010-06-15 11:44:39.333, (Timestamp) 2010-06-15 11:47:18.712]
15-Jun-2010 11:47:22 org.apache.openjpa.lib.log.CommonsLogFactory$LogAdapter trace
FINEST: <t 14375743, conn 4308745> [143 ms] spent
which only executes once. So I guess it would be best to concentrate on the insert into DOLLAR_RETURN.


Here are some of those stats:
mysql> SHOW VARIABLES LIKE '%log%'; 
+---------------------------------+------------+
| Variable_name                   | Value      |
+---------------------------------+------------+
| back_log                        | 50         | 
| binlog_cache_size               | 32768      | 
| expire_logs_days                | 10         | 
| innodb_flush_log_at_trx_commit  | 1          | 
| innodb_locks_unsafe_for_binlog  | OFF        | 
| innodb_log_arch_dir             |            | 
| innodb_log_archive              | OFF        | 
| innodb_log_buffer_size          | 1048576    | 
| innodb_log_file_size            | 5242880    | 
| innodb_log_files_in_group       | 2          | 
| innodb_log_group_home_dir       | ./         | 
| innodb_mirrored_log_groups      | 1          | 
| log                             | OFF        | 
| log_bin                         | OFF        | 
| log_bin_trust_function_creators | OFF        | 
| log_error                       |            | 
| log_queries_not_using_indexes   | ON         | 
| log_slave_updates               | OFF        | 
| log_slow_queries                | ON         | 
| log_warnings                    | 1          | 
| max_binlog_cache_size           | 4294967295 | 
| max_binlog_size                 | 104857600  | 
| max_relay_log_size              | 0          | 
| relay_log_purge                 | ON         | 
| relay_log_space_limit           | 0          | 
| sync_binlog                     | 0          | 
+---------------------------------+------------+
26 rows in set (0.00 sec)

mysql> SHOW GLOBAL STATUS LIKE '%log%'; 
+------------------------------+---------+
| Variable_name                | Value   |
+------------------------------+---------+
| Binlog_cache_disk_use        | 0       | 
| Binlog_cache_use             | 0       | 
| Com_show_binlog_events       | 0       | 
| Com_show_binlogs             | 0       | 
| Com_show_logs                | 0       | 
| Innodb_log_waits             | 0       | 
| Innodb_log_write_requests    | 12184   | 
| Innodb_log_writes            | 446     | 
| Innodb_os_log_fsyncs         | 503     | 
| Innodb_os_log_pending_fsyncs | 0       | 
| Innodb_os_log_pending_writes | 0       | 
| Innodb_os_log_written        | 5669888 | 
| Tc_log_max_pages_used        | 0       | 
| Tc_log_page_size             | 0       | 
| Tc_log_page_waits            | 0       | 
+------------------------------+---------+
15 rows in set (0.00 sec)

mysql> SHOW GLOBAL STATUS LIKE '%time';
+----------------------+-------+
| Variable_name        | Value |
+----------------------+-------+
| Innodb_row_lock_time | 0     | 
| Uptime               | 13715 | 
+----------------------+-------+
2 rows in set (0.00 sec)

This was after I restarted with the new innodb_buffer_pool_size and ran through the app's process once.

Options: ReplyQuote




Sorry, you can't reply to this topic. It has been closed.

Content reproduced on this site is the property of the respective copyright holders. It is not reviewed in advance by Oracle and does not necessarily represent the opinion of Oracle or any other party.