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

Jump to bottom

[Windows] test_logging.test_namer_rotator_inheritance() logs a logging error #88127

Closed
vstinner opened this issue Apr 27, 2021 · 6 comments
Closed

[Windows] test_logging.test_namer_rotator_inheritance() logs a logging error #88127

vstinner opened this issue Apr 27, 2021 · 6 comments
Labels
3.9 only security fixes 3.10 only security fixes OS-windows tests Tests in the Lib/test dir

Comments

@vstinner
Copy link
Member

BPO 43961
Nosy @pfmoore, @vsajip, @vstinner, @tjguk, @zware, @zooba, @miss-islington
PRs
  • bpo-43961: Fix test_logging.test_namer_rotator_inheritance() #25684
  • [3.9] bpo-43961: Fix test_logging.test_namer_rotator_inheritance() (GH-25684) #25688
    		•

    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-04-28.15:28:58.467>
created_at = <Date 2021-04-27.21:25:51.228>
labels = ['3.10', 'tests', '3.9', 'OS-windows']
title = '[Windows] test_logging.test_namer_rotator_inheritance() logs a logging error'
updated_at = <Date 2021-04-28.15:28:58.466>
user = 'https://github.com/vstinner'

    bugs.python.org fields:

    activity = <Date 2021-04-28.15:28:58.466>
actor = 'vstinner'
assignee = 'none'
closed = True
closed_date = <Date 2021-04-28.15:28:58.467>
closer = 'vstinner'
components = ['Tests', 'Windows']
creation = <Date 2021-04-27.21:25:51.228>
creator = 'vstinner'
dependencies = []
files = []
hgrepos = []
issue_num = 43961
keywords = ['patch']
message_count = 6.0
messages = ['392137', '392138', '392156', '392185', '392198', '392220']
nosy_count = 7.0
nosy_names = ['paul.moore', 'vinay.sajip', 'vstinner', 'tim.golden', 'zach.ware', 'steve.dower', 'miss-islington']
pr_nums = ['25684', '25688']
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = None
url = 'https://bugs.python.org/issue43961'
versions = ['Python 3.9', 'Python 3.10']
    @vstinner
    Copy link
    Member Author

    vstinner@DESKTOP-DK7VBIL C:\vstinner\python\master>python -m test test_logging -m test_namer_rotator_inheritance
    Running Debug|x64 interpreter...
    0:00:00 Run tests sequentially
    0:00:00 [1/1] test_logging
    --- Logging error ---

    Traceback (most recent call last):
  File "C:\vstinner\python\master\lib\logging\handlers.py", line 74, in emit
    self.doRollover()
  File "C:\vstinner\python\master\lib\logging\handlers.py", line 179, in doRollover
    self.rotate(self.baseFilename, dfn)
  File "C:\vstinner\python\master\lib\logging\handlers.py", line 117, in rotate
    self.rotator(source, dest)
  File "C:\vstinner\python\master\lib\test\test_logging.py", line 5222, in rotator
    os.rename(source, dest + ".rotated")
FileExistsError: [WinError 183] Cannot create a file when that file already exists: 'C:\\Users\\vstinner\\AppData\\Local\\Temp\\test_logging-2-tj71b
t8k.log' -> 'C:\\Users\\vstinner\\AppData\\Local\\Temp\\test_logging-2-tj71bt8k.log.1.test.rotated'
Call stack:
  File "C:\vstinner\python\master\lib\runpy.py", line 196, in _run_module_as_main
    return _run_code(code, main_globals, None,
  File "C:\vstinner\python\master\lib\runpy.py", line 86, in _run_code
    exec(code, run_globals)
  File "C:\vstinner\python\master\lib\test\__main__.py", line 2, in <module>
    main()
  File "C:\vstinner\python\master\lib\test\libregrtest\main.py", line 719, in main
    Regrtest().main(tests=tests, **kwargs)
  File "C:\vstinner\python\master\lib\test\libregrtest\main.py", line 641, in main
    self._main(tests, kwargs)
  File "C:\vstinner\python\master\lib\test\libregrtest\main.py", line 694, in _main
    self.run_tests()
  File "C:\vstinner\python\master\lib\test\libregrtest\main.py", line 521, in run_tests
    self.run_tests_sequential()
  File "C:\vstinner\python\master\lib\test\libregrtest\main.py", line 423, in run_tests_sequential
    result = runtest(self.ns, test_name)
  File "C:\vstinner\python\master\lib\test\libregrtest\runtest.py", line 194, in runtest
    return _runtest(ns, test_name)
  File "C:\vstinner\python\master\lib\test\libregrtest\runtest.py", line 154, in _runtest
    result = _runtest_inner(ns, test_name,
  File "C:\vstinner\python\master\lib\test\libregrtest\runtest.py", line 282, in _runtest_inner
    refleak = _runtest_inner2(ns, test_name)
  File "C:\vstinner\python\master\lib\test\libregrtest\runtest.py", line 246, in _runtest_inner2
    test_runner()
  File "C:\vstinner\python\master\lib\test\support\__init__.py", line 682, in inner
    return func(*args, **kwds)
  File "C:\vstinner\python\master\lib\test\test_logging.py", line 5503, in test_main
    support.run_unittest(*tests)
  File "C:\vstinner\python\master\lib\test\support\__init__.py", line 1082, in run_unittest
    _run_suite(suite)
  File "C:\vstinner\python\master\lib\test\support\__init__.py", line 959, in _run_suite
    result = runner.run(suite)
  File "C:\vstinner\python\master\lib\test\support\testresult.py", line 169, in run
    test(self.result)
  File "C:\vstinner\python\master\lib\unittest\suite.py", line 84, in __call__
    return self.run(*args, **kwds)
  File "C:\vstinner\python\master\lib\unittest\suite.py", line 122, in run
    test(result)
  File "C:\vstinner\python\master\lib\unittest\suite.py", line 84, in __call__
    return self.run(*args, **kwds)
  File "C:\vstinner\python\master\lib\unittest\suite.py", line 122, in run
    test(result)
  File "C:\vstinner\python\master\lib\unittest\case.py", line 652, in __call__
    return self.run(*args, **kwds)
  File "C:\vstinner\python\master\lib\unittest\case.py", line 592, in run
    self._callTestMethod(testMethod)
  File "C:\vstinner\python\master\lib\unittest\case.py", line 549, in _callTestMethod
    method()
  File "C:\vstinner\python\master\lib\test\test_logging.py", line 5229, in test_namer_rotator_inheritance
    rh.emit(self.next_rec())
Message: '2'
Arguments: None

    == Tests result: SUCCESS ==

    1 test OK.

    Total duration: 1.1 sec
    Tests result: SUCCESS

    @vstinner vstinner added 3.10 only security fixes tests Tests in the Lib/test dir labels Apr 27, 2021
    @vstinner
    Copy link
    Member Author

    Ah, I only see this output on Windows. On Linux, I don't see it.

    @vstinner vstinner changed the title test_logging.test_namer_rotator_inheritance() logs a logging error [Windows] test_logging.test_namer_rotator_inheritance() logs a logging error Apr 27, 2021
    @vstinner vstinner changed the title test_logging.test_namer_rotator_inheritance() logs a logging error [Windows] test_logging.test_namer_rotator_inheritance() logs a logging error Apr 27, 2021
    @zooba
    Copy link
    Member

    zooba commented Apr 28, 2021

    What does os.rename do on Linux? Does it just overwrite existing files by default?

    @vstinner
    Copy link
    Member Author

    I wrote PR 25684 to fix this issue.

    What does os.rename do on Linux? Does it just overwrite existing files by default?

    os.rename() calls rename():
    https://man7.org/linux/man-pages/man2/rename.2.html

       rename() renames a file, moving it between directories if
   required.  Any other hard links to the file (as created using
   link(2)) are unaffected.  Open file descriptors for oldpath are
   also unaffected.

   If newpath already exists, it will be atomically replaced, so
   that there is no point at which another process attempting to
   access newpath will find it missing.  However, there will
   probably be a window in which both oldpath and newpath refer to
   the file being renamed.

    On Windows, os.rename() is implemented with MoveFileExW(src, dst, 0).

    Maybe the test should use os.replace() instead of os.rename()? On Windows, os.replace() is implemented with with MoveFileExW(src, dst, MOVEFILE_REPLACE_EXISTING).

    HandlerWithNamerAndRotator.rotator() of test_logging calls os.rename() when the file already exists:

    if os.path.exists(source):
    os.rename(source, dest + ".rotated")

    And the test fails with "Cannot create a file when that file already exists"... well yes, we just tested that it exists.

    @vstinner
    Copy link
    Member Author

    New changeset fe52eb6 by Victor Stinner in branch 'master':
    bpo-43961: Fix test_logging.test_namer_rotator_inheritance() (GH-25684)
    fe52eb6

    @vstinner
    Copy link
    Member Author

    New changeset 629ef0f by Miss Islington (bot) in branch '3.9':
    bpo-43961: Fix test_logging.test_namer_rotator_inheritance() (GH-25684) (GH-25688)
    629ef0f

    @vstinner vstinner added the 3.9 only security fixes label Apr 28, 2021
    @vstinner vstinner added the 3.9 only security fixes label Apr 28, 2021
    @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
    Assignees
    No one assigned
    Labels
    3.9 only security fixes 3.10 only security fixes OS-windows tests Tests in the Lib/test dir
    Projects
    None yet
    Milestone
    No milestone
    Development

    No branches or pull requests
    2 participants
    @vstinner @zooba