Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

test_multiprocessing_fork fails if run sequentially after test_genericalias and test_logging #89291

Closed
pablogsal opened this issue Sep 7, 2021 · 15 comments
Labels
3.10 only security fixes tests Tests in the Lib/test dir

Comments

@pablogsal
Copy link
Member

BPO 45128
Nosy @vstinner, @ambv, @pablogsal, @miss-islington, @kanavin, @sobolevn
PRs
  • bpo-45128: fixes test_multiprocessing_fork mysterious crash #28387
  • [3.10] bpo-45128: fixes test_multiprocessing_fork mysterious crash (GH-28387) #28462
  • Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.

    Show more details

    GitHub fields:

    assignee = None
    closed_at = <Date 2021-09-19.23:34:08.602>
    created_at = <Date 2021-09-07.14:33:53.106>
    labels = ['tests', '3.10']
    title = 'test_multiprocessing_fork fails if run sequentially after test_genericalias and test_logging'
    updated_at = <Date 2021-10-04.19:18:43.128>
    user = 'https://github.com/pablogsal'

    bugs.python.org fields:

    activity = <Date 2021-10-04.19:18:43.128>
    actor = 'pablogsal'
    assignee = 'none'
    closed = True
    closed_date = <Date 2021-09-19.23:34:08.602>
    closer = 'pablogsal'
    components = ['Tests']
    creation = <Date 2021-09-07.14:33:53.106>
    creator = 'pablogsal'
    dependencies = []
    files = []
    hgrepos = []
    issue_num = 45128
    keywords = ['patch']
    message_count = 15.0
    messages = ['401287', '401291', '401332', '401333', '401846', '401855', '401925', '401928', '401929', '401930', '401931', '402178', '402183', '402199', '403165']
    nosy_count = 6.0
    nosy_names = ['vstinner', 'lukasz.langa', 'pablogsal', 'miss-islington', 'Alexander Kanavin', 'sobolevn']
    pr_nums = ['28387', '28462']
    priority = 'normal'
    resolution = 'fixed'
    stage = 'resolved'
    status = 'closed'
    superseder = None
    type = None
    url = 'https://bugs.python.org/issue45128'
    versions = ['Python 3.10']

    @pablogsal
    Copy link
    Member Author

    While testing the release artifacts I encountered this failure:

    test test_multiprocessing_fork failed -- Traceback (most recent call last):
      File "/tmp/tmpu30qfjpr/installation/lib/python3.10/unittest/mock.py", line 1239, in _dot_lookup
        return getattr(thing, comp)
    AttributeError: module 'multiprocessing' has no attribute 'shared_memory'
    
    During handling of the above exception, another exception occurred:
    
    Traceback (most recent call last):
      File "/tmp/tmpu30qfjpr/installation/lib/python3.10/test/_test_multiprocessing.py", line 3818, in test_shared_memory_basics
        with unittest.mock.patch(
      File "/tmp/tmpu30qfjpr/installation/lib/python3.10/unittest/mock.py", line 1422, in __enter__
        self.target = self.getter()
      File "/tmp/tmpu30qfjpr/installation/lib/python3.10/unittest/mock.py", line 1609, in <lambda>
        getter = lambda: _importer(target)
      File "/tmp/tmpu30qfjpr/installation/lib/python3.10/unittest/mock.py", line 1252, in _importer
        thing = _dot_lookup(thing, comp, import_path)
      File "/tmp/tmpu30qfjpr/installation/lib/python3.10/unittest/mock.py", line 1242, in _dot_lookup
        return getattr(thing, comp)
    AttributeError: module 'multiprocessing' has no attribute 'shared_memory'
    
    0:09:11 load avg: 0.71 [231/427/1] test_multiprocessing_forkserver -- test_multiprocessing_fork failed (1 error) in 1 min 11 sec
    test test_multiprocessing_forkserver failed -- Traceback (most recent call last):
      File "/tmp/tmpu30qfjpr/installation/lib/python3.10/unittest/mock.py", line 1239, in _dot_lookup
        return getattr(thing, comp)
    AttributeError: module 'multiprocessing' has no attribute 'shared_memory'
    
    During handling of the above exception, another exception occurred:
    
    Traceback (most recent call last):
      File "/tmp/tmpu30qfjpr/installation/lib/python3.10/test/_test_multiprocessing.py", line 3818, in test_shared_memory_basics
        with unittest.mock.patch(
      File "/tmp/tmpu30qfjpr/installation/lib/python3.10/unittest/mock.py", line 1422, in __enter__
        self.target = self.getter()
      File "/tmp/tmpu30qfjpr/installation/lib/python3.10/unittest/mock.py", line 1609, in <lambda>
        getter = lambda: _importer(target)
      File "/tmp/tmpu30qfjpr/installation/lib/python3.10/unittest/mock.py", line 1252, in _importer
        thing = _dot_lookup(thing, comp, import_path)
      File "/tmp/tmpu30qfjpr/installation/lib/python3.10/unittest/mock.py", line 1242, in _dot_lookup
        return getattr(thing, comp)
    AttributeError: module 'multiprocessing' has no attribute 'shared_memory'
    
    0:11:11 load avg: 0.93 [232/427/2] test_multiprocessing_main_handling -- test_multiprocessing_forkserver failed (1 error) in 2 min
    0:11:18 load avg: 1.09 [233/427/2] test_multiprocessing_spawn
    test test_multiprocessing_spawn failed -- Traceback (most recent call last):
      File "/tmp/tmpu30qfjpr/installation/lib/python3.10/unittest/mock.py", line 1239, in _dot_lookup
        return getattr(thing, comp)
    AttributeError: module 'multiprocessing' has no attribute 'shared_memory'

    I cannot reproduce it from installed Python or when testing directly on the repo, but the error seems to still happen from time to time.

    @pablogsal pablogsal added 3.10 only security fixes tests Tests in the Lib/test dir labels Sep 7, 2021
    @sobolevn
    Copy link
    Member

    sobolevn commented Sep 7, 2021

    @vstinner
    Copy link
    Member

    vstinner commented Sep 7, 2021

    I guess that the test was previously skipped, and bpo-45042 enabled again the test:

    commit e5976dd
    Author: Miss Islington (bot) <31488909+miss-islington@users.noreply.github.com>
    Date: Sat Sep 4 14:04:44 2021 -0700

    bpo-45042: Now test classes decorated with `requires_hashdigest` are not skipped (GH-28060)
    
    
    Co-authored-by: Serhiy Storchaka <storchaka@gmail.com>
    (cherry picked from commit dd7b816ac87e468e2fa65ce83c2a03fe1da8503e)
    
    Co-authored-by: Nikita Sobolev <mail@sobolevn.me>
    

    @vstinner
    Copy link
    Member

    vstinner commented Sep 7, 2021

    I'm not sure if unittest.mock code to import the module is reliable: see bpo-39551. It imports "multiprocessing", use getattr() to get multiprocessing.shared_memory. If getattr() fails with AttributeError, it tries to import "mulitprocessing.shared_memory", and then tries again the same getattr() on the previously imported "multiprocessing" module.

    I'm curious if this change works around the issue:

    diff --git a/Lib/unittest/mock.py b/Lib/unittest/mock.py
    index c6067151de..1e3a8277ca 100644
    --- a/Lib/unittest/mock.py
    +++ b/Lib/unittest/mock.py
    @@ -1238,7 +1238,7 @@ def _dot_lookup(thing, comp, import_path):
         try:
             return getattr(thing, comp)
         except AttributeError:
    -        __import__(import_path)
    +        thing = __import__(import_path)
             return getattr(thing, comp)

    @kanavin
    Copy link
    Mannequin

    kanavin mannequin commented Sep 15, 2021

    I am seeing this one too in my yocto builds of 3.10rc2. What is bizarre is that the issue does not occur if the multiprocessing test is run in isolation:

    python3 -m test -v test_multiprocessing_fork

    but quite reliably does occur (three times in three different spots) if the whole test suite is executed:

    python3 -m test -v

    @pablogsal
    Copy link
    Member Author

    but quite reliably does occur (three times in three different spots) if the whole test suite is executed:

    The thing is that we are running the test suite constantly on CI and buildbots and non of them have seen this problem :(

    We should see if we could reproduce this easily first. Łukasz, could you take a look if you have some availability?

    @vstinner
    Copy link
    Member

    The thing is that we are running the test suite constantly on CI and buildbots and non of them have seen this problem :(

    Most (if not all) Python CIs run the Python test suite using -jN option which runs each test in isolation: a fresh process is spawned to a test file.

    @vstinner
    Copy link
    Member

    Minimum command to reproduce the issue (on Linux):

    $ ./python -m test -m test.test_logging.LogRecordTest.test_multiprocessing test_genericalias test_logging test_multiprocessing_fork -v

    (...)
    0:00:00 load avg: 0.45 Run tests sequentially
    0:00:00 load avg: 0.45 [1/3] test_genericalias

    ----------------------------------------------------------------------
    Ran 0 tests in 0.000s

    OK
    0:00:00 load avg: 0.49 [2/3] test_logging -- test_genericalias ran no tests
    test_multiprocessing (test.test_logging.LogRecordTest) ... ok

    ----------------------------------------------------------------------
    Ran 1 test in 0.008s

    OK
    0:00:00 load avg: 0.49 [3/3] test_multiprocessing_fork
    test test_multiprocessing_fork crashed -- Traceback (most recent call last):
      File "/home/vstinner/python/main/Lib/test/libregrtest/runtest.py", line 340, in _runtest_inner
        refleak = _runtest_inner2(ns, test_name)
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
      File "/home/vstinner/python/main/Lib/test/libregrtest/runtest.py", line 280, in _runtest_inner2
        the_module = importlib.import_module(abstest)
                     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
      File "/home/vstinner/python/main/Lib/importlib/__init__.py", line 126, in import_module
        return _bootstrap._gcd_import(name[level:], package, level)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
      File "<frozen importlib._bootstrap>", line 1072, in _gcd_import
      File "<frozen importlib._bootstrap>", line 1044, in _find_and_load
      File "<frozen importlib._bootstrap>", line 1015, in _find_and_load_unlocked
      File "<frozen importlib._bootstrap>", line 689, in _load_unlocked
      File "<frozen importlib._bootstrap_external>", line 894, in exec_module
      File "<frozen importlib._bootstrap>", line 241, in _call_with_frames_removed
      File "/home/vstinner/python/main/Lib/test/test_multiprocessing_fork.py", line 2, in <module>
        import test._test_multiprocessing
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
      File "/home/vstinner/python/main/Lib/test/_test_multiprocessing.py", line 5374, in <module>
        class TestSyncManagerTypes(unittest.TestCase):
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
      File "/home/vstinner/python/main/Lib/test/_test_multiprocessing.py", line 5396, in TestSyncManagerTypes
        manager_class = multiprocessing.managers.SyncManager
                        ^^^^^^^^^^^^^^^^^^^^^^^^
    AttributeError: module 'multiprocessing' has no attribute 'managers'

    test_multiprocessing_fork failed (uncaught exception)
    (...)

    @vstinner
    Copy link
    Member

    I can still reproduce the issue if test_logging.py is simplified to:
    ---

    import unittest
    import sys
    
    class LogRecordTest(unittest.TestCase):
        def test_multiprocessing(self):
            import multiprocessing.queues
            del sys.modules['multiprocessing']
            import multiprocessing

    The "del sys.modules['multiprocessing']" line comes from LogRecordTest._extract_logrecord_process_name() method.

    @vstinner vstinner changed the title test_multiprocessing fails sporadically on the release artifacts test_multiprocessing_fork fails if run sequentially after test_logging Sep 16, 2021
    @vstinner vstinner changed the title test_multiprocessing fails sporadically on the release artifacts test_multiprocessing_fork fails if run sequentially after test_logging Sep 16, 2021
    @vstinner
    Copy link
    Member

    ./python -m test -m test.test_logging.LogRecordTest.test_multiprocessing test_genericalias test_logging test_multiprocessing_fork -v

    This command reproduces the issue:

    • importing test.test_genericalias imports multiprocessing submodules like multiprocessing.queues
    • test_logging does: del sys.modules['multiprocessing']
    • test_multiprocessing_fork fails to import multiprocessing submodules

    @vstinner
    Copy link
    Member

    The issue can be reproduced just with these lines:
    ---

    import sys
    import multiprocessing.queues
    del sys.modules['multiprocessing']
    import multiprocessing
    import multiprocessing.connection
    from multiprocessing.connection import wait
    connection = multiprocessing.connection   # AttributeError here

    @vstinner vstinner changed the title test_multiprocessing_fork fails if run sequentially after test_logging test_multiprocessing_fork fails if run sequentially after test_genericalias and test_logging Sep 16, 2021
    @vstinner vstinner changed the title test_multiprocessing_fork fails if run sequentially after test_logging test_multiprocessing_fork fails if run sequentially after test_genericalias and test_logging Sep 16, 2021
    @pablogsal
    Copy link
    Member Author

    New changeset 1d42408 by Nikita Sobolev in branch 'main':
    bpo-45128: fixes test_multiprocessing_fork mysterious crash (GH-28387)
    1d42408

    @miss-islington
    Copy link
    Contributor

    New changeset 0e96086 by Miss Islington (bot) in branch '3.10':
    bpo-45128: fixes test_multiprocessing_fork mysterious crash (GH-28387)
    0e96086

    @vstinner
    Copy link
    Member

    This bug was interesting (funny) :-) Thanks for the fix Nikita Sobolev :-)

    @pablogsal
    Copy link
    Member Author

    New changeset 7661103 by Pablo Galindo (Miss Islington (bot)) in branch '3.10':
    bpo-45128: fixes test_multiprocessing_fork mysterious crash (GH-28387)
    7661103

    @ezio-melotti ezio-melotti transferred this issue from another repository Apr 10, 2022
    Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
    Labels
    3.10 only security fixes tests Tests in the Lib/test dir
    Projects
    None yet
    Development

    No branches or pull requests

    4 participants