Por Saulo Cruz

No seguinte cenário, durante a copia de arquivos para um recurso de disco físico de um novo cluster o recurso de disco falha.

Cenário:

  • 1 cluster Windows 2003 SP2 com 2 ou mais nós.
  • Arquivos à serem migrados para o recurso de disco físico.

Plano de ação seguido:

  • Instalado um novo cluster para substituir o antigo servidor de arquivos.
  • Novo cluster contém vários recursos de discos físicos.
  • Mantidas as atuais permissões NTFS.
  • Criado um batch file para copiar os arquivos usando o ROBOCOPY.

Durante o processo de cópia para um dos recursos de disco físico o disco fica "offline". O cluster tenta trazer o recurso online novamente no(s) outro(s) nós e também falha.

Revisando os logs de evento encontram-se as seguintes entradas:

Time: 10/10/2008 10:00:00 PM
ID: 1066
Level: Error
Provider: ClusSvc
Machine: CluterLab_N1
Message: Cluster disk resource "Disk H:" is corrupt. Run 'ChkDsk /F' to repair problems.
The volume name for this resource is \\?\Volume{85bafcb6-be1c-11dd-ad38-0015172a2f8f}\.
If available, ChkDsk output will be in the file "C:\WINDOWS\Cluster\ChkDsk_Disk9_Sig523071B0.log".
ChkDsk may write information to the Application Event Log with Event ID 26180.

Time: 10/10/2008 10:00:00 PM
ID: 1069
Level: Error
Provider: ClusSvc
Machine: ClusterLab_N1
Message: Cluster resource 'Disk H:' in Resource Group 'FileShare' failed.

Time: 10/10/2008 10:00:00 PM
ID: 1037
Level: Error
Provider: ClusSvc
Machine: ClusterLab_N1
Message: Cluster disk resource 'Disk H:' has failed a file system check. Please check your disk configuration.

Tentado sem sucesso trazer o recurso de volta. Deletar o recurso e criar um novo também não funciona. O disco não está mais acessível nesse momento. Nesse ponto a LUN no servidor foi: removida, destruída, recriada e apresentada novamente. Foi criado um novo recurso de disco físico e foi testado o acesso de leitura e gravação. Tudo funcionando perfeitamente.

Novamente é rodado o ROBOCOPY para copiar os arquivos para o novo recurso. Após um tempo copiando os arquivos, novamente o disco falha com os mesmos sintomas.

É acionado o suporte do storage, pois acredita-se que existe um problema com o hardware. Todos os testes são feitos e nenhum problema no hardware é encontrado.

O problema é facilmente reproduzido. Mas só acontece quando o ROBOCOPY é executado para fazer a cópia de uma pasta específica para qualquer recurso de disco físico. Detalhe importante, mas não foi levado em conta pois se acreditava ser problema de hardware.

Durante as inúmeras tentativas de solucionar o mistério os serviços de cluster são parados e o "cluster disk driver" desabilitado. Verifica-se que o disco é acessível e que os dados copiados até o momento da falha estão presentes.

Nesse momento o Suporte da Microsoft é acionado, pois o problema é com o serviço de cluster.

Analisando os logs do cluster vemos que o problema é devido ao acesso negado na raiz do disco:

...
00000ac4.00000ad0::2008/10/10-10:00:00.659 ERR Physical Disk <Disk H:>: DiskspCheckPath: GetFileAttrs(\\?\Volume{85bafcb6-be1c-11dd-ad38-0015172a2f8f}\) returned status of 5.
00000ac4.00000ad0::2008/10/10-10:00:00.659 WARN Physical Disk <Disk H:>: DiskspCheckPath: DCPI(\\?\Volume{85bafcb6-be1c-11dd-ad38-0015172a2f8f}\) returned status of 5, files scanned 0.
00000ac4.00000ad0::2008/10/10-10:00:00.659 ERR Physical Disk <Disk H:>: DiskpCheckPath for \\?\Volume{85bafcb6-be1c-11dd-ad38-0015172a2f8f}\: returned status = 5
000007e8.00000ad8::2008/10/10-10:00:00.659 INFO [FM] NotifyCallBackRoutine: enqueuing event
...

"Returned Status of 5" Significa que o serviço de cluster tentou acessar o disco é não conseguiu devido ao acesso ter sido negado.

O artigo KB286052 "The meaning of state codes in the Cluster log" tem uma descrição dos códigos de status registrados nos logs do cluster.

Reproduzimos os problemas e verificamos que estava-se copiando os dados para a raiz do recurso de disco físico. Nesse processo o ROBOCOPY estava substituindo as permissões, inclusive removendo as permissões da conta de serviço do cluster.

Foi criada uma pasta na raiz do disco e modificado o comando do ROBOCOPY para copiar os arquivos para o subpasta e não para a pasta raiz. O comando funcionou perfeitamente.

Mas porque o erro 1066 "Cluster disk resource "Disk H:" is corrupt. Run 'ChkDsk /F' to repair problems" estava sendo reportado?

Isso é explicado no artigo KB317635 "ChkDsk Utility Runs on the Shared Cluster Hard Disk When You Bring a Physical Disk Resource Online". Quando o cluster tenta trazer o recuso de disco físico "online" ele executa os seguintes passos para detectar se existe alguma corrupção com o recurso de disco:

  1. Um arquivo temporário chamado zClusterOnlineChk.tmp é criado na raiz do disco.
  2. Um padrão de testes é escrito e o cluster tenta salvar o arquivo.
  3. O arquivo é reaberto e lido e os dados escritos verificados.
  4. O arquivo é deletado.

Se qualquer passo anterior não é completado com sucesso o serviço de Cluster determina que o disco está corrompido e executa o utilitário ChkDsk /F para reparar possíveis danos.

Podemos ver isso no log do cluster:

...
00000ac4.000011b8::2008/10/10-10:00:05.471 ERR Physical Disk <Disk H:>: DiskspCheckPath: GetFileAttrs(H:) returned status of 5.
00000ac4.000011b8::2008/10/10-10:00:05.471 WARN Physical Disk <Disk H:>: DiskspCheckDriveLetter: Checking drive name (H:) returns 5
00000ac4.000011b8::2008/10/10-10:00:05.471 INFO Physical Disk <Disk H:>: DisksMountDrives: calling IsAlive function.
00000ac4.000011b8::2008/10/10-10:00:05.471 INFO Physical Disk <Disk H:>: DriveIsAlive called for Online check
00000ac4.000011b8::2008/10/10-10:00:05.471 INFO Physical Disk <Disk H:>: DriveIsAlive: GetVolumeNameForVolumeMountPoint (quorum) returned 2
00000ac4.000011b8::2008/10/10-10:00:05.471 ERR Physical Disk <Disk H:>: DiskspCheckPath: GetFileAttrs(\\?\Volume{85bafcb6-be1c-11dd-ad38-0015172a2f8f}\) returned status of 5.
00000ac4.000011b8::2008/10/10-10:00:05.471 WARN Physical Disk <Disk H:>: DiskspCheckPath: DCPI(\\?\Volume{85bafcb6-be1c-11dd-ad38-0015172a2f8f}\) returned status of 5, files scanned 0.
00000ac4.000011b8::2008/10/10-10:00:05.471 ERR Physical Disk <Disk H:>: DiskpCheckPath for \\?\Volume{85bafcb6-be1c-11dd-ad38-0015172a2f8f}\: returned status = 5
00000ac4.000011b8::2008/10/10-10:00:05.581 INFO Physical Disk <Disk H:>: DisksOpenChkdskLogFile: chkdsk.exe output is in file: C:\WINDOWS\Cluster\ChkDsk_Disk9_Sig523071B0.log
...

...
00000ac4.000011b8::2008/10/10-10:02:56.159 WARN Physical Disk <Disk H:>: FixCorruption: chkdsk.exe returned status of 1 - No errors or minor errors fixed.
00000ac4.000011b8::2008/10/10-10:02:57.003 ERR Physical Disk <Disk H:>: DiskspCheckPath: GetFileAttrs(H:) returned status of 5.
00000ac4.000011b8::2008/10/10-10:02:57.003 WARN Physical Disk <Disk H:>: DiskspCheckDriveLetter: Checking drive name (H:) returns 5
00000ac4.000011b8::2008/10/10-10:02:57.003 ERR Physical Disk <Disk H:>: DriveIsAlive failed checking drive letters
00000ac4.000011b8::2008/10/10-10:02:57.003 ERR Physical Disk <Disk H:>: Online, error mounting disk or creating share names for disk. Error: 5.
00000ac4.000011b8::2008/10/10-10:02:57.003 INFO Physical Disk <Disk H:>: Online, setting ResourceState 4 .
...

A mensagem do disco corrupto causou a confusão nesse caso tendo em vista que se iniciou o processo de resolução do problema primeiro pelo hardware mas não pelos logs do cluster.

Os seguintes artigos reportam que problemas em algumas versões do CHKDSK podem fazer com que as permissões do disco sejam alteradas e podem levar a incidentes similares ao cenário discutido:

Conclusão: a análise dos logs mostrou que o cluster não podia acessar os disco físicos devido as permissões terem sido removidas da pasta raiz.