MySQL今天早上在我身上崩溃了。
除了标准的 MySQL 包含的数据库之外,我使用的一切都是 InnoDB。
我试图重新启动 MySQL 守护程序,但它失败了两次。
然后我重新启动了整个服务器,MySQL 正确启动并且从那以后一直运行良好。
初始崩溃的 mysqld 日志文件包含以下内容:
120927 10:21:05 mysqld_safe Number of processes running now: 0 120927 10:21:06 mysqld_safe mysqld restarted 120927 10:21:12 [Note] Plugin 'FEDERATED' is disabled. 120927 10:21:12 InnoDB: The InnoDB memory heap is disabled 120927 10:21:12 InnoDB: Mutexes and rw_locks use GCC atomic builtins 120927 10:21:12 InnoDB: Compressed tables use zlib 1.2.3 120927 10:21:12 InnoDB: Using Linux native AIO 120927 10:21:13 InnoDB: Initializing buffer pool, size = 4.0G InnoDB: mmap(4395630592 bytes) failed; errno 12 120927 10:21:13 InnoDB: Completed initialization of buffer pool 120927 10:21:13 InnoDB: Fatal error: cannot allocate memory for the buffer pool 120927 10:21:13 [ERROR] Plugin 'InnoDB' init function returned error. 120927 10:21:13 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed. 120927 10:21:13 [ERROR] Unknown/unsupported storage engine: InnoDB 120927 10:21:13 [ERROR] Aborting 120927 10:21:13 [Note] /usr/libexec/mysqld: Shutdown complete 120927 10:21:13 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended
尝试重新启动守护程序时,mysqld 日志文件包含:
120927 10:43:44 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql 120927 10:43:44 [Note] Plugin 'FEDERATED' is disabled. 120927 10:43:44 InnoDB: The InnoDB memory heap is disabled 120927 10:43:44 InnoDB: Mutexes and rw_locks use GCC atomic builtins 120927 10:43:44 InnoDB: Compressed tables use zlib 1.2.3 120927 10:43:44 InnoDB: Using Linux native AIO 120927 10:43:44 InnoDB: Initializing buffer pool, size = 4.0G InnoDB: mmap(4395630592 bytes) failed; errno 12 120927 10:43:44 InnoDB: Completed initialization of buffer pool 120927 10:43:44 InnoDB: Fatal error: cannot allocate memory for the buffer pool 120927 10:43:44 [ERROR] Plugin 'InnoDB' init function returned error. 120927 10:43:44 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed. 120927 10:43:44 [ERROR] Unknown/unsupported storage engine: InnoDB 120927 10:43:44 [ERROR] Aborting 120927 10:43:44 [Note] /usr/libexec/mysqld: Shutdown complete 120927 10:43:44 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended
服务器重新启动后,mysqld 日志文件包含:
120927 10:46:11 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql 120927 10:46:11 [Note] Plugin 'FEDERATED' is disabled. 120927 10:46:11 InnoDB: The InnoDB memory heap is disabled 120927 10:46:11 InnoDB: Mutexes and rw_locks use GCC atomic builtins 120927 10:46:11 InnoDB: Compressed tables use zlib 1.2.3 120927 10:46:11 InnoDB: Using Linux native AIO 120927 10:46:11 InnoDB: Initializing buffer pool, size = 4.0G 120927 10:46:11 InnoDB: Completed initialization of buffer pool 120927 10:46:12 InnoDB: highest supported file format is Barracuda. InnoDB: The log sequence number in ibdata files does not match InnoDB: the log sequence number in the ib_logfiles! 120927 10:46:12 InnoDB: Database was not shut down normally! InnoDB: Starting crash recovery. InnoDB: Reading tablespace information from the .ibd files... InnoDB: Restoring possible half-written data pages from the doublewrite InnoDB: buffer... 120927 10:46:15 InnoDB: Waiting for the background threads to start 120927 10:46:16 InnoDB: 1.1.8 started; log sequence number 57665645675 120927 10:46:16 [Note] Event Scheduler: Loaded 0 events 120927 10:46:16 [Note] /usr/libexec/mysqld: ready for connections. Version: '5.5.21-cll' socket: '/var/lib/mysql/mysql.sock' port: 3306 MySQL Community Server (GPL) by Atomicorp
我从来没有尝试解密崩溃的 MySQL 日志文件。
我正在使用版本:5.5.21-cll MySQL Community Server (GPL) by Atomicorp
关于我应该从哪里开始的任何想法?
更新:根据@Michael-sqlbot 的建议,我提取了系统日志并发现了这一点:
Sep 27 10:20:58 ip-97-74-197-181 kernel: pcscd invoked oom-killer: gfp_mask=0xd0, order=0, oomkilladj=0 Sep 27 10:21:00 ip-97-74-197-181 kernel: Sep 27 10:21:00 ip-97-74-197-181 kernel: Call Trace: Sep 27 10:21:00 ip-97-74-197-181 kernel: [<ffffffff800c9f35>] out_of_memory+0x8e/0x2f3 Sep 27 10:21:00 ip-97-74-197-181 kernel: [<ffffffff8002dfc7>] __wake_up+0x38/0x4f Sep 27 10:21:00 ip-97-74-197-181 kernel: [<ffffffff8000f67d>] __alloc_pages+0x27f/0x308 Sep 27 10:21:00 ip-97-74-197-181 kernel: [<ffffffff80017a84>] cache_grow+0x139/0x3c7 Sep 27 10:21:00 ip-97-74-197-181 kernel: [<ffffffff8005be28>] cache_alloc_refill+0x138/0x188 Sep 27 10:21:00 ip-97-74-197-181 kernel: [<ffffffff8000ad2e>] kmem_cache_alloc+0x6c/0x76 Sep 27 10:21:00 ip-97-74-197-181 kernel: [<ffffffff80012877>] getname+0x25/0x1c2 Sep 27 10:21:00 ip-97-74-197-181 kernel: [<ffffffff8001a04b>] do_sys_open+0x17/0xbe Sep 27 10:21:00 ip-97-74-197-181 kernel: [<ffffffff8005d28d>] tracesys+0xd5/0xe0 Sep 27 10:21:00 ip-97-74-197-181 kernel: Sep 27 10:21:11 ip-97-74-197-181 kernel: Mem-info: Sep 27 10:21:20 ip-97-74-197-181 kernel: Node 0 DMA per-cpu: Sep 27 10:21:27 ip-97-74-197-181 kernel: cpu 0 hot: high 0, batch 1 used:0 Sep 27 10:21:38 ip-97-74-197-181 kernel: cpu 0 cold: high 0, batch 1 used:0 Sep 27 10:21:49 ip-97-74-197-181 kernel: cpu 1 hot: high 0, batch 1 used:0 Sep 27 10:21:49 ip-97-74-197-181 kernel: cpu 1 cold: high 0, batch 1 used:0 Sep 27 10:21:49 ip-97-74-197-181 kernel: cpu 2 hot: high 0, batch 1 used:0 Sep 27 10:21:52 ip-97-74-197-181 kernel: cpu 2 cold: high 0, batch 1 used:0 Sep 27 10:21:52 ip-97-74-197-181 kernel: cpu 3 hot: high 0, batch 1 used:0 Sep 27 10:21:52 ip-97-74-197-181 kernel: cpu 3 cold: high 0, batch 1 used:0 Sep 27 10:21:52 ip-97-74-197-181 kernel: Node 0 DMA32 per-cpu: Sep 27 10:21:52 ip-97-74-197-181 kernel: cpu 0 hot: high 186, batch 31 used:60 Sep 27 10:21:52 ip-97-74-197-181 kernel: cpu 0 cold: high 62, batch 15 used:57 Sep 27 10:21:52 ip-97-74-197-181 kernel: cpu 1 hot: high 186, batch 31 used:139 Sep 27 10:21:52 ip-97-74-197-181 kernel: cpu 1 cold: high 62, batch 15 used:61 Sep 27 10:21:52 ip-97-74-197-181 kernel: cpu 2 hot: high 186, batch 31 used:47 Sep 27 10:21:52 ip-97-74-197-181 kernel: cpu 2 cold: high 62, batch 15 used:57 Sep 27 10:21:52 ip-97-74-197-181 kernel: cpu 3 hot: high 186, batch 31 used:52 Sep 27 10:21:52 ip-97-74-197-181 kernel: cpu 3 cold: high 62, batch 15 used:53 Sep 27 10:21:52 ip-97-74-197-181 kernel: Node 0 Normal per-cpu: Sep 27 10:21:52 ip-97-74-197-181 kernel: cpu 0 hot: high 186, batch 31 used:29 Sep 27 10:21:52 ip-97-74-197-181 kernel: cpu 0 cold: high 62, batch 15 used:17 Sep 27 10:21:52 ip-97-74-197-181 kernel: cpu 1 hot: high 186, batch 31 used:178 Sep 27 10:21:52 ip-97-74-197-181 kernel: cpu 1 cold: high 62, batch 15 used:52 Sep 27 10:21:52 ip-97-74-197-181 kernel: cpu 2 hot: high 186, batch 31 used:22 Sep 27 10:21:52 ip-97-74-197-181 kernel: cpu 2 cold: high 62, batch 15 used:59 Sep 27 10:21:52 ip-97-74-197-181 kernel: cpu 3 hot: high 186, batch 31 used:71 Sep 27 10:21:52 ip-97-74-197-181 kernel: cpu 3 cold: high 62, batch 15 used:54 Sep 27 10:21:52 ip-97-74-197-181 kernel: Node 0 HighMem per-cpu: empty Sep 27 10:21:52 ip-97-74-197-181 kernel: Free pages: 41728kB (0kB HighMem) Sep 27 10:21:52 ip-97-74-197-181 kernel: Active:1031140 inactive:970428 dirty:0 writeback:0 unstable:0 free:10432 slab:4277 mapped-file:801 mapped-anon:1993003 pagetables:11636 Sep 27 10:21:52 ip-97-74-197-181 kernel: Node 0 DMA free:10096kB min:12kB low:12kB high:16kB active:0kB inactive:0kB present:9700kB pages_scanned:0 all_unreclaimable? yes Sep 27 10:21:52 ip-97-74-197-181 kernel: lowmem_reserve[]: 0 2965 8015 8015 Sep 27 10:21:52 ip-97-74-197-181 kernel: Node 0 DMA32 free:24424kB min:4236kB low:5292kB high:6352kB active:1544164kB inactive:1428756kB present:3037024kB pages_scanned:7185900 all_unreclaimable? yes Sep 27 10:21:52 ip-97-74-197-181 kernel: lowmem_reserve[]: 0 0 5050 5050 Sep 27 10:21:52 ip-97-74-197-181 kernel: Node 0 Normal free:7208kB min:7212kB low:9012kB high:10816kB active:2580172kB inactive:2453052kB present:5171200kB pages_scanned:12935183 all_unreclaimable? yes Sep 27 10:21:52 ip-97-74-197-181 kernel: lowmem_reserve[]: 0 0 0 0 Sep 27 10:21:52 ip-97-74-197-181 kernel: Node 0 HighMem free:0kB min:128kB low:128kB high:128kB active:0kB inactive:0kB present:0kB pages_scanned:0 all_unreclaimable? no Sep 27 10:21:52 ip-97-74-197-181 kernel: lowmem_reserve[]: 0 0 0 0 Sep 27 10:21:52 ip-97-74-197-181 kernel: Node 0 DMA: 6*4kB 3*8kB 4*16kB 4*32kB 4*64kB 5*128kB 1*256kB 1*512kB 0*1024kB 0*2048kB 2*4096kB = 10096kB Sep 27 10:21:52 ip-97-74-197-181 kernel: Node 0 DMA32: 24*4kB 3*8kB 1*16kB 1*32kB 1*64kB 3*128kB 1*256kB 0*512kB 1*1024kB 1*2048kB 5*4096kB = 24424kB Sep 27 10:21:52 ip-97-74-197-181 kernel: Node 0 Normal: 0*4kB 13*8kB 8*16kB 0*32kB 19*64kB 1*128kB 2*256kB 0*512kB 1*1024kB 0*2048kB 1*4096kB = 7208kB Sep 27 10:21:52 ip-97-74-197-181 kernel: Node 0 HighMem: empty Sep 27 10:21:52 ip-97-74-197-181 kernel: 9391 pagecache pages Sep 27 10:21:52 ip-97-74-197-181 kernel: Swap cache: add 5745145, delete 5744809, find 81873079/82270945, race 0+63 Sep 27 10:21:52 ip-97-74-197-181 kernel: Free swap = 0kB Sep 27 10:21:52 ip-97-74-197-181 kernel: Total swap = 2096472kB Sep 27 10:21:52 ip-97-74-197-181 kernel: Free swap: 0kB Sep 27 10:21:52 ip-97-74-197-181 kernel: 2359296 pages of RAM Sep 27 10:21:52 ip-97-74-197-181 kernel: 324458 reserved pages Sep 27 10:21:52 ip-97-74-197-181 kernel: 21388 pages shared Sep 27 10:21:52 ip-97-74-197-181 kernel: 336 pages swap cached Sep 27 10:21:52 ip-97-74-197-181 kernel: Out of memory: Killed process 3044, UID 27, (mysqld).
我有好消息,也有坏消息。好消息是,您的文件系统和 mysql 很可能没问题……但请检查 /var/log/syslog 或等效项,以查看 10:21:05 之前系统上发生的其他情况。
当您发布的第一条消息被记录时,您的 mysql 服务器已经死了。
120927 10:21:05 mysqld_safe Number of processes running now: 0
所以,假设你没有忽略 mysql 错误日志中的任何内容,我会说它没有崩溃和死亡——它实际上被杀死了。
当 mysqld_safe (它是一个包装器,而不是服务器本身)意识到服务器没有运行,并且服务器没有正常终止时,它会为你重新启动它......
120927 10:21:06 mysqld_safe mysqld restarted
…然后服务器守护进程记录了一些正常的启动消息…
120927 10:21:12 [Note] Plugin 'FEDERATED' is disabled. 120927 10:21:12 InnoDB: The InnoDB memory heap is disabled 120927 10:21:12 InnoDB: Mutexes and rw_locks use GCC atomic builtins 120927 10:21:12 InnoDB: Compressed tables use zlib 1.2.3 120927 10:21:12 InnoDB: Using Linux native AIO
…但是当 mysqld 要求操作系统为 InnoDB 缓冲池分配 4GB 内存时…
120927 10:21:13 InnoDB: Initializing buffer pool, size = 4.0G
…内核说“不”。
InnoDB: mmap(4395630592 bytes) failed; errno 12
检查内核源代码以确保:
#define ENOMEM 12 /* Out of memory */
是的。因此,应该忽略“失败;errno 12”行下方的每条消息——它们都是这条消息的副作用。
但同样,所有这些事情都发生在第一次崩溃之后。
我最好的猜测是,极低的内存条件导致您的内核最初杀死 mysqld 以试图稳定系统。
自然,导致内存不足的任何原因在重新启动后都消失了。mysql 服务器能够为 InnoDB 缓冲池分配 4GB,并且一切都应该很好,直到导致内存不足的原因再次导致它。
第一个猜测:apache 子进程运行异常。