Moodle en français: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

[2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

par Luiggi Sansonetti, lundi 5 novembre 2012, 22:35

Bonjour

depuis 3 semaines, nous avons des messages d'erreur à des moments précis de la journée, sans qu'on sache vraiment d'où ça vient (petite idée quand même) ni comment les éviter...

par exemple, à 10h15 puis 15h15 puis 20h15 on a le message suivant (aujourd'hui 13h15 aussi) :

puis en actualisant la page on a celui-là :

la semaine dernière, c'était celui-ci :

La table « context » n'existe pas

Et le détail en mode débug

Debug info:
Error code: ddltablenotexist

Stack trace:

line 519 of /lib/dml/moodle_database.php: dml_exception thrown
line 1287 of /lib/dml/moodle_database.php: call to moodle_database->where_clause()
line 5673 of /lib/accesslib.php: call to moodle_database->get_record()
line 6933 of /lib/accesslib.php: call to context_system::instance()
line 690 of /lib/setup.php: call to get_system_context()
line 27 of /config.php: call to require_once()
line 5 of /course/view.php: call to require_once()

je pense que c'est lié au relancement du cron mais bon...

pour info :

le paramètre max_allowed_packet: de 16M et normalement passé à 512M (d'après mon collègue qui l'a fait)
et 13 * * * * /usr/bin/php /var/www/moodle/admin/cli/cron.php > /var/log/apache2/icampus-moodle_cron.log

et j'essaierai de voir un peu le contenu du cron (et du fichier log).

mais si déjà quelqu'un a rencontré ce problème, je suis preneur.

bien à tous.

Moyenne des évaluations -

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

par Sophie Ricci, lundi 12 novembre 2012, 17:21

Bonjour, Pour information, j'ai constaté il n'y a pas longtemps ce message : La table « context » n'existe pas. Il était affiché au moment où les sauvegardes du serveur dédié était programmées. Lors de la sauvegarde, moodle ne reconnaissait plus la base de données (du moins l'ensemble des tables). J'espère que vous trouverez rapidement à résoudre votre difficulté. Cdlt

Moyenne des évaluations -

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

par Séverin Terrier, lundi 12 novembre 2012, 17:25

Sans vraiment plus de détail, je pense que la connexion à la base de données se perd en route (à cause d'une durée d'exécution longue, plus que ce qui est paramétré) ; et du coup, la suite des opérations ne peut plus se faire...

Moyenne des évaluations -

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

par Luiggi Sansonetti, lundi 12 novembre 2012, 18:26

bonjour

et merci à vous pour ces idées

ça peut venir des sessions (même si avec la régularité j'en doutais), car ça me l'a fait ce matin à 10h15 puis là à l'instant à 11h15...)

[... ]MySQL max_allowed_packet [...]

Moyenne des évaluations -

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

par Séverin Terrier, lundi 12 novembre 2012, 19:03

Personnellement, je n'ai jamais stocké les fichiers de sessions en base de données...

Moyenne des évaluations -

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

par Luiggi Sansonetti, lundi 12 novembre 2012, 19:24

donc ça peut alors ne servir à rien ?

pour les historiques ou les trackeurs d'activités ?

car si ça sert à rien, je peux faire un test de ne pas les garder pour vérifier s'il y a encore ce bug...

Moyenne des évaluations -

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

par Séverin Terrier, lundi 12 novembre 2012, 20:38

Je ne suis pas certain que l'on parle de la même chose : comme tu parlais de "session", je pensais que tu parlais du réglage accessible depuis Administration ► Serveur ► Gestion des sessions ; et je t'indiquais que je ne les stockais pas en base de données, mais sur le disque (dans moodledata/sessions).

Moyenne des évaluations -

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

par Luiggi Sansonetti, lundi 12 novembre 2012, 21:17

ha, quelle régularité (mais du coup ce n'est plus toutes les 5 heures, c'est plus rapproché...)

La table « context » n'existe pas

Debug info:
Error code: ddltablenotexist

Stack trace:

line 519 of /lib/dml/moodle_database.php: dml_exception thrown
line 1287 of /lib/dml/moodle_database.php: call to moodle_database->where_clause()
line 5673 of /lib/accesslib.php: call to moodle_database->get_record()
line 6933 of /lib/accesslib.php: call to context_system::instance()
line 690 of /lib/setup.php: call to get_system_context()
line 27 of /config.php: call to require_once()
line 26 of /user/view.php: call to require_once()

Moyenne des évaluations -

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

par Luiggi Sansonetti, mardi 13 novembre 2012, 17:29

bonjour

mon collègue MySQL a fait ça : max_allowed_packet = 540 Mo

on verra bien aujourd'hui comment ça se passe pour bien être sûr qu'il s'agisse de ce problème de session

à moins que la vérité ne soit ailleurs...

Moyenne des évaluations -

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

par Séverin Terrier, mardi 13 novembre 2012, 18:52

Bonjour,

Pour ma part, j'ai 64 Mo sur le serveur...

Séverin

Moyenne des évaluations -

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

par Luiggi Sansonetti, mardi 13 novembre 2012, 20:26

oui, avec mon collègue on a voulu être sûr de notre certitude !

pour le moment, pas de blocage vu, mais je ne suis pas tout le temps en devant ma plateforme...

mais je tiendrai informé pour marqué comme [résolu]

Moyenne des évaluations -

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

par Luiggi Sansonetti, mardi 13 novembre 2012, 22:00

bon, ben ça rebloque à 14h15...

et message avec la table context n'existe pas...

donc on poursuit

Moyenne des évaluations -

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

par Séverin Terrier, mardi 13 novembre 2012, 23:46

Ne serait-ce pas lié à des durées d’exécutions maximales (à régler dans php.ini) ?

Il ne serait sans doute pas inutile que tu reprennes/répondes à ton message d'origine, pour donner un maximum de renseignements clairs et précis...

En effet, j'ai du mal à comprendre si tu constates le problème dans l'exécution du cron, en même temps que l'exécution du cron, ou à d'autres moments...

Peut-être également en profiter pour passer à Moodle 2.3.3

Moyenne des évaluations -

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

par Luiggi Sansonetti, mercredi 14 novembre 2012, 15:20

bonjour

oui, je vais aujourd'hui refaire un point précis, d'autant plus que ce matin j'ai vu un webservice user à 8h05 et hop, blocage à 8h15...

donc je me renseigne auprès de mon collègue qui gère les webservices pour voir ce qu'il en est et je ferai un topo sous peu (avec - j'espère - les informations )

Moyenne des évaluations -

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

par Luiggi Sansonetti, mercredi 14 novembre 2012, 18:46

Bonjour

petite ré-explication de ce qui se passe toujours et de façon maintenant plus fréquente...

depuis qu'on a relancé le cron vers mi-octobre, nous avons des blocages d'accès à la plateforme.

les 1ers messages d'erreurs étaient :

moodle_database::update_record_raw() id field must be specified

puis après rafraichissement

... valeur trop faible du réglage MySQL max_allowed_packet

et de temps en temps aussi

La table « context » n'existe pas

j'ai débord pensé au cron mais il s'exécute toutes les 13 minutes.

et ça ne bloque pas toutes les 13 minutes, car il y a un blocage systématique à xxh15, et les heures peuvent varier.

au début cétait 10h15 puis 15h15 puis 20h15

après 10h15 puis 13h15 puis 15h15...

aujourd'hui, c'était 8h15 puis 10h15 puis 11h15 !!!

le blocage dure toujours 5 minutes (entre 3 et 8 minutes).

et maintenant c'est systématiquement La table « context » n'existe pas

on a pensé comme suggéré que ça pouvait venir des sessions : on a augmenté la taille de 4 à 540mo hier matin

on pense à des backup comme suggéré, mais depuis Moodle je n'ai pas de backup automatique et la seule sauvegarde qu'on fait "en dur" est à 3h du matin.

ce matin je me suis aperçu qu'il y a eu un webservice à 8h09 et le blocage à 8h15.

j'attends toujours de mon collègue pour savoir si ça peut être lié ou non, mais je n'ai pas vu justement ce webservice à 10h15 ni 11h15...

je suppose (mais j'attends toujours un retour à mes mails) que ça peut venir de la création automatique des cours, car ils sont créés dans une catégorie par défaut, et j'ai réorganisé les cours dasn d'autres catégories.

donc je ne sais pas si le script en vérifiant l'existance d'un cours ne bloque pas car il cherche si le cours existe et il le trouve pas et le crée mais comme il existe dans une autre catégorie il peut pas car doublon...

j'ignore si c'est ça, si le processus peut se répété un certain nombre de fois avant abandon...

et je ne sais pas si en mettant en 2.3.3 ça éradiquera le problème (si la base n'est pas "propre"...)

donc j'attends d'en savoir plus, mais le symptôme est le même (table context à xxh15, durée de 5 minutes du blocage) mais les causes nombreuses (cron, script...).

c'était juste pour apporter, j'espère, un peu plus de précision.

(ps oui, je suis fan des Beatles et de certains de leurs messages surtout en ce moment...)

Moyenne des évaluations -

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (détails des erreurs !!)

par Luiggi Sansonetti, mercredi 14 novembre 2012, 19:04

ça y est une info :

le cron est exécuté toutes les heures à 13minutes

############
Server Time: Wed, 14 Nov 2012 10:13:01 +0100

Running clean-up tasks...
Deleted old log records
Deleted old backup records
Deleted old cache_text records
Executed tag cron
Cleaned up context instances
Built context paths
Cleaned cache flags
!!! Erreur d'écriture vers la base de données !!!

Debug info: Error writing file '/tmp/ML7HFHsj' (Errcode: 28)
DELETE FROM mdl_message_read WHERE notification=1 AND timeread<?
[array (
0 => 1352279583,
)]
Error code: dmlwriteexception
Stack trace: * line 410 of /lib/dml/moodle_database.php: dml_write_exception thrown
* line 1151 of /lib/dml/mysqli_native_moodle_database.php: call to moodle_database->query_end()
* line 166 of /lib/cronlib.php: call to mysqli_native_moodle_database->delete_records_select()
* line 61 of /admin/cli/cron.php: call to cron_run()
#############

et dans le fichier de logs (je cite mon collègue : "Il y a ENORmément de logs dans /var/log/apache2/icampus-error.log. Voici un extrait, il semble que ce soit toujours la même erreur"

un extrait donc :

[Wed Nov 14 11:10:06 2012] [error] [client xxx.xxx.xx.xx] PHP Notice: Did you remember to make the first column something unique in your call to get_records? Duplicate value '1' found in column 'visible'.<ul style="text-align: left"><li>line 873 of /lib/dml/mysqli_native_moodle_database.php: call to debugging()</li><li>line 1337 of /lib/dml/moodle_database.php: call to mysqli_native_moodle_database->get_records_sql()</li><li>line 1309 of /lib/dml/moodle_database.php: call to moodle_database->get_record_sql()</li><li>line 1288 of /lib/dml/moodle_database.php: call to moodle_database->get_record_select()</li><li>line 4158 of /lib/filelib.php: call to moodle_database->get_record()</li><li>line 38 of /pluginfile.php: call to file_pluginfile()</li></ul> in /var/www/moodle-2.3.1/lib/weblib.php on line 2865, referer: http://icampus.univ-paris3.fr/

donc ça viendrait (si mes yeux sont bons) du cache flags ?!

Cette erreur est apparue le 23 Octobre 2012 à 09:59:00 et persiste depuis

quant aux sauvegardes :

Il existe plusieurs types de sauvegardes:

3.1) Pour l'ensemble du serveur (pas de restriction sur les écritures et les lectures)
- Incrémentales -> Tous les jour sauf samedi : de 20:00 à 21:00
- Totales -> Tous les samedi : de 16:00 à 20:00

3.2) Pour les bases de données :
- Sauvegardes logiques (accès uniquement en lecture, écritures interdites) -> Tous les jours : de 4:24 à 4:30
- Sauvegardes physiques (bases arrêtées, lectures et écritures impossibles) -> Tous les jours : de 1:01 à 1:05

Toutes les sauvegardes s'effectuent avec succès.

donc le cache flag serait (je dis bien serait) le coupable ?!?

avis aux spécialistes

Moyenne des évaluations -

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (détails des erreurs !!)

par Séverin Terrier, mercredi 14 novembre 2012, 21:34

Bonjour,

Je commencerais par :

passer à Moodle 2.3.3

lancer le cron plus souvent qu'uniquement une fois par heure

vérifier à quelle heure se termine chaque cron (et si plusieurs sont exécutés en même temps)

désactiver les statistiques (pour voir si le problème vient de là)

désactiver les sauvegardes automatiques (pour voir si le problème vient de là)

Je pense que cela vient juste après le "cache flags"... vu ce qui est écrit dans le message d'erreur (DELETE FROM mdl_message_read WHERE notification=1 AND timeread...), et je pencherais plutôt pour un souci dans le "Cleaned up read notifications" (nettoyage des notifications de lecture)

En espérant que cela aide, en mettant sur la bonne piste...

Moyenne des évaluations Utile (1)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

par Séverin Terrier, mercredi 14 novembre 2012, 21:43

> depuis qu'on a relancé le cron vers mi-octobre, nous avons des blocages d'accès à la plateforme.

A vrai dire, je n'ai toujours pas bien compris en quoi consiste(nt) le(s) blocage(s), et par qui il est/sont constaté(s) ?

Blocage de l'exécution du cron ? de tout accès à la plateforme, pour tout le monde ? autre (détails) ?

Est-ce que d'autres éléments sont programmés sur ce serveur (au niveau système...) ?

Il semblerait malgré tout que ce soit lié au cron (2 minutes après le début d'exécution), lorsqu'il y a traitement des notifications de lecture (donc pas à chaque exécution)...

Moyenne des évaluations Utile (1)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

par Luiggi Sansonetti, mercredi 14 novembre 2012, 22:01

le blocage --> pas d'accès à la plateforme car on tombe sur le message d'erreur table contexte... puis après 5 minutes et un rafraichissement, hop on est toujous connecté à la bonne page.

c'est pour tout le monde semble-t-il car j'ai constaté, mes collègues aussi et j'ai eu des retours par mails aussi (j'ai fait une vérif sur mon pc et mon smartphone pour voir à un moment où c'était HS) et de n'importe où (j'ai fait du boulot, en wifi, de chez moi...)

d'autres programmes sont actifs (webservice notamment) mais j'attends toujours une réponse de mon autre collègue qui gère les scripts

pour l'instant on a stoppé le cron pour voir justement si ça vient d'ailleurs... et toutes les heures à xxh15 je guette !

après, je vois pas pourquoi (si c'est bien ça) la vérification des notifications bug, j'ai pas vu de trakeur pour la 2.3.1 (ni autre)

edit : si là http://tracker.moodle.org/browse/MDL-35313 pour les assignment View/grade all submissions

Moyenne des évaluations -

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

par Luiggi Sansonetti, vendredi 16 novembre 2012, 19:54

bonjour

on va commenter les lignes 158-160

// Remove expired cache flags
gc_cache_flags();
mtrace(' Cleaned cache flags');

pour voir si ça bloque plus ou juste après...

et un jour on le remettra, mais avant de mettre à jour en 2.3.3, j'aimerai quand même être sûr de l'intégrité de la table (comme j'ai demandé ici https://moodle.org/mod/forum/discuss.php?d=216054 )

j'aurai après d'autres questions de nettoyage mais un autre post s'imposera , là c'est le bug lié au cache_flag et le cron...

merci en tout cas des retours et propositions.

bien à tous.

Moyenne des évaluations -

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

par Séverin Terrier, mardi 20 novembre 2012, 18:42

Hello,

Comme je le disais dans mon précédent message à 14h35, le problème ne doit pas venir du cache flag, étant donné que le cron indique bien que cela vient d'être fait (et pas à faire) : Cleaned cache flags

Moyenne des évaluations Utile (1)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

par Luiggi Sansonetti, mardi 20 novembre 2012, 20:49

bonjour

oui, on a fait ça et on s'est bien aperçu du blocage juste après le cache_flag

ça concerne donc le nettoyage des messages lus

je récupère normalement le fichier error tantôt pour en voir plus...

merci à toi pour la remarque

Moyenne des évaluations -

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

par Pascal Maury, mercredi 21 novembre 2012, 19:10

Bon courage !

Moyenne des évaluations -

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

par Luiggi Sansonetti, vendredi 23 novembre 2012, 01:18

bonsoir

donc oui, c'est bien au niveau

// Cleanup messaging
        if (!empty($CFG->messagingdeletereadnotificationsdelay)) {
            $notificationdeletetime = time() - $CFG->messagingdeletereadnotificationsdelay;
            $DB->delete_records_select('message_read', 'notification=1 AND timeread<:notificationdeletetime', array('notificationdeletetime'=>$notificationdeletetime));
            mtrace(' Cleaned up read notifications');

lignes 163-167

donc à savoir si je peux "manuellement" mettre à jour ces valeurs dans la table pour purger un peu...

j'ai vu le script de Le maire que je testerai demain avant (quand même...)

et donc à suivre

merci à tous.

Moyenne des évaluations -

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

par Séverin Terrier, mercredi 12 décembre 2012, 21:09

Bonjour Luiggi,

Alors, du nouveau concernant tes problèmes liés au cron ?

As tu réussi à les régler ? Si oui, comment ? et sinon, à quel niveau as-tu avancé ?

Séverin

Moyenne des évaluations -

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?) [RESOLU]

par Luiggi Sansonetti, mercredi 12 décembre 2012, 21:57

bonjour

désolé et merci pour la relance, car je suis un peu off (ou en mode "ouf" aussi ) en ce moment...

mon collègue m'a dit :

Vendredi j'ai réussi à purger la table mdl_messaqe_read sur la plateforme test. J'ai modifié le paramètre de MySQL : innodb_buffer_pool_size
De 8 Mo (valeur par défaut), il est passé à 256 Mo.

Dimanche, matin, j'ai effectué la même manipulation sur la plateforme prod mais sans succès car le FileSytem /tmp était trop petit.
Lundi, nous avons augmenté /tmp (de 1Go à 5 Go) et tout s'est déroulé correctement.

Depuis lundi matin, je relance manuellement le cron autant de fois qu'il le faudra pour épurer toutes les notifications en attente.

on a testé les crons simultanés (pour voir si le lancement d'un cron ne bloquait pas le processus du 1er encore en action)

comme ça marchait, on a remis automatiquement tous les quarts d'heures, et pas de blocage... plus de blocage... même avec la ligne décommentée...

donc c'est bien revenu comme avant toutes les 13 minutes.

il faut encore que j'épluche avec mon collègue les derniers fichiers logs des crons pour voir en détails, mais pour l'heure, ça tient.

pour info, on avait plus de 660 000 enregistrements dans la table mdl_message_read en attente...

donc OUF ! cette fois-ci, ça passe...

merci à vous pour les suivi, conseils et relances.

bien à tous

Moyenne des évaluations -

Assistance technique

[2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

[2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (détails des erreurs !!)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (détails des erreurs !!)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?)

Re: [2.3.1] Bug répétitif et ponctuel lié au cron (ou pas ?) [RESOLU]

Empowering educators to improve our world

Moodle

Support

Get Involved

Contributions

Downloads

Tracker

Development

Empowering educators to improve our world