Development #57604
suivi global exécution cron
0%
Description
Avoir un log global de l'exécution des crons, la motivation principale étant de comprendre/débugger des situations comme "il est mis 20 minutes mais ça s'est exécuté deux heures plus tard, genre #57145).
2021-05-10 15:07:00 starting cron (minutes offset is 23) (<-- ord(settings.SECRET_KEY[-1])) % 60) 2021-05-10 15:07:02 [tenant XXX] start 2021-05-10 15:07:12 [tenant YYY] start 2021-05-10 15:09:52 [tenant YYY] long job: evaluate_jumps (took 2 minutes)
en anticipant déjà un peu je me dis aussi que ça serait utile d'avoir de l'info un peu plus profonde, genre :
2021-05-10 15:09:52 [tenant YYY] evaluate_jumps: running on "formdef/carddef + url_name" took 2 minutes
histoire de ne pas charger en lignes inutiles, inclure seulement les moments dont la durée dépasse un seuil (on peut commencer à 2 minutes et affiner après selon ce qu'on verra).
Fichiers
Révisions associées
misc: more logs for some cron jobs (#57604)
Historique
Mis à jour par Lauréline Guérin il y a plus de 2 ans
- Fichier 0002-misc-more-logs-for-some-cron-jobs-57604.patch 0002-misc-more-logs-for-some-cron-jobs-57604.patch ajouté
- Fichier 0001-misc-add-log-mecanism-for-cron-jobs-57604.patch 0001-misc-add-log-mecanism-for-cron-jobs-57604.patch ajouté
- Statut changé de Nouveau à Solution proposée
- Patch proposed changé de Non à Oui
proposition
comme il s'agit d'un log global, et non d'un log par tenant, j'ai opté pour un logger générique "wcs.cron", mais sans grande conviction
Mis à jour par Frédéric Péters il y a plus de 2 ans
Perso j'ai toujours bien du mal avec logging et comment ça se configure mal (je trouve), on peut faire avec mais qu'il y ait en début d'exécution la configuration du logging pour de forcer taper quelque chose qui serait
'class': 'logging.handlers.TimedRotatingFileHandler', 'filename': '/var/lib/wcs/logs/cron.log', 'when': 'w0',
pour rendre la configuration indépendante de ce qui pourrait arriver via une configuration de LOGGING ?
Ça me va alternativement de faire totalement sans logging, avec juste
+ def log(self, message): + self.logger.info('[tenant %s] %s', get_publisher().tenant.hostname, message)
transformé pour faire
with open(..., 'a+') as fd: fd.write('la date et le tenant et le message\n')
Mis à jour par Benjamin Dauvergne il y a plus de 2 ans
Frédéric Péters a écrit :
Perso j'ai toujours bien du mal avec logging et comment ça se configure mal (je trouve), on peut faire avec mais qu'il y ait en début d'exécution la configuration du logging pour de forcer taper quelque chose qui serait
Juste un disclaimer : on a un TimedRotatingHandler maintenant pour les logs /var/log/brique/debug, je l'ai utilisé récemment pour débugger l'authentification OIDC sur l'instance intranet du GL (#57517), et ça marche très bizarrement avec uwsgi, la rotation du fichier est faite par un peu n'importe quel worker, donc on se retrouve avec un worker loggant vers debug
et un autre vers debug.2021-10-11
. Je déconseille vraiment, le plus sûr/simple ça reste de balancer ça sur stdout pour systemd (sans timestamp systemd/syslog l'ajouteront).
PS: et si /var/lib/wcs et sur un NFS c'est encore pire, le mode append ne marche pas avec NFS (et si besoin le soutien de SO https://stackoverflow.com/questions/41559260/djangouwsgi-logging-with-timedrotatingfilehandler-overwrites-rotated-log-file).
Mis à jour par Frédéric Péters il y a plus de 2 ans
Juste un disclaimer (...)
(on est sur un cron qui s'exécute sur un seul nœud et pas via uwsgi).
Mis à jour par Lauréline Guérin il y a plus de 2 ans
- Statut changé de Solution proposée à En cours
Mis à jour par Lauréline Guérin il y a plus de 2 ans
- Fichier 0002-misc-more-logs-for-some-cron-jobs-57604.patch 0002-misc-more-logs-for-some-cron-jobs-57604.patch ajouté
- Fichier 0001-misc-add-log-mecanism-for-cron-jobs-57604.patch 0001-misc-add-log-mecanism-for-cron-jobs-57604.patch ajouté
- Statut changé de En cours à Solution proposée
Solution alternative à base de fichiers.
La date dans le nom du ficher et pour chaque log est en UTC.
Mis à jour par Frédéric Péters il y a plus de 2 ans
Ça m'irait qu'on utilise l'heure locale, ça sera plus simple à comparer avec ce qu'on voit dans l'ui.
if 'job' in inspect.getfullargspec(job.function).args:
Je serais pour ajouter des **kwargs partout et ne pas ainsi avoir besoin d'utiliser inspect. (désolé ici je m'étais déjà fait cette remarque et j'avais oublié de l'écrire).
CRON_LOG_FILENAME = '/var/lib/wcs/cron.log'
Il faudrait ne pas mettre ça ainsi et se baser sur WcsPublisher.APP_DIR. (je me suis dit 2 minutes que l'erreur jenkins venait peut-être de là mais sans doute que non).
Mis à jour par Lauréline Guérin il y a plus de 2 ans
je me suis dit 2 minutes que l'erreur jenkins venait peut-être de là
très probablement, mais je n'avais pas eu le temps de creuser encore :)
Mis à jour par Frédéric Péters il y a plus de 2 ans
- Statut changé de Solution proposée à Résolu (à déployer)
Validé poussé,
commit b3c957c071894c96fce700ec6c9cbab28f2139ea Author: Lauréline Guérin <zebuline@entrouvert.com> Date: Mon Oct 11 17:59:15 2021 +0200 misc: more logs for some cron jobs (#57604) commit 75727642c1e37b7af1b20d2ff1873e8c84fc1097 Author: Lauréline Guérin <zebuline@entrouvert.com> Date: Mon Oct 11 15:15:57 2021 +0200 misc: add log mecanism for cron jobs (#57604)
Mis à jour par Frédéric Péters il y a plus de 2 ans
- Statut changé de Résolu (à déployer) à Solution déployée
misc: add log mecanism for cron jobs (#57604)