Page MenuHomeSoftware Heritage

High disk usage on www.softwareheritage.org Gandi PAAS instance
Closed, MigratedEdits Locked

Description

www.softwareheritage.org became available at 02:00 UTC on 2021-12-31 because it ran out of disk space.

The space usage grew from 9 GB steady state at 23:00 UTC on 2021-12-30 to the full 20GB three hours later.

Event Timeline

olasd triaged this task as Unbreak Now! priority.Dec 31 2021, 2:06 PM
olasd created this task.

After enabling the emergency console on the gandi interface, I couldn't find the disk usage culprit with du. It soon became obvious that the disk usage came from the database (which is the only bit of the disk that's not readble via the account used to connect to the emergency console).

After some sleuthing, the wp_options table had ballooned up to 44 GB (!) of used space, as claimed in the information_schema.tables data. Dumping and restoring that table brought it back to a more reasonable couple of megabytes, and freed 5 gigabytes out of the disk quota, enough to restart the instance.

Message sent to gandi simple hosting support:

Bonjour,

Cette nuit, le disque de 20GB de mon instance PAAS www.softwareheritage.org s'est rempli, passant de 9GB à 20GB en trois heures.

Après avoir constaté le problème ce matin, et après m'être connecté à l'interface shell d'urgence, j'ai pu deviner que l'utilisation disque était probablement dûe à MySQL.

J'ai dumpé / restauré une table qui s'était bloatée de plusieurs GB (selon information_schema.tables, 44GB utilisés) ce qui a libéré 5 GB d'espace sur mon quota.

Cependant, je n'arrive pas à libérer plus d'espace, et je ne comprends pas où est l'espace utilisé. Je pense qu'il s'agit de structures internes de MySQL qui sont bloatées et ne sont pas libérables sans recréer le serveur MySQL.

Vous serait-il possible de confirmer où est l'espace utilisé dans mon quota, et potentiellement de lancer des actions correctives (ou me conseiller sur la suite à suivre) ?

Pour info, après avoir tenté un nouveau du sur le shell d'urgence, j'obtiens maintenant la sortie suivante :

hosting-user@softwareheritage:/srv/data$ ls -al
ls: cannot open directory '.': Stale file handle

Je pense qu'il y a eu un souci de nfs... L'instance s'est retrouvée indisponible. Après redémarrage de l'instance, voilà la sortie actuelle:

hosting-user@softwareheritage:/srv/data$ du -sh .[^.]* *
512     .config
512     .current_db
512     .current_www
512     .paas
du: cannot read directory 'db': Permission denied
512     db
28K     etc
29K     home
8.0M    tmp
25K     trash
2.3M    var
973M    vcs
1.1G    web

On est loin des 15GB supposément utilisés, donc j'imagine qu'ils sont cachés dans le répertoire de MySQL.

Par ailleurs, quelques remarques sur ce que j'ai constaté en diagnostiquant ce problème :

  • Lorsque le disque est plein, l'interface web d'administration est inaccessible (erreurs 503 varnish). Il pourrait être bon de découpler les deux quotas pour éviter de se retrouver bloqué.
  • Pour diagnostiquer l'espace disque rapidement, la disponibilité d'un outil comme ncdu dans la console d'urgence serait appréciable.
  • Il serait opportun que l'utilisateur hosting-user ait accès en lecture au répertoire de données SQL (disponible uniquement pour l'utilisateur hosting-db).
  • Lorsque tout le quota est utilisé, un changement du mot de passe d'administration vide le fichier .htpasswd de l'interface web d'administration, plutôt que de le mettre à jour (ce qui empêche les accès subséquents à cette interface, jusqu'à ce que le mot de passe soit mis à jour de nouveau). Cela rejoint l'idée de séparer les quotas (ou d'écrire ce fichier avec un utilisateur qui n'est pas soumis au même quota).

Merci de votre aide,
Nicolas Dandrimont

Response from Gandi support

Bonjour Nicolas,

Tout d'abord je tenais à vous remercier pour votre message et pour l'intérêt que vous portez à Gandi.

[...]

Il est fort possible que cet espace disque soit occupé par des fichier binlog de Mysql, cette fonction étant activé par défaut sur Mysql 8.0.

Je vous invite à vérifier avec la commande suivante :

show binary logs;

Puis pour les supprimer :

Purge binary logs to 'binlog.xxx'; ou xxx est le numéro du plus ancien fichier.

Afin de désactiver bin_logging au démarrage, modifiez le fichier /srv/data/etc/mysql/custom.cnf comme suit :

[mysqld]
skip-log-bin

Je reste à votre disposition pour toute demande d'information complémentaire.

Cordialement,

\o/ Valère
G http://www.gandi.net/

Own response:

On Fri, Dec 31, 2021, at 15:08, Gandi Service Support wrote:

Bonjour Nicolas,

Tout d'abord je tenais à vous remercier pour votre message et pour 
l'intérêt que vous portez à Gandi.

Merci pour la réponse rapide !

Il est fort possible que cet espace disque soit occupé par des fichier 
binlog de Mysql, cette fonction étant activé par défaut sur Mysql 8.0.

Je vous invite à vérifier avec la commande suivante :

show binary logs;

Bien vu !

Puis pour les supprimer :

Purge binary logs to 'binlog.xxx'; ou xxx est le numéro du plus ancien fichier.

Cette commande a besoin du privilège SUPER, ce qui n'est apparemment pas le cas de l'utilisateur root.

Par contre, la commande reset master, qui supprime tous les logs binaires, a fonctionné avec l'utilisateur root (il n'y a besoin que du privilège RELOAD, va comprendre...)

L'espace a bien été libéré.

Afin de désactiver bin_logging au démarrage, modifiez le fichier 
/srv/data/etc/mysql/custom.cnf comme suit :

[mysqld]
skip-log-bin

J'imagine qu'il faut redémarrer l'instance pour que ce soit pris en compte ?

Bonne journée,
Nicolas Dandrimont

After running the reset master command on the mysql server, the disk quota usage is back down to ~2 GB, which matches usage from files + the actual MySQL data.

Root cause analysis points to a high amount of stripe webhooks being received on/around the time of the outage.

After getting access to the stripe admin console, I found the following:

  • One very persistent spammer is using a payment created via our donation form to test out credit cards
    • payment id = pi_3KCWdkAX883mzeaz3GoSt6qr
    • The date of payment creation matches the onset of the disk usage problem
    • The actual requests with CC data happen on Stripe servers, so they're invisible to us
    • The payment is both blocked by Stripe's Radar feature (automatically), and by me adding the email address to our deny list, but we still get payment attempts...
  • the Stripe webhook is configured twice on separate endpoints; one of them is definitely the GiveWP endpoint, the other one I couldn't track down
  • the Stripe webhooks were both configured to send us data on all events
  • the spammer activity creates a lot of (webhooked) payment_intent.requires_action events (multiple per second) that GiveWP doesn't care about, according to their Stripe integration docs (https://givewp.com/documentation/add-ons/stripe-gateway/). This webhook hit would only create a line in the GiveWP logs.
  • I've changed both webhook configs to only send us the events GiveWP cares about (according to the previous docs).
  • We now only get a webhook hit every minute or so, on a payment_intent.payment_failed event, when the spammer actually tries a new card number and gets rejected.

I used the Stripe API to cancel the fraudulous payment intent (https://stripe.com/docs/api/payment_intents/cancel). (request req_J31DYN4PJsxdkK)

While tracking down the root issue in WordPress, I noticed (from the php-fpm error logs) that WPML's languages weren't properly initialized, so I did that in the WordPress admin interface (enabled the same languages as the rest of the website).

After restarting the instance, MySQL binary logs are disabled, which should avoid us getting some confusing hidden disk usage again.

Looks like the bogus payment requests have stopped now. Disk usage on the PAAS instance is under control.

Things we should consider:

  • confirming what the second stripe webhook endpoint (the one to wp-admin) does and removing it if it isn't used
  • move 2FA for the stripe account accounting@softwareheritage.org to an "OTP app" (making it usable by oathtool / multiple users) rather than SMS to @anlambert's phone
  • downgrade the stripe access for olasd@softwareheritage.org, if considered necessary

Thanks a lot for fixing this and the detailed report, this is pretty terrifying. I do not get why the Stripe API does not have some rate limit to prevent such abuse.

Anyway, I changed the 2FA authentication on our Stripe account to use an OTP app instead of texting to my phone.
I put the OTP key in the //operations/stripe.com/oath_key entry in our pass repository.
The 2FA code can then be easily obtained through that command: $ oathtool --base32 --totp <oath_key>.