build checks.x86_64-linux.e2e-test
0.13 s
$ /nix/store/9ypz3flqsrl5xl495mm8h645gadjsxi1-coreutils-9.11/bin/timeout --kill-after=15s 7200s /nix/store/23zk8sgzamrbmj1fday15szf7f2279s8-nix-2.34.7/bin/nix --extra-experimental-features nix-command --extra-experimental-features flakes --log-format internal-json build --no-link --print-out-paths git+https://github.com/NorfairKing/centjes?ref=virtual-assertions&rev=5b28b734206cf997a043907b38d89a39384fd866&shallow=1#checks.x86_64-linux.e2e-test --print-build-logs
0.15 s
warning: ignoring untrusted flake configuration setting 'extra-substituters'.
0.15 s
Pass '--accept-flake-config' to trust it
0.15 s
warning: ignoring untrusted flake configuration setting 'extra-trusted-public-keys'.
0.15 s
Pass '--accept-flake-config' to trust it
7.70 s
10.06 s
Waiting for lock on centjes-switzerland-0.0.0-doc
55.12 s
Waiting for lock on centjes-docs-site-source
60.15 s
Waiting for lock on centjes-docs-site
80.26 s
Building /nix/store/kajg1s0iqk2sbbv8w5sd5rla6cbxkxyi-settings-check.drv
80.28 s
Building /nix/store/b8d6h6an01dczd8vr3vcnypb90b6j82k-unit-script-centjes-docs-site-production-start.drv
80.33 s
[unit-script-centjes-docs-site-production-start:post-build] Uploading to cachix cache "centjes": /nix/store/33lh8aggac4by8xnrkp8mch5bby1aazv-unit-script-centjes-docs-site-production-start
80.69 s
[unit-script-centjes-docs-site-production-start:post-build] Pushing 1 paths (29 are already present) using zstd to cache centjes ⏳
80.69 s
[unit-script-centjes-docs-site-production-start:post-build]
81.05 s
[unit-script-centjes-docs-site-production-start:post-build] Pushing /nix/store/33lh8aggac4by8xnrkp8mch5bby1aazv-unit-script-centjes-docs-site-production-start (680.00 B)
81.96 s
[unit-script-centjes-docs-site-production-start:post-build]
81.96 s
[unit-script-centjes-docs-site-production-start:post-build] All done.
81.98 s
[unit-script-centjes-docs-site-production-start:post-build] Uploading to the NixCI staging cache: /nix/store/33lh8aggac4by8xnrkp8mch5bby1aazv-unit-script-centjes-docs-site-production-start
82.02 s
[unit-script-centjes-docs-site-production-start:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
82.26 s
[unit-script-centjes-docs-site-production-start:post-build] copying 1 paths...
82.26 s
[unit-script-centjes-docs-site-production-start:post-build] copying path '/nix/store/33lh8aggac4by8xnrkp8mch5bby1aazv-unit-script-centjes-docs-site-production-start' to 'https://cache.staging.nix-ci.com'...
82.46 s
[unit-script-centjes-docs-site-production-start:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
82.68 s
[unit-script-centjes-docs-site-production-start:post-build] copying 1 paths...
82.68 s
[unit-script-centjes-docs-site-production-start:post-build] copying path '/nix/store/b8d6h6an01dczd8vr3vcnypb90b6j82k-unit-script-centjes-docs-site-production-start.drv' to 'https://cache.staging.nix-ci.com'...
82.86 s
Uploaded unit-script-centjes-docs-site-production-start in 2.5s
82.86 s
Progress: 1 of 13 built (1 building)
82.86 s
Built unit-script-centjes-docs-site-production-start in 2.5s
82.88 s
[settings-check:post-build] Uploading to cachix cache "centjes": /nix/store/ig0311v4pin291dbyiwcgd2dri09a4k8-settings-check
83.28 s
[settings-check:post-build] Pushing 1 paths (30 are already present) using zstd to cache centjes ⏳
83.28 s
[settings-check:post-build]
83.65 s
[settings-check:post-build] Pushing /nix/store/ig0311v4pin291dbyiwcgd2dri09a4k8-settings-check (880.00 B)
84.57 s
[settings-check:post-build]
84.57 s
[settings-check:post-build] All done.
84.58 s
[settings-check:post-build] Uploading to the NixCI staging cache: /nix/store/ig0311v4pin291dbyiwcgd2dri09a4k8-settings-check
84.63 s
[settings-check:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
84.63 s
[settings-check:post-build] copying 1 paths...
84.64 s
[settings-check:post-build] copying path '/nix/store/ig0311v4pin291dbyiwcgd2dri09a4k8-settings-check' to 'https://cache.staging.nix-ci.com'...
84.86 s
[settings-check:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
85.34 s
[settings-check:post-build] copying 1 paths...
85.36 s
[settings-check:post-build] copying path '/nix/store/kajg1s0iqk2sbbv8w5sd5rla6cbxkxyi-settings-check.drv' to 'https://cache.staging.nix-ci.com'...
85.53 s
Uploaded settings-check in 2.6s
85.53 s
Progress: 2 of 13 built
85.53 s
Built settings-check in 5.2s
85.55 s
Building /nix/store/zcph62ggq8f7id593cy9y956niwn4apq-settings-check.drv
85.58 s
[settings-check] WithConfig : src/Centjes/Docs/Site/OptParse.hs:27:7 in centjes-docs-site:Centjes.Docs.Site.OptParse
85.58 s
[settings-check] loading config
85.59 s
[settings-check] Parser with check : src/Centjes/Docs/Site/OptParse.hs:27:7 in centjes-docs-site:Centjes.Docs.Site.OptParse
85.59 s
[settings-check] parser
85.59 s
[settings-check] Alt
85.59 s
[settings-check] Trying left side.
85.59 s
[settings-check] Parser with check : src/Centjes/Docs/Site/OptParse.hs:27:7 in centjes-docs-site:Centjes.Docs.Site.OptParse
85.59 s
[settings-check] parser
85.59 s
[settings-check] Setting : src/Centjes/Docs/Site/OptParse.hs:27:7 in centjes-docs-site:Centjes.Docs.Site.OptParse
85.59 s
[settings-check] could not set based on options, no option: ["--config-file"]
85.59 s
[settings-check] set based on env: "/nix/store/vb9vv8cg7xwfa7010fyznaj7b5syrx63-centjes-docs-site-config.yaml"
85.59 s
[settings-check] check
85.59 s
[settings-check] succeeded
85.59 s
[settings-check] Left side succeeded.
85.59 s
[settings-check] check
85.59 s
[settings-check] succeeded
85.59 s
[settings-check] with loaded config
85.59 s
[settings-check] Ap
85.59 s
[settings-check] Ap
85.59 s
[settings-check] Parser with check : without srcLoc
85.59 s
[settings-check] parser
85.62 s
[settings-check] Setting : src/Centjes/Docs/Site/OptParse.hs:29:11 in centjes-docs-site:Centjes.Docs.Site.OptParse
85.62 s
[settings-check] could not set based on options, no option: ["--port"]
85.62 s
[settings-check] could not set based on env vars, no var: [EnvVarSetting {envVarSettingVar = "CENTJES_DOCS_SITE_PORT", envVarSettingAllowPrefix = True}]
85.62 s
[settings-check] set based on config value: Number 8001.0
85.62 s
[settings-check] check
85.62 s
[settings-check] succeeded
85.62 s
[settings-check] Alt
85.62 s
[settings-check] Trying left side.
85.62 s
[settings-check] Parser with check : without srcLoc
85.62 s
[settings-check] parser
85.62 s
[settings-check] Setting : src/Centjes/Docs/Site/OptParse.hs:38:13 in centjes-docs-site:Centjes.Docs.Site.OptParse
85.62 s
[settings-check] could not set based on options, no option: ["--google-analytics-tracking"]
85.62 s
[settings-check] could not set based on env vars, no var: [EnvVarSetting {envVarSettingVar = "CENTJES_DOCS_SITE_GOOGLE_ANALYTICS_TRACKING", envVarSettingAllowPrefix = True}]
85.62 s
[settings-check] could not set based on config value, configured to nothing: ["google-analytics-tracking"]
85.62 s
[settings-check] not found
85.62 s
[settings-check] check
85.62 s
[settings-check] Left side failed, trying right side.
85.62 s
[settings-check] pure value
85.62 s
[settings-check] Alt
85.62 s
[settings-check] Trying left side.
85.62 s
[settings-check] Parser with check : without srcLoc
85.62 s
[settings-check] parser
85.62 s
[settings-check] Setting : src/Centjes/Docs/Site/OptParse.hs:46:13 in centjes-docs-site:Centjes.Docs.Site.OptParse
85.62 s
[settings-check] could not set based on options, no option: ["--google-search-console-verification"]
85.62 s
[settings-check] could not set based on env vars, no var: [EnvVarSetting {envVarSettingVar = "CENTJES_DOCS_SITE_GOOGLE_SEARCH_CONSOLE_VERIFICATION", envVarSettingAllowPrefix = True}]
85.62 s
[settings-check] could not set based on config value, configured to nothing: ["google-search-console-verification"]
85.62 s
[settings-check] not found
85.62 s
[settings-check] check
85.66 s
[settings-check] Left side failed, trying right side.
85.66 s
[settings-check] pure value
85.68 s
[settings-check:post-build] Uploading to cachix cache "centjes": /nix/store/bp7ak7r85za1cwc3snhzm6cz1ypyh3wv-settings-check
86.05 s
[settings-check:post-build] Pushing 1 paths (0 are already present) using zstd to cache centjes ⏳
86.05 s
[settings-check:post-build]
86.42 s
[settings-check:post-build] Pushing /nix/store/bp7ak7r85za1cwc3snhzm6cz1ypyh3wv-settings-check (144.00 B)
87.31 s
[settings-check:post-build]
87.31 s
[settings-check:post-build] All done.
87.32 s
[settings-check:post-build] Uploading to the NixCI staging cache: /nix/store/bp7ak7r85za1cwc3snhzm6cz1ypyh3wv-settings-check
87.37 s
[settings-check:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
87.37 s
[settings-check:post-build] copying 1 paths...
87.37 s
[settings-check:post-build] copying path '/nix/store/bp7ak7r85za1cwc3snhzm6cz1ypyh3wv-settings-check' to 'https://cache.staging.nix-ci.com'...
87.49 s
[settings-check:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
88.28 s
[settings-check:post-build] copying 1 paths...
88.28 s
[settings-check:post-build] copying path '/nix/store/zcph62ggq8f7id593cy9y956niwn4apq-settings-check.drv' to 'https://cache.staging.nix-ci.com'...
88.54 s
Uploaded settings-check in 2.8s
88.54 s
Progress: 3 of 13 built
88.54 s
Built settings-check in 2.9s
88.57 s
Building /nix/store/plqd0rvv12rdrkv364arn8j5sp2hyz22-unit-centjes-docs-site-production.service.drv
88.62 s
[unit-centjes-docs-site-production.service:post-build] Uploading to cachix cache "centjes": /nix/store/9cz2hif6s9wka0byi75l7jpgn54q0r51-unit-centjes-docs-site-production.service
89.00 s
[unit-centjes-docs-site-production.service:post-build] Pushing 1 paths (91 are already present) using zstd to cache centjes ⏳
89.00 s
[unit-centjes-docs-site-production.service:post-build]
89.36 s
[unit-centjes-docs-site-production.service:post-build] Pushing /nix/store/9cz2hif6s9wka0byi75l7jpgn54q0r51-unit-centjes-docs-site-production.service (1.62 KiB)
90.48 s
[unit-centjes-docs-site-production.service:post-build]
90.48 s
[unit-centjes-docs-site-production.service:post-build] All done.
90.51 s
[unit-centjes-docs-site-production.service:post-build] Uploading to the NixCI staging cache: /nix/store/9cz2hif6s9wka0byi75l7jpgn54q0r51-unit-centjes-docs-site-production.service
90.54 s
[unit-centjes-docs-site-production.service:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
90.70 s
[unit-centjes-docs-site-production.service:post-build] copying 1 paths...
90.70 s
[unit-centjes-docs-site-production.service:post-build] copying path '/nix/store/9cz2hif6s9wka0byi75l7jpgn54q0r51-unit-centjes-docs-site-production.service' to 'https://cache.staging.nix-ci.com'...
90.91 s
[unit-centjes-docs-site-production.service:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
91.19 s
[unit-centjes-docs-site-production.service:post-build] copying 1 paths...
91.20 s
[unit-centjes-docs-site-production.service:post-build] copying path '/nix/store/plqd0rvv12rdrkv364arn8j5sp2hyz22-unit-centjes-docs-site-production.service.drv' to 'https://cache.staging.nix-ci.com'...
91.38 s
Uploaded unit-centjes-docs-site-production.service in 2.7s
91.38 s
Progress: 4 of 13 built
91.38 s
Built unit-centjes-docs-site-production.service in 2.8s
91.44 s
Building /nix/store/g9afyhhwm9vfiq99h1syk7rnzb1n46b5-system-units.drv
92.20 s
[system-units:post-build] Uploading to cachix cache "centjes": /nix/store/hvhyvg8xna322m8k7kj41agw2ypnm0vz-system-units
92.80 s
[system-units:post-build] Pushing 1 paths (450 are already present) using zstd to cache centjes ⏳
92.80 s
[system-units:post-build]
93.25 s
[system-units:post-build] Pushing /nix/store/hvhyvg8xna322m8k7kj41agw2ypnm0vz-system-units (96.09 KiB)
94.27 s
[system-units:post-build]
94.27 s
[system-units:post-build] All done.
94.29 s
[system-units:post-build] Uploading to the NixCI staging cache: /nix/store/hvhyvg8xna322m8k7kj41agw2ypnm0vz-system-units
94.33 s
[system-units:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
94.51 s
[system-units:post-build] copying 1 paths...
94.51 s
[system-units:post-build] copying path '/nix/store/hvhyvg8xna322m8k7kj41agw2ypnm0vz-system-units' to 'https://cache.staging.nix-ci.com'...
94.73 s
[system-units:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
95.07 s
[system-units:post-build] copying 1 paths...
95.07 s
[system-units:post-build] copying path '/nix/store/g9afyhhwm9vfiq99h1syk7rnzb1n46b5-system-units.drv' to 'https://cache.staging.nix-ci.com'...
95.26 s
Uploaded system-units in 3.0s
95.26 s
Progress: 5 of 13 built
95.26 s
Built system-units in 3.8s
95.31 s
Building /nix/store/cnq1ph2w7rcap51ci0nwf5gmgarh2h57-etc.drv
95.69 s
[etc:post-build] Uploading to cachix cache "centjes": /nix/store/183a1d9nfwb22r6xg7bgkl8c3rd25vbm-etc
96.29 s
[etc:post-build] Pushing 1 paths (546 are already present) using zstd to cache centjes ⏳
96.32 s
[etc:post-build]
96.66 s
[etc:post-build] Pushing /nix/store/183a1d9nfwb22r6xg7bgkl8c3rd25vbm-etc (31.56 KiB)
97.73 s
[etc:post-build]
97.73 s
[etc:post-build] All done.
97.75 s
[etc:post-build] Uploading to the NixCI staging cache: /nix/store/183a1d9nfwb22r6xg7bgkl8c3rd25vbm-etc
97.79 s
[etc:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
97.96 s
[etc:post-build] copying 1 paths...
97.97 s
[etc:post-build] copying path '/nix/store/183a1d9nfwb22r6xg7bgkl8c3rd25vbm-etc' to 'https://cache.staging.nix-ci.com'...
98.18 s
[etc:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
98.46 s
[etc:post-build] copying 1 paths...
98.46 s
[etc:post-build] copying path '/nix/store/cnq1ph2w7rcap51ci0nwf5gmgarh2h57-etc.drv' to 'https://cache.staging.nix-ci.com'...
98.67 s
Uploaded etc in 2.9s
98.67 s
Progress: 6 of 13 built
98.67 s
Built etc in 3.3s
98.74 s
Building /nix/store/n8rk19azj14a89dg7yh4j5nwp9zkrdp8-nixos-system-docsserver-test.drv
98.82 s
[nixos-system-docsserver-test:post-build] Uploading to cachix cache "centjes": /nix/store/65s8l6c9brrb1g3yskvbz60cb4rmq4db-nixos-system-docsserver-test
99.51 s
[nixos-system-docsserver-test:post-build] Pushing 1 paths (568 are already present) using zstd to cache centjes ⏳
99.51 s
[nixos-system-docsserver-test:post-build]
99.97 s
[nixos-system-docsserver-test:post-build] Pushing /nix/store/65s8l6c9brrb1g3yskvbz60cb4rmq4db-nixos-system-docsserver-test (17.26 KiB)
100.88 s
[nixos-system-docsserver-test:post-build]
100.88 s
[nixos-system-docsserver-test:post-build] All done.
100.90 s
[nixos-system-docsserver-test:post-build] Uploading to the NixCI staging cache: /nix/store/65s8l6c9brrb1g3yskvbz60cb4rmq4db-nixos-system-docsserver-test
100.94 s
[nixos-system-docsserver-test:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
101.11 s
[nixos-system-docsserver-test:post-build] copying 1 paths...
101.11 s
[nixos-system-docsserver-test:post-build] copying path '/nix/store/65s8l6c9brrb1g3yskvbz60cb4rmq4db-nixos-system-docsserver-test' to 'https://cache.staging.nix-ci.com'...
101.33 s
[nixos-system-docsserver-test:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
101.62 s
[nixos-system-docsserver-test:post-build] copying 1 paths...
101.62 s
[nixos-system-docsserver-test:post-build] copying path '/nix/store/n8rk19azj14a89dg7yh4j5nwp9zkrdp8-nixos-system-docsserver-test.drv' to 'https://cache.staging.nix-ci.com'...
101.88 s
Uploaded nixos-system-docsserver-test in 3.0s
101.88 s
Progress: 7 of 13 built
101.88 s
Built nixos-system-docsserver-test in 3.1s
102.28 s
Building /nix/store/kbpvq91gx1i1bbk5jm33z6zkz7bfxj0y-closure-info.drv
102.29 s
[closure-info] structuredAttrs is enabled
102.37 s
[closure-info:post-build] Uploading to cachix cache "centjes": /nix/store/ildfwjvkp1mgxjlcmj4jd3l802909i52-closure-info
102.81 s
[closure-info:post-build] Pushing 1 paths (569 are already present) using zstd to cache centjes ⏳
102.81 s
[closure-info:post-build]
103.18 s
[closure-info:post-build] Pushing /nix/store/ildfwjvkp1mgxjlcmj4jd3l802909i52-closure-info (228.66 KiB)
104.12 s
[closure-info:post-build]
104.12 s
[closure-info:post-build] All done.
104.14 s
[closure-info:post-build] Uploading to the NixCI staging cache: /nix/store/ildfwjvkp1mgxjlcmj4jd3l802909i52-closure-info
104.18 s
[closure-info:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
104.21 s
[closure-info:post-build] copying 1 paths...
104.22 s
[closure-info:post-build] copying path '/nix/store/ildfwjvkp1mgxjlcmj4jd3l802909i52-closure-info' to 'https://cache.staging.nix-ci.com'...
104.53 s
[closure-info:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
104.84 s
[closure-info:post-build] copying 1 paths...
104.84 s
[closure-info:post-build] copying path '/nix/store/kbpvq91gx1i1bbk5jm33z6zkz7bfxj0y-closure-info.drv' to 'https://cache.staging.nix-ci.com'...
105.03 s
Uploaded closure-info in 2.6s
105.03 s
Progress: 8 of 13 built
105.03 s
Built closure-info in 2.7s
105.08 s
Building /nix/store/0ifg8fkfgd8w8mj74a4ipszqzh8w39ac-run-nixos-vm.drv
105.15 s
[run-nixos-vm:post-build] Uploading to cachix cache "centjes": /nix/store/hm0jrf3h3g89wzzhyv95z64y4hkz4akx-run-nixos-vm
105.98 s
[run-nixos-vm:post-build] Pushing 1 paths (580 are already present) using zstd to cache centjes ⏳
105.98 s
[run-nixos-vm:post-build]
106.37 s
[run-nixos-vm:post-build] Pushing /nix/store/hm0jrf3h3g89wzzhyv95z64y4hkz4akx-run-nixos-vm (2.94 KiB)
107.29 s
[run-nixos-vm:post-build]
107.29 s
[run-nixos-vm:post-build] All done.
107.31 s
[run-nixos-vm:post-build] Uploading to the NixCI staging cache: /nix/store/hm0jrf3h3g89wzzhyv95z64y4hkz4akx-run-nixos-vm
107.35 s
[run-nixos-vm:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
107.52 s
[run-nixos-vm:post-build] copying 1 paths...
107.53 s
[run-nixos-vm:post-build] copying path '/nix/store/hm0jrf3h3g89wzzhyv95z64y4hkz4akx-run-nixos-vm' to 'https://cache.staging.nix-ci.com'...
107.73 s
[run-nixos-vm:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
107.98 s
[run-nixos-vm:post-build] copying 1 paths...
107.99 s
[run-nixos-vm:post-build] copying path '/nix/store/0ifg8fkfgd8w8mj74a4ipszqzh8w39ac-run-nixos-vm.drv' to 'https://cache.staging.nix-ci.com'...
108.18 s
Uploaded run-nixos-vm in 3.0s
108.18 s
Progress: 9 of 13 built
108.18 s
Built run-nixos-vm in 3.0s
108.24 s
Building /nix/store/9c6mc3gk5nm2fjzr6clvmyn037nsg8yl-nixos-vm.drv
108.30 s
[nixos-vm:post-build] Uploading to cachix cache "centjes": /nix/store/9kzx216k2yx2k92fg96w4k0ii2v7msda-nixos-vm
109.13 s
[nixos-vm:post-build] Pushing 1 paths (581 are already present) using zstd to cache centjes ⏳
109.13 s
[nixos-vm:post-build]
109.57 s
[nixos-vm:post-build] Pushing /nix/store/9kzx216k2yx2k92fg96w4k0ii2v7msda-nixos-vm (776.00 B)
110.49 s
[nixos-vm:post-build]
110.49 s
[nixos-vm:post-build] All done.
110.50 s
[nixos-vm:post-build] Uploading to the NixCI staging cache: /nix/store/9kzx216k2yx2k92fg96w4k0ii2v7msda-nixos-vm
110.54 s
[nixos-vm:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
110.58 s
[nixos-vm:post-build] copying 1 paths...
110.58 s
[nixos-vm:post-build] copying path '/nix/store/9kzx216k2yx2k92fg96w4k0ii2v7msda-nixos-vm' to 'https://cache.staging.nix-ci.com'...
110.81 s
[nixos-vm:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
111.09 s
[nixos-vm:post-build] copying 1 paths...
111.09 s
[nixos-vm:post-build] copying path '/nix/store/9c6mc3gk5nm2fjzr6clvmyn037nsg8yl-nixos-vm.drv' to 'https://cache.staging.nix-ci.com'...
111.28 s
Uploaded nixos-vm in 2.9s
111.28 s
Progress: 10 of 13 built
111.28 s
Built nixos-vm in 3.0s
111.34 s
Building /nix/store/2nq014fj1ppaglffarcp1nspq67xb1qc-nixos-test-driver-centjes-e2e-test.drv
111.49 s
[nixos-test-driver-centjes-e2e-test] Running type check (enable/disable: config.skipTypeCheck)
111.49 s
[nixos-test-driver-centjes-e2e-test] See https://nixos.org/manual/nixos/stable/#test-opt-skipTypeCheck
117.46 s
[nixos-test-driver-centjes-e2e-test] Success: no issues found in 1 source file
118.28 s
[nixos-test-driver-centjes-e2e-test] additionally exposed symbols:
118.31 s
[nixos-test-driver-centjes-e2e-test] ,
118.31 s
[nixos-test-driver-centjes-e2e-test] ,
118.31 s
[nixos-test-driver-centjes-e2e-test] start_all, test_script, machines, vlans, driver, log, os, create_machine, subtest, run_tests, join_all, retry, serial_stdout_off, serial_stdout_on, polling_condition, Machine, t, debug
118.33 s
[nixos-test-driver-centjes-e2e-test] Linting test script (enable/disable: config.skipLint)
118.33 s
[nixos-test-driver-centjes-e2e-test] See https://nixos.org/manual/nixos/stable/#test-opt-skipLint
118.46 s
[nixos-test-driver-centjes-e2e-test:post-build] Uploading to cachix cache "centjes": /nix/store/kyip61120rsn9hriisbr4v2wjy9dknsq-nixos-test-driver-centjes-e2e-test
118.92 s
[nixos-test-driver-centjes-e2e-test:post-build] Pushing 1 paths (633 are already present) using zstd to cache centjes ⏳
118.92 s
[nixos-test-driver-centjes-e2e-test:post-build]
119.29 s
[nixos-test-driver-centjes-e2e-test:post-build] Pushing /nix/store/kyip61120rsn9hriisbr4v2wjy9dknsq-nixos-test-driver-centjes-e2e-test (1.84 KiB)
120.48 s
[nixos-test-driver-centjes-e2e-test:post-build]
120.48 s
[nixos-test-driver-centjes-e2e-test:post-build] All done.
120.49 s
[nixos-test-driver-centjes-e2e-test:post-build] Uploading to the NixCI staging cache: /nix/store/kyip61120rsn9hriisbr4v2wjy9dknsq-nixos-test-driver-centjes-e2e-test
120.54 s
[nixos-test-driver-centjes-e2e-test:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
120.58 s
[nixos-test-driver-centjes-e2e-test:post-build] copying 1 paths...
120.58 s
[nixos-test-driver-centjes-e2e-test:post-build] copying path '/nix/store/kyip61120rsn9hriisbr4v2wjy9dknsq-nixos-test-driver-centjes-e2e-test' to 'https://cache.staging.nix-ci.com'...
120.80 s
[nixos-test-driver-centjes-e2e-test:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
121.28 s
[nixos-test-driver-centjes-e2e-test:post-build] copying 1 paths...
121.28 s
[nixos-test-driver-centjes-e2e-test:post-build] copying path '/nix/store/2nq014fj1ppaglffarcp1nspq67xb1qc-nixos-test-driver-centjes-e2e-test.drv' to 'https://cache.staging.nix-ci.com'...
121.47 s
Uploaded nixos-test-driver-centjes-e2e-test in 3.0s
121.47 s
Progress: 11 of 13 built
121.47 s
Built nixos-test-driver-centjes-e2e-test in 10.1s
121.54 s
Building /nix/store/7i80czand4927npm2s8v8j9w554vlmcz-vm-test-run-centjes-e2e-test.drv
121.87 s
[vm-test-run-centjes-e2e-test] Machine state will be reset. To keep it, pass --keep-vm-state
121.87 s
[vm-test-run-centjes-e2e-test] start all VLans
121.87 s
[vm-test-run-centjes-e2e-test] start vlan
121.87 s
[vm-test-run-centjes-e2e-test] running vlan (pid 7; ctl /build/vde1.ctl)
121.87 s
[vm-test-run-centjes-e2e-test] (finished: start all VLans, in 0.00 seconds)
121.87 s
[vm-test-run-centjes-e2e-test] Test will time out and terminate in 3600 seconds
121.87 s
[vm-test-run-centjes-e2e-test] run the VM test script
121.87 s
[vm-test-run-centjes-e2e-test] additionally exposed symbols:
121.87 s
[vm-test-run-centjes-e2e-test] client, docsserver,
121.87 s
[vm-test-run-centjes-e2e-test] vlan1,
121.87 s
[vm-test-run-centjes-e2e-test] start_all, test_script, machines, vlans, driver, log, os, create_machine, subtest, run_tests, join_all, retry, serial_stdout_off, serial_stdout_on, polling_condition, Machine, t, debug
121.87 s
[vm-test-run-centjes-e2e-test] docsserver: starting vm
121.98 s
[vm-test-run-centjes-e2e-test] mke2fs 1.47.3 (8-Jul-2025)
122.16 s
[vm-test-run-centjes-e2e-test] docsserver # Disk image does not exist, creating the virtualisation disk image...
122.16 s
[vm-test-run-centjes-e2e-test] docsserver: QEMU running (pid 9)
122.16 s
[vm-test-run-centjes-e2e-test] docsserver # Formatting '/build/vm-state-docsserver/tmp.sGzkliwl0I', fmt=raw size=1073741824
122.16 s
[vm-test-run-centjes-e2e-test] client: starting vm
122.16 s
[vm-test-run-centjes-e2e-test] docsserver # Discarding device blocks: 0/262144 done
122.16 s
[vm-test-run-centjes-e2e-test] docsserver # Creating filesystem with 262144 4k blocks and 65536 inodes
122.16 s
[vm-test-run-centjes-e2e-test] docsserver # Filesystem UUID: 30ec696d-0ac4-40d1-ae34-d8585a77d8c1
122.16 s
[vm-test-run-centjes-e2e-test] docsserver # Superblock backups stored on blocks:
122.16 s
[vm-test-run-centjes-e2e-test] docsserver # 32768, 98304, 163840, 229376
122.18 s
[vm-test-run-centjes-e2e-test] docsserver #
122.18 s
[vm-test-run-centjes-e2e-test] docsserver # Allocating group tables: 0/8 done
122.18 s
[vm-test-run-centjes-e2e-test] docsserver # Writing inode tables: 0/8 done
122.18 s
[vm-test-run-centjes-e2e-test] docsserver # Creating journal (8192 blocks): done
122.18 s
[vm-test-run-centjes-e2e-test] docsserver # Writing superblocks and filesystem accounting information: 0/8 done
122.18 s
[vm-test-run-centjes-e2e-test] docsserver #
122.18 s
[vm-test-run-centjes-e2e-test] docsserver # Virtualisation disk image created.
122.18 s
[vm-test-run-centjes-e2e-test] mke2fs 1.47.3 (8-Jul-2025)
122.25 s
[vm-test-run-centjes-e2e-test] docsserver # c [ ?7l SeaBIOS (version rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org)
122.29 s
[vm-test-run-centjes-e2e-test] client # Disk image does not exist, creating the virtualisation disk image...
122.29 s
[vm-test-run-centjes-e2e-test] client: QEMU running (pid 31)
122.29 s
[vm-test-run-centjes-e2e-test] client # Formatting '/build/vm-state-client/tmp.qzWMICso0O', fmt=raw size=1073741824
122.29 s
[vm-test-run-centjes-e2e-test] client # Discarding device blocks: 0/262144 done
122.29 s
[vm-test-run-centjes-e2e-test] client # Creating filesystem with 262144 4k blocks and 65536 inodes
122.29 s
[vm-test-run-centjes-e2e-test] client # Filesystem UUID: 4f1a6b4a-0db2-43fb-b27b-7012ebb0ac47
122.29 s
[vm-test-run-centjes-e2e-test] client # Superblock backups stored on blocks:
122.29 s
[vm-test-run-centjes-e2e-test] client # 32768, 98304, 163840, 229376
122.31 s
[vm-test-run-centjes-e2e-test] docsserver: waiting for unit default.target
122.31 s
[vm-test-run-centjes-e2e-test] client #
122.31 s
[vm-test-run-centjes-e2e-test] docsserver: waiting for the VM to finish booting
122.31 s
[vm-test-run-centjes-e2e-test] client # Allocating group tables: 0/8 done
122.31 s
[vm-test-run-centjes-e2e-test] client # Writing inode tables: 0/8 done
122.31 s
[vm-test-run-centjes-e2e-test] client # Creating journal (8192 blocks): done
122.31 s
[vm-test-run-centjes-e2e-test] client # Writing superblocks and filesystem accounting information: 0/8 done
122.31 s
[vm-test-run-centjes-e2e-test] client #
122.31 s
[vm-test-run-centjes-e2e-test] client # Virtualisation disk image created.
122.35 s
[vm-test-run-centjes-e2e-test] docsserver #
122.35 s
[vm-test-run-centjes-e2e-test] docsserver #
122.36 s
[vm-test-run-centjes-e2e-test] docsserver # iPXE (http://ipxe.org) 00:03.0 CA00 PCI2.10 PnP PMM+3EFD1920+3EF31920 CA00
122.37 s
[vm-test-run-centjes-e2e-test] docsserver # Press Ctrl-B to configure iPXE (PCI 00:03.0)...
122.37 s
[vm-test-run-centjes-e2e-test] docsserver #
122.37 s
[vm-test-run-centjes-e2e-test] docsserver #
122.37 s
[vm-test-run-centjes-e2e-test] docsserver #
122.37 s
[vm-test-run-centjes-e2e-test] docsserver #
122.38 s
[vm-test-run-centjes-e2e-test] docsserver # iPXE (http://ipxe.org) 00:09.0 CB00 PCI2.10 PnP PMM 3EFD1920 3EF31920 CB00
122.39 s
[vm-test-run-centjes-e2e-test] client # c [ ?7l SeaBIOS (version rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org)
122.39 s
[vm-test-run-centjes-e2e-test] docsserver # Press Ctrl-B to configure iPXE (PCI 00:09.0)...
122.39 s
[vm-test-run-centjes-e2e-test] docsserver #
122.39 s
[vm-test-run-centjes-e2e-test] docsserver #
122.41 s
[vm-test-run-centjes-e2e-test] docsserver # Booting from ROM...
122.42 s
[vm-test-run-centjes-e2e-test] docsserver # Probing EDD (edd=off to disable)... ok
122.49 s
[vm-test-run-centjes-e2e-test] client #
122.49 s
[vm-test-run-centjes-e2e-test] client #
122.49 s
[vm-test-run-centjes-e2e-test] client # iPXE (http://ipxe.org) 00:03.0 CA00 PCI2.10 PnP PMM+3EFD1920+3EF31920 CA00
122.51 s
[vm-test-run-centjes-e2e-test] client # Press Ctrl-B to configure iPXE (PCI 00:03.0)...
122.51 s
[vm-test-run-centjes-e2e-test] client #
122.51 s
[vm-test-run-centjes-e2e-test] client #
122.51 s
[vm-test-run-centjes-e2e-test] client #
122.51 s
[vm-test-run-centjes-e2e-test] client #
122.51 s
[vm-test-run-centjes-e2e-test] client # iPXE (http://ipxe.org) 00:09.0 CB00 PCI2.10 PnP PMM 3EFD1920 3EF31920 CB00
122.53 s
[vm-test-run-centjes-e2e-test] client # Press Ctrl-B to configure iPXE (PCI 00:09.0)...
122.53 s
[vm-test-run-centjes-e2e-test] client #
122.53 s
[vm-test-run-centjes-e2e-test] client #
122.57 s
[vm-test-run-centjes-e2e-test] client # Booting from ROM...
122.72 s
[vm-test-run-centjes-e2e-test] docsserver # c [ ?7l [ 0.000000] Linux version 6.12.62 (nixbld@localhost) (gcc (GCC) 14.3.0, GNU ld (GNU Binutils) 2.44) #1-NixOS SMP PREEMPT_DYNAMIC Fri Dec 12 17:37:22 UTC 2025
122.73 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] Command line: console=ttyS0 console=tty0 panic=1 boot.panic_on_fail clocksource=acpi_pm loglevel=7 net.ifnames=0 lsm=landlock,yama,bpf init=/nix/store/65s8l6c9brrb1g3yskvbz60cb4rmq4db-nixos-system-docsserver-test/init regInfo=/nix/store/ildfwjvkp1mgxjlcmj4jd3l802909i52-closure-info/registration console=ttyS0,115200n8 console=tty0
122.74 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-provided physical RAM map:
122.74 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
122.74 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
122.74 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
122.74 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000003ffdafff] usable
122.75 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x000000003ffdb000-0x000000003fffffff] reserved
122.75 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
122.75 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
122.75 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x000000fd00000000-0x000000ffffffffff] reserved
122.76 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] NX (Execute Disable) protection: active
122.76 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] APIC: Static calls initialized
122.76 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] SMBIOS 2.8 present.
122.76 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org 04/01/2014
122.76 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] DMI: Memory slots populated: 1/1
122.76 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] Hypervisor detected: KVM
122.76 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
122.76 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
122.78 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] kvm-clock: using sched offset of 420522404 cycles
122.78 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000002] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
122.78 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000005] tsc: Detected 3399.998 MHz processor
122.78 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000736] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
122.78 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000937] MTRR map: 4 entries (3 fixed + 1 variable; max 19), built from 8 variable MTRRs
122.78 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.000944] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT
122.78 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.002765] found SMP MP-table at [mem 0x000f5470-0x000f547f]
122.80 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.002776] Using GB pages for direct mapping
122.80 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.002823] RAMDISK: [mem 0x3f3cd000-0x3ffcffff]
122.80 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.002841] ACPI: Early table checksum verification disabled
122.80 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.002844] ACPI: RSDP 0x00000000000F5290 000014 (v00 BOCHS )
122.80 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.002847] ACPI: RSDT 0x000000003FFE23D9 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001)
122.80 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.002851] ACPI: FACP 0x000000003FFE228D 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001)
122.80 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.002854] ACPI: DSDT 0x000000003FFE0040 00224D (v01 BOCHS BXPC 00000001 BXPC 00000001)
122.80 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.002856] ACPI: FACS 0x000000003FFE0000 000040
122.82 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.002857] ACPI: APIC 0x000000003FFE2301 000078 (v03 BOCHS BXPC 00000001 BXPC 00000001)
122.82 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.002859] ACPI: HPET 0x000000003FFE2379 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001)
122.82 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.002861] ACPI: WAET 0x000000003FFE23B1 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001)
122.82 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.002863] ACPI: Reserving FACP table memory at [mem 0x3ffe228d-0x3ffe2300]
122.82 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.002865] ACPI: Reserving DSDT table memory at [mem 0x3ffe0040-0x3ffe228c]
122.82 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.002865] ACPI: Reserving FACS table memory at [mem 0x3ffe0000-0x3ffe003f]
122.82 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.002866] ACPI: Reserving APIC table memory at [mem 0x3ffe2301-0x3ffe2378]
122.82 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.002866] ACPI: Reserving HPET table memory at [mem 0x3ffe2379-0x3ffe23b0]
122.82 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.002867] ACPI: Reserving WAET table memory at [mem 0x3ffe23b1-0x3ffe23d8]
122.82 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.003594] No NUMA configuration found
122.84 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.003595] Faking a node at [mem 0x0000000000000000-0x000000003ffdafff]
122.84 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.003597] NODE_DATA(0) allocated [mem 0x3ffd58c0-0x3ffdadff]
122.84 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.003612] Zone ranges:
122.84 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.003612] DMA [mem 0x0000000000001000-0x0000000000ffffff]
122.84 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.003613] DMA32 [mem 0x0000000001000000-0x000000003ffdafff]
122.84 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.003614] Normal empty
122.84 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.003615] Device empty
122.84 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.003615] Movable zone start for each node
122.84 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.003616] Early memory node ranges
122.84 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.003616] node 0: [mem 0x0000000000001000-0x000000000009efff]
122.84 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.003617] node 0: [mem 0x0000000000100000-0x000000003ffdafff]
122.84 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.003618] Initmem setup node 0 [mem 0x0000000000001000-0x000000003ffdafff]
122.84 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.003754] On node 0, zone DMA: 1 pages in unavailable ranges
122.84 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.003767] On node 0, zone DMA: 97 pages in unavailable ranges
122.84 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.005328] On node 0, zone DMA32: 37 pages in unavailable ranges
122.84 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.006873] ACPI: PM-Timer IO Port: 0x608
122.84 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.006902] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
122.84 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.006981] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
122.85 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.006983] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
122.85 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.006985] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
122.85 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.006985] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
122.85 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.006986] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
122.86 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.006987] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
122.86 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.006989] ACPI: Using ACPI (MADT) for SMP configuration information
122.86 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.006989] ACPI: HPET id: 0x8086a201 base: 0xfed00000
122.86 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.006992] TSC deadline timer available
122.86 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.006995] CPU topo: Max. logical packages: 1
122.86 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.006995] CPU topo: Max. logical dies: 1
122.86 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.006996] CPU topo: Max. dies per package: 1
122.87 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.006999] CPU topo: Max. threads per core: 1
122.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.006999] CPU topo: Num. cores per package: 1
122.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.007000] CPU topo: Num. threads per package: 1
122.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.007000] CPU topo: Allowing 1 present CPUs plus 0 hotplug CPUs
122.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.007025] kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write()
122.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.007075] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]
122.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.007076] PM: hibernation: Registered nosave memory: [mem 0x0009f000-0x000fffff]
122.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.007078] [mem 0x40000000-0xfeffbfff] available for PCI devices
122.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.007078] Booting paravirtualized kernel on KVM
122.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.007080] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
122.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.010540] setup_percpu: NR_CPUS:384 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1
122.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.010770] percpu: Embedded 116 pages/cpu s294912 r65536 d114688 u2097152
122.91 s
[vm-test-run-centjes-e2e-test] client # Probing EDD (edd=off to disable)... o c [ ?7l k[ 0.000000] Linux version 6.12.62 (nixbld@localhost) (gcc (GCC) 14.3.0, GNU ld (GNU Binutils) 2.44) #1-NixOS SMP PREEMPT_DYNAMIC Fri Dec 12 17:37:22 UTC 2025
122.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.010839] kvm-guest: PV spinlocks disabled, single CPU
122.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.010840] Kernel command line: console=ttyS0 console=tty0 panic=1 boot.panic_on_fail clocksource=acpi_pm loglevel=7 net.ifnames=0 lsm=landlock,yama,bpf init=/nix/store/65s8l6c9brrb1g3yskvbz60cb4rmq4db-nixos-system-docsserver-test/init regInfo=/nix/store/ildfwjvkp1mgxjlcmj4jd3l802909i52-closure-info/registration console=ttyS0,115200n8 console=tty0
122.91 s
[vm-test-run-centjes-e2e-test] client # [ 0.000000] Command line: console=ttyS0 console=tty0 panic=1 boot.panic_on_fail clocksource=acpi_pm loglevel=7 net.ifnames=0 lsm=landlock,yama,bpf init=/nix/store/001k9r4jinw78ih5x5hxggb82ynlbkqn-nixos-system-client-test/init regInfo=/nix/store/j7kn31fka8vp5bhm6sw8hv64iyzix7xw-closure-info/registration console=ttyS0,115200n8 console=tty0
122.91 s
[vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-provided physical RAM map:
122.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.010930] Unknown kernel command line parameters "regInfo=/nix/store/ildfwjvkp1mgxjlcmj4jd3l802909i52-closure-info/registration", will be passed to user space.
122.91 s
[vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
122.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.010943] random: crng init done
122.91 s
[vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
122.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.010997] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
122.91 s
[vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
122.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.011031] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)
122.91 s
[vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000003ffdafff] usable
122.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.011068] Fallback order for Node 0: 0
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x000000003ffdb000-0x000000003fffffff] reserved
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.011070] Built 1 zonelists, mobility grouping on. Total pages: 262009
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.011071] Policy zone: DMA32
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.011275] mem auto-init: stack:all(zero), heap alloc:on, heap free:off
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.013079] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x000000fd00000000-0x000000ffffffffff] reserved
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.013291] allocated 2097152 bytes of page_ext
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.000000] NX (Execute Disable) protection: active
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.013303] ftrace: allocating 46208 entries in 181 pages
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.000000] APIC: Static calls initialized
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.021075] ftrace: allocated 181 pages with 5 groups
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.000000] SMBIOS 2.8 present.
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.021848] Dynamic Preempt: voluntary
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.022019] rcu: Preemptible hierarchical RCU implementation.
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org 04/01/2014
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.022019] rcu: RCU event tracing is enabled.
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.000000] DMI: Memory slots populated: 1/1
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.000000] Hypervisor detected: KVM
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.022020] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1.
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.000000] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.022021] Trampoline variant of Tasks RCU enabled.
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.022021] Rude variant of Tasks RCU enabled.
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.022022] Tracing variant of Tasks RCU enabled.
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.000000] kvm-clock: using sched offset of 451238282 cycles
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.022022] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.000001] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.022023] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.000004] tsc: Detected 3399.998 MHz processor
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.000727] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.022030] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.000917] MTRR map: 4 entries (3 fixed + 1 variable; max 19), built from 8 variable MTRRs
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.022031] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.000924] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.022032] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.002793] found SMP MP-table at [mem 0x000f5470-0x000f547f]
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.002804] Using GB pages for direct mapping
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.025473] NR_IRQS: 24832, nr_irqs: 256, preallocated irqs: 16
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.002898] RAMDISK: [mem 0x3f3cd000-0x3ffcffff]
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.025720] rcu: srcu_init: Setting srcu_struct sizes based on contention.
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.002916] ACPI: Early table checksum verification disabled
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.002919] ACPI: RSDP 0x00000000000F5290 000014 (v00 BOCHS )
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.025789] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.038500] Console: colour VGA+ 80x25
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.002922] ACPI: RSDT 0x000000003FFE23D9 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001)
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.038502] printk: legacy console [tty0] enabled
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.002925] ACPI: FACP 0x000000003FFE228D 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001)
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.142490] printk: legacy console [ttyS0] enabled
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.377445] ACPI: Core revision 20240827
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.002928] ACPI: DSDT 0x000000003FFE0040 00224D (v01 BOCHS BXPC 00000001 BXPC 00000001)
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.002930] ACPI: FACS 0x000000003FFE0000 000040
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.379641] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.002931] ACPI: APIC 0x000000003FFE2301 000078 (v03 BOCHS BXPC 00000001 BXPC 00000001)
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.383813] APIC: Switch to symmetric I/O mode setup
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.002933] ACPI: HPET 0x000000003FFE2379 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001)
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.386802] x2apic enabled
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.002934] ACPI: WAET 0x000000003FFE23B1 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001)
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.002936] ACPI: Reserving FACP table memory at [mem 0x3ffe228d-0x3ffe2300]
122.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.388999] APIC: Switched APIC routing to: physical x2apic
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.002937] ACPI: Reserving DSDT table memory at [mem 0x3ffe0040-0x3ffe228c]
122.97 s
[vm-test-run-centjes-e2e-test] client # [ 0.002937] ACPI: Reserving FACS table memory at [mem 0x3ffe0000-0x3ffe003f]
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.395008] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.002938] ACPI: Reserving APIC table memory at [mem 0x3ffe2301-0x3ffe2378]
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.002938] ACPI: Reserving HPET table memory at [mem 0x3ffe2379-0x3ffe23b0]
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.397754] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x31024cfe468, max_idle_ns: 440795307017 ns
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.002938] ACPI: Reserving WAET table memory at [mem 0x3ffe23b1-0x3ffe23d8]
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.003716] No NUMA configuration found
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.003717] Faking a node at [mem 0x0000000000000000-0x000000003ffdafff]
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.402434] Calibrating delay loop (skipped) preset value.. 6799.99 BogoMIPS (lpj=3399998)
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.003720] NODE_DATA(0) allocated [mem 0x3ffd58c0-0x3ffdadff]
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.003734] Zone ranges:
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.404975] x86/cpu: User Mode Instruction Prevention (UMIP) activated
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.003734] DMA [mem 0x0000000000001000-0x0000000000ffffff]
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.003736] DMA32 [mem 0x0000000001000000-0x000000003ffdafff]
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.407595] Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.003737] Normal empty
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.003738] Device empty
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.003739] Movable zone start for each node
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.408433] Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.003740] Early memory node ranges
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.003740] node 0: [mem 0x0000000000001000-0x000000000009efff]
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.410443] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.003741] node 0: [mem 0x0000000000100000-0x000000003ffdafff]
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.412434] Spectre V2 : Mitigation: Retpolines
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.003743] Initmem setup node 0 [mem 0x0000000000001000-0x000000003ffdafff]
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.003874] On node 0, zone DMA: 1 pages in unavailable ranges
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.003889] On node 0, zone DMA: 97 pages in unavailable ranges
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.414433] Spectre V2 : Spectre v2 / SpectreRSB: Filling RSB on context switch and VMEXIT
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.005501] On node 0, zone DMA32: 37 pages in unavailable ranges
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007130] ACPI: PM-Timer IO Port: 0x608
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.416433] Spectre V2 : Enabling Restricted Speculation for firmware calls
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007154] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007235] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.419435] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007237] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007239] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.421434] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007240] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.424433] active return thunk: srso_alias_return_thunk
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007240] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007241] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.426433] Speculative Return Stack Overflow: Mitigation: Safe RET
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007243] ACPI: Using ACPI (MADT) for SMP configuration information
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.428433] Transient Scheduler Attacks: Forcing mitigation on in a VM
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007244] ACPI: HPET id: 0x8086a201 base: 0xfed00000
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007246] TSC deadline timer available
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007250] CPU topo: Max. logical packages: 1
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.429434] Transient Scheduler Attacks: Vulnerable: Clear CPU buffers attempted, no microcode
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007251] CPU topo: Max. logical dies: 1
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007251] CPU topo: Max. dies per package: 1
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007254] CPU topo: Max. threads per core: 1
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.432468] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007255] CPU topo: Num. cores per package: 1
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007255] CPU topo: Num. threads per package: 1
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007255] CPU topo: Allowing 1 present CPUs plus 0 hotplug CPUs
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007281] kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write()
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007332] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007333] PM: hibernation: Registered nosave memory: [mem 0x0009f000-0x000fffff]
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007334] [mem 0x40000000-0xfeffbfff] available for PCI devices
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.434433] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007335] Booting paravirtualized kernel on KVM
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.007336] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.436433] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.010871] setup_percpu: NR_CPUS:384 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.438433] x86/fpu: Supporting XSAVE feature 0x200: 'Protection Keys User registers'
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.011100] percpu: Embedded 116 pages/cpu s294912 r65536 d114688 u2097152
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.011169] kvm-guest: PV spinlocks disabled, single CPU
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.440433] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.442433] x86/fpu: xstate_offset[9]: 832, xstate_sizes[9]: 8
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.444433] x86/fpu: Enabled xstate features 0x207, context size is 840 bytes, using 'compacted' format.
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.011171] Kernel command line: console=ttyS0 console=tty0 panic=1 boot.panic_on_fail clocksource=acpi_pm loglevel=7 net.ifnames=0 lsm=landlock,yama,bpf init=/nix/store/001k9r4jinw78ih5x5hxggb82ynlbkqn-nixos-system-client-test/init regInfo=/nix/store/j7kn31fka8vp5bhm6sw8hv64iyzix7xw-closure-info/registration console=ttyS0,115200n8 console=tty0
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.011244] Unknown kernel command line parameters "regInfo=/nix/store/j7kn31fka8vp5bhm6sw8hv64iyzix7xw-closure-info/registration", will be passed to user space.
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.011259] random: crng init done
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.011322] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.011360] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.011409] Fallback order for Node 0: 0
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.011412] Built 1 zonelists, mobility grouping on. Total pages: 262009
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.011413] Policy zone: DMA32
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.011609] mem auto-init: stack:all(zero), heap alloc:on, heap free:off
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.013552] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.013762] allocated 2097152 bytes of page_ext
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.013774] ftrace: allocating 46208 entries in 181 pages
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.021574] ftrace: allocated 181 pages with 5 groups
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.022155] Dynamic Preempt: voluntary
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.022335] rcu: Preemptible hierarchical RCU implementation.
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.022336] rcu: RCU event tracing is enabled.
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.472280] Freeing SMP alternatives memory: 40K
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.022336] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1.
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.473434] pid_max: default: 32768 minimum: 301
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.022338] Trampoline variant of Tasks RCU enabled.
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.022338] Rude variant of Tasks RCU enabled.
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.022338] Tracing variant of Tasks RCU enabled.
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.474497] LSM: initializing lsm=capability,landlock,yama,bpf
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.476505] landlock: Up and running.
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.022339] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.478434] Yama: becoming mindful.
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.022339] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.479623] LSM support for eBPF active
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.022347] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.022349] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.480454] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.022350] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.482435] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.026090] NR_IRQS: 24832, nr_irqs: 256, preallocated irqs: 16
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.026339] rcu: srcu_init: Setting srcu_struct sizes based on contention.
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.484825] smpboot: CPU0: AMD Ryzen 9 5950X 16-Core Processor (family: 0x19, model: 0x21, stepping: 0x0)
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.026409] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.039409] Console: colour VGA+ 80x25
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.039412] printk: legacy console [tty0] enabled
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.486652] Performance Events: Fam17h+ core perfctr, AMD PMU driver.
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.142399] printk: legacy console [ttyS0] enabled
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.488468] ... version: 0
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.373084] ACPI: Core revision 20240827
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.489439] ... bit width: 48
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.490440] ... generic registers: 6
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.375098] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.491440] ... value mask: 0000ffffffffffff
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.379135] APIC: Switch to symmetric I/O mode setup
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.492440] ... max period: 00007fffffffffff
123.12 s
[vm-test-run-centjes-e2e-test] client # [ 0.382464] x2apic enabled
123.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.493461] ... fixed-purpose events: 0
123.13 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.494441] ... event mask: 000000000000003f
123.13 s
[vm-test-run-centjes-e2e-test] client # [ 0.384948] APIC: Switched APIC routing to: physical x2apic
123.13 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.495525] signal: max sigframe size: 3376
123.13 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.496486] rcu: Hierarchical SRCU implementation.
123.13 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.497442] rcu: Max phase no-delay instances is 400.
123.13 s
[vm-test-run-centjes-e2e-test] client # [ 0.391950] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
123.14 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.501622] smp: Bringing up secondary CPUs ...
123.14 s
[vm-test-run-centjes-e2e-test] client # [ 0.395008] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x31024cfe468, max_idle_ns: 440795307017 ns
123.14 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.502461] smp: Brought up 1 node, 1 CPU
123.14 s
[vm-test-run-centjes-e2e-test] client # [ 0.399793] Calibrating delay loop (skipped) preset value.. 6799.99 BogoMIPS (lpj=3399998)
123.14 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.503443] smpboot: Total of 1 processors activated (6799.99 BogoMIPS)
123.15 s
[vm-test-run-centjes-e2e-test] client # [ 0.403099] x86/cpu: User Mode Instruction Prevention (UMIP) activated
123.15 s
[vm-test-run-centjes-e2e-test] client # [ 0.405197] Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127
123.15 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.504750] Memory: 962124K/1048036K available (16384K kernel code, 2645K rwdata, 12580K rodata, 3408K init, 3360K bss, 78836K reserved, 0K cma-reserved)
123.15 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.506543] devtmpfs: initialized
123.15 s
[vm-test-run-centjes-e2e-test] client # [ 0.406791] Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0
123.15 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.507499] x86/mm: Memory block size: 128MB
123.16 s
[vm-test-run-centjes-e2e-test] client # [ 0.408803] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
123.16 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.508903] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
123.16 s
[vm-test-run-centjes-e2e-test] client # [ 0.410793] Spectre V2 : Mitigation: Retpolines
123.16 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.510445] futex hash table entries: 256 (order: 2, 16384 bytes, linear)
123.16 s
[vm-test-run-centjes-e2e-test] client # [ 0.411792] Spectre V2 : Spectre v2 / SpectreRSB: Filling RSB on context switch and VMEXIT
123.16 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.511487] pinctrl core: initialized pinctrl subsystem
123.17 s
[vm-test-run-centjes-e2e-test] client # [ 0.413792] Spectre V2 : Enabling Restricted Speculation for firmware calls
123.17 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.512738] PM: RTC time: 20:41:41, date: 2026-08-04
123.17 s
[vm-test-run-centjes-e2e-test] client # [ 0.414794] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
123.17 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.514959] NET: Registered PF_NETLINK/PF_ROUTE protocol family
123.17 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.516617] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations
123.17 s
[vm-test-run-centjes-e2e-test] client # [ 0.416792] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl
123.18 s
[vm-test-run-centjes-e2e-test] client # [ 0.418792] active return thunk: srso_alias_return_thunk
123.18 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.518448] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
123.18 s
[vm-test-run-centjes-e2e-test] client # [ 0.420792] Speculative Return Stack Overflow: Mitigation: Safe RET
123.18 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.520443] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
123.18 s
[vm-test-run-centjes-e2e-test] client # [ 0.422792] Transient Scheduler Attacks: Forcing mitigation on in a VM
123.18 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.522446] audit: initializing netlink subsys (disabled)
123.19 s
[vm-test-run-centjes-e2e-test] client # [ 0.423792] Transient Scheduler Attacks: Vulnerable: Clear CPU buffers attempted, no microcode
123.19 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.523468] audit: type=2000 audit(1785876100.954:1): state=initialized audit_enabled=0 res=1
123.19 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.525542] thermal_sys: Registered thermal governor 'bang_bang'
123.19 s
[vm-test-run-centjes-e2e-test] client # [ 0.425871] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
123.19 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.525543] thermal_sys: Registered thermal governor 'step_wise'
123.19 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.526440] thermal_sys: Registered thermal governor 'user_space'
123.20 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.527458] cpuidle: using governor menu
123.20 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.531138] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
123.20 s
[vm-test-run-centjes-e2e-test] client # [ 0.427791] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
123.20 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.532654] PCI: Using configuration type 1 for base access
123.20 s
[vm-test-run-centjes-e2e-test] client # [ 0.429791] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
123.21 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.533439] PCI: Using configuration type 1 for extended access
123.21 s
[vm-test-run-centjes-e2e-test] client # [ 0.431792] x86/fpu: Supporting XSAVE feature 0x200: 'Protection Keys User registers'
123.21 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.534587] kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible.
123.21 s
[vm-test-run-centjes-e2e-test] client # [ 0.433792] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256
123.21 s
[vm-test-run-centjes-e2e-test] client # [ 0.435793] x86/fpu: xstate_offset[9]: 832, xstate_sizes[9]: 8
123.22 s
[vm-test-run-centjes-e2e-test] client # [ 0.437792] x86/fpu: Enabled xstate features 0x207, context size is 840 bytes, using 'compacted' format.
123.23 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.556457] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages
123.24 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.557457] HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page
123.24 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.558440] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
123.24 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.559439] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page
123.24 s
[vm-test-run-centjes-e2e-test] client # [ 0.453790] Freeing SMP alternatives memory: 40K
123.25 s
[vm-test-run-centjes-e2e-test] client # [ 0.453790] pid_max: default: 32768 minimum: 301
123.25 s
[vm-test-run-centjes-e2e-test] client # [ 0.453790] LSM: initializing lsm=capability,landlock,yama,bpf
123.25 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.564065] ACPI: Added _OSI(Module Device)
123.25 s
[vm-test-run-centjes-e2e-test] client # [ 0.453790] landlock: Up and running.
123.25 s
[vm-test-run-centjes-e2e-test] client # [ 0.453790] Yama: becoming mindful.
123.25 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.566460] ACPI: Added _OSI(Processor Device)
123.25 s
[vm-test-run-centjes-e2e-test] client # [ 0.453790] LSM support for eBPF active
123.25 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.567676] ACPI: Added _OSI(Processor Aggregator Device)
123.26 s
[vm-test-run-centjes-e2e-test] client # [ 0.453790] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
123.26 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.571258] ACPI: 1 ACPI AML tables successfully acquired and loaded
123.26 s
[vm-test-run-centjes-e2e-test] client # [ 0.453790] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
123.26 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.573682] ACPI: Interpreter enabled
123.26 s
[vm-test-run-centjes-e2e-test] client # [ 0.453790] smpboot: CPU0: AMD Ryzen 9 5950X 16-Core Processor (family: 0x19, model: 0x21, stepping: 0x0)
123.27 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.574453] ACPI: PM: (supports S0 S3 S4 S5)
123.27 s
[vm-test-run-centjes-e2e-test] client # [ 0.455021] Performance Events: Fam17h+ core perfctr, AMD PMU driver.
123.27 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.575444] ACPI: Using IOAPIC for interrupt routing
123.27 s
[vm-test-run-centjes-e2e-test] client # [ 0.456806] ... version: 0
123.27 s
[vm-test-run-centjes-e2e-test] client # [ 0.457798] ... bit width: 48
123.27 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.576464] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
123.27 s
[vm-test-run-centjes-e2e-test] client # [ 0.458798] ... generic registers: 6
123.27 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.578439] PCI: Using E820 reservations for host bridge windows
123.28 s
[vm-test-run-centjes-e2e-test] client # [ 0.459799] ... value mask: 0000ffffffffffff
123.28 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.579611] ACPI: Enabled 2 GPEs in block 00 to 0F
123.28 s
[vm-test-run-centjes-e2e-test] client # [ 0.460798] ... max period: 00007fffffffffff
123.28 s
[vm-test-run-centjes-e2e-test] client # [ 0.461798] ... fixed-purpose events: 0
123.28 s
[vm-test-run-centjes-e2e-test] client # [ 0.462798] ... event mask: 000000000000003f
123.28 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.584363] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
123.36 s
[vm-test-run-centjes-e2e-test] client # [ 0.463889] signal: max sigframe size: 3376
123.36 s
[vm-test-run-centjes-e2e-test] client # [ 0.464840] rcu: Hierarchical SRCU implementation.
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.585443] acpi PNP0A03:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3]
123.36 s
[vm-test-run-centjes-e2e-test] client # [ 0.465799] rcu: Max phase no-delay instances is 400.
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.587758] acpiphp: Slot [3] registered
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.588504] acpiphp: Slot [4] registered
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.589477] acpiphp: Slot [5] registered
123.36 s
[vm-test-run-centjes-e2e-test] client # [ 0.469836] smp: Bringing up secondary CPUs ...
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.590480] acpiphp: Slot [6] registered
123.36 s
[vm-test-run-centjes-e2e-test] client # [ 0.470828] smp: Brought up 1 node, 1 CPU
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.591478] acpiphp: Slot [7] registered
123.36 s
[vm-test-run-centjes-e2e-test] client # [ 0.471801] smpboot: Total of 1 processors activated (6799.99 BogoMIPS)
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.592477] acpiphp: Slot [8] registered
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.593495] acpiphp: Slot [9] registered
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.594483] acpiphp: Slot [10] registered
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.595495] acpiphp: Slot [11] registered
123.36 s
[vm-test-run-centjes-e2e-test] client # [ 0.473141] Memory: 962120K/1048036K available (16384K kernel code, 2645K rwdata, 12580K rodata, 3408K init, 3360K bss, 78840K reserved, 0K cma-reserved)
123.36 s
[vm-test-run-centjes-e2e-test] client # [ 0.474895] devtmpfs: initialized
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.596482] acpiphp: Slot [12] registered
123.36 s
[vm-test-run-centjes-e2e-test] client # [ 0.475875] x86/mm: Memory block size: 128MB
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.597483] acpiphp: Slot [13] registered
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.598478] acpiphp: Slot [14] registered
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.599506] acpiphp: Slot [15] registered
123.36 s
[vm-test-run-centjes-e2e-test] client # [ 0.477289] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.600479] acpiphp: Slot [16] registered
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.601508] acpiphp: Slot [17] registered
123.36 s
[vm-test-run-centjes-e2e-test] client # [ 0.478804] futex hash table entries: 256 (order: 2, 16384 bytes, linear)
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.602479] acpiphp: Slot [18] registered
123.36 s
[vm-test-run-centjes-e2e-test] client # [ 0.480852] pinctrl core: initialized pinctrl subsystem
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.603481] acpiphp: Slot [19] registered
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.604480] acpiphp: Slot [20] registered
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.605477] acpiphp: Slot [21] registered
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.606479] acpiphp: Slot [22] registered
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.607480] acpiphp: Slot [23] registered
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.608500] acpiphp: Slot [24] registered
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.609502] acpiphp: Slot [25] registered
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.610493] acpiphp: Slot [26] registered
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.611477] acpiphp: Slot [27] registered
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.612495] acpiphp: Slot [28] registered
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.613476] acpiphp: Slot [29] registered
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.614476] acpiphp: Slot [30] registered
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.615509] acpiphp: Slot [31] registered
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.616487] PCI host bridge to bus 0000:00
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.617445] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]
123.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.618440] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]
123.37 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.619440] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
123.37 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.621440] pci_bus 0000:00: root bus resource [mem 0x40000000-0xfebfffff window]
123.37 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.623440] pci_bus 0000:00: root bus resource [mem 0x100000000-0x17fffffff window]
123.37 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.625440] pci_bus 0000:00: root bus resource [bus 00-ff]
123.37 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.626967] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 conventional PCI endpoint
123.38 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.629685] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 conventional PCI endpoint
123.38 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.633154] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 conventional PCI endpoint
123.39 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.639440] pci 0000:00:01.1: BAR 4 [io 0xc1e0-0xc1ef]
123.40 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.641921] pci 0000:00:01.1: BAR 0 [io 0x01f0-0x01f7]: legacy IDE quirk
123.40 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.643441] pci 0000:00:01.1: BAR 1 [io 0x03f6]: legacy IDE quirk
123.40 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.644439] pci 0000:00:01.1: BAR 2 [io 0x0170-0x0177]: legacy IDE quirk
123.40 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.645442] pci 0000:00:01.1: BAR 3 [io 0x0376]: legacy IDE quirk
123.41 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.646815] pci 0000:00:01.2: [8086:7020] type 00 class 0x0c0300 conventional PCI endpoint
123.41 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.651439] pci 0000:00:01.2: BAR 4 [io 0xc100-0xc11f]
123.42 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.654637] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 conventional PCI endpoint
123.43 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.657659] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI
123.43 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.659463] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB
123.43 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.661006] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000 conventional PCI endpoint
123.44 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.663979] pci 0000:00:02.0: BAR 0 [mem 0xfd000000-0xfdffffff pref]
123.44 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.668049] pci 0000:00:02.0: BAR 2 [mem 0xfebd0000-0xfebd0fff]
123.45 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.674302] pci 0000:00:02.0: ROM [mem 0xfebc0000-0xfebcffff pref]
123.46 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.675636] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
123.46 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.678198] pci 0000:00:03.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
123.47 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.680440] pci 0000:00:03.0: BAR 0 [io 0xc120-0xc13f]
123.47 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.682419] pci 0000:00:03.0: BAR 1 [mem 0xfebd1000-0xfebd1fff]
123.48 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.687439] pci 0000:00:03.0: BAR 4 [mem 0xfe000000-0xfe003fff 64bit pref]
123.48 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.690443] pci 0000:00:03.0: ROM [mem 0xfeb40000-0xfeb7ffff pref]
123.49 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.694189] pci 0000:00:04.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
123.49 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.696440] pci 0000:00:04.0: BAR 0 [io 0xc140-0xc15f]
123.50 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.698440] pci 0000:00:04.0: BAR 1 [mem 0xfebd2000-0xfebd2fff]
123.50 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.702322] pci 0000:00:04.0: BAR 4 [mem 0xfe004000-0xfe007fff 64bit pref]
123.51 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.707154] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
123.52 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.709417] pci 0000:00:05.0: BAR 0 [io 0xc080-0xc0bf]
123.52 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.711439] pci 0000:00:05.0: BAR 1 [mem 0xfebd3000-0xfebd3fff]
123.53 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.716042] pci 0000:00:05.0: BAR 4 [mem 0xfe008000-0xfe00bfff 64bit pref]
123.54 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.721754] pci 0000:00:06.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
123.54 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.724441] pci 0000:00:06.0: BAR 0 [io 0xc160-0xc17f]
123.54 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.726890] pci 0000:00:06.0: BAR 1 [mem 0xfebd4000-0xfebd4fff]
123.55 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.730964] pci 0000:00:06.0: BAR 4 [mem 0xfe00c000-0xfe00ffff 64bit pref]
123.56 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.736894] pci 0000:00:07.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
123.56 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.739388] pci 0000:00:07.0: BAR 0 [io 0xc180-0xc19f]
123.57 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.741440] pci 0000:00:07.0: BAR 1 [mem 0xfebd5000-0xfebd5fff]
123.57 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.744884] pci 0000:00:07.0: BAR 4 [mem 0xfe010000-0xfe013fff 64bit pref]
123.58 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.750964] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint
123.58 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.753439] pci 0000:00:08.0: BAR 0 [io 0xc000-0xc07f]
123.59 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.755439] pci 0000:00:08.0: BAR 1 [mem 0xfebd6000-0xfebd6fff]
123.60 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.760161] pci 0000:00:08.0: BAR 4 [mem 0xfe014000-0xfe017fff 64bit pref]
123.60 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.764938] pci 0000:00:09.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
123.61 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.767439] pci 0000:00:09.0: BAR 0 [io 0xc1a0-0xc1bf]
123.61 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.770250] pci 0000:00:09.0: BAR 1 [mem 0xfebd7000-0xfebd7fff]
123.62 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.773841] pci 0000:00:09.0: BAR 4 [mem 0xfe018000-0xfe01bfff 64bit pref]
123.68 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.776280] pci 0000:00:09.0: ROM [mem 0xfeb80000-0xfebbffff pref]
123.69 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.780001] pci 0000:00:0a.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint
123.69 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.782766] pci 0000:00:0a.0: BAR 1 [mem 0xfebd8000-0xfebd8fff]
123.70 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.786412] pci 0000:00:0a.0: BAR 4 [mem 0xfe01c000-0xfe01ffff 64bit pref]
123.70 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.790990] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint
123.71 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.793439] pci 0000:00:0b.0: BAR 0 [io 0xc0c0-0xc0ff]
123.71 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.795439] pci 0000:00:0b.0: BAR 1 [mem 0xfebd9000-0xfebd9fff]
123.72 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.798851] pci 0000:00:0b.0: BAR 4 [mem 0xfe020000-0xfe023fff 64bit pref]
123.73 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.804797] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
123.73 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.807439] pci 0000:00:0c.0: BAR 0 [io 0xc1c0-0xc1df]
123.73 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.809403] pci 0000:00:0c.0: BAR 1 [mem 0xfebda000-0xfebdafff]
123.74 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.812853] pci 0000:00:0c.0: BAR 4 [mem 0xfe024000-0xfe027fff 64bit pref]
123.75 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.818984] ACPI: PCI: Interrupt link LNKA configured for IRQ 10
123.75 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.820645] ACPI: PCI: Interrupt link LNKB configured for IRQ 10
123.75 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.822615] ACPI: PCI: Interrupt link LNKC configured for IRQ 11
123.75 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.823622] ACPI: PCI: Interrupt link LNKD configured for IRQ 11
123.76 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.824536] ACPI: PCI: Interrupt link LNKS configured for IRQ 9
123.76 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.825827] iommu: Default domain type: Translated
123.76 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.827439] iommu: DMA domain TLB invalidation policy: lazy mode
123.76 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.828486] ACPI: bus type USB registered
123.77 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.829461] usbcore: registered new interface driver usbfs
123.77 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.830449] usbcore: registered new interface driver hub
123.77 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.831448] usbcore: registered new device driver usb
123.77 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.832752] NetLabel: Initializing
123.78 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.833439] NetLabel: domain hash size = 128
123.78 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.834443] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO
123.78 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.835458] NetLabel: unlabeled traffic allowed by default
123.78 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.836441] PCI: Using ACPI for IRQ routing
123.79 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.838227] pci 0000:00:02.0: vgaarb: setting as boot VGA device
123.79 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.838431] pci 0000:00:02.0: vgaarb: bridge control possible
123.79 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.838431] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
123.80 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.838441] vgaarb: loaded
123.80 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.839543] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
123.80 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.840439] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
123.81 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.843479] clocksource: Switched to clocksource kvm-clock
123.81 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.847170] VFS: Disk quotas dquot_6.6.0
123.81 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.849086] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
123.81 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.852210] pnp: PnP ACPI init
123.82 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.854445] pnp: PnP ACPI: found 6 devices
123.83 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.862667] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
123.83 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.866509] clocksource: Switched to clocksource acpi_pm
123.83 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.869136] NET: Registered PF_INET protocol family
123.83 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.871525] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
123.85 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.884039] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)
123.85 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.887792] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
123.85 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.891346] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)
123.86 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.894933] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)
123.86 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.898247] TCP: Hash tables configured (established 8192 bind 8192)
123.86 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.901238] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)
123.87 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.904561] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
123.87 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.907810] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
123.87 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.911311] NET: Registered PF_UNIX/PF_LOCAL protocol family
123.88 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.913910] NET: Registered PF_XDP protocol family
123.88 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.916176] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]
123.88 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.919140] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]
123.88 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.921988] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
123.89 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.925154] pci_bus 0000:00: resource 7 [mem 0x40000000-0xfebfffff window]
123.89 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.928373] pci_bus 0000:00: resource 8 [mem 0x100000000-0x17fffffff window]
123.89 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.931800] pci 0000:00:01.0: PIIX3: Enabling Passive Release
123.90 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.934521] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
123.90 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.938660] ACPI: \_SB_.LNKD: Enabled at IRQ 11
123.90 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.942889] PCI: CLS 0 bytes, default 64
123.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.944988] Trying to unpack rootfs image as initramfs...
123.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.949891] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x31024cfe468, max_idle_ns: 440795307017 ns
123.94 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.982002] Initialise system trusted keyrings
123.95 s
[vm-test-run-centjes-e2e-test] docsserver # [ 0.988922] workingset: timestamp_bits=40 max_order=18 bucket_order=0
123.96 s
[vm-test-run-centjes-e2e-test] client # [ 1.108728] Reading current time from RTC took around 470 ms
123.97 s
[vm-test-run-centjes-e2e-test] client # [ 1.109798] PM: RTC time: 20:41:41, date: 2026-08-04
123.97 s
[vm-test-run-centjes-e2e-test] client # [ 1.111469] NET: Registered PF_NETLINK/PF_ROUTE protocol family
123.97 s
[vm-test-run-centjes-e2e-test] client # [ 1.112957] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations
123.98 s
[vm-test-run-centjes-e2e-test] client # [ 1.114807] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
123.98 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.014902] Key type asymmetric registered
123.98 s
[vm-test-run-centjes-e2e-test] client # [ 1.116807] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
123.98 s
[vm-test-run-centjes-e2e-test] client # [ 1.118811] audit: initializing netlink subsys (disabled)
123.98 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.019906] Asymmetric key parser 'x509' registered
123.98 s
[vm-test-run-centjes-e2e-test] client # [ 1.119848] audit: type=2000 audit(1785876101.720:1): state=initialized audit_enabled=0 res=1
123.99 s
[vm-test-run-centjes-e2e-test] client # [ 1.121929] thermal_sys: Registered thermal governor 'bang_bang'
123.99 s
[vm-test-run-centjes-e2e-test] client # [ 1.121931] thermal_sys: Registered thermal governor 'step_wise'
123.99 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.026825] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
123.99 s
[vm-test-run-centjes-e2e-test] client # [ 1.122799] thermal_sys: Registered thermal governor 'user_space'
123.99 s
[vm-test-run-centjes-e2e-test] client # [ 1.123814] cpuidle: using governor menu
124.00 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.036223] Freeing initrd memory: 12300K
124.00 s
[vm-test-run-centjes-e2e-test] client # [ 1.127470] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
124.00 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.038340] io scheduler mq-deadline registered
124.00 s
[vm-test-run-centjes-e2e-test] client # [ 1.129061] PCI: Using configuration type 1 for base access
124.00 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.040566] io scheduler kyber registered
124.00 s
[vm-test-run-centjes-e2e-test] client # [ 1.130797] PCI: Using configuration type 1 for extended access
124.01 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.043053] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
124.01 s
[vm-test-run-centjes-e2e-test] client # [ 1.131948] kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible.
124.01 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.046423] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
124.01 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.051012] Linux agpgart interface v0.103
124.01 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.053104] ACPI: bus type drm_connector registered
124.02 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.055670] usbcore: registered new interface driver usbserial_generic
124.02 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.058627] usbserial: USB Serial support registered for generic
124.02 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.061664] amd_pstate: the _CPC object is not present in SBIOS or ACPI disabled
124.03 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.065285] drop_monitor: Initializing network drop monitor service
124.03 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.068315] NET: Registered PF_INET6 protocol family
124.03 s
[vm-test-run-centjes-e2e-test] client # [ 1.153877] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages
124.03 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.071424] Segment Routing with IPv6
124.03 s
[vm-test-run-centjes-e2e-test] client # [ 1.154798] HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page
124.03 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.073414] In-situ OAM (IOAM) with IPv6
124.04 s
[vm-test-run-centjes-e2e-test] client # [ 1.155799] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
124.04 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.075823] IPI shorthand broadcast: enabled
124.04 s
[vm-test-run-centjes-e2e-test] client # [ 1.156800] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page
124.04 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.080192] registered taskstats version 1
124.04 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.082916] Loading compiled-in X.509 certificates
124.05 s
[vm-test-run-centjes-e2e-test] client # [ 1.162810] ACPI: Added _OSI(Module Device)
124.05 s
[vm-test-run-centjes-e2e-test] client # [ 1.163813] ACPI: Added _OSI(Processor Device)
124.05 s
[vm-test-run-centjes-e2e-test] client # [ 1.164802] ACPI: Added _OSI(Processor Aggregator Device)
124.05 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.090629] Demotion targets for Node 0: null
124.05 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.093088] Key type .fscrypt registered
124.06 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.095192] Key type fscrypt-provisioning registered
124.06 s
[vm-test-run-centjes-e2e-test] client # [ 1.167804] ACPI: 1 ACPI AML tables successfully acquired and loaded
124.06 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.097787] PM: Magic number: 6:567:699
124.06 s
[vm-test-run-centjes-e2e-test] client # [ 1.170066] ACPI: Interpreter enabled
124.06 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.100621] RAS: Correctable Errors collector initialized.
124.06 s
[vm-test-run-centjes-e2e-test] client # [ 1.170816] ACPI: PM: (supports S0 S3 S4 S5)
124.07 s
[vm-test-run-centjes-e2e-test] client # [ 1.171799] ACPI: Using IOAPIC for interrupt routing
124.07 s
[vm-test-run-centjes-e2e-test] client # [ 1.172813] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
124.07 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.106963] Unstable clock detected, switching default tracing clock to "global"
124.07 s
[vm-test-run-centjes-e2e-test] client # [ 1.174797] PCI: Using E820 reservations for host bridge windows
124.07 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.106963] If you want to keep using the local clock, then add:
124.07 s
[vm-test-run-centjes-e2e-test] client # [ 1.175947] ACPI: Enabled 2 GPEs in block 00 to 0F
124.08 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.106963] "trace_clock=local"
124.08 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.106963] on the kernel command line
124.08 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.117001] clk: Disabling unused clocks
124.08 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.119127] PM: genpd: Disabling unused power domains
124.08 s
[vm-test-run-centjes-e2e-test] client # [ 1.180506] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
124.08 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.122572] Freeing unused decrypted memory: 2028K
124.09 s
[vm-test-run-centjes-e2e-test] client # [ 1.181802] acpi PNP0A03:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3]
124.09 s
[vm-test-run-centjes-e2e-test] client # [ 1.184126] acpiphp: Slot [3] registered
124.09 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.125194] Freeing unused kernel image (initmem) memory: 3408K
124.09 s
[vm-test-run-centjes-e2e-test] client # [ 1.184835] acpiphp: Slot [4] registered
124.09 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.127956] Write protecting the kernel read-only data: 30720k
124.09 s
[vm-test-run-centjes-e2e-test] client # [ 1.185835] acpiphp: Slot [5] registered
124.09 s
[vm-test-run-centjes-e2e-test] client # [ 1.186834] acpiphp: Slot [6] registered
124.09 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.131562] Freeing unused kernel image (rodata/data gap) memory: 1756K
124.09 s
[vm-test-run-centjes-e2e-test] client # [ 1.187836] acpiphp: Slot [7] registered
124.10 s
[vm-test-run-centjes-e2e-test] client # [ 1.188860] acpiphp: Slot [8] registered
124.10 s
[vm-test-run-centjes-e2e-test] client # [ 1.189835] acpiphp: Slot [9] registered
124.10 s
[vm-test-run-centjes-e2e-test] client # [ 1.190834] acpiphp: Slot [10] registered
124.10 s
[vm-test-run-centjes-e2e-test] client # [ 1.191834] acpiphp: Slot [11] registered
124.10 s
[vm-test-run-centjes-e2e-test] client # [ 1.192837] acpiphp: Slot [12] registered
124.11 s
[vm-test-run-centjes-e2e-test] client # [ 1.193836] acpiphp: Slot [13] registered
124.11 s
[vm-test-run-centjes-e2e-test] client # [ 1.194833] acpiphp: Slot [14] registered
124.11 s
[vm-test-run-centjes-e2e-test] client # [ 1.195834] acpiphp: Slot [15] registered
124.11 s
[vm-test-run-centjes-e2e-test] client # [ 1.196837] acpiphp: Slot [16] registered
124.11 s
[vm-test-run-centjes-e2e-test] client # [ 1.197854] acpiphp: Slot [17] registered
124.12 s
[vm-test-run-centjes-e2e-test] client # [ 1.198835] acpiphp: Slot [18] registered
124.12 s
[vm-test-run-centjes-e2e-test] client # [ 1.199834] acpiphp: Slot [19] registered
124.12 s
[vm-test-run-centjes-e2e-test] client # [ 1.200836] acpiphp: Slot [20] registered
124.12 s
[vm-test-run-centjes-e2e-test] client # [ 1.201834] acpiphp: Slot [21] registered
124.12 s
[vm-test-run-centjes-e2e-test] client # [ 1.202832] acpiphp: Slot [22] registered
124.13 s
[vm-test-run-centjes-e2e-test] client # [ 1.203834] acpiphp: Slot [23] registered
124.13 s
[vm-test-run-centjes-e2e-test] client # [ 1.204836] acpiphp: Slot [24] registered
124.13 s
[vm-test-run-centjes-e2e-test] client # [ 1.205836] acpiphp: Slot [25] registered
124.13 s
[vm-test-run-centjes-e2e-test] client # [ 1.206852] acpiphp: Slot [26] registered
124.13 s
[vm-test-run-centjes-e2e-test] client # [ 1.207835] acpiphp: Slot [27] registered
124.13 s
[vm-test-run-centjes-e2e-test] client # [ 1.208837] acpiphp: Slot [28] registered
124.14 s
[vm-test-run-centjes-e2e-test] client # [ 1.209835] acpiphp: Slot [29] registered
124.14 s
[vm-test-run-centjes-e2e-test] client # [ 1.210835] acpiphp: Slot [30] registered
124.14 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.176176] x86/mm: Checked W+X mappings: passed, no W+X pages found.
124.14 s
[vm-test-run-centjes-e2e-test] client # [ 1.211837] acpiphp: Slot [31] registered
124.14 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.179117] Run /init as init process
124.14 s
[vm-test-run-centjes-e2e-test] client # [ 1.212824] PCI host bridge to bus 0000:00
124.15 s
[vm-test-run-centjes-e2e-test] client # [ 1.213805] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]
124.15 s
[vm-test-run-centjes-e2e-test] client # [ 1.214801] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]
124.15 s
[vm-test-run-centjes-e2e-test] client # [ 1.215804] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
124.15 s
[vm-test-run-centjes-e2e-test] client # [ 1.216817] pci_bus 0000:00: root bus resource [mem 0x40000000-0xfebfffff window]
124.16 s
[vm-test-run-centjes-e2e-test] client # [ 1.218800] pci_bus 0000:00: root bus resource [mem 0x100000000-0x17fffffff window]
124.16 s
[vm-test-run-centjes-e2e-test] client # [ 1.220799] pci_bus 0000:00: root bus resource [bus 00-ff]
124.16 s
[vm-test-run-centjes-e2e-test] client # [ 1.222240] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 conventional PCI endpoint
124.17 s
[vm-test-run-centjes-e2e-test] client # [ 1.224921] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 conventional PCI endpoint
124.17 s
[vm-test-run-centjes-e2e-test] client # [ 1.228442] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 conventional PCI endpoint
124.18 s
[vm-test-run-centjes-e2e-test] client # [ 1.233209] pci 0000:00:01.1: BAR 4 [io 0xc1e0-0xc1ef]
124.19 s
[vm-test-run-centjes-e2e-test] client # [ 1.236272] pci 0000:00:01.1: BAR 0 [io 0x01f0-0x01f7]: legacy IDE quirk
124.19 s
[vm-test-run-centjes-e2e-test] client # [ 1.237798] pci 0000:00:01.1: BAR 1 [io 0x03f6]: legacy IDE quirk
124.19 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.226242] device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@lists.linux.dev
124.19 s
[vm-test-run-centjes-e2e-test] client # [ 1.238799] pci 0000:00:01.1: BAR 2 [io 0x0170-0x0177]: legacy IDE quirk
124.19 s
[vm-test-run-centjes-e2e-test] client # [ 1.239798] pci 0000:00:01.1: BAR 3 [io 0x0376]: legacy IDE quirk
124.20 s
[vm-test-run-centjes-e2e-test] client # [ 1.241143] pci 0000:00:01.2: [8086:7020] type 00 class 0x0c0300 conventional PCI endpoint
124.20 s
[vm-test-run-centjes-e2e-test] client # [ 1.245607] pci 0000:00:01.2: BAR 4 [io 0xc100-0xc11f]
124.21 s
[vm-test-run-centjes-e2e-test] client # [ 1.249736] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 conventional PCI endpoint
124.21 s
[vm-test-run-centjes-e2e-test] client # [ 1.251978] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI
124.22 s
[vm-test-run-centjes-e2e-test] client # [ 1.253819] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB
124.22 s
[vm-test-run-centjes-e2e-test] client # [ 1.255332] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000 conventional PCI endpoint
124.23 s
[vm-test-run-centjes-e2e-test] client # [ 1.258375] pci 0000:00:02.0: BAR 0 [mem 0xfd000000-0xfdffffff pref]
124.23 s
[vm-test-run-centjes-e2e-test] client # [ 1.262455] pci 0000:00:02.0: BAR 2 [mem 0xfebd0000-0xfebd0fff]
124.24 s
[vm-test-run-centjes-e2e-test] client # [ 1.268773] pci 0000:00:02.0: ROM [mem 0xfebc0000-0xfebcffff pref]
124.25 s
[vm-test-run-centjes-e2e-test] client # [ 1.269943] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
124.25 s
[vm-test-run-centjes-e2e-test] client # [ 1.272554] pci 0000:00:03.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
124.25 s
[vm-test-run-centjes-e2e-test] client # [ 1.274798] pci 0000:00:03.0: BAR 0 [io 0xc120-0xc13f]
124.26 s
[vm-test-run-centjes-e2e-test] client # [ 1.276798] pci 0000:00:03.0: BAR 1 [mem 0xfebd1000-0xfebd1fff]
124.26 s
[vm-test-run-centjes-e2e-test] client # [ 1.281271] pci 0000:00:03.0: BAR 4 [mem 0xfe000000-0xfe003fff 64bit pref]
124.27 s
[vm-test-run-centjes-e2e-test] client # [ 1.283699] pci 0000:00:03.0: ROM [mem 0xfeb40000-0xfeb7ffff pref]
124.27 s
[vm-test-run-centjes-e2e-test] client # [ 1.287624] pci 0000:00:04.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
124.28 s
[vm-test-run-centjes-e2e-test] client # [ 1.289798] pci 0000:00:04.0: BAR 0 [io 0xc140-0xc15f]
124.28 s
[vm-test-run-centjes-e2e-test] client # [ 1.291798] pci 0000:00:04.0: BAR 1 [mem 0xfebd2000-0xfebd2fff]
124.29 s
[vm-test-run-centjes-e2e-test] client # [ 1.297739] pci 0000:00:04.0: BAR 4 [mem 0xfe004000-0xfe007fff 64bit pref]
124.30 s
[vm-test-run-centjes-e2e-test] client # [ 1.302693] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
124.30 s
[vm-test-run-centjes-e2e-test] client # [ 1.304803] pci 0000:00:05.0: BAR 0 [io 0xc080-0xc0bf]
124.31 s
[vm-test-run-centjes-e2e-test] client # [ 1.306631] pci 0000:00:05.0: BAR 1 [mem 0xfebd3000-0xfebd3fff]
124.31 s
[vm-test-run-centjes-e2e-test] client # [ 1.310798] pci 0000:00:05.0: BAR 4 [mem 0xfe008000-0xfe00bfff 64bit pref]
124.32 s
[vm-test-run-centjes-e2e-test] client # [ 1.315102] pci 0000:00:06.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
124.32 s
[vm-test-run-centjes-e2e-test] client # [ 1.317797] pci 0000:00:06.0: BAR 0 [io 0xc160-0xc17f]
124.33 s
[vm-test-run-centjes-e2e-test] client # [ 1.319631] pci 0000:00:06.0: BAR 1 [mem 0xfebd4000-0xfebd4fff]
124.33 s
[vm-test-run-centjes-e2e-test] client # [ 1.323547] pci 0000:00:06.0: BAR 4 [mem 0xfe00c000-0xfe00ffff 64bit pref]
124.34 s
[vm-test-run-centjes-e2e-test] client # [ 1.328128] pci 0000:00:07.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
124.34 s
[vm-test-run-centjes-e2e-test] client # [ 1.330797] pci 0000:00:07.0: BAR 0 [io 0xc180-0xc19f]
124.35 s
[vm-test-run-centjes-e2e-test] client # [ 1.332654] pci 0000:00:07.0: BAR 1 [mem 0xfebd5000-0xfebd5fff]
124.35 s
[vm-test-run-centjes-e2e-test] client # [ 1.336304] pci 0000:00:07.0: BAR 4 [mem 0xfe010000-0xfe013fff 64bit pref]
124.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.399082] ACPI: \_SB_.LNKC: Enabled at IRQ 10
124.36 s
[vm-test-run-centjes-e2e-test] client # [ 1.342315] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint
124.37 s
[vm-test-run-centjes-e2e-test] client # [ 1.344798] pci 0000:00:08.0: BAR 0 [io 0xc000-0xc07f]
124.37 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.405677] uhci_hcd 0000:00:01.2: UHCI Host Controller
124.37 s
[vm-test-run-centjes-e2e-test] client # [ 1.347252] pci 0000:00:08.0: BAR 1 [mem 0xfebd6000-0xfebd6fff]
124.37 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.408961] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
124.38 s
[vm-test-run-centjes-e2e-test] client # [ 1.351367] pci 0000:00:08.0: BAR 4 [mem 0xfe014000-0xfe017fff 64bit pref]
124.38 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.417302] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
124.38 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.423104] SCSI subsystem initialized
124.39 s
[vm-test-run-centjes-e2e-test] client # [ 1.356423] pci 0000:00:09.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
124.39 s
[vm-test-run-centjes-e2e-test] client # [ 1.358798] pci 0000:00:09.0: BAR 0 [io 0xc1a0-0xc1bf]
124.39 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.429061] serio: i8042 KBD port at 0x60,0x64 irq 1
124.39 s
[vm-test-run-centjes-e2e-test] client # [ 1.361676] pci 0000:00:09.0: BAR 1 [mem 0xfebd7000-0xfebd7fff]
124.40 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.434918] uhci_hcd 0000:00:01.2: detected 2 ports
124.40 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.441148] ACPI: \_SB_.LNKA: Enabled at IRQ 10
124.41 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.443430] serio: i8042 AUX port at 0x60,0x64 irq 12
124.41 s
[vm-test-run-centjes-e2e-test] client # [ 1.365347] pci 0000:00:09.0: BAR 4 [mem 0xfe018000-0xfe01bfff 64bit pref]
124.41 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.448028] uhci_hcd 0000:00:01.2: irq 11, io port 0x0000c100
124.41 s
[vm-test-run-centjes-e2e-test] client # [ 1.367801] pci 0000:00:09.0: ROM [mem 0xfeb80000-0xfebbffff pref]
124.42 s
[vm-test-run-centjes-e2e-test] client # [ 1.371298] pci 0000:00:0a.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint
124.42 s
[vm-test-run-centjes-e2e-test] client # [ 1.374135] pci 0000:00:0a.0: BAR 1 [mem 0xfebd8000-0xfebd8fff]
124.43 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.463286] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 6.12
124.43 s
[vm-test-run-centjes-e2e-test] client # [ 1.377798] pci 0000:00:0a.0: BAR 4 [mem 0xfe01c000-0xfe01ffff 64bit pref]
124.43 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.467070] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
124.43 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.470403] usb usb1: Product: UHCI Host Controller
124.44 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.472910] usb usb1: Manufacturer: Linux 6.12.62 uhci_hcd
124.44 s
[vm-test-run-centjes-e2e-test] client # [ 1.382279] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint
124.44 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.475463] usb usb1: SerialNumber: 0000:00:01.2
124.44 s
[vm-test-run-centjes-e2e-test] client # [ 1.384797] pci 0000:00:0b.0: BAR 0 [io 0xc0c0-0xc0ff]
124.44 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.480810] ACPI: \_SB_.LNKB: Enabled at IRQ 11
124.44 s
[vm-test-run-centjes-e2e-test] client # [ 1.386643] pci 0000:00:0b.0: BAR 1 [mem 0xfebd9000-0xfebd9fff]
124.45 s
[vm-test-run-centjes-e2e-test] client # [ 1.390283] pci 0000:00:0b.0: BAR 4 [mem 0xfe020000-0xfe023fff 64bit pref]
124.45 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.492619] scsi host0: ata_piix
124.46 s
[vm-test-run-centjes-e2e-test] client # [ 1.396142] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
124.46 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.498899] scsi host1: ata_piix
124.46 s
[vm-test-run-centjes-e2e-test] client # [ 1.398797] pci 0000:00:0c.0: BAR 0 [io 0xc1c0-0xc1df]
124.47 s
[vm-test-run-centjes-e2e-test] client # [ 1.400626] pci 0000:00:0c.0: BAR 1 [mem 0xfebda000-0xfebdafff]
124.47 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.507413] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc1e0 irq 14 lpm-pol 0
124.47 s
[vm-test-run-centjes-e2e-test] client # [ 1.404232] pci 0000:00:0c.0: BAR 4 [mem 0xfe024000-0xfe027fff 64bit pref]
124.47 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.511197] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc1e8 irq 15 lpm-pol 0
124.48 s
[vm-test-run-centjes-e2e-test] client # [ 1.410218] ACPI: PCI: Interrupt link LNKA configured for IRQ 10
124.48 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.520226] hub 1-0:1.0: USB hub found
124.48 s
[vm-test-run-centjes-e2e-test] client # [ 1.412004] ACPI: PCI: Interrupt link LNKB configured for IRQ 10
124.49 s
[vm-test-run-centjes-e2e-test] client # [ 1.413998] ACPI: PCI: Interrupt link LNKC configured for IRQ 11
124.49 s
[vm-test-run-centjes-e2e-test] client # [ 1.415998] ACPI: PCI: Interrupt link LNKD configured for IRQ 11
124.49 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.528450] hub 1-0:1.0: 2 ports detected
124.49 s
[vm-test-run-centjes-e2e-test] client # [ 1.417903] ACPI: PCI: Interrupt link LNKS configured for IRQ 9
124.49 s
[vm-test-run-centjes-e2e-test] client # [ 1.420200] iommu: Default domain type: Translated
124.50 s
[vm-test-run-centjes-e2e-test] client # [ 1.421799] iommu: DMA domain TLB invalidation policy: lazy mode
124.50 s
[vm-test-run-centjes-e2e-test] client # [ 1.422826] ACPI: bus type USB registered
124.50 s
[vm-test-run-centjes-e2e-test] client # [ 1.423820] usbcore: registered new interface driver usbfs
124.50 s
[vm-test-run-centjes-e2e-test] client # [ 1.424814] usbcore: registered new interface driver hub
124.51 s
[vm-test-run-centjes-e2e-test] client # [ 1.425810] usbcore: registered new device driver usb
124.51 s
[vm-test-run-centjes-e2e-test] client # [ 1.427121] NetLabel: Initializing
124.51 s
[vm-test-run-centjes-e2e-test] client # [ 1.427798] NetLabel: domain hash size = 128
124.51 s
[vm-test-run-centjes-e2e-test] client # [ 1.428798] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO
124.52 s
[vm-test-run-centjes-e2e-test] client # [ 1.429821] NetLabel: unlabeled traffic allowed by default
124.52 s
[vm-test-run-centjes-e2e-test] client # [ 1.430799] PCI: Using ACPI for IRQ routing
124.52 s
[vm-test-run-centjes-e2e-test] client # [ 1.432613] pci 0000:00:02.0: vgaarb: setting as boot VGA device
124.52 s
[vm-test-run-centjes-e2e-test] client # [ 1.432790] pci 0000:00:02.0: vgaarb: bridge control possible
124.53 s
[vm-test-run-centjes-e2e-test] client # [ 1.432790] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
124.53 s
[vm-test-run-centjes-e2e-test] client # [ 1.432801] vgaarb: loaded
124.53 s
[vm-test-run-centjes-e2e-test] client # [ 1.433879] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
124.54 s
[vm-test-run-centjes-e2e-test] client # [ 1.434799] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
124.54 s
[vm-test-run-centjes-e2e-test] client # [ 1.438826] clocksource: Switched to clocksource kvm-clock
124.54 s
[vm-test-run-centjes-e2e-test] client # [ 1.442129] VFS: Disk quotas dquot_6.6.0
124.55 s
[vm-test-run-centjes-e2e-test] client # [ 1.444072] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
124.55 s
[vm-test-run-centjes-e2e-test] client # [ 1.447689] pnp: PnP ACPI init
124.55 s
[vm-test-run-centjes-e2e-test] client # [ 1.449925] pnp: PnP ACPI: found 6 devices
124.56 s
[vm-test-run-centjes-e2e-test] client # [ 1.458220] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
124.56 s
[vm-test-run-centjes-e2e-test] client # [ 1.461982] clocksource: Switched to clocksource acpi_pm
124.57 s
[vm-test-run-centjes-e2e-test] client # [ 1.464587] NET: Registered PF_INET protocol family
124.57 s
[vm-test-run-centjes-e2e-test] client # [ 1.466851] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
124.58 s
[vm-test-run-centjes-e2e-test] client # [ 1.479430] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)
124.59 s
[vm-test-run-centjes-e2e-test] client # [ 1.483050] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
124.59 s
[vm-test-run-centjes-e2e-test] client # [ 1.486487] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)
124.59 s
[vm-test-run-centjes-e2e-test] client # [ 1.489999] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)
124.60 s
[vm-test-run-centjes-e2e-test] client # [ 1.493287] TCP: Hash tables configured (established 8192 bind 8192)
124.60 s
[vm-test-run-centjes-e2e-test] client # [ 1.496145] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)
124.60 s
[vm-test-run-centjes-e2e-test] client # [ 1.499555] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
124.61 s
[vm-test-run-centjes-e2e-test] client # [ 1.502382] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
124.61 s
[vm-test-run-centjes-e2e-test] client # [ 1.505555] NET: Registered PF_UNIX/PF_LOCAL protocol family
124.61 s
[vm-test-run-centjes-e2e-test] client # [ 1.508108] NET: Registered PF_XDP protocol family
124.61 s
[vm-test-run-centjes-e2e-test] client # [ 1.510536] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]
124.62 s
[vm-test-run-centjes-e2e-test] client # [ 1.513565] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]
124.62 s
[vm-test-run-centjes-e2e-test] client # [ 1.516301] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
124.62 s
[vm-test-run-centjes-e2e-test] client # [ 1.519328] pci_bus 0000:00: resource 7 [mem 0x40000000-0xfebfffff window]
124.63 s
[vm-test-run-centjes-e2e-test] client # [ 1.522397] pci_bus 0000:00: resource 8 [mem 0x100000000-0x17fffffff window]
124.63 s
[vm-test-run-centjes-e2e-test] client # [ 1.525589] pci 0000:00:01.0: PIIX3: Enabling Passive Release
124.63 s
[vm-test-run-centjes-e2e-test] client # [ 1.528204] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
124.63 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.669619] ata2: found unknown device (class 0)
124.63 s
[vm-test-run-centjes-e2e-test] client # [ 1.532324] ACPI: \_SB_.LNKD: Enabled at IRQ 11
124.64 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.673033] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100
124.64 s
[vm-test-run-centjes-e2e-test] client # [ 1.536566] PCI: CLS 0 bytes, default 64
124.64 s
[vm-test-run-centjes-e2e-test] client # [ 1.538850] Trying to unpack rootfs image as initramfs...
124.64 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.678347] scsi 1:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5
124.65 s
[vm-test-run-centjes-e2e-test] client # [ 1.544611] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x31024cfe468, max_idle_ns: 440795307017 ns
124.68 s
[vm-test-run-centjes-e2e-test] client # [ 1.573945] Initialise system trusted keyrings
124.68 s
[vm-test-run-centjes-e2e-test] client # [ 1.579706] workingset: timestamp_bits=40 max_order=18 bucket_order=0
124.71 s
[vm-test-run-centjes-e2e-test] client # [ 1.604591] Key type asymmetric registered
124.71 s
[vm-test-run-centjes-e2e-test] client # [ 1.609682] Asymmetric key parser 'x509' registered
124.72 s
[vm-test-run-centjes-e2e-test] client # [ 1.615584] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
124.72 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.756812] usb 1-1: new full-speed USB device number 2 using uhci_hcd
124.73 s
[vm-test-run-centjes-e2e-test] client # [ 1.623600] io scheduler mq-deadline registered
124.73 s
[vm-test-run-centjes-e2e-test] client # [ 1.625664] io scheduler kyber registered
124.73 s
[vm-test-run-centjes-e2e-test] client # [ 1.631297] Freeing initrd memory: 12300K
124.74 s
[vm-test-run-centjes-e2e-test] client # [ 1.633691] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
124.74 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.775959] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
124.74 s
[vm-test-run-centjes-e2e-test] client # [ 1.636941] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
124.74 s
[vm-test-run-centjes-e2e-test] client # [ 1.641393] Linux agpgart interface v0.103
124.75 s
[vm-test-run-centjes-e2e-test] client # [ 1.643379] ACPI: bus type drm_connector registered
124.75 s
[vm-test-run-centjes-e2e-test] client # [ 1.645958] usbcore: registered new interface driver usbserial_generic
124.75 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.788516] virtio_blk virtio5: 1/0/0 default/read/poll queues
124.75 s
[vm-test-run-centjes-e2e-test] client # [ 1.649107] usbserial: USB Serial support registered for generic
124.76 s
[vm-test-run-centjes-e2e-test] client # [ 1.651820] amd_pstate: the _CPC object is not present in SBIOS or ACPI disabled
124.76 s
[vm-test-run-centjes-e2e-test] client # [ 1.655279] drop_monitor: Initializing network drop monitor service
124.76 s
[vm-test-run-centjes-e2e-test] client # [ 1.658201] NET: Registered PF_INET6 protocol family
124.76 s
[vm-test-run-centjes-e2e-test] client # [ 1.661109] Segment Routing with IPv6
124.76 s
[vm-test-run-centjes-e2e-test] client # [ 1.662955] In-situ OAM (IOAM) with IPv6
124.77 s
[vm-test-run-centjes-e2e-test] client # [ 1.665273] IPI shorthand broadcast: enabled
124.77 s
[vm-test-run-centjes-e2e-test] client # [ 1.669690] registered taskstats version 1
124.77 s
[vm-test-run-centjes-e2e-test] client # [ 1.671887] Loading compiled-in X.509 certificates
124.78 s
[vm-test-run-centjes-e2e-test] client # [ 1.679003] Demotion targets for Node 0: null
124.78 s
[vm-test-run-centjes-e2e-test] client # [ 1.681184] Key type .fscrypt registered
124.78 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.820791] virtio_blk virtio5: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)
124.79 s
[vm-test-run-centjes-e2e-test] client # [ 1.683189] Key type fscrypt-provisioning registered
124.79 s
[vm-test-run-centjes-e2e-test] client # [ 1.685765] PM: Magic number: 6:567:699
124.79 s
[vm-test-run-centjes-e2e-test] client # [ 1.688333] RAS: Correctable Errors collector initialized.
124.80 s
[vm-test-run-centjes-e2e-test] client # [ 1.694089] Unstable clock detected, switching default tracing clock to "global"
124.80 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.838358] netfs: FS-Cache loaded
124.80 s
[vm-test-run-centjes-e2e-test] client # [ 1.694089] If you want to keep using the local clock, then add:
124.80 s
[vm-test-run-centjes-e2e-test] client # [ 1.694089] "trace_clock=local"
124.80 s
[vm-test-run-centjes-e2e-test] client # [ 1.694089] on the kernel command line
124.81 s
[vm-test-run-centjes-e2e-test] client # [ 1.703104] clk: Disabling unused clocks
124.81 s
[vm-test-run-centjes-e2e-test] client # [ 1.705319] PM: genpd: Disabling unused power domains
124.81 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.844441] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray
124.81 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.848203] cdrom: Uniform CD-ROM driver Revision: 3.20
124.81 s
[vm-test-run-centjes-e2e-test] client # [ 1.708764] Freeing unused decrypted memory: 2028K
124.81 s
[vm-test-run-centjes-e2e-test] client # [ 1.711549] Freeing unused kernel image (initmem) memory: 3408K
124.82 s
[vm-test-run-centjes-e2e-test] client # [ 1.714280] Write protecting the kernel read-only data: 30720k
124.82 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.858145] 9pnet: Installing 9P2000 support
124.82 s
[vm-test-run-centjes-e2e-test] client # [ 1.717361] Freeing unused kernel image (rodata/data gap) memory: 1756K
124.86 s
[vm-test-run-centjes-e2e-test] client # [ 1.761246] x86/mm: Checked W+X mappings: passed, no W+X pages found.
124.87 s
[vm-test-run-centjes-e2e-test] client # [ 1.764267] Run /init as init process
124.90 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.932595] usb 1-1: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00
124.90 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.936342] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=10
124.90 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.939577] usb 1-1: Product: QEMU USB Tablet
124.90 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.941658] usb 1-1: Manufacturer: QEMU
124.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.943539] usb 1-1: SerialNumber: 28754-0000:00:01.2-1
124.91 s
[vm-test-run-centjes-e2e-test] client # [ 1.808183] device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@lists.linux.dev
124.93 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.962220] hid: raw HID events driver (C) Jiri Kosina
124.94 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.981173] usbcore: registered new interface driver usbhid
124.95 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.983994] usbhid: USB HID core driver
124.95 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.988531] input: QEMU QEMU USB Tablet as /devices/pci0000:00/0000:00:01.2/usb1/1-1/1-1:1.0/0003:0627:0001.0001/input/input2
124.96 s
[vm-test-run-centjes-e2e-test] docsserver # [ 1.995023] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:01.2-1/input0
125.09 s
[vm-test-run-centjes-e2e-test] client # [ 1.985150] ACPI: \_SB_.LNKC: Enabled at IRQ 10
125.09 s
[vm-test-run-centjes-e2e-test] client # [ 1.988214] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
125.09 s
[vm-test-run-centjes-e2e-test] client # [ 1.992588] uhci_hcd 0000:00:01.2: UHCI Host Controller
125.10 s
[vm-test-run-centjes-e2e-test] client # [ 1.999655] SCSI subsystem initialized
125.11 s
[vm-test-run-centjes-e2e-test] client # [ 2.004541] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
125.11 s
[vm-test-run-centjes-e2e-test] client # [ 2.009856] serio: i8042 KBD port at 0x60,0x64 irq 1
125.12 s
[vm-test-run-centjes-e2e-test] client # [ 2.017535] serio: i8042 AUX port at 0x60,0x64 irq 12
125.13 s
[vm-test-run-centjes-e2e-test] client # [ 2.023557] uhci_hcd 0000:00:01.2: detected 2 ports
125.13 s
[vm-test-run-centjes-e2e-test] docsserver # [ 2.163014] EXT4-fs (vda): mounted filesystem 30ec696d-0ac4-40d1-ae34-d8585a77d8c1 r/w with ordered data mode. Quota mode: none.
125.13 s
[vm-test-run-centjes-e2e-test] client # [ 2.031133] ACPI: \_SB_.LNKA: Enabled at IRQ 10
125.14 s
[vm-test-run-centjes-e2e-test] client # [ 2.038132] uhci_hcd 0000:00:01.2: irq 11, io port 0x0000c100
125.15 s
[vm-test-run-centjes-e2e-test] docsserver # [ 2.190887] 9p: Installing v9fs 9p2000 file system support
125.16 s
[vm-test-run-centjes-e2e-test] client # [ 2.052716] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 6.12
125.16 s
[vm-test-run-centjes-e2e-test] client # [ 2.056499] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
125.16 s
[vm-test-run-centjes-e2e-test] client # [ 2.060063] usb usb1: Product: UHCI Host Controller
125.17 s
[vm-test-run-centjes-e2e-test] client # [ 2.062654] usb usb1: Manufacturer: Linux 6.12.62 uhci_hcd
125.17 s
[vm-test-run-centjes-e2e-test] client # [ 2.065293] usb usb1: SerialNumber: 0000:00:01.2
125.17 s
[vm-test-run-centjes-e2e-test] client # [ 2.071709] ACPI: \_SB_.LNKB: Enabled at IRQ 11
125.18 s
[vm-test-run-centjes-e2e-test] client # [ 2.083003] scsi host0: ata_piix
125.19 s
[vm-test-run-centjes-e2e-test] client # [ 2.090302] scsi host1: ata_piix
125.20 s
[vm-test-run-centjes-e2e-test] client # [ 2.096870] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc1e0 irq 14 lpm-pol 0
125.21 s
[vm-test-run-centjes-e2e-test] client # [ 2.100430] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc1e8 irq 15 lpm-pol 0
125.21 s
[vm-test-run-centjes-e2e-test] client # [ 2.111940] hub 1-0:1.0: USB hub found
125.22 s
[vm-test-run-centjes-e2e-test] client # [ 2.117540] hub 1-0:1.0: 2 ports detected
125.37 s
[vm-test-run-centjes-e2e-test] client # [ 2.265613] ata2: found unknown device (class 0)
125.37 s
[vm-test-run-centjes-e2e-test] client # [ 2.268873] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100
125.38 s
[vm-test-run-centjes-e2e-test] client # [ 2.273893] scsi 1:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5
125.41 s
[vm-test-run-centjes-e2e-test] docsserver # [ 2.442855] EXT4-fs (vda): re-mounted 30ec696d-0ac4-40d1-ae34-d8585a77d8c1.
125.41 s
[vm-test-run-centjes-e2e-test] docsserver # [ 2.447420] booting system configuration /nix/store/65s8l6c9brrb1g3yskvbz60cb4rmq4db-nixos-system-docsserver-test
125.45 s
[vm-test-run-centjes-e2e-test] client # [ 2.344550] usb 1-1: new full-speed USB device number 2 using uhci_hcd
125.46 s
[vm-test-run-centjes-e2e-test] client # [ 2.359992] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
125.49 s
[vm-test-run-centjes-e2e-test] client # [ 2.386422] virtio_blk virtio5: 1/0/0 default/read/poll queues
125.52 s
[vm-test-run-centjes-e2e-test] client # [ 2.412117] virtio_blk virtio5: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)
125.52 s
[vm-test-run-centjes-e2e-test] client # [ 2.422375] netfs: FS-Cache loaded
125.54 s
[vm-test-run-centjes-e2e-test] client # [ 2.437396] 9pnet: Installing 9P2000 support
125.54 s
[vm-test-run-centjes-e2e-test] client # [ 2.441760] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray
125.55 s
[vm-test-run-centjes-e2e-test] client # [ 2.444743] cdrom: Uniform CD-ROM driver Revision: 3.20
125.62 s
[vm-test-run-centjes-e2e-test] client # [ 2.519798] usb 1-1: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00
125.63 s
[vm-test-run-centjes-e2e-test] client # [ 2.523756] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=10
125.63 s
[vm-test-run-centjes-e2e-test] client # [ 2.527757] usb 1-1: Product: QEMU USB Tablet
125.63 s
[vm-test-run-centjes-e2e-test] client # [ 2.530174] usb 1-1: Manufacturer: QEMU
125.64 s
[vm-test-run-centjes-e2e-test] client # [ 2.532267] usb 1-1: SerialNumber: 28754-0000:00:01.2-1
125.67 s
[vm-test-run-centjes-e2e-test] client # [ 2.563846] hid: raw HID events driver (C) Jiri Kosina
125.68 s
[vm-test-run-centjes-e2e-test] client # [ 2.576561] usbcore: registered new interface driver usbhid
125.68 s
[vm-test-run-centjes-e2e-test] client # [ 2.579522] usbhid: USB HID core driver
125.69 s
[vm-test-run-centjes-e2e-test] client # [ 2.589341] input: QEMU QEMU USB Tablet as /devices/pci0000:00/0000:00:01.2/usb1/1-1/1-1:1.0/0003:0627:0001.0001/input/input2
125.70 s
[vm-test-run-centjes-e2e-test] client # [ 2.594625] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:01.2-1/input0
125.84 s
[vm-test-run-centjes-e2e-test] client # [ 2.733629] EXT4-fs (vda): mounted filesystem 4f1a6b4a-0db2-43fb-b27b-7012ebb0ac47 r/w with ordered data mode. Quota mode: none.
125.86 s
[vm-test-run-centjes-e2e-test] client # [ 2.758637] 9p: Installing v9fs 9p2000 file system support
126.10 s
[vm-test-run-centjes-e2e-test] client # [ 2.996651] EXT4-fs (vda): re-mounted 4f1a6b4a-0db2-43fb-b27b-7012ebb0ac47.
126.11 s
[vm-test-run-centjes-e2e-test] client # [ 3.006141] booting system configuration /nix/store/001k9r4jinw78ih5x5hxggb82ynlbkqn-nixos-system-client-test
127.23 s
[vm-test-run-centjes-e2e-test] docsserver # [ 4.272251] systemd[1]: Inserted module 'autofs4'
127.30 s
[vm-test-run-centjes-e2e-test] docsserver # [ 4.329462] systemd[1]: systemd 258.2 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN -IPTC +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP -SYSVINIT +LIBARCHIVE)
127.31 s
[vm-test-run-centjes-e2e-test] docsserver # [ 4.342998] systemd[1]: Detected virtualization kvm.
127.31 s
[vm-test-run-centjes-e2e-test] docsserver # [ 4.345870] systemd[1]: Detected architecture x86-64.
127.31 s
[vm-test-run-centjes-e2e-test] docsserver # [ 4.348478] systemd[1]: Detected first boot.
127.32 s
[vm-test-run-centjes-e2e-test] docsserver # [ 4.358687] systemd[1]: Initializing machine ID from random generator.
127.35 s
[vm-test-run-centjes-e2e-test] docsserver # [ 4.385441] systemd[1]: Hostname set to <docsserver>.
127.46 s
[vm-test-run-centjes-e2e-test] docsserver # [ 4.496854] systemd[1]: bpf-restrict-fs: LSM BPF program attached
127.60 s
[vm-test-run-centjes-e2e-test] docsserver # [ 4.638281] systemd[1]: Applying preset policy.
127.61 s
[vm-test-run-centjes-e2e-test] client # [ 4.512244] systemd[1]: Inserted module 'autofs4'
127.67 s
[vm-test-run-centjes-e2e-test] client # [ 4.558866] systemd[1]: systemd 258.2 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN -IPTC +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP -SYSVINIT +LIBARCHIVE)
127.68 s
[vm-test-run-centjes-e2e-test] client # [ 4.572840] systemd[1]: Detected virtualization kvm.
127.68 s
[vm-test-run-centjes-e2e-test] client # [ 4.575295] systemd[1]: Detected architecture x86-64.
127.68 s
[vm-test-run-centjes-e2e-test] client # [ 4.577697] systemd[1]: Detected first boot.
127.69 s
[vm-test-run-centjes-e2e-test] client # [ 4.585141] systemd[1]: Initializing machine ID from random generator.
127.71 s
[vm-test-run-centjes-e2e-test] client # [ 4.608633] systemd[1]: Hostname set to <client>.
127.82 s
[vm-test-run-centjes-e2e-test] client # [ 4.720843] systemd[1]: bpf-restrict-fs: LSM BPF program attached
127.96 s
[vm-test-run-centjes-e2e-test] client # [ 4.857932] systemd[1]: Applying preset policy.
128.13 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.170617] systemd[1]: Populated /etc with preset unit settings.
128.47 s
[vm-test-run-centjes-e2e-test] client # [ 5.363039] systemd[1]: Populated /etc with preset unit settings.
128.54 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.577490] systemd[1]: /etc/systemd/system/centjes-docs-site-production.service:3: Invalid URL, ignoring: /nix/store/bp7ak7r85za1cwc3snhzm6cz1ypyh3wv-settings-check
128.70 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.700174] systemd[1]: Queued start job for default target Multi-User System.
128.70 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.731395] systemd[1]: Created slice Slice /system/getty.
128.70 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.734159] systemd[1]: Created slice Slice /system/modprobe.
128.70 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.737034] systemd[1]: Created slice User and Session Slice.
128.70 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.739574] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
128.70 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.742462] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
128.71 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.745339] systemd[1]: Expecting device /dev/hvc0...
128.71 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.747215] systemd[1]: Expecting device /dev/ttyS0...
128.71 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.749147] systemd[1]: Expecting device /sys/subsystem/net/devices/eth1...
128.71 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.751618] systemd[1]: Reached target Local Encrypted Volumes.
128.72 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.753836] systemd[1]: Reached target Virtual Machines and Containers.
128.72 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.756103] systemd[1]: Reached target Path Units.
128.72 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.758292] systemd[1]: Reached target Remote File Systems.
128.72 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.760372] systemd[1]: Reached target Slice Units.
128.72 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.762328] systemd[1]: Reached target Swaps.
128.73 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.767973] systemd[1]: Listening on Process Core Dump Socket.
128.74 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.774974] systemd[1]: Listening on Credential Encryption/Decryption.
128.74 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.777826] systemd[1]: Listening on Journal Audit Socket.
128.74 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.780032] systemd[1]: Listening on Journal Socket (/dev/log).
128.74 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.782410] systemd[1]: Listening on Journal Sockets.
128.75 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.784796] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.
128.75 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.787590] systemd[1]: Make TPM PCR Policy was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
128.75 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.791509] systemd[1]: Listening on udev Control Socket.
128.76 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.793897] systemd[1]: Listening on udev Kernel Socket.
128.76 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.800861] systemd[1]: Mounting Huge Pages File System...
128.77 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.806358] systemd[1]: Mounting POSIX Message Queue File System...
128.78 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.814969] systemd[1]: Mounting Kernel Debug File System...
128.79 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.827385] systemd[1]: Mounting Kernel Trace File System...
128.80 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.841576] systemd[1]: Starting Create List of Static Device Nodes...
128.81 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.848372] systemd[1]: Load Kernel Module 9pnet_virtio was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!9pnet_virtio).
128.83 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.866525] systemd[1]: Starting Load Kernel Module configfs...
128.83 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.869451] systemd[1]: Load Kernel Module drm was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!drm).
128.84 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.882828] systemd[1]: Starting Load Kernel Module efi_pstore...
128.85 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.890956] systemd[1]: Starting Load Kernel Module fuse...
128.86 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.895879] systemd[1]: File System Check on Root Device was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/).
128.87 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.901243] systemd[1]: Clear Stale Hibernate Storage Info was skipped because of an unmet condition check (ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67).
128.87 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.912950] systemd[1]: Starting Journal Service...
128.88 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.921806] systemd[1]: Starting Load Kernel Modules...
128.89 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.932465] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...
128.90 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.940890] systemd[1]: Starting Remount Root and Kernel File Systems...
128.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.946231] systemd[1]: Early TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
128.92 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.958235] systemd[1]: Starting Coldplug All udev Devices...
128.93 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.967515] systemd[1]: Mounted Huge Pages File System.
128.93 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.972004] systemd[1]: Mounted POSIX Message Queue File System.
128.94 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.977434] systemd[1]: Mounted Kernel Debug File System.
128.94 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.983475] systemd[1]: Mounted Kernel Trace File System.
128.95 s
[vm-test-run-centjes-e2e-test] docsserver # [ 5.990054] systemd[1]: Finished Create List of Static Device Nodes.
128.96 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.002569] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...
128.99 s
[vm-test-run-centjes-e2e-test] client # [ 5.883040] systemd[1]: Queued start job for default target Multi-User System.
129.01 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.044228] systemd[1]: modprobe@configfs.service: Deactivated successfully.
129.01 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.050608] systemd[1]: Finished Load Kernel Module configfs.
129.01 s
[vm-test-run-centjes-e2e-test] client # [ 5.911106] systemd[1]: Created slice Slice /system/getty.
129.02 s
[vm-test-run-centjes-e2e-test] client # [ 5.913815] systemd[1]: Created slice Slice /system/modprobe.
129.02 s
[vm-test-run-centjes-e2e-test] client # [ 5.916406] systemd[1]: Created slice User and Session Slice.
129.02 s
[vm-test-run-centjes-e2e-test] client # [ 5.919045] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
129.02 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.059645] systemd[1]: Mounting Kernel Configuration File System...
129.02 s
[vm-test-run-centjes-e2e-test] client # [ 5.921854] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
129.03 s
[vm-test-run-centjes-e2e-test] client # [ 5.924776] systemd[1]: Expecting device /dev/hvc0...
129.03 s
[vm-test-run-centjes-e2e-test] client # [ 5.926667] systemd[1]: Expecting device /dev/ttyS0...
129.03 s
[vm-test-run-centjes-e2e-test] client # [ 5.928610] systemd[1]: Expecting device /sys/subsystem/net/devices/eth1...
129.03 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.068669] systemd[1]: modprobe@efi_pstore.service: Deactivated successfully.
129.03 s
[vm-test-run-centjes-e2e-test] client # [ 5.931184] systemd[1]: Reached target Local Encrypted Volumes.
129.04 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.073468] EXT4-fs (vda): re-mounted 30ec696d-0ac4-40d1-ae34-d8585a77d8c1.
129.04 s
[vm-test-run-centjes-e2e-test] client # [ 5.933604] systemd[1]: Reached target Virtual Machines and Containers.
129.04 s
[vm-test-run-centjes-e2e-test] client # [ 5.936189] systemd[1]: Reached target Path Units.
129.04 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.076631] systemd[1]: Finished Load Kernel Module efi_pstore.
129.04 s
[vm-test-run-centjes-e2e-test] client # [ 5.938146] systemd[1]: Reached target Remote File Systems.
129.04 s
[vm-test-run-centjes-e2e-test] client # [ 5.940400] systemd[1]: Reached target Slice Units.
129.04 s
[vm-test-run-centjes-e2e-test] client # [ 5.942522] systemd[1]: Reached target Swaps.
129.05 s
[vm-test-run-centjes-e2e-test] client # [ 5.947799] systemd[1]: Listening on Process Core Dump Socket.
129.06 s
[vm-test-run-centjes-e2e-test] client # [ 5.953030] systemd[1]: Listening on Credential Encryption/Decryption.
129.06 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.093520] systemd[1]: Mounted Kernel Configuration File System.
129.06 s
[vm-test-run-centjes-e2e-test] client # [ 5.955876] systemd[1]: Listening on Journal Audit Socket.
129.06 s
[vm-test-run-centjes-e2e-test] client # [ 5.958104] systemd[1]: Listening on Journal Socket (/dev/log).
129.06 s
[vm-test-run-centjes-e2e-test] client # [ 5.960429] systemd[1]: Listening on Journal Sockets.
129.06 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.103673] loop: module loaded
129.07 s
[vm-test-run-centjes-e2e-test] client # [ 5.962823] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.
129.07 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.105421] systemd-journald[383]: Collecting audit messages is enabled.
129.07 s
[vm-test-run-centjes-e2e-test] client # [ 5.965803] systemd[1]: Make TPM PCR Policy was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
129.07 s
[vm-test-run-centjes-e2e-test] client # [ 5.969834] systemd[1]: Listening on udev Control Socket.
129.07 s
[vm-test-run-centjes-e2e-test] client # [ 5.972104] systemd[1]: Listening on udev Kernel Socket.
129.08 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.114172] systemd[1]: Finished Remount Root and Kernel File Systems.
129.08 s
[vm-test-run-centjes-e2e-test] client # [ 5.978147] systemd[1]: Mounting Huge Pages File System...
129.08 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.119063] systemd[1]: Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore).
129.09 s
[vm-test-run-centjes-e2e-test] client # [ 5.983690] systemd[1]: Mounting POSIX Message Queue File System...
129.09 s
[vm-test-run-centjes-e2e-test] client # [ 5.991781] systemd[1]: Mounting Kernel Debug File System...
129.10 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.135885] fuse: init (API version 7.41)
129.10 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.140913] systemd[1]: Starting Load/Save OS Random Seed...
129.11 s
[vm-test-run-centjes-e2e-test] client # [ 6.003830] systemd[1]: Mounting Kernel Trace File System...
129.11 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.146275] systemd[1]: TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
129.12 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.158104] systemd[1]: Finished Load Kernel Modules.
129.12 s
[vm-test-run-centjes-e2e-test] client # [ 6.021303] systemd[1]: Starting Create List of Static Device Nodes...
129.13 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.167596] systemd[1]: Starting Firewall...
129.13 s
[vm-test-run-centjes-e2e-test] client # [ 6.030127] systemd[1]: Load Kernel Module 9pnet_virtio was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!9pnet_virtio).
129.14 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.175336] systemd[1]: Starting Apply Kernel Variables...
129.14 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.179648] systemd[1]: modprobe@fuse.service: Deactivated successfully.
129.15 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.186900] systemd[1]: Finished Load Kernel Module fuse.
129.15 s
[vm-test-run-centjes-e2e-test] client # [ 6.048089] systemd[1]: Starting Load Kernel Module configfs...
129.16 s
[vm-test-run-centjes-e2e-test] client # [ 6.051894] systemd[1]: Load Kernel Module drm was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!drm).
129.16 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.197471] systemd[1]: Mounting FUSE Control File System...
129.16 s
[vm-test-run-centjes-e2e-test] client # [ 6.060573] systemd[1]: Starting Load Kernel Module efi_pstore...
129.17 s
[vm-test-run-centjes-e2e-test] client # [ 6.069081] systemd[1]: Starting Load Kernel Module fuse...
129.18 s
[vm-test-run-centjes-e2e-test] client # [ 6.072639] systemd[1]: File System Check on Root Device was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/).
129.19 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.224469] systemd[1]: Mounted FUSE Control File System.
129.19 s
[vm-test-run-centjes-e2e-test] client # [ 6.081984] systemd[1]: Clear Stale Hibernate Storage Info was skipped because of an unmet condition check (ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67).
129.20 s
[vm-test-run-centjes-e2e-test] client # [ 6.094946] systemd[1]: Starting Journal Service...
129.20 s
[vm-test-run-centjes-e2e-test] client # [ 6.102148] systemd[1]: Starting Load Kernel Modules...
129.21 s
[vm-test-run-centjes-e2e-test] client # [ 6.111171] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...
129.22 s
[vm-test-run-centjes-e2e-test] client # [ 6.121605] systemd[1]: Starting Remount Root and Kernel File Systems...
129.23 s
[vm-test-run-centjes-e2e-test] client # [ 6.126694] systemd[1]: Early TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
129.24 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.280154] systemd[1]: Finished Load/Save OS Random Seed.
129.24 s
[vm-test-run-centjes-e2e-test] client # [ 6.141922] systemd[1]: Starting Coldplug All udev Devices...
129.25 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.284276] systemd[1]: Reached target First Boot Complete.
129.25 s
[vm-test-run-centjes-e2e-test] client # [ 6.152988] systemd[1]: Mounted Huge Pages File System.
129.26 s
[vm-test-run-centjes-e2e-test] client # [ 6.157369] systemd[1]: Mounted POSIX Message Queue File System.
129.26 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.296133] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
129.26 s
[vm-test-run-centjes-e2e-test] client # [ 6.162214] systemd[1]: Mounted Kernel Debug File System.
129.27 s
[vm-test-run-centjes-e2e-test] client # [ 6.167384] systemd[1]: Mounted Kernel Trace File System.
129.27 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.307939] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.
129.28 s
[vm-test-run-centjes-e2e-test] client # [ 6.174167] systemd[1]: Finished Create List of Static Device Nodes.
129.28 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.322319] systemd[1]: Starting Create Static Device Nodes in /dev...
129.29 s
[vm-test-run-centjes-e2e-test] client # [ 6.185929] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...
129.30 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.337653] systemd[1]: Finished Apply Kernel Variables.
129.33 s
[vm-test-run-centjes-e2e-test] client # [ 6.227134] systemd[1]: modprobe@configfs.service: Deactivated successfully.
129.34 s
[vm-test-run-centjes-e2e-test] client # [ 6.233297] systemd[1]: Finished Load Kernel Module configfs.
129.34 s
[vm-test-run-centjes-e2e-test] client # [ 6.242099] systemd[1]: Mounting Kernel Configuration File System...
129.35 s
[vm-test-run-centjes-e2e-test] client # [ 6.248351] EXT4-fs (vda): re-mounted 4f1a6b4a-0db2-43fb-b27b-7012ebb0ac47.
129.37 s
[vm-test-run-centjes-e2e-test] client # [ 6.271281] systemd[1]: Mounted Kernel Configuration File System.
129.38 s
[vm-test-run-centjes-e2e-test] client # [ 6.279631] loop: module loaded
129.39 s
[vm-test-run-centjes-e2e-test] client # [ 6.284008] systemd[1]: Finished Remount Root and Kernel File Systems.
129.39 s
[vm-test-run-centjes-e2e-test] client # [ 6.290008] systemd[1]: modprobe@efi_pstore.service: Deactivated successfully.
129.40 s
[vm-test-run-centjes-e2e-test] client # [ 6.297588] systemd[1]: Finished Load Kernel Module efi_pstore.
129.40 s
[vm-test-run-centjes-e2e-test] client # [ 6.300718] systemd-journald[383]: Collecting audit messages is enabled.
129.41 s
[vm-test-run-centjes-e2e-test] client # [ 6.303732] systemd[1]: Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore).
129.42 s
[vm-test-run-centjes-e2e-test] client # [ 6.318102] systemd[1]: Starting Load/Save OS Random Seed...
129.43 s
[vm-test-run-centjes-e2e-test] client # [ 6.322184] systemd[1]: TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
129.43 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.464917] systemd[1]: Finished Create Static Device Nodes in /dev.
129.43 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.472206] systemd[1]: Reached target Preparation for Local File Systems.
129.44 s
[vm-test-run-centjes-e2e-test] client # [ 6.333629] systemd[1]: Finished Load Kernel Modules.
129.44 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.481522] systemd[1]: Starting Rule-based Manager for Device Events and Files...
129.45 s
[vm-test-run-centjes-e2e-test] client # [ 6.343802] fuse: init (API version 7.41)
129.45 s
[vm-test-run-centjes-e2e-test] client # [ 6.347191] systemd[1]: Starting Firewall...
129.46 s
[vm-test-run-centjes-e2e-test] client # [ 6.355730] systemd[1]: Starting Apply Kernel Variables...
129.47 s
[vm-test-run-centjes-e2e-test] client # [ 6.363928] systemd[1]: modprobe@fuse.service: Deactivated successfully.
129.47 s
[vm-test-run-centjes-e2e-test] client # [ 6.370534] systemd[1]: Finished Load Kernel Module fuse.
129.48 s
[vm-test-run-centjes-e2e-test] client # [ 6.379907] systemd[1]: Mounting FUSE Control File System...
129.51 s
[vm-test-run-centjes-e2e-test] client # [ 6.405722] systemd[1]: Mounted FUSE Control File System.
129.56 s
[vm-test-run-centjes-e2e-test] client # [ 6.453622] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
129.57 s
[vm-test-run-centjes-e2e-test] client # [ 6.465990] systemd[1]: Starting Create Static Device Nodes in /dev...
129.57 s
[vm-test-run-centjes-e2e-test] client # [ 6.471876] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.
129.58 s
[vm-test-run-centjes-e2e-test] client # [ 6.479414] systemd[1]: Finished Load/Save OS Random Seed.
129.59 s
[vm-test-run-centjes-e2e-test] client # [ 6.485097] systemd[1]: Reached target First Boot Complete.
129.60 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.640522] systemd[1]: Started Journal Service.
129.61 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.272648] systemd-modules-load[384]: Inserted module 'loop'
129.62 s
[vm-test-run-centjes-e2e-test] client # [ 6.513712] systemd[1]: Finished Apply Kernel Variables.
129.62 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.288406] systemd-oomd[385]: [ 0;1;38:5:185mNo swap; memory pressure usage will be degraded
129.64 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.303943] systemd-udevd[410]: Using default interface naming scheme 'v258'.
129.65 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.314333] systemd[1]: Starting Flush Journal to Persistent Storage...
129.70 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.741275] systemd-journald[383]: Received client request to flush runtime journal.
129.70 s
[vm-test-run-centjes-e2e-test] client # [ 6.602855] systemd[1]: Finished Create Static Device Nodes in /dev.
129.71 s
[vm-test-run-centjes-e2e-test] client # [ 6.607979] systemd[1]: Reached target Preparation for Local File Systems.
129.72 s
[vm-test-run-centjes-e2e-test] client # [ 6.617916] systemd[1]: Starting Rule-based Manager for Device Events and Files...
129.91 s
[vm-test-run-centjes-e2e-test] client # [ 6.812956] systemd[1]: Started Journal Service.
129.92 s
[vm-test-run-centjes-e2e-test] client # [ 6.453167] systemd-modules-load[384]: Inserted module 'loop'
129.92 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.585366] systemd[1]: Finished Coldplug All udev Devices.
129.93 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.593918] systemd[1]: Started Rule-based Manager for Device Events and Files.
129.94 s
[vm-test-run-centjes-e2e-test] client # [ 6.462695] systemd-oomd[385]: [ 0;1;38:5:185mNo swap; memory pressure usage will be degraded
129.94 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.603882] systemd[1]: Finished Flush Journal to Persistent Storage.
129.95 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.612697] systemd[1]: Mounting /run/wrappers...
129.95 s
[vm-test-run-centjes-e2e-test] client # [ 6.478247] systemd-udevd[409]: Using default interface naming scheme 'v258'.
129.96 s
[vm-test-run-centjes-e2e-test] client # [ 6.486646] systemd[1]: Starting Flush Journal to Persistent Storage...
129.98 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.646202] systemd[1]: Mounted /run/wrappers.
129.99 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.651385] systemd[1]: Reached target Local File Systems.
130.00 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.658643] systemd[1]: Listening on Boot Entries Service Socket.
130.00 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.668344] systemd[1]: Starting Create SUID/SGID Wrappers...
130.02 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.680227] systemd[1]: Update Boot Loader Random Seed was skipped because no trigger condition checks were met.
130.03 s
[vm-test-run-centjes-e2e-test] client # [ 6.923903] systemd-journald[383]: Received client request to flush runtime journal.
130.03 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.691186] systemd[1]: Starting Save Transient machine-id to Disk...
130.04 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.699531] systemd[1]: Starting Create System Files and Directories...
130.10 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.762426] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
130.11 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.775087] systemd[1]: Finished Save Transient machine-id to Disk.
130.17 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.831190] systemd[1]: Finished Create System Files and Directories.
130.18 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.842596] systemd[1]: Starting Rebuild Journal Catalog...
130.19 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.850499] systemd[1]: Starting Record System Boot/Shutdown in UTMP...
130.21 s
[vm-test-run-centjes-e2e-test] client # [ 6.740385] systemd[1]: Started Rule-based Manager for Device Events and Files.
130.22 s
[vm-test-run-centjes-e2e-test] client # [ 6.749385] systemd[1]: Finished Coldplug All udev Devices.
130.23 s
[vm-test-run-centjes-e2e-test] client # [ 6.754860] systemd[1]: Finished Flush Journal to Persistent Storage.
130.26 s
[vm-test-run-centjes-e2e-test] client # [ 6.790779] systemd[1]: Mounting /run/wrappers...
130.26 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.926792] systemd[1]: Finished Record System Boot/Shutdown in UTMP.
130.30 s
[vm-test-run-centjes-e2e-test] client # [ 6.831892] systemd[1]: Mounted /run/wrappers.
130.31 s
[vm-test-run-centjes-e2e-test] client # [ 6.836784] systemd[1]: Reached target Local File Systems.
130.32 s
[vm-test-run-centjes-e2e-test] client # [ 6.843962] systemd[1]: Listening on Boot Entries Service Socket.
130.32 s
[vm-test-run-centjes-e2e-test] client # [ 6.852419] systemd[1]: Starting Create SUID/SGID Wrappers...
130.33 s
[vm-test-run-centjes-e2e-test] docsserver # [ 6.995213] systemd[1]: Finished Rebuild Journal Catalog.
130.34 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.002390] systemd[1]: Starting Update is Completed...
130.34 s
[vm-test-run-centjes-e2e-test] client # [ 6.860365] systemd[1]: Update Boot Loader Random Seed was skipped because no trigger condition checks were met.
130.35 s
[vm-test-run-centjes-e2e-test] client # [ 6.876297] systemd[1]: Starting Save Transient machine-id to Disk...
130.36 s
[vm-test-run-centjes-e2e-test] client # [ 6.886651] systemd[1]: Starting Create System Files and Directories...
130.41 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.078400] systemd[1]: Finished Update is Completed.
130.44 s
[vm-test-run-centjes-e2e-test] client # [ 6.961224] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
130.45 s
[vm-test-run-centjes-e2e-test] client # [ 6.976281] systemd[1]: Finished Save Transient machine-id to Disk.
130.51 s
[vm-test-run-centjes-e2e-test] client # [ 7.036299] systemd[1]: Finished Create System Files and Directories.
130.52 s
[vm-test-run-centjes-e2e-test] client # [ 7.044324] systemd[1]: Starting Rebuild Journal Catalog...
130.53 s
[vm-test-run-centjes-e2e-test] client # [ 7.055418] systemd[1]: Starting Record System Boot/Shutdown in UTMP...
130.59 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.250713] systemd[1]: Found device /dev/hvc0.
130.60 s
[vm-test-run-centjes-e2e-test] client # [ 7.132649] systemd[1]: Finished Record System Boot/Shutdown in UTMP.
130.64 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.303754] systemd[1]: Found device /dev/ttyS0.
130.67 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.323703] (udev-worker)[504]: [ 0;1;38:5:185meth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.
130.68 s
[vm-test-run-centjes-e2e-test] client # [ 7.206327] systemd[1]: Finished Rebuild Journal Catalog.
130.68 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.346547] (udev-worker)[504]: Network interface NamePolicy= disabled on kernel command line.
130.69 s
[vm-test-run-centjes-e2e-test] client # [ 7.216158] systemd[1]: Starting Update is Completed...
130.70 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.359657] (udev-worker)[499]: Network interface NamePolicy= disabled on kernel command line.
130.75 s
[vm-test-run-centjes-e2e-test] client # [ 7.281212] systemd[1]: Finished Update is Completed.
130.80 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.463902] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.
130.81 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.471934] systemd[1]: Finished Create SUID/SGID Wrappers.
130.81 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.478479] systemd[1]: Reached target System Initialization.
130.82 s
[vm-test-run-centjes-e2e-test] client # [ 7.350738] systemd[1]: Found device /dev/hvc0.
130.83 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.485761] systemd[1]: Started Discard unused filesystem blocks once a week.
130.85 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.498658] systemd[1]: Started Daily Cleanup of Temporary Directories.
130.86 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.520195] systemd[1]: Reached target Timer Units.
130.88 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.534619] systemd[1]: Listening on D-Bus System Message Bus Socket.
130.89 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.549461] systemd[1]: Listening on Nix Daemon Socket.
130.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.563865] systemd[1]: Listening on Hostname Service Socket.
130.91 s
[vm-test-run-centjes-e2e-test] client # [ 7.442864] systemd[1]: Found device /dev/ttyS0.
130.92 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.589214] systemd[1]: Reached target Socket Units.
130.93 s
[vm-test-run-centjes-e2e-test] client # [ 7.458773] (udev-worker)[485]: Network interface NamePolicy= disabled on kernel command line.
130.95 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.601300] systemd[1]: Reached target Basic System.
130.96 s
[vm-test-run-centjes-e2e-test] client # [ 7.480898] (udev-worker)[483]: [ 0;1;38:5:185meth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.
130.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.627350] systemd[1]: System is tainted: support-ended
130.97 s
[vm-test-run-centjes-e2e-test] client # [ 7.496734] (udev-worker)[483]: Network interface NamePolicy= disabled on kernel command line.
130.98 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.646401] systemd[1]: Started backdoor.service.
131.00 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.660251] systemd[1]: Starting Import lastlog data into lastlog2 database...
131.02 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.676797] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
131.04 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.690871] systemd[1]: Started Reset console on configuration changes.
131.05 s
[vm-test-run-centjes-e2e-test] docsserver # connecting to host...
131.05 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.712855] systemd[1]: Starting resolvconf update...
131.07 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.727203] systemd[1]: Started Centjes docs site production Service.
131.08 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.736791] systemd[1]: Starting D-Bus System Message Bus...
131.09 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.752890] systemd[1]: Finished Firewall.
131.10 s
[vm-test-run-centjes-e2e-test] client # [ 7.634226] systemd[1]: Finished Firewall.
131.11 s
[vm-test-run-centjes-e2e-test] docsserver: Guest shell says: b'Spawning backdoor root shell...\n'
131.12 s
[vm-test-run-centjes-e2e-test] docsserver: connected to guest root shell
131.12 s
[vm-test-run-centjes-e2e-test] docsserver: (connecting took 8.83 seconds)
131.12 s
[vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for the VM to finish booting, in 8.83 seconds)
131.13 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.763991] nsncd[617]: Aug 04 20:41:48.544 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
131.14 s
[vm-test-run-centjes-e2e-test] client # [ 7.664756] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.
131.14 s
[vm-test-run-centjes-e2e-test] client # [ 7.674302] systemd[1]: Finished Create SUID/SGID Wrappers.
131.14 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.801093] systemd[1]: Finished Import lastlog data into lastlog2 database.
131.15 s
[vm-test-run-centjes-e2e-test] client # [ 7.680119] systemd[1]: Reached target System Initialization.
131.16 s
[vm-test-run-centjes-e2e-test] client # [ 7.684663] systemd[1]: Started Discard unused filesystem blocks once a week.
131.16 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.813877] dbus-daemon[622]: dbus[622]: Unknown username "systemd-timesync" in message bus configuration file
131.18 s
[vm-test-run-centjes-e2e-test] client # [ 7.696811] systemd[1]: Started Daily Cleanup of Temporary Directories.
131.18 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.836311] systemd[1]: Started Name Service Cache Daemon (nsncd).
131.19 s
[vm-test-run-centjes-e2e-test] client # [ 7.714276] systemd[1]: Reached target Timer Units.
131.19 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.847715] systemd[1]: Reached target Host and Network Name Lookups.
131.20 s
[vm-test-run-centjes-e2e-test] client # [ 7.723138] systemd[1]: Listening on D-Bus System Message Bus Socket.
131.20 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.863663] systemd[1]: Reached target User and Group Name Lookups.
131.21 s
[vm-test-run-centjes-e2e-test] client # [ 7.732362] systemd[1]: Listening on Nix Daemon Socket.
131.21 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.875374] systemd[1]: Starting User Login Management...
131.22 s
[vm-test-run-centjes-e2e-test] client # [ 7.747325] systemd[1]: Listening on Hostname Service Socket.
131.23 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.882664] systemd[1]: Found device Virtio network device.
131.23 s
[vm-test-run-centjes-e2e-test] client # [ 7.757680] systemd[1]: Reached target Socket Units.
131.24 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.898917] systemd[1]: Started D-Bus System Message Bus.
131.25 s
[vm-test-run-centjes-e2e-test] client # [ 7.770911] systemd[1]: Reached target Basic System.
131.26 s
[vm-test-run-centjes-e2e-test] client # [ 7.788210] systemd[1]: System is tainted: support-ended
131.27 s
[vm-test-run-centjes-e2e-test] client # [ 7.799816] systemd[1]: Started backdoor.service.
131.29 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.948232] systemd[1]: Stopped target Host and Network Name Lookups.
131.29 s
[vm-test-run-centjes-e2e-test] client # [ 7.815352] systemd[1]: Starting Import lastlog data into lastlog2 database...
131.30 s
[vm-test-run-centjes-e2e-test] client # [ 7.826457] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
131.30 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.962169] systemd[1]: Stopping Host and Network Name Lookups...
131.30 s
[vm-test-run-centjes-e2e-test] client # connecting to host...
131.31 s
[vm-test-run-centjes-e2e-test] client # [ 7.841105] systemd[1]: Started Reset console on configuration changes.
131.31 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.971899] systemd[1]: Stopped target User and Group Name Lookups.
131.33 s
[vm-test-run-centjes-e2e-test] client # [ 7.853866] systemd[1]: Starting resolvconf update...
131.33 s
[vm-test-run-centjes-e2e-test] docsserver # [ 7.989820] systemd[1]: Stopping User and Group Name Lookups...
131.33 s
[vm-test-run-centjes-e2e-test] client # [ 7.863197] systemd[1]: Found device Virtio network device.
131.34 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.001717] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...
131.34 s
[vm-test-run-centjes-e2e-test] client # [ 7.871771] systemd[1]: Starting D-Bus System Message Bus...
131.35 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.009542] systemd[1]: nscd.service: Deactivated successfully.
131.36 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.021859] systemd[1]: Stopped Name Service Cache Daemon (nsncd).
131.37 s
[vm-test-run-centjes-e2e-test] client # [ 7.884631] nsncd[621]: Aug 04 20:41:48.834 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
131.38 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.035456] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
131.38 s
[vm-test-run-centjes-e2e-test] client # [ 7.903476] systemd[1]: Finished Import lastlog data into lastlog2 database.
131.39 s
[vm-test-run-centjes-e2e-test] client # [ 7.913488] systemd[1]: Started Name Service Cache Daemon (nsncd).
131.40 s
[vm-test-run-centjes-e2e-test] client # [ 7.920674] systemd[1]: Reached target Host and Network Name Lookups.
131.40 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.055722] systemd-logind[644]: New seat seat0.
131.41 s
[vm-test-run-centjes-e2e-test] client # [ 7.933388] dbus-daemon[624]: dbus[624]: Unknown username "systemd-timesync" in message bus configuration file
131.41 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.066777] systemd[1]: Started User Login Management.
131.42 s
[vm-test-run-centjes-e2e-test] client # [ 7.944887] systemd[1]: Reached target User and Group Name Lookups.
131.42 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.079932] systemd[1]: Starting linger-users.service...
131.43 s
[vm-test-run-centjes-e2e-test] client # [ 7.958346] systemd[1]: Starting User Login Management...
131.45 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.112780] systemd[1]: Started Name Service Cache Daemon (nsncd).
131.46 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.123295] systemd[1]: Reached target Host and Network Name Lookups.
131.47 s
[vm-test-run-centjes-e2e-test] client # [ 7.994678] systemd[1]: Started D-Bus System Message Bus.
131.48 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.131873] nsncd[695]: Aug 04 20:41:48.919 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
131.49 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.149857] systemd[1]: Reached target User and Group Name Lookups.
131.50 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.160800] systemd[1]: linger-users.service: Deactivated successfully.
131.51 s
[vm-test-run-centjes-e2e-test] client # [ 8.038397] systemd[1]: Stopped target Host and Network Name Lookups.
131.51 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.174826] systemd[1]: Finished linger-users.service.
131.52 s
[vm-test-run-centjes-e2e-test] client # [ 8.048948] systemd[1]: Stopping Host and Network Name Lookups...
131.53 s
[vm-test-run-centjes-e2e-test] client # [ 8.055250] systemd[1]: Stopped target User and Group Name Lookups.
131.53 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.193686] systemd[1]: Finished resolvconf update.
131.54 s
[vm-test-run-centjes-e2e-test] client # [ 8.065719] systemd[1]: Stopping User and Group Name Lookups...
131.54 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.203260] systemd[1]: Reached target Preparation for Network.
131.55 s
[vm-test-run-centjes-e2e-test] client # [ 8.072577] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...
131.55 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.215179] systemd[1]: Starting DHCP Client...
131.56 s
[vm-test-run-centjes-e2e-test] client # [ 8.081572] systemd[1]: nscd.service: Deactivated successfully.
131.56 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.220361] systemd[1]: Starting Address configuration of eth1...
131.57 s
[vm-test-run-centjes-e2e-test] client # [ 8.091861] systemd[1]: Stopped Name Service Cache Daemon (nsncd).
131.58 s
[vm-test-run-centjes-e2e-test] client # [ 8.103735] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
131.59 s
[vm-test-run-centjes-e2e-test] client # [ 8.116737] systemd-logind[640]: New seat seat0.
131.59 s
[vm-test-run-centjes-e2e-test] client # [ 8.126162] systemd[1]: Started User Login Management.
131.60 s
[vm-test-run-centjes-e2e-test] client # [ 8.131817] systemd[1]: Starting linger-users.service...[ 8.499279] mousedev: PS/2 mouse device common for all mice
131.61 s
[vm-test-run-centjes-e2e-test] client #
131.65 s
[vm-test-run-centjes-e2e-test] client # [ 8.164628] nsncd[684]: Aug 04 20:41:49.121 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
131.65 s
[vm-test-run-centjes-e2e-test] client # [ 8.181790] systemd[1]: Started Name Service Cache Daemon (nsncd).
131.66 s
[vm-test-run-centjes-e2e-test] client # [ 8.191467] systemd[1]: Reached target Host and Network Name Lookups.
131.67 s
[vm-test-run-centjes-e2e-test] client # [ 8.197865] systemd[1]: Reached target User and Group Name Lookups.
131.67 s
[vm-test-run-centjes-e2e-test] client # [ 8.202184] systemd[1]: linger-users.service: Deactivated successfully.
131.67 s
[vm-test-run-centjes-e2e-test] client # [ 8.205995] systemd[1]: Finished linger-users.service.
131.69 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.346512] network-addresses-eth1-start[730]: adding address 192.168.1.2/24... done
131.69 s
[vm-test-run-centjes-e2e-test] client # [ 8.590054] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input3
131.70 s
[vm-test-run-centjes-e2e-test] client # [ 8.233303] systemd[1]: Finished resolvconf update.
131.71 s
[vm-test-run-centjes-e2e-test] client # [ 8.237934] systemd[1]: Reached target Preparation for Network.
131.71 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.367925] network-addresses-eth1-start[730]: adding address 2001:db8:1::2/64... done[ 8.745853] mousedev: PS/2 mouse device common for all mice
131.71 s
[vm-test-run-centjes-e2e-test] docsserver #
131.71 s
[vm-test-run-centjes-e2e-test] client # [ 8.243245] systemd[1]: Starting DHCP Client...
131.72 s
[vm-test-run-centjes-e2e-test] client # [ 8.247935] systemd[1]: Starting Address configuration of eth1...
131.74 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.404189] systemd[1]: Finished Address configuration of eth1.
131.75 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.409990] systemd[1]: Starting Networking Setup...
131.75 s
[vm-test-run-centjes-e2e-test] client # [ 8.648902] ACPI: button: Power Button [PWRF]
131.76 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.794467] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input3
131.77 s
[vm-test-run-centjes-e2e-test] client # [ 8.673267] rtc_cmos 00:05: RTC can wake from S4
131.80 s
[vm-test-run-centjes-e2e-test] client # [ 8.698355] parport_pc 00:03: reported by Plug and Play ACPI
131.81 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.473816] dhcpcd[737]: dhcpcd-10.2.4 starting
131.81 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.851956] ACPI: button: Power Button [PWRF]
131.83 s
[vm-test-run-centjes-e2e-test] client # [ 8.362451] network-addresses-eth1-start[714]: adding address 192.168.1.1/24... done[ 8.730705] Floppy drive(s): fd0 is 2.88M AMI BIOS
131.84 s
[vm-test-run-centjes-e2e-test] client #
131.84 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.503659] dhcpcd[750]: dev: loaded udev
131.84 s
[vm-test-run-centjes-e2e-test] client # [ 8.736998] parport0: PC-style at 0x378, irq 7 [PCSPP(,...)]
131.84 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.878677] rtc_cmos 00:05: RTC can wake from S4
131.85 s
[vm-test-run-centjes-e2e-test] client # [ 8.745623] rtc_cmos 00:05: registered as rtc0
131.86 s
[vm-test-run-centjes-e2e-test] client # [ 8.386670] network-addresses-eth1-start[714]: adding address 2001:db8:1::1/64... done
131.87 s
[vm-test-run-centjes-e2e-test] client # [ 8.765794] rtc_cmos 00:05: setting system clock to 2026-08-04T20:41:49 UTC (1785876109)
131.87 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.911393] 8021q: 802.1Q VLAN Support v1.8
131.88 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.913955] Floppy drive(s): fd0 is 2.88M AMI BIOS
131.88 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.915790] 8021q: adding VLAN 0 to HW filter on device eth1
131.89 s
[vm-test-run-centjes-e2e-test] client # [ 8.415445] systemd[1]: Finished Address configuration of eth1.
131.89 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.926081] parport_pc 00:03: reported by Plug and Play ACPI
131.89 s
[vm-test-run-centjes-e2e-test] client # [ 8.420826] systemd[1]: Starting Networking Setup...
131.90 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.935064] rtc_cmos 00:05: registered as rtc0
131.90 s
[vm-test-run-centjes-e2e-test] client # [ 8.795594] FDC 0 is a S82078B
131.91 s
[vm-test-run-centjes-e2e-test] client # [ 8.808240] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs
131.91 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.950504] parport0: PC-style at 0x378, irq 7 [PCSPP(,...)]
131.92 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.961994] rtc_cmos 00:05: setting system clock to 2026-08-04T20:41:49 UTC (1785876109)
131.93 s
[vm-test-run-centjes-e2e-test] client # [ 8.459760] dhcpcd[720]: dhcpcd-10.2.4 starting
131.93 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.971551] FDC 0 is a S82078B
131.94 s
[vm-test-run-centjes-e2e-test] client # [ 8.472938] dhcpcd[733]: dev: loaded udev
131.96 s
[vm-test-run-centjes-e2e-test] client # [ 8.861186] 8021q: 802.1Q VLAN Support v1.8
131.97 s
[vm-test-run-centjes-e2e-test] client # [ 8.865540] 8021q: adding VLAN 0 to HW filter on device eth1
131.97 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.006317] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs
132.00 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.653740] systemd[1]: Finished Networking Setup.
132.00 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.666546] systemd[1]: Reached target Network.
132.01 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.676240] systemd[1]: Starting Permit User Sessions...
132.03 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.067822] cfg80211: Loading compiled-in X.509 certificates for regulatory database
132.06 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.099566] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
132.07 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.103444] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'
132.07 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.110818] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
132.08 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.115974] cfg80211: failed to load regulatory.db
132.08 s
[vm-test-run-centjes-e2e-test] client # [ 8.981754] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0
132.09 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.753109] systemd[1]: Finished Permit User Sessions.
132.09 s
[vm-test-run-centjes-e2e-test] client # [ 8.985619] cfg80211: Loading compiled-in X.509 certificates for regulatory database
132.09 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.761245] systemd[1]: Started Getty on tty1.
132.10 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.766685] systemd[1]: Reached target Login Prompts.
132.12 s
[vm-test-run-centjes-e2e-test] client # [ 9.015385] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
132.12 s
[vm-test-run-centjes-e2e-test] client # [ 9.018829] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'
132.13 s
[vm-test-run-centjes-e2e-test] client # [ 9.026870] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
132.13 s
[vm-test-run-centjes-e2e-test] client # [ 9.031891] cfg80211: failed to load regulatory.db
132.15 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.185864] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0
132.15 s
[vm-test-run-centjes-e2e-test] client # [ 8.682377] systemd[1]: Finished Networking Setup.
132.16 s
[vm-test-run-centjes-e2e-test] client # [ 8.687482] systemd[1]: Reached target Network.
132.16 s
[vm-test-run-centjes-e2e-test] client # [ 8.694215] systemd[1]: Starting Permit User Sessions...
132.17 s
[vm-test-run-centjes-e2e-test] client # [ 9.071933] i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD
132.18 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.214171] 8021q: adding VLAN 0 to HW filter on device eth0
132.18 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.849222] dhcpcd[750]: eth0: waiting for carrier
132.19 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.852913] dhcpcd[750]: libudev: received NULL device [ 9.227376] i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD
132.19 s
[vm-test-run-centjes-e2e-test] docsserver #
132.19 s
[vm-test-run-centjes-e2e-test] client # [ 9.088310] input: QEMU Virtio Keyboard as /devices/pci0000:00/0000:00:0a.0/virtio7/input/input4
132.19 s
[vm-test-run-centjes-e2e-test] docsserver # [ 8.859689] dhcpcd[750]: libudev: received NULL device
132.20 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.234869] input: QEMU Virtio Keyboard as /devices/pci0000:00/0000:00:0a.0/virtio7/input/input4
132.20 s
[vm-test-run-centjes-e2e-test] client # [ 9.099134] bochs-drm 0000:00:02.0: vgaarb: deactivate vga console
132.22 s
[vm-test-run-centjes-e2e-test] client # [ 8.750560] systemd[1]: Finished Permit User Sessions.
132.22 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.247481] bochs-drm 0000:00:02.0: vgaarb: deactivate vga console
132.22 s
[vm-test-run-centjes-e2e-test] client # [ 8.757252] systemd[1]: Started Getty on tty1.
132.23 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.265016] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input6
132.23 s
[vm-test-run-centjes-e2e-test] client # [ 8.760621] systemd[1]: Reached target Login Prompts.
132.23 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.268595] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input5
132.24 s
[vm-test-run-centjes-e2e-test] client # [ 9.134817] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input6
132.25 s
[vm-test-run-centjes-e2e-test] client # [ 9.139031] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input5
132.26 s
[vm-test-run-centjes-e2e-test] client # [ 9.159795] 8021q: adding VLAN 0 to HW filter on device eth0
132.26 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.300552] cryptd: max_cpu_qlen set to 1000
132.27 s
[vm-test-run-centjes-e2e-test] client # [ 8.798206] dhcpcd[733]: eth0: waiting for carrier
132.28 s
[vm-test-run-centjes-e2e-test] client # [ 8.801565] dhcpcd[733]: libudev: received NULL device
132.28 s
[vm-test-run-centjes-e2e-test] client # [ 8.814325] dhcpcd[733]: libudev: received NULL device
132.28 s
[vm-test-run-centjes-e2e-test] client # [ 8.815858] dhcpcd[733]: eth0: carrier acquired
132.30 s
[vm-test-run-centjes-e2e-test] client # [ 8.826725] dhcpcd[733]: DUID 00:01:00:01:32:05:0b:0d:52:54:00:12:34:56
132.30 s
[vm-test-run-centjes-e2e-test] client # [ 8.830704] dhcpcd[733]: eth0: IAID 00:12:34:56
132.30 s
[vm-test-run-centjes-e2e-test] client # [ 8.834412] dhcpcd[733]: eth0: adding address fe80::5054:ff:fe12:3456
132.32 s
[vm-test-run-centjes-e2e-test] client # [ 9.208120] cryptd: max_cpu_qlen set to 1000
132.32 s
[vm-test-run-centjes-e2e-test] client # [ 9.214652] Console: switching to colour dummy device 80x25
132.33 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.335967] AES CTR mode by8 optimization enabled
132.33 s
[vm-test-run-centjes-e2e-test] client # [ 9.229277] AES CTR mode by8 optimization enabled
132.34 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.368078] Console: switching to colour dummy device 80x25
132.34 s
[vm-test-run-centjes-e2e-test] client # [ 9.239831] [drm] Found bochs VGA, ID 0xb0c5.
132.34 s
[vm-test-run-centjes-e2e-test] client # [ 9.240778] [drm] Framebuffer size 16384 kB @ 0xfd000000, mmio @ 0xfebd0000.
132.35 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.389406] [drm] Found bochs VGA, ID 0xb0c5.
132.35 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.390329] [drm] Framebuffer size 16384 kB @ 0xfd000000, mmio @ 0xfebd0000.
132.37 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.033334] systemd[1]: Starting Virtual Console Setup...
132.39 s
[vm-test-run-centjes-e2e-test] client # [ 9.289323] [drm] Found EDID data blob.
132.41 s
[vm-test-run-centjes-e2e-test] client # [ 8.936600] systemd[1]: Starting Virtual Console Setup...
132.41 s
[vm-test-run-centjes-e2e-test] client # [ 9.308285] [drm] Initialized bochs-drm 1.0.0 for 0000:00:02.0 on minor 0
132.42 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.459406] [drm] Found EDID data blob.
132.44 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.101765] systemd-logind[644]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard)[ 9.475852] [drm] Initialized bochs-drm 1.0.0 for 0000:00:02.0 on minor 0
132.44 s
[vm-test-run-centjes-e2e-test] docsserver #
132.45 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.109910] systemd-logind[644]: Watching system buttons on /dev/input/event2 (Power Button)
132.98 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.126215] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
132.99 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.656529] dhcpcd[750]: eth0: carrier acquired
133.01 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.675397] dhcpcd[750]: DUID 00:01:00:01:32:05:0b:0e:52:54:00:12:34:56
133.01 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.678182] dhcpcd[750]: eth0: IAID 00:12:34:56
133.01 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.679684] dhcpcd[750]: eth0: adding address fe80::5054:ff:fe12:3456
133.12 s
[vm-test-run-centjes-e2e-test] client # [ 9.337628] fbcon: bochs-drmdrmfb (fb0) is primary device
133.12 s
[vm-test-run-centjes-e2e-test] client # [ 9.887795] Console: switching to colour frame buffer device 160x50
133.13 s
[vm-test-run-centjes-e2e-test] client # [ 10.024976] bochs-drm 0000:00:02.0: [drm] fb0: bochs-drmdrmfb frame buffer device
133.13 s
[vm-test-run-centjes-e2e-test] client # [ 9.655469] systemd-logind[640]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard)
133.16 s
[vm-test-run-centjes-e2e-test] docsserver # [ 9.493953] fbcon: bochs-drmdrmfb (fb0) is primary device
133.17 s
[vm-test-run-centjes-e2e-test] docsserver # [ 10.064468] Console: switching to colour frame buffer device 160x50
133.17 s
[vm-test-run-centjes-e2e-test] docsserver # [ 10.207064] bochs-drm 0000:00:02.0: [drm] fb0: bochs-drmdrmfb frame buffer device
133.32 s
[vm-test-run-centjes-e2e-test] client # [ 9.851256] systemd-logind[640]: Watching system buttons on /dev/input/event2 (Power Button)
133.32 s
[vm-test-run-centjes-e2e-test] client # [ 10.223826] ppdev: user-space parallel port driver
133.37 s
[vm-test-run-centjes-e2e-test] client # [ 9.898438] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
133.39 s
[vm-test-run-centjes-e2e-test] docsserver # [ 10.426961] ppdev: user-space parallel port driver
133.45 s
[vm-test-run-centjes-e2e-test] client # [ 10.345701] kvm_amd: TSC scaling supported
133.45 s
[vm-test-run-centjes-e2e-test] client # [ 10.346632] kvm_amd: Nested Virtualization enabled
133.45 s
[vm-test-run-centjes-e2e-test] client # [ 10.347725] kvm_amd: Nested Paging enabled
133.45 s
[vm-test-run-centjes-e2e-test] client # [ 10.348657] kvm_amd: LBR virtualization supported
133.47 s
[vm-test-run-centjes-e2e-test] docsserver # [ 10.513139] kvm_amd: TSC scaling supported
133.47 s
[vm-test-run-centjes-e2e-test] docsserver # [ 10.514123] kvm_amd: Nested Virtualization enabled
133.48 s
[vm-test-run-centjes-e2e-test] docsserver # [ 10.515395] kvm_amd: Nested Paging enabled
133.48 s
[vm-test-run-centjes-e2e-test] docsserver # [ 10.516324] kvm_amd: LBR virtualization supported
133.48 s
[vm-test-run-centjes-e2e-test] client # [ 10.006640] systemd-logind[640]: Watching system buttons on /dev/input/event5 (QEMU Virtio Keyboard)
133.49 s
[vm-test-run-centjes-e2e-test] client # [ 10.020452] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
133.50 s
[vm-test-run-centjes-e2e-test] client # [ 10.029749] systemd[1]: Stopped Virtual Console Setup.
133.50 s
[vm-test-run-centjes-e2e-test] client # [ 10.036250] systemd[1]: Starting Virtual Console Setup...
133.51 s
[vm-test-run-centjes-e2e-test] client # [ 10.411548] kvm_amd: Virtual VMLOAD VMSAVE supported
133.51 s
[vm-test-run-centjes-e2e-test] client # [ 10.412625] kvm_amd: Virtual GIF supported
133.52 s
[vm-test-run-centjes-e2e-test] docsserver # [ 10.183479] systemd-logind[644]: Watching system buttons on /dev/input/event5 (QEMU Virtio Keyboard)
133.53 s
[vm-test-run-centjes-e2e-test] docsserver # [ 10.570131] kvm_amd: Virtual VMLOAD VMSAVE supported
133.53 s
[vm-test-run-centjes-e2e-test] docsserver # [ 10.571511] kvm_amd: Virtual GIF supported
133.57 s
[vm-test-run-centjes-e2e-test] docsserver # [ 10.229960] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
133.57 s
[vm-test-run-centjes-e2e-test] docsserver # [ 10.237316] systemd[1]: Stopped Virtual Console Setup.
133.74 s
[vm-test-run-centjes-e2e-test] client # [ 10.102649] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
133.74 s
[vm-test-run-centjes-e2e-test] docsserver # [ 10.241984] systemd[1]: Starting Virtual Console Setup...
133.74 s
[vm-test-run-centjes-e2e-test] client # [ 10.112503] systemd[1]: Stopped Virtual Console Setup.
133.74 s
[vm-test-run-centjes-e2e-test] client # [ 10.118418] systemd[1]: Starting Virtual Console Setup...
133.74 s
[vm-test-run-centjes-e2e-test] client # [ 10.500104] EDAC MC: Ver: 3.0.0
133.74 s
[vm-test-run-centjes-e2e-test] docsserver # [ 10.272984] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
133.74 s
[vm-test-run-centjes-e2e-test] docsserver # [ 10.278878] systemd[1]: Stopped Virtual Console Setup.
133.74 s
[vm-test-run-centjes-e2e-test] docsserver # [ 10.283420] systemd[1]: Starting Virtual Console Setup...
133.74 s
[vm-test-run-centjes-e2e-test] docsserver # [ 10.680940] EDAC MC: Ver: 3.0.0
133.78 s
[vm-test-run-centjes-e2e-test] docsserver # [ 10.445979] dhcpcd[750]: eth0: soliciting a DHCP lease
133.81 s
[vm-test-run-centjes-e2e-test] docsserver # [ 10.845230] NET: Registered PF_PACKET protocol family
133.82 s
[vm-test-run-centjes-e2e-test] docsserver # [ 10.484707] dhcpcd[750]: eth0: offered 10.0.2.15 from 10.0.2.2
133.82 s
[vm-test-run-centjes-e2e-test] docsserver # [ 10.489402] dhcpcd[750]: eth0: probing address 10.0.2.15/24
134.01 s
[vm-test-run-centjes-e2e-test] docsserver # [ 10.676171] systemd[1]: Finished Virtual Console Setup.
134.01 s
[vm-test-run-centjes-e2e-test] client # [ 10.542418] systemd[1]: Finished Virtual Console Setup.
134.06 s
[vm-test-run-centjes-e2e-test] client # [ 10.593313] dhcpcd[733]: eth0: soliciting a DHCP lease
134.08 s
[vm-test-run-centjes-e2e-test] client # [ 10.981299] NET: Registered PF_PACKET protocol family
134.09 s
[vm-test-run-centjes-e2e-test] client # [ 10.624936] dhcpcd[733]: eth0: offered 10.0.2.15 from 10.0.2.2
134.10 s
[vm-test-run-centjes-e2e-test] client # [ 10.628365] dhcpcd[733]: eth0: probing address 10.0.2.15/24
134.12 s
[vm-test-run-centjes-e2e-test] client # [ 10.652887] dhcpcd[733]: eth0: soliciting an IPv6 router
134.12 s
[vm-test-run-centjes-e2e-test] client # [ 10.654956] dhcpcd[733]: eth0: Router Advertisement from fe80::2
134.12 s
[vm-test-run-centjes-e2e-test] client # [ 10.656813] dhcpcd[733]: eth0: adding address fec0::5054:ff:fe12:3456/64
134.13 s
[vm-test-run-centjes-e2e-test] client # [ 10.658788] dhcpcd[733]: eth0: adding route to fec0::/64
134.13 s
[vm-test-run-centjes-e2e-test] client # [ 10.660451] dhcpcd[733]: eth0: adding default route via fe80::2
134.73 s
[vm-test-run-centjes-e2e-test] docsserver # [ 11.400513] dhcpcd[750]: eth0: soliciting an IPv6 router
134.73 s
[vm-test-run-centjes-e2e-test] docsserver # [ 11.402597] dhcpcd[750]: eth0: Router Advertisement from fe80::2
134.74 s
[vm-test-run-centjes-e2e-test] docsserver # [ 11.404711] dhcpcd[750]: eth0: adding address fec0::5054:ff:fe12:3456/64
134.74 s
[vm-test-run-centjes-e2e-test] docsserver # [ 11.406735] dhcpcd[750]: eth0: adding route to fec0::/64
134.74 s
[vm-test-run-centjes-e2e-test] docsserver # [ 11.408463] dhcpcd[750]: eth0: adding default route via fe80::2
139.41 s
[vm-test-run-centjes-e2e-test] docsserver # [ 16.080220] dhcpcd[750]: eth0: leased 10.0.2.15 for 86400 seconds
139.44 s
[vm-test-run-centjes-e2e-test] docsserver # [ 16.082479] dhcpcd[750]: eth0: adding route to 10.0.2.0/24
139.44 s
[vm-test-run-centjes-e2e-test] docsserver # [ 16.084495] dhcpcd[750]: eth0: adding default route via 10.0.2.2
139.52 s
[vm-test-run-centjes-e2e-test] docsserver # [ 16.191240] systemd[1]: Started DHCP Client.
139.53 s
[vm-test-run-centjes-e2e-test] docsserver # [ 16.194546] systemd[1]: Reached target Multi-User System.
139.53 s
[vm-test-run-centjes-e2e-test] docsserver # [ 16.196941] systemd[1]: Startup finished in 3.834s (kernel) + 12.359s (userspace) = 16.193s.
139.73 s
[vm-test-run-centjes-e2e-test] client # [ 16.267177] dhcpcd[733]: eth0: leased 10.0.2.15 for 86400 seconds
139.74 s
[vm-test-run-centjes-e2e-test] client # [ 16.269456] dhcpcd[733]: eth0: adding route to 10.0.2.0/24
139.74 s
[vm-test-run-centjes-e2e-test] client # [ 16.271490] dhcpcd[733]: eth0: adding default route via 10.0.2.2
139.81 s
[vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for unit default.target, in 17.52 seconds)
139.81 s
[vm-test-run-centjes-e2e-test] client: waiting for unit default.target
139.81 s
[vm-test-run-centjes-e2e-test] client: waiting for the VM to finish booting
139.81 s
[vm-test-run-centjes-e2e-test] client: Guest shell says: b'Spawning backdoor root shell...\n'
139.81 s
[vm-test-run-centjes-e2e-test] client: connected to guest root shell
139.81 s
[vm-test-run-centjes-e2e-test] client: (connecting took 0.00 seconds)
139.81 s
[vm-test-run-centjes-e2e-test] client: (finished: waiting for the VM to finish booting, in 0.00 seconds)
139.87 s
[vm-test-run-centjes-e2e-test] client # [ 16.406158] systemd[1]: Started DHCP Client.
139.88 s
[vm-test-run-centjes-e2e-test] client # [ 16.407771] systemd[1]: Reached target Multi-User System.
139.88 s
[vm-test-run-centjes-e2e-test] client # [ 16.411911] systemd[1]: Startup finished in 4.101s (kernel) + 12.303s (userspace) = 16.405s.
139.95 s
[vm-test-run-centjes-e2e-test] client: (finished: waiting for unit default.target, in 0.13 seconds)
140.02 s
[vm-test-run-centjes-e2e-test] docsserver: waiting for unit centjes-docs-site-production.service
140.07 s
[vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for unit centjes-docs-site-production.service, in 0.05 seconds)
140.07 s
[vm-test-run-centjes-e2e-test] docsserver: waiting for unit default.target
140.12 s
[vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for unit default.target, in 0.05 seconds)
140.12 s
[vm-test-run-centjes-e2e-test] docsserver: waiting for TCP port 8001 on localhost
140.21 s
[vm-test-run-centjes-e2e-test] docsserver # Connection to localhost (127.0.0.1) 8001 port [tcp/vcom-tunnel] succeeded!
140.21 s
[vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for TCP port 8001 on localhost, in 0.09 seconds)
140.21 s
[vm-test-run-centjes-e2e-test] client: must succeed: curl docsserver:8001
140.29 s
[vm-test-run-centjes-e2e-test] client # % Total % Received % Xferd Average Speed Time Time Time Current
140.30 s
[vm-test-run-centjes-e2e-test] client # Dload Upload Total Spent Left Speed
140.32 s
[vm-test-run-centjes-e2e-test] docsserver # [ 16.991448] centjes-docs-site-production-start[633]: 192.168.1.1 - - [04/Aug/2026:20:41:57 +0000] "GET / HTTP/1.1" 200 3595 "" "curl/8.17.0"
140.34 s
[vm-test-run-centjes-e2e-test] client # 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0100 3595 100 3595 0 0 59622 0 --:--:-- --:--:-- --:--:-- 60932
140.35 s
[vm-test-run-centjes-e2e-test] client: (finished: must succeed: curl docsserver:8001, in 0.14 seconds)
140.35 s
[vm-test-run-centjes-e2e-test] (finished: run the VM test script, in 18.48 seconds)
140.46 s
[vm-test-run-centjes-e2e-test] test script finished in 18.59s
140.46 s
[vm-test-run-centjes-e2e-test] cleanup
140.46 s
[vm-test-run-centjes-e2e-test] kill machine (pid 31)
140.46 s
[vm-test-run-centjes-e2e-test] qemu-system-x86_64: terminating on signal 15 from pid 6 (/nix/store/jj6jldlw37r8yy9kc1smrax9dhnjm2x4-python3-3.13.9/bin/python3.13)
140.46 s
[vm-test-run-centjes-e2e-test] kill machine (pid 9)
140.46 s
[vm-test-run-centjes-e2e-test] qemu-system-x86_64: terminating on signal 15 from pid 6 (/nix/store/jj6jldlw37r8yy9kc1smrax9dhnjm2x4-python3-3.13.9/bin/python3.13)
140.47 s
[vm-test-run-centjes-e2e-test] kill vlan (pid 7)
140.47 s
[vm-test-run-centjes-e2e-test] (finished: cleanup, in 0.02 seconds)
140.56 s
[vm-test-run-centjes-e2e-test:post-build] Uploading to cachix cache "centjes": /nix/store/c0bj8pmwm676biix4cdd80lkb98crl0p-vm-test-run-centjes-e2e-test
140.91 s
[vm-test-run-centjes-e2e-test:post-build] Pushing 1 paths (0 are already present) using zstd to cache centjes ⏳
140.91 s
[vm-test-run-centjes-e2e-test:post-build]
141.27 s
[vm-test-run-centjes-e2e-test:post-build] Pushing /nix/store/c0bj8pmwm676biix4cdd80lkb98crl0p-vm-test-run-centjes-e2e-test (96.00 B)
142.16 s
[vm-test-run-centjes-e2e-test:post-build]
142.16 s
[vm-test-run-centjes-e2e-test:post-build] All done.
142.18 s
[vm-test-run-centjes-e2e-test:post-build] Uploading to the NixCI staging cache: /nix/store/c0bj8pmwm676biix4cdd80lkb98crl0p-vm-test-run-centjes-e2e-test
142.22 s
[vm-test-run-centjes-e2e-test:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
142.23 s
[vm-test-run-centjes-e2e-test:post-build] copying 1 paths...
142.23 s
[vm-test-run-centjes-e2e-test:post-build] copying path '/nix/store/c0bj8pmwm676biix4cdd80lkb98crl0p-vm-test-run-centjes-e2e-test' to 'https://cache.staging.nix-ci.com'...
142.42 s
[vm-test-run-centjes-e2e-test:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
142.70 s
[vm-test-run-centjes-e2e-test:post-build] copying 1 paths...
142.70 s
[vm-test-run-centjes-e2e-test:post-build] copying path '/nix/store/7i80czand4927npm2s8v8j9w554vlmcz-vm-test-run-centjes-e2e-test.drv' to 'https://cache.staging.nix-ci.com'...
142.89 s
Uploaded vm-test-run-centjes-e2e-test in 2.3s
142.89 s
Progress: 12 of 13 built
142.89 s
Built vm-test-run-centjes-e2e-test in 21.3s
142.89 s
Progress: 13 of 13 built
142.89 s
/nix/store/c0bj8pmwm676biix4cdd80lkb98crl0p-vm-test-run-centjes-e2e-test
143.03 s
Build succeeded.