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

[ FAILED ] ClientSurfaceEventsTest.buffer_release #22

Closed
AlanGriffiths opened this issue Apr 26, 2018 · 4 comments
Closed

[ FAILED ] ClientSurfaceEventsTest.buffer_release #22

AlanGriffiths opened this issue Apr 26, 2018 · 4 comments

Comments

@AlanGriffiths
Copy link
Contributor

$ while cmake-build-debug/bin/mir_wlcs_tests --gtest_filter=ClientSurfaceEventsTest.buffer_release; do :; done

Expect: continues to pass indefinitely
Actual: After around a minute:

Note: Google Test filter = ClientSurfaceEventsTest.buffer_release
[==========] Running 1 test from 1 test case.
[----------] Global test environment set-up.
[----------] 1 test from ClientSurfaceEventsTest
[ RUN      ] ClientSurfaceEventsTest.buffer_release
[2018-04-26 11:19:24.699071] mirserver: Selected driver: mir:stub-graphics (version 0.31.2)
[2018-04-26 11:19:24.699280] <DEBUG> mirserver: No session management supported
[2018-04-26 11:19:24.699535] mirserver: Starting
[2018-04-26 11:19:24.706867] mirserver: Using software cursor
[2018-04-26 11:19:24.709797] mirserver: Selected input driver: mir:stub-input (version: 0.31.2)
unable to open lockfile /run/user/1000/snap.clion/wayland-0.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-1.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-2.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-3.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-4.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-5.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-6.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-7.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-8.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-9.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-10.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-11.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-12.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-13.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-14.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-15.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-16.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-17.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-18.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-19.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-20.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-21.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-22.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-23.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-24.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-25.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-26.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-27.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-28.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-29.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-30.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-31.lock check permissions
unable to open lockfile /run/user/1000/snap.clion/wayland-32.lock check permissions
[2018-04-26 11:19:24.711140] mirserver: Mir version 0.31.2
[2018-04-26 11:19:24.711689] mirserver: Initial display configuration:
[2018-04-26 11:19:24.711722] mirserver: * Output 1: VGA connected, used
[2018-04-26 11:19:24.711752] mirserver: . |_ Physical size 0.0" 0x0mm
[2018-04-26 11:19:24.711766] mirserver: . |_ Power is on
[2018-04-26 11:19:24.711780] mirserver: . |_ Current mode 1600x1600 60.00Hz
[2018-04-26 11:19:24.711794] mirserver: . |_ Preferred mode 1600x1600 60.00Hz
[2018-04-26 11:19:24.711806] mirserver: . |_ Orientation normal
[2018-04-26 11:19:24.711820] mirserver: . |_ Logical size 1600x1600
[2018-04-26 11:19:24.711832] mirserver: . |_ Logical position +0+0
[2018-04-26 11:19:24.711844] mirserver: . |_ Scaling factor: 1.00
/home/alan/display_server/mir/tests/acceptance-tests/wayland/wlcs/tests/test_surface_events.cpp:566: Failure
Value of: buffer_released[1]
  Actual: false
Expected: true
[2018-04-26 11:19:24.714914] mirserver: Stopping
[  FAILED  ] ClientSurfaceEventsTest.buffer_release (22 ms)
[----------] 1 test from ClientSurfaceEventsTest (22 ms total)

[----------] Global test environment tear-down
[==========] 1 test from 1 test case ran. (22 ms total)
[  PASSED  ] 0 tests.
[  FAILED  ] 1 test, listed below:
[  FAILED  ] ClientSurfaceEventsTest.buffer_release
@AlanGriffiths
Copy link
Contributor Author

Also in CI:

[ RUN ] ClientSurfaceEventsTest.buffer_release
[2018-05-01 08:56:14.059625] mirserver: Selected driver: mir:stub-graphics (version 0.31.2)
[2018-05-01 08:56:14.059692] <DEBUG> mirserver: Using Linux VT subsystem for session management
[2018-05-01 08:56:14.060007] mirserver: Starting
[2018-05-01 08:56:14.066034] mirserver: Using software cursor
[2018-05-01 08:56:14.066832] mirserver: Selected input driver: mir:stub-input (version: 0.31.2)
[2018-05-01 08:56:14.067508] mirserver: Mir version 0.31.2
[2018-05-01 08:56:14.068746] mirserver: Initial display configuration:
[2018-05-01 08:56:14.068765] mirserver: CTestConfig.cmake CTestTestfile.cmake steer.cmake Testing Output 1: VGA connected, used
[2018-05-01 08:56:14.068773] mirserver: . |_ Physical size 0.0" 0x0mm
[2018-05-01 08:56:14.068786] mirserver: . |_ Power is on
[2018-05-01 08:56:14.068792] mirserver: . |_ Current mode 1600x1600 60.00Hz
[2018-05-01 08:56:14.068797] mirserver: . |_ Preferred mode 1600x1600 60.00Hz
[2018-05-01 08:56:14.068800] mirserver: . |_ Orientation normal
[2018-05-01 08:56:14.068805] mirserver: . |_ Logical size 1600x1600
[2018-05-01 08:56:14.068809] mirserver: . |_ Logical position +0+0
[2018-05-01 08:56:14.068813] mirserver: . |_ Scaling factor: 1.00
message too short, object (49), message done(u)
unknown file: Failure
C++ exception with description "Error while dispatching Wayland events: Invalid argument" thrown in the test body.
[2018-05-01 08:56:14.070339] mirserver: Stopping
[ FAILED ] ClientSurfaceEventsTest.buffer_release (12 ms)

https://api.travis-ci.org/v3/job/373384346/log.txt

@AlanGriffiths
Copy link
Contributor Author

Seen again locally (after around 10min of $ rm core;while cmake-build-debug/bin/mir_wlcs_tests --gtest_filter=-Bad*:Copy*; do :; done):

[ RUN      ] ClientSurfaceEventsTest.buffer_release
[2018-05-10 11:04:55.160460] mirserver: Selected driver: mir:stub-graphics (version 0.31.2)
[2018-05-10 11:04:55.160606] <DEBUG> mirserver: No session management supported
[2018-05-10 11:04:55.170491] mirserver: Starting
[2018-05-10 11:04:55.176701] mirserver: Using software cursor
[2018-05-10 11:04:55.177551] mirserver: Selected input driver: mir:stub-input (version: 0.31.2)
[2018-05-10 11:04:55.178176] mirserver: Mir version 0.31.2
[2018-05-10 11:04:55.178539] mirserver: Initial display configuration:
[2018-05-10 11:04:55.178562] mirserver: * Output 1: VGA connected, used
[2018-05-10 11:04:55.178645] mirserver: . |_ Physical size 0.0" 0x0mm
[2018-05-10 11:04:55.178662] mirserver: . |_ Power is on
[2018-05-10 11:04:55.178669] mirserver: . |_ Current mode 1600x1600 60.00Hz
[2018-05-10 11:04:55.178707] mirserver: . |_ Preferred mode 1600x1600 60.00Hz
[2018-05-10 11:04:55.178724] mirserver: . |_ Orientation normal
[2018-05-10 11:04:55.178730] mirserver: . |_ Logical size 1600x1600
[2018-05-10 11:04:55.178738] mirserver: . |_ Logical position +0+0
[2018-05-10 11:04:55.178744] mirserver: . |_ Scaling factor: 1.00
message too short, object (8753), message done(u)
unknown file: Failure
C++ exception with description "Error while dispatching Wayland events: Invalid argument" thrown in the test body.
[2018-05-10 11:04:55.192773] mirserver: Stopping
[  FAILED  ] ClientSurfaceEventsTest.buffer_release (35 ms)

NB I can only run that long without hitting other issues with canonical/mir#356, canonical/mir#360 & wlcs master

@AlanGriffiths
Copy link
Contributor Author

AlanGriffiths commented May 10, 2018

A bit of soak testing with:

while cmake-build-debug/bin/mir_wlcs_tests --gtest_filter=ClientSurfaceEventsTest.buffer_release; do :; done

Shows two failure modes:

  1. The expectation failure above
  2. A hang at the earlier client.dispatch_until() on line 540

I note that this test submits buffers (which we've also noted problems with in the discussion of #30). Also, with the merges mentioned above we seem to be stable on the remaining tests (so we may have only one underlying issue left). The following ran for around 20min:

while bin/mir_wlcs_tests --gtest_filter=-Bad*:Copy*:ClientSurfaceEventsTest.buffer_release; do :; done

@AlanGriffiths
Copy link
Contributor Author

Part of the answer is that the frame callback done() and buffer release() do not appear to be ordered. Specifically, from a passing run I see:

[2237162.190]  -> wl_buffer@13.release()
[2237162.217]  -> wl_callback@20.done(0)

And from a failing (expectation) run

[2237271.319]  -> wl_callback@20.done(0)
...
[2237271.362]  -> wl_buffer@17.release()

@AlanGriffiths AlanGriffiths mentioned this issue May 10, 2018
bors bot added a commit that referenced this issue May 10, 2018
33: fix-22 r=wmww a=AlanGriffiths

Block in create_visible_surface() until we get a frame callback. (Fixes #22)

Otherwise test logic using frame callbacks becomes racy.

Also disabled CopyCutPaste.given_source_has_offered_data_sink_sees_offer as it isn't obvious why that's broken.

Co-authored-by: Alan Griffiths <alan@octopull.co.uk>
@bors bors bot closed this as completed in #33 May 10, 2018
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

No branches or pull requests

1 participant