I suspect you're not initalizing the logger properly, you will have to define separate handlers for each PythonCaller if you want them to log to different files. This is by design in the logging module and is not specific to FME. The first paragraph here probably applies to your case: https://docs.python.org/2/howto/logging-cookbook.html#using-logging-in-multiple-modules
Sample PythonCaller that initializes its own handler:
import fmeimport fmeobjectsimport loggingclass FeatureProcessor1(object): def __init__(self): logger_name = self.__class__.__name__ logger_filename = self.__class__.__name__+'.log' print "%s is logging to file %s" % (logger_name, logger_filename) self.logger = logging.getLogger(logger_name) self.logger.setLevel(logging.INFO) fh = logging.FileHandler(logger_filename) # create formatter and add it to the handlers formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') fh.setFormatter(formatter) # add the handlers to the logger self.logger.addHandler(fh) def input(self,feature): self.logger.info('A message from PythonCaller_1') self.pyoutput(feature)
Sample workspace with two PythonCallers that log to separate files using the logging module: pythonlogger.fmwt
For the above to work without modifications, make sure that all your PythonCallers use separate class names, otherwise they'll end competing for the same log file name. Sample output
FeatureProcessor1.log
2017-03-16 13:23:20,411 - FeatureProcessor1 - INFO - A message from PythonCaller_1
FeatureProcessor2.log
2017-03-16 13:23:20,411 - FeatureProcessor2 - INFO - A message from PythonCaller_2
Hi,
Are you raising back the exception after logging it?
If this is the case, this is why the previous PythonCallers are also logging the exception.
My understanding is that when you have PythonCaller_1 followed by PythonCaller_2 and PythonCaller_1 calls self.pyoutput, this function call does not return until the feature is written in the output or held by a blocking transformer. Thus, if PythonCaller_2 catch an exception, log and raise it, PythonCaller_2 will catch it too.
And following the discussion I had with @david_r in the comments below, if you are raising back the exception and don't want to have it logged by the previous PythonCallers, you have to place the pyoutput call outside of your try block.
Hi,
Are you raising back the exception after logging it?
If this is the case, this is why the previous PythonCallers are also logging the exception.
My understanding is that when you have PythonCaller_1 followed by PythonCaller_2 and PythonCaller_1 calls self.pyoutput, this function call does not return until the feature is written in the output or held by a blocking transformer. Thus, if PythonCaller_2 catch an exception, log and raise it, PythonCaller_2 will catch it too.
And following the discussion I had with @david_r in the comments below, if you are raising back the exception and don't want to have it logged by the previous PythonCallers, you have to place the pyoutput call outside of your try block.
This interests me because it reminds me of some weird behaviour I've seen before, so I tried to reproduce using the attached workspace, but FME 2017 seems to handle it correctly.
PythonCaller_1 raises an exception and the log reads:
2017-03-16 14:28:20,157 - FeatureProcessor1 - INFO - A message from PythonCaller_12017-03-16 14:28:20,157 - FeatureProcessor1 - ERROR - integer division or modulo by zero
The log from PythonCaller_2 remains empty, as expected. See
pythonlogger.fmwt
Or am I misunderstanding something?
This interests me because it reminds me of some weird behaviour I've seen before, so I tried to reproduce using the attached workspace, but FME 2017 seems to handle it correctly.
PythonCaller_1 raises an exception and the log reads:
2017-03-16 14:28:20,157 - FeatureProcessor1 - INFO - A message from PythonCaller_12017-03-16 14:28:20,157 - FeatureProcessor1 - ERROR - integer division or modulo by zero
The log from PythonCaller_2 remains empty, as expected. See
pythonlogger.fmwt
Or am I misunderstanding something?
Note: I don't have 2017 installed yet and I ran your code with 2016.
The behavior depends on two major things.
1- Where the pyoutput is called: inside or outside of the try section.
2- If you are raising back the exception
In your particular case, as soon as there is an exception caught, you are logging and raising back the exception. Since your pyoutput is called after the raise, it is not called.
On the other hand, if you make the code work normally in PythonCaller_1 (P1) and let the feature go to PythonCaller_2 (P2), P2 will catch/raise the exception and P1 will only detect that an exception occured but not catch it because the pyoutput is outside the try block. You'll see in following pictures that the message "(PythonFactory): PythonFactory failed to process feature" appears twice in the second example, one for the first raise in P2 and one when P1 receives the exception raised by P2.
Original code:
Modified code to let the feature go to P2:
Note: I don't have 2017 installed yet and I ran your code with 2016.
The behavior depends on two major things.
1- Where the pyoutput is called: inside or outside of the try section.
2- If you are raising back the exception
In your particular case, as soon as there is an exception caught, you are logging and raising back the exception. Since your pyoutput is called after the raise, it is not called.
On the other hand, if you make the code work normally in PythonCaller_1 (P1) and let the feature go to PythonCaller_2 (P2), P2 will catch/raise the exception and P1 will only detect that an exception occured but not catch it because the pyoutput is outside the try block. You'll see in following pictures that the message "(PythonFactory): PythonFactory failed to process feature" appears twice in the second example, one for the first raise in P2 and one when P1 receives the exception raised by P2.
Original code:
Modified code to let the feature go to P2:
Thanks, that makes sense.
Hi,
Are you raising back the exception after logging it?
If this is the case, this is why the previous PythonCallers are also logging the exception.
My understanding is that when you have PythonCaller_1 followed by PythonCaller_2 and PythonCaller_1 calls self.pyoutput, this function call does not return until the feature is written in the output or held by a blocking transformer. Thus, if PythonCaller_2 catch an exception, log and raise it, PythonCaller_2 will catch it too.
And following the discussion I had with @david_r in the comments below, if you are raising back the exception and don't want to have it logged by the previous PythonCallers, you have to place the pyoutput call outside of your try block.
Not sure whether or not that applies to my issue, I don't think I raised it back, (I didn't want the workspace to fail in these exceptions handling scenarii) but I will check !
I suspect you're not initalizing the logger properly, you will have to define separate handlers for each PythonCaller if you want them to log to different files. This is by design in the logging module and is not specific to FME. The first paragraph here probably applies to your case: https://docs.python.org/2/howto/logging-cookbook.html#using-logging-in-multiple-modules
Sample PythonCaller that initializes its own handler:
import fmeimport fmeobjectsimport loggingclass FeatureProcessor1(object): def __init__(self): logger_name = self.__class__.__name__ logger_filename = self.__class__.__name__+'.log' print "%s is logging to file %s" % (logger_name, logger_filename) self.logger = logging.getLogger(logger_name) self.logger.setLevel(logging.INFO) fh = logging.FileHandler(logger_filename) # create formatter and add it to the handlers formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') fh.setFormatter(formatter) # add the handlers to the logger self.logger.addHandler(fh) def input(self,feature): self.logger.info('A message from PythonCaller_1') self.pyoutput(feature)
Sample workspace with two PythonCallers that log to separate files using the logging module: pythonlogger.fmwt
For the above to work without modifications, make sure that all your PythonCallers use separate class names, otherwise they'll end competing for the same log file name. Sample output
FeatureProcessor1.log
2017-03-16 13:23:20,411 - FeatureProcessor1 - INFO - A message from PythonCaller_1
FeatureProcessor2.log
2017-03-16 13:23:20,411 - FeatureProcessor2 - INFO - A message from PythonCaller_2
Well that seems to match with my issue, this was indeed my first guess and as said in the original post, I used different object names for each loggers/formatters/handlers to rule that out, but I always thought that FME was secretly renaming the class to prevent classes from two different callers to interfere.
So... might there be any other things that might be at odds with to pythonCallers sharing their classes names ?
Well that seems to match with my issue, this was indeed my first guess and as said in the original post, I used different object names for each loggers/formatters/handlers to rule that out, but I always thought that FME was secretly renaming the class to prevent classes from two different callers to interfere.
So... might there be any other things that might be at odds with to pythonCallers sharing their classes names ?
For what it's worth, I've never seen any evidence of some "secret renaming" of the classes in FME, it works pretty transparently. You do have to be careful about namespaces and scopes, however, but that isn't really specific to FME.
