Mir

[ FAILED ] NestedInput.nested_event_filter_receives_keyboard_from_host

Bug #1613523 reported by Daniel van Vugt on 2016-08-16
20
This bug affects 3 people
Affects Status Importance Assigned to Milestone
Mir
Triaged
High
Unassigned
mir (Ubuntu)
High
Unassigned

Bug Description

Sounds like bug 1462033 but seems different...

06:57:59 [ RUN ] NestedInput.nested_event_filter_receives_keyboard_from_host
06:57:59 unknown file: Failure
06:57:59
06:57:59 Unexpected mock function call - returning default value.
06:57:59 Function call: handle(key_event(when=529970166879 (1.635846ms ago), from=1, down, code=97, scan=30, modifiers=1))
06:57:59 Returns: false
06:57:59 Google Mock tried the following 3 expectations, but none matched:
06:57:59
06:57:59 /build/mir-CSdSFG/mir-0.24.0+vivid1833bzr3644/tests/acceptance-tests/test_nested_input.cpp:195: tried expectation #0: EXPECT_CALL(nested_event_filter, handle(mt::InputDeviceStateEvent()))...
06:57:59 Expected arg #0: input device state event
06:57:59 Actual: key_event(when=529970166879 (1.214154ms ago), from=1, down, code=97, scan=30, modifiers=1)
06:57:59 Expected: to be called once
06:57:59 Actual: never called - unsatisfied and active
06:57:59 /build/mir-CSdSFG/mir-0.24.0+vivid1833bzr3644/tests/acceptance-tests/test_nested_input.cpp:196: tried expectation #1: EXPECT_CALL(nested_event_filter, handle(mt::KeyOfScanCode(30)))...
06:57:59 Expected: all pre-requisites are satisfied
06:57:59 Actual: the following immediate pre-requisites are not satisfied:
06:57:59 /build/mir-CSdSFG/mir-0.24.0+vivid1833bzr3644/tests/acceptance-tests/test_nested_input.cpp:195: pre-requisite #0
06:57:59 (end of pre-requisites)
06:57:59 Expected: to be called at least once
06:57:59 Actual: never called - unsatisfied and active
06:57:59 /build/mir-CSdSFG/mir-0.24.0+vivid1833bzr3644/tests/acceptance-tests/test_nested_input.cpp:200: tried expectation #2: EXPECT_CALL(nested_event_filter, handle(mt::KeyOfScanCode(54)))...
06:57:59 Expected arg #0: key of scan code 54
06:57:59 Actual: key_event(when=529970166879 (1.579538ms ago), from=1, down, code=97, scan=30, modifiers=1)
06:57:59 Expected: to be called twice
06:57:59 Actual: never called - unsatisfied and active
06:57:59 [ FAILED ] NestedInput.nested_event_filter_receives_keyboard_from_host (200 ms)

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

Related branches

tags: added: testsfail
summary: - FAILED ] NestedInput.nested_event_filter_receives_keyboard_from_host
+ [ FAILED ] NestedInput.nested_event_filter_receives_keyboard_from_host
Daniel van Vugt (vanvugt) wrote :

See also duplicate bug 1623059

Daniel van Vugt (vanvugt) wrote :
Download full text (3.8 KiB)

Again:

06:50:03 [ RUN ] NestedInput.nested_event_filter_receives_keyboard_from_host
06:50:03 unknown file: Failure
06:50:03
06:50:03 Unexpected mock function call - returning default value.
06:50:03 Function call: handle(key_event(when=419249997874 (1.613693ms ago), from=1, down, code=97, scan=30, modifiers=1))
06:50:03 Returns: false
06:50:03 Google Mock tried the following 3 expectations, but none matched:
06:50:03
06:50:03 /build/mir-nODQMP/mir-0.25.0+vivid2815bzr3811/tests/acceptance-tests/test_nested_input.cpp:195: tried expectation #0: EXPECT_CALL(nested_event_filter, handle(mt::InputDeviceStateEvent()))...
06:50:03 Expected arg #0: input device state event
06:50:03 Actual: key_event(when=419249997874 (1.139231ms ago), from=1, down, code=97, scan=30, modifiers=1)
06:50:03 Expected: to be called once
06:50:03 Actual: never called - unsatisfied and active
06:50:03 /build/mir-nODQMP/mir-0.25.0+vivid2815bzr3811/tests/acceptance-tests/test_nested_input.cpp:196: tried expectation #1: EXPECT_CALL(nested_event_filter, handle(mt::KeyOfScanCode(30)))...
06:50:03 Expected: all pre-requisites are satisfied
06:50:03 Actual: the following immediate pre-requisites are not satisfied:
06:50:03 /build/mir-nODQMP/mir-0.25.0+vivid2815bzr3811/tests/acceptance-tests/test_nested_input.cpp:195: pre-requisite #0
06:50:03 (end of pre-requisites)
06:50:03 Expected: to be called at least once
06:50:03 Actual: never called - unsatisfied and active
06:50:03 /build/mir-nODQMP/mir-0.25.0+vivid2815bzr3811/tests/acceptance-tests/test_nested_input.cpp:200: tried expectation #2: EXPECT_CALL(nested_event_filter, handle(mt::KeyOfScanCode(54)))...
06:50:03 Expected arg #0: key of scan code 54
06:50:03 Actual: key_event(when=419249997874 (1.548308ms ago), from=1, down, code=97, scan=30, modifiers=1)
06:50:03 Expected: to be called twice
06:50:03 Actual: never called - unsatisfied and active
06:50:03 unknown file: Failure
06:50:03
06:50:03 Unexpected mock function call - returning default value.
06:50:03 Function call: handle(key_event(when=419250811721 (3.481538ms ago), from=1, up, code=97, scan=30, modifiers=1))
06:50:03 Returns: false
06:50:03 Google Mock tried the following 3 expectations, but none matched:
06:50:03
06:50:03 /build/mir-nODQMP/mir-0.25.0+vivid2815bzr3811/tests/acceptance-tests/test_nested_input.cpp:195: tried expectation #0: EXPECT_CALL(nested_event_filter, handle(mt::InputDeviceStateEvent()))...
06:50:03 Expected arg #0: input device state event
06:50:03 Actual: key_event(when=419250811721 (2.989076ms ago), from=1, up, code=97, scan=30, modifiers=1)
06:50:03 Expected: to be called once
06:50:03 Actual: never called - unsatisfied and active
06:50:03 /build/mir-nODQMP/mir-0.25.0+vivid2815bzr3811/tests/acceptance-tests/test_nested_input.cpp:196: tried expectation #1: EXPECT_CALL(nested_event_filter, handle(mt::KeyOfScanCode(30)))...
06:50:03 Expected: all pre-requisites are satisfied
06:50:03 Actual: the following immediate pre-requisites are not satisfied:
06:50:03 /build/mir-nODQMP/mir-0.25.0+vivid2815bzr3811/tests/acceptance-tests/test_nested_input.cpp:195: pre-requisite #0
06:50:03 (end of pre-requisites)
06:50:03 Expected: to be called at ...

Read more...

Daniel van Vugt (vanvugt) wrote :

Again:

07:13:33 [ RUN ] NestedInput.nested_event_filter_receives_keyboard_from_host
...
07:13:33 unknown file: Failure
07:13:33
07:13:33 Unexpected mock function call - returning default value.
07:13:33 Function call: handle(key_event(when=463331346108 (1.957077ms ago), from=1, down, code=97, scan=30, modifiers=1))
07:13:33 Returns: false
07:13:33 Google Mock tried the following 3 expectations, but none matched:
07:13:33
07:13:33 /build/mir-plzkv2/mir-0.25.0+vivid2901bzr3826/tests/acceptance-tests/test_nested_input.cpp:195: tried expectation #0: EXPECT_CALL(nested_event_filter, handle(mt::InputDeviceStateEvent()))...
07:13:33 Expected arg #0: input device state event
07:13:33 Actual: key_event(when=463331346108 (1.523923ms ago), from=1, down, code=97, scan=30, modifiers=1)
07:13:33 Expected: to be called once
07:13:33 Actual: never called - unsatisfied and active
07:13:33 /build/mir-plzkv2/mir-0.25.0+vivid2901bzr3826/tests/acceptance-tests/test_nested_input.cpp:196: tried expectation #1: EXPECT_CALL(nested_event_filter, handle(mt::KeyOfScanCode(30)))...
07:13:33 Expected: all pre-requisites are satisfied
07:13:33 Actual: the following immediate pre-requisites are not satisfied:
07:13:33 /build/mir-plzkv2/mir-0.25.0+vivid2901bzr3826/tests/acceptance-tests/test_nested_input.cpp:195: pre-requisite #0
07:13:33 (end of pre-requisites)
07:13:33 Expected: to be called at least once
07:13:33 Actual: never called - unsatisfied and active
07:13:33 /build/mir-plzkv2/mir-0.25.0+vivid2901bzr3826/tests/acceptance-tests/test_nested_input.cpp:200: tried expectation #2: EXPECT_CALL(nested_event_filter, handle(mt::KeyOfScanCode(54)))...
07:13:33 Expected arg #0: key of scan code 54
07:13:33 Actual: key_event(when=463331346108 (1.885461ms ago), from=1, down, code=97, scan=30, modifiers=1)
07:13:33 Expected: to be called twice
07:13:33 Actual: never called - unsatisfied and active
...
07:13:33 [2016-11-17 07:13:33.755390] mirserver: Stopping
07:13:33 [ FAILED ] NestedInput.nested_event_filter_receives_keyboard_from_host (415 ms)

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

Daniel van Vugt (vanvugt) wrote :

Today:

09:06:08 [ RUN ] NestedInput.nested_event_filter_receives_keyboard_from_host
...
09:06:09 unknown file: Failure
09:06:09
09:06:09 Unexpected mock function call - returning default value.
09:06:09 Function call: handle(key_event(when=464983726337 (2.103846ms ago), from=1, down, code=97, scan=30, modifiers=none))
09:06:09 Returns: false
09:06:09 Google Mock tried the following 3 expectations, but none matched:
09:06:09
09:06:09 /build/mir-AYKG1P/mir-0.25.0+vivid3027bzr3856/tests/acceptance-tests/test_nested_input.cpp:202: tried expectation #0: EXPECT_CALL(nested_event_filter, handle(mt::InputDeviceStateEvent()))...
09:06:09 Expected arg #0: input device state event
09:06:09 Actual: key_event(when=464983726337 (1.374077ms ago), from=1, down, code=97, scan=30, modifiers=none)
09:06:09 Expected: to be called once
09:06:09 Actual: never called - unsatisfied and active
09:06:09 /build/mir-AYKG1P/mir-0.25.0+vivid3027bzr3856/tests/acceptance-tests/test_nested_input.cpp:203: tried expectation #1: EXPECT_CALL(nested_event_filter, handle(mt::KeyOfScanCode(30)))...
09:06:09 Expected: all pre-requisites are satisfied
09:06:09 Actual: the following immediate pre-requisites are not satisfied:
09:06:09 /build/mir-AYKG1P/mir-0.25.0+vivid3027bzr3856/tests/acceptance-tests/test_nested_input.cpp:202: pre-requisite #0
09:06:09 (end of pre-requisites)
09:06:09 Expected: to be called at least once
09:06:09 Actual: never called - unsatisfied and active
09:06:09 /build/mir-AYKG1P/mir-0.25.0+vivid3027bzr3856/tests/acceptance-tests/test_nested_input.cpp:207: tried expectation #2: EXPECT_CALL(nested_event_filter, handle(mt::KeyOfScanCode(54)))...
09:06:09 Expected arg #0: key of scan code 54
09:06:09 Actual: key_event(when=464983726337 (2.031461ms ago), from=1, down, code=97, scan=30, modifiers=none)
09:06:09 Expected: to be called twice
09:06:09 Actual: never called - unsatisfied and active
09:06:09 [2016-11-30 09:06:09.077352] mirserver: Stopping
09:06:09 [2016-11-30 09:06:09.089352] mirserver: Stopping
09:06:09 [ FAILED ] NestedInput.nested_event_filter_receives_keyboard_from_host (406 ms)

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

Daniel van Vugt (vanvugt) wrote :

Again:

08:24:47 /build/mir-1ObCXm/mir-0.25.0+vivid3046bzr3857/tests/acceptance-tests/test_nested_input.cpp:202: tried expectation #0: EXPECT_CALL(nested_event_filter, handle(mt::InputDeviceStateEvent()))...
08:24:47 Expected arg #0: input device state event
08:24:47 Actual: key_event(when=415056363949 (0.859385ms ago), from=1, down, code=97, scan=30, modifiers=none)
08:24:47 Expected: to be called once
08:24:47 Actual: never called - unsatisfied and active
08:24:47 /build/mir-1ObCXm/mir-0.25.0+vivid3046bzr3857/tests/acceptance-tests/test_nested_input.cpp:203: tried expectation #1: EXPECT_CALL(nested_event_filter, handle(mt::KeyOfScanCode(30)))...
08:24:47 Expected: all pre-requisites are satisfied
08:24:47 Actual: the following immediate pre-requisites are not satisfied:
08:24:47 /build/mir-1ObCXm/mir-0.25.0+vivid3046bzr3857/tests/acceptance-tests/test_nested_input.cpp:202: pre-requisite #0
08:24:47 (end of pre-requisites)
08:24:47 Expected: to be called at least once
08:24:47 Actual: never called - unsatisfied and active
08:24:47 /build/mir-1ObCXm/mir-0.25.0+vivid3046bzr3857/tests/acceptance-tests/test_nested_input.cpp:207: tried expectation #2: EXPECT_CALL(nested_event_filter, handle(mt::KeyOfScanCode(54)))...
08:24:47 Expected arg #0: key of scan code 54
08:24:47 Actual: key_event(when=415056363949 (1.237154ms ago), from=1, down, code=97, scan=30, modifiers=none)
08:24:47 Expected: to be called twice
08:24:47 Actual: never called - unsatisfied and active
08:24:47 [2016-12-01 08:24:47.176004] mirserver: Stopping
08:24:47 [2016-12-01 08:24:47.182858] mirserver: Stopping
08:24:47 [ FAILED ] NestedInput.nested_event_filter_receives_keyboard_from_host (294 ms)

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

Daniel van Vugt (vanvugt) wrote :

Again today:

15:53:32 11: Unexpected mock function call - returning default value.
15:53:32 11: Function call: handle(key_event(when=3055312056847927 (86.092935ms ago), from=1, down, code=97, scan=30, modifiers=none))
15:53:32 11: Returns: false
15:53:32 11: Google Mock tried the following 3 expectations, but none matched:
15:53:32 11:
15:53:32 11: /<<BUILDDIR>>/mir-0.25.0+xenial3171bzr3848/tests/acceptance-tests/test_nested_input.cpp:202: tried expectation #0: EXPECT_CALL(nested_event_filter, handle(mt::InputDeviceStateEvent()))...
15:53:32 11: Expected arg #0: input device state event
15:53:32 11: Actual: key_event(when=3055312056847927 (33.752407ms ago), from=1, down, code=97, scan=30, modifiers=none)
15:53:32 11: Expected: to be called once
15:53:32 11: Actual: never called - unsatisfied and active
15:53:32 11: /<<BUILDDIR>>/mir-0.25.0+xenial3171bzr3848/tests/acceptance-tests/test_nested_input.cpp:203: tried expectation #1: EXPECT_CALL(nested_event_filter, handle(mt::KeyOfScanCode(30)))...
15:53:32 11: Expected: all pre-requisites are satisfied
15:53:32 11: Actual: the following immediate pre-requisites are not satisfied:
15:53:32 11: /<<BUILDDIR>>/mir-0.25.0+xenial3171bzr3848/tests/acceptance-tests/test_nested_input.cpp:202: pre-requisite #0
15:53:32 11: (end of pre-requisites)
15:53:32 11: Expected: to be called at least once
15:53:32 11: Actual: never called - unsatisfied and active
15:53:32 11: /<<BUILDDIR>>/mir-0.25.0+xenial3171bzr3848/tests/acceptance-tests/test_nested_input.cpp:207: tried expectation #2: EXPECT_CALL(nested_event_filter, handle(mt::KeyOfScanCode(54)))...
15:53:32 11: Expected arg #0: key of scan code 54
15:53:32 11: Actual: key_event(when=3055312056847927 (80.882561ms ago), from=1, down, code=97, scan=30, modifiers=none)
15:53:32 11: Expected: to be called twice
15:53:32 11: Actual: never called - unsatisfied and active
15:53:32 11: [2016-12-13 15:53:32.595013] mirserver: Stopping
15:53:32 11: [2016-12-13 15:53:32.823189] mirserver: Stopping
15:53:32 11: [ FAILED ] NestedInput.nested_event_filter_receives_keyboard_from_host (3175 ms)

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

Daniel van Vugt (vanvugt) wrote :

Again:

07:07:57 Unexpected mock function call - returning default value.
07:07:57 Function call: handle(key_event(when=466311417721 (2.077616ms ago), from=1, down, code=97, scan=30, modifiers=none))
07:07:57 Returns: false
07:07:57 Google Mock tried the following 3 expectations, but none matched:
07:07:57
07:07:57 /build/mir-nHmyWA/mir-0.26.0+vivid3365bzr3911/tests/acceptance-tests/test_nested_input.cpp:202: tried expectation #0: EXPECT_CALL(nested_event_filter, handle(mt::InputDeviceStateEvent()))...
07:07:57 Expected arg #0: input device state event
07:07:57 Actual: key_event(when=466311417721 (1.616077ms ago), from=1, down, code=97, scan=30, modifiers=none)
07:07:57 Expected: to be called once
07:07:57 Actual: never called - unsatisfied and active
07:07:57 /build/mir-nHmyWA/mir-0.26.0+vivid3365bzr3911/tests/acceptance-tests/test_nested_input.cpp:203: tried expectation #1: EXPECT_CALL(nested_event_filter, handle(mt::KeyOfScanCode(30)))...
07:07:57 Expected: all pre-requisites are satisfied
07:07:57 Actual: the following immediate pre-requisites are not satisfied:
07:07:57 /build/mir-nHmyWA/mir-0.26.0+vivid3365bzr3911/tests/acceptance-tests/test_nested_input.cpp:202: pre-requisite #0
07:07:57 (end of pre-requisites)
07:07:57 Expected: to be called at least once
07:07:57 Actual: never called - unsatisfied and active
07:07:57 /build/mir-nHmyWA/mir-0.26.0+vivid3365bzr3911/tests/acceptance-tests/test_nested_input.cpp:207: tried expectation #2: EXPECT_CALL(nested_event_filter, handle(mt::KeyOfScanCode(54)))...
07:07:57 Expected arg #0: key of scan code 54
07:07:57 Actual: key_event(when=466311417721 (2.010693ms ago), from=1, down, code=97, scan=30, modifiers=none)
07:07:57 Expected: to be called twice
07:07:57 Actual: never called - unsatisfied and active
07:07:57 [2017-01-06 07:07:57.231091] mirserver: Stopping
07:07:57 [2017-01-06 07:07:57.242373] mirserver: Stopping
07:07:57 [ FAILED ] NestedInput.nested_event_filter_receives_keyboard_from_host (409 ms)

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

Changed in mir:
importance: Undecided → Medium
status: New → Triaged
Changed in mir:
importance: Medium → High
Kevin DuBois (kdub) wrote :

lets see how far I can get here

Changed in mir:
assignee: nobody → Kevin DuBois (kdub)
Kevin DuBois (kdub) on 2017-03-14
Changed in mir:
assignee: Kevin DuBois (kdub) → nobody

Investigation indicates that this is caused by out-of-order receipt of input-device-state vs key events. A successful run is:

MockEventFilter: input-device-state
MockEventFilter: key 97 down
MockEventFilter: key 97 up
MockEventFilter: key 65506 down
MockEventFilter: key 65506 up

Whereas a failing run is:

MockEventFilter: key 97 down
MockEventFilter: key 97 up
MockEventFilter: input-device-state
MockEventFilter: key 65506 down
MockEventFilter: key 65506 up

Changed in mir:
assignee: nobody → Alexandros Frantzis (afrantzis)
status: Triaged → In Progress
Mir CI Bot (mir-ci-bot) wrote :

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

Changed in mir:
status: In Progress → Fix Committed
Changed in mir:
milestone: none → 1.0.0
Daniel van Vugt (vanvugt) wrote :
Changed in mir:
milestone: 0.27.0 → none
assignee: Alexandros Frantzis (afrantzis) → nobody
status: Fix Committed → Triaged
Michał Sawicz (saviq) wrote :

Syncing task from Mir.

Changed in mir (Ubuntu):
importance: Undecided → High
status: New → Triaged
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Duplicates of this bug

Other bug subscribers