Produits Entr'ouvert » Hobo

J'ai été un peu vite, ça viendrait contrarier ce qui a été mis en place dans #7906.

On pourrait très bien remplacer tout ce que j'ai fait dans #7906 par le filtre django.utils.log.RequireDebugTrue sur un handler spécial "debug".

Juste pour clarifier ce qui est attendu, du moins par moi: actuellement quand on a DEBUG=True, on se retrouve avec les log de niveau debug, mais ça ne devrait pas être lié. DEBUG=True devrait rester uniquement dans son rôle d'afficher des traces à l'écran (et autres messages par ci par là), mais les log devraient rester en mode INFO par défaut. On aurait à trouver un autre settings (genre settings.LOG_LEVEL ?) pour permettre de forcer le niveau de log sur un tenant particulier, via son settings.json, pendant une phase de diagnostic.

Thomas Noël a écrit :

Juste pour clarifier ce qui est attendu, du moins par moi: actuellement quand on a DEBUG=True, on se retrouve avec les log de niveau debug, mais ça ne devrait pas être lié. DEBUG=True devrait rester uniquement dans son rôle d'afficher des traces à l'écran (et autres messages par ci par là), mais les log devraient rester en mode INFO par défaut. On aurait à trouver un autre settings (genre settings.LOG_LEVEL ?) pour permettre de forcer le niveau de log sur un tenant particulier, via son settings.json, pendant une phase de diagnostic.

• DEBUG_LOG=False : le filtre bloque tout ce qui est au niveau DEBUG ou moins
• DEBUG_LOG=True : le filtre laisse passer tout ce qui est au niveau DEBUG ou moins
• DEBUG_LOG="authentic2" : le filtre laisse passer tous ce qui est au niveau DEBUG ou moins pour les domaines "authentic2.*"
• DEBUG_LOG="authentic2,django" : le filtre laisse passer tous ce qui est au niveau DEBUG ou moins pour les domaines "authentic2*" ou "django.*"

Pour reprendre des remarques récentes de Fred ça pourrait utilement être géré depuis hobo via un écran dédié.

Quand à DEBUG=True, je serai assez pour avoir un setting DEBUG_IP="<ip1> <ip2>", idem géré par hobo (je clique sur activate debug et ça ajoute mon ip cliente dans le truc), et avoir un middleware qui quand il voit l'IP pose DEBUG=True pour la durée de la requête.

Bon je vais faire des tickets au lieu de tout polluer.

Pour revenir au ticket, Emmanuel ce que tu modifies n'a pas d'effet sur le code de #7906, juste qu'il ne servira à rien si il n'y a plus aucun handler de niveau DEBUG, alors go si tu veux (mais les gens vous ne verrez plus les logs de debug pendant un moment).

Renommage de DEBUG_IP en INTERNAL_IPS ce qui nous donne le supporte de django-debug-toolbar au passage.

Benjamin Dauvergne a écrit :

Rebasé suite au push de #29240, j'ai juste un doute sur InternalIPMiddleware, j'ai un peu peur que DEBUG reste à True en cas d'exception; je ne vois pas vraiment comment faire mieux sans les middleware moderne de Django 1.11 basés sur une fonction recevant un get_response() en paramètre.

Non en fait ça devrait aller process_response() est toujours appelé.

Désolé de demander ça, mais à l'occasion, est-ce que tu pourrais rebaser (pour me donner une chance de relire) ?

Je n'ai pas traité cet aspect du problème :

Parce que ça s'adresse au développeur qui devrait lire ça sur son terminal, pas à un fichier de log qui va se remplir sans lecteur.

Entre le titre du ticket qui a changé et 80% de se description du ticket qui n'est pas traitée, on pourrait s'interroger sur le rapport entre le travail fait ici et la situation initiale.

Pour reprendre, donc, la situation initiale c'est DEBUG=True posé sur la recette, qui amenait à avoir des logs chargés de mille choses, et plus d'espace disque. Et je posais comme idée que les logs de debug étaient juste utiles sur le moment, qu'ils pouvaient défiler sur un terminal, suivis à un moment précis (et pas réunis par milliers dans des fichiers).

La partie de pas logguer en debug, elle doit être arrivée dans #29240, ok.

Et ce ticket gère l'autre côté, avoir un endroit qui puisse être consulté sur le moment (tail -f /var/log/authentic2/debug).

Ni du patch ni du commentaire de Nicolas je n'arrive à dire si ce fichier de log contiendra tous les niveaux, ou uniquement le niveau debug, et je dirais qu'avoir tous les niveaux pourraient être utiles, les niveaux supérieux pouvant quand même aider à suivre, mais peu importe.

Frédéric Péters a écrit :

Pour reprendre, donc, la situation initiale c'est DEBUG=True posé sur la recette, qui amenait à avoir des logs chargés de mille choses, et plus d'espace disque. Et je posais comme idée que les logs de debug étaient juste utiles sur le moment, qu'ils pouvaient défiler sur un terminal, suivis à un moment précis (et pas réunis par milliers dans des fichiers).

Oui c'est exactement ce qui est fait ici.

La partie de pas logguer en debug, elle doit être arrivée dans #29240, ok.

#29240 c'est pour contrôler les settings DEBUG_LOG et INTERNAL_IPS depuis le BO d'hobo.

Et ce ticket gère l'autre côté, avoir un endroit qui puisse être consulté sur le moment (tail -f /var/log/authentic2/debug).

Oui ça c'est fait mais il y aussi le fait d'activer DEBUG à la volée en fonction de INTERNAL_IPS, c'était l'autre aspect.

Ni du patch ni du commentaire de Nicolas je n'arrive à dire si ce fichier de log contiendra tous les niveaux, ou uniquement le niveau debug, et je dirais qu'avoir tous les niveaux pourraient être utiles, les niveaux supérieux pouvant quand même aider à suivre, mais peu importe.

Oui c'est exactement ce qui est fait ici, c'est un log classique on a tout à partir de DEBUG.

Oui c'est exactement ce qui est fait ici.

Oui mon commentaire était pour pointer que malgré la distance qui pouvait être sentie entre la réalisation et le ticket initial, ça correspondait bien.

• quand on a bool(settings.*DEBUG_LOG*) est vrai on log dans /var/log/brique/debug.log au niveau DEBUG et supérieur,
  (d'après les commentaires par exemple : '''Filter debug log records based on the DEBUG_LOG setting''')

Et j'en profite pour indiquer à nouveau que les deux mécanismes (traces HTML et logs dans fichier debug) sont à présent décorélés.

Nicolas Roche a écrit :

Et j'en profite pour indiquer à nouveau que les deux mécanismes (traces HTML et logs dans fichier debug) sont à présent décorélés.

Oui, c'était un des objectifs effectivement.

Le middleware 'InternalIPMiddleware' ne fonctionne toujours pas chez moi.
Cf https://dev.entrouvert.org/issues/29149#note-20, si je le déplace à côté de 'RobotsTxtMiddleware' ça fonctionne.

"user", qui apparaît dans les logs de niveau DEBUG, n'apparaît pas dans les log de niveau supérieur (INFO, ERROR).
Dans ces niveaux, RequestContextFilter est exécuté 2 fois, avec à la seconde fois la variable user "délazifiée".

L'ajout du parseur DebugLog dans le premier patch, et le 3ème patch de la branche, c'est bien pour le point 4 ?
https://dev.entrouvert.org/issues/29149#note-25

Nicolas Roche a écrit :

Le middleware 'InternalIPMiddleware' ne fonctionne toujours pas chez moi.
Cf https://dev.entrouvert.org/issues/29149#note-20, si je le déplace à côté de 'RobotsTxtMiddleware' ça fonctionne.

J'avais oublié, c'est fait, branche à jour.

"user", qui apparaît dans les logs de niveau DEBUG, n'apparaît pas dans les log de niveau supérieur (INFO, ERROR).
Dans ces niveaux, RequestContextFilter est exécuté 2 fois, avec à la seconde fois la variable user "délazifiée".

J'ai sorti le filtre request_context des handlers pour le mettre au niveau du logger racine, il ne devrait s'exécuter qu'une fois désormais (mais ça rend un peu la configuration des handlers dépendant du logger) :

diff --git debian/debian_config_common.py debian/debian_config_common.py
index 553a1b6..6f0dcae 100644
--- debian/debian_config_common.py
+++ debian/debian_config_common.py
@@ -90,7 +90,6 @@ LOGGING = {
             'address': '/dev/log',
             'class': 'logging.handlers.SysLogHandler',
             'formatter': 'syslog',
-            'filters': ['request_context'],
         },
         'syslog_no_filter': {
             'level': 'INFO',
@@ -111,7 +110,7 @@ LOGGING = {
             'when': 'midnight',
             'backupCount': 1,
             'interval': 1,
-            'filters': ['request_context', 'debug_log'],
+            'filters': ['debug_log'],
         }
     },
     'loggers': {
@@ -169,6 +168,7 @@ LOGGING = {
         },
         '': {
             'level': 'DEBUG',
+            'filters': ['request_context'],
             'handlers': ['syslog', 'mail_admins', 'debug'],
         },
     },

L'ajout du parseur DebugLog dans le premier patch, et le 3ème patch de la branche, c'est bien pour le point 4 ?
https://dev.entrouvert.org/issues/29149#note-25

Dans le patch 0001 c'est surtout pour pouvoir faire des tests qui justifient mon format de log ; le 0003 c'est un goodies si on voulait afficher tout ça quelque part; ça peut ne pas être commité pour le faire correctement plus tard.

Je viens de rajouter un commit pour déprécier SettingsLogLevel, tant qu'à faire retirons du code.

Encore un nouveau commit pour prévenir plusieurs exécutions de RequestContextFilter, et je l'ai remis dans la configuration des handlers parce qu'à cause de leur chaîne de formatage ils en sont fortement dépendant.

Je n'ai pas réussi à exploiter la vue DebugLogView dans les briques, parce que settings.INTERNAL_IPS ne renvoit rien,
mais sinon j'ai relu.

Nicolas Roche a écrit :

Je n'ai pas réussi à exploiter la vue DebugLogView dans les briques, parce que settings.INTERNAL_IPS ne renvoit rien,
mais sinon j'ai relu.

Je vais virer DebugLogView et en faire un ticket à part; mais settings.INTERNAL_IPS qui ne renvoie rien, que veux-tu dire par là ?

PS: DebugLogView retiré sur la branche.

Je n'ai pas réussi à exploiter la vue DebugLogView dans les briques

Suite à un second essai, je constate qu'en fait ça fonctionne très bien.
Pour info, j'ai copié le template donné en exemple dans combo/public/templates/debug_log.html et j'ai modifié combo/urls.py :

from hobo.logger import DebugLogView
...
urlpatterns = [
    ...
    url(r'^log/$', DebugLogView.as_view(template_name='debug_log.html', paginate=10)),
]

j'ai lu et testé, ça me semble ok, il y a encore des bouts que je n'ai pas compris, je validerais demain une fois ceux-ci investigués.

dans a41ccf5 il y a ce commentaire en trop :

+ # add space after newlines to reconstruct message when reading
+ # debug.log

je ne comprends pas encore 'request_context' et ff72e25.

Peux-tu m'expliquer ce bout, quand/comment est-ce que RequestContextFilter est appellé plusieurs fois?

+        # prevent multiple execution on the same record
+        if getattr(record, 'request_context', False):
+            return True

Par ailleurs, pour être certain que je comprends bien :

• les fichiers debug contiennent les logs de niveau debug et au dessus? * InternalIPMiddleware active DEBUG quand l'adresse IP est listée dans internal_ips, même quand la boîte debug_log est décochée?

Christophe Siraut a écrit :

Peux-tu m'expliquer ce bout, quand/comment est-ce que RequestContextFilter est appellé plusieurs fois?

[...]

Si c'est mal configuré, par exemple si le filtre est posé à la fois sur le logger et le handler.

Par ailleurs, pour être certain que je comprends bien :

• les fichiers debug contiennent les logs de niveau debug et au dessus?

Oui.

• InternalIPMiddleware active DEBUG quand l'adresse IP est listée dans internal_ips, même quand la boîte debug_log est décochée?

Oui ça n'a rien à voir en fait, ça active l'affichage des traces dans le navigateur. ça s'est retrouvé dans le même ticket pare que j'avais fait tout ça dans un même élan avec l'interface de gestion des options de debug dans hobo. On peut en faire un autre ticket ou le garder là, c'est la suite de #29240.

Faut pas pousser ça la semaine de mise en prod :/

Et encore moins tagguer derrière.

On est mardi, 2j ça suffit largement à tester ça en recette, sachant que le code a été relu 100 fois.

PS: et des trucs on été taggé hier donc je ne comprends pas la différence.

On est mardi, 2j ça suffit largement à tester ça en recette, sachant que le code a été relu 100 fois.

Mais le code n'est pas encore en recette, parce que pousser/tagguer/oublier merci. Résultat je dois m'en préoccuper et j'avais peut-être autre chose de prévu. Et l'idée est d'avoir un principe simple qui évite comme ça des après-midis où je dois chasser les possibles bugs, pas un principe sur mesure "le code a vraiment bien été relu, tapons ça à l'arrache".

PS: et des trucs on été taggé hier donc je ne comprends pas la différence.

La question n'est pas de tagger mais d'ajouter des nouvelles fonctionnalités; les trucs limite c'est #24397 et #41792, côté authentic, qui avaient été poussés et où il a bien fallu que je passe derrière pour traduire/déployer.

Et in fine, je fais tout ce taf de préparation des mises à jour, j'y ai besoin de structure, c'est tout à fait pénible que tu t'en contrefiches.