Originally written for Percona Blog in April, 2024 – MongoDB Log and the Message “RSM Not Processing Response”
Uma das tarefas mais comuns para os DBAs é verificar os logs; você pode trabalhar diretamente com o arquivo ou processá-lo usando outra ferramenta. De qualquer forma, verificar os logs regularmente continua sendo essencial.
Dentro desse contexto, algumas mensagens de log ocasionalmente começam a aparecer e, infelizmente, não há muita literatura sobre algumas delas. Isso acontece porque nem a comunidade nem a documentação oferecem explicações detalhadas.
Este artigo tem como objetivo explicar mais profundamente a mensagem “RSM not processing response” e fornecer uma base mais sólida para entendê-la.
Dividiremos este artigo em três seções:
- O que é essa mensagem?
- Por que isso acontece?
- Como corrigir?
Primeiramente, vamos dar uma olhada em uma instância típica do erro que estamos discutindo:
|
1 |
{"t":{"$date":"2024-03-05T08:33:41.685-03:00"},"s":"I", "c":"-", "id":4495400, "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"RSM not processing response","attr":{"error":{"code":0,"codeName":"OK"},"replicaSet":"rs0"}} |
Antes de entrarmos nas seções, vamos detalhar essa mensagem e explicar o que o mongo.log está tentando nos comunicar.
- Timestamp (t): Indica o momento em que a entrada de log foi registrada. O formato segue o padrão ISO 8601, incluindo data, hora e o fuso horário (ex.:
-03:00). - Severity (s): “I” representa o nível de severidade da entrada de log. “I” significa “Informational”, indicando que essa entrada é informativa, não sendo um erro ou aviso.
- Component (c): “-“ normalmente indica o componente do banco de dados que gerou a mensagem de log. Um traço (“-“) sugere que esta entrada de log não está associada a um componente específico do banco de dados.
- Identifier (id): 4495400 é um identificador único para esta entrada de log. Ele pode ser usado para referenciar essa mensagem específica na documentação ou ao buscar suporte.
- Context (ctx): “ReplicaSetMonitor-TaskExecutor” indica o nome da thread que gerou a mensagem de log. Neste caso, trata-se do executor de tarefas do Replica Set Monitor.
- Message (msg): “RSM not processing response” é a mensagem principal do log.
- Attributes (attr): error: Contém detalhes sobre qualquer erro que possa ter ocorrido.
O que é essa mensagem?
Conforme vimos na análise do log, essa mensagem está associada à thread ReplicaSetMonitor-TaskExecutor. O ReplicaSetMonitor (RSM) é um componente crítico do MongoDB, responsável por monitorar o status e a configuração do replica set. Quando o log exibe a mensagem “RSM not processing response”, isso sugere um problema na forma como o RSM está lidando ou reagindo às respostas recebidas durante suas atividades de monitoramento.
Conforme a documentação, os objetivos do ReplicaSetMonitor (RSM) incluem:
- Descoberta e monitoramento de nós: Os nós em uma topologia são descobertos e monitorados através do monitoramento do replica set.
- Atualização periódica da topologia local: O monitoramento do replica set envolve a atualização periódica da visão local das topologias que o cliente precisa atingir.
- Monitores específicos para cada replica set: O cliente possui um ReplicaSetMonitor para cada replica set que precisa atingir no cluster.
- Por exemplo: se um mongos precisa direcionar 2 shards para uma consulta, ele terá ou criará um ReplicaSetMonitor para cada um dos shards correspondentes.
Esse monitoramento e descoberta são realizados através da operação isMaster/hello.
O que está acontecendo aqui é que o nó recebeu uma resposta dessa operação isMaster/hello, mas está em um estado de desligamento (shutdown). Assim, ele não pode processar a resposta.
Também é importante mencionar que o MongoDB usa dois métodos para esse processo de rastreamento: “sdam” (Server Discovery and Monitoring) e o método “streamable”.
- O “SDAM” ajuda o MongoDB a determinar a estrutura e o status de seus bancos de dados, como quem é o primário e quem está fazendo backup.
- O método “streamable” é preferido por sua eficiência em monitorar mudanças na configuração do banco de dados. Ele detecta muito mais rapidamente eventos como rebaixamentos (stepdowns), eleições, reconfigurações, entre outros.
Esse método mantém conexões atualizadas com cada banco de dados no conjunto de maneira inteligente, sem sobrecarregar o sistema, aprimorando a eficácia do RSM.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 |
StatusWith<TaskExecutor::CallbackHandle> SingleServerDiscoveryMonitor::_scheduleStreamableHello() { auto maxAwaitTimeMS = durationCount<Milliseconds>(kMaxAwaitTime); overrideMaxAwaitTimeMS.execute([&](const BSONObj& data) { maxAwaitTimeMS = durationCount<Milliseconds>(Milliseconds(data["maxAwaitTimeMS"].numberInt())); }); BSONObjBuilder bob; bob.append("hello", 1); bob.append("maxAwaitTimeMS", maxAwaitTimeMS); bob.append("topologyVersion", _topologyVersion->toBSON()); WireSpec::getWireSpec(getGlobalServiceContext()).appendInternalClientWireVersionIfNeeded(&bob); const auto timeoutMS = _connectTimeout + kMaxAwaitTime; auto request = executor::RemoteCommandRequest( HostAndPort(_host), DatabaseName::kAdmin, bob.obj(), nullptr, timeoutMS); request.sslMode = _setUri.getSSLMode(); auto swCbHandle = _executor->scheduleExhaustRemoteCommand( request, [self = shared_from_this(), helloStats = _stats->collectHelloStats()]( const executor::TaskExecutor::RemoteCommandCallbackArgs& result) mutable { Milliseconds nextRefreshPeriod; { stdx::lock_guard lk(self->_mutex); if (self->_isShutdown) { self->_helloOutstanding = false; LOGV2_DEBUG(4495400, kLogLevel, "RSM not processing response", "error"_attr = result.response.status, "replicaSet"_attr = self->_setUri.getSetName()); return; } |
E também:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 |
StatusWith<TaskExecutor::CallbackHandle> SingleServerDiscoveryMonitor::_scheduleSingleHello() { BSONObjBuilder bob; bob.append("hello", 1); WireSpec::getWireSpec(getGlobalServiceContext()).appendInternalClientWireVersionIfNeeded(&bob); auto request = executor::RemoteCommandRequest( HostAndPort(_host), DatabaseName::kAdmin, bob.obj(), nullptr, _connectTimeout); request.sslMode = _setUri.getSSLMode(); auto swCbHandle = _executor->scheduleRemoteCommand( request, [self = shared_from_this(), helloStats = _stats->collectHelloStats()]( const executor::TaskExecutor::RemoteCommandCallbackArgs& result) mutable { Milliseconds nextRefreshPeriod; { stdx::lock_guard lk(self->_mutex); self->_helloOutstanding = false; if (self->_isShutdown) { LOGV2_DEBUG(4333219, kLogLevel, "RSM not processing response", "error"_attr = result.response.status, "replicaSet"_attr = self->_setUri.getSetName()); return; } |
Nas duas funções responsáveis pelo ReplicaSet Monitor:
SingleServerDiscoveryMonitor::_scheduleStreamableHello()SingleServerDiscoveryMonitor::_scheduleSingleHello()
Há a condição if (self->_isShutdown). Quando essa condição é verdadeira, indicando que o ReplicaSetMonitor (RSM) está em estado de desligamento (shutdown), ela aciona uma entrada de log com a mensagem ‘RSM not processing response’.
O log inclui atributos como o status do erro e o nome do replica set. Quando em estado de shutdown, o RSM para de processar respostas, o que é refletido nos logs.
Por que isso acontece?
Em uma configuração padrão de replicação, o ReplicaSetMonitor (RSM) deve operar continuamente, monitorando o status dos nós em um replica set.
Na camada administrativa, não temos controle sobre esse processo, pois ele é iniciado e encerrado automaticamente. Por exemplo, durante o desligamento do banco de dados, você provavelmente verá essa mensagem, já que o processo do banco está realizando a limpeza antes de encerrar. No entanto, o MongoDB controla todos os processos internamente.
Outra condição que pode levar o processo ao estado de shutdown é uma mudança na configuração do Replica Set. Isso ocorre porque, se houver alterações significativas no replica set ou nos parâmetros de conexão, o RSM pode ser desligado para aplicar essas atualizações.
Para compreender melhor, você pode rastrear a sequência de eventos do ReplicaSetMonitor nos logs. No entanto, além do desligamento do nó, o log não fornece muitos detalhes sobre o motivo pelo qual a tarefa do RSM entrou em estado de shutdown.
Como corrigir?
É importante mencionar que, embora a mensagem não seja exibida como um ERRO ou AVISO, ter o RSM em estado de shutdown durante a operação normal não é bom para o cluster, principalmente devido à sua função principal, que é monitorar o estado do replica set.
Com o RSM inoperante, alguns problemas podem surgir:
- Atrasos ou informações incorretas sobre a topologia:
O RSM é responsável por rastrear o status e a configuração dos nós no replica set. Se o RSM estiver inativo, o cliente pode não estar ciente de mudanças na topologia, como qual nó é o primário ou o estado dos nós secundários. - Impacto em operações de leitura e escrita:
Os clientes do MongoDB usam o RSM para direcionar operações de leitura e escrita com base no estado atual do replica set e nas preferências de leitura/escrita especificadas. Sem um RSM operacional, essas operações podem falhar ou ser menos eficientes, resultando em degradação do desempenho ou inconsistência no acesso aos dados. - Manuseio ineficaz de failover:
Em caso de falha do nó primário, o RSM ajuda a identificar um novo nó primário. Se o RSM não estiver funcionando, os processos de failover podem ser atrasados ou não ocorrer corretamente, afetando a disponibilidade e a resiliência do banco de dados. - Alta disponibilidade e tolerância a falhas comprometidas:
Um dos principais benefícios do uso de um replica set é a alta disponibilidade e tolerância a falhas. Com o RSM inativo, essas funcionalidades são comprometidas, pois o sistema pode não responder adequadamente a falhas de nós ou partições de rede.
Como mencionado anteriormente, não temos controle sobre a thread em si. Se você estiver sendo inundado por essas mensagens, a melhor ação que pode tomar é reiniciar o processo do banco de dados:
|
1 |
sudo systemctl restart mongodb |
Embora seja uma solução um pouco drástica, um stop-and-start limpo é, atualmente, a única maneira de restaurar a saúde dos processos.
Conclusão:
Neste artigo, exploramos a mensagem ‘RSM not processing response’ no MongoDB, um indicador crítico do estado de shutdown do ReplicaSetMonitor. Entender essa mensagem ajuda a manter a saúde e o desempenho do sistema de replicação do MongoDB, com a reinicialização do processo do banco como uma solução potencial para problemas que persistem.
