MySQL caiu em mim esta manhã.
Com exceção dos bancos de dados incluídos no MySQL padrão, tudo o que uso é o InnoDB.
Tentei reiniciar o daemon do MySQL, mas falhou duas vezes.
Em seguida, reiniciei todo o servidor e o MySQL iniciou corretamente e tem funcionado bem desde então.
O arquivo de log do mysqld para a falha inicial contém o seguinte:
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
Ao tentar reiniciar o daemon, o arquivo de log mysqld contém:
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
Após a reinicialização do servidor, o arquivo de log do mysqld contém:
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
Eu nunca tive que tentar decifrar um arquivo de log do MySQL com falha.
Estou usando a versão: 5.5.21-cll MySQL Community Server (GPL) da Atomicorp
Alguma ideia de por onde devo começar?
ATUALIZAÇÃO: Por recomendação de @Michael-sqlbot, puxei o syslog e encontrei isto:
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).
Tenho boas notícias e más notícias. A boa notícia é que seu sistema de arquivos e mysql provavelmente estão bem ... mas verifique /var/log/syslog ou equivalente para ver o que mais estava acontecendo em seu sistema antes de 10:21:05.
Quando a primeira mensagem que você postou foi registrada, seu servidor mysql já havia morrido.
Portanto, supondo que você não tenha esquecido nada no log de erros do mysql, direi que ele não travou e morreu - na verdade, foi morto.
Quando mysqld_safe (que é um wrapper, não o servidor em si) percebeu que o servidor não estava rodando, e que o servidor não havia terminado corretamente, ele o reiniciou para você...
...então o daemon do servidor registrou algumas mensagens normais de inicialização...
...mas quando o mysqld pediu ao sistema operacional para alocar 4GB de memória para o pool de buffer InnoDB...
...o kernel disse "não".
Verificando a fonte do kernel para ter certeza:
Sim. Portanto, todas as mensagens abaixo da linha "falha; errno 12" devem ser desconsideradas - todas são efeitos colaterais desta.
Mas, novamente, todas essas coisas aconteceram após o primeiro acidente.
Meu melhor palpite é que uma condição de memória extremamente baixa fez com que seu kernel originalmente matasse o mysqld em uma tentativa de estabilizar o sistema.
Naturalmente, o que causou a falta de memória desapareceu após a reinicialização. O servidor mysql foi capaz de alocar 4 GB para o buffer pool do InnoDB, e tudo deve estar bom até que o que quer que tenha causado a falta de memória o cause novamente.
Primeiro palpite: os processos filhos do apache ficam descontrolados.
Isso aconteceu comigo recentemente e este tópico foi inestimável para me ajudar a entender o que está acontecendo.
Estou executando uma pilha LAMP no Ubuntu 14.04 com 1 GB de RAM. Meu servidor continuou travando devido a picos de tráfego na web. Para mim, mexer no arquivo de configuração mysql apenas estendeu a quantidade de tempo que eu experimentaria outra falha aleatória. Para testar e consertar isso, acabei usando a ferramenta ab do Apache:
ab -n 100 -c 10 http://gastonia.com/
10 simultaneidades (-c) estava ok, então incrementei até atingir 30 - bam - crash. Recuei até encontrar um número seguro e, em seguida, ajustei a diretiva ServerLimit do Apache:
ServerLimit 20
Depois disso, eu poderia alterar -c para qualquer número que quisesse e ainda não experimentei outro travamento.
Espero que seja útil para qualquer pessoa que tenha o mesmo problema.
Eu tive o mesmo problema postado originalmente, além de corrupções recorrentes do InnoDB em intervalos aleatórios após reinicializações misteriosas do Mysql_safe.
Normalmente, eu era capaz de reiniciar o Mysql parando primeiro o Apache.
Depois de ler este post, procurei nos logs do syslog e encontrei: kernel: Sem memória: Kill process 19468 (mysqld) score 256 ou sacrificar filho Com o mesmo registro de data e hora que o misterioso mysql trava.
Eu também correspondi a rajadas de tráfego e pilhas de processos httpd (apache). Reduzi o tamanho do pool innoDB, aumentei um pouco o tamanho da troca e limitei o número máximo de processos apache apenas por precaução.
quando você tem
tente detectar quais processos consomem sua memória e troque:
então mate todos eles: