What is Profile_query_end?

MySQL & MariaDB Other MySQL® Questions
1

Hi!
Insert into InnoDB table are too slow. Below is an excerpt from slow_log:

Query_time: 0.635458 Lock_time: 0.000028 Rows_sent: 0 Rows_examined: 0 Rows_affected: 1 Rows_read: 0# Bytes_sent: 19 Tmp_tables: 0 Tmp_disk_tables: 0 Tmp_table_sizes: 0# Profile_starting: 0.000018 Profile_starting_cpu: 0.000018 Profile_checking_permissions: 0.000003 Profile_checking_permissions_cpu: 0.000002 Profile_Opening_tables: 0.000006 Profile_Opening_tables_cpu: 0.000006 Profile_System_lock: 0.000002 Profile_System_lock_cpu: 0.000002 Profile_init: 0.000006 Profile_init_cpu: 0.000006 Profile_update: 0.000025 Profile_update_cpu: 0.000025 Profile_Waiting_for_query_cache_lock: 0.000001 Profile_Waiting_for_query_cache_lock_cpu: 0.000001 Profile_update: 0.000004 Profile_update_cpu: 0.000004 Profile_end: 0.000001 Profile_end_cpu: 0.000001 Profile_query_end: 0.635375 Profile_query_end_cpu: 0.000263 Profile_closing_tables: 0.000007 Profile_closing_tables_cpu: 0.000007 Profile_freeing_items: 0.000012 Profile_freeing_items_cpu: 0.000011 Profile_logging_slow_query: 0.000001 Profile_logging_slow_query_cpu: 0.000001# Profile_total: 0.635460 Profile_total_cpu: 0.000347# InnoDB_trx_id: C3FEF74# QC_Hit: No Full_scan: No Full_join: No Tmp_table: No Tmp_table_on_disk: No# Filesort: No Filesort_on_disk: No Merge_passes: 0# InnoDB_IO_r_ops: 0 InnoDB_IO_r_bytes: 0 InnoDB_IO_r_wait: 0.000000# InnoDB_rec_lock_wait: 0.000000 InnoDB_queue_wait: 0.000000# InnoDB_pages_distinct: 4INSERT INTO logs (userid, date, ip, ip1, host, domain, address, referer, browser) VALUES (‘32f1d43dcc84ff1d5a2f1da2d7b1e35d’, 1321853873, INET_ATON(‘1.2.3.4’), ‘’, ‘’, ‘www.company.com’, ‘/lib/action.php’, ‘http://www.company.com/cart’, ‘Mozilla/5.0 (Windows NT 5.1; rv:6.0) Gecko/20100101 Firefox/6.0’);

Table structure is as follows:

CREATE TABLE logs( id INT(11) NOT NULL AUTO_INCREMENT, userid CHAR(32) NOT NULL, date INT(11) NOT NULL, ip BIGINT(20) NOT NULL DEFAULT 0, ip1 CHAR(255) NOT NULL, host CHAR(255) NOT NULL, domain CHAR(50) NOT NULL, address VARCHAR(1023) NOT NULL, referer VARCHAR(1023) NOT NULL, browser VARCHAR(511) NOT NULL, PRIMARY KEY (id), INDEX date (date))ENGINE = INNODBAVG_ROW_LENGTH = 904CHARACTER SET utf8COLLATE utf8_unicode_ci

Maybe, long VARCHARs do matter?

2

By the way,
CPU: 2x X5687 3.6 GHz
RAM: 96 GB
HDD: RAID10 with BBWC
OS: CentOS 6
Percona Server 5.5.16
my.cnf:

skip-external-lockingskip-name-resolveft_min_word_len = 4back_log = 100max_connections = 200max_user_connections = 200interactive_timeout = 120wait_timeout = 120connect_timeout = 5key_buffer_size = 6Gmyisam_sort_buffer_size = 4095Mjoin_buffer_size = 1Msort_buffer_size = 2Mtable_cache = 2048thread_cache_size = 286thread_stack = 196Kmax_allowed_packet = 16Mmax_connect_errors = 10max_heap_table_size = 1Gtmp_table_size = 64Minnodb_data_file_path = ibdata1:10M:autoextendinnodb_file_per_tableinnodb_buffer_pool_size = 40Ginnodb_additional_mem_pool_size = 20Minnodb_log_file_size = 1900Minnodb_log_buffer_size = 16Minnodb_flush_log_at_trx_commit = 1innodb_flush_method = O_DIRECTinnodb_lock_wait_timeout = 50innodb_thread_concurrency = 32transaction_isolation = REPEATABLE-READ# Profiling queriesslow-query-log = 0long_query_time = 0.5log_slow_rate_limit = 1log_slow_verbosity = full,profilingquery_response_time_stats = ON# Replicationserver-id = 103binlog-format = MIXEDlog-bin = mysql-binlog-bin-index = mysql-bin.indexrelay-log = relay-logrelay-log-index = relay-log.indexexpire_logs_days = 10log-slave-updates = 1sync_binlog = 1binlog_cache_size = 1M

3

Can you reproduce this by inserting into the table yourself, and using SHOW PROFILES? Or is this query only slow sometimes?