Antes de começar, um aviso rápido. Eu sou basicamente um desenvolvedor forçado em um papel sysadmin pelas circunstâncias, por isso peço desculpas antecipadamente se eu disser algo estúpido ou parecer que não sei o que estou fazendo.
Então, estamos tendo problemas com um dos HDD-s em nosso servidor principal. /dev/sda tem duas partições, uma montada como / e outra usada como unidade de dados PostgreSQL ( /dev/sda2 ).
$ df -h
Filesystem Size Used Avail Use% Mounted on
rootfs 92G 13G 75G 14% /
udev 10M 0 10M 0% /dev
tmpfs 1.6G 12M 1.6G 1% /run
/dev/disk/by-uuid/8ffca87a-ffe4-4c39-ab30-352b61f039f8 92G 13G 75G 14% /
tmpfs 5.0M 0 5.0M 0% /run/lock
tmpfs 3.2G 0 3.2G 0% /run/shm
/dev/sda2 826G 66G 719G 9% /var/lib/data/vol1
/dev/sdb1 917G 75G 797G 9% /var/lib/data/vol2
(/ dev / sda1 é montado usando seu UUID por algum motivo)
Ultimamente, começou a experimentar intervalos de 100% I / O / P, durante os quais o sistema está praticamente bloqueado e incapaz de executar as tarefas mais simples.
Um breve trecho do dmesg:
[6554534.743764] INFO: task /usr/bin/monito:29408 blocked for more than 120 seconds.
[6554534.743828] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[6554534.743889] /usr/bin/monito D ffff88041fcd3780 0 29408 1 0x00000000
[6554534.743891] ffff880101906780 0000000000000082 ffff880100000000 ffff88040f2c0100
[6554534.743893] 0000000000013780 ffff880187b45fd8 ffff880187b45fd8 ffff880101906780
[6554534.743895] 0000000000000246 000000018134fb39 ffff88041ffc8328 ffff88039bac2dd8
[6554534.743896] Call Trace:
[6554534.743899] [<ffffffffa019e660>] ? do_get_write_access+0x1ad/0x36a [jbd2]
...
Sabemos que isso é acionado por consultas do PostgreSQL. Aqui está a saída iotop enquanto isso está acontecendo:
22609 be/4 postgres 441.12 K/s 0.00 B/s 0.00 % 98.46 % postgres: db_name~a_1 127.0.0.1(33183) SELECT
24359 be/4 postgres 988.02 K/s 0.00 B/s 0.00 % 98.22 % postgres: db_name~a_1 127.0.0.1(34194) SELECT
Você pode estar pensando: "Apenas otimize seu DB, cara. Onde está o mistério?"
No entanto, leve em consideração 3 coisas:
-
Há outra instância do mesmo aplicativo, executando o mesmo esquema do banco de dados em /dev/sdb , sob carga semelhante. A pressão de E / S é normal, raramente acima de 10 a 20%.
-
Veja a taxa de transferência combinada dos dois processos do PostgreSQL nessa listagem. Ele mal passa 1MB / s. Isso parece muito baixo para um processo de banco de dados (que deve ser otimizado para ser o mais sequencial possível).
-
Qualquer que seja a carga no disco rígido, ele nunca deve ser bloqueado completamente como acontece aqui, ao ponto de produzir erros do kernel e um simples ls levando um minuto para ser concluído.
Minha conclusão de tudo isso é que /dev/sda está falhando e precisa ser substituído. E aqui reside o problema. Antes de entrar em contato com a empresa de hospedagem, preciso fornecer algumas provas de que o HDD está realmente falhando. No entanto ...
smartctl /dev/sda --all
smartctl 5.41 2011-06-09 r3365 [x86_64-linux-3.2.0-4-amd64] (local build)
Copyright (C) 2002-11 by Bruce Allen, http://smartmontools.sourceforge.net
=== START OF INFORMATION SECTION ===
Device Model: WDC WD1003FBYZ-010FB0
...
=== START OF READ SMART DATA SECTION ===
SMART overall-health self-assessment test result: PASSED
...
SMART Attributes Data Structure revision number: 16
Vendor Specific SMART Attributes with Thresholds:
ID# ATTRIBUTE_NAME FLAG VALUE WORST THRESH TYPE UPDATED WHEN_FAILED RAW_VALUE
1 Raw_Read_Error_Rate 0x002f 200 200 051 Pre-fail Always - 0
3 Spin_Up_Time 0x0027 100 253 021 Pre-fail Always - 0
4 Start_Stop_Count 0x0032 100 100 000 Old_age Always - 2
5 Reallocated_Sector_Ct 0x0033 200 200 140 Pre-fail Always - 0
7 Seek_Error_Rate 0x002e 100 253 000 Old_age Always - 0
9 Power_On_Hours 0x0032 098 098 000 Old_age Always - 2114
10 Spin_Retry_Count 0x0032 100 253 000 Old_age Always - 0
11 Calibration_Retry_Count 0x0032 100 253 000 Old_age Always - 0
12 Power_Cycle_Count 0x0032 100 100 000 Old_age Always - 2
192 Power-Off_Retract_Count 0x0032 200 200 000 Old_age Always - 2
193 Load_Cycle_Count 0x0032 200 200 000 Old_age Always - 9
194 Temperature_Celsius 0x0022 112 109 000 Old_age Always - 35
196 Reallocated_Event_Count 0x0032 200 200 000 Old_age Always - 0
197 Current_Pending_Sector 0x0032 200 200 000 Old_age Always - 0
198 Offline_Uncorrectable 0x0030 100 253 000 Old_age Offline - 0
199 UDMA_CRC_Error_Count 0x0032 200 200 000 Old_age Always - 0
200 Multi_Zone_Error_Rate 0x0008 200 200 000 Old_age Offline - 0
SMART Error Log Version: 1
No Errors Logged
SMART Self-test log structure revision number 1
Num Test_Description Status Remaining LifeTime(hours) LBA_of_first_error
# 1 Extended offline Completed without error 00% 2108 -
...
(saída truncada, deixe-me um comentário se eu cortar muito)
Como você pode ver, o smartctl diz que tudo está OK. Eu até fiz um teste completo e nenhum erro foi encontrado.
Então estou perdido aqui. Tudo aponta para um disco rígido com falha, mas o monitoramento de S.M.A.R.T não detecta nada.
Minhas perguntas:
- O meu diagnóstico está correto? A unidade está realmente falhando?
- Se sim, como obtenho algum relatório sobre isso, que posso mostrar à empresa de hospedagem para que eles concordem em substituí-lo?
- Se não, qual é o próximo culpado mais provável?
UPDATE 1
De acordo com o conselho de Baruch, eu executei o discscan. Infelizmente, não encontrei nada que eu possa apontar.
diskscan /dev/sda
diskscan version HEAD
I: Validating path /dev/sda
I: Opened disk /dev/sda sector size 512 num bytes 1000204885504
I: Scanning disk /dev/sda in 65536 byte steps
I: Scan started at: Sun Aug 31 04:21:33 2014
Access time histogram:
1: 14138808
10: 923503
100: 183268
500: 15944
1000: 436
2000: 1
3000: 0
4000: 0
5000: 0
6000: 0
7000: 0
8000: 0
9000: 0
10000: 0
15000: 0
20000: 0
25000: 0
30000: 0
above that: 0
1290 |
|
| ^
|
|
1075 |
|
| ^
|
|
860 | ^
| ^ ^
|
| ^ ^ ^ ^ ^
| ^ ^^ ^ ^
645 | ^^ ^ ^ ^^^ ^ ^ ^ ^^^^^ ^^ ^
| ^ ^ ^ ^ ^ ^ ^^^ ^
| ^ ^ ^ ^ ^ ^ ^^
| ^ ^ ^ ^
| ^ ^ ^ ^
430 | ^ ^^^ ^ ^ ^
|
| ^ ^ ^^
|
|
215 |
|
|
| **********************************************************************
| ______________________________________________________________________
+-----------------------------------------------------------------------
Conclusion: passed
I: Scan ended at: Sun Aug 31 09:22:34 2014
I: Scan took 18061 second
I: Closed disk /dev/sda
Também atualizei meus backups parciais e estou prestes a fazer um backup completo antes de continuar.
Próximos passos:
Eu instalei o script iosnoop (sugerido por Baruch). Eu posso conseguir isso para coletar latências, mas não consigo descobrir como posso fazer com que ele produza algo que seja uma informação acionável para a empresa de hospedagem.
A terceira sugestão de Baruch está acima da minha cabeça ATM. Vou investigar mais e atualizar se eu descobrir alguma coisa.
Se eu não descobrir nada até amanhã, recomendarei apenas comprar outro disco e transferir o sda para lá. Então saberemos se houve um problema no disco ou algo mais e continuemos a partir daí.
UPDATE 2
Executou smartctl -x . Nada demais para ver, mas aqui está um pastebin com resultados completos.
Ativado o registro detalhado do scsi de acordo com as instruções do Baruch. Estou recebendo muitas coisas assim em minhas / var / log / messages:
Aug 31 15:28:07 swfemail kernel: [7539683.491379] sd 0:0:0:0: [sda] Send:
Aug 31 15:28:07 swfemail kernel: [7539683.491382] sd 0:0:0:0: [sda] CDB: Write(10): 2a 00 01 3f ce 80 00 00 10 00
Aug 31 15:28:07 swfemail kernel: [7539683.491526] sd 0:0:0:0: [sda] Send:
Aug 31 15:28:07 swfemail kernel: [7539683.491528] sd 0:0:0:0: [sda] CDB: Synchronize Cache(10): 35 00 00 00 00 00 00 00 00 00
Aug 31 15:28:08 swfemail kernel: [7539684.411573] sd 0:0:0:0: [sda] Send:
Aug 31 15:28:08 swfemail kernel: [7539684.411576] sd 0:0:0:0: [sda] CDB: Write(10): 2a 00 01 b6 da d0 00 00 08 00
Aug 31 15:28:08 swfemail kernel: [7539684.411597] sd 0:0:0:0: [sda] Send:
Aug 31 15:28:08 swfemail kernel: [7539684.411598] sd 0:0:0:0: [sda] CDB: Write(10): 2a 00 01 b6 ba d0 00 00 08 00
Aug 31 15:28:08 swfemail kernel: [7539684.411639] sd 0:0:0:0: [sda] Send:
Aug 31 15:28:08 swfemail kernel: [7539684.411639] sd 0:0:0:0: [sda] CDB: Write(10): 2a 00 05 c6 18 88 00 00 a8 00
Aug 31 15:28:08 swfemail kernel: [7539684.412056] sd 0:0:0:0: [sda] Send:
Aug 31 15:28:08 swfemail kernel: [7539684.412057] sd 0:0:0:0: [sda] CDB: Synchronize Cache(10): 35 00 00 00 00 00 00 00 00 00
Nada muito útil até agora, mas o disco entrou em uma fase "silenciosa". Vou tentar pegar a saída assim que começar a bloquear novamente.
Afinal, pensei em verificar as mensagens de erro mais antigas do kernel. Nada aparece como um erro direto. Apenas um monte de avisos de tempo limite.
UPDATE 3
Tentei ler os logs scsi durante a janela de tempo de pressão de 100%. Nenhuma entrada de ERRO ou TIMEOUT: - (
Adicionamos outro disco rígido. Atualmente estou clonando com dd if=/dev/sda of=/dev/sdc bs=32M (mais tarde eu farei outra passagem com o rsync enquanto estiver offline). Espero que isso seja feito até o final do dia.
Eu atualizarei novamente em alguns dias com resultados.
UPDATE 4
Devido a problemas com nossa empresa de hospedagem, não conseguimos mudar totalmente para um novo disco. Até que os problemas fossem resolvidos, comprometemo-nos a mover apenas o banco de dados para o novo disco. Aqui está o layout atual (apenas dispositivos pertinentes):
/dev/sdc1 92G 23G 65G 26% /
/dev/sdb1 917G 170G 701G 20% /var/lib/data/vol2
/dev/sda2 826G 71G 714G 9% /var/lib/data/vol1
/dev/sdc é o disco (potencialmente) ruim. /dev/sda é o novo disco que agora tem o banco de dados.
O próximo passo é monitorar a situação e ver se as rajadas de uso de 100% retornam. Vou atualizar (e espero postar a resposta aceita) em poucos dias.