Announcement

Announcement Module
Collapse
No announcement yet.

MySQLD + OOM

Page Title Module
Move Remove Collapse
X
Conversation Detail Module
Collapse
  • Filter
  • Time
  • Show
Clear All
new posts

  • MySQLD + OOM

    Hi,

    I am using Percona-XtraDB-server-51-5.1.45-10.rhel5.x86_64 on CentOS 5.5 64bit. The hardware specs are:Intel Core 2 Duo E8400/3Ghz/4GB RAM, 160GB HDD.

    When I try to run mysqlreport, or any other tools like innotop, mytop, tuning-primter.sh, etc I get the mysqld process killed by the oom-killer. If these tools are not run, mysqld process runs fine. The mysqld process gets into oom phase while the "show innodb status" is issued by these scripts, even the ssh becomes unresponsive

    The /var/log/messages is as follows

    Jun 28 21:26:24 blr-cos-mdb01 kernel: sendmail invoked oom-killer: gfp_mask=0x201d2, order=0, oomkilladj=0Jun 28 21:26:30 blr-cos-mdb01 kernel: Jun 28 21:26:30 blr-cos-mdb01 kernel: Call Trace:Jun 28 21:26:30 blr-cos-mdb01 kernel: [] out_of_memory+0x8e/0x2f3Jun 28 21:26:30 blr-cos-mdb01 kernel: [] __alloc_pages+0x245/0x2ceJun 28 21:26:30 blr-cos-mdb01 kernel: [] __do_page_cache_readahead+0x96/0x179Jun 28 21:26:30 blr-cos-mdb01 kernel: [] filemap_nopage+0x14c/0x360Jun 28 21:26:30 blr-cos-mdb01 kernel: [] __handle_mm_fault+0x1fa/0xf99Jun 28 21:26:30 blr-cos-mdb01 kernel: [] do_page_fault+0x4cb/0x830Jun 28 21:26:30 blr-cos-mdb01 kernel: [] lock_kernel+0x1b/0x32Jun 28 21:26:30 blr-cos-mdb01 kernel: [] de_put+0xe/0x63Jun 28 21:26:30 blr-cos-mdb01 kernel: [] error_exit+0x0/0x84Jun 28 21:27:10 blr-cos-mdb01 kernel: Jun 28 21:27:27 blr-cos-mdb01 kernel: Mem-info:Jun 28 21:27:28 blr-cos-mdb01 kernel: Node 0 DMA per-cpu:Jun 28 21:27:29 blr-cos-mdb01 kernel: cpu 0 hot: high 0, batch 1 used:0Jun 28 21:27:30 blr-cos-mdb01 kernel: cpu 0 cold: high 0, batch 1 used:0Jun 28 21:27:31 blr-cos-mdb01 kernel: cpu 1 hot: high 0, batch 1 used:0Jun 28 21:27:31 blr-cos-mdb01 kernel: cpu 1 cold: high 0, batch 1 used:0Jun 28 21:27:31 blr-cos-mdb01 kernel: Node 0 DMA32 per-cpu:Jun 28 21:27:31 blr-cos-mdb01 kernel: cpu 0 hot: high 186, batch 31 used:42Jun 28 21:27:31 blr-cos-mdb01 kernel: cpu 0 cold: high 62, batch 15 used:33Jun 28 21:27:31 blr-cos-mdb01 kernel: cpu 1 hot: high 186, batch 31 used:16Jun 28 21:27:31 blr-cos-mdb01 kernel: cpu 1 cold: high 62, batch 15 used:55Jun 28 21:27:31 blr-cos-mdb01 kernel: Node 0 Normal per-cpu:Jun 28 21:27:31 blr-cos-mdb01 kernel: cpu 0 hot: high 90, batch 15 used:36Jun 28 21:27:31 blr-cos-mdb01 kernel: cpu 0 cold: high 30, batch 7 used:24Jun 28 21:27:31 blr-cos-mdb01 kernel: cpu 1 hot: high 90, batch 15 used:10Jun 28 21:27:31 blr-cos-mdb01 kernel: cpu 1 cold: high 30, batch 7 used:6Jun 28 21:27:31 blr-cos-mdb01 kernel: Node 0 HighMem per-cpu: emptyJun 28 21:27:31 blr-cos-mdb01 kernel: Free pages: 19644kB (0kB HighMem)Jun 28 21:27:31 blr-cos-mdb01 kernel: Active:615433 inactive:300772 dirty:0 writeback:0 unstable:0 free:4911 slab:7871 mapped-file:2467 mapped-anon:914152 pagetables:3128Jun 28 21:27:31 blr-cos-mdb01 kernel: Node 0 DMA free:10940kB min:20kB low:24kB high:28kB active:0kB inactive:0kB present:10556kB pages_scanned:0 all_unreclaimable? yesJun 28 21:27:31 blr-cos-mdb01 kernel: lowmem_reserve[]: 0 3471 3724 3724Jun 28 21:27:31 blr-cos-mdb01 kernel: Node 0 DMA32 free:8228kB min:7268kB low:9084kB high:10900kB active:2367512kB inactive:1128516kB present:3555172kB pages_scanned:6669291 all_unreclaimable? yesJun 28 21:27:31 blr-cos-mdb01 kernel: lowmem_reserve[]: 0 0 252 252Jun 28 21:27:31 blr-cos-mdb01 kernel: Node 0 Normal free:476kB min:528kB low:660kB high:792kB active:94092kB inactive:74700kB present:258560kB pages_scanned:391691 all_unreclaimable? yesJun 28 21:27:31 blr-cos-mdb01 kernel: lowmem_reserve[]: 0 0 0 0Jun 28 21:27:31 blr-cos-mdb01 kernel: Node 0 HighMem free:0kB min:128kB low:128kB high:128kB active:0kB inactive:0kB present:0kB pages_scanned:0 all_unreclaimable? noJun 28 21:27:31 blr-cos-mdb01 kernel: lowmem_reserve[]: 0 0 0 0Jun 28 21:27:31 blr-cos-mdb01 kernel: Node 0 DMA: 5*4kB 5*8kB 6*16kB 3*32kB 3*64kB 2*128kB 0*256kB 0*512kB 2*1024kB 0*2048kB 2*4096kB = 10940kBJun 28 21:27:31 blr-cos-mdb01 kernel: Node 0 DMA32: 13*4kB 2*8kB 2*16kB 0*32kB 1*64kB 1*128kB 1*256kB 1*512kB 1*1024kB 1*2048kB 1*4096kB = 8228kBJun 28 21:27:31 blr-cos-mdb01 kernel: Node 0 Normal: 21*4kB 3*8kB 7*16kB 2*32kB 1*64kB 1*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 476kBJun 28 21:27:31 blr-cos-mdb01 kernel: Node 0 HighMem: emptyJun 28 21:27:31 blr-cos-mdb01 kernel: 475586 pagecache pagesJun 28 21:27:31 blr-cos-mdb01 kernel: Swap cache: add 2772590, delete 2299569, find 289296/360387, race 1+154Jun 28 21:27:31 blr-cos-mdb01 kernel: Free swap = 0kBJun 28 21:27:31 blr-cos-mdb01 kernel: Total swap = 2096472kBJun 28 21:27:31 blr-cos-mdb01 kernel: Free swap: 0kBJun 28 21:27:31 blr-cos-mdb01 kernel: 1114112 pages of RAMJun 28 21:27:31 blr-cos-mdb01 kernel: 176150 reserved pagesJun 28 21:27:31 blr-cos-mdb01 kernel: 4197 pages sharedJun 28 21:27:31 blr-cos-mdb01 kernel: 473021 pages swap cachedJun 28 21:27:31 blr-cos-mdb01 kernel: klogd invoked oom-killer: gfp_mask=0x200d2, order=0, oomkilladj=0Jun 28 21:27:31 blr-cos-mdb01 kernel: Jun 28 21:27:31 blr-cos-mdb01 kernel: Call Trace:Jun 28 21:27:31 blr-cos-mdb01 kernel: [] out_of_memory+0x8e/0x2f3Jun 28 21:27:31 blr-cos-mdb01 kernel: [] __alloc_pages+0x245/0x2ceJun 28 21:27:31 blr-cos-mdb01 kernel: [] read_swap_cache_async+0x45/0xd8Jun 28 21:27:31 blr-cos-mdb01 kernel: [] swapin_readahead+0x60/0xd3Jun 28 21:27:31 blr-cos-mdb01 kernel: [] __handle_mm_fault+0xacc/0xf99Jun 28 21:27:31 blr-cos-mdb01 kernel: [] autoremove_wake_function+0x0/0x2eJun 28 21:27:31 blr-cos-mdb01 kernel: [] skb_queue_tail+0x17/0x3eJun 28 21:27:31 blr-cos-mdb01 kernel: [] sock_def_readable+0x10/0x5fJun 28 21:27:31 blr-cos-mdb01 kernel: [] unix_dgram_sendmsg+0x44e/0x4e0Jun 28 21:27:31 blr-cos-mdb01 kernel: [] do_page_fault+0x4cb/0x830Jun 28 21:27:31 blr-cos-mdb01 kernel: [] do_sock_write+0xc6/0x102Jun 28 21:27:31 blr-cos-mdb01 kernel: [] dequeue_task+0x18/0x37Jun 28 21:27:31 blr-cos-mdb01 kernel: [] error_exit+0x0/0x84Jun 28 21:27:31 blr-cos-mdb01 kernel: [] do_syslog+0x16e/0x3aaJun 28 21:27:31 blr-cos-mdb01 kernel: [] do_syslog+0x13c/0x3aaJun 28 21:27:31 blr-cos-mdb01 kernel: [] autoremove_wake_function+0x0/0x2eJun 28 21:27:31 blr-cos-mdb01 kernel: [] kmsg_read+0x3a/0x44Jun 28 21:27:31 blr-cos-mdb01 kernel: [] vfs_read+0xcb/0x171Jun 28 21:27:31 blr-cos-mdb01 kernel: [] sys_read+0x45/0x6eJun 28 21:27:31 blr-cos-mdb01 kernel: [] tracesys+0xd5/0xe0Jun 28 21:27:31 blr-cos-mdb01 kernel: Jun 28 21:27:31 blr-cos-mdb01 kernel: Mem-info:Jun 28 21:27:31 blr-cos-mdb01 kernel: Node 0 DMA per-cpu:Jun 28 21:27:31 blr-cos-mdb01 kernel: cpu 0 hot: high 0, batch 1 used:0Jun 28 21:27:31 blr-cos-mdb01 kernel: cpu 0 cold: high 0, batch 1 used:0Jun 28 21:27:31 blr-cos-mdb01 kernel: cpu 1 hot: high 0, batch 1 used:0Jun 28 21:27:31 blr-cos-mdb01 kernel: cpu 1 cold: high 0, batch 1 used:0Jun 28 21:27:31 blr-cos-mdb01 kernel: Node 0 DMA32 per-cpu:Jun 28 21:27:31 blr-cos-mdb01 kernel: cpu 0 hot: high 186, batch 31 used:42Jun 28 21:27:31 blr-cos-mdb01 kernel: cpu 0 cold: high 62, batch 15 used:33Jun 28 21:27:31 blr-cos-mdb01 kernel: cpu 1 hot: high 186, batch 31 used:16Jun 28 21:27:31 blr-cos-mdb01 kernel: cpu 1 cold: high 62, batch 15 used:58Jun 28 21:27:31 blr-cos-mdb01 kernel: Node 0 Normal per-cpu:Jun 28 21:27:31 blr-cos-mdb01 kernel: cpu 0 hot: high 90, batch 15 used:37Jun 28 21:27:31 blr-cos-mdb01 kernel: cpu 0 cold: high 30, batch 7 used:24Jun 28 21:27:31 blr-cos-mdb01 kernel: cpu 1 hot: high 90, batch 15 used:10Jun 28 21:27:31 blr-cos-mdb01 kernel: cpu 1 cold: high 30, batch 7 used:6Jun 28 21:27:31 blr-cos-mdb01 kernel: Node 0 HighMem per-cpu: emptyJun 28 21:27:31 blr-cos-mdb01 kernel: Free pages: 19644kB (0kB HighMem)Jun 28 21:27:31 blr-cos-mdb01 kernel: Active:506530 inactive:409576 dirty:0 writeback:0 unstable:0 free:4911 slab:7870 mapped-file:2464 mapped-anon:914152 pagetables:3128Jun 28 21:27:31 blr-cos-mdb01 kernel: Node 0 DMA free:10940kB min:20kB low:24kB high:28kB active:0kB inactive:0kB present:10556kB pages_scanned:0 all_unreclaimable? yesJun 28 21:27:31 blr-cos-mdb01 kernel: lowmem_reserve[]: 0 3471 3724 3724Jun 28 21:27:31 blr-cos-mdb01 kernel: Node 0 DMA32 free:8228kB min:7268kB low:9084kB high:10900kB active:1922752kB inactive:1572880kB present:3555172kB pages_scanned:7849499 all_unreclaimable? yesJun 28 21:27:31 blr-cos-mdb01 kernel: lowmem_reserve[]: 0 0 252 252Jun 28 21:27:31 blr-cos-mdb01 kernel: Node 0 Normal free:476kB min:528kB low:660kB high:792kB active:103368kB inactive:65424kB present:258560kB pages_scanned:453079 all_unreclaimable? yesJun 28 21:27:31 blr-cos-mdb01 kernel: lowmem_reserve[]: 0 0 0 0Jun 28 21:27:31 blr-cos-mdb01 kernel: Node 0 HighMem free:0kB min:128kB low:128kB high:128kB active:0kB inactive:0kB present:0kB pages_scanned:0 all_unreclaimable? noJun 28 21:27:31 blr-cos-mdb01 kernel: lowmem_reserve[]: 0 0 0 0Jun 28 21:27:31 blr-cos-mdb01 kernel: Node 0 DMA: 5*4kB 5*8kB 6*16kB 3*32kB 3*64kB 2*128kB 0*256kB 0*512kB 2*1024kB 0*2048kB 2*4096kB = 10940kBJun 28 21:27:31 blr-cos-mdb01 kernel: Node 0 DMA32: 13*4kB 2*8kB 2*16kB 0*32kB 1*64kB 1*128kB 1*256kB 1*512kB 1*1024kB 1*2048kB 1*4096kB = 8228kBJun 28 21:27:31 blr-cos-mdb01 kernel: Node 0 Normal: 21*4kB 3*8kB 7*16kB 2*32kB 1*64kB 1*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 476kBJun 28 21:27:31 blr-cos-mdb01 kernel: Node 0 HighMem: emptyJun 28 21:27:31 blr-cos-mdb01 kernel: 475583 pagecache pagesJun 28 21:27:31 blr-cos-mdb01 kernel: Swap cache: add 2772590, delete 2299569, find 289296/360389, race 1+154Jun 28 21:27:31 blr-cos-mdb01 kernel: Free swap = 0kBJun 28 21:27:31 blr-cos-mdb01 kernel: Total swap = 2096472kBJun 28 21:27:31 blr-cos-mdb01 kernel: Free swap: 0kBJun 28 21:27:31 blr-cos-mdb01 kernel: 1114112 pages of RAMJun 28 21:27:31 blr-cos-mdb01 kernel: 176150 reserved pagesJun 28 21:27:31 blr-cos-mdb01 kernel: 4234 pages sharedJun 28 21:27:31 blr-cos-mdb01 kernel: 473021 pages swap cachedJun 28 21:27:31 blr-cos-mdb01 kernel: Out of memory: Killed process 27935 (mysqld).

    The other system monitoring outputs are

    free -m total used free shared buffers cachedMem: 3663 3636 27 0 146 425-/+ buffers/cache: 3063 599Swap: 2047 114 1932


    top - 18:03:35 up 9 days, 22:51, 2 users, load average: 0.12, 0.36, 0.51Tasks: 97 total, 1 running, 96 sleeping, 0 stopped, 0 zombieCpu(s): 6.0%us, 1.8%sy, 0.0%ni, 90.9%id, 0.8%wa, 0.0%hi, 0.5%si, 0.0%stMem: 3751848k total, 3727120k used, 24728k free, 150732k buffersSwap: 2096472k total, 117376k used, 1979096k free, 438476k cached PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND27935 mysql 15 0 4439m 2.8g 9852 S 14.6 79.3 13:32.85 mysqld 1 root 15 0 10348 168 116 S 0.0 0.0 0:49.24 init 2 root RT -5 0 0 0 S 0.0 0.0 0:00.00 migration/0 3 root 34 19 0 0 0 S 0.0 0.0 0:00.04 ksoftirqd/0 4 root RT -5 0 0 0 S 0.0 0.0 0:00.00 watchdog/0 5 root RT -5 0 0 0 S 0.0 0.0 0:00.00 migration/1 6 root 34 19 0 0 0 S 0.0 0.0 0:00.02 ksoftirqd/1 7 root RT -5 0 0 0 S 0.0 0.0 0:00.00 watchdog/1 8 root 10 -5 0 0 0 S 0.0 0.0 0:00.39 events/0 9 root 10 -5 0 0 0 S 0.0 0.0 0:00.14 events/1 10 root 10 -5 0 0 0 S 0.0 0.0 0:00.00 khelper 45 root 14 -5 0 0 0 S 0.0 0.0 1:45.18 kthread 50 root 10 -5 0 0 0 S 0.0 0.0 0:23.54 kblockd/0 51 root 10 -5 0 0 0 S 0.0 0.0 0:00.32 kblockd/1 52 root 15 -5 0 0 0 S 0.0 0.0 0:00.00 kacpid 161 root 15 -5 0 0 0 S 0.0 0.0 0:00.00 cqueue/0 162 root 15 -5 0 0 0 S 0.0 0.0 0:00.00 cqueue/1 165 root 10 -5 0 0 0 S 0.0 0.0 0:00.00 khubd 167 root 10 -5 0 0 0 S 0.0 0.0 0:00.00 kseriod 241 root 10 -5 0 0 0 S 0.0 0.0 157:58.93 kswapd0 242 root 16 -5 0 0 0 S 0.0 0.0 0:00.00 aio/0 243 root 17 -5 0 0 0 S 0.0 0.0 0:00.00 aio/1 390 root 11 -5 0 0 0 S 0.0 0.0 0:00.00 kpsmoused 422 root 12 -5 0 0 0 S 0.0 0.0 0:00.00 ata/0 423 root 13 -5 0 0 0 S 0.0 0.0 0:00.00 ata/1 424 root 10 -5 0 0 0 S 0.0 0.0 0:00.00 ata_aux 428 root 10 -5 0 0 0 S 0.0 0.0 0:00.00 scsi_eh_0 429 root 10 -5 0 0 0 S 0.0 0.0 0:13.51 scsi_eh_1 430 root 10 -5 0 0 0 S 0.0 0.0 0:00.00 scsi_eh_2 431 root 10 -5 0 0 0 S 0.0 0.0 0:00.00 scsi_eh_3


    ps aux | grep mysqlroot 2826 0.0 0.0 65964 748 ? S Jun18 0:00 /bin/sh /usr/bin/mysqld_safe --datadir=/var/lib/mysql/data --pid-file=/var/lib/mysql/data/blr-cos-mdb01.digi.com.pidmysql 27935 17.8 79.2 4283676 2974276 ? SLl 16:49 13:58 /usr/sbin/mysqld --basedir=/ --datadir=/var/lib/mysql/data --user=mysql --log-error=/var/log/mysqld.log --open-files-limit=8192 --pid-file=/var/lib/mysql/data/blr-cos-mdb01.digi.com.pid --socket=/var/lib/mysql/mysql.sock --port=3306


    vmstat 1 2procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu------ r b swpd free buff cache si so bi bo in cs us sy id wa st 0 0 117376 24524 151876 436388 1 1 4882 404 24 13 9 4 76 10 0 0 0 117376 24524 151876 436388 0 0 0 0 1022 263 0 0 100 0 0

    and finally the /etc/my.cnf is
    [client]port = 3306socket = /var/lib/mysql/mysql.sock[mysqld]port = 3306datadir = /var/lib/mysql/datasocket = /var/lib/mysql/mysql.sockuser=mysqlback_log = 50skip-name-resolvemax_connections = 1000max_connect_errors = 10table_cache = 2048max_allowed_packet = 64Mbinlog_cache_size = 32Mmax_heap_table_size = 64Mlower_case_table_names=1sort_buffer_size = 8Mjoin_buffer_size = 8Mthread_cache_size = 8thread_concurrency = 8query_cache_size = 64Mquery_cache_limit = 2Mft_min_word_len = 4memlockdefault_table_type = MYISAMthread_stack = 192Ktransaction_isolation = READ-COMMITTEDmax_write_lock_count = 1net_read_timeout = 60tmp_table_size = 64Mlog_bin = /var/lib/mysql/binlogs/mtrak32-binlog-bin-index = /var/lib/mysql/binlogs/mtrak32-bin.indexexpire_logs_days = 10max_binlog_size=100Mmax_binlog_cache_size=32Mbin log_format=MIXEDbinlog-ignore-db=mysqlbinlog-ignore-db=testbinlog-ignore-db=information_schemalog_warningslong_query_time = 2server-id = 1key_buffer_size = 32Mread_buffer_size = 2Mread_rnd_buffer_size = 32Mbulk_insert_buffer_size = 64Mmyisam_sort_buffer_size = 128Mmyisam_max_sort_file_size = 10Gmyisam_repair_threads = 10innodb_file_per_table=1innodb_additional_mem_poo l_size = 20Minnodb_buffer_pool_size = 2Ginnodb_data_file_path = ibdata1:100M:autoextendinnodb_read_io_threads = 20innodb_write_io_threads = 10innodb_thread_concurrency = 16innodb_flush_log_at_trx_commit = 2innodb_log_file_size = 256Minnodb_max_dirty_pages_pct = 90innodb_flush_method = O_DIRECTinnodb_autoextend_increment = 1innodb_open_files = 2048sync-binlog=1log-slave-updatesauto_increment_increment = 10auto_increment_offset = 1innodb_io_capacity = 1000innodb_log_files_in_group = 3innodb_log_buffer_size = 64Minnodb_extra_rsegments = 32innodb_lock_wait_timeout = 120innodb_table_locks = 0[mysqldump]quickmax_allowed_packet = 16M[mysql]no-auto-rehash[isamchk]key_buffer = 512Msort_buffer_size = 512Mread_buffer = 8Mwrite_buffer = 8M[myisamchk]key_buffer = 512Msort_buffer_size = 512Mread_buffer = 8Mwrite_buffer = 8M[mysqlhotcopy]interactive-timeout[mysqld_safe]open-files-limit = 8192log-error=/var/log/mysqld.logpid-file=/var/run/mysqld/mysqld.pid

    I am wondering whu mysql instance is getting out of memory when show innodb status is issued?

    Regards
    Prashant

  • #2
    Hi,

    I upgraded mysql binaries to
    Percona-Server-client-51-5.1.47-rel11.1.51.rhel5.x86_64.rpmPercona-Server-devel-51-5.1.47-rel11.1.51.rhel5.x86_64.rpmPercona-Server-server-51-5.1.47-rel11.1.51.rhel5.x86_64.rpmPercona-Server-shared-51-5.1.47-rel11.1.51.rhel5.x86_64.rpmPercona-Server-test-51-5.1.47-rel11.1.51.rhel5.x86_64.rpm

    and checked out. Still the results are same.

    However, the same does not happen on
    MySQL-shared-percona-5.1.34-5.rhel5MySQL-client-percona-5.1.34-5.rhel5MySQL-test-percona-5.1.34-5.rhel5MySQL-devel-percona-5.1.34-5.rhel5MySQL-server-percona-5.1.34-5.rhel5

    Can someone help me please ?

    Comment


    • #3
      I don't know what exactly is happening here, but this could be a bug. Can you strace the process, run SHOW INNODB STATUS, and find what it does just before it gets killed?

      Comment

      Working...
      X