rhel8 flakes: "ERR anaconda:anaconda: core.util: Timeout trying to start Xorg"

[rvykydal]

On 12-29-2022 3 tests failed. We already increased the timeout some time ago in https://github.com/rhinstaller/kickstart-tests/issues/795. This is the only occurrence since the increase as of 03-01-2023.

mountpoint-assignment-2 virt-install.log

team-httpks virt-install.log

timezoneLOCAL virt-install.log

[VladimirSlavik]

Looking at the logs, it seems xserver waits some 80 seconds on the glamoregl module, decides it won't run "on llvmpipe", and then the timeout happens juuuust before the server is ready.

Obviously, starting the module for 80 seconds is a no-go since we normally wait 60 seconds for the whole X works to start.

Maybe we can gather some statistics about how long it takes to reject glamoregl on successful runs, and on real hardware?

timezoneLOCAL: 84 seconds

``` 23:23:31,185 DEBUG anaconda:anaconda: core.util: Setting timeout 100 seconds for starting X. 23:23:31,211 INFO anaconda:program: Running... Xorg -br -logfile /tmp/X.log :1 vt6 -s 1440 -ac -nolisten tcp -dpi 96 -noreset (...) 23:23:50,224 NOTICE xserver:[ 306.805] (II) Loading sub module "glamoregl" 23:23:50,224 NOTICE xserver:[ 306.806] (II) LoadModule: "glamoregl" 23:23:50,224 NOTICE xserver:[ 306.808] (II) Loading /usr/lib64/xorg/modules/libglamoregl.so 23:23:50,224 NOTICE xserver:[ 307.268] (II) Module glamoregl: vendor="X.Org Foundation" 23:23:50,224 NOTICE xserver:[ 307.268] compiled for 1.20.11, module version = 1.0.1 23:23:50,224 NOTICE xserver:[ 307.268] ABI class: X.Org ANSI C Emulation, version 0.4 (...) 23:25:11,660 ERR anaconda:anaconda: core.util: Timeout trying to start Xorg 23:25:11,736 DEBUG anaconda:anaconda: core.util: Exception handler test suspended to prevent accidental activation by delayed Xorg start. Next SIGUSR1 will be handled as delayed Xorg start. 23:25:11,944 WARNING anaconda:anaconda: display: X startup failed: Timeout trying to start Xorg 23:25:11,998 INFO anaconda:program: Running... chvt 1 23:25:14,557 NOTICE xserver:[ 393.878] (II) modeset(0): Refusing to try glamor on llvmpipe 23:25:14,557 NOTICE xserver:[ 394.113] (II) modeset(0): glamor initialization failed ```

team-httpks: 82 seconds

``` 23:24:13,098 DEBUG anaconda:anaconda: core.util: Setting timeout 100 seconds for starting X. 23:24:13,154 INFO anaconda:program: Running... Xorg -br -logfile /tmp/X.log :1 vt6 -s 1440 -ac -nolisten tcp -dpi 96 -noreset (...) 23:24:26,642 NOTICE xserver:[ 340.798] (II) Loading sub module "glamoregl" 23:24:26,642 NOTICE xserver:[ 340.798] (II) LoadModule: "glamoregl" 23:24:26,642 NOTICE xserver:[ 340.807] (II) Loading /usr/lib64/xorg/modules/libglamoregl.so 23:24:26,642 NOTICE xserver:[ 341.695] (II) Module glamoregl: vendor="X.Org Foundation" 23:24:26,642 NOTICE xserver:[ 341.695] compiled for 1.20.11, module version = 1.0.1 23:24:26,642 NOTICE xserver:[ 341.695] ABI class: X.Org ANSI C Emulation, version 0.4 23:25:48,338 NOTICE xserver:[ 429.525] (II) modeset(0): Refusing to try glamor on llvmpipe 23:25:48,338 NOTICE xserver:[ 429.759] (II) modeset(0): glamor initialization failed (...) 23:25:53,490 ERR anaconda:anaconda: core.util: Timeout trying to start Xorg ```

mountpoint-assignment-2: 84 seconds

``` 23:23:31,185 DEBUG anaconda:anaconda: core.util: Setting timeout 100 seconds for starting X. 23:23:31,211 INFO anaconda:program: Running... Xorg -br -logfile /tmp/X.log :1 vt6 -s 1440 -ac -nolisten tcp -dpi 96 -noreset (...) 23:23:50,224 NOTICE xserver:[ 306.805] (II) Loading sub module "glamoregl" 23:23:50,224 NOTICE xserver:[ 306.806] (II) LoadModule: "glamoregl" 23:23:50,224 NOTICE xserver:[ 306.808] (II) Loading /usr/lib64/xorg/modules/libglamoregl.so 23:23:50,224 NOTICE xserver:[ 307.268] (II) Module glamoregl: vendor="X.Org Foundation" 23:23:50,224 NOTICE xserver:[ 307.268] compiled for 1.20.11, module version = 1.0.1 23:23:50,224 NOTICE xserver:[ 307.268] ABI class: X.Org ANSI C Emulation, version 0.4 (...) 23:25:11,660 ERR anaconda:anaconda: core.util: Timeout trying to start Xorg 23:25:11,736 DEBUG anaconda:anaconda: core.util: Exception handler test suspended to prevent accidental activation by delayed Xorg start. Next SIGUSR1 will be handled as delayed Xorg start. 23:25:11,944 WARNING anaconda:anaconda: display: X startup failed: Timeout trying to start Xorg 23:25:11,998 INFO anaconda:program: Running... chvt 1 23:25:14,557 NOTICE xserver:[ 393.878] (II) modeset(0): Refusing to try glamor on llvmpipe 23:25:14,557 NOTICE xserver:[ 394.113] (II) modeset(0): glamor initialization failed ```

[VladimirSlavik]

Looks like the RHEL 9 crash is mostly the same.