[regression] [ FAILED ] ClientSurfaceEvents.surface_receives_output_event_on_creation

[Daniel van Vugt]

Seems like a simple failure happening in CI:

[ RUN ] ClientSurfaceEvents.surface_receives_output_event_on_creation
[1449579223.606336] mirserver: Starting
[1449579223.607784] mirserver: Selected driver: dummy (version 0.19.0)
[1449579223.618750] mirserver: Initial display configuration:
[1449579223.619939] mirserver: 1.1: VGA 0.0" 0x0mm
[1449579223.620142] mirserver: Current mode 1600x1600 60.00Hz
[1449579223.620297] mirserver: Preferred mode 1600x1600 60.00Hz
[1449579223.620418] mirserver: Logical position +0+0
[1449579223.628689] mirserver: Using software cursor
[1449579223.632268] mirserver: Selected input driver: stub-input (version: 0.19.0)
[1449579223.632562] mirserver: Mir version 0.19.0
[1449579224.046279] mirserver: New display configuration:
[1449579224.051970] mirserver: 1.1: VGA 0.0" 0x0mm
[1449579224.052194] mirserver: Current mode 1600x1600 60.00Hz
[1449579224.052374] mirserver: Preferred mode 1600x1600 60.00Hz
[1449579224.052518] mirserver: Logical position +0+0
/tmp/buildd/mir-0.18.0bzr3180pkg0xenial76/tests/acceptance-tests/test_client_surface_events.cpp:418: Failure
Value of: mir_surface_output_event_get_form_factor(surface_event)
Expected: is equal to 2
Actual: 3 (of type MirFormFactor)
/tmp/buildd/mir-0.18.0bzr3180pkg0xenial76/tests/acceptance-tests/test_client_surface_events.cpp:419: Failure
Value of: mir_surface_output_event_get_scale(surface_event)
Expected: is equal to 2.15
Actual: 1 (of type float)
[1449579224.139455] mirserver: Stopping
[ FAILED ] ClientSurfaceEvents.surface_receives_output_event_on_creation (549 ms)

https://jenkins.qa.ubuntu.com/job/mir-xenial-amd64-autolanding/76/consoleFull

[Daniel van Vugt (vanvugt)]

Incomplete. Maybe the bug only exists in branch lp:~alan-griffiths/mir/we-dont-need-future-here

[Daniel van Vugt (vanvugt)]

Invalid for Mir. The bug only ever existed in Alan's branch.

[PS Jenkins bot (ps-jenkins)]

Fix committed into lp:mir at revision None, scheduled for release in mir, milestone 0.19.0

[Daniel van Vugt (vanvugt)]

Now happening on trunk. What changed?

See:
https://jenkins.qa.ubuntu.com/job/mir-xenial-i386-autolanding/110/consoleFull
https://code.launchpad.net/~andreas-pokorny/mir/bump-platform-to-5/+merge/280590

[Daniel van Vugt (vanvugt)]

Erm, so now a regression? Started in r3197 probably.

[Alberto Aguirre (albaguirre)]

Confirmed with:

../tools/detect_fd_leaks.bash "/usr/bin/valgrind" "--error-exitcode=1" "--trace-children=yes" "--leak-check=full" "--show-leak-kinds=definite" "--errors-for-leak-kinds=definite" "--track-fds=yes" "--num-callers=128" "--suppressions=../tools/valgrind_suppressions_generic" "--suppressions=../tools/valgrind_suppressions_glibc_2.21" bin/mir_acceptance_tests --gtest_filter=ClientSurfaceEvents.surface_receives_output_event_on_creation --gtest_repeat=100

[Alberto Aguirre (albaguirre)]

So the root cause is a race between ApplicationSession::create_surface and ApplicationSession::send_display_config.

The issue is:

T1 - ApplicationSession::send_display_config
-- calls event_sink->handle_display_config_change(info);
---- Test receives display_config_change_callback
------ Test creates a new surface

T2 pre-empts T1, calls ms::ApplicationSession::create_surface
--- surface is added to stack
--- eventually ends in SurfaceEventSource::moved_to
----- calls OutputPropertiesCache::properties_for which gets a copy of the old cache

T1 pre-empts T2
--- Updates OutputPropertiesCache with new display config
---- Sends surface output event with new config values
------exits send_display_config

T2 runs
--- Sends event with old display config values

[PS Jenkins bot (ps-jenkins)]

Fix committed into lp:mir at revision None, scheduled for release in mir, milestone 0.19.0

[Daniel van Vugt (vanvugt)]

mir (0.19.0+16.04.20160128-0ubuntu1) xenial; urgency=medium