nixosTests.pantheon "Login with elementary-greeter" subtest is flaky

[bobby285271]

Describe the bug

https://github.com/NixOS/nixpkgs/blob/master/nixos/tests/pantheon.nix

I have seen the following failure multiple times on hydra:

machine: sending monitor command: sendkey ret
machine: waiting for monitor prompt
(finished: waiting for monitor prompt, in 0.00 seconds)
(finished: sending monitor command: sendkey ret, in 0.00 seconds)
(finished: sending keys 'foobar
', in 0.07 seconds)
machine: waiting for the X11 server
machine # [   33.642457] dbus-daemon[738]: [system] Failed to activate service 'org.bluez': timed out (service_start_timeout=25000ms)
machine # [   33.644227] pulseaudio[1095]: GetManagedObjects() failed: org.freedesktop.DBus.Error.TimedOut: Failed to activate service 'org.bluez': timed out (service_start_timeout=25000ms)
machine # [   39.289377] systemd[1]: systemd-hostnamed.service: Deactivated successfully.
machine # [  400.236988] systemd[1]: Started Logrotate Service.
machine # [  400.245211] systemd[1]: logrotate.service: Deactivated successfully.
machine # [  905.987229] systemd[1]: Starting Cleanup of Temporary Directories...
machine # [  906.035720] systemd[1]: systemd-tmpfiles-clean.service: Deactivated successfully.
machine # [  906.038284] systemd[1]: Finished Cleanup of Temporary Directories.
machine # [  906.039344] systemd[1]: run-credentials-systemd\x2dtmpfiles\x2dclean.service.mount: Deactivated successfully.
Test "Login with elementary-greeter" failed with error: "action timed out after 900 seconds"
cleanup
kill machine (pid 6)
machine # qemu-kvm: terminating on signal 15 from pid 4 (/nix/store/abax98471z8fshv4b9p46bkh3lxmpy0z-python3-3.10.9/bin/python3.10)
(finished: cleanup, in 0.05 seconds)
kill vlan (pid 5)

https://hydra.nixos.org/build/205937795/nixlog/31
https://hydra.nixos.org/build/204525007/nixlog/1
https://hydra.nixos.org/build/205951447/nixlog/17

Also on random PRs (e.g. in #211346):

https://logs.nix.ci/?attempt_id=d90638d2-837c-4c35-83c0-cd7fdde419ac&key=nixos%2Fnixpkgs.211346
https://logs.nix.ci/?attempt_id=6983cb3b-cf3f-45a8-a60d-dbf551d9542b&key=nixos%2Fnixpkgs.211346

In 99% cases, restarting the test will work. (for example it succeed once in #211346) But it is unclear for me why the test is flaky. Since the test is a channel blocker (why worldofpeace why) this is not good.

I believe this is not something regressed recently.

Steps To Reproduce

Steps to reproduce the behavior:

1. Build nixosTests.pantheon

Expected behavior

Not flaky.

Notify maintainers

@NixOS/pantheon

[bobby285271]

I finally managed to reproduce the failure once on my laptop when I am testing something like

with subtest("Login with elementary-greeter"):
   machine.send_chars("${user.password}\n")
   machine.sleep(20)
   machine.screenshot("screen")

So now I have some screenshots.

It looks like the password entry isn't focused

[davidak]

It also happened to me sometimes that i typed and it was not focused. Maybe you have to wait a bit?

[bobby285271]

Going to give this some try in #219677 since there is no webkitgtk rebuild on master right now.

The main idea:

machine.succeed("XAUTHORITY=/var/lib/lightdm/.Xauthority DISPLAY=:0 xdotool mousemove 512 505 click 1")
machine.sleep(2)

[bobby285271]

Closing since the tests are running fine so far, it looks like this should be something to be solved on upstream

• looks like it does look flaky... Autofocus Password Field elementary/greeter#495
• and... there is also an issue for the mouse position: mouse placement on bottom right on boot and sometimes can't enter password (to enter password cursor need to be pointer at password feild) elementary/greeter#641