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

Build problems on Windows #91193

Closed
terryjreedy opened this issue Mar 16, 2022 · 15 comments
Closed

Build problems on Windows #91193

terryjreedy opened this issue Mar 16, 2022 · 15 comments
Labels
3.9 only security fixes 3.10 only security fixes 3.11 only security fixes build The build process and cross-build OS-windows

Comments

@terryjreedy
Copy link
Member

BPO 47037
Nosy @tim-one, @terryjreedy, @pfmoore, @tiran, @tjguk, @ambv, @zware, @eryksun, @zooba, @pablogsal, @sweeneyde
PRs
  • bpo-47037: Don't test for strftime('%4Y') on Windows #31945
  • bpo-47037: Test debug builds on Windows in CI so that native assertions are noticed sooner #31965
  • 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 2022-03-21.17:02:50.838>
    created_at = <Date 2022-03-16.18:30:03.251>
    labels = ['3.10', 'build', '3.9', 'OS-windows', '3.11']
    title = 'Build problems on Windows'
    updated_at = <Date 2022-03-21.17:02:50.838>
    user = 'https://github.com/terryjreedy'

    bugs.python.org fields:

    activity = <Date 2022-03-21.17:02:50.838>
    actor = 'steve.dower'
    assignee = 'none'
    closed = True
    closed_date = <Date 2022-03-21.17:02:50.838>
    closer = 'steve.dower'
    components = ['Build', 'Windows']
    creation = <Date 2022-03-16.18:30:03.251>
    creator = 'terry.reedy'
    dependencies = []
    files = []
    hgrepos = []
    issue_num = 47037
    keywords = ['patch']
    message_count = 15.0
    messages = ['415355', '415357', '415358', '415360', '415362', '415363', '415365', '415366', '415368', '415372', '415435', '415486', '415503', '415508', '415513']
    nosy_count = 11.0
    nosy_names = ['tim.peters', 'terry.reedy', 'paul.moore', 'christian.heimes', 'tim.golden', 'lukasz.langa', 'zach.ware', 'eryksun', 'steve.dower', 'pablogsal', 'Dennis Sweeney']
    pr_nums = ['31945', '31965']
    priority = 'critical'
    resolution = 'fixed'
    stage = 'resolved'
    status = 'closed'
    superseder = None
    type = 'compile error'
    url = 'https://bugs.python.org/issue47037'
    versions = ['Python 3.9', 'Python 3.10', 'Python 3.11']

    @terryjreedy
    Copy link
    Member Author

    3.11 apparently builds without error, and 'python' and 'python -m idlelib' appears to start normally, but there is a new problem.
    python -m test
    raises OS box with 'Debug Assertion Failed!', program python_d.exe,
    File minkernal\crts\ucrt\src\time\wcsftime.exe
    Line 1184, expression false.
    Dismiss box and a few tests run until box repeats and Command Prompt eventually locks.
    ...test test_idle finished OK once after dismissing box. On retry, test ran OK but CP locked instead of showing new prompt.

    3.10 and 3.9 (but not 3.11): compiling show a newish warning.
    pythonw.vcxproj -> f:\dev\310\PCbuild\amd64\pythonw_d.exe
    pythonw.vcxproj -> f:\dev\310\PCbuild\amd64\pythonw_d.pdb (Full PDB)
    f:\dev\310\PCbuild\pythoncore.vcxproj(554,5): warning : A copy of vcruntime140.dll is also required

    Does not 3.11 also require this? (wherever it is supposed to be?). Aside from the warning, 3.10 appear to be working normally. There is no error box when starting tests and 50 have run so far without a box.

    @terryjreedy terryjreedy added 3.9 only security fixes 3.10 only security fixes 3.11 only security fixes build The build process and cross-build OS-windows labels Mar 16, 2022
    @zooba
    Copy link
    Member

    zooba commented Mar 16, 2022

    This sounds more like recent installation changes on your machine. Have
    you updated Visual Studio or something like that? Perhaps the debug UCRT
    has gone missing.

    I'm not aware of any recent compilation changes that would cause this.

    @tim-one
    Copy link
    Member

    tim-one commented Mar 16, 2022

    Actually, I see this ('Debug Assertion Failed!' in the same spot) every time I try to run the test suite with a debug build, starting yesterday.

    Didn't have time to track it down. It _appeared_ to an obscure consequence of this commit:

    """
    $ git log timemodule.c
    commit a4674f0
    Author: Christian Heimes <christian@python.org>
    Date: Tue Mar 15 22:55:35 2022 +0200

    bpo-40280: Detect presence of time.tzset and thread_time clock (GH-31898)
    

    """

    @tim-one
    Copy link
    Member

    tim-one commented Mar 16, 2022

    BTW, the frequency of this new failure mode appears to be vastly increased if running the debug tests with "-j0". For example, the box popping up is reliably the very first sign of life if I run this from the PCBuild directory:

    rt -q -d -j0

    @eryksun
    Copy link
    Contributor

    eryksun commented Mar 16, 2022

    bpo-46587 added top-level code to "Lib/test/support/init.py" to check whether time.strftime("%4Y") works. Since "Lib/test/libregrtest/setup.py" imports the support module, that code executes before suppress_msvcrt_asserts() is called by setup_tests().

    @sweeneyde
    Copy link
    Member

    indeed, bisected to

    2cf7f86 is the first bad commit
    commit 2cf7f86
    Author: Christian Heimes <christian@python.org>
    Date: Tue Mar 15 11:41:04 2022 +0200

    bpo-46587: Skip tests if strftime does not support glibc extension (GH-31873)
    
    Co-authored-by: Victor Stinner <vstinner@python.org>
    

    @tiran
    Copy link
    Member

    tiran commented Mar 16, 2022

    Ouch, is Python crashes because of an unsupported strftime call?

    @tim-one
    Copy link
    Member

    tim-one commented Mar 16, 2022

    Christian, yes, but only in a debug build. See Eryk Sun's message a bit above: the machinery to prevent this is already present, but isn't getting called early enough.

    @terryjreedy
    Copy link
    Member Author

    Re the 3.9/3.10 warnings: I have not intentionally touched my C install in years. I don't know what Windows' updates do (most recently yesterday) . I presume vcruntime140.dll is on my C: ssd, which has shown no problems. Debug runs w/o -j0 normally take about 18 minutes. After 51 minutes, the 3.10 test run froze CP (as in, had to close with [X] and reopen). Output ends with

    "0:51:02 load avg: 0.01 [407/427] test_winconsoleio

    Ä^Z"

    @eryksun
    Copy link
    Contributor

    eryksun commented Mar 16, 2022

    Ouch, is Python crashes because of an unsupported strftime call?

    It's not a crash. It's a CRT error report dialog, which is enabled by default for the _CRT_ASSERT and _CRT_ERROR macros in debug builds. This dialog can be helpful when debugging interactively. It gives a developer the option to abort, retry, or ignore. If a debugger is attached, the retry option breaks into the debugger. I attached a debugger to the test runner to diagnose the problem with format code "%4Y". For example:

        >>> time.strftime('%4Y')
        Debug Assertion Failed!
        [...]
        (Press Retry to debug the application)
        (1a6c.101c): Break instruction exception - code 80000003 (first chance)
        ucrtbased!_Wcsftime_l+0x5af:
        00007ff8`a582b9af cc              int     3

    backtrace:

    0:000> kc 4
    Call Site
    ucrtbased!_Wcsftime_l
    ucrtbased!_Strftime_l
    ucrtbased!strftime
    python311_d!time_strftime
    

    locals:

    0:000> dv
          _Expr_val = 0n0
             string = 0x00000226`fe38d1c0 ""
           max_size = 0x400
             format = 0x00000226`fe37e7d0 "%4Y"
            timeptr = 0x00000041`c1feeda0
        lc_time_arg = 0x00000000`00000000
             locale = 0x00000000`00000000
      locale_update = class _LocaleUpdate
          format_it = 0x00000226`fe37e7d2 "4Y"
          remaining = 0x400
            lc_time = 0x00007ff8`a5868550
             failed = true
          string_it = 0x00000226`fe38d1c0 ""
    

    resume, with the STATUS_BREAKPOINT (0x80000003) exception handled:

        0:000> gh
        Traceback (most recent call last):
          File "<stdin>", line 1, in <module>
        ValueError: Invalid format string
        >>> 

    For non-interactive testing the report mode needs to be configured to 0 (no report) or to report to stderr. For example:

        >>> msvcrt.CrtSetReportMode(msvcrt.CRT_ERROR, msvcrt.CRTDBG_MODE_FILE)
        4
        >>> msvcrt.CrtSetReportFile(msvcrt.CRT_ERROR, msvcrt.CRTDBG_FILE_STDERR)
        18446744073709551615
        >>> os.abort()
        abort() has been called

    For time.strftime('%4Y'), the source of the report is _VALIDATE_RETURN(false, EINVAL, 0) in _Wcsftime_l(). This macro includes an _ASSERT_EXPR(expr, msg) check. In a debug build, this calls _CrtDbgReportW(_CRT_ASSERT, ...) if the expression is false. If the latter returns 1 (retry), the __debugbreak() intrinsic is called to break into the debugger. To suppress the dialog, either temporarily set the CRT_ASSERT report mode to 0, or set it to report to stderr. For example:

        >>> msvcrt.CrtSetReportMode(msvcrt.CRT_ASSERT, msvcrt.CRTDBG_MODE_FILE)
        4
        >>> msvcrt.CrtSetReportFile(msvcrt.CRT_ASSERT, msvcrt.CRTDBG_FILE_STDERR)
        18446744073709551615
    
        >>> time.strftime('%4Y')
        minkernel\crts\ucrt\src\appcrt\time\wcsftime.cpp(1163) : Assertion failed: false
        Traceback (most recent call last):
          File "<stdin>", line 1, in <module>
        ValueError: Invalid format string

    @zooba
    Copy link
    Member

    zooba commented Mar 17, 2022

    I think this is also a good enough reason to switch the GitHub CI back to a debug build, rather than release, so that assert failures are caught before they get merged. This is not the first time it's happened.

    @zooba
    Copy link
    Member

    zooba commented Mar 18, 2022

    New changeset d190a93 by Christian Heimes in branch 'main':
    bpo-47037: Don't test for strftime('%4Y') on Windows (GH-31945)
    d190a93

    @terryjreedy
    Copy link
    Member Author

    I recompiled, retested, and all tests are ok, with no unexpected box. Thank you all.

    The vcruntime warnings are also gone, so I will chalk them up to a onetime glitch.

    @eryksun
    Copy link
    Contributor

    eryksun commented Mar 18, 2022

    The main entry point for python[_d].exe should support a command-line -X option or environment variable that suppresses Windows error/assert/warn reporting, or redirects it to stderr in verbose mode. This would be useful to simplify everyone's automated testing. It should require opting in, both for backward compatibility and also because the dialogs are useful for interactive testing.

    @zooba
    Copy link
    Member

    zooba commented Mar 18, 2022

    New changeset d0a91bd by Steve Dower in branch 'main':
    bpo-47037: Test debug builds on Windows in CI so that native assertions are noticed sooner (GH-31965)
    d0a91bd

    @zooba zooba closed this as completed Mar 21, 2022
    @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.9 only security fixes 3.10 only security fixes 3.11 only security fixes build The build process and cross-build OS-windows
    Projects
    None yet
    Development

    No branches or pull requests

    6 participants