[Dynamo+=Python] Débogage - le module logging (partie 2/2 pratique)

 

Voici quelques exemples d'implémentation d'un logger dans Dynamo (Python)

if this article is not in your language, use the Google Translate widget (bottom of page for Mobile version)⬈

Comme exemple nous allons prendre ce code

import clr
import sys
import System
clr.AddReference('ProtoGeometry')
from Autodesk.DesignScript.Geometry import *
import Autodesk.DesignScript.Geometry as DS

clr.AddReference('RevitAPI')
import Autodesk
from Autodesk.Revit.DB import *
import Autodesk.Revit.DB as DB

from System.Collections.Generic import List
clr.AddReference('RevitNodes')
import Revit
clr.ImportExtensions(Revit.GeometryConversion)

#import transactionManager and DocumentManager (RevitServices is specific to Dynamo)
clr.AddReference('RevitServices')
import RevitServices
from RevitServices.Persistence import DocumentManager
from RevitServices.Transactions import TransactionManager
doc = DocumentManager.Instance.CurrentDBDocument


class MyRoomUtils():
	def __init__(self, doc):
		self._doc = doc
		
	def GetProtoRoomSolid(self):
		"""
		return a dictionnary Rooms
		"""
		DS_Solid = []
		calculator = SpatialElementGeometryCalculator(self._doc)
		fecRoom = FilteredElementCollector(self._doc).OfCategory(BuiltInCategory.OST_Rooms).WhereElementIsNotElementType().ToElements()
		for room in fecRoom:
			edgeBoundaries = []
			results = calculator.CalculateSpatialElementGeometry(room)
			roomSolid = results.GetGeometry()
			DS_Solid.append(roomSolid.ToProtoType())		
			
		return DS_Solid
		
ObjR_util = MyRoomUtils(doc)

OUT = ObjR_util.GetProtoRoomSolid()

mais voilà lorsqu'on exécute le script.... 

En gros on a une ou plusieurs pièces qui ont un souci dans le projet.

Plutôt que de rediriger l'erreur (ou les pièces qui pose problème) vers la variable OUT on va utiliser un logger 

a la fin de votre script Python ou le dernier script Python penser à mettre fin aux loggers avec la méthode statique du package logging

  
# python 2 and 3  carrefully shutdown all loggers
logging.shutdown()
# or
# python 3
logger.handlers.clear() 
# or
# python2.7 and 3
try:
    for handler in logger.handlers:
        if isinstance(handler, logging.FileHandler):
            handler.close()
except:
    for handler in logger.handlers[:]:
        logger.removeHandler(handler)
    

 

Plusieurs exemples d'implémentation : 

• le cas ou votre fonction est dans un nœud Python Dynamo

on définit le logger directement dans le nœud Python:

#
# ⊞imports clr, modules, Revit API, Dynamo API and set importants Variables...
#
my_path = System.Environment.GetFolderPath(System.Environment.SpecialFolder.MyDocuments)
pf_path = System.Environment.GetFolderPath(System.Environment.SpecialFolder.ProgramFilesX86)
sys.path.append(pf_path + '\\IronPython 2.7\\Lib')

import logging
from logging.handlers import RotatingFileHandler
import traceback

## Start create logger Object ##
logger = logging.getLogger("PizzaLogger")
# set to  DEBUG
logger.setLevel(logging.DEBUG)
formatter = logging.Formatter('%(asctime)s :: %(levelname)s :: %(funcName)s :: %(process)d :: %(message)s')
# create handler 
file_handler = RotatingFileHandler(my_path + '\\debug.log', mode='a', maxBytes=100000, backupCount=1)
file_handler.setLevel(logging.DEBUG)
file_handler.setFormatter(formatter)
logger.addHandler(file_handler)
logger.disabled = False


class MyRoomUtils():
    def __init__(self, doc):
        self._doc = doc
        
    def GetProtoRoomSolid(self):
        DS_Solid = []
        calculator = SpatialElementGeometryCalculator(self._doc)
        fecRoom = FilteredElementCollector(self._doc).OfCategory(BuiltInCategory.OST_Rooms).WhereElementIsNotElementType().ToElements()
        for room in fecRoom:
            try:
                results = calculator.CalculateSpatialElementGeometry(room)
                roomSolid = results.GetGeometry()
                DS_Solid.append(roomSolid.ToProtoType())    
            except Exception as ex:
                # catch the traceback
                # BAD METHOD ↓
                # logger.error(traceback.format_exc())
                # BETTER METHOD ↓
                logger.exception(ex)
                # get somes informations of room and put them into a dictionary
                logger.info("get infos from room")
                dictRoomDataFail = {"Id" :room.Id, "Name": Element.Name.GetValue(room), "volume": room.Volume, "Area" : room.Area}  
                logger.debug(dictRoomDataFail)  
                        
        return DS_Solid
        
ObjR_util = MyRoomUtils(doc)
#logging.shutdown()
for handler in logger.handlers[:]:
	logger.removeHandler(handler)
OUT = ObjR_util.GetProtoRoomSolid()

le résultat du log

• le cas ou votre fonction est dans un module Python (fichier .py)

on définit le logger avec un nom "PizzaLogger" 

#
# ⊞imports clr, modules, Revit API, Dynamo API and set importants Variables...
#
my_path = System.Environment.GetFolderPath(System.Environment.SpecialFolder.MyDocuments)
pf_path = System.Environment.GetFolderPath(System.Environment.SpecialFolder.ProgramFilesX86)
sys.path.append(pf_path + '\\IronPython 2.7\\Lib')
sys.path.append(r'C:\Users\sneep\OneDrive\Documents\SharpDevelop Projects\MyCollector\MyCollector')
import logging
import traceback
# workaround to force to reload module
if "MyCollector_v2" in sys.modules:
    del sys.modules["MyCollector_v2"]
import MyCollector_v2

## Start create logger Object ##
logger = logging.getLogger("PizzaLogger")
# set to  DEBUG
logger.setLevel(logging.DEBUG)
formatter = logging.Formatter('%(asctime)s :: %(levelname)s :: %(funcName)s :: %(message)s')
# create handler 
file_handler = logging.FileHandler(my_path + '\\MyCollector.log', mode='w')
file_handler.setLevel(logging.DEBUG)
file_handler.setFormatter(formatter)
logger.addHandler(file_handler)
logger.disabled = False

objRoomUtils = MyCollector_v2.MyRoomUtils(doc)

OUT = objRoomUtils.GetProtoRoomSolid()

puis dans le fichier python .py on fait juste un rappel du logger avec la méthode logging.getLogger("PizzaLogger") cela évite d'avoir à se trimbaler la référence du logger 

  

#
# ⊞imports clr, modules, Revit API, Dynamo API and set importants Variables...
#
import traceback
import logging

class MyRoomUtils():
    def __init__(self, doc):
        self._doc = doc
        self.logger = logging.getLogger("PizzaLogger")
        self.logger.info( "MyRoomUtils instance created")
        
    def GetProtoRoomSolid(self):
        DS_Solid = []
        calculator = SpatialElementGeometryCalculator(self._doc)
        fecRoom = FilteredElementCollector(self._doc).OfCategory(BuiltInCategory.OST_Rooms).WhereElementIsNotElementType().ToElements()
        for room in fecRoom:
            try:
                results = calculator.CalculateSpatialElementGeometry(room)
                roomSolid = results.GetGeometry()
                DS_Solid.append(roomSolid.ToProtoType())
            except Exception as ex:
                # BAD METHOD ↓
                # self.logger.error(traceback.format_exc())
                # BETTER ↓
                logger.exception(ex)
                self.logger.info("get infos from room")
                dictRoomDataFail = {"Id" :room.Id, "Name": Element.Name.GetValue(room), "volume": room.Volume, "Area" : room.Area}  
                self.logger.debug(dictRoomDataFail)         

        return DS_Solid
#logging.shutdown()
for handler in logger.handlers[:]:
	logger.removeHandler(handler)
  

• le cas ou vous souhaiter utiliser le logger entre plusieurs nœuds Python Dynamo
  
  comme chaque nœud Python est exécuté par une instance du moteur Python, il n'est pas possible de récupérer le logger via la méthode logging.getLogger("MyLogger") en passant d'un nœud a un autre, voici 2 solutions
  
  

• méthode 1 : passer par un fichier de configuration
  plutôt que de reconstruire un logger avec toutes les propriétés pour chaque nœud, on sauvegarde les caractéristiques dans un fichier que l'on re-utilise

écriture du fichier de configuration (config.txt)

  
my_path = System.Environment.GetFolderPath(System.Environment.SpecialFolder.MyDocuments)      
import logging
import logging.config
from logging.handlers import RotatingFileHandler
import os

configtxt = """[loggers]
keys=root, myLooger

[handlers]
keys=fileHandler

[formatters]
keys=Formatter

[logger_root]
level=DEBUG
handlers=fileHandler
qualname=main

[logger_myLooger]
level=DEBUG
handlers=fileHandler
qualname=myLooger
propagate=0

[handler_fileHandler]
class=handlers.RotatingFileHandler
level=DEBUG
formatter=Formatter
args=('%(logfilename)s', 'a', 100000, 1)

[formatter_Formatter]
format=%(asctime)s :: %(levelname)s :: %(funcName)s :: %(message)s
datefmt="%Y-%m-%d %H:%M:%S"
"""

loginipath = my_path + '\\config.txt'
logfilename = my_path + '\\debug.log'.replace("\\", "\\\\")
with open(loginipath, 'w') as f:
    f.write(configtxt)
   
logging.config.fileConfig(loginipath, defaults={'logfilename': logfilename.replace("\\", "/")}, disable_existing_loggers = True)
logger = logging.getLogger("myLooger")  
  

• méthode 2 : utiliser la même référence du logger
  on utilise le même logger que l'on transfère d'un nœud Python a un autre

Note :

dans les exemples ci-dessus le logger est défini en tant qu’attribut d'instance, mais il sera préférable dans certains cas de le définir  en tant qu’attribut de classe

Astuce : utiliser la console Dynamo

Depuis Dynamo 2.10 il est possible d'afficher les print() dans la console Dynamo, et comme cette fonction utilise le sdtout (https://docs.python.org/fr/3/library/sys.html), il est possible de configurer un handler pour afficher les messages dans la console (en fonction des niveaux et du format définit).

Il faut juste utiliser la fonction print() en fin de script pour déclencher l'affichage. 

import sys
import logging

logger = logging.getLogger('MyTracker')
# set root's level
logger.setLevel(logging.DEBUG)
formatter = logging.Formatter('%(asctime)s :: %(levelname)s :: %(funcName)s :: %(message)s')
#
# create a Stream Handler with redirection to stdout
stdout_handler =  logging.StreamHandler(sys.stdout)
stdout_handler.setLevel(logging.DEBUG)
stdout_handler.setFormatter(formatter)
logger.addHandler(stdout_handler)
logger.disabled = False #or True
#
def printer():
    logger.debug('MyList is ')
    logger.debug(list(range(6)))
    logger.info('Hello')
    logger.warning('This is a warning')
    logger.error('This is a critical error')
    print()
    
    
OUT = printer()  
#logging.shutdown()
for handler in logger.handlers[:]:
	logger.removeHandler(handler)