Alguém mais experimentando altas taxas de falhas no servidor Linux durante um segundo dia de salto?

* NOTA: se o seu servidor ainda tiver problemas devido a kernels confusos e você não puder reiniciar - a solução mais simples proposta com o gnu date instalado no seu sistema é: date -s now. Isso redefinirá a variável interna "time_was_set" do kernel e corrigirá os loops futex da CPU em java e outras ferramentas de espaço do usuário. Eu tracei esse comando no meu próprio sistema e confirmei que está fazendo o que diz na lata *

POSTMORTEM

Anticlimax: a única coisa que morreu foi o link da minha VPN (openvpn) para o cluster, então houve alguns segundos emocionantes enquanto ele foi restabelecido. Tudo o resto estava bem, e a inicialização do ntp foi limpa após o segundo salto ter passado.

Eu escrevi minha experiência completa do dia em http://blog.fastmail.fm/2012/07/03/a-story-of-leaping-seconds/

Se você consultar o blog de Marco em http://my.opera.com/marcomarongiu/blog/2012/06/01/an-humble-attempt-to-work-around-the-leap-second - ele tem uma solução para faseando a mudança de horário em 24 horas usando ntpd -x para evitar o segundo salto. Este é um método de mancha alternativo para executar sua própria infraestrutura de NTP.

Ainda hoje, sábado, 30 de junho de 2012 - começando logo após o início do dia GMT. Tivemos um punhado de servidores em diferentes datacenters, gerenciados por equipes diferentes, todos ficam escuros - sem responder a pings, a tela em branco.

Todos eles estão executando o Debian Squeeze - com tudo, desde o kernel do estoque até as versões 3.2.21 personalizadas. A maioria são lâminas Dell M610, mas também perdi um Dell R510 e outros departamentos também perderam máquinas de outros fornecedores. Havia também um IBM x3550 mais antigo que travava e que eu pensava não estar relacionado, mas agora estou pensando.

A única falha na qual recebi um despejo de tela disse:

[3161000.864001] BUG: spinlock lockup on CPU#1, ntpd/3358
[3161000.864001]  lock: ffff88083fc0d740, .magic: dead4ead, .owner: imapd/24737, .owner_cpu: 0

Infelizmente, todas as lâminas supostamente tinham o kdump configurado, mas morreram tanto que o kdump não foi acionado - e tiveram o apagamento do console ativado. Desativei o apagamento do console agora, portanto, cruzei os dedos para obter mais informações após a próxima falha.

Só quero saber se é um tópico comum ou "apenas nós". É realmente estranho que sejam unidades diferentes em diferentes datacenters comprados em momentos diferentes e executados por diferentes administradores (eu executo os do FastMail.FM) ... e agora até hardware de fornecedor diferente. A maioria das máquinas que travavam estavam em funcionamento há semanas / meses e estavam executando os kernels da série 3.1 ou 3.2.

O acidente mais recente foi uma máquina que estava em funcionamento apenas cerca de 6 horas executando o 3.2.21.

A SOLUÇÃO

Ok pessoal, aqui está como eu trabalhei em torno disso.

1. ntp desativado: /etc/init.d/ntp stop
2. criado http://linux.brong.fastmail.fm/2012-06-30/fixtime.pl (código roubado de Marco, veja as postagens nos comentários)
3. correu fixtime.plsem argumento para ver que havia um segundo salto
4. correu fixtime.plcom um argumento para remover o segundo salto

NOTA: depende adjtimex. Coloquei uma cópia do squeeze adjtimexbinário em http://linux.brong.fastmail.fm/2012-06-30/adjtimex - ele será executado sem dependências em um sistema squeeze de 64 bits. Se você colocá-lo no mesmo diretório que fixtime.pl, ele será usado se o sistema não estiver presente. Obviamente, se você não tiver um aperto de 64 bits ... encontre o seu.

Eu vou começar de ntpnovo amanhã.

Como sugeriu um usuário anônimo - uma alternativa à execução adjtimexé definir o horário, o que provavelmente também limpará o contador de segundos.

Isso é causado por um livelock quando o ntpd chama adjtimex (2) para dizer ao kernel para inserir um segundo de salto. Consulte a publicação do lkml http://lkml.indiana.edu/hypermail/linux/kernel/1203.1/04598.html

A Red Hat também deve estar atualizando seu artigo da base de conhecimento. https://access.redhat.com/knowledge/articles/15145

ATUALIZAÇÃO: A Red Hat tem um segundo artigo da KB apenas para este problema aqui: https://access.redhat.com/knowledge/solutions/154713 - o artigo anterior é para um problema anterior, não relacionado

A solução alternativa é desativar o ntpd. Se o ntpd já emitiu a chamada adjtimex (2), pode ser necessário desativar o ntpd e reiniciar para ser 100% seguro.

Isso afeta o RHEL 6 e outras distros que executam kernels mais recentes (mais recentes que aproximadamente 2.6.26), mas não o RHEL 5.

A razão pela qual isso ocorre antes do segundo salto realmente está agendado para ocorrer é que o ntpd permite que o kernel lide com o segundo salto à meia-noite, mas precisa alertar o kernel para inserir o segundo salto antes da meia-noite. Portanto, o ntpd chama adjtimex (2) em algum momento do dia do segundo bissexto, momento em que esse bug é acionado.

Se você tiver o adjtimex (8) instalado, poderá usar este script para determinar se o sinalizador 16 está definido. O sinalizador 16 é "inserindo o segundo bissexto":

adjtimex -p | perl -p -e 'undef $_, next unless m/status: (\d+)/; (16 & $1) && print "leap second flag is set:\n"'

ATUALIZAR:

A Red Hat atualizou seu artigo da KB para observar: "Os clientes do RHEL 6 podem ser afetados por um problema conhecido que faz com que o NMI Watchdog detecte um travamento ao receber o anúncio de NTP em um segundo. Este problema está sendo tratado em tempo hábil. Se os seus sistemas receberam o anúncio de um segundo e não tiver esse problema, eles não serão mais afetados ".

ATUALIZAÇÃO: O idioma acima foi removido do artigo da Red Hat; e uma segunda solução de KB foi adicionada detalhando o problema de falha do adjtimex (2): https://access.redhat.com/knowledge/solutions/154713

No entanto, a alteração de código na postagem LKML do engenheiro John Stultz da IBM observa que também pode haver um impasse quando o segundo de salto é realmente aplicado; portanto, convém desativar o salto segundo, reinicializando ou usando adjtimex (8) após desativar o ntpd.

ATUALIZAÇÃO FINAL:

Bem, eu não sou desenvolvedor de kernel, mas revi o patch de John Stultz aqui: https://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h = 6b43ae8a619d17c4935c3320d2ef9e92bdeed05d

Se eu estiver lendo certo desta vez, eu estava errado sobre haver outro impasse quando o segundo de salto é aplicado. Essa parece ser a opinião da Red Hat também, com base na entrada da KB. No entanto, se você desativou o ntpd, mantenha-o desativado por mais 10 minutos, para não atingir o impasse quando o ntpd chamar adjtimex (2).

Descobriremos se há mais erros em breve :)

SEGUNDA ATUALIZAÇÃO PÓS-SALTO:

Passei as últimas horas lendo o código do kernel ntpd e pré-patch (buggy) e, embora eu esteja muito errado aqui, tentarei explicar o que acho que estava acontecendo:

Primeiro, o ntpd chama adjtimex (2) o tempo todo. Ele faz isso como parte de seu "filtro de loop de relógio", definido no local_clock em ntp_loopfilter.c. Você pode ver esse código aqui: http://www.opensource.apple.com/source/ntp/ntp-70/ntpd/ntp_loopfilter.c (da versão 4.2.6 da ntp).

O filtro de loop de relógio é executado com bastante frequência - ele é executado sempre que o ntpd consulta seus servidores upstream, que por padrão é a cada 17 minutos ou mais. O bit relevante do filtro de loop de relógio é:

if (sys_leap == LEAP_ADDSECOND)
    ntv.status |= STA_INS;

E depois:

ntp_adjtime(&ntv)

Em outras palavras, nos dias em que há um segundo, o ntpd define o sinalizador "STA_INS" e chama adjtimex (2) (por meio de seu invólucro de portabilidade).

Essa chamada de sistema faz o seu caminho para o kernel. Aqui está o código do kernel relevante: https://github.com/mirrors/linux/blob/a078c6d0e6288fad6d83fb6d5edd91ddb7b6ab33/kernel/time/ntp.c

O caminho do código do kernel é aproximadamente este:

• linha 663 - início da rotina do_adjtimex.
• linha 691 - cancela qualquer temporizador de segundos bissextos existente.
• linha 709 - pegue o spinlock ntp_lock (esse bloqueio está envolvido na possível falha do livelock)
• linha 724 - chame process_adjtimex_modes.
• linha 616 - chame process_adj_status.
• linha 590 - defina a variável global time_status, com base nos sinalizadores definidos na chamada adjtimex (2)
• linha 592 - verifique a variável global time_state. na maioria dos casos, chame ntp_start_leap_timer.
• linha 554 - verifique a variável global time_status. STA_INS será definido; portanto, defina time_state como TIME_INS e chame hrtimer_start (outra função do kernel) para iniciar o temporizador do segundo salto. no processo de criação de um timer, esse código captura o xtime_lock. se isso acontecer enquanto outra CPU já tiver capturado o xtime_lock e o ntp_lock, os livelocks do kernel. foi por isso que John Stultz escreveu o patch para evitar o uso de hrtimers. Isso é o que estava causando problemas a todos hoje.
• linha 598 - se o ntp_start_leap_timer não tiver realmente iniciado um temporizador, defina time_state como TIME_OK
• linha 751 - assumindo que o kernel não livelock, a pilha é desenrolada e o spinlock ntp_lock é liberado.

Há algumas coisas interessantes aqui.

Primeiro, a linha 691 cancela o cronômetro existente toda vez que o adjtimex (2) é chamado. Então, 554 recria esse timer. Isso significa que cada vez que o ntpd executava seu filtro de loop de relógio, o código de buggy era chamado.

Portanto, acredito que a Red Hat estava errada quando disseram que uma vez que o ntpd definisse a bandeira do segundo salto, o sistema não falharia. Acredito que cada sistema executando o ntpd tinha o potencial de bloquear a cada 17 minutos (ou mais) pelo período de 24 horas antes do segundo de salto. Eu acredito que isso também pode explicar por que tantos sistemas falharam; uma chance única de cair teria muito menos probabilidade de atingir do que três chances por hora.

ATUALIZAÇÃO: Na solução de KB da Red Hat em https://access.redhat.com/knowledge/solutions/154713 , os engenheiros da Red Hat chegaram à mesma conclusão (que a execução do ntpd atingia continuamente o código do buggy). E de fato o fizeram várias horas antes de mim. Esta solução não estava vinculada ao artigo principal em https://access.redhat.com/knowledge/articles/15145 , então eu não percebi até agora.

Segundo, isso explica por que os sistemas carregados eram mais propensos a travar. Os sistemas carregados manipularão mais interrupções, fazendo com que a função do kernel "do_tick" seja chamada com mais frequência, dando mais chances de esse código ser executado e capturar o ntp_lock enquanto o timer estava sendo criado.

Terceiro, há uma chance do sistema travar quando o segundo de salto realmente ocorre? Não sei ao certo, mas possivelmente sim, porque o timer que dispara e realmente executa o ajuste de segundos bissextos (ntp_leap_second, na linha 388) também pega o spinlock ntp_lock e tem uma chamada para hrtimer_add_expires_ns. Não sei se essa ligação também pode causar um bloqueio, mas não parece impossível.

Por fim, o que causa a desativação do sinalizador de segundo após o segundo ter sido executado? A resposta é ntpd para de definir o sinalizador de segundos bissextos em algum momento após a meia-noite quando chama adjtimex (2). Como o sinalizador não está definido, a verificação na linha 554 não será verdadeira e nenhum timer será criado, e a linha 598 redefinirá a variável global time_state para TIME_OK. Isso explica por que, se você verificasse a sinalização com adjtimex (8) logo após o segundo de salto, ainda veria o sinalizador de segundo de salto definido.

Em suma, o melhor conselho para hoje parece ser o primeiro que eu dei, afinal: desabilite o ntpd e desative o sinalizador de segundos bissextos.

E algumas considerações finais:

• nenhum dos fornecedores de Linux notou o patch de John Stultz e o aplicou em seus kernels :(
• por que John Stultz não alertou alguns dos fornecedores que isso era necessário? talvez a chance de o livelock parecesse baixa o suficiente, fazendo barulho não fosse justificado.
• Ouvi relatos de processos Java travando ou girando quando o segundo foi aplicado. Talvez devamos seguir o exemplo do Google e repensar como aplicamos segundos bissextos em nossos sistemas: http://googleblog.blogspot.com/2011/09/time-technology-and-leaping-seconds.html

06/02 Atualização de John Stultz:

https://lkml.org/lkml/2012/7/1/203

A postagem continha uma explicação passo a passo de por que o segundo salto fez com que os temporizadores do futex expirassem prematuramente e continuamente, aumentando a carga da CPU.

Isso nos atingiu com força. Depois de reiniciar muitos de nossos hosts, o seguinte se mostrou embaraçosamente simples e totalmente eficaz sem a reinicialização do host:

/etc/init.d/ntp stop
ntpdate 0.us.pool.ntp.org
/etc/init.d/ntp start

Tudo o que é necessário é redefinir o relógio do sistema. Sheesh. O que eu dou para saber isso seis horas atrás.

Um programa C simples que limpa o segundo bit de salto no campo de status de hora do kernel:

#include <sys/timex.h>
#include <string.h>
#include <stdio.h>

int main(int argc, char **argv) {
    struct timex txc;
    int ret;

    (void) argc;
    (void) argv;

    bzero(&txc, sizeof(txc));
    txc.modes = 0;  /* fetch */
    ret = adjtimex(&txc);
    if (ret < 0) {
        perror("adjtimex (get)");
        return 1;
    }

    txc.modes = ADJ_STATUS;
    txc.status &= ~16;
    ret = adjtimex(&txc);
    if (ret < 0) {
        perror("adjtimex (set)");
        return 1;
    }

    return 0;
}

Salvar como lsec.c, compilar gcc -Wall -Wextra -o lsec lsec.ce executar como root.

Você provavelmente desejará parar o ntpd antes de executá-lo e reiniciar o ntpd após o segundo.

Postmortem parece ./lsec não tem efeito.

O que estamos vendo são muitos processos softirqd que consomem CPU (geralmente lineares à carga dos processos java)

O que funciona para corrigir o POSTMORTEM com segundos bissextos já aplicados pelo ntp é o seguinte:

Parece ser suficiente apenas emitir:

export LANG="en_EN"; date -s "`date`"

Isso deve reduzir a carga sem a reinicialização ou reinicialização do ntpd. Como alternativa, você pode emitir:

apt-get install ntpdate
/etc/init.d/ntpd stop; ntpdate pool.ntp.org; /etc/init.d/ntpd start

http://my.opera.com/marcomarongiu/blog/2012/03/12/no-step-back parece indicar que o kernel squeeze do Debian não lidará com o segundo salto.

Este tópico sobre comp.protocols.tim.ntp também é interessante: https://groups.google.com/forum/?fromgroups#!topic/comp.protocols.time.ntp/KSflIgjUdPE

Dito isto, o segundo salto ainda não aconteceu: 23:59:60 UTC

Por fim, https://access.redhat.com/knowledge/articles/15145 tem o seguinte a dizer: "Quando o segundo ocorre, o kernel imprime uma mensagem no log do sistema. Há uma chance de que a impressão dessa mensagem pode causar a falha do kernel no Red Hat Enterprise Linux ".