New - and consistent - failiures of the QtQml tests on macOS (CI)

[Legorooj]

Description of the issue

Context information

• Output of pyinstaller --version: develop.
• Version of Python: e.g. 3.7.5
• Platform: OS X (macOS CI on Travis)

Issue

QtQml is consistently failing. From Travis:

----------------------------- Captured stdout call -----------------------------
------- Starting build. -------
------- Build finshed, now running executable. -------
[7439]  RUNNING:  '/private/var/folders/nz/vv4_9tw56nv9k3tkvyszvwg80000gn/T/pytest-of-travis/pytest-0/test_Qt5_QtQml_onedir_PyQt5_0/dist/test_source/test_source' , args:  ['./test_source']
----------------------------- Captured stderr call -----------------------------
------- Starting build. -------
------- Build finshed, now running executable. -------
[7439] PyInstaller Bootloader 3.x
[7439] LOADER: executable is /private/var/folders/nz/vv4_9tw56nv9k3tkvyszvwg80000gn/T/pytest-of-travis/pytest-0/test_Qt5_QtQml_onedir_PyQt5_0/dist/test_source/test_source
[7439] LOADER: homepath is /private/var/folders/nz/vv4_9tw56nv9k3tkvyszvwg80000gn/T/pytest-of-travis/pytest-0/test_Qt5_QtQml_onedir_PyQt5_0/dist/test_source
[7439] LOADER: _MEIPASS2 is NULL
[7439] LOADER: archivename is /private/var/folders/nz/vv4_9tw56nv9k3tkvyszvwg80000gn/T/pytest-of-travis/pytest-0/test_Qt5_QtQml_onedir_PyQt5_0/dist/test_source/test_source
[7439] LOADER: No need to extract files to run; setting extractionpath to homepath
[7439] LOADER: Already in the child - running user's code.
[7439] LOADER: Python library: /private/var/folders/nz/vv4_9tw56nv9k3tkvyszvwg80000gn/T/pytest-of-travis/pytest-0/test_Qt5_QtQml_onedir_PyQt5_0/dist/test_source/Python
[7439] LOADER: Loaded functions from Python library.
[7439] LOADER: Manipulating environment (sys.path, sys.prefix)
[7439] LOADER: sys.prefix is /private/var/folders/nz/vv4_9tw56nv9k3tkvyszvwg80000gn/T/pytest-of-travis/pytest-0/test_Qt5_QtQml_onedir_PyQt5_0/dist/test_source
[7439] LOADER: Pre-init sys.path is /private/var/folders/nz/vv4_9tw56nv9k3tkvyszvwg80000gn/T/pytest-of-travis/pytest-0/test_Qt5_QtQml_onedir_PyQt5_0/dist/test_source/base_library.zip:/private/var/folders/nz/vv4_9tw56nv9k3tkvyszvwg80000gn/T/pytest-of-travis/pytest-0/test_Qt5_QtQml_onedir_PyQt5_0/dist/test_source
[7439] LOADER: Setting runtime options
[7439] LOADER: Initializing python
[7439] LOADER: Overriding Python's sys.path
[7439] LOADER: Post-init sys.path is /private/var/folders/nz/vv4_9tw56nv9k3tkvyszvwg80000gn/T/pytest-of-travis/pytest-0/test_Qt5_QtQml_onedir_PyQt5_0/dist/test_source/base_library.zip:/private/var/folders/nz/vv4_9tw56nv9k3tkvyszvwg80000gn/T/pytest-of-travis/pytest-0/test_Qt5_QtQml_onedir_PyQt5_0/dist/test_source
[7439] LOADER: Setting sys.argv
[7439] LOADER: setting sys._MEIPASS
[7439] LOADER: importing modules from CArchive
[7439] LOADER: extracted struct
[7439] LOADER: callfunction returned...
[7439] LOADER: extracted pyimod01_os_path
[7439] LOADER: callfunction returned...
[7439] LOADER: extracted pyimod02_archive
[7439] LOADER: callfunction returned...
[7439] LOADER: extracted pyimod03_importers
[7439] LOADER: callfunction returned...
[7439] LOADER: Installing PYZ archive with Python modules.
[7439] LOADER: PYZ archive: PYZ-09.pyz
[7439] LOADER: Running pyiboot01_bootstrap.py
[7439] LOADER: Running pyi_rth_pyqt5.py
[7439] LOADER: Running test_source.py
[7439] Failed to execute script test_source
[7439] Error: 0
[7439] Traceback: ['Traceback (most recent call last):\n', '  File "/private/var/folders/nz/vv4_9tw56nv9k3tkvyszvwg80000gn/T/pytest-of-travis/pytest-0/test_Qt5_QtQml_onedir_PyQt5_0/test_source.py", line 33, in <module>\n    sys.exit(res)\n', 'int: 0\n']
[7439] LOADER: OK.
[7439] LOADER: Cleaning up Python interpreter.
------------------------------ Captured log call -------------------------------

Links to failing builds:

First noticed in https://travis-ci.org/github/bjones1/pyinstaller/jobs/683086293

• https://travis-ci.org/github/pyinstaller/pyinstaller/jobs/683275309
• https://travis-ci.org/github/pyinstaller/pyinstaller/jobs/683703566
• https://travis-ci.org/github/bjones1/pyinstaller/jobs/683551334

Solution

I'd suggest marking these tests as skipif(is_darwin, reason='Issue #4860') temporarily whilst we find a solution to allow CI to keep passing.

[bjones1]

I agree -- mark as skipif for now. I ran https://travis-ci.org/github/bjones1/pyinstaller/jobs/683086293 on PyInstaller's develop branch and got the same failure. This raises the question: why? What changed?

[bjones1]

Doing some looking in the past:

• Commit c389fbe passes per https://travis-ci.org/github/bjones1/pyinstaller/builds/683891038.
• d08a42c passes - https://travis-ci.org/github/bjones1/pyinstaller/builds/683943570
• 763094c passes - https://travis-ci.org/github/bjones1/pyinstaller/builds/683983654
• f877f3e passes - https://travis-ci.org/github/bjones1/pyinstaller/builds/684025166
• cd3d805 passes - https://travis-ci.org/github/bjones1/pyinstaller/builds/684056299

[Legorooj]

@bjones1 none of us have a mac, so we can't git bisect. I'll see if I can setup a macOS CI job to run git bisect on my fork.

Also, this occurred I the last few days. #4805 has passing CI 7 days ago, so it's recent commits. With any luck, I should narrow down the cause of this in a day or two.

I'll mark as skipif when on PC in a bit.

[bjones1]

Sounds good. I'll continue playing as well when I have time. I did start too far back in time...

[Legorooj]

I've skipped the tests in 6aebb5c.

I'll work on debugging it now.

[Legorooj]

Found the bad commit. I'm going to run CI on a branch which has the commit removed to check it works, but the first bad commit is 70709cd from PR #4592.

https://github.com/Legorooj/pyinstaller/runs/652139359?check_suite_focus=true

[bjones1]

Wow, I never would have guessed that. Nice job using git bisect. I have absolutely no clue why this causes it, though -- to fix, it will definitely take time on a Mac. For now, just point to this issue and add the skipif.

[Legorooj]

Scratch what I said. Apparently I hadn't dropped the commit - git had sneaked it back in there during one of the rebases. I just tried again, and got loads of conflicts. I tried to resolve them, but the result was the bootloader wouldn't compile.

We should leave the skipif for now.

@htgoebel @danyeaw can we have help here? You two wrote the code that caused this.

Also, I think this isn't actually a failiure of Qt, its a failiure of the bootloader. ... sys.exit(res)\n', 'int: 0\n']. I think the new traceback isn't reading properly.

[andyfaff]

I have a mac and am happy to donate some time running tests to see where things fail. However, I'm not familiar with the internals of pyinstaller, so won't be able to contribute much to fixes to start with.

[Legorooj]

@andyfaff can you write or read C? If so, help would be great. Also, this issue isn't particularly internal (ie not modulegraph):

Also, I think this isn't actually a failiure of Qt, its a failiure of the bootloader. `... sys.exit(res)\n', 'int: 0\n']. I think the new traceback isn't reading properly.

[andyfaff]

I'm somewhat familiar with C, but nothing too complicated.

[Legorooj]

@andyfaff if you could take a look, that'd be great. Take a look at the source code for the failing test, and try to replicate without using pytest (You'll need to build with -d noarchive -d bootloader). Then figure out why 70709cd is causing the failiure.

Thanks!

[danyeaw]

If we are having trouble debugging the issue, we could also pull out support for macOS in the implementation of #4592. Unfortunately, I don't have a mac to test this on.

[Legorooj]

@danyeaw I'll pull support for the new traceback on Apple today, and use the old traceback for apple.

[Legorooj]

Support for apple has been dropped in bcf7fae. Now we need to figure out why it was causing errors.

[Legorooj]

Found da bug.

pyinstaller/bootloader/src/pyi_launch.c

Lines 415 to 422 in b5ebff3

	retval = PI_PyEval_EvalCode(code, main_dict, main_dict);
	/* If retval is NULL, an error occurred. Otherwise, it is a Python object.
	* (Since we evaluate module-level code, which is not allowed to return an
	* object, the Python object returned is always None.) */
	if (!retval) {
	FATALERROR("Failed to execute script %s\n", ptoc->name);

This used to be:

pyinstaller/bootloader/src/pyi_launch.c

Lines 418 to 428 in b3dd91c

	retval = PI_PyEval_EvalCode(code, main_dict, main_dict);
	/* If retval is NULL, an error occured. Otherwise, it is a Python object.
	* (Since we evaluate module-level code, which is not allowed to return an
	* object, the Python object returned is always None.) */
	if (!retval) {
	PI_PyErr_Print();
	/* If the error was SystemExit, PyErr_Print calls exit() without
	* returning. So don't print "Failed to execute" on SystemExit. */
	FATALERROR("Failed to execute script %s\n", ptoc->name);
	return -1;

The comment in the original - 2nd snippet - shows the cause. We aren't checking if this is a SystemExit with the new traceback. I'll get to work on fixing this.