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=<root@localhost>, 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
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
