[WIP] Fix the broken celery logging #1030
Conversation
This is an attempted solution to fix the broken pipe errors in the celery worker logging. It probably is not the correct way of solving it and is merely patching the result of an incorrect configuration elsewhere. The logging for AiiDA is configured from a dictionary in aiida/__init__.py, where for the 'aiida' loggers and all its children a database and console handler are configured. The console handler is set to print to stdout. Once this logger is triggered in the code executed by one of the celery workers of the daemon process, the pipe to this file descriptor is broken and an IOError exception is thrown. The botch in this commit, reconfigures the logging at each task call, which ensures that the file descriptor of the StreamHandler is pointing to the correct stdout of the worker.
There was a problem hiding this comment.
I understand that it is in line with what we discussed yesterday (that the celery logging is not properly initialised - and needs proper initialisation). I also suspect that it is an almost correct solution.
What is missing is to understand how supervisor managed to properly initialise the logging of celery (to ensure that you don't hide another problem). But I suppose that there is not enough time for this. Let's also wait Giovanni's feedback of this if it is not too blocking.
|
I would definitely not merge this yet. I just wanted to open a PR so we can have a discussion. I am pretty sure that ultimately this is not the correct solution and I am merely triaging the underlying problem. If you don't have an idea let's indeed wait to discuss with the others first. |
|
If this works, I would merge this for the time being, at least it alleviates the problem. If you agree with this view, feel free to merge this PR. |
|
It "works" but not as intended I presume. The logged messages now do show up in the daemon's logfile I am not sure this actually fixes the real issue. See for example a potentially other related issue #1006 |
We define a new function aiida.common.log.setup_logging that will configure the logging from the aiida.LOGGING dictionary. When the argument 'daemon' is set to True, the logging will be configured for a daemon process, which is currently being run by celery workers. The logging configuration is adapted, such that all loggers will get a RotatingFileHandler handler that writes to the daemon log file which is the same as the log file of the master celery process that is launched when the daemon started. This accomplishes that in that log file both the celery log messages show up, with celery's own formatting, as well as the log messages from all the loggers configured by aiida itself.
With the new configure_logging function, in the global init file we simply call this function, which will setup all the necessary code for logging and configures all the loggers from the default dictionary
The module aiida.common.log now provides all the logging related concepts within AiiDA.
In the aiida initialization the configure_logging() function will be called, which will use the aiida.common.log.LOGGIN dictionary to configure the logger. It defined the 'daemon_logfile' RotatingFileHandler, with a filename in the daemon log directory of the AiiDA config directory. The problem is that this directory does not necessary exist, but when the logging is configured the file handler setup will break if it doesn't. To solve this we remove the handler from the default dictionary and only add it when the configure_logging is called with daemon=True
|
@greschd This should now fix the issue of logging. If you have the time and interest, maybe you could run this PR against your workchains and see if you can reproduce it. Of course given that it was difficult to reproduce to begin with I am not sure how useful this is 😄 |
Fix #943
Reconfigure the logging for each periodic celery task
This is an attempted solution to fix the broken pipe errors
in the celery worker logging. It probably is not the correct
way of solving it and is merely patching the result of an
incorrect configuration elsewhere.
The logging for AiiDA is configured from a dictionary in
aiida/__init__.py, where for the 'aiida' loggers and all itschildren a database and console handler are configured. The
console handler is set to print to stdout. Once this logger is
triggered in the code executed by one of the celery workers of
the daemon process, the pipe to this file descriptor is broken
and an
IOErrorexception is thrown.The botch in this commit, reconfigures the logging at each task
call, which ensures that the file descriptor of the
StreamHandleris pointing to the correct stdout of the worker.