O que aconteceu com o Vivaldi Social?
(thomasp.vivaldi.net)- Em 8 de julho de 2023, contas antigas de usuários desapareceram na instância Mastodon do Vivaldi Social, e no fim ocorreu um incidente em que 198 contas foram mescladas em uma única conta remota
- A causa não foi exclusão manual nem ataque, mas um desencontro na ordem das operações entre o comportamento de mesclagem de contas do Mastodon e a configuração de replicação PostgreSQL baseada em Makara do Vivaldi Social
- As contas pareciam ter sido apagadas, mas os nomes de usuário foram atribuídos novamente e as imagens de avatar e cabeçalho também desapareceram, o que restringiu o problema ao funcionamento interno do aplicativo Mastodon
- Enquanto preparava um rollback completo do banco de dados, a equipe de operação também trabalhou em paralelo num script de recuperação seletiva para restaurar contas, posts, follows, followers e dados de relacionamento
- O Mastodon v4.1.5 inclui o bloqueio do uso de Makara por workers do Sidekiq e uma correção na ordem da mesclagem de contas; administradores de servidores que usam banco replicado devem revisar o caminho de leitura dos workers
O incidente do fim de semana em que 198 contas desapareceram
- No sábado, 8 de julho de 2023, por volta de 17:25 CEST, a aba do Vivaldi Social voltou a pedir login e, após entrar, foi confirmado que a timeline inicial estava vazia
- O mesmo sintoma apareceu em outras contas de administrador do sistema, e a verificação do banco de dados mostrou que as contas afetadas estavam sendo apagadas e depois recriadas como se fossem contas novas quando o usuário fazia login novamente
- O Vivaldi Social tinha um backup noturno de sexta-feira às 23:00 UTC, e a equipe de operação começou a copiar os arquivos de backup para verificar as possibilidades de recuperação
- Numa exclusão normal de conta no Mastodon, o nome de usuário fica reservado permanentemente e não pode ser reutilizado, mas neste incidente o mesmo nome foi atribuído novamente, então não se tratava de uma exclusão normal
A exclusão ainda estava em andamento
- No início, haviam desaparecido contas antigas com ID inferior a 142; às 19:10, até contas com ID inferior a 217 tinham sumido, revelando que a exclusão estava em andamento
- Às 19:18, foi pedido ajuda a desenvolvedores do Mastodon, e após a resposta de Renaud, Claire e Eugen também entraram na investigação
- Às 19:20, ao reiniciar as instâncias Docker do Mastodon, a exclusão parou, e o menor ID de conta no banco passou a ser 236
- Durante o incidente, o total de contas apagadas ou mescladas foi confirmado em 198
O foco se estreitou para o comportamento da aplicação, não um ataque
- A equipe de operação e os desenvolvedores do Mastodon verificaram se o
UserCleanupSchedulerpoderia ter apagado contas “unconfirmed”, mas os usuários removidos não se encaixavam nas condições dessa query, então a hipótese foi descartada - Como o upgrade para o Mastodon 4.1.3 havia sido feito 48 horas antes do incidente, foram revisadas as mudanças entre v4.1.2 e v4.1.3, além das alterações publicadas pela Vivaldi, mas nenhuma causa relacionada foi encontrada
- As imagens de avatar e cabeçalho das contas apagadas também haviam sumido do filesystem, confirmando que não foi uma simples exclusão direta no banco e sim uma ação de exclusão executada pelo aplicativo Mastodon
- Foram procurados indícios de intrusão ou ataque nos logs e no filesystem, mas não houve evidência; também não foi confirmada qualquer possibilidade de exploit ligada às correções de segurança do Mastodon v4.1.3
- Na noite de sábado, foi aplicado um patch para adicionar logs à ação de exclusão de contas e, após a versão corrigida ser implantada às 00:29 CEST, a equipe fez uma pausa
A pista decisiva: posts concentrados em uma conta remota
- No domingo, às 13:56, foi reportado que a página de perfil do especialista em segurança da Vivaldi, Yngve, retornava erro HTTP 500, e essa conta não estava entre as 198 contas apagadas
- Nos logs, a mesma conta da mesma instância remota do Mastodon aparecia repetidamente; no texto, ela é anonimizada como uma conta de
social.example.com - A query para consultar os status dessa conta remota retornou 17.600 linhas
- Às 14:43, a comparação com o backup confirmou que todos os status de todas as contas apagadas haviam sido reatribuídos a um único usuário de
social.example.com - Depois das 15:00, com logs do
AccountMergingWorker, console Rails e queries adicionais no banco, ganhou força a hipótese de que o worker de mesclagem de contas estava fundindo todas as contas em uma única conta remota
Causa raiz: mesclagem de contas e atraso na replicação do PostgreSQL
- O Vivaldi Social usava uma configuração de replicação com 2 servidores PostgreSQL, e os processos worker podiam fazer leituras do banco no servidor standby por meio do Makara
- O cenário do incidente apresentado por Claire às 17:28 foi o seguinte
- O Vivaldi Social recebe uma notificação de mudança de nome de conta vinda de
social.example.com - Quando a nova conta é criada no banco, o campo
URIentra comonull - Depois, o
URIda nova conta é definido com o valor correto da conta remota - Via Redis, é agendada a execução do
AccountMergingWorker, que mescla os dados da conta antiga na nova conta - Por causa do atraso de replicação do banco, a ordem entre a definição do
URIe o agendamento da execução do worker ficou invertida no momento real da leitura
- O Vivaldi Social recebe uma notificação de mudança de nome de conta vinda de
- Como todas as contas locais de uma instância Mastodon têm valor
URIigual anull, o worker acabou encontrando todas as contas locais com o mesmoURIe as mesclou na nova conta remota - Os desenvolvedores avaliaram que isso pode acontecer com mais facilidade quando a carga no banco aumenta e o atraso de replicação fica mais longo
- A equipe de operação e os desenvolvedores do Mastodon concluíram que essa configuração tinha altíssima probabilidade de ser a causa raiz
Patch e mudanças de configuração
- Depois que a causa foi delimitada, a equipe de operação passou a focar na recuperação dos dados, e Claire ficou responsável por escrever um patch para evitar recorrência
- Hlini assumiu a aplicação do patch e a mudança da configuração de replicação que já não era mais recomendada
- Às 17:58, houve um problema durante o deploy e ocorreu o único downtime total daquele fim de semana; às 18:18, o Vivaldi Social voltou ao ar
- Às 18:44, o patch e a mudança de configuração foram implantados com sucesso, e concluiu-se que o mesmo incidente não deveria se repetir
Recuperação: restauração seletiva em vez de rollback completo
- No início, foi considerado um rollback completo do banco de dados, mas, por problemas de desempenho já conhecidos, isso exigiria um procedimento complexo de converter o backup
.dumpem.sqle editar um arquivo de texto de 54 GB - A equipe tocou em paralelo o procedimento de restauração total e a recuperação seletiva
- Hlini editou o arquivo
.sqlde 54 GB e preparou a restauração completa - Thomas escreveu um script para restaurar as contas apagadas e seus dados relacionados
- Hlini editou o arquivo
- Durante a escrita do script, houve um erro ao tratar por referência o binding de parâmetros de query do PDO, e Ísak encontrou esse problema
- Às 23:04, ficou pronta a primeira parte para corrigir os registros de user, account e identity dos 198 usuários afetados
- Às 23:55, foi concluído o script de recuperação seletiva para restaurar status, follows, followers e outros dados de relacionamento ao estado anterior ao incidente
Conclusão da recuperação seletiva e correções posteriores
- Por causa das restrições de relacionamento no banco de dados, a recuperação foi feita em 2 etapas
- Primeiro, foram restaurados os registros de user/account/identity dos 198 usuários
- Depois, foi restaurado o restante dos dados de relacionamento
- Em alguns casos, usuários fizeram login de novo após o incidente e configuraram follows, o que gerou erros de chave duplicada; o script foi ajustado para apagar registros antigos irrecuperáveis e manter os registros mais novos
- À 01:27 CEST de segunda-feira, a última tarefa do script foi concluída e, às 01:40, a reindexação do feed inicial terminou
- Como resultado, os feeds iniciais das 198 contas foram restaurados e não foi necessário rollback completo
- Na segunda e na terça-feira, problemas adicionais foram corrigidos
- problema de login em 6 contas com símbolos no nome de usuário
- perda dos dados de configuração web das 198 contas
- erros em contadores de perfil, como número de seguidores e de posts
- 4 contas com dados incorretos
Correções oficiais do Mastodon
- Os desenvolvedores do Mastodon alertaram outros administradores de servidores sobre o risco de usar o Mastodon com configuração de replicação baseada em Makara
- Foi observado que esse tipo de configuração é raro e geralmente só seria considerado em instâncias grandes como o Vivaldi Social
- O Mastodon v4.1.5 inclui duas correções relacionadas a este incidente
Linha do tempo do incidente em UTC
- Sábado 15:15: uma mensagem de mudança de nome de conta vinda de uma instância externa chega ao Vivaldi Social, e começa a tarefa incorreta de mesclagem de contas
- Sábado 15:25: o primeiro sinal do incidente é observado
- Sábado 17:20: após reiniciar os contêineres Docker, a tarefa de mesclagem de contas para; entre 15:15 e 17:20, um total de 198 contas foi apagado/mesclado
- Domingo 13:00: uma possível causa raiz é identificada
- Domingo 14:25: a causa raiz é confirmada
- Domingo 21:55: a recuperação dos dados começa
- Domingo 23:27: a recuperação dos dados é concluída
- Segunda-feira 10:40: são corrigidas 6 contas com símbolos no nome de usuário
- Segunda-feira 11:05: os dados perdidos de configuração web são restaurados
- Terça-feira 15:31: valores incorretos de contadores são corrigidos
- Terça-feira 16:01: são corrigidas 4 contas com dados incorretos
1 comentários
Opiniões no Hacker News
Foi uma excelente retrospectiva, e capturou especialmente bem como custos humanos, como privação de sono, podem ter um grande impacto na resolução de incidentes complexos
A parte que mais chamou atenção foi: “novas contas foram criadas no banco de dados com valor null no campo URI”
Toda vez que leio uma análise pós-incidente envolvendo banco de dados, quase sempre há um NULL escondido perto da cena do acidente. Mesmo quando NULL não é o culpado, ele sempre deve ser levado para interrogatório
Como conselho, é melhor não depender de NULL como valor sentinela e, se possível, nem permitir isso no banco de dados. Mesmo que pareça haver vantagens, anos depois o significado do modelo de dados muda, e alguma instrução aparentemente inofensiva que esperava NULL ou NOT NULL acaba sendo compensada por um bug difícil de encontrar e com resultado inesperado
Neste caso foi uma condição de corrida, mas se contas locais e remotas tivessem sido claramente diferenciadas por tipo, a ordem das operações talvez não importasse, e o código de mesclagem de contas também poderia ter sido limitado a um escopo mais estreito
Null é um valor perfeitamente válido para dados e deve ser tratado assim. Valores padrão como usar -1 para booleanos ou uma string vazia para strings podem fazer um sistema que teria gerado erro em tempo de execução se fosse NULL parecer funcionar, mas isso não significa que o sistema esteja funcionando como esperado; ele só fica silencioso
Entendo a tentação de esconder NULL, mas “ausente” é um estado de dados tão válido quanto “presente”, e em geral os sistemas devem ser escritos para aceitá-lo
Neste caso, acho que o problema não é o NULL do banco de dados, mas o NULL da camada de aplicação
Se NULL fosse um valor que precisa ser tratado obrigatoriamente, como uma espécie de mônada Maybe, no fim ele seria tratado, e faria você pensar. Não há muita diferença se é uma string vazia, a string null da linguagem usada ou um valor marcador especial criado por você
Em muitos casos, quem implementa deveria primeiro pensar nas preocupações e exigências de interação que um conflito de merge ao estilo Git exige e, a partir desse ponto, estabelecer suposições simplificadoras adequadas ao domínio do problema
Olhando o código-fonte do Mastodon https://github.com/mastodon/mastodon/blob/main/app/workers/a..., nem parece haver uma lista explícita de “de quais IDs mesclar” passada por quem iniciou a solicitação de mesclagem para o executor assíncrono da mesclagem, então parece que era questão de tempo até algo assim acontecer
Isso não é uma crítica ao Mastodon. Eu mesmo escrevi lógica de mesclagem com condições de corrida muito piores e sofri as consequências. Na verdade, é surpreendente que um projeto voluntário como https://opencollective.com/mastodon tenha esse tipo de recurso. Ainda assim, é um caso para ficar atento
Mais profundamente, a realidade é bagunçada, e NULL é inevitável porque um banco de dados não pode se recusar a processar só porque a realidade é bagunçada. Por exemplo, imagine modelar formas de tratamento, títulos antes do nome e títulos depois do nome e querer criar uma saudação completa com esses dados; pelo menos algumas pessoas não terão título depois do nome. Mesmo que você não armazene NULL, obterá NULL no resultado do JOIN usado para criar a saudação
Você pode eliminar valores NULL específicos, mas não pode eliminar o fato de que, no mundo real, “não se aplica” ou “desconhecido” muitas vezes são valores válidos, e o banco de dados precisa lidar com isso
O fluxo que faz sentido aqui começa com “temos um backup completo do banco de dados, então basta fazer uma restauração completa”, passa para “uma restauração completa é difícil e tem downtime e efeitos colaterais”, volta para “dá para restaurar de forma inteligente só os dados que faltaram”, então isso é feito manualmente, surge um erro estranho, por fim é implantada uma restauração seletiva temporária, e finalmente os cinco últimos dados ausentes são limpos. Torcendo para que não tenham perdido um sexto
Sempre que alguém pratica backup/restauração, acaba indo nessa direção. No fim, decidir quais dados reverter a partir da imagem de backup é sempre algo que precisa ser feito no nível da aplicação
Mas neste caso não sei bem qual era o problema. Restaurar tudo a partir do último backup bom faria alguns posts publicados nesse intervalo desaparecerem, o que é uma pena, mas seria uma solução imediata em vez de trabalho manual e incerteza
Achei marcante a parte em que Renaud, Claire e Eugen, da equipe de desenvolvimento do Mastodon, ajudaram além do esperado
Não sei se a Vivaldi apoia financeiramente o Mastodon, e também não encontrei o nome na página de patrocinadores. Se não apoia, espero que este caso leve a Vivaldi ou outras empresas que usam Mastodon a considerar patrocínio ou contrato de suporte
Patrocínios estão abertos e realmente fazem grande diferença. É muito importante o projeto ter pessoas em tempo integral, mas atualmente, na área técnica, além do fundador Eugen, há apenas 1 desenvolvedor em tempo integral e 1 pessoa de DevOps
Foi uma das melhores análises pós-incidente que li em bastante tempo
O fato de os itens 2 e 3 não serem processados atomicamente parece um problema. Claro que deve haver algum motivo para não ser trivial fazer isso, mas ainda não vi o código e preciso ver algum dia
Parece que tornar isso atômico era trivial
Antes simplesmente não havia necessidade. Quer dizer, não ser atômico não causava problema, a menos que alguém fizesse uma configuração ruim conectando o sidekiq a um servidor de banco de dados desatualizado, ou seja, a uma réplica. Aqui, essa configuração parece ser o principal problema
Nunca vou esquecer a primeira vez que precisei restaurar um dump SQL enorme e vi o vim realmente dar erro de segmentação ao tentar lê-lo
Foi quando descobri a mágica do split(1), ou seja, dividir arquivos em partes. Separei o dump grande em um arquivo por tabela
Claro que uma única tabela também pode ser enorme, mas pelo menos os arquivos ficam mais uniformes, o que facilita transformar consultas com outras ferramentas como sed ou awk
Ainda assim, se você chega ao ponto de precisar editar um dump para restaurar os dados, há algo muito errado no procedimento de restauração. Claro que, quando você de fato está nessa situação, esse conhecimento não ajuda muito
A solução de contorno foi escrever um script em Python para processar tudo de forma incremental e mover os arquivos para subdiretórios com base em prefixos comuns
A parte “Claire pediu o stack trace completo da entrada de log, e também foi possível extraí-lo dos logs” me fez levantar a sobrancelha
Isso é algum vodu profundo, ou o código/configuração está transformando um Xeon em um 286. Não vira megabytes por requisição?
É o comportamento padrão do Ruby on Rails. Quando ocorre um 500 ou um erro desconhecido, ele imprime o stack trace, cujo conteúdo é basicamente números de linha e caminhos de arquivos
Opero uma aplicação Rails com um design bem ruim e acabei de verificar: o stack trace de um único 500 tinha 5 KiB. Como erros 500 acontecem só mais ou menos uma vez por hora, não dá nem 1 MiB por dia
Manter a pilha de chamadas por perto é, na prática, bastante aceitável em termos de desempenho. O comportamento padrão de exceções em Java também é carregar um stack trace junto com cada exceção, mesmo que você não o imprima, e ainda assim aplicações Java funcionam bem. De qualquer forma, é preciso saber como retornar, então a pilha de chamadas já existe; a única informação extra necessária são os símbolos de debug com nome de arquivo e número de linha. Em Ruby, pela natureza da linguagem, essa informação já é necessária de qualquer jeito
Como é possível que “todas as contas locais da instância Mastodon tivessem o campo URI com valor null, então todas correspondiam”?
NULL = NULL é avaliado como FALSE. SQL usa lógica de três valores, mais precisamente a lógica trivalorada fraca de Kleene, e aplicar qualquer operador a NULL resulta em NULL
Não sei como contas com valor NULL na coluna URI entraram na query. NULL não é comparado como igual a NULL. Isso é alguma magia terrível do Rails?
Ao ver o trecho dizendo que seis usuários com símbolos no nome de usuário não conseguiam fazer login e que isso foi corrigido facilmente porque era um erro no script de recuperação, fiquei com a sensação de que o UTF-8 aprontou mais uma vez