mysqld and clamd killed to free memory (?) pls help.

Discussion in 'Server Operation' started by Nap, Jan 18, 2015.

  1. Nap

    Nap Member

    I've had this situation happen on two occasions now. The first was a couple weeks ago and again this morning at just before 2015-01-18 :: 05:31. I can't display all the relevant log extracts because they make my post too big. :( (10000 characters for a post is not enough in a forum like this. Or, attachments should be allowed. Also, the preview allows around 15000.)
    Full error log extracts can be viewed at my server: mysql_error_information.txt


    The syslog logs indicates this error occurred when the Kernel determined that killing clamd (score 114) was not enough and decided to kill mysqld as well. I think it was related to memory, but can't find the cause I was hoping to see.

    To get the server running normally again, I needed to restart apache2 in addition to starting MySQL and clamav-daemon.

    I'm not quite sure what the cause of the error is, but I believe from looking at the log files (included below) that it has something to do with running out of memory. Overall, the server has been running fine before and in between.

    If anyone is familiar with reading these files, please help me interpret what the issue is so I can fix it.

    Cheers,
    Nap

    syslog below:
    Code:
    Jan 18 05:30:50 hostname kernel: Killed process 4647 (clamd) total-vm:516904kB, anon-rss:231980kB, file-rss:4kB
    Jan 18 05:30:58 hostname kernel: python invoked oom-killer: gfp_mask=0x201da, order=0, oom_score_adj=0
    Jan 18 05:30:58 hostname kernel: python cpuset=/ mems_allowed=0
    Jan 18 05:30:58 hostname kernel: CPU: 0 PID: 4801 Comm: python Not tainted 3.18.1-x86_64-linode50 #1
    Jan 18 05:30:58 hostname kernel: 0000000000000000 ffff88007795f290 ffffffff817c1447 ffff88007795ec80
    Jan 18 05:30:58 hostname kernel: ffffffff817bbc6d 00000000000201da 0000000000000000 ffffffff817c8e7a
    Jan 18 05:30:58 hostname kernel: ffffffff817c7e7f ffff880038f13858 ffff880038f13640 0000000000000010
    Jan 18 05:30:58 hostname kernel: Call Trace:
    Jan 18 05:30:58 hostname kernel: [<ffffffff817c1447>] ? dump_stack+0x41/0x51
    Jan 18 05:30:58 hostname kernel: [<ffffffff817bbc6d>] ? dump_header.isra.7+0x73/0x1cb
    Jan 18 05:30:58 hostname kernel: [<ffffffff817c8e7a>] ? error_exit+0x2a/0x60
    Jan 18 05:30:58 hostname kernel: [<ffffffff817c7e7f>] ? retint_restore_args+0x5/0x6
    Jan 18 05:30:58 hostname kernel: [<ffffffff817c6dd2>] ? _raw_spin_unlock_irqrestore+0x42/0x5b
    Jan 18 05:30:58 hostname kernel: [<ffffffff811395eb>] ? oom_kill_process+0x76/0x33c
    Jan 18 05:30:58 hostname kernel: [<ffffffff8113939a>] ? find_lock_task_mm+0x27/0x76
    Jan 18 05:30:58 hostname kernel: [<ffffffff810c9c19>] ? has_ns_capability_noaudit+0xd/0x14
    Jan 18 05:30:58 hostname kernel: [<ffffffff81139e31>] ? out_of_memory+0x414/0x447
    Jan 18 05:30:58 hostname kernel: [<ffffffff8113dbe5>] ? __alloc_pages_nodemask+0x70f/0x877
    Jan 18 05:30:58 hostname kernel: [<ffffffff814cceb6>] ? radix_tree_lookup_slot+0x10/0x23
    Jan 18 05:30:58 hostname kernel: [<ffffffff81167ceb>] ? alloc_pages_current+0xaf/0xcc
    Jan 18 05:30:58 hostname kernel: [<ffffffff81006900>] ? xen_make_pte+0x7/0xa
    Jan 18 05:30:58 hostname kernel: [<ffffffff81138b1b>] ? filemap_fault+0x274/0x399
    Jan 18 05:30:58 hostname kernel: [<ffffffff81152965>] ? __do_fault+0x35/0x6a
    Jan 18 05:30:58 hostname kernel: [<ffffffff811548f2>] ? do_read_fault.isra.68+0x1c5/0x293
    Jan 18 05:30:58 hostname kernel: [<ffffffff81233838>] ? htree_dirblock_to_tree+0x130/0x141
    Jan 18 05:30:58 hostname kernel: [<ffffffff811566fb>] ? handle_mm_fault+0x437/0x8e5
    Jan 18 05:30:58 hostname kernel: [<ffffffff8118104c>] ? core_sys_select+0x244/0x26a
    Jan 18 05:30:58 hostname kernel: [<ffffffff8103153c>] ? __do_page_fault+0x3a4/0x401
    Jan 18 05:30:58 hostname kernel: [<ffffffff810fc396>] ? timespec_add_safe+0x1e/0x50
    Jan 18 05:30:58 hostname kernel: [<ffffffff81006e89>] ? xen_clocksource_read+0x13/0x15
    Jan 18 05:30:58 hostname kernel: [<ffffffff811017fd>] ? ktime_get_ts64+0x4b/0xb6
    Jan 18 05:30:58 hostname kernel: [<ffffffff81180506>] ? poll_select_copy_remaining+0xe0/0xf6
    Jan 18 05:30:58 hostname kernel: [<ffffffff817c8c38>] ? page_fault+0x28/0x30
    Jan 18 05:30:58 hostname kernel: Mem-Info:
    Jan 18 05:30:58 hostname kernel: Node 0 DMA per-cpu:
    Jan 18 05:30:58 hostname kernel: CPU  0: hi:  0, btch:  1 usd:  0
    Jan 18 05:30:58 hostname kernel: CPU  1: hi:  0, btch:  1 usd:  0
    Jan 18 05:30:58 hostname kernel: Node 0 DMA32 per-cpu:
    Jan 18 05:30:58 hostname kernel: CPU  0: hi:  186, btch:  31 usd:  22
    Jan 18 05:30:58 hostname kernel: CPU  1: hi:  186, btch:  31 usd:  34
    Jan 18 05:30:58 hostname kernel: active_anon:345271 inactive_anon:115576 isolated_anon:0
    Jan 18 05:30:58 hostname kernel: active_file:34 inactive_file:35 isolated_file:18
    Jan 18 05:30:58 hostname kernel: unevictable:0 dirty:0 writeback:0 unstable:0
    Jan 18 05:30:58 hostname kernel: free:3378 slab_reclaimable:3315 slab_unreclaimable:8624
    Jan 18 05:30:58 hostname kernel: mapped:253476 shmem:253591 pagetables:18335 bounce:0
    Jan 18 05:30:58 hostname kernel: free_cma:0
    Jan 18 05:30:58 hostname kernel: Node 0 DMA free:7952kB min:44kB low:52kB high:64kB active_anon:2728kB inactive_anon:2840kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15996kB managed:15912kB mlocked:0kB dirty:0kB writeback:0kB mapped:2132kB shmem:2128kB slab_reclaimable:56kB slab_unreclaimable:220kB kernel_stack:0kB pagetables:232kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
    Jan 18 05:30:58 hostname kernel: lowmem_reserve[]: 0 1977 1977 1977
    Jan 18 05:30:58 hostname kernel: Node 0 DMA32 free:5560kB min:5664kB low:7080kB high:8496kB active_anon:1378356kB inactive_anon:459464kB active_file:136kB inactive_file:140kB unevictable:0kB isolated(anon):0kB isolated(file):72kB present:2080768kB managed:2026792kB mlocked:0kB dirty:0kB writeback:0kB mapped:1011772kB shmem:1012236kB slab_reclaimable:13204kB slab_unreclaimable:34276kB kernel_stack:5024kB pagetables:73108kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:1960 all_unreclaimable? yes
    Jan 18 05:30:58 hostname kernel: lowmem_reserve[]: 0 0 0 0
    Jan 18 05:30:58 hostname kernel: Node 0 DMA: 2*4kB (UM) 3*8kB (M) 3*16kB (U) 10*32kB (UM) 4*64kB (UEM) 1*128kB (E) 2*256kB (UE) 5*512kB (UM) 0*1024kB 0*2048kB 1*4096kB (R) = 7952kB
    Jan 18 05:30:58 hostname kernel: Node 0 DMA32: 79*4kB (UR) 2*8kB (R) 2*16kB (R) 3*32kB (R) 0*64kB 0*128kB 0*256kB 0*512kB 1*1024kB (R) 0*2048kB 1*4096kB (R) = 5580kB
    Jan 18 05:30:58 hostname kernel: 255892 total pagecache pages
    Jan 18 05:30:58 hostname kernel: 2197 pages in swap cache
    Jan 18 05:30:58 hostname kernel: Swap cache stats: add 158865, delete 156668, find 74905/79363
    Jan 18 05:30:58 hostname kernel: Free swap  = 0kB
    Jan 18 05:30:58 hostname kernel: Total swap = 524284kB
    Jan 18 05:30:58 hostname kernel: 524191 pages RAM
    Jan 18 05:30:58 hostname kernel: 0 pages HighMem/MovableOnly
    Jan 18 05:30:58 hostname kernel: 13515 pages reserved
    Jan 18 05:30:58 hostname kernel: [ pid ]  uid  tgid total_vm  rss nr_ptes swapents oom_score_adj name
    ***** I'll include the PID list on request *****
    Jan 18 05:30:58 hostname kernel: Out of memory: Kill process 2899 (mysqld) score 45 or sacrifice child
    Jan 18 05:30:58 hostname kernel: Killed process 2899 (mysqld) total-vm:1344164kB, anon-rss:34980kB, file-rss:0kB
    Jan 18 05:30:58 hostname kernel: init: mysql main process (2899) killed by KILL signal
    Jan 18 05:30:58 hostname kernel: init: mysql main process ended, respawning
    Jan 18 05:30:59 hostname kernel: init: mysql main process (24127) terminated with status 1
    Jan 18 05:30:59 hostname kernel: init: mysql main process ended, respawning
    Jan 18 05:31:00 hostname kernel: init: mysql post-start process (24128) terminated with status 1
    Jan 18 05:31:01 hostname kernel: init: mysql main process (24162) terminated with status 1
    Jan 18 05:31:01 hostname kernel: init: mysql respawning too fast, stopped
    Jan 18 05:31:01 hostname CRON[24175]: (root) CMD (/usr/local/ispconfig/server/server.sh 2>&1 > /dev/null | while read line; do echo `/bin/date` "$line" >> /var/log/ispconfig/cron.log; done)
    Jan 18 05:31:28 hostname postfix/qmgr[4933]: 44CE71233C: from=<[email protected]>, size=439, nrcpt=1 (queue active)
    Jan 18 05:31:29 hostname amavis[21709]: (21709-01) (!)connect_to_sql: unable to connect to DSN 'DBI:mysql:database=dbispconfig;host=127.0.0.1;port=3306': Can't connect to MySQL server on '127.0.0.1' (111)
    Jan 18 05:31:29 hostname postfix/smtp[23949]: 44CE71233C: to=<[email protected]>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.96, delays=0.04/0.01/0.55/0.37, dsn=4.3.2, status=deferred (host 127.0.0.1[127.0.0.1] said: 421 4.3.2 Service shutting down, closing channel (in reply to RCPT TO command))
    Jan 18 05:31:29 hostname postfix/smtp[23949]: warning: connect to mysql server 127.0.0.1: Can't connect to MySQL server on '127.0.0.1' (111)
    Jan 18 05:31:29 hostname postfix/smtp[23949]: warning: mysql:/etc/postfix/mysql-virtual_relaydomains.cf: table lookup problem
    Jan 18 05:31:29 hostname postfix/smtp[23949]: warning: 44CE71233C: flush service failure
    Jan 18 05:32:01 hostname CRON[24289]: (root) CMD (/usr/local/ispconfig/server/server.sh 2>&1 > /dev/null | while read line; do echo `/bin/date` "$line" >> /var/log/ispconfig/cron.log; done)
    Jan 18 05:33:01 hostname CRON[24412]: (root) CMD (/usr/local/ispconfig/server/server.sh 2>&1 > /dev/null | while read line; do echo `/bin/date` "$line" >> /var/log/ispconfig/cron.log; done)
    Jan 18 05:33:44 hostname postfix/smtpd[24509]: connect from s15424830.domainepardefaut.fr[87.106.96.164]
    Jan 18 05:33:45 hostname dovecot: auth-worker(24511): Error: mysql(localhost): Connect failed to database (dbispconfig): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111) - waiting for 1 seconds before retry
    
     
    Last edited: Jan 18, 2015
  2. concept21

    concept21 Member

    With clamd running, 2GB is necessary.
     
  3. Nap

    Nap Member

    My VPS has 2G memory. (1.95 actually) But it's been running fine for over 2 years now and the first time the problem occurred was a couple weeks ago.
    I'm hoping that someone can easily see what the cause was from the log files I linked.

    Cheers,
    Nap
     

Share This Page