fireworks icon indicating copy to clipboard operation
fireworks copied to clipboard

Minor problem with get_fw_logger

Open gpetretto opened this issue 5 years ago • 0 comments

I have encountered an unexpected behavior from the get_fw_logger function and I think it could be handled in a better way.

Running the example:

lpad add_scripts 'echo "hello"' -n hello goodbye -w test_workflow
rlaunch --loglvl DEBUG rapidfire

I get the following output:

2019-03-27 11:25:34,916 INFO Hostname/IP lookup (this will take a few seconds)
2019-03-27 11:25:34,977 INFO Created new dir /home/guido/tmp/test_fw/launcher_2019-03-27-10-25-34-976908
2019-03-27 11:25:34,977 INFO Launching Rocket
2019-03-27 11:25:34,987 INFO RUNNING fw_id: 2 in directory: /launcher_2019-03-27-10-25-34-976908
2019-03-27 11:25:34,987 INFO RUNNING fw_id: 2 in directory: /launcher_2019-03-27-10-25-34-976908
2019-03-27 11:25:34,999 INFO Task started: ScriptTask.
2019-03-27 11:25:34,999 INFO Task started: ScriptTask.
hello
2019-03-27 11:25:35,003 INFO Task completed: ScriptTask 
2019-03-27 11:25:35,003 INFO Task completed: ScriptTask 
2019-03-27 11:25:35,020 INFO Rocket finished
2019-03-27 11:25:35,020 INFO Rocket finished

with duplicated logging messages, which is a bit annoying. This is due to the fact that a logger named rocket.launcher is obtained in different parts of the code using get_fw_logger, and can be called with different logging levels (as in the example above). In this case two handlers are generated for the same logger, with two different logging levels. This does not make much sense to me.

The simplest way of fixing this might be to give loggers different names, but as more general fix I propose to define PREVIOUS_STREAM_LOGGERS as a dict instead of a list and modify get_fw_logger as follows:

    if name not in PREVIOUS_STREAM_LOGGERS:
        # add stream handler
        sh = logging.StreamHandler(stream=sys.stdout)
        sh.setLevel(getattr(logging, stream_level))
        sh.setFormatter(formatter)
        logger.addHandler(sh)
        PREVIOUS_STREAM_LOGGERS[name] = sh
    else:
        new_level = getattr(logging, stream_level)
        sh = PREVIOUS_STREAM_LOGGERS[name]
        # use the lowest level
        if new_level < sh.level:
            sh.setLevel(new_level)

This should give the same level of output that is given now, but avoiding the duplicated messages.

gpetretto avatar Apr 03 '19 00:04 gpetretto