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_close_session_signal intermittently failing #166

Closed
smcv opened this issue Sep 6, 2024 · 3 comments · Fixed by #168
Closed

test_close_session_signal intermittently failing #166

smcv opened this issue Sep 6, 2024 · 3 comments · Fixed by #168

Comments

@smcv
Copy link
Contributor

smcv commented Sep 6, 2024

I'm seeing intermittent test failures with 0.8.0 (example full log) which still seem to be present in 0.8.1:

=================================== FAILURES ===================================
_________________ TestRemoteDesktop.test_close_session_signal __________________

self = <pyportaltest.test_remotedesktop.TestRemoteDesktop testMethod=test_close_session_signal>

    def test_close_session_signal(self):
        """
        Ensure that we get the GObject signal when our session is closed
        externally.
        """
        params = {"close-after-start": 500}
        setup = self.create_session(params=params)
        session = setup.session
    
        session_closed_signal_received = False
    
        def session_closed(session):
            nonlocal session_closed_signal_received
            session_closed_signal_received = True
            self.mainloop.quit()
    
        session.connect("closed", session_closed)
    
        self.mainloop.run()
    
>       assert session_closed_signal_received is True
E       assert False is True

pyportaltest/test_remotedesktop.py:599: AssertionError

I'm not sure I understand how this can happen: if session_closed didn't run, then how can we leave self.mainloop.run without having set session_closed_signal_received?

Is it possible that self.mainloop might sometimes be terminated by a leftover signal handler from a previous test, or something like that?

@GeorgesStavracas
Copy link
Member

Hm, I was reasonably sure that commit a8f7b0e would have fixed that - at least it made it unreproducible (so far) here.

@whot any idea what this could be?

@smcv
Copy link
Contributor Author

smcv commented Sep 9, 2024

This mainloop automatically quits after a fixed timeout [which is currently 2 seconds], but only on the first run

I wonder whether this is just too short, on an autobuilder system that might be heavily-loaded? Ideally each test that waits for an event should be explicitly stopping the main loop when that event has been received, so that the timeout in mainloop() is never reached unless something has gone wrong, which would mean it could be made longer (perhaps more like 20s than 2s).

I also wonder whether attributes of the PortalTest, like the _mainloop, its timeout handler, and any signal connections, could be bleeding from one test into the next (I'm not particularly familiar with dbusmock, so I don't know to what extent it recycles test objects between tests). Ideally we'd explicitly disconnect every timeout and signal handler after it has either fired or otherwise become irrelevant.

whot added a commit to whot/libportal that referenced this issue Sep 10, 2024
If our test machine is under load let's keep waiting a bit longer for
the signal to arrive.

Closes flatpak#166
whot added a commit to whot/libportal that referenced this issue Sep 10, 2024
If our test machine is under load let's keep waiting a bit longer for
the signal to arrive.

Closes flatpak#166
@smcv
Copy link
Contributor Author

smcv commented Sep 19, 2024

This doesn't seem to be a memory error, unlike #169. I was able to reproduce it with

LD_PRELOAD=libasan.so.8 ASAN_OPTIONS=detect_leaks=0 meson test -v -C ~/tmp/build/libportal/asan pytest --test-args '-x -s -k test_close_session_signal' --repeat=100 -j1

(it failed on the 22nd iteration) and there was no report of a use-after-free having happened.

whot added a commit to whot/libportal that referenced this issue Oct 9, 2024
If our test machine is under load let's keep waiting a bit longer for
the signal to arrive.

Closes flatpak#166
whot added a commit to whot/libportal that referenced this issue Oct 9, 2024
This works around a race condition where test_close_session_signal
registers a callback but on slow systems the Close signal may be sent
before said callback can be registered.

Closes flatpak#166
whot added a commit to whot/libportal that referenced this issue Oct 10, 2024
This works around a race condition where test_close_session_signal
registers a callback but on slow systems the Close signal may be sent
before said callback can be registered.

Note that we need to keep the returned SessionResult alive so the
XdpSession isn't cleaned up by the Python GC before we finish the test.

Closes flatpak#166
whot added a commit to whot/libportal that referenced this issue Oct 10, 2024
This works around a race condition where test_close_session_signal
registers a callback but on slow systems the Close signal may be sent
before said callback can be registered.

Note that we need to keep the returned SessionResult alive so the
XdpSession isn't cleaned up by the Python GC before we finish the test.

Closes flatpak#166
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants