[ FAILED ] ClientLatency.dropping_latency_is_limited_to_one (AKA dropping_latency_is_closer_to_zero_than_one)

One frame hiccup out of 98. Wait and see how often this happens in CI I guess.

Although this should never happen if threads are being scheduled adequately. The client should be producing many frames per compositor frames and so should never miss like this.

Again:

04:08:00 12: /<<BUILDDIR>>/mir-0.25.0+yakkety2810bzr3811/tests/acceptance-tests/test_latency.cpp:341: Failure
04:08:00 12: Value of: max_latency
04:08:00 12: Expected: is <= 1
04:08:00 12: Actual: 2 (of type unsigned int)
04:08:00 12: [ debug ] 98 frames sampled, averaging 1.0 frames latency
04:08:00 12: [ debug ] 0: 1 1 1 1 1 1 1 1 1 1
04:08:00 12: [ debug ] 10: 1 1 1 1 1 1 1 1 1 1
04:08:00 12: [ debug ] 20: 1 1 1 1 1 1 1 1 1 1
04:08:00 12: [ debug ] 30: 1 1 1 1 1 1 1 1 1 1
04:08:00 12: [ debug ] 40: 1 1 1 1 1 1 1 1 1 1
04:08:00 12: [ debug ] 50: 1 1 1 1 1 1 1 1 1 1
04:08:00 12: [ debug ] 60: 1 1 1 1 1 1 1 1 1 1
04:08:00 12: [ debug ] 70: 1 1 1 1 1 1 1 1 1 1
04:08:00 12: [ debug ] 80: 1 1 1 1 1 1 1 1 1 1
04:08:00 12: [ debug ] 90: 1 1 1 2 1 1 1 1
04:08:00 12: [2016-11-09 04:08:00.110391] mirserver: Stopping
04:08:00 12: [ FAILED ] ClientLatency.dropping_latency_is_limited_to_one (1821 ms)

https://mir-jenkins.ubuntu.com/job/build-2-binpkg-mir/arch=amd64,compiler=gcc,platform=mesa,release=yakkety/2784/consoleFull

Interesting the test only started failing after:

------------------------------------------------------------
revno: 3810 [merge]
author: Kevin DuBois <email address hidden>
committer: Tarmac
branch nick: development-branch
timestamp: Tue 2016-11-08 00:46:03 +0000
message:
  split out the swap interval arrangements from mcl::BufferStream so that MirPresentationChain can alter its submit behaviour as well. Add private functions so that the nested server can make the host server and the nested client agree on swapintervals.

  Approved by mir-ci-bot, Cemil Azizoglu.
------------------------------------------------------------

Although this might help to mask the failures in future and stop the test (under a new name) from failing:

https://code.launchpad.net/~vanvugt/mir/test-for-fractional-latency/+merge/309541

Again:

https://mir-jenkins.ubuntu.com/job/device-runtests-mir/1931/device_type=krillin/consoleFull

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

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

Same problem or a different type of testfail?

19:54:42 [ RUN ] ClientLatency.dropping_latency_is_closer_to_zero_than_one
19:54:42 [2017-01-31 19:54:42.347490] mirserver: Starting
19:54:42 [2017-01-31 19:54:42.347814] mirserver: Selected driver: mir:stub-graphics (version 0.26.0)
19:54:42 [2017-01-31 19:54:42.365959] mirserver: Using software cursor
19:54:42 [2017-01-31 19:54:42.378848] mirserver: Selected input driver: mir:stub-input (version: 0.26.0)
19:54:42 [2017-01-31 19:54:42.379166] mirserver: Mir version 0.26.0
19:54:42 [2017-01-31 19:54:42.387115] mirserver: Initial display configuration:
19:54:42 [2017-01-31 19:54:42.387331] mirserver: Output 1: HDMI-A connected, used
19:54:42 [2017-01-31 19:54:42.387422] mirserver: Physical size 0.0" 0x0mm
19:54:42 [2017-01-31 19:54:42.387506] mirserver: Power is on
19:54:42 [2017-01-31 19:54:42.387580] mirserver: Current mode 1920x1080 60.00Hz
19:54:42 [2017-01-31 19:54:42.387647] mirserver: Preferred mode 1920x1080 60.00Hz
19:54:42 [2017-01-31 19:54:42.387710] mirserver: Orientation normal
19:54:42 [2017-01-31 19:54:42.387786] mirserver: Logical size 1920x1080
19:54:42 [2017-01-31 19:54:42.387887] mirserver: Logical position +0+0
19:54:44 /&lt;&lt;BUILDDIR&gt;&gt;/mir-0.26.0+xenial3900bzr3541/tests/acceptance-tests/test_latency.cpp:376: Failure
19:54:44 Value of: average_latency
19:54:44 Expected: is &lt; 0.5
19:54:44 Actual: 0.50877 (of type float)
19:54:44 [ debug ] 97 frames sampled, averaging 0.509 frames latency
19:54:44 [ debug ] 0: 1.00 1.00 0.50 0.50 0.06 0.07 0.07 0.07 0.08 0.08
19:54:44 [ debug ] 10: 0.08 0.08 0.25 0.25 0.12 0.10 0.17 0.08 0.04 0.25
19:54:44 [ debug ] 20: 0.20 0.50 0.09 0.33 1.00 0.50 1.00 1.00 1.00 1.00
19:54:44 [ debug ] 30: 1.00 1.00 1.00 1.00 1.00 0.50 0.12 0.11 3.00 0.04
19:54:44 [ debug ] 40: 0.10 0.14 2.00 1.00 0.17 0.50 0.50 0.33 0.33 0.25
19:54:44 [ debug ] 50: 0.08 0.07 0.07 0.08 0.07 0.08 0.33 0.33 1.00 0.20
19:54:44 [ debug ] 60: 1.00 0.11 0.17 0.33 1.00 0.11 0.06 0.33 0.50 0.11
19:54:44 [ debug ] 70: 0.11 0.04 0.04 0.07 0.04 0.07 0.06 0.04 0.33 2.00
19:54:44 [ debug ] 80: 2.00 0.50 0.50 1.00 1.00 2.00 1.00 1.00 2.00 1.00
19:54:44 [ debug ] 90: 0.14 1.00 0.14 0.50 0.14 0.04 1.00
19:54:44 [2017-01-31 19:54:44.472992] mirserver: Stopping
19:54:44 [ FAILED ] ClientLatency.dropping_latency_is_closer_to_zero_than_one (2234 ms)

in the same run:
19:54:48 [ RUN ] ClientLatency.async_swap_dropping_latency_is_closer_to_zero_than_one
19:54:48 [2017-01-31 19:54:48.485202] mirserver: Starting
19:54:48 [2017-01-31 19:54:48.485592] mirserver: Selected driver: mir:stub-graphics (version 0.26.0)
19:54:48 [2017-01-31 19:54:48.507703] mirserver: Using software cursor
19:54:48 [2017-01-31 19:54:48.524831] mirserver: Selected input driver: mir:stub-input (version: 0.26.0)
19:54:48 [2017-01-31 19:54:48.525074] mirserver: Mir version 0.26.0
19:54:48 [2017-01-31 19:54:48.535165] mirserver: Initial display configuration:
19:54:48 [2017-01-31 19:54:48.535282] mirserver: Output 1: HDMI-A connecte...

It appears my fix branch just made the bug less likely, not impossible.

This bug was fixed in the package mir - 0.26.0+17.04.20170126.3-0ubuntu1

---------------
mir (0.26.0+17.04.20170126.3-0ubuntu1) zesty; urgency=medium

  [ Daniel van Vugt ]
  * New upstream release 0.26.0 (https://launchpad.net/mir/+milestone/0.26.0)
    - ABI summary:
      . mirclient ABI unchanged at 9
      . mirserver ABI bumped to 43
      . mircommon ABI unchanged at 7
      . mirplatform ABI unchanged at 14
      . mirprotobuf ABI unchanged at 3
      . mirplatformgraphics ABI unchanged at 11
      . mirclientplatform ABI unchanged at 5
      . mirinputplatform ABI unchanged at 6
      . mircore ABI unchanged at 1
    - Enhancements:
      . New/improved toolkit APIs: MirInputConfig and related functions,
        MirWindow and related functions, DisplayConfig and related functions,
        MirScreencastSpec and related functions,
      . Support for configuring input configuration
      . Introduce toolkit extension mechanism for platform specific APIs.
      . Toolkit extensions for: mesa_drm_auth, set_gbm_device and
        window_coordinate_translation
      . Screencasting to a specific MirBuffer.
      . Add DisplayConfigurationController::base_configuration() so downstreams
        can get the base configuration. (Weirdly they can already set it.).
      . x11 platform: allow adjustable scale parameter.
      . Added EDID support: client API, server logging and in mirout.
      . mirout: Add newer attributes only available in the new display
        config API: scaling factor, subpixel arrangement and form factor.
      . mirout: Log the orientation and logical size of each output too.
      . Replace the mir::Server-overridable Reports with Observers.
      . Add xkbcommon to mirclient.pc Requires.private.
      . Deprecate legacy toolkit APIs that will be removed in Mir 1.0
      . Introduced 'client-side vsync', which dramatically reduces latency
        from the client to the screen (particularly for nested servers like
        Unity8).
    - Bugs fixed:
      . [performance] Restore support for better-than-triple buffering by
        default. (LP: #1240909)
      . Frame rate is artificially low on Diamondville Intel Atom systems due
        to aggressive power management (LP: #1388490)
      . [testsfail] failure in CI in
        AndroidInputReceiverSetup.slow_raw_input_doesnt_cause_frameskipping
        (LP: #1394369)
      . [trusted prompt sessions] Can't open two prompt sessions at the same
        time (LP: #1494197)
      . Changing scale, formFactor or DPI in display configuration causes
        renderer teardown/recreate unnecessarily (LP: #1556142)
      . [testsfail] ApplicationNotRespondingDetection.failure_to_pong_is_
        noticed (LP: #1570327)
      . CI failure in TestClientInput.receives_one_touch_event_per_frame
        (LP: #1570698)
      . Mir-on-X mouse input is jerky/stuttery compared to Mir-on-KMS
        (LP: #1576600)
      . [regression] Two fingers in mir_proving_server now resizes/moves app
        windows (two finger apps unusable) (LP: #1586311)
      . Pointer/cursor input lag in unity8 session (LP: #1591328)
      . PointerConfinement.test_we_update_our_confined_region_on_a_resize
      ...

https://mir-jenkins.ubuntu.com/job/build-2-binpkg-mir/arch=amd64,compiler=gcc,platform=mesa,release=zesty/4242/consoleFull

https://mir-jenkins.ubuntu.com/job/build-2-binpkg-mir/arch=i386,compiler=gcc,platform=mesa,release=xenial+overlay/4268/consoleFull

OK, two fails in two days, but zero during the previous 6 weeks or so.

This is an important test so I'd rather have it fail on the odd occasion than to weaken it too much. Although I may well weaken it a little...

Two more fails today:

https://mir-jenkins.ubuntu.com/job/build-2-binpkg-mir/arch=i386,compiler=gcc,platform=mesa,release=xenial/4876/consoleFull

https://mir-jenkins.ubuntu.com/job/build-2-binpkg-mir/arch=i386,compiler=gcc,platform=mesa,release=xenial/4879/consoleFull

And again today:

https://mir-jenkins.ubuntu.com/job/build-2-binpkg-mir/arch=amd64,compiler=gcc,platform=mesa,release=zesty/4892/consoleFull