MongoDB, pb de flush (fsync)

Bonjour à tous,

Je suis confronté à un problème sur une base de prod MongoDB (2.2) sous windows 2008 server (l'appli est en c#).

Le perf sont globalement bonnes, sauf 'occasionnellement' où le fsync gèle l'ensemble des accès pendant environ 1 minute (ce qui bloque tous les opérateurs en prod).

Sans raison apparente, le temps de flush est super variable en moyenne 2,5 secondes, et parfois très long (ces lenteurs arrivent une fois par heure environ).

- Quand c'est court : les logs montrent des accès concurrent sans problème
- Quand c'est long : tous les autres accès sont figés et très souvent il y a des reconnexions de sessions en simultané (interaction avec le driver ?)

Quelles solutions ? et en sachant que j'aurais beaucoup de mal à faire des tests or prod pour valider les approches...


Merci par avance

Qui appelle ces fsync ?

fsync est une commande admin qui force l'écriture de l'ensemble des opérations sur disque et qui bloque l'ensemble de la base pendant le fsync. C'est donc normal d'avoir un gel ressenti par les clients.

En général on fait des fsync avant des opérations de backup, mais pas dans le code d'une appli.
A quoi servent-ils ?

Citation:

---

Envoyé par hugo123

Qui appelle ces fsync ?

fsync est une commande admin qui force l'écriture de l'ensemble des opérations sur disque et qui bloque l'ensemble de la base pendant le fsync. C'est donc normal d'avoir un gel ressenti par les clients.

En général on fait des fsync avant des opérations de backup, mais pas dans le code d'une appli.
A quoi servent-ils ?

---

Je me suis mal exprimé. Il n'y a pas d'appel explicite à cette commande mais mongo l'appelle régulièrement toutes les 60 secondes, par défaut (c'est le fsyncdelay).

Voici ce qu'on trouve dans les logs lorsque ça arrive :

Fri Dec 20 09:52:10 [DataFileSync] flushing mmaps took 55505ms for 11 files


Et dans les log, avant ça, on voit clairement que pour la même période les accès base liés aux requêtes utilisateurs disparaissent. Ce qui est "normal" car comme tu le disais ça "bloque l'ensemble de la base".

Mon souci n'est pas le fsync en lui-même mais qu'il soit parfois très long, sans raison apparente.

salut

une réponse sans prétention et sous forme de questions :
quel est le sous-système disque ? hardware et/ou raid ?
concurrence avec d'autres processus pour les accès disques au moment des freeze ?
une idée de la taille des données écrites ?

Citation:

---

Envoyé par fredoche

salut

une réponse sans prétention et sous forme de questions :
quel est le sous-système disque ? hardware et/ou raid ?
concurrence avec d'autres processus pour les accès disques au moment des freeze ?
une idée de la taille des données écrites ?

---

le disque d: est en raid10 (aucune partition),

140Go de libre (la base en fait environ 14),

le journal mongo est sur le même disque (mais a priori, lui il écrit toutes les 100ms et comme il y a un lock, il n'a normalement rien à écrire pendant le sync),

pas d'autres accès concurrents connus...

Pour la taille des données, je ne sais pas exactement lors d'un flush, mais je dirais qu'en 1 minute, on touche 300 à 1000 documents d'environ 1Ko chacun (après il y a les index, d'éventuels réallocations/replacements des données). 12 index sur la table principale touchée.

Ce qui est étonnant, c'est que ces freezes ne sont pas liés aux intégrations de données : les freezes ont lieu quelques minutes après et pas forcément lorsque les données intégrées sont en "gros volume" (un gros volume dans ce contexte, c'est 8000 documents de 1ko chacun).

Je dirais pourtant que si les flush sur disque sont lents, c'est soit parce que les accès disques sont lent, soit que le volume de données est très important.

Tu peux monitorer les données qui entrent et sortent avec mongostats.
En parrallèle tu peux utiliser des outils pour mesurer la rapidité des IO sur tes disques.
Et pendant l'execution des process, je ne connais pas bien Windows mais il y a peut être un équivalent de iostats ?
D'ailleurs en pensant à Windows, j'ai souvent vu des soucis sur ce genre de plateforme en écriture avec des outils type antivirus.

Parmi les autres pistes, tu peux avoir les fichiers journaux sur un autre disque que les fichiers data pour répartir les écritures sur deux disques physiques.

Autre piste toujours, voir s'il n'y aurait pas des optimisations en version supérieur sur ces points. En rêgle générale je déconseille les anciennes versions qui sont connues pour avoir pas mal de souci de concurrence.

Tiens nous au courant, ca m'intéresse de connaitre la réponse.

Je vais suivre tes conseils, Hugo, dès que possible (c'est à dire probablement après les fêtes pour pouvoir accéder dans de bonnes conditions à l'environnement de prod).

Mais peut-être ça serait bien que je vous donne l'historique du projet et quelques derniers tests que j'ai effectués sur ma machine de dev :

- Petit historique :
Pour x raisons, nous avons pendant longtemps dû faire tourner la prod sur un pc windows 7 (un bon pc, mais pas un serveur).
Il y avait quelques soucis, mais jamais ce problème de gèle de la prod.
Puis, un week-end, il y a 2 ou 3 semaines, nous avons migré la machine pour un serveur power edge, avec une cpu xeon et deux fois plus de proc, plus de ram, disques raid, etc.
Et dès le lundi matin suivant : bing ! Les gèles apparaissent...

Donc premier réflexe : c'est la machine ou son environnement, mais jusqu'ici on n'a rien trouvé...

- Derniers tests sur ma machine de dev :
J'ai rapatrié la base et fait un petit soft pour simuler les ordres vers mongo induits par les opérateurs en prod.
Temps moyen des sync : 8,5 secondes (contre 2,5 sur la machine de prod). Je n'ai pas reproduit les longs freeze (c'est parce que mon soft de simul ne simule pas encore tout, je pense).

Après j'ai fait une modif dans les données pour la cause suivante : certains enregistrements comportent un tableau dont la taille augmente. Je me suis donc dit que mongo devait réallouer ces objets et que donc cela avait un impact un peu global sur tous les index de la collection (12 index dont normalement un seul devrait être impacté en l'occurence : le champ état de l'objet).

Donc la modif : supprimer le tableau (dans une version à part du soft pour faire le test).
Effectivement, j'obtiens un gain puisque le temps moyen des sync est tombé à 4,7 secondes.

Mais ! Mais ! mon test induit qu'en moyenne (sans écart type significatif) 320 objets sont écrits par minute (chaque objet faisant un petit Ko). Ce qui signifie qu'au final mongo met 4,7 secondes pour écrire 320 objets...

Je n'ose pas en tirer des conclusions (pas tout de suite)...

Pour info, au total, 2,2 millions de documents dans cette collection, aucun problème sur les accès en lecture (en dehors des gèles).


Je vous tiens au courant... mais si vous avez des idées entre temps, n'hésitez pas !

Citation:

---

Envoyé par Alikendarfen

- Petit historique :
.../...

---

Je reviens sur ce que j'ai dit précédemment : sur l'ancienne machine serveur, c'était pareil (analyse des log), sauf que pour une raison que j'ignore, les utilisateurs n'ont pas perçu le problème de la même façon...


Sinon, quelques chiffres sur mes tests/simulations (sur machine de dev) :
- syncdelay 60 secondes : average freeze 8,5 secondes
- syncdelay 30 secondes : average freeze 5,1 secondes
- syncdelay 5 secondes : average freeze 1,2 seconde

Donc plus le syncdelay est court, plus on y perd, au total.

pas déconnant cela dit. Le syncdelay c'est le temps entre deux flush. Plus on fait de flush, moins il y a de choses a flusher mais plus on monopolise le temps pour les faire.
Ca me parait plus sain de les espacer pour les grouper.

Citation:

---

Envoyé par hugo123

Ca me parait plus sain de les espacer pour les grouper.

---

Oui et non. Je pense que ça dépend du type d'appli que tu mets en place.

Dans mon cas, les regrouper induit actuellement des interruptions de services pendant une minute assez souvent. Et ça n'est pas acceptable vu l'usage de mon appli.


A part cela, je viens de faire un test sur un disque SSD. C'est 14 fois plus rapide dans ma situation, ce qui fait que les 8,5 secondes (avec syncdelay de 60s) deviennent 589ms.