Message339503
On Fri, 5 Apr 2019 at 04:15, Gregory P. Smith <report@bugs.python.org> wrote:
>
>
> New submission from Gregory P. Smith <greg@krypto.org>:
>
> I'm spawning a dicussion buried in the way too long thread of https://bugs.python.org/issue6721 over here into its own specific issue to treat as a 3.7 release blocker for a rollback or repair decision before 3.7.4.
>
> https://github.com/python/cpython/commit/3b699932e5ac3e76031bbb6d700fbea07492641d
>
> I believe that was released in 3.7.1 is leading to a behavior regression for an application (the Fedora installer's libreswan kvmrunner?). Full details can be found in the messages of the other issue starting with:
> https://bugs.python.org/issue6721#msg329474
Two separate applications have tripped up on this:
- Fedora's installer aka anaconda
I don't know any further details.
- libreswan's test framework aka kvmrunner
kvmrunner uses pexpect
pexpect uses ptyprocess
ptyprocess uses pty.fork() + os.exec*(); but, hey, who knew! I didn't
until this week.
this seems to be a long standing concern:
https://github.com/pexpect/ptyprocess/issues/43
> TL;DR - logging.Handler instances each have their own threading.Rlock.
> libreswan implements at least one logging.Handler subclass. That subclass's custom emit() implementation directly calls potentially many other sub-handlers emit() methods. Some of those emit() methods (such as logging.StreamHandler) call flush() which acquires the handler's lock.
# Implement log-level inversion.
#
# Ref: https://docs.python.org/2/howto/logging.html#logging-flow
#
# By default, a parent (root) logger, regardless of its log-level,
# will log all the records logged by a child. For instance, if a
# child logger is logging at DEBUG-level, then the parent will log
# (display on the console) those DEBUG-level records even when it has
# been configured to log only INFO-level records. This is because the
# default log-level ("Logger enabled for level of call?") check is
# only applied once at record-creation.
#
# This code allows DEBUG-level logging to a file, while simultaneously
# (the inversion) restricting console log records to just INFO-level
# say.
The logging.Handler's lock ensures that the two sub-streams are kept
in ordered. It prevents threads interleaving their writes.
> So they've got a dependency between these two locks, the first's must be acquired before the second.
>
> But the logging module APIs have no concept of sub-handlers and lock ordering.
>
> I see many flaws with the libreswan code's design (I'm already ignoring the futility of threading + fork) but this still caused a behavior regression in the stable 3.7 release.
Always first understand the problem.
> (more comments coming as followups to avoid a wall of text with too many topics)
>
> ----------
> assignee: gregory.p.smith
> components: Library (Lib)
> keywords: 3.7regression
> messages: 339472
> nosy: cagney, gregory.p.smith, ned.deily, vstinner
> priority: release blocker
> severity: normal
> status: open
> title: logging regression with threading + fork are mixed in 3.7.1rc2 (deadlock potential)
> type: behavior
> versions: Python 3.7
>
> _______________________________________
> Python tracker <report@bugs.python.org>
> <https://bugs.python.org/issue36533>
> _______________________________________ |
|
Date |
User |
Action |
Args |
2019-04-05 15:11:07 | cagney | set | recipients:
+ cagney, gregory.p.smith, vstinner, ned.deily |
2019-04-05 15:11:07 | cagney | link | issue36533 messages |
2019-04-05 15:11:07 | cagney | create | |
|