Checkpoint Depth too deep

Por: Viviane Lopes

Uma das causas mais comuns para o súbito shutdown dos bancos de dados de um servidor Exchange é o comportamento conhecido como “Checkpoint Depth too deep”.

Neste artigo vou explicar o que acontece durante o processo, principais causas e como monitorar o servidor Exchange de forma a evitar o acontecimento deste comportamento.

Conceitos importantes:

• ESE (Extensible Storage Engine): Database Engine utilizada pelo Exchange Information Store, baseado na tecnologia denominada Microsoft Joint Engine (JET).

• Log de transação (Transaction Log):  Todas as alterações realizadas no banco de dados do Exchange são inicialmente gravadas no log de transação, e posteriormente no banco de dados.

  Os logs de transações são críticos para o servidor Exchange e existem para garantir a integridade transacional do banco de dados e possibilitar a recuperação total dos dados em caso de uma parada abrupta do servidor.

• Checkpoint: O Checkpoint é um arquivo de sistema do servidor Exchange responsável por acompanhar o progresso dos logs de transações em relação aos bancos de dados.

  Cada Storage Group contém um único arquivo de Checkpoint, denominado Enn.chk, onde nn representa o prefixo do Storage Group em questão.

Exemplo:

E00.chk – checkpoint do Primeiro Storage Group.

E01.chk – checkpoint do Segundo Storage Group

E02.chk – checkpoint do Terceiro Storage Group.

E03.chk – checkpoint do Quarto Storage Group.

Checkpoint Depth:

Em um servidor Exchange 2000 ou 2003, cada Storage Group pode ter no máximo 1008 logs de transações não aplicados nos bancos de dados em um dado momento. O número 1008 está pré-definido no código do produto e não pode ser customizado.

O controle de transações não aplicadas no banco de dados é realizado através do Checkpoint.

Quando o número de logs de transações não aplicados em um Storage Group atinge o número máximo permitido, o servidor Exchange começa o processo de shutdown de todos os bancos de dados do Storage Group em questão.

Nesta situação, os seguintes eventos são informados no log de aplicações:

Event ID : 471

Category : Logging/Recovery

Source : ESE

Type : Error

Message : Information Store (2908) Unable to rollback operation #12317050 on database G:\First Storage Group\Mailbox Store (Server1). Error: -614. All future database updates will be rejected.

Event Type: Error
Event Source: MSExchangeIS
Event Category: General
Event ID: 1159
Description: Database error 0xfffffd9a occurred in function JTAB_BASE::EcUpdate while accessing the database "<C:\Program Files\Exchsrvr\mdbdata\vip.edb>".

Os erros -614 e 0xfffffd9a podem ser traduzidos para:

“ JET_errCheckpointDepthTooDeep” – too many outstanding generations between checkpoint and current generation.

O serviço do Information Store opera desta forma para impedir que o controle de Checkpoint fique muito distante dos logs de transações criados pelo sistema. É uma proteção do servidor Exchange para garantir a integridade dos dados.

Em um servidor Exchange com alto volume de carga, o valor do Checkpoint Depth normalmente deve ficar entre 4 ou 5 logs. Isso significa que as transações contidas nestes logs ainda não foram aplicadas no banco de dados. Se o servidor parar subitamente, por exemplo, por um problema de falta de energia, estes 4 logs serão os logs de transações necessários para colocar o banco de dados consistente, até o momento da queda.

Quando a energia for restaurada e o serviço do Information Store reiniciado, o arquivo Checkpoint de cada Storage Group será consultado. O Checkpoint informa ao Information Store à partir de qual log de transação ele deverá iniciar o processo de recuperação dos dados que ainda não haviam sido gravados nos bancos de dados.

Os cenários mais comuns para o acontecimento deste problema são:

01 – Um processo “congelou” as atualizações no arquivo de checkpoint. Normalmente isso acontece durante o processo de backup on-line.

02 – Duas tarefas concorrentes estão sendo executadas ao mesmo tempo, como por exemplo uma movimentação de mailboxes em larga escala e uma tarefa de backup.

03 – O servidor está experimentando problemas de performance. Por exemplo, problemas de performance nos discos podem prevenir o servidor de responder rapidamente a múltiplas requisições de I/O.

Como monitorar o servidor Exchange ?

01 - À partir do Rollup de Setembro para o Exchange 2000 e versões posteriores, é possivel monitorar o número de logs de transações não aplicados em um Storage Group através do Performance Monitor.

O contador “Log Generation Checkpoint Depth” (Objeto Database è Instances) reporta o número de logs de transações de um Storage Group que ainda não foram aplicados nos bancos de dados.

O valor informado pode ser entendido como a quantidade de logs que devem ser aplicados no banco de dados caso o processo do Information Store (Store.exe) apresente qualquer tipo de falha.

A lógica é – quanto maior o “Log generation depth” , mais tempo o processo de inicio (startup) do serviço do Information Store levará.

Muitas vezes trabalhamos em incidentes de suporte em que o cliente reporta uma demora significativa para que o serviço do Information Store inicie – nesta situação, o serviço permanece no estado de “Starting” e todas as tentativas de conexões de clientes são recusadas.

O log de aplicações irá reportar o evento 301 – indicando que o processo de aplicação dos logs de transações nos bancos de dados está sendo realizado (soft-recovery). Se o Checkpoint estiver muito atrás em relação a geração de logs presente no disco, o processo poderá demorar muito mais do que o “desejado”.

Event Type: Information
Event Source: ESE
Event Category:
Event ID: 301
Description: Information Store (1728) The database engine has begun replaying logfile D:\Program Files\Exchsrvr\SG1\E001453A.log.

O efeito colateral é obviamente percebido pelos clientes, que não poderão se conectar no servidor Exchange enquanto o processo não estiver finalizado.

No exemplo abaixo, o Checkpoint Depth está no valor 4, ou seja, informações contidas em 4 logs de transações ainda não foram aplicados nos bancos de dados.

Durante uma tarefa de backup, é normal que este valor cresça, pois o processo de backup “congela” o checkpoint temporariamente para garantir a integridade dos dados que estão sendo copiados. Porém, se o tempo de backup de um Storage Group for demasiado alto, e o servidor estiver sendo acessado durante o processo (gerando logs de transações), o valor pode chegar ao limite de 1008 logs, quando então todos os bancos de dados serão desmontados.

A solução neste caso é planejar o tamanho dos Storage Groups adequadamente, levando em consideração o tempo de backup e a quantidade de logs de transações gerados durante as atividades normais dos usuários.

Outra situação comum, é uma tarefa de backup mal-sucedida, onde o processo de backup não descongela o Checkpoint. O servidor Exchange continuará trabalhando normalmente, até que o Checkpoint Depth atinga 1008 logs – neste ponto os bancos de dados serão desmontados.

Neste caso, o melhor é verificar o que há de errado com a rotina de backup e o motivo pela qual o processo não está sendo finalizado corretamente.

02 – Outra forma de monitorar o CheckPoint Depth é utilizando o pacote para monitoramento do Exchange existente no servidor MOM (Microsoft Operations Management):

O pacote de monitoramento para Exchange existente no servidor MOM inclui a seguinte regra:

ESE Log Generation CheckPoint Depth > 800 – O MOM irá disparar um alerta ao administrador quando o valor ultrapassar a marca de 800.

Se você precisar de mais informações, por favor utilize os seguintes artigos da Microsoft como referência:

905801 The information store is dismounted, and an event ID 1159 message is logged in Exchange Server 2003 or in Exchange 2000 Server

https://support.microsoft.com/default.aspx?scid=kb;EN-US;905801

819771 Update to monitor uncommitted transaction log files

https://support.microsoft.com/default.aspx?scid=kb;EN-US;819771