Uma lista de brokers velha que dava 504

O sintoma

Em 22 de setembro uma tela do sistema financeiro começou a responder 504. O gateway na frente da aplicação desiste depois de alguns segundos, então o usuário via uma página de erro genérica, e o log da aplicação tinha uma linha para cada tentativa:

ERROR: Local: Timed out

"Local" é a palavra importante. Na librdkafka, os erros que começam com Local: são produzidos pelo próprio cliente, antes de qualquer broker dizer alguma coisa. O cliente estava esperando algo e ninguém respondia.

A causa

A config de produção do serviço tinha a lista de brokers fixa no código, assim (aqui com nomes de host, o arquivo real tinha IPs):

defined('KAFKA_BROKER_PRODUCER') || define('KAFKA_BROKER_PRODUCER', ["kafka-old-1:9092", "kafka-old-2:9092"]);

Essa lista veio do primeiro commit do projeto. Em maio a empresa passou para um cluster novo com três brokers, e os serviços foram reapontados um a um; este ficou com a lista antiga, e os brokers antigos tinham ficado inalcançáveis. A correção foi uma linha, a mesma lista que os outros serviços já usavam em produção:

defined('KAFKA_BROKER_PRODUCER') || define('KAFKA_BROKER_PRODUCER', ["kafka-1:9092", "kafka-2:9092", "kafka-3:9092"]);

Por que nada reclamou na inicialização

A biblioteca tinha uma checagem que parecia certa:

$ok = $producer->addBrokers(implode(",", $brokers));
if ($ok == 0)
    throw new KafkaException("Could not connect to any broker");

O addBrokers() devolve quantos brokers foram adicionados à lista do cliente. Ele interpreta a string e retorna. A conexão acontece depois, em segundo plano, então com dois brokers mortos ele devolve 2 e a exceção nunca dispara.

Depois, cada envio fazia um poll(3000) e um flush(3000) com até três tentativas. Sem nenhum broker vivo, isso dá uns 12 segundos até o erro, para uma mensagem. Some um segundo envio, ou o flush que roda de novo no destrutor, e a requisição passa do timeout do gateway. O usuário vê um 504, e o erro de verdade fica num log que ninguém estava lendo.

Fazer falhar em um segundo

Se você quer saber na inicialização que um broker responde, peça metadados. O getMetadata() precisa de um broker de verdade e lança exceção quando o timeout passa:

try {
    $producer->getMetadata(false, null, 1000);   // 1 s, sem lista de tópicos
} catch (\RdKafka\Exception $e) {
    throw new KafkaException("No Kafka broker answered: " . $e->getMessage());
}

Rodar isso em toda requisição é exagero; um health check com cache basta. E para qualquer coisa que o usuário espera, deixe o flush curto e devolva um erro claro, ou grave a mensagem numa tabela de outbox e mande fora da requisição. Assim um Kafka lento vira uma mensagem atrasada, e a tela continua funcionando.

O que ficou

• Lista de brokers por serviço, copiada à mão, envelhece. Um lugar só (variável de ambiente vinda da mesma fonte, ou um nome de DNS por broker) muda junto com o cluster.
• O addBrokers() conta strings. Quem prova a conexão é um pedido de metadados.
• Local: Timed out quer dizer que o cliente nunca teve resposta. Olhe a rede e a config antes do broker.
• Um produce síncrono dentro de uma requisição HTTP transforma qualquer problema do Kafka em problema do gateway, com uma mensagem pior.

Arquivado pelo problema que resolve

• kafka
• librdkafka
• php-rdkafka
• deriva de configuração
• timeouts
• confiabilidade