Qu’est-il arrivé à Vivaldi Social ?

• Le 8 juillet 2023, d’anciens comptes utilisateurs ont disparu de l’instance Mastodon de Vivaldi Social, et l’incident a finalement conduit à la fusion de 198 comptes vers un seul compte distant
• La cause n’était ni une suppression manuelle ni une attaque, mais un décalage dans l’ordre des opérations entre le comportement de fusion de comptes de Mastodon et la configuration de réplication PostgreSQL basée sur Makara utilisée par Vivaldi Social
• Les comptes semblaient avoir été supprimés, mais les noms d’utilisateur étaient réattribués et les images d’avatar et d’en-tête disparaissaient aussi, ce qui a permis de circonscrire le problème à un comportement interne de l’application Mastodon
• L’équipe d’exploitation a préparé un rollback complet de la base de données tout en développant en parallèle des scripts de restauration sélective pour rétablir les comptes, publications, abonnements, abonnés et données relationnelles
• Mastodon v4.1.5 inclut le blocage de l’usage de Makara par les workers Sidekiq ainsi qu’une correction de l’ordre de fusion des comptes ; les administrateurs de serveurs utilisant une base répliquée doivent vérifier le chemin de lecture des workers

---

Le week-end où 198 comptes ont disparu

• Le samedi 8 juillet 2023 vers 17:25 CEST, l’onglet Vivaldi Social a de nouveau demandé une connexion, et après authentification il a été constaté que la timeline d’accueil était vide
• Le même symptôme est apparu sur d’autres comptes d’administrateur système ; la vérification de la base de données a montré que les comptes affectés étaient supprimés puis recréés comme de nouveaux comptes quand l’utilisateur se reconnectait
• Vivaldi Social disposait d’une sauvegarde nocturne du vendredi à 23:00 UTC, et l’équipe a commencé à copier le fichier de sauvegarde afin de vérifier les possibilités de restauration
• Lors d’une suppression normale de compte Mastodon, le nom d’utilisateur reste réservé de façon permanente et ne peut pas être réutilisé, mais dans cet incident le même nom d’utilisateur était réattribué, ce qui montrait qu’il ne s’agissait pas d’une suppression normale

Les suppressions étaient toujours en cours

• Au départ, les anciens comptes avec un ID inférieur à 142 avaient disparu ; à 19:10, les comptes avec un ID inférieur à 217 avaient aussi disparu, révélant que la suppression était encore en cours
• À 19:18, l’équipe a demandé de l’aide aux développeurs de Mastodon ; Renaud a répondu, puis Claire et Eugen ont également participé à l’enquête
• À 19:20, après le redémarrage des instances Docker de Mastodon, les suppressions se sont arrêtées, et l’ID de compte le plus bas en base est devenu 236
• Sur toute la durée de l’incident, le nombre final de comptes supprimés ou fusionnés a été confirmé à 198

La piste s’est resserrée sur le comportement de l’application, pas sur une attaque

• L’équipe d’exploitation et les développeurs de Mastodon ont vérifié si UserCleanupScheduler avait pu supprimer des comptes “unconfirmed”, mais les utilisateurs supprimés ne pouvaient pas correspondre aux conditions de cette requête, ce qui a permis d’écarter cette hypothèse
• Comme Mastodon avait été mis à niveau vers la 4.1.3 48 heures avant l’incident, les changements entre v4.1.2 et v4.1.3, ainsi que les modifications publiées par Vivaldi, ont été examinés, sans qu’aucune cause liée ne soit trouvée
• Les avatars et images d’en-tête des comptes supprimés avaient également disparu du système de fichiers, confirmant qu’il ne s’agissait pas d’une simple suppression directe en base, mais bien d’une action de suppression exécutée par l’application Mastodon
• Les journaux et le système de fichiers ont été inspectés à la recherche de traces d’intrusion ou d’attaque, sans résultat, et aucune possibilité d’exploit liée aux correctifs de sécurité de Mastodon v4.1.3 n’a été confirmée
• Dans la nuit de samedi, un patch ajoutant des logs sur les opérations de suppression de compte a été déployé, et après la mise en production de cette version patchée à 00:29 CEST, l’équipe a pris un peu de repos

L’indice décisif : des publications concentrées sur un seul compte distant

• Le dimanche à 13:56, il a été signalé que la page de profil de l’expert sécurité Vivaldi Yngve renvoyait une erreur HTTP 500, alors que ce compte ne faisait pas partie des 198 comptes supprimés
• Dans les logs, le même compte d’une même instance Mastodon distante revenait sans cesse ; dans le texte, il est anonymisé comme étant un compte de social.example.com
• La requête interrogeant les statuts de ce compte distant a renvoyé 17 600 lignes
• À 14:43, une comparaison avec la sauvegarde a confirmé que tous les statuts de tous les comptes supprimés avaient été réattribués à un seul utilisateur de social.example.com
• Après 15:00, les logs de AccountMergingWorker, la console Rails et d’autres requêtes SQL ont fortement renforcé l’hypothèse selon laquelle le worker de fusion de comptes fusionnait tous les comptes vers un seul compte distant

Cause racine : fusion de comptes et latence de réplication PostgreSQL

• Vivaldi Social utilisait une configuration de réplication à 2 serveurs PostgreSQL, et les processus worker pouvaient effectuer des lectures de base de données sur le serveur standby via Makara
• Le scénario d’incident proposé par Claire à 17:28 était le suivant
  • Vivaldi Social reçoit depuis social.example.com une notification de changement de nom de compte
  • Lors de la création du nouveau compte dans la base, le champ URI est enregistré à null
  • Ensuite, l’URI du nouveau compte est définie avec la valeur correcte du compte distant
  • L’exécution de AccountMergingWorker, qui fusionne les données de l’ancien compte vers le nouveau, est planifiée via Redis
  • À cause de la latence de réplication de la base, l’ordre entre la définition de l’URI et la planification du worker s’est trouvé inversé au moment effectif de lecture
• Comme tous les comptes locaux d’une instance Mastodon ont une valeur URI à null, le worker a fusionné vers le nouveau compte distant tous les comptes ayant la même URI, ce qui a fait correspondre tous les comptes locaux
• Les développeurs estiment que ce type de problème peut se produire plus facilement quand la charge de la base augmente et allonge la latence de réplication
• L’équipe d’exploitation et les développeurs de Mastodon ont jugé très probable que cette configuration soit la cause racine

Patchs et changements de configuration

• Une fois la cause cernée, l’équipe d’exploitation s’est concentrée sur la restauration des données, tandis que Claire a pris en charge l’écriture d’un patch de prévention
• Hlini s’est occupé d’appliquer le patch et de modifier une configuration de réplication qui n’était plus recommandée
• Un problème est survenu pendant le déploiement à 17:58, provoquant la seule interruption complète de tout le week-end, puis Vivaldi Social est revenu en ligne à 18:18
• À 18:44, le patch et les changements de configuration avaient été déployés avec succès, et l’équipe a estimé que le même incident ne se reproduirait pas

Restauration : une remise en état sélective plutôt qu’un rollback complet

• Au départ, un rollback complet de la base de données a été envisagé, mais à cause de problèmes de performance connus, il aurait fallu suivre une procédure complexe consistant à convertir la sauvegarde .dump en .sql, puis à modifier un fichier texte de 54 Go
• L’équipe a mené en parallèle la procédure de restauration complète et la restauration sélective
  • Hlini a modifié le fichier .sql de 54 Go et préparé la restauration complète
  • Thomas a écrit un script pour restaurer les comptes supprimés et les données associées
• Pendant l’écriture du script, une erreur a été commise dans le traitement par référence du binding des paramètres de requête PDO, puis Ísak l’a repérée
• À 23:04, la première partie corrigeant les enregistrements user, account et identity des 198 utilisateurs affectés était terminée
• À 23:55, le script de restauration sélective restaurant les statuts, abonnements, abonnés et autres données relationnelles à l’état antérieur à l’incident était achevé

Fin de la restauration sélective et correctifs de suivi

• En raison des contraintes de relations dans la base de données, la restauration s’est déroulée en 2 étapes
  • d’abord, restauration des enregistrements user/account/identity des 198 personnes
  • ensuite, restauration du reste des données relationnelles
• Pour certains utilisateurs qui s’étaient reconnectés après l’incident et avaient recréé des abonnements, des erreurs de clé dupliquée sont apparues ; le script a été modifié pour supprimer les anciens enregistrements impossibles à restaurer et conserver les plus récents
• Le lundi à 01:27 CEST, la dernière opération du script s’est terminée, et à 01:40 la réindexation du flux d’accueil était achevée
• Au final, les flux d’accueil des 198 comptes ont été restaurés, et un rollback complet n’a plus été nécessaire
• D’autres problèmes de suivi ont été corrigés le lundi et le mardi
  • problème de connexion pour 6 comptes dont le nom d’utilisateur contenait des symboles
  • perte des données de configuration web des 198 comptes
  • erreurs dans les compteurs de profil comme le nombre d’abonnés ou de publications
  • 4 comptes contenant des données incorrectes

Correctifs officiels de Mastodon

• Les développeurs de Mastodon ont averti les autres administrateurs de serveurs du risque d’utiliser Mastodon avec une configuration de réplication basée sur Makara
• Il a été noté qu’une telle configuration reste rare, car elle n’est généralement envisageable que sur de grandes instances comme Vivaldi Social
• Mastodon v4.1.5 inclut deux correctifs liés à cet incident
  • Empêcher l’utilisation de Makara dans les workers Sidekiq
  • Correction garantissant le bon ordre des opérations dans la fusion de comptes

Chronologie de l’incident en UTC

• Samedi 15:15 : un message de changement de nom de compte provenant d’une instance externe est transmis à Vivaldi Social, et l’opération de fusion incorrecte commence
• Samedi 15:25 : les premiers signes de l’incident sont observés
• Samedi 17:20 : après le redémarrage des conteneurs Docker, les opérations de fusion de comptes s’arrêtent ; entre 15:15 et 17:20, 198 comptes ont au total été supprimés ou fusionnés
• Dimanche 13:00 : identification d’une cause racine possible
• Dimanche 14:25 : confirmation de la cause racine
• Dimanche 21:55 : début de la restauration des données
• Dimanche 23:27 : fin de la restauration des données
• Lundi 10:40 : correction de 6 comptes dont le nom d’utilisateur contenait des symboles
• Lundi 11:05 : restauration des données de configuration web perdues
• Mardi 15:31 : correction des valeurs de compteurs erronées
• Mardi 16:01 : correction de 4 comptes contenant des données incorrectes

[GN⁺]

Avis sur Hacker News

• C’était un excellent retour d’expérience, et il montrait particulièrement bien à quel point les coûts humains, comme le manque de sommeil, peuvent peser dans la résolution d’incidents complexes
  Le passage qui m’a le plus frappé est celui où « de nouveaux comptes ont été créés dans la base de données avec une valeur null dans le champ URI »
  Chaque fois que je lis une analyse post-mortem liée à une base de données, NULL rôde presque toujours quelque part près de la scène de l’accident. Même si NULL n’est pas le coupable, il faut toujours le mettre sur la liste des suspects à interroger
  Mon conseil serait de ne pas s’appuyer sur NULL comme valeur sentinelle et, si possible, de ne tout simplement pas l’autoriser dans la base de données. Même si cela semble apporter des avantages, ils finissent généralement par être annulés quelques années plus tard quand la signification du modèle de données évolue, et qu’une instruction apparemment inoffensive attend NULL ou NOT NULL puis produit un résultat inattendu sous forme de bug difficile à trouver
  Dans ce cas, c’était une condition de concurrence, mais si les comptes locaux et distants avaient été clairement distingués par des types, l’ordre des opérations n’aurait peut-être pas eu d’importance, et le code de fusion des comptes aurait aussi pu être limité à un périmètre plus étroit

  • J’ai fini par créer un compte pour répondre à ce point, en espérant ne pas paraître trop agressif
    Null est une valeur de donnée tout à fait valide et doit être traité comme telle. Des valeurs par défaut comme -1 pour un booléen ou une chaîne vide pour une chaîne peuvent donner l’impression qu’un système fonctionne là où NULL aurait provoqué une erreur à l’exécution, mais cela ne signifie pas que le système fonctionne comme prévu, seulement qu’il devient silencieux
    Je comprends la tentation de masquer NULL, mais « absent » est un état aussi valide de la donnée que « présent », et les systèmes devraient généralement être écrits pour l’accepter
  • L’alternative serait une chaîne vide ?
    Dans ce cas, je pense que le problème n’est pas le NULL de la base de données, mais le NULL de la couche applicative
    Si NULL est une valeur qu’on est obligé de traiter, comme une sorte de monade Maybe, alors on finit par la traiter, et par y réfléchir. Que ce soit une chaîne vide, la chaîne null du langage utilisé, ou une valeur marqueur spéciale fabriquée maison, ça ne change pas grand-chose
  • La fusion/déduplication automatique fait partie de ces problèmes très difficiles où, quand on manipule des enregistrements « similaires », il faut autant que possible faire intervenir un humain. Les cas limites et les conditions de concurrence abondent, et les données consommées de manière asynchrone doivent être transmises aussi explicitement que possible, avec plusieurs vérifications pour s’assurer que les faits réels n’ont pas changé
    Dans beaucoup de cas, l’implémenteur devrait d’abord penser aux préoccupations et aux exigences d’interaction qu’impliquent les conflits de fusion à la Git, puis, à partir de là, poser des hypothèses simplificatrices adaptées au domaine du problème
    En regardant le code source de Mastodon https://github.com/mastodon/mastodon/blob/main/app/workers/a..., il ne semble même pas y avoir de liste explicite des « ID à partir desquels fusionner » transmise par l’initiateur de la demande de fusion à l’exécuteur asynchrone de la fusion ; on dirait donc que ce genre d’incident n’était qu’une question de temps
    Ce n’est pas une critique de Mastodon. J’ai moi-même écrit de la logique de fusion avec des conditions de concurrence bien pires, et j’en ai subi les conséquences. En réalité, il est déjà surprenant qu’une telle fonctionnalité existe dans un projet bénévole comme https://opencollective.com/mastodon. Mais cela reste un cas dont il faut se méfier
  • Avec des JOIN, NULL est inévitable. C’est la nature même des JOIN
    Plus profondément, la réalité est désordonnée, et comme une base de données ne peut pas refuser de la traiter au motif qu’elle est désordonnée, NULL est inévitable. Par exemple, si l’on modélise les titres de civilité, les titres placés avant le nom et ceux placés après le nom, puis qu’on veut construire une formule de salutation complète à partir de ces données, il y aura au moins des personnes sans titre post-nominal. Même si l’on ne stocke pas NULL, le résultat du JOIN utilisé pour créer la salutation produira des NULL
    On peut éliminer certaines valeurs NULL précises, mais on ne peut pas éliminer le fait que, dans le monde réel, « non applicable » ou « inconnu » sont souvent des valeurs valides, et la base de données doit les gérer
  • Même avec des null, la fonction de fusion aurait dû faire, d’une manière ou d’une autre, une vérification de null ou de vérité. C’est assez incroyable

• Le déroulé auquel je m’identifie ici commence par « on a une sauvegarde complète de la base, donc il suffit de tout restaurer », passe à « une restauration complète est difficile, implique du downtime et a des effets de bord », puis revient à « on doit pouvoir restaurer intelligemment seulement les données manquantes », avant de partir dans du manuel, de tomber sur une erreur bizarre, de finir par déployer une restauration sélective bricolée, puis de nettoyer les cinq dernières données manquantes. En espérant ne pas avoir raté la sixième
  Chaque fois que quelqu’un s’entraîne à la sauvegarde/restauration, ça se passe toujours comme ça. Au final, décider quelles données restaurer depuis une image de sauvegarde relève toujours du niveau applicatif

  • Je suis d’accord. Il y a ce dicton : « si vous n’avez pas testé votre sauvegarde, vous n’avez pas de sauvegarde »
    Cela dit, dans ce cas, je ne comprends pas bien où était le problème. Restaurer entièrement depuis la dernière sauvegarde saine aurait fait disparaître une partie des messages publiés entre-temps, ce qui est regrettable, mais c’était une solution immédiate au lieu d’un travail manuel et incertain

• Le passage disant que Renaud, Claire et Eugen de l’équipe de développement de Mastodon ont apporté une aide au-delà des attentes m’a marqué
  Je ne sais pas si Vivaldi soutient financièrement Mastodon, et je n’ai pas trouvé son nom sur la page des sponsors. Si ce n’est pas le cas, j’espère que cet incident poussera Vivaldi, ou d’autres entreprises utilisant Mastodon, à envisager un sponsoring ou un contrat de support

  • Actuellement, l’organisation à but non lucratif Mastodon ne propose pas de contrat de support, mais c’est une bonne idée
    Le sponsoring est ouvert et a réellement un impact important. Avoir des personnes à temps plein sur le projet est crucial, mais côté technique il n’y a actuellement, en dehors du fondateur Eugen, qu’un développeur à temps plein et une personne DevOps
  • Comme ils ne figurent pas sur https://joinmastodon.org/sponsors, ils ne sont probablement pas sponsors
  • Cela dit, ils fournissent quand même une instance assez importante à la fédération Mastodon, ainsi que des personnes qui travaillent dessus

• C’était l’un des meilleurs post-mortems que j’aie lus depuis un moment

  • Je me souviens que le post-mortem de hachyderm était aussi plutôt bon. Heureusement que les gens font preuve de transparence

• Le fait que les points 2 et 3 ne soient pas traités atomiquement me semble problématique. Bien sûr, il y a sans doute des raisons pour lesquelles ce n’est pas trivial à faire, mais je n’ai pas encore regardé le code et il faudra que je le fasse un jour

  • L’un des correctifs liés est https://github.com/mastodon/mastodon/commit/13ec425b721c9594...
    Rendre ça atomique semble avoir été trivial
    C’est juste qu’avant il n’y en avait pas besoin. Le fait que ce ne soit pas atomique ne posait pas de problème, sauf si quelqu’un faisait une mauvaise configuration en connectant sidekiq à un ancien serveur de base de données, c’est-à-dire à une réplique. Ici, cette configuration semble être le principal problème

• La première fois que j’ai dû restaurer un énorme dump SQL, je n’oublierai jamais avoir vu vim faire réellement une erreur de segmentation en essayant de le lire
  C’est là que j’ai découvert la magie de split(1), c’est-à-dire découper un fichier en morceaux. J’ai fractionné le gros dump en un fichier par table
  Bien sûr, une seule table peut aussi être énorme, mais au moins les fichiers deviennent plus uniformes, ce qui facilite la transformation des requêtes avec d’autres outils comme sed ou awk

  • Je suis surpris que vim puisse faire une erreur de segmentation. J’ai déjà vu l’ouverture de gros fichiers être lente, mais j’ai toujours pensé qu’avec une sorte de mise en mémoire tampon magique il pouvait tout gérer. Je me trompe peut-être
    Cela dit, si on en est au point de devoir modifier un dump pour restaurer des données, c’est qu’il y a quelque chose de sérieusement cassé dans la procédure de restauration. Évidemment, quand on se retrouve effectivement dans cette situation, ce savoir n’aide pas beaucoup
  • J’ai déjà administré un système où un dossier contenait tellement de fichiers que même la commande ls ne se terminait pas. C’était probablement de l’ext3 ou de l’ext2
    Le contournement a consisté à écrire un script Python pour tout traiter progressivement et déplacer les fichiers dans des sous-répertoires selon leur préfixe commun

• Le passage « Claire a demandé la trace de pile complète de l’entrée de journal, et on a aussi pu l’extraire des logs » m’a fait tiquer
  Soit c’est du vaudou très avancé, soit le code ou la configuration transforme un Xeon en 286. Ça ne finit pas en mégaoctets par requête ?

  • Il y avait une erreur HTTP 500 lors de la consultation du compte, et il s’agit de la trace de pile de cette 500
    C’est le comportement par défaut de Ruby on Rails. En cas de 500 ou d’erreur inconnue, il affiche une trace de pile, dont le contenu se limite grosso modo aux numéros de ligne et aux chemins de fichiers
    J’exploite une application Rails assez mal conçue, et je viens de vérifier : la trace de pile d’une 500 fait 5 KiB. Comme il n’y a environ qu’une erreur 500 par heure, cela fait moins de 1 MiB par jour
    Garder la pile d’appels à portée de main est en réalité assez correct côté performances. Le comportement par défaut des exceptions en Java consiste aussi à remonter une trace de pile avec chaque exception, même si elle n’est pas affichée, et pourtant les applications Java tournent bien. De toute façon, il faut savoir comment revenir, donc la pile d’appels existe déjà ; les seules informations supplémentaires nécessaires sont les symboles de débogage pour le nom de fichier et le numéro de ligne. En Ruby, ces informations sont de toute façon nécessaires par nature du langage
  • Enregistrer la trace de pile d’une erreur est tout à fait raisonnable. Idéalement, toutes les requêtes ne produisent pas d’erreur
  • Tu veux dire que tu ne captures pas les traces de pile des erreurs sur un système en production ? Comment sais-tu d’où vient l’erreur ?
  • Tu sembles confondre une trace de pile avec un core dump ou quelque chose du genre

• Comment est-il possible que « tous les comptes locaux de l’instance Mastodon correspondaient tous, parce que leur champ URI valait null » ?
  NULL = NULL s’évalue à FALSE. SQL utilise une logique à trois valeurs, plus précisément la logique ternaire faible de Kleene, et appliquer n’importe quel opérateur à NULL donne NULL

  • Je me suis posé la même question. Peut-être que le filtrage se faisait au niveau de la couche applicative, avec un test d’égalité sur la valeur null du langage utilisé

• Je ne vois pas comment des comptes dont la colonne URI contient NULL ont pu correspondre à la requête. NULL ne se compare pas comme égal à NULL. C’est une horrible magie Rails ?

• En voyant le passage disant que 6 utilisateurs dont le nom d’utilisateur contenait des symboles ne pouvaient pas se connecter, et que c’était dû à une erreur dans le script de récupération, facilement corrigée, j’ai l’impression que UTF-8 a encore frappé