Projet

Général

Profil

Development #31774

ajouter au log d'un appel à un endpoint la réponse produite

Ajouté par Frédéric Péters il y a presque 5 ans. Mis à jour il y a plus de 2 ans.

Statut:
Rejeté
Priorité:
Normal
Assigné à:
Version cible:
-
Début:
27 mars 2019
Echéance:
% réalisé:

0%

Temps estimé:
Patch proposed:
Oui
Planning:
Non

Description

Besoin noté dans #31740, il me semble qu'on pourrait modifier les méthodes de ProxyLogger pour retourner l'objet ResourceLog créé, l'attacher à la requête, et en fin de parcours ajouter dans son .extra le contenu de la réponse.


Fichiers

Historique

#1

Mis à jour par Nicolas Roche il y a plus de 4 ans

  • Assigné à mis à Nicolas Roche
#2

Mis à jour par Nicolas Roche il y a plus de 4 ans

J'ai rencontré des difficultés sur l'enregistrement des réponses en base en rejouant les tests.
En l'état, quand ça ne passe pas je ne logue rien.
  • sur test_family.py
    je peux contourner avec un .decode('utf-8', errors='ignore').encode()
      UnicodeDecodeError: 'utf8' codec can't decode byte 0x93
    
  • sur test_opengis.py
    il s'agit d'une image ; même erreur plus une autre que je n'arrive pas à contourner.

Aussi, j'ai fait apparaître dans le nom de la clé du dictionnaire le fait que la réponse provient du cache et non pas de l'application métier : encore un choix discutable.

#3

Mis à jour par Benjamin Dauvergne il y a plus de 4 ans

Nicolas Roche a écrit :

J'ai rencontré des difficultés sur l'enregistrement des réponses en base en rejouant les tests.
En l'état, quand ça ne passe pas je ne logue rien.
  • sur test_family.py
    je peux contourner avec un .decode('utf-8', errors='ignore').encode()

force_text(..., errors='ignore') lors du log.

[...]
  • sur test_opengis.py
    il s'agit d'une image ; même erreur plus une autre que je n'arrive pas à contourner.

Même avec errors='ignore' ? Dans ce cas fallback sur un chaîne explicative de l'absence des données : '<binary>' ou alors encore une partie en base64 si on juge que ça peut être utile d'avoir un extrait d'un document (m'enfin ça va bien charger les logs).

Aussi, j'ai fait apparaître dans le nom de la clé du dictionnaire le fait que la réponse provient du cache et non pas de l'application métier : encore un choix discutable.

Mouais toujours dans 'response' plutôt que connector_response mais tu peux mettre à coté un 'from_cache': True.

#4

Mis à jour par Nicolas Roche il y a plus de 4 ans

ou alors encore une partie en base64 si on juge que ça peut être utile

Je pensais qu'on pourrait toujours récupérer cette info via les logs simples (def log_http_request),
mais j'avoue que je n'arrive pas à le mettre en évidence.
(du coup je veux bien une piste pour m'orienter dans ce ticket, svp)

#5

Mis à jour par Benjamin Dauvergne il y a plus de 4 ans

Nicolas Roche a écrit :

ou alors encore une partie en base64 si on juge que ça peut être utile

Je pensais qu'on pourrait toujours récupérer cette info via les logs simples (def log_http_request),
mais j'avoue que je n'arrive pas à le mettre en évidence.

Désolé je ne comprends pas ta réponse.

#6

Mis à jour par Nicolas Roche il y a plus de 4 ans

C'est que ce n'est pas clair pour moi non plus (d'ailleurs c'est l'occasion pour moi de voir si j'ai bien compris).
passerelle/utils/_init__.py_:

def log_http_request(logger, ...):    if response is not None:
...
        if logger.level == 10:  # DEBUG
...
                content = response.content[:max_size]
                extra['response_content'] = repr(content)

Je pense que ce code fait déjà ce que demande ce ticket, mais dans les logs "standards" (ie: /var/log/...).
Si vraiment on veux chercher du binaire dans les logs, on peut envisager de ne pas le faire via l'IHM (ie: l'objet de ce ticket)

#7

Mis à jour par Benjamin Dauvergne il y a plus de 4 ans

Nicolas Roche a écrit :

C'est que ce n'est pas clair pour moi non plus (d'ailleurs c'est l'occasion pour moi de voir si j'ai bien compris).
passerelle/utils/_init__.py_:
[...]
Je pense que ce code fait déjà ce que demande ce ticket, mais dans les logs "standards" (ie: /var/log/...).
Si vraiment on veux chercher du binaire dans les logs, on peut envisager de ne pas le faire via l'IHM (ie: l'objet de ce ticket)

Ok, je pense qu'il faut coordonner tout le monde et décider si on veut les mêmes informations dans les logs structuré et dans les logs de resource (je pense d'ailleurs que tout le bordel dans ProxyLogger est inutile on aurait pu s'en sortir avec un handler et un LogWrapper qui met juste la resource dans 'extra', mais soit..).

#8

Mis à jour par Nicolas Roche il y a plus de 4 ans

coordonner tout le monde

Vu ensemble ce lundi, '<binary>' ça passe.

#9

Mis à jour par Valentin Deniaud il y a environ 4 ans

  • Statut changé de Solution proposée à En cours
Quelque chose bloque ce ticket ? Sinon c'est bon pour moi modulo :
  • import UnicodeDecodeError inutile
  • « troncate » dans un commentaire au lieu de « truncate »
  • dans le test, ajouter une petite ligne pas méchante genre '6.172122' in log.extra['response'] pour vérifier qu'on logge bien quelque chose d'intelligible
  • je ne comprends pas le try/except, qu'est-ce qui lie un DataError du fait que les données soient binaires ? Si rien, l'enlever, si quelque chose, faire un test.
  • dans log_http_request qui logge déjà les réponses du logiciel métier, la clé dans extra s'appelle response_content, pourquoi pas suivre cela
  • je ne suis pas fan de définir une fonction locale vs une nouvelle méthode, parce que perform() est déjà beaucoup trop longue, mais peut-être que c'est que moi
  • en tant que non expert en encodage je ne trouve pas ça clair de passer value dans str puis dans force_text, je serai plus rassuré si on utilisait que force_text
  • et vérifier que les tests passent en python3.
#10

Mis à jour par Nicolas Roche il y a environ 4 ans

Remarques prises en compte dans le patch.

dans le test, ajouter une petite ligne pas méchante genre '6.172122' in log.extra['response'] pour vérifier qu'on logge bien quelque chose d'intelligible

ici je logue la réponse ('6.172122' fait parti des paramètres de la requête)

assert eval(log.extra['response'])['data']['text'] == 'HAUSSONVILLE / BLANDAN / MON DESERT / SAURUPT'

je ne comprends pas le try/except, qu'est-ce qui lie un DataError du fait que les données soient binaires ? Si rien, l'enlever, si quelque chose, faire un test.

cf https://dev.entrouvert.org/issues/31774#note-2
sur test_family.py et test_opengis.py, l'enregistrement d'une image plante en base de donnée.

dans log_http_request qui logge déjà les réponses du logiciel métier, la clé dans extra s'appelle response_content, pourquoi pas suivre cela

fait, j'ai aussi ajouté le statut et les en-têtes.

en tant que non expert en encodage je ne trouve pas ça clair de passer value dans str puis dans force_text, je serai plus rassuré si on utilisait que force_text

il s'agit de l'appel à "__str__" sur l'objet HttpResponse ou sur un dictionnaire si la requête est en cache.

#11

Mis à jour par Frédéric Péters il y a environ 4 ans

En fait, une fois qu'on a #38157 (la possibilité d'afficher tous les logs liés à une requête), il n'y a plus vraiment d'intérêt à ce ticket, je pense.

#12

Mis à jour par Valentin Deniaud il y a environ 4 ans

  • Statut changé de Solution proposée à En cours

Je trouve quand même ça sympa d'avoir des logs les plus complets possibles.
En plus j'aime bien la tête qu'a le patch maintenant, reste que si en raison du loglevel l'objet ResourceLog n'est pas créé, on va se retrouver à faire resource_log.log_response avec resource_log qui est à None et ça va planter.

#13

Mis à jour par Frédéric Péters il y a environ 4 ans

Je trouve quand même ça sympa d'avoir des logs les plus complets possibles.

Oui mais tout ne doit pas(plus) nécessairement être dans le même objet, si on a une ligne de log avec la réponse, avec le même transaction_id, on peut y aller, on a tout, sans duplication ici, sans ce truc quand même bizarre de revenir après coup sur une ligne de log.

Et à nouveau je partais de l'idée qu'on avait déjà ce log de la réponse, si ce n'est pas/plus le cas (peut-être parce qu'on retire le logging de to_json, peut-être pour autre chose), je suis bien sûr pour logguer la réponse.

#14

Mis à jour par Valentin Deniaud il y a environ 4 ans

Ce qu'on logge ici n'est jamais loggé nulle part, il s'agit du json que renvoie un endpoint, sinon ce qu'on logge déjà c'est la réponse du logiciel métier. Le logging dans to_json logge aussi à ce niveau là, mais que en cas d'erreur, donc jamais la réponse.

sans ce truc quand même bizarre de revenir après coup sur une ligne de log

C'est vrai qu'on aurait pu choisir d'en ajouter une, c'est fonction de ce qui paraît le plus clair dans l'interface.

#15

Mis à jour par Frédéric Péters il y a environ 4 ans

Je suis plutôt pour ajouter une ligne, pour ne pas avoir à modifier toutes les méthodes de log pour retourner l'objet, et pour offrir une chronologie lisible des moments de l'appel.

#16

Mis à jour par Nicolas Roche il y a plus de 2 ans

  • Statut changé de En cours à Rejeté

Vu la description : "modifier les méthodes de ProxyLogger pour retourner l'objet ResourceLog créé", en fait ce path n'est pas souhaitable.

Je rejette car le besoin énoncé dans le ticket lié "Logging des réponses (payload) des requêtes aux webservices (de WCS vers Passerelle)"
y trouve sa résolution :

si c'est du JSON et que l'appel webservice dans w.c.s. contient un identifiant, il sera enregistré de ce côté là"

#17

Mis à jour par Frédéric Péters il y a plus de 2 ans

Surtout il y a eu #38157 et un bouton qui permet de voir la liste des appels liés.

Formats disponibles : Atom PDF