Open rotu opened 4 years ago
Loggers are designed to be predictably named and long-lived. We should not be creating 3 different loggers PER SUBPROCESS NAME. Instead we should probably be using one logger named
launch
and maybe one logging handler per subprocess, that lives no longer than the subprocess.
So, on one hand we have internal launch
logging needs. In that case, yes, one could even get away with a single launch
logger if actions consistently self identify in each one of their logs. On the other hand, we have process output logging needs. If we collapse those into one of the aforementioned loggers, we can no longer configure different handlers and formatters for each. And we must if we want to respect ExecuteProcess
output configurations. At some point, I entertained the idea of having a custom handler and formatter classes that could mux log records, reducing the total amount of loggers, but it seemed inappropriate.
I agree though that each action could and should shutdown their loggers, if any.
We don't close the logging handlers. We just delete the handler and hope it gets cleaned up by the system. I believe this is the most proximal cause to the above issues.
That is true. And we could do better in many places.
We accumulate
LaunchLoggers
into a list all_loggers that gets arbitrarily long.
That is correct, but the only way to shutdown all launch
loggers at once without affecting other logging
loggers. launch
logging uses Python's logging
module and it is intended to coexist with client code that also uses it.
On the other hand, we have process output logging needs. If we collapse those into one of the aforementioned loggers, we can no longer configure different handlers and formatters for each.
What are these logging needs? Do they consist of having more than one logger per subprocess stream?
If not, there is no need to go through the logging infrastructure, in which case we can just use the Handler.emit
instead.
At some point, I entertained the idea of having a custom handler and formatter classes that could mux log records, reducing the total amount of loggers, but it seemed inappropriate.
It seems that if that sort of flexibility is needed, it could be done with a QueueHandler.
What are these logging needs? Do they consist of having more than one logger per subprocess stream?
In the most general case, different log formats and sinks for each process output descriptor. See get_output_loggers()
documentation.
If not, there is no need to go through the logging infrastructure, in which case we can just use the
Handler.emit
instead.
I guess you could bypass much of the logging infrastructure, manually creating log records and such, but I fail to see why would you do that. Note this has nothing to do with explicitly cleaning up resources. That we can do.
It seems that if that sort of flexibility is needed, it could be done with a
QueueHandler
.
Sure, yeah, there're multiple ways to do it. The question is if we should.
In the most general case, different log formats and sinks for each process output descriptor. See
get_output_loggers()
documentation.
Excellent! I love good documentation and can definitely preserve that behavior.
I guess you could bypass much of the logging infrastructure, manually creating log records and such, but I fail to see why would you do that.
We would do that because right now we're abusing the logging infrastructure, particularly logging.getLogger
, and creating objects that never get cleaned up.
Also, we're altering the global logging configuration so any loggers that get created after launch
has been imported will be created as LaunchLoggers
. I expect that e.g. loggers created by pytest
will be very surprised to have their level changed by the launch.logging.reset
function!
The question is if we should.
Agreed. I don't think it's the easiest approach nor the most correct one.
Would you like to take a crack at a fix PR or should I?
Would you like to take a crack at a fix PR or should I?
If you have the time, go ahead. Many of your concerns are perfectly valid ones, but do bear in mind that the intent was (and is) to not re-implement logging
functionality that later doesn't interplay with the logging
module itself when/if launch
is embedded in another application.
do bear in mind that the intent was (and is) to not re-implement
logging
functionality that later doesn't interplay with thelogging
module itself when/iflaunch
is embedded in another application.
I don't understand what you mean. Explain?
launch.logging
reuses logging
as much as possible in an attempt to not recreate what is already available in logging
and to make it easy for launch
to be integrated into a larger application/library that also uses logging
. That is to say, it'd be a bummer if we end up with a custom logging
-like module with half the features.
I still don't quite understand how this can fit into a larger application/library.
By setting propagate = False
in LaunchLogger
, we prevent any logging records from getting out of launch
into an application handler.
I can't find any way for an application logging record to get into a launch
handler.
Am I missing a piece of the puzzle?
At any rate, I'm sure I can do this without reinventing Logger
significantly.
- By setting propagate = False in LaunchLogger, we prevent any logging records from getting out of launch into an application handler.
logging.Logger.propagate
is mutable.
- I can't find any way for an application logging record to get into a launch handler.
Any application can use a launch.logging
.
With this I'm not saying it cannot be made better, but that we should try not making it worse.
Bug report
Required Info:
Steps to reproduce issue
Expected behavior
No leaks are reported.
Actual behavior
Many filehandle leaks are reported.
Additional information
These are all launch handlers registered in launch.
There are a few problems with our logging setup:
launch
and maybe one logging handler per subprocess, that lives no longer than the subprocess. https://github.com/ros2/launch/blob/cac43b195fb767128df1fdf494687973d538c792/launch/launch/actions/execute_process.py#L617 https://github.com/ros2/launch/blob/cac43b195fb767128df1fdf494687973d538c792/launch/launch/logging/__init__.py#L431-L432all_loggers
that gets arbitrarily long. https://github.com/ros2/launch/blob/cac43b195fb767128df1fdf494687973d538c792/launch/launch/logging/__init__.py#L436-L447