le module Logging et relativeCreated

**rosty38** · 15/10/2010, 10h58

Bonjours,
sa fait 2 jours que j'essaie de trouver une solution a mon problème sans succès.
je souhaite créer un fichier log , mais avec un format dateTime relative. pour avoir ce resultat:

08:41:59.328: Thu Oct 14 08:41:59 2010
+0.000: Initializing test engine
+0.000: Log file='toto.log'
+0.000: Starting Tester on COM50
+0.000: Starting Rx thread
+0.000: Starting Tx thread
+0.000: Executing command: verbose(level=10)
+0.000: Verbosity level 10

+1.687: Executing command: ping()
+0.000: --> Send len=5, crc=0x20
+0.031: <-- Recv len=7, crc=0xBE

+7.954: Executing command: ieee(node=0xFFFF)
+0.000: --> Send len=15, crc=0x68
+0.030: <-- Recv len=6, crc=0x64
+0.016: <-- Recv len=8, crc=0x0D
+0.359: <-- Recv len=30, crc=0x36
+0.032: <-- Recv len=30, crc=0x87

j'ai utilisé ce script:

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
 
LOGFILE = "test_toto.log"
loglev = logging.DEBUG # debug and logging.DEBUG or logging.INFO
print "startTime"
print logging._startTime
 
logfmt = "%(relativeCreated)f.%(msecs)03d: %(message)s"
 
logging.basicConfig(level=loglev,
                        format=logfmt,
                        datefmt="%H:%M:%S",
                        filename=LOGFILE, filemode='wb')
# Add console output to stdout for the time being
conlog = logging.StreamHandler(sys.stdout)
conlog.setFormatter(logging.Formatter("%(message)s"))
 
log = logging.getLogger("test_toto")
log.addHandler(conlog)
print logging.time
log.info("%s" % time.asctime())
#llname = logging.getLevelName(loglev)
log.debug("Log file='%s'" % LOGFILE)

sans succès car "relativeCreated" est calculer par rapport a StartTime et non pas par rapport a la commande précédente .
d'après ce que j'ai vue , "relativeCreated" est une clé de dictionnaire, peut on changer sa valeur ??
merci

**wiztricks** · 15/10/2010, 12h31

Salut,

La variable relativeCreated se rapporte au chargement du module logging.
Et plus généralement, les lignes expédiées dans le log sont indépendantes les unes des autres: il n'y a pas de mémoire.

Je ne pense pas qu'il soit "intelligent" de changer la structure du fichier log: il est bon de garder des timestamps croissants avec les informations associées.
Par contre, vous pouvez intercaler des informations contextuelles "entre", i.e.
passer de d'un format:
"%(asctime)-15s %(name)-5s %(levelname)-8s %(message)s"
à une ligne dans laquelle vous insérez ce que j'ai appelé "chrono".
"%(asctime)-15s chrono: %(seconds)-3s %(name)-5s %(levelname)-8s %(message)s"

Avec ce qui dans la documentation s'appelle "context filter".
La documentation donne un exemple ou les informations sont "statiques".
Mais le filter est une classe. L'instance pourra être initialisée avec la date courante pour qu'a chaque appel on retourne le delta.
Il doit certainement y avoir d'autres méthodes.
Exemple:

Code Python :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
import logging
from random import choice
from time import time
 
class MyFilter(logging.Filter):
    def __init__(self):
        self._start = time()
        super(MyFilter, self).__init__()
 
    def filter(self, record):
        record.seconds = '%.2f Ms' % ((time() - self._start) * 1000)
        return True
 
    def restart(self):
        self._start = time()
 
 
 
if __name__ == "__main__":
   levels = (logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR, logging.CRITICAL)
 
   def log_messages(count):
       for x in range(count):
           lvl = choice(levels)
           lvlname = logging.getLevelName(lvl)
           log.log(lvl, "A message at %s level" % lvlname)
 
   logging.basicConfig(level=logging.DEBUG,
                       format="%(asctime)-15s %(name)-5s %(levelname)-8s [ %(seconds)-4s ] %(message)s")
   log = logging.getLogger("a.b.c")
   timer_filter = MyFilter()
   log.addFilter(timer_filter)
   log_messages(5)
   timer_filter.restart()
   log_messages( 5)

En sortie, ca donne:

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
7
8
9
10
2010-10-15 14:15:11,640 a.b.c WARNING  [ 0.59 Ms ] A message at WARNING level
2010-10-15 14:15:11,641 a.b.c DEBUG    [ 1.63 Ms ] A message at DEBUG level
2010-10-15 14:15:11,646 a.b.c DEBUG    [ 6.84 Ms ] A message at DEBUG level
2010-10-15 14:15:11,647 a.b.c INFO     [ 7.76 Ms ] A message at INFO level
2010-10-15 14:15:11,648 a.b.c ERROR    [ 8.69 Ms ] A message at ERROR level
2010-10-15 14:15:11,649 a.b.c INFO     [ 0.49 Ms ] A message at INFO level
2010-10-15 14:15:11,650 a.b.c INFO     [ 1.44 Ms ] A message at INFO level
2010-10-15 14:15:11,651 a.b.c DEBUG    [ 2.38 Ms ] A message at DEBUG level
2010-10-15 14:15:11,652 a.b.c INFO     [ 3.35 Ms ] A message at INFO level
2010-10-15 14:15:11,653 a.b.c INFO     [ 4.29 Ms ] A message at INFO level

- W