Como lidar com problemas de sincronismo de horário em redes instáveis

Olá  pessoal! Me chamo Guilherme Pohlmann e faço parte do time de suporte Windows do Brasil.

Recentemente trabalhei em alguns incidentes deste cliente, todos relacionados ao serviço de Horário do Windows. O ambiente possuia configurações confusas para o serviço em questão, incluindo ferramentas de terceiros usadas para fazer a sincronização de múltiplas máquinas, logo, foram incidentes que demandaram uma revisão do serviço como um todo.

 

Apesar de arrumar todas as configurações, fazendo com que as máquinas sincronizassem o horário respeitando a hierarquia do domínio, alguma coisa ainda não estava certa. Embora todas as máquinas (estações de trabalho e servidores) estivessem sincronizando horário com os domain controllers e os próprios domain controllers sincronizando horário com o PDCe, ainda estávamos "perdendo tempo" de forma gradativa.

 

Na verdade, a cada hora tínhamos alguns segundos sendo perdidos no PDCe e, com dias, estes segundos se tornavam minutos e levavam a problemas devido aos procedimentos de entrada e saída de funcionários do cliente.

 

Com isso em mente, preparamos uma coleta de dados utilizando capturas de rede e logs de depuração do serviço de Horário do Windows. Agora percebo que um dia de coleta de dados foi demais, mas isso fará mais sentido conforme avançamos na análise. Mesmo assim, os dados coletados foram importantes para entender o que estava acontecendo.

 

Por questões de informação, este artigo explica como habilitar os logs de depuração do serviço de Horário do Windows. Ou, podemos simplesmente usar o
reg add: 

reg add HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\W32Time\Config /v FileLogSize /t REG_DWORD /d 10000000 /f

reg add HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\W32Time\Config /v FileLogName /t REG_SZ /d C:\temp\logs\%computername%-w32time.log /f

reg add HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\W32Time\Config /v FileLogEntries /t REG_SZ /d 0-300 /f

 

Na coleta de dados, podemos ver que a rede em si não era das mais estáveis, visto que diversos comandos baseados no w32tm, falhavam com erros de timeout:

 

08:19:01 error: 0x800705B4

08:19:04 error: 0x800705B4

08:19:07 error: 0x800705B4

08:19:10 error: 0x800705B4

08:19:13 error: 0x800705B4

08:19:16 error: 0x800705B4

08:19:19 error: 0x800705B4

Vale mencionar que o código hexadecimal 0x800705B4 é equivalente a ERROR_TIMEOUT.

 

Com mais conversa, estávamos então cientes de que a rede não era estável, visto que foi mencionado que o PDCe encontra-se localizado em uma área rural.

 

De volta à análise, verificamos que não havia qualquer tráfego SNTP. Não para os NTPs configurados pelo menos. Era possível visualizar máquinas do domínio solicitando notificações de horário do servidor e o próprio servidor as respondendo, entretanto, quando falando da sincronização do horário do próprio PDCe, nenhum tráfego.

 

Uma nota importante: se a sincronização de horário fosse forçada utilizando ou o w32tm /resync ou o w32tm /resync /force, o horário do servidor seria sincronizado e voltaria ao normal, entretanto, apenas por alguns minutos ou possivelmente algumas horas.

 

Antes de continuarmos, vamos manter em mente que os NTPs aqui configurados são os NTPs do ntp.br. Mais especificamente, três servidores NTP foram configurados:

a.st1.ntp.br [200.160.7.186]

b.st1.ntp.br [201.49.148.135]

c.st1.ntp.br [200.186.125.195]

 

Retornando aos logs de depuração, encontramos o seguinte:

 

152056 01:26:06.1412895s - PeerPollingThread: WaitTimeout

152056 01:26:06.1412895s - PeerPollingThread: waiting 0.008s

152056 01:26:06.1492895s - PeerPollingThread: WaitTimeout

152056 01:26:06.1492895s - Polling peer b.st1.ntp.br,0x9 (ntp.m|0x9|0.0.0.0:123->201.49.148.135:123)

152056 01:26:06.1492895s - Sending packet to b.st1.ntp.br,0x9 (ntp.m|0x9|0.0.0.0:123->201.49.148.135:123) in Win2K detect mode, stage 1.

152056 01:26:06.1492895s - PollIntervalChange(b.st1.ntp.br,0x9 (ntp.m|0x9|0.0.0.0:123->201.49.148.135:123)): adjust: (--) -> 4

152056 01:26:06.1492895s - No response from peer b.st1.ntp.br,0x9 (ntp.m|0x9|0.0.0.0:123->201.49.148.135:123).

152056 01:26:06.1492895s - 5 Age:5 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.4999996s Dst:16.4999996s
FDsp:08.0000000s

152056 01:26:06.1492895s - 4 Age:4 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.4999996s Dst:16.4999996s
FDsp:12.0000000s

152056 01:26:06.1492895s - 3 Age:3 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.4999996s Dst:16.4999996s
FDsp:14.0000000s

152056 01:26:06.1492895s - 2 Age:2 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.4999996s Dst:16.4999996s
FDsp:15.0000000s

152056 01:26:06.1492895s - 1 Age:0 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.3333332s Dst:16.3333332s
FDsp:15.5000000s

152056 01:26:06.1492895s - 0 Age:1 Ofs:+00.0000000s Dly:+00.0000000s RDly:+00.0000000s Dsp:16.0000000s RDsp:00.0000000s Pnt:00.1666664s Dst:16.1666664s
FDsp:15.7500000s

152056 01:26:06.1502895s - Logging information: NtpClient has not received response from server b.st1.ntp.br,0x9 (ntp.m|0x9|0.0.0.0:123->201.49.148.135:123).

152056 01:26:06.1502895s - Peer poll: Max:3600.0000000s (special) Cur:00.0000000s

152056 01:26:06.1502895s - PeerPollingThread: waiting 2699.998s

 

Este comportamento se repete a cada hora, mas por quê? Vamos verificar as configurações da chave NtpServer aqui:

 

HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\services\w32time\Parameters

Key

Type

String

NtpServer

REG_SZ

a.st1.ntp.br,0x9b.st1.btp.br,0x9 c.st1.ntp.br,0x9

 

Cada NTP configurado está utilizando as flags 0x9, que são uma soma de 0x1 e 0x8, flags de SpecialInterval e Client respectivamente. Podemos dizer que a flag de Client
é necessário. Embora o PDCe aja como um NTP Server interno no domínio, o mesmo sincronizará horário com um NTP externo como se fosse uma Client.

 

Agora, quando analisamos a flag de SpecialInterval mais a fundo, a mesma determina que o servidor sincronizará com seus peers, utilizando o valor da chave SpecialPollInterval como intervalo. O valor da chave mencionada, por padrão, é 3600, que representa o intervalo de sincronização em segundos, ou seja, o servidor tentaria
sincronizar seu horário com os servidores NTP configurados a cada uma hora.

 

Este intervalo em si não necesariamente quer dizer um problema, entretanto, quando trabalhamos com redes instáveis ou redes que sofram com problemas de alta latência ou jitter, este valor pode ajudar a causar um problema, visto que neste tipo de rede, o horário do Windows pode sofrer de picos (spikes). Estes picos por si só não
são um problema, entretanto, se um pico é mantido por muito tempo, o servidor passará a considerá-lo o horário correto.

 

A pergunta agora é, quanto tempo é demais?

 

O Windows Time Service é completamente pré configurado e os valores importantes para picos de horário são baseados nas chaves LargePhaseOffset e SpikeWatchPeriod. Os valores padrão para estas chaves são 50000000 (nano segundos) e 900 (segundos) respectivamente. O LargePhaseOffset determina o que é considerado um pico, ou seja, 5000000 nano segundos, ou, 0,05 segundos, o SpikeWatchPeriod determina por quanto tempo um pico é considerado pico antes de ser considerado o horário correto, ou seja, 900 segundos, ou, 15 minutos.

 

Assim, se o Horário do Windows sofre um pico de 0,05 segundos e este pico permanece por 15 minutos o Horário do Windows não mais consideraria esse hiorário como um pico e sim o horário correto. Quando voltamos a configuração deste ambiente, o Horário do Windows está configurado para tentar sincronizar a cada uma hora, logo, existem 4 oportunidades de um pico acontecer e acabar sendo considerado o horário correto.

 

Existem alguns métodos possíveis de evitar este problema: aumentar o valor do SpikeWatchPeriod para uma hora. Aumentar o valor do LargePhaseOffSet, entretanto não seria muito sábido para redes instáveis ou, ainda, remover a flag de SpecialInterval (0x1).

 

Sem a flag de SpecialInterval, o Horário do Windows tentará sincronizar baseado nos valores das chaves MinPollInterval e MaxPollInterval. Os valores padrão para estas chaves são 6 e 10, respetivamente, e representam o intervalo em segundos log(2) .
O intervalo real pode ser calculado usando a equação log(2) = 2n e o resultado seria o intervalo em segundos. Portanto, o horário seria sincronizado entre um mínimo de 64 segundos (log(2) = 26) e um máximo de 1024 segundos (log(2) = 210), ou, aproxuidamente entre 1 e 17 minutos.

 

Esta configuração diminuiria a probabilidade de um pico ser mantido "ativo" por tempo suficiente para ser considerado o horário correto pelo serviço de Horário do Windows, visto que o serviço em questão tende a tentar sincronizar o horário com maior frequência.

 

Para verificar se o horário está sofrendo um pico, basta utilizar o comando w32tm /query /status /verbose:

 

Leap Indicator: 3(last minute has 61 seconds)

Stratum: 0 (unspecified)

Precision: -6 (15.625ms per tick)

Root Delay: 0.3761841s

Root Dispersion: 50.2604864s

ReferenceId: 0x00000000 (unspecified)

Last Successful Sync Time: 02/05/2017 16:40:10

Source: time.windows.com,0x9

Poll Interval: 6 (64s)

 

Phase Offset: 0.0000000s

ClockRate: 0.0156213s

State Machine: 0 (Unset)

Time Source Flags: 0 (None)

Server Role: 0 (None)

Last Sync Error: 1 (The computer did not resync because no time data was available.)

Time since Last Good Sync Time: 76589.2080416s

 

O campo de state retorna o valor 3 quando um pico é detectado. Todos os valores possíveis podem ser encontrados aqui.

 

Também possuimos o seguinte KB que discute esta situação: https://support.microsoft.com/pt-br/help/2638243/when-specialpollinterval-is-used-as-a-polling-interval,-the-windows-time-service-does-not-correct-the-time-if-the-service-gets-into-spike-state

 

Para um melhor entendimento de NTP, recomendo a leitura do documento NTP-TR9733, assim como o artigo de configurações avançadas do serviço de Horário do Windows.

Comments

  • Anonymous
    May 10, 2017
    Muito bom esse artigo. Típico de quem sabe.
  • Anonymous
    May 10, 2017
    Muito bom mesmo!!