MySQL database drop insanely slow
Posted by: Stephane Eybert
Date: April 15, 2013 01:31PM
Date: April 15, 2013 01:31PM
Hi,
I just installed MySQL 5.0.45-log Source distribution on my Debian 6.0.6 server.
I installed it under my user home directory like I'm used to doing.
But this time the queries are extremely slow to run.
Running a create table or a database drop takes ages. I can literally watch tv in the meantime.
So I did a profiling of the database drop statement.
We can see the time it takes for the checking of permissions is of 369 seconds.
I also did a show status of the InnoDB engine.
And here is my environment.
I just installed MySQL 5.0.45-log Source distribution on my Debian 6.0.6 server.
I installed it under my user home directory like I'm used to doing.
But this time the queries are extremely slow to run.
Running a create table or a database drop takes ages. I can literally watch tv in the meantime.
So I did a profiling of the database drop statement.
mysql> SHOW PROFILES; +----------+--------------+------------------------------+ | Query_ID | Duration | Query | +----------+--------------+------------------------------+ | 1 | 369.54719400 | drop database db_madeintouch | | 2 | 0.00004600 | SELECT DATABASE() | +----------+--------------+------------------------------+ 2 rows in set (0.00 sec) mysql> SHOW PROFILE FOR QUERY 1; +----------------------+-----------+ | Status | Duration | +----------------------+-----------+ | (initialization) | 0.000001 | | checking permissions | 369.54705 | | Opening table | 0.000103 | | System lock | 0.000003 | | Table lock | 0.000018 | | query end | 0.000004 | | freeing items | 0.000004 | | logging slow query | 0.000002 | +----------------------+-----------+ 8 rows in set (0.00 sec)
We can see the time it takes for the checking of permissions is of 369 seconds.
I also did a show status of the InnoDB engine.
mysql> show engine innodb status\G *************************** 1. row *************************** Status: ===================================== 130415 23:11:27 INNODB MONITOR OUTPUT ===================================== Per second averages calculated from the last 9 seconds ---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 781, signal count 781 Mutex spin waits 0, rounds 8629, OS waits 231 RW-shared spins 379, OS waits 190; RW-excl spins 380, OS waits 342 ------------ TRANSACTIONS ------------ Trx id counter 0 7599 Purge done for trx's n:o < 0 7430 undo n:o < 0 0 History list length 3 Total number of lock structs in row lock hash table 0 LIST OF TRANSACTIONS FOR EACH SESSION: ---TRANSACTION 0 0, not started, process no 14133, OS thread id 140617364518656 MySQL thread id 16, query id 1305 localhost stephane checking permissions drop database db_madeintouch ---TRANSACTION 0 0, not started, process no 14133, OS thread id 140617364383488 MySQL thread id 13, query id 1307 localhost stephane show engine innodb status ---TRANSACTION 0 7597, COMMITTED IN MEMORY, process no 14133, OS thread id 140617364518656 dropping table COMMITTING , undo log entries 16 MySQL thread id 16, query id 1305 localhost stephane checking permissions drop database db_madeintouch -------- FILE I/O -------- I/O thread 0 state: waiting for i/o request (insert buffer thread) I/O thread 1 state: waiting for i/o request (log thread) I/O thread 2 state: waiting for i/o request (read thread) I/O thread 3 state: waiting for i/o request (write thread) 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: 1; buffer pool: 0 174 OS file reads, 3781 OS file writes, 2099 OS fsyncs 0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s ------------------------------------- INSERT BUFFER AND ADAPTIVE HASH INDEX ------------------------------------- Ibuf: size 1, free list len 0, seg size 2, 0 inserts, 0 merged recs, 0 merges Hash table size 17393, used cells 122, node heap has 1 buffer(s) 0.00 hash searches/s, 0.00 non-hash searches/s --- LOG --- Log sequence number 0 7801057 Log flushed up to 0 7798962 Last checkpoint at 0 7798962 1 pending log writes, 0 pending chkp writes 1535 log i/o's done, 0.00 log i/o's/second ---------------------- BUFFER POOL AND MEMORY ---------------------- Total memory allocated 22136914; in additional pool allocated 1048576 Buffer pool size 512 Free buffers 2 Database pages 509 Modified db pages 18 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages read 183, created 1444, written 6980 0.00 reads/s, 0.00 creates/s, 0.00 writes/s No buffer pool page gets since the last printout -------------- ROW OPERATIONS -------------- 0 queries inside InnoDB, 0 queries in queue 1 read views open inside InnoDB Main thread process no. 14133, id 140617334142720, state: waiting for server activity Number of rows inserted 0, updated 0, deleted 0, read 0 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s ---------------------------- END OF INNODB MONITOR OUTPUT ============================ 1 row in set (0.00 sec)
And here is my environment.
mysql> SHOW VARIABLES; > +---------------------------------+--------------------------------------------------------------------+ | Variable_name | Value > | > +---------------------------------+--------------------------------------------------------------------+ | auto_increment_increment | 1 > | | auto_increment_offset | 1 > | | automatic_sp_privileges | ON > | | back_log | 50 > | | basedir | > /home/stephane/programs/mysql-5.0.45/install/ | > | binlog_cache_size | 32768 > | | bulk_insert_buffer_size | 8388608 > | | character_set_client | latin1 > | | character_set_connection | latin1 > | | character_set_database | latin1 > | | character_set_filesystem | binary > | | character_set_results | latin1 > | | character_set_server | latin1 > | | character_set_system | utf8 > | | character_sets_dir | > /home/stephane/programs/mysql-5.0.45/install/share/mysql/charsets/ | > | collation_connection | latin1_swedish_ci > | | collation_database | latin1_swedish_ci > | | collation_server | latin1_swedish_ci > | | completion_type | 0 > | | concurrent_insert | 1 > | | connect_timeout | 5 > | | datadir | > /home/stephane/programs/mysql/install/data/ | > | date_format | %Y-%m-%d > | | datetime_format | %Y-%m-%d %H:%i:%s > | | default_week_format | 0 > | | delay_key_write | ON > | | delayed_insert_limit | 100 > | | delayed_insert_timeout | 300 > | | delayed_queue_size | 1000 > | | div_precision_increment | 4 > | | engine_condition_pushdown | OFF > | | expire_logs_days | 0 > | | flush | OFF > | | flush_time | 0 > | | ft_boolean_syntax | + -><()~*:""&| > | | ft_max_word_len | 84 > | | ft_min_word_len | 4 > | | ft_query_expansion_limit | 20 > | | ft_stopword_file | (built-in) > | | group_concat_max_len | 1024 > | | have_archive | NO > | | have_bdb | NO > | | have_blackhole_engine | NO > | | have_compress | YES > | | have_crypt | YES > | | have_csv | NO > | | have_dynamic_loading | YES > | | have_example_engine | NO > | | have_federated_engine | NO > | | have_geometry | YES > | | have_innodb | YES > | | have_isam | NO > | | have_merge_engine | YES > | | have_ndbcluster | NO > | | have_openssl | NO > | | have_ssl | NO > | | have_query_cache | YES > | | have_raid | NO > | | have_rtree_keys | YES > | | have_symlink | YES > | | hostname | server1 > | | init_connect | > | | init_file | > | | init_slave | > | | innodb_additional_mem_pool_size | 1048576 > | | innodb_autoextend_increment | 8 > | | innodb_buffer_pool_awe_mem_mb | 0 > | | innodb_buffer_pool_size | 8388608 > | | innodb_checksums | ON > | | innodb_commit_concurrency | 0 > | | innodb_concurrency_tickets | 500 > | | innodb_data_file_path | ibdata1:10M:autoextend > | | innodb_data_home_dir | > | | innodb_doublewrite | ON > | | innodb_fast_shutdown | 1 > | | innodb_file_io_threads | 4 > | | innodb_file_per_table | OFF > | | innodb_flush_log_at_trx_commit | 1 > | | innodb_flush_method | > | | innodb_force_recovery | 0 > | | innodb_lock_wait_timeout | 50 > | | 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_max_dirty_pages_pct | 90 > | | innodb_max_purge_lag | 0 > | | innodb_mirrored_log_groups | 1 > | | innodb_open_files | 300 > | | innodb_rollback_on_timeout | OFF > | | innodb_support_xa | ON > | | innodb_sync_spin_loops | 20 > | | innodb_table_locks | ON > | | innodb_thread_concurrency | 8 > | | innodb_thread_sleep_delay | 10000 > | | interactive_timeout | 28800 > | | join_buffer_size | 131072 > | | key_buffer_size | 16384 > | | key_cache_age_threshold | 300 > | | key_cache_block_size | 1024 > | | key_cache_division_limit | 100 > | | language | > /home/stephane/programs/mysql-5.0.45/install/share/mysql/english/ | > | large_files_support | ON > | | large_page_size | 0 > | | large_pages | OFF > | | lc_time_names | en_US > | | license | GPL > | | local_infile | ON > | | locked_in_memory | OFF > | | log | ON > | | log_bin | OFF > | | log_bin_trust_function_creators | OFF > | | log_error | > /home/stephane/programs/mysql/install/mysql.error.log | > | log_queries_not_using_indexes | OFF > | | log_slave_updates | OFF > | | log_slow_queries | ON > | | log_warnings | 1 > | | long_query_time | 10 > | | low_priority_updates | OFF > | | lower_case_file_system | OFF > | | lower_case_table_names | 0 > | | max_allowed_packet | 1047552 > | | max_binlog_cache_size | 18446744073709551615 > | | max_binlog_size | 1073741824 > | | max_connect_errors | 10 > | | max_connections | 100 > | | max_delayed_threads | 20 > | | max_error_count | 64 > | | max_heap_table_size | 16777216 > | | max_insert_delayed_threads | 20 > | | max_join_size | 18446744073709551615 > | | max_length_for_sort_data | 1024 > | | max_prepared_stmt_count | 16382 > | | max_relay_log_size | 0 > | | max_seeks_for_key | 18446744073709551615 > | | max_sort_length | 1024 > | | max_sp_recursion_depth | 0 > | | max_tmp_tables | 32 > | | max_user_connections | 0 > | | max_write_lock_count | 18446744073709551615 > | | multi_range_count | 256 > | | myisam_data_pointer_size | 6 > | | myisam_max_sort_file_size | 9223372036854775807 > | | myisam_recover_options | OFF > | | myisam_repair_threads | 1 > | | myisam_sort_buffer_size | 8388608 > | | myisam_stats_method | nulls_unequal > | | net_buffer_length | 2048 > | | net_read_timeout | 30 > | | net_retry_count | 10 > | | net_write_timeout | 60 > | | new | OFF > | | old_passwords | OFF > | | open_files_limit | 1024 > | | optimizer_prune_level | 1 > | | optimizer_search_depth | 62 > | | pid_file | > /home/stephane/programs/mysql/install/data/server1.pid | > | port | 3306 > | | preload_buffer_size | 32768 > | | profiling | OFF > | | profiling_history_size | 15 > | | protocol_version | 10 > | | query_alloc_block_size | 8192 > | | query_cache_limit | 1048576 > | | query_cache_min_res_unit | 4096 > | | query_cache_size | 0 > | | query_cache_type | ON > | | query_cache_wlock_invalidate | OFF > | | query_prealloc_size | 8192 > | | range_alloc_block_size | 2048 > | | read_buffer_size | 258048 > | | read_only | OFF > | | read_rnd_buffer_size | 258048 > | | relay_log_purge | ON > | | relay_log_space_limit | 0 > | | rpl_recovery_rank | 0 > | | secure_auth | OFF > | | secure_file_priv | > | | server_id | 1 > | | skip_external_locking | ON > | | skip_networking | OFF > | | skip_show_database | OFF > | | slave_compressed_protocol | OFF > | | slave_load_tmpdir | /tmp/ > | | slave_net_timeout | 3600 > | | slave_skip_errors | OFF > | | slave_transaction_retries | 10 > | | slow_launch_time | 2 > | | socket | /tmp/mysql.sock > | | sort_buffer_size | 65528 > | | sql_big_selects | ON > | | sql_mode | > | | sql_notes | ON > | | sql_warnings | OFF > | | ssl_ca | > | | ssl_capath | > | | ssl_cert | > | | ssl_cipher | > | | ssl_key | > | | storage_engine | MyISAM > | | sync_binlog | 0 > | | sync_frm | ON > | | system_time_zone | MSK > | | table_cache | 4 > | | table_lock_wait_timeout | 50 > | | table_type | MyISAM > | | thread_cache_size | 0 > | | thread_stack | 131072 > | | time_format | %H:%i:%s > | | time_zone | SYSTEM > | | timed_mutexes | OFF > | | tmp_table_size | 33554432 > | | tmpdir | /tmp/ > | | transaction_alloc_block_size | 8192 > | | transaction_prealloc_size | 4096 > | | tx_isolation | REPEATABLE-READ > | | updatable_views_with_limit | YES > | | version | 5.0.45-log > | | version_comment | Source distribution > | | version_compile_machine | x86_64 > | | version_compile_os | unknown-linux-gnu > | | wait_timeout | 28800 > | > +---------------------------------+--------------------------------------------------------------------+ 225 rows in set (43.41 sec)
Subject
Views
Written By
Posted
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.