Testbed failures on macOS

[HalfWhitt]

I believe I have my development environment set up correctly — I have an editable install from my (up-to-date) fork of the repo, and the core test suite runs just fine. However, the testbed test suite fails, mostly about various sizing checks:

=========================== short test summary info ============================
FAILED tests/test_window.py::test_secondary_window[second_window_kwargs0] - a...
FAILED tests/test_window.py::test_secondary_window_with_args[second_window_kwargs0]
FAILED tests/test_window.py::test_visibility[second_window_kwargs0] - assert ...
FAILED tests/test_window.py::test_move_and_resize[second_window_kwargs0] - as...
FAILED tests/widgets/test_box.py::test_flex_widget_size - assert 200.0 > 350
FAILED tests/widgets/test_button.py::test_flex_horizontal_widget_size - Asser...
FAILED tests/widgets/test_canvas.py::test_flex_widget_size - assert 200.0 > 350
FAILED tests/widgets/test_canvas.py::test_resize - assert 300 > 300
FAILED tests/widgets/test_detailedlist.py::test_flex_widget_size - assert 200...
FAILED tests/widgets/test_detailedlist.py::test_actions - AssertionError: Exp...
FAILED tests/widgets/test_multilinetextinput.py::test_flex_widget_size - asse...
FAILED tests/widgets/test_optioncontainer.py::test_flex_widget_size - assert ...
FAILED tests/widgets/test_optioncontainer.py::test_select_tab - assert 394.0 ...
FAILED tests/widgets/test_optioncontainer.py::test_change_content - assert 39...
FAILED tests/widgets/test_scrollcontainer.py::test_flex_widget_size - assert ...
FAILED tests/widgets/test_splitcontainer.py::test_flex_widget_size - assert 3...
FAILED tests/widgets/test_splitcontainer.py::test_set_direction - assert 202....
FAILED tests/widgets/test_splitcontainer.py::test_move_splitter - assert 302....
FAILED tests/widgets/test_table.py::test_flex_widget_size - assert 300.0 > 350
FAILED tests/widgets/test_tree.py::test_flex_widget_size - assert 300.0 > 350
FAILED tests/widgets/test_tree.py::test_select - AssertionError: assert <Node...
FAILED tests/widgets/test_tree.py::test_multiselect - AssertionError: assert ...
FAILED tests/widgets/test_tree.py::test_column_changes - assert False
FAILED tests/widgets/test_webview.py::test_flex_widget_size - assert 300.0 > 350
= 24 failed, 362 passed, 26 skipped, 12 xfailed, 16 warnings in 63.78s (0:01:03) =

Since I've seen that everything passes on CI, I'm wondering if perhaps I have something misconfigured; at the same time, I'm not on the same version of macOS as the CI server, so perhaps there's a version-dependent bug?

	My machine	CI test
macOS	13.5	12.6.9
Python	3.12.0	3.10.13

Any idea what might be doing this? I can provide the full results of the failed tests if that would be helpful.

[freakboy3742]

I can't say I've seen that particular set of failures before.

I've just run the test suite on Python 3.12.0, on macOS 13.5.2, on a 16" M1 Pro-based MacBook Pro - I get no test failures (I do see 2 missing branch coverage failures, but those looks like they're due to changes in how coverage is computed in Python 3.12).
If you're running on particularly faster or slower hardware (so - an M2 Ultra, or older x86 hardware), it might be timing differences that you're hitting. That shouldn't happen - and CI runs on x86_64 hardware, so that should rule that out as a cause - but anything is possible.

One thing I've noticed is that a failure in the window tests can sometimes have cascading impacts on subsequent tests. The tests should be isolated, but that's difficult to guarantee when the tests are all running in the same "app". As a result, a failure in the window tests can change the size of the window; and if the test doesn't recover correctly, that can cause subsequent tests to fail because the window isn't the expected size.

Some ideas on how to narrow this down:

1. Run the test suite again. Do you get exactly the same failures? Note that the test suite is very sensitive to touching the mouse while the tests are running - so start the test suite, and don't touch the computer until the test suite finishes.
2. Do you get different results if you run as briefcase dev --test vs briefcase run --test? This shouldn't matter, but if it gives different results, it might point at a problem. FWIW, CI is doing run.
3. Run a subset of the test suite - say, just the table tests (briefcase dev --test -- tests/widgets/test_table.py) or just the widget tests (briefcase dev --test -- tests/widgets). Do the same tests fail? If they don't, that could be the issue.
4. Run the tests (or a subset of the tests) with --slow (i.e. briefcase dev --test -- --slow). This runs the test suite in "slow mode", which is a lot easier to see what is going on. Do you get the same failures? If not, then it's definitely a timing issue, so we need to work out why your machine is handling events differently.
5. Comment out the first test that fails. Does the suite still generate the same failures? If not, then there's something in the failure mode of that first test that is causing cascading problems.

[freakboy3742]

Well that's... good news? I think? :-)

If the problem is the Window tests, we can focus in on exactly what is causing them to fail.

If you run each of the problem tests by themselves (e.g., briefcase dev --test -- tests/test_window.py::test_visibility) - do they still fail? If so - can you run them with --slow enabled, and see if the log of what the test should be doing - where do they go off the rails?

Sharing the full log for each of those test failures would also be helpful at this point.

[HalfWhitt]

Okay, I've done some more fiddling. I've confirmed that running in normal vs. slow speed doesn't change any results, and neither does running the window tests individually vs. altogether. What I have found is that, somehow, test_app.py::test_main_window_toolbar, while it passes, has a cascading effect on three of the window tests, causing test_secondary_window to fail and changing with what dimensions test_secondary_window_with_args and test_visibility fail.

	Expected	Without toolbar test	After toolbar test
test_secondary_window	640 x 480	Passes	640 x 532
test_secondary_window_with_args	300 x 200	640 x 480	640 x 532
test_visibility	640 x 480	100 x 100	640 x 532
test_move_and_resize	200 x 150	200 x 156	200 x 156

Relevant bits of logs from running tests in slow mode:

test_secondary_window

tests/test_window.py::test_secondary_window[second_window_kwargs0] Window (Toga) has been created
Secondary window has been closed
PASSED

test_secondary_window_with_args

tests/test_window.py::test_secondary_window_with_args[second_window_kwargs0] Window (Secondary Window) has been created
Secondary window has been shown
FAILED

=================================== FAILURES ===================================
____________ test_secondary_window_with_args[second_window_kwargs0] ____________
Traceback (most recent call last):
  File "/Users/charles/toga_dev/toga/testbed/tests/test_window.py", line 196, in test_secondary_window_with_args
    assert second_window.size == (300, 200)
AssertionError: assert (640.0, 480.0) == (300, 200)
  At index 0 diff: 640.0 != 300
  Full diff:
  - (300, 200)
  + (640.0, 480.0)

test_visibility

tests/test_window.py::test_visibility[second_window_kwargs0] Window (Secondary Window) has been created
FAILED

=================================== FAILURES ===================================
____________________ test_visibility[second_window_kwargs0] ____________________
Traceback (most recent call last):
  File "/Users/charles/toga_dev/toga/testbed/tests/test_window.py", line 322, in test_visibility
    assert second_window.position == (200, 150)
AssertionError: assert (100.0, 100.0) == (200, 150)
  At index 0 diff: 100.0 != 200
  Full diff:
  - (200, 150)
  + (100.0, 100.0)

test_move_and_resize

tests/test_window.py::test_move_and_resize[second_window_kwargs0] Window (Secondary Window) has been created
Secondary window has been moved
Secondary window has been resized
FAILED

=================================== FAILURES ===================================
_________________ test_move_and_resize[second_window_kwargs0] __________________
Traceback (most recent call last):
  File "/Users/charles/toga_dev/toga/testbed/tests/test_window.py", line 403, in test_move_and_resize
    assert second_window.size == (200, 150)
AssertionError: assert (200.0, 156.0) == (200, 150)
  At index 1 diff: 156.0 != 150
  Full diff:
  - (200, 150)
  + (200.0, 156.0)
  ?     ++    ++

Five tests in a row:

• test_main_window_toolbar
• test_secondary_window
• test_secondary_window_with_args
• test_visibility
• test_move_resize

tests/test_app.py::test_main_window_toolbar 
Constructing Window probe
Main window has a toolbar
Command 1 invoked
Command 1 disabled
Command 1 re-enabled
Main window has no toolbar
Main window has no toolbar
PASSED
tests/test_window.py::test_secondary_window[second_window_kwargs0] Window (Toga) has been created
FAILED
tests/test_window.py::test_secondary_window_with_args[second_window_kwargs0] Window (Secondary Window) has been created
Secondary window has been shown
FAILED
tests/test_window.py::test_visibility[second_window_kwargs0] Window (Secondary Window) has been created
FAILED
tests/test_window.py::test_move_and_resize[second_window_kwargs0] Window (Secondary Window) has been created
Secondary window has been moved
Secondary window has been resized
FAILED

=================================== FAILURES ===================================
_________________ test_secondary_window[second_window_kwargs0] _________________
Traceback (most recent call last):
  File "/Users/charles/toga_dev/toga/testbed/tests/test_window.py", line 167, in test_secondary_window
    assert second_window.size == (640, 480)
AssertionError: assert (640.0, 532.0) == (640, 480)
  At index 1 diff: 532.0 != 480
  Full diff:
  - (640, 480)
  + (640.0, 532.0)
____________ test_secondary_window_with_args[second_window_kwargs0] ____________
Traceback (most recent call last):
  File "/Users/charles/toga_dev/toga/testbed/tests/test_window.py", line 196, in test_secondary_window_with_args
    assert second_window.size == (300, 200)
AssertionError: assert (640.0, 532.0) == (300, 200)
  At index 0 diff: 640.0 != 300
  Full diff:
  - (300, 200)
  + (640.0, 532.0)
____________________ test_visibility[second_window_kwargs0] ____________________
Traceback (most recent call last):
  File "/Users/charles/toga_dev/toga/testbed/tests/test_window.py", line 321, in test_visibility
    assert second_window.size == (640, 480)
AssertionError: assert (640.0, 532.0) == (640, 480)
  At index 1 diff: 532.0 != 480
  Full diff:
  - (640, 480)
  + (640.0, 532.0)
_________________ test_move_and_resize[second_window_kwargs0] __________________
Traceback (most recent call last):
  File "/Users/charles/toga_dev/toga/testbed/tests/test_window.py", line 403, in test_move_and_resize
    assert second_window.size == (200, 150)
AssertionError: assert (200.0, 156.0) == (200, 150)
  At index 1 diff: 156.0 != 150
  Full diff:
  - (200, 150)
  + (200.0, 156.0)
  ?     ++    ++

Something that occurs to me — I don't know what screen size the CI simulates, but you mentioned you ran your tests on a 16" M1 Macbook Pro, which if I'm not mistaken has a 3456 x 2234 display. I'm still living in the low-res times of yesteryear, and each of my monitors is only 2560 x 1440. Perhaps lower screen resolution is a factor?

[freakboy3742]

That's some good debugging info - thanks for all that.

Screen size differences is an interesting theory for the cause, and I can't 100% rule it out... but it seems unlikely. FWIW, I'm running on a 16" MacBook with 2 external 4K monitors (running 1920x1080, the "larger text" scaling option), and the "primary" where the tests are running is one of the externals - but I get the same successes on a Mac mini with a 1080p screen. I don't know what sized screen CI is using, but the tests themselves don't use a window any larger than 640x480 (plus toolbar allowances), positioned no further from the origin than (300, 300) - and most of those "far from home" tests are also with a smaller window - so it would need to be a particularly small window for those sizes to become a problem. Plus, you can define windows that are bigger than the screen and position them off secreen... you just can't control them with the mouse :-)

What seems more likely is the extra size is related to the toolbar somehow. The interesting detail I noticed from the pass/fail window size info you provided is that the "failed" size (640x532) is the size of a window with a toolbar - but the secondary window shouldn't have a toolbar, or be sized to accomodate one.

Using the following test run:
briefcase dev --test -- tests/test_app.py::test_main_window_toolbar tests/test_window.py::test_secondary_window --slow
This is what the app looks like for me just after the "Window (Toga) has been created" message is logged:

There should be 2 windows - the Secondary window (grey background) on top of the Primary window (yellow background). The Primary window is slightly taller because it did have a toolbar, but it should have lost the toolbar at the end of the main_window_toolbar test.

Does this match what you're seeing?

[HalfWhitt]

Oh holy crap! Mine showed up as a tab rather than a window, apparently! I hadn't even noticed.

It also shows up as a tab if I omit the toolbar test. But then that would be why the window size is different in those two cases!

[HalfWhitt]

Just confirming — yep, post-toolbar on the left, without toolbar test on the right.

[freakboy3742]

😳

Well.. that would do it then :-)

I presume you have the "Prefer tabs when opening documents" display setting to True? The immediate fix will be to turn off that setting (or at least make it "full screen only"). That's definitely something worth documenting in the contribution guide.

Ideally, the test suite wouldn't be sensitive to this setting - either turning it off on a per-app basis, or identifying when it's turned on and validating the different behavior. I'm not sure how easy that would be though - just documenting "don't do this" may be the much easier option.

Either way... fancy trying your hand at a PR?

[freakboy3742]

From a quick search, it looks like NSWindow.allowsAutomaticWindowTabbing is the magic method here. We probably don't want to turn this off for all cocoa windows, but should definitely turn it off in the test framework when a WindowProbe is wrapped around a window (i.e., in the constructor for cocoa/tests_backend/window.py)

[freakboy3742]

Yup - putting NSWindow.allowsAutomaticWindowTabbing = False in the WindowProbe constructor looks like it does the job.

[HalfWhitt]

...I had forgotten that even was a setting. And sure, I'd be happy to try a PR! I haven't looked at the testbed / implementation layer much yet but I'll give it a go.

[HalfWhitt]

Okay, I may need a little hand-holding here. (I appreciate you taking the time to let me try a PR for something you've obviously already figured out how to fix.)

I can verify that the class NSWindow has an attribute named allowsAutomaticWindowTabbing which is initially True, but setting it to False in the WindowProbe constructor has no visible effect on the test.

I also see in the WindowProbe constructor that self.native is a toga_cocoa.window.TogaWindow, which subclasses NSWindow, yet has no visible allowsAutomaticWindowTabbing attribute. I tried self.native.allowsAutomaticWindowTabbing = False anyway, still no dice.

I've never messed with interfacing to Objective C — what am I missing? How to I successfully turn off that flag?

Also if my debugging print calls are to be believed, the WindowProbe constructor is only called once; I don't see its output again when the secondary window is created, whether I have my global "open in tabs" setting on or off. Is that normal?

[freakboy3742]

You're missed one really subtle detail in the documentation of allowsAutomaticWindowTabbing - it's a class attribute.

So - you access it as NSWindow.allowsAutomaticWindowTabbing, not self.native.allowsAutomaticWindowTabbing. Rubicon will allow you to set the attribute on a NSWindow instance (because you can set any attribute you like on a Python object), but it won't do anything when you set it, because it's not tied to an ObjC attribute under the hood. And if you try to look for the attribute on an arbitrary NSWindow instance, it won't be there.

As for the when the WindowProbe is constructed, and seeing debug statements; you won't see print output unless a test fails, or you're running --slow, or use the -s flag (to disable stdout capture).

WindowProbe should be called once per window instance that is created - the MainWindow is only created once per test run, but you should be seeing (and I am seeing in my testing) an extra WindowProbe invocation in each of the "Secondary Window" tests.

[HalfWhitt]

Huh. Okay. I now realize that I was doing it right the first time, but that the result depends, for some reason, on the order of tests. With the global tabs preference set to Always and NSWindow.allowsAutomaticWindowTabbing = False in the constructor, the first test I run will open a second window as a tab. Any subsequent tests will open new windows as intended.

I suppose that's technically okay, as long as there's a note that you always have to run at least one other test before one that depends on creating a separate window, or make sure your tab setting is turned off. I guess I'll put a note in the testbed How To section as part of the pull request.