build checks.x86_64-linux.e2e-test

Reproduce this run
  1. 0.02 s $ /nix/store/vzx1mi9c0xfadmsm9dhd83d005cb1qs9-coreutils-9.8/bin/timeout --kill-after=15s 7200s /nix/store/99b1z08awpxj8b6mzggn59gp1shljnff-nix-2.34.5/bin/nix --extra-experimental-features nix-command --extra-experimental-features flakes --log-format internal-json build --no-link git+https://github.com/NorfairKing/centjes?ref=fix-price-change-not-counted-in-average&rev=d9b7e0c6102bb9d29abf89ac5e2d1bc0f38016f4#checks.x86_64-linux.e2e-test --print-build-logs
  2. 0.08 s warning: ignoring untrusted flake configuration setting 'extra-substituters'.
  3. 0.08 s Pass '--accept-flake-config' to trust it
  4. 0.08 s warning: ignoring untrusted flake configuration setting 'extra-trusted-public-keys'.
  5. 0.08 s Pass '--accept-flake-config' to trust it
  6. 0.08 s
  7. 2.30 s Substituting unit-script-centjes-docs-site-production-start from https://cache.staging.nix-ci.com
  8. 2.32 s Progress: 0 of 2 built, 1 of 9 fetched
  9. 2.40 s Substituting settings-check from https://cache.staging.nix-ci.com
  10. 2.42 s Progress: 0 of 11 built, 2 of 2 fetched
  11. 2.50 s Building settings-check
  12. 2.54 s [settings-check] WithConfig: src/Centjes/Docs/Site/OptParse.hs:27:7 in centjes-docs-site:Centjes.Docs.Site.OptParse
  13. 2.54 s [settings-check] loading config
  14. 2.54 s [settings-check] Parser with check: src/Centjes/Docs/Site/OptParse.hs:27:7 in centjes-docs-site:Centjes.Docs.Site.OptParse
  15. 2.54 s [settings-check] parser
  16. 2.54 s [settings-check] Alt
  17. 2.54 s [settings-check] Trying left side.
  18. 2.54 s [settings-check] Parser with check: src/Centjes/Docs/Site/OptParse.hs:27:7 in centjes-docs-site:Centjes.Docs.Site.OptParse
  19. 2.54 s [settings-check] parser
  20. 2.54 s [settings-check] Setting: src/Centjes/Docs/Site/OptParse.hs:27:7 in centjes-docs-site:Centjes.Docs.Site.OptParse
  21. 2.54 s [settings-check] could not set based on options, no option: ["--config-file"]
  22. 2.54 s [settings-check] set based on env: "/nix/store/vb9vv8cg7xwfa7010fyznaj7b5syrx63-centjes-docs-site-config.yaml"
  23. 2.54 s [settings-check] check
  24. 2.54 s [settings-check] succeeded
  25. 2.54 s [settings-check] Left side succeeded.
  26. 2.54 s [settings-check] check
  27. 2.54 s [settings-check] succeeded
  28. 2.54 s [settings-check] with loaded config
  29. 2.54 s [settings-check] Ap
  30. 2.54 s [settings-check] Ap
  31. 2.54 s [settings-check] Parser with check: without srcLoc
  32. 2.54 s [settings-check] parser
  33. 2.54 s [settings-check] Setting: src/Centjes/Docs/Site/OptParse.hs:29:11 in centjes-docs-site:Centjes.Docs.Site.OptParse
  34. 2.55 s [settings-check] could not set based on options, no option: ["--port"]
  35. 2.55 s [settings-check] could not set based on env vars, no var: [EnvVarSetting {envVarSettingVar = "CENTJES_DOCS_SITE_PORT", envVarSettingAllowPrefix = True}]
  36. 2.55 s [settings-check] set based on config value: Number 8001.0
  37. 2.55 s [settings-check] check
  38. 2.55 s [settings-check] succeeded
  39. 2.55 s [settings-check] Alt
  40. 2.55 s [settings-check] Trying left side.
  41. 2.55 s [settings-check] Parser with check: without srcLoc
  42. 2.55 s [settings-check] parser
  43. 2.55 s [settings-check] Setting: src/Centjes/Docs/Site/OptParse.hs:38:13 in centjes-docs-site:Centjes.Docs.Site.OptParse
  44. 2.55 s [settings-check] could not set based on options, no option: ["--google-analytics-tracking"]
  45. 2.55 s [settings-check] could not set based on env vars, no var: [EnvVarSetting {envVarSettingVar = "CENTJES_DOCS_SITE_GOOGLE_ANALYTICS_TRACKING", envVarSettingAllowPrefix = True}]
  46. 2.55 s [settings-check] could not set based on config value, configured to nothing: ["google-analytics-tracking"]
  47. 2.55 s [settings-check] not found
  48. 2.55 s [settings-check] check
  49. 2.55 s [settings-check] Left side failed, trying right side.
  50. 2.55 s [settings-check] pure value
  51. 2.55 s [settings-check] Alt
  52. 2.55 s [settings-check] Trying left side.
  53. 2.55 s [settings-check] Parser with check: without srcLoc
  54. 2.55 s [settings-check] parser
  55. 2.55 s [settings-check] Setting: src/Centjes/Docs/Site/OptParse.hs:46:13 in centjes-docs-site:Centjes.Docs.Site.OptParse
  56. 2.55 s [settings-check] could not set based on options, no option: ["--google-search-console-verification"]
  57. 2.56 s [settings-check] could not set based on env vars, no var: [EnvVarSetting {envVarSettingVar = "CENTJES_DOCS_SITE_GOOGLE_SEARCH_CONSOLE_VERIFICATION", envVarSettingAllowPrefix = True}]
  58. 2.56 s [settings-check] could not set based on config value, configured to nothing: ["google-search-console-verification"]
  59. 2.56 s [settings-check] not found
  60. 2.56 s [settings-check] check
  61. 2.56 s [settings-check] Left side failed, trying right side.
  62. 2.56 s [settings-check] pure value
  63. 2.57 s [post-build-hook] Uploading paths from nix-ci to cachix cache "centjes" /nix/store/181fxqzmzn69yk3i6hw52nnxqml2g4xz-settings-check
  64. 5.86 s [post-build-hook] Pushing 1 paths (0 are already present) using zstd to cache centjes ⏳
  65. 5.86 s [post-build-hook]
  66. 7.45 s [post-build-hook] Pushing /nix/store/181fxqzmzn69yk3i6hw52nnxqml2g4xz-settings-check (144.00 B)
  67. 10.21 s [post-build-hook]
  68. 10.21 s [post-build-hook] All done.
  69. 10.22 s [post-build-hook] Uploading paths from nix-ci to the NixCI staging cache /nix/store/181fxqzmzn69yk3i6hw52nnxqml2g4xz-settings-check
  70. 10.26 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  71. 10.27 s [post-build-hook] copying 1 paths...
  72. 10.27 s [post-build-hook] copying path '/nix/store/181fxqzmzn69yk3i6hw52nnxqml2g4xz-settings-check' to 'https://cache.staging.nix-ci.com'...
  73. 10.37 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  74. 10.51 s [post-build-hook] copying 0 paths...
  75. 10.53 s Progress: 1 of 11 built, 2 of 2 fetched
  76. 10.56 s Building unit-centjes-docs-site-production.service
  77. 10.62 s [post-build-hook] Uploading paths from nix-ci to cachix cache "centjes" /nix/store/4mlr1a9spk5qng3jakqk1ml4gpiqgjd0-unit-centjes-docs-site-production.service
  78. 13.96 s [post-build-hook] Pushing 2 paths (90 are already present) using zstd to cache centjes ⏳
  79. 13.96 s [post-build-hook]
  80. 15.35 s [post-build-hook] Pushing /nix/store/4mlr1a9spk5qng3jakqk1ml4gpiqgjd0-unit-centjes-docs-site-production.service (1.62 KiB)
  81. 15.39 s [post-build-hook] Pushing /nix/store/5bk9xjc8si86dglhrd51va0gm26kcqcb-unit-script-centjes-docs-site-production-start (680.00 B)
  82. 18.29 s [post-build-hook]
  83. 18.29 s [post-build-hook] All done.
  84. 18.31 s [post-build-hook] Uploading paths from nix-ci to the NixCI staging cache /nix/store/4mlr1a9spk5qng3jakqk1ml4gpiqgjd0-unit-centjes-docs-site-production.service
  85. 18.34 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  86. 18.36 s [post-build-hook] copying 0 paths...
  87. 18.40 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  88. 18.57 s [post-build-hook] copying 0 paths...
  89. 18.59 s Progress: 2 of 11 built, 2 of 2 fetched
  90. 18.65 s Building system-units
  91. 19.52 s [post-build-hook] Uploading paths from nix-ci to cachix cache "centjes" /nix/store/1n9cmcz3pv1pig5dgxi1w6a86jh56kv4-system-units
  92. 22.72 s [post-build-hook] Pushing 2 paths (449 are already present) using zstd to cache centjes ⏳
  93. 22.72 s [post-build-hook]
  94. 23.59 s [post-build-hook] Pushing /nix/store/qps1mnjz35261mynpfpxsli7fmi50bpb-unit-nix-optimise.service (1.34 KiB)
  95. 23.63 s [post-build-hook] Pushing /nix/store/1n9cmcz3pv1pig5dgxi1w6a86jh56kv4-system-units (96.09 KiB)
  96. 25.31 s [post-build-hook]
  97. 25.31 s [post-build-hook] All done.
  98. 25.33 s [post-build-hook] Uploading paths from nix-ci to the NixCI staging cache /nix/store/1n9cmcz3pv1pig5dgxi1w6a86jh56kv4-system-units
  99. 25.36 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  100. 25.39 s [post-build-hook] copying 0 paths...
  101. 25.43 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  102. 25.65 s [post-build-hook] copying 0 paths...
  103. 25.68 s Progress: 3 of 11 built, 2 of 2 fetched
  104. 25.75 s Building etc
  105. 26.32 s [post-build-hook] Uploading paths from nix-ci to cachix cache "centjes" /nix/store/7vssgwc1b8r7jm1f887igzyp41wmdr4h-etc
  106. 29.57 s [post-build-hook] Pushing 1 paths (546 are already present) using zstd to cache centjes ⏳
  107. 29.57 s [post-build-hook]
  108. 30.24 s [post-build-hook] Pushing /nix/store/7vssgwc1b8r7jm1f887igzyp41wmdr4h-etc (31.56 KiB)
  109. 31.55 s [post-build-hook]
  110. 31.55 s [post-build-hook] All done.
  111. 31.56 s [post-build-hook] Uploading paths from nix-ci to the NixCI staging cache /nix/store/7vssgwc1b8r7jm1f887igzyp41wmdr4h-etc
  112. 31.60 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  113. 31.63 s [post-build-hook] copying 0 paths...
  114. 31.67 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  115. 31.87 s [post-build-hook] copying 0 paths...
  116. 31.89 s Progress: 4 of 11 built, 2 of 2 fetched
  117. 31.96 s Building nixos-system-docsserver-test
  118. 32.04 s [post-build-hook] Uploading paths from nix-ci to cachix cache "centjes" /nix/store/hk9888llhk4kkgz98y983g2r70r1xhfp-nixos-system-docsserver-test
  119. 32.91 s [post-build-hook] Pushing 1 paths (568 are already present) using zstd to cache centjes ⏳
  120. 32.91 s [post-build-hook]
  121. 33.31 s [post-build-hook] Pushing /nix/store/hk9888llhk4kkgz98y983g2r70r1xhfp-nixos-system-docsserver-test (17.26 KiB)
  122. 34.42 s [post-build-hook]
  123. 34.42 s [post-build-hook] All done.
  124. 34.43 s [post-build-hook] Uploading paths from nix-ci to the NixCI staging cache /nix/store/hk9888llhk4kkgz98y983g2r70r1xhfp-nixos-system-docsserver-test
  125. 34.47 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  126. 34.50 s [post-build-hook] copying 0 paths...
  127. 34.55 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  128. 34.74 s [post-build-hook] copying 0 paths...
  129. 34.77 s Progress: 5 of 11 built, 2 of 2 fetched
  130. 35.20 s Building closure-info
  131. 35.20 s [closure-info] structuredAttrs is enabled
  132. 35.30 s [post-build-hook] Uploading paths from nix-ci to cachix cache "centjes" /nix/store/y80mhfwjfvc24k06yxm5ibfscl6sjw28-closure-info
  133. 36.30 s [post-build-hook] Pushing 2 paths (568 are already present) using zstd to cache centjes ⏳
  134. 36.30 s [post-build-hook]
  135. 36.74 s [post-build-hook] Pushing /nix/store/ib8knpqn913hw717wjkgrh49flndihrz-llhttp-9.3.0 (85.40 KiB)
  136. 36.76 s [post-build-hook] Pushing /nix/store/y80mhfwjfvc24k06yxm5ibfscl6sjw28-closure-info (228.66 KiB)
  137. 37.78 s [post-build-hook]
  138. 37.78 s [post-build-hook] All done.
  139. 37.80 s [post-build-hook] Uploading paths from nix-ci to the NixCI staging cache /nix/store/y80mhfwjfvc24k06yxm5ibfscl6sjw28-closure-info
  140. 37.83 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  141. 37.87 s [post-build-hook] copying 0 paths...
  142. 37.92 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  143. 38.12 s [post-build-hook] copying 0 paths...
  144. 38.15 s Progress: 6 of 11 built, 2 of 2 fetched
  145. 38.22 s Building run-nixos-vm
  146. 38.28 s [post-build-hook] Uploading paths from nix-ci to cachix cache "centjes" /nix/store/n568r6m4wv5mjzm8cy3sy9p0dqbba1pp-run-nixos-vm
  147. 39.03 s [post-build-hook] Pushing 1 paths (580 are already present) using zstd to cache centjes ⏳
  148. 39.03 s [post-build-hook]
  149. 39.42 s [post-build-hook] Pushing /nix/store/n568r6m4wv5mjzm8cy3sy9p0dqbba1pp-run-nixos-vm (2.94 KiB)
  150. 40.41 s [post-build-hook]
  151. 40.41 s [post-build-hook] All done.
  152. 40.42 s [post-build-hook] Uploading paths from nix-ci to the NixCI staging cache /nix/store/n568r6m4wv5mjzm8cy3sy9p0dqbba1pp-run-nixos-vm
  153. 40.46 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  154. 40.51 s [post-build-hook] copying 0 paths...
  155. 40.56 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  156. 40.78 s [post-build-hook] copying 0 paths...
  157. 40.81 s Progress: 7 of 11 built, 2 of 2 fetched
  158. 40.89 s Building nixos-vm
  159. 40.96 s [post-build-hook] Uploading paths from nix-ci to cachix cache "centjes" /nix/store/2m4xmvaz64mwc79hh2yl7hljzjf09s47-nixos-vm
  160. 41.78 s [post-build-hook] Pushing 2 paths (580 are already present) using zstd to cache centjes ⏳
  161. 41.78 s [post-build-hook]
  162. 42.16 s [post-build-hook] Pushing /nix/store/2m4xmvaz64mwc79hh2yl7hljzjf09s47-nixos-vm (776.00 B)
  163. 42.17 s [post-build-hook] Pushing /nix/store/rk6wz4rw43g5a7nxn3cbkq2ql9dvh22m-unit-keys.target (352.00 B)
  164. 43.45 s [post-build-hook]
  165. 43.45 s [post-build-hook] All done.
  166. 43.46 s [post-build-hook] Uploading paths from nix-ci to the NixCI staging cache /nix/store/2m4xmvaz64mwc79hh2yl7hljzjf09s47-nixos-vm
  167. 43.50 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  168. 43.54 s [post-build-hook] copying 0 paths...
  169. 43.58 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  170. 44.36 s [post-build-hook] copying 0 paths...
  171. 44.39 s Progress: 8 of 11 built, 2 of 2 fetched
  172. 44.46 s Building nixos-test-driver-centjes-e2e-test
  173. 44.59 s [nixos-test-driver-centjes-e2e-test] Running type check (enable/disable: config.skipTypeCheck)
  174. 44.59 s [nixos-test-driver-centjes-e2e-test] See https://nixos.org/manual/nixos/stable/#test-opt-skipTypeCheck
  175. 50.09 s [nixos-test-driver-centjes-e2e-test] Success: no issues found in 1 source file
  176. 50.41 s [nixos-test-driver-centjes-e2e-test] additionally exposed symbols:
  177. 50.41 s [nixos-test-driver-centjes-e2e-test] ,
  178. 50.41 s [nixos-test-driver-centjes-e2e-test] ,
  179. 50.41 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
  180. 50.46 s [nixos-test-driver-centjes-e2e-test] Linting test script (enable/disable: config.skipLint)
  181. 50.46 s [nixos-test-driver-centjes-e2e-test] See https://nixos.org/manual/nixos/stable/#test-opt-skipLint
  182. 50.59 s [post-build-hook] Uploading paths from nix-ci to cachix cache "centjes" /nix/store/sqvjj5x5x9ls60g13g9s30df69yckynx-nixos-test-driver-centjes-e2e-test
  183. 51.42 s [post-build-hook] Pushing 1 paths (633 are already present) using zstd to cache centjes ⏳
  184. 51.42 s [post-build-hook]
  185. 51.79 s [post-build-hook] Pushing /nix/store/sqvjj5x5x9ls60g13g9s30df69yckynx-nixos-test-driver-centjes-e2e-test (1.84 KiB)
  186. 52.81 s [post-build-hook]
  187. 52.81 s [post-build-hook] All done.
  188. 52.82 s [post-build-hook] Uploading paths from nix-ci to the NixCI staging cache /nix/store/sqvjj5x5x9ls60g13g9s30df69yckynx-nixos-test-driver-centjes-e2e-test
  189. 52.86 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  190. 52.90 s [post-build-hook] copying 0 paths...
  191. 52.95 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  192. 53.17 s [post-build-hook] copying 0 paths...
  193. 53.20 s Progress: 9 of 11 built, 2 of 2 fetched
  194. 53.27 s Building vm-test-run-centjes-e2e-test
  195. 53.59 s [vm-test-run-centjes-e2e-test] Machine state will be reset. To keep it, pass --keep-vm-state
  196. 53.59 s [vm-test-run-centjes-e2e-test] start all VLans
  197. 53.59 s [vm-test-run-centjes-e2e-test] start vlan
  198. 53.59 s [vm-test-run-centjes-e2e-test] running vlan (pid 7; ctl /build/vde1.ctl)
  199. 53.59 s [vm-test-run-centjes-e2e-test] (finished: start all VLans, in 0.00 seconds)
  200. 53.59 s [vm-test-run-centjes-e2e-test] Test will time out and terminate in 3600 seconds
  201. 53.59 s [vm-test-run-centjes-e2e-test] run the VM test script
  202. 53.59 s [vm-test-run-centjes-e2e-test] additionally exposed symbols:
  203. 53.59 s [vm-test-run-centjes-e2e-test] client, docsserver,
  204. 53.59 s [vm-test-run-centjes-e2e-test] vlan1,
  205. 53.59 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
  206. 53.59 s [vm-test-run-centjes-e2e-test] docsserver: starting vm
  207. 53.61 s [vm-test-run-centjes-e2e-test] mke2fs 1.47.3 (8-Jul-2025)
  208. 53.76 s [vm-test-run-centjes-e2e-test] docsserver # Disk image does not exist, creating the virtualisation disk image...
  209. 53.76 s [vm-test-run-centjes-e2e-test] docsserver: QEMU running (pid 9)
  210. 53.76 s [vm-test-run-centjes-e2e-test] docsserver # Formatting '/build/vm-state-docsserver/tmp.8AmoLQN3Tt', fmt=raw size=1073741824
  211. 53.76 s [vm-test-run-centjes-e2e-test] client: starting vm
  212. 53.76 s [vm-test-run-centjes-e2e-test] docsserver # Discarding device blocks: 0/262144 done
  213. 53.76 s [vm-test-run-centjes-e2e-test] docsserver # Creating filesystem with 262144 4k blocks and 65536 inodes
  214. 53.76 s [vm-test-run-centjes-e2e-test] docsserver # Filesystem UUID: 6e28e413-a81c-44a9-9ae4-e393375b3fa3
  215. 53.76 s [vm-test-run-centjes-e2e-test] docsserver # Superblock backups stored on blocks:
  216. 53.76 s [vm-test-run-centjes-e2e-test] docsserver # 32768, 98304, 163840, 229376
  217. 53.76 s [vm-test-run-centjes-e2e-test] docsserver #
  218. 53.76 s [vm-test-run-centjes-e2e-test] docsserver # Allocating group tables: 0/8 done
  219. 53.76 s [vm-test-run-centjes-e2e-test] docsserver # Writing inode tables: 0/8 done
  220. 53.76 s [vm-test-run-centjes-e2e-test] docsserver # Creating journal (8192 blocks): done
  221. 53.76 s [vm-test-run-centjes-e2e-test] docsserver # Writing superblocks and filesystem accounting information: 0/8 done
  222. 53.76 s [vm-test-run-centjes-e2e-test] docsserver #
  223. 53.76 s [vm-test-run-centjes-e2e-test] docsserver # Virtualisation disk image created.
  224. 53.78 s [vm-test-run-centjes-e2e-test] mke2fs 1.47.3 (8-Jul-2025)
  225. 53.85 s [vm-test-run-centjes-e2e-test] docsserver # c[?7lSeaBIOS (version rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org)
  226. 53.91 s [vm-test-run-centjes-e2e-test] client: QEMU running (pid 31)
  227. 53.91 s [vm-test-run-centjes-e2e-test] client # Disk image does not exist, creating the virtualisation disk image...
  228. 53.91 s [vm-test-run-centjes-e2e-test] docsserver: waiting for unit default.target
  229. 53.91 s [vm-test-run-centjes-e2e-test] client # Formatting '/build/vm-state-client/tmp.JPfiLLgbn2', fmt=raw size=1073741824
  230. 53.91 s [vm-test-run-centjes-e2e-test] docsserver: waiting for the VM to finish booting
  231. 53.91 s [vm-test-run-centjes-e2e-test] client # Discarding device blocks: 0/262144 done
  232. 53.91 s [vm-test-run-centjes-e2e-test] client # Creating filesystem with 262144 4k blocks and 65536 inodes
  233. 53.91 s [vm-test-run-centjes-e2e-test] client # Filesystem UUID: 5bc27674-668d-4e8b-ab42-ceb2d700589d
  234. 53.91 s [vm-test-run-centjes-e2e-test] client # Superblock backups stored on blocks:
  235. 53.91 s [vm-test-run-centjes-e2e-test] client # 32768, 98304, 163840, 229376
  236. 53.91 s [vm-test-run-centjes-e2e-test] client #
  237. 53.91 s [vm-test-run-centjes-e2e-test] client # Allocating group tables: 0/8 done
  238. 53.91 s [vm-test-run-centjes-e2e-test] client # Writing inode tables: 0/8 done
  239. 53.91 s [vm-test-run-centjes-e2e-test] client # Creating journal (8192 blocks): done
  240. 53.91 s [vm-test-run-centjes-e2e-test] client # Writing superblocks and filesystem accounting information: 0/8 done
  241. 53.91 s [vm-test-run-centjes-e2e-test] client #
  242. 53.91 s [vm-test-run-centjes-e2e-test] client # Virtualisation disk image created.
  243. 53.96 s [vm-test-run-centjes-e2e-test] docsserver #
  244. 53.96 s [vm-test-run-centjes-e2e-test] docsserver #
  245. 53.96 s [vm-test-run-centjes-e2e-test] docsserver # iPXE (http://ipxe.org) 00:03.0 CA00 PCI2.10 PnP PMM+3EFD1920+3EF31920 CA00
  246. 53.98 s [vm-test-run-centjes-e2e-test] docsserver # Press Ctrl-B to configure iPXE (PCI 00:03.0)...
  247. 53.98 s [vm-test-run-centjes-e2e-test] docsserver #
  248. 53.98 s [vm-test-run-centjes-e2e-test] docsserver #
  249. 53.98 s [vm-test-run-centjes-e2e-test] docsserver #
  250. 53.98 s [vm-test-run-centjes-e2e-test] docsserver #
  251. 53.98 s [vm-test-run-centjes-e2e-test] docsserver # iPXE (http://ipxe.org) 00:09.0 CB00 PCI2.10 PnP PMM 3EFD1920 3EF31920 CB00
  252. 54.00 s [vm-test-run-centjes-e2e-test] docsserver # Press Ctrl-B to configure iPXE (PCI 00:09.0)...
  253. 54.00 s [vm-test-run-centjes-e2e-test] docsserver #
  254. 54.00 s [vm-test-run-centjes-e2e-test] docsserver #
  255. 54.01 s [vm-test-run-centjes-e2e-test] docsserver # Booting from ROM...
  256. 54.01 s [vm-test-run-centjes-e2e-test] client # c[?7lSeaBIOS (version rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org)
  257. 54.02 s [vm-test-run-centjes-e2e-test] docsserver # Probing EDD (edd=off to disable)... ok
  258. 54.11 s [vm-test-run-centjes-e2e-test] client #
  259. 54.11 s [vm-test-run-centjes-e2e-test] client #
  260. 54.11 s [vm-test-run-centjes-e2e-test] client # iPXE (http://ipxe.org) 00:03.0 CA00 PCI2.10 PnP PMM+3EFD1920+3EF31920 CA00
  261. 54.13 s [vm-test-run-centjes-e2e-test] client # Press Ctrl-B to configure iPXE (PCI 00:03.0)...
  262. 54.13 s [vm-test-run-centjes-e2e-test] client #
  263. 54.13 s [vm-test-run-centjes-e2e-test] client #
  264. 54.13 s [vm-test-run-centjes-e2e-test] client #
  265. 54.13 s [vm-test-run-centjes-e2e-test] client #
  266. 54.13 s [vm-test-run-centjes-e2e-test] client # iPXE (http://ipxe.org) 00:09.0 CB00 PCI2.10 PnP PMM 3EFD1920 3EF31920 CB00
  267. 54.15 s [vm-test-run-centjes-e2e-test] client # Press Ctrl-B to configure iPXE (PCI 00:09.0)...
  268. 54.15 s [vm-test-run-centjes-e2e-test] client #
  269. 54.15 s [vm-test-run-centjes-e2e-test] client #
  270. 54.15 s [vm-test-run-centjes-e2e-test] client # Booting from ROM...
  271. 54.17 s [vm-test-run-centjes-e2e-test] client # Probing EDD (edd=off to disable)... ok
  272. 54.33 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
  273. 54.34 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/hk9888llhk4kkgz98y983g2r70r1xhfp-nixos-system-docsserver-test/init regInfo=/nix/store/y80mhfwjfvc24k06yxm5ibfscl6sjw28-closure-info/registration console=ttyS0,115200n8 console=tty0
  274. 54.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-provided physical RAM map:
  275. 54.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
  276. 54.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
  277. 54.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
  278. 54.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000003ffdafff] usable
  279. 54.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x000000003ffdb000-0x000000003fffffff] reserved
  280. 54.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
  281. 54.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
  282. 54.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x000000fd00000000-0x000000ffffffffff] reserved
  283. 54.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] NX (Execute Disable) protection: active
  284. 54.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] APIC: Static calls initialized
  285. 54.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] SMBIOS 2.8 present.
  286. 54.37 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
  287. 54.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] DMI: Memory slots populated: 1/1
  288. 54.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] Hypervisor detected: KVM
  289. 54.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
  290. 54.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
  291. 54.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] kvm-clock: using sched offset of 426888236 cycles
  292. 54.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000001] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
  293. 54.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000003] tsc: Detected 3399.996 MHz processor
  294. 54.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000694] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
  295. 54.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000896] MTRR map: 4 entries (3 fixed + 1 variable; max 19), built from 8 variable MTRRs
  296. 54.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000904] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT
  297. 54.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002669] found SMP MP-table at [mem 0x000f5470-0x000f547f]
  298. 54.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002678] Using GB pages for direct mapping
  299. 54.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002727] RAMDISK: [mem 0x3f3cd000-0x3ffcffff]
  300. 54.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002745] ACPI: Early table checksum verification disabled
  301. 54.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002747] ACPI: RSDP 0x00000000000F5290 000014 (v00 BOCHS )
  302. 54.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002750] ACPI: RSDT 0x000000003FFE23D9 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  303. 54.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002754] ACPI: FACP 0x000000003FFE228D 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  304. 54.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002756] ACPI: DSDT 0x000000003FFE0040 00224D (v01 BOCHS BXPC 00000001 BXPC 00000001)
  305. 54.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002758] ACPI: FACS 0x000000003FFE0000 000040
  306. 54.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002759] ACPI: APIC 0x000000003FFE2301 000078 (v03 BOCHS BXPC 00000001 BXPC 00000001)
  307. 54.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002761] ACPI: HPET 0x000000003FFE2379 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  308. 54.42 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002762] ACPI: WAET 0x000000003FFE23B1 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  309. 54.42 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002763] ACPI: Reserving FACP table memory at [mem 0x3ffe228d-0x3ffe2300]
  310. 54.42 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002764] ACPI: Reserving DSDT table memory at [mem 0x3ffe0040-0x3ffe228c]
  311. 54.42 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002765] ACPI: Reserving FACS table memory at [mem 0x3ffe0000-0x3ffe003f]
  312. 54.42 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002765] ACPI: Reserving APIC table memory at [mem 0x3ffe2301-0x3ffe2378]
  313. 54.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002765] ACPI: Reserving HPET table memory at [mem 0x3ffe2379-0x3ffe23b0]
  314. 54.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002766] ACPI: Reserving WAET table memory at [mem 0x3ffe23b1-0x3ffe23d8]
  315. 54.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003550] No NUMA configuration found
  316. 54.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003551] Faking a node at [mem 0x0000000000000000-0x000000003ffdafff]
  317. 54.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003553] NODE_DATA(0) allocated [mem 0x3ffd58c0-0x3ffdadff]
  318. 54.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003567] Zone ranges:
  319. 54.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003567] DMA [mem 0x0000000000001000-0x0000000000ffffff]
  320. 54.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003568] DMA32 [mem 0x0000000001000000-0x000000003ffdafff]
  321. 54.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003569] Normal empty
  322. 54.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003570] Device empty
  323. 54.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003570] Movable zone start for each node
  324. 54.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003570] Early memory node ranges
  325. 54.45 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003571] node 0: [mem 0x0000000000001000-0x000000000009efff]
  326. 54.45 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003572] node 0: [mem 0x0000000000100000-0x000000003ffdafff]
  327. 54.45 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003573] Initmem setup node 0 [mem 0x0000000000001000-0x000000003ffdafff]
  328. 54.45 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003732] On node 0, zone DMA: 1 pages in unavailable ranges
  329. 54.45 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003744] On node 0, zone DMA: 97 pages in unavailable ranges
  330. 54.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.005429] On node 0, zone DMA32: 37 pages in unavailable ranges
  331. 54.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007058] ACPI: PM-Timer IO Port: 0x608
  332. 54.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007082] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
  333. 54.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007202] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
  334. 54.46 s [vm-test-run-centjes-e2e-test] client # 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
  335. 54.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007204] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
  336. 54.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007206] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
  337. 54.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007207] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
  338. 54.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007207] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
  339. 54.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007208] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
  340. 54.47 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
  341. 54.47 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-provided physical RAM map:
  342. 54.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007210] ACPI: Using ACPI (MADT) for SMP configuration information
  343. 54.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007211] ACPI: HPET id: 0x8086a201 base: 0xfed00000
  344. 54.48 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
  345. 54.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007213] TSC deadline timer available
  346. 54.48 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
  347. 54.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007216] CPU topo: Max. logical packages: 1
  348. 54.48 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
  349. 54.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007217] CPU topo: Max. logical dies: 1
  350. 54.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007217] CPU topo: Max. dies per package: 1
  351. 54.48 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000003ffdafff] usable
  352. 54.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007220] CPU topo: Max. threads per core: 1
  353. 54.48 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x000000003ffdb000-0x000000003fffffff] reserved
  354. 54.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007221] CPU topo: Num. cores per package: 1
  355. 54.49 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
  356. 54.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007221] CPU topo: Num. threads per package: 1
  357. 54.49 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
  358. 54.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007221] CPU topo: Allowing 1 present CPUs plus 0 hotplug CPUs
  359. 54.49 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x000000fd00000000-0x000000ffffffffff] reserved
  360. 54.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007250] kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write()
  361. 54.49 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] NX (Execute Disable) protection: active
  362. 54.49 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] APIC: Static calls initialized
  363. 54.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007305] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]
  364. 54.49 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] SMBIOS 2.8 present.
  365. 54.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007306] PM: hibernation: Registered nosave memory: [mem 0x0009f000-0x000fffff]
  366. 54.50 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
  367. 54.50 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007307] [mem 0x40000000-0xfeffbfff] available for PCI devices
  368. 54.50 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] DMI: Memory slots populated: 1/1
  369. 54.50 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007308] Booting paravirtualized kernel on KVM
  370. 54.50 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] Hypervisor detected: KVM
  371. 54.50 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
  372. 54.50 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007310] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
  373. 54.50 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
  374. 54.50 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] kvm-clock: using sched offset of 409773052 cycles
  375. 54.50 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.010720] setup_percpu: NR_CPUS:384 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1
  376. 54.51 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.010967] percpu: Embedded 116 pages/cpu s294912 r65536 d114688 u2097152
  377. 54.51 s [vm-test-run-centjes-e2e-test] client # [ 0.000001] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
  378. 54.51 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.011040] kvm-guest: PV spinlocks disabled, single CPU
  379. 54.51 s [vm-test-run-centjes-e2e-test] client # [ 0.000004] tsc: Detected 3399.996 MHz processor
  380. 54.51 s [vm-test-run-centjes-e2e-test] client # [ 0.000707] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
  381. 54.51 s [vm-test-run-centjes-e2e-test] client # [ 0.000915] MTRR map: 4 entries (3 fixed + 1 variable; max 19), built from 8 variable MTRRs
  382. 54.51 s [vm-test-run-centjes-e2e-test] client # [ 0.000923] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT
  383. 54.52 s [vm-test-run-centjes-e2e-test] client # [ 0.002726] found SMP MP-table at [mem 0x000f5470-0x000f547f]
  384. 54.52 s [vm-test-run-centjes-e2e-test] client # [ 0.002738] Using GB pages for direct mapping
  385. 54.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.011041] 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/hk9888llhk4kkgz98y983g2r70r1xhfp-nixos-system-docsserver-test/init regInfo=/nix/store/y80mhfwjfvc24k06yxm5ibfscl6sjw28-closure-info/registration console=ttyS0,115200n8 console=tty0
  386. 54.52 s [vm-test-run-centjes-e2e-test] client # [ 0.002818] RAMDISK: [mem 0x3f3cd000-0x3ffcffff]
  387. 54.52 s [vm-test-run-centjes-e2e-test] client # [ 0.002840] ACPI: Early table checksum verification disabled
  388. 54.52 s [vm-test-run-centjes-e2e-test] client # [ 0.002843] ACPI: RSDP 0x00000000000F5290 000014 (v00 BOCHS )
  389. 54.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.011144] Unknown kernel command line parameters "regInfo=/nix/store/y80mhfwjfvc24k06yxm5ibfscl6sjw28-closure-info/registration", will be passed to user space.
  390. 54.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.011158] random: crng init done
  391. 54.52 s [vm-test-run-centjes-e2e-test] client # [ 0.002845] ACPI: RSDT 0x000000003FFE23D9 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  392. 54.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.011210] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
  393. 54.53 s [vm-test-run-centjes-e2e-test] client # [ 0.002849] ACPI: FACP 0x000000003FFE228D 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  394. 54.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.011240] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)
  395. 54.53 s [vm-test-run-centjes-e2e-test] client # [ 0.002852] ACPI: DSDT 0x000000003FFE0040 00224D (v01 BOCHS BXPC 00000001 BXPC 00000001)
  396. 54.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.011277] Fallback order for Node 0: 0
  397. 54.53 s [vm-test-run-centjes-e2e-test] client # [ 0.002854] ACPI: FACS 0x000000003FFE0000 000040
  398. 54.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.011279] Built 1 zonelists, mobility grouping on. Total pages: 262009
  399. 54.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.011279] Policy zone: DMA32
  400. 54.53 s [vm-test-run-centjes-e2e-test] client # [ 0.002855] ACPI: APIC 0x000000003FFE2301 000078 (v03 BOCHS BXPC 00000001 BXPC 00000001)
  401. 54.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.011485] mem auto-init: stack:all(zero), heap alloc:on, heap free:off
  402. 54.54 s [vm-test-run-centjes-e2e-test] client # [ 0.002857] ACPI: HPET 0x000000003FFE2379 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  403. 54.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.013225] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
  404. 54.54 s [vm-test-run-centjes-e2e-test] client # [ 0.002858] ACPI: WAET 0x000000003FFE23B1 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  405. 54.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.013433] allocated 2097152 bytes of page_ext
  406. 54.54 s [vm-test-run-centjes-e2e-test] client # [ 0.002859] ACPI: Reserving FACP table memory at [mem 0x3ffe228d-0x3ffe2300]
  407. 54.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.013444] ftrace: allocating 46208 entries in 181 pages
  408. 54.54 s [vm-test-run-centjes-e2e-test] client # [ 0.002860] ACPI: Reserving DSDT table memory at [mem 0x3ffe0040-0x3ffe228c]
  409. 54.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.020933] ftrace: allocated 181 pages with 5 groups
  410. 54.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.021470] Dynamic Preempt: voluntary
  411. 54.54 s [vm-test-run-centjes-e2e-test] client # [ 0.002861] ACPI: Reserving FACS table memory at [mem 0x3ffe0000-0x3ffe003f]
  412. 54.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.021666] rcu: Preemptible hierarchical RCU implementation.
  413. 54.55 s [vm-test-run-centjes-e2e-test] client # [ 0.002861] ACPI: Reserving APIC table memory at [mem 0x3ffe2301-0x3ffe2378]
  414. 54.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.021667] rcu: RCU event tracing is enabled.
  415. 54.55 s [vm-test-run-centjes-e2e-test] client # [ 0.002862] ACPI: Reserving HPET table memory at [mem 0x3ffe2379-0x3ffe23b0]
  416. 54.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.021667] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1.
  417. 54.55 s [vm-test-run-centjes-e2e-test] client # [ 0.002862] ACPI: Reserving WAET table memory at [mem 0x3ffe23b1-0x3ffe23d8]
  418. 54.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.021668] Trampoline variant of Tasks RCU enabled.
  419. 54.55 s [vm-test-run-centjes-e2e-test] client # [ 0.003490] No NUMA configuration found
  420. 54.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.021669] Rude variant of Tasks RCU enabled.
  421. 54.55 s [vm-test-run-centjes-e2e-test] client # [ 0.003490] Faking a node at [mem 0x0000000000000000-0x000000003ffdafff]
  422. 54.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.021669] Tracing variant of Tasks RCU enabled.
  423. 54.55 s [vm-test-run-centjes-e2e-test] client # [ 0.003492] NODE_DATA(0) allocated [mem 0x3ffd58c0-0x3ffdadff]
  424. 54.56 s [vm-test-run-centjes-e2e-test] client # [ 0.003508] Zone ranges:
  425. 54.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.021669] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.
  426. 54.56 s [vm-test-run-centjes-e2e-test] client # [ 0.003509] DMA [mem 0x0000000000001000-0x0000000000ffffff]
  427. 54.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.021670] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
  428. 54.56 s [vm-test-run-centjes-e2e-test] client # [ 0.003510] DMA32 [mem 0x0000000001000000-0x000000003ffdafff]
  429. 54.56 s [vm-test-run-centjes-e2e-test] client # [ 0.003511] Normal empty
  430. 54.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.021675] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  431. 54.56 s [vm-test-run-centjes-e2e-test] client # [ 0.003511] Device empty
  432. 54.56 s [vm-test-run-centjes-e2e-test] client # [ 0.003512] Movable zone start for each node
  433. 54.56 s [vm-test-run-centjes-e2e-test] client # [ 0.003512] Early memory node ranges
  434. 54.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.021676] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  435. 54.56 s [vm-test-run-centjes-e2e-test] client # [ 0.003513] node 0: [mem 0x0000000000001000-0x000000000009efff]
  436. 54.57 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.021677] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  437. 54.57 s [vm-test-run-centjes-e2e-test] client # [ 0.003514] node 0: [mem 0x0000000000100000-0x000000003ffdafff]
  438. 54.57 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.025128] NR_IRQS: 24832, nr_irqs: 256, preallocated irqs: 16
  439. 54.57 s [vm-test-run-centjes-e2e-test] client # [ 0.003515] Initmem setup node 0 [mem 0x0000000000001000-0x000000003ffdafff]
  440. 54.57 s [vm-test-run-centjes-e2e-test] client # [ 0.003733] On node 0, zone DMA: 1 pages in unavailable ranges
  441. 54.57 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.025380] rcu: srcu_init: Setting srcu_struct sizes based on contention.
  442. 54.57 s [vm-test-run-centjes-e2e-test] client # [ 0.003746] On node 0, zone DMA: 97 pages in unavailable ranges
  443. 54.57 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.025455] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)
  444. 54.57 s [vm-test-run-centjes-e2e-test] client # [ 0.005668] On node 0, zone DMA32: 37 pages in unavailable ranges
  445. 54.57 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.039029] Console: colour VGA+ 80x25
  446. 54.58 s [vm-test-run-centjes-e2e-test] client # [ 0.006974] ACPI: PM-Timer IO Port: 0x608
  447. 54.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.039032] printk: legacy console [tty0] enabled
  448. 54.58 s [vm-test-run-centjes-e2e-test] client # [ 0.006999] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
  449. 54.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.145958] printk: legacy console [ttyS0] enabled
  450. 54.58 s [vm-test-run-centjes-e2e-test] client # [ 0.007084] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
  451. 54.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.397416] ACPI: Core revision 20240827
  452. 54.58 s [vm-test-run-centjes-e2e-test] client # [ 0.007086] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
  453. 54.58 s [vm-test-run-centjes-e2e-test] client # [ 0.007088] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
  454. 54.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.399630] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
  455. 54.58 s [vm-test-run-centjes-e2e-test] client # [ 0.007089] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
  456. 54.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.404011] APIC: Switch to symmetric I/O mode setup
  457. 54.59 s [vm-test-run-centjes-e2e-test] client # [ 0.007089] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
  458. 54.59 s [vm-test-run-centjes-e2e-test] client # [ 0.007090] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
  459. 54.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.407294] x2apic enabled
  460. 54.59 s [vm-test-run-centjes-e2e-test] client # [ 0.007092] ACPI: Using ACPI (MADT) for SMP configuration information
  461. 54.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.409644] APIC: Switched APIC routing to: physical x2apic
  462. 54.59 s [vm-test-run-centjes-e2e-test] client # [ 0.007093] ACPI: HPET id: 0x8086a201 base: 0xfed00000
  463. 54.59 s [vm-test-run-centjes-e2e-test] client # [ 0.007094] TSC deadline timer available
  464. 54.60 s [vm-test-run-centjes-e2e-test] client # [ 0.007098] CPU topo: Max. logical packages: 1
  465. 54.60 s [vm-test-run-centjes-e2e-test] client # [ 0.007099] CPU topo: Max. logical dies: 1
  466. 54.60 s [vm-test-run-centjes-e2e-test] client # [ 0.007099] CPU topo: Max. dies per package: 1
  467. 54.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.416017] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
  468. 54.60 s [vm-test-run-centjes-e2e-test] client # [ 0.007102] CPU topo: Max. threads per core: 1
  469. 54.60 s [vm-test-run-centjes-e2e-test] client # [ 0.007103] CPU topo: Num. cores per package: 1
  470. 54.60 s [vm-test-run-centjes-e2e-test] client # [ 0.007103] CPU topo: Num. threads per package: 1
  471. 54.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.418923] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x31024b3bec5, max_idle_ns: 440795366697 ns
  472. 54.61 s [vm-test-run-centjes-e2e-test] client # [ 0.007103] CPU topo: Allowing 1 present CPUs plus 0 hotplug CPUs
  473. 54.61 s [vm-test-run-centjes-e2e-test] client # [ 0.007132] kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write()
  474. 54.61 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.423787] Calibrating delay loop (skipped) preset value.. 6799.99 BogoMIPS (lpj=3399996)
  475. 54.61 s [vm-test-run-centjes-e2e-test] client # [ 0.007187] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]
  476. 54.61 s [vm-test-run-centjes-e2e-test] client # [ 0.007189] PM: hibernation: Registered nosave memory: [mem 0x0009f000-0x000fffff]
  477. 54.61 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.427048] x86/cpu: User Mode Instruction Prevention (UMIP) activated
  478. 54.61 s [vm-test-run-centjes-e2e-test] client # [ 0.007190] [mem 0x40000000-0xfeffbfff] available for PCI devices
  479. 54.61 s [vm-test-run-centjes-e2e-test] client # [ 0.007191] Booting paravirtualized kernel on KVM
  480. 54.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.429203] Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127
  481. 54.62 s [vm-test-run-centjes-e2e-test] client # [ 0.007192] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
  482. 54.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.430785] Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0
  483. 54.62 s [vm-test-run-centjes-e2e-test] client # [ 0.010608] setup_percpu: NR_CPUS:384 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1
  484. 54.62 s [vm-test-run-centjes-e2e-test] client # [ 0.010885] percpu: Embedded 116 pages/cpu s294912 r65536 d114688 u2097152
  485. 54.62 s [vm-test-run-centjes-e2e-test] client # [ 0.010959] kvm-guest: PV spinlocks disabled, single CPU
  486. 54.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.432795] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
  487. 54.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.434786] Spectre V2 : Mitigation: Retpolines
  488. 54.63 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.436785] Spectre V2 : Spectre v2 / SpectreRSB: Filling RSB on context switch and VMEXIT
  489. 54.63 s [vm-test-run-centjes-e2e-test] client # [ 0.010960] 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
  490. 54.63 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.438785] Spectre V2 : Enabling Restricted Speculation for firmware calls
  491. 54.63 s [vm-test-run-centjes-e2e-test] client # [ 0.011032] Unknown kernel command line parameters "regInfo=/nix/store/j7kn31fka8vp5bhm6sw8hv64iyzix7xw-closure-info/registration", will be passed to user space.
  492. 54.64 s [vm-test-run-centjes-e2e-test] client # [ 0.011046] random: crng init done
  493. 54.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.440787] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
  494. 54.64 s [vm-test-run-centjes-e2e-test] client # [ 0.011105] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
  495. 54.64 s [vm-test-run-centjes-e2e-test] client # [ 0.011136] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)
  496. 54.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.442786] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl
  497. 54.64 s [vm-test-run-centjes-e2e-test] client # [ 0.011172] Fallback order for Node 0: 0
  498. 54.64 s [vm-test-run-centjes-e2e-test] client # [ 0.011174] Built 1 zonelists, mobility grouping on. Total pages: 262009
  499. 54.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.444785] active return thunk: srso_alias_return_thunk
  500. 54.64 s [vm-test-run-centjes-e2e-test] client # [ 0.011175] Policy zone: DMA32
  501. 54.64 s [vm-test-run-centjes-e2e-test] client # [ 0.011464] mem auto-init: stack:all(zero), heap alloc:on, heap free:off
  502. 54.65 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.445785] Speculative Return Stack Overflow: Mitigation: Safe RET
  503. 54.65 s [vm-test-run-centjes-e2e-test] client # [ 0.013369] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
  504. 54.65 s [vm-test-run-centjes-e2e-test] client # [ 0.013661] allocated 2097152 bytes of page_ext
  505. 54.65 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.447785] Transient Scheduler Attacks: Forcing mitigation on in a VM
  506. 54.65 s [vm-test-run-centjes-e2e-test] client # [ 0.013674] ftrace: allocating 46208 entries in 181 pages
  507. 54.65 s [vm-test-run-centjes-e2e-test] client # [ 0.021610] ftrace: allocated 181 pages with 5 groups
  508. 54.65 s [vm-test-run-centjes-e2e-test] client # [ 0.022202] Dynamic Preempt: voluntary
  509. 54.65 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.449785] Transient Scheduler Attacks: Vulnerable: Clear CPU buffers attempted, no microcode
  510. 54.65 s [vm-test-run-centjes-e2e-test] client # [ 0.022443] rcu: Preemptible hierarchical RCU implementation.
  511. 54.65 s [vm-test-run-centjes-e2e-test] client # [ 0.022444] rcu: RCU event tracing is enabled.
  512. 54.66 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.452866] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
  513. 54.66 s [vm-test-run-centjes-e2e-test] client # [ 0.022444] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1.
  514. 54.66 s [vm-test-run-centjes-e2e-test] client # [ 0.022446] Trampoline variant of Tasks RCU enabled.
  515. 54.66 s [vm-test-run-centjes-e2e-test] client # [ 0.022446] Rude variant of Tasks RCU enabled.
  516. 54.66 s [vm-test-run-centjes-e2e-test] client # [ 0.022446] Tracing variant of Tasks RCU enabled.
  517. 54.66 s [vm-test-run-centjes-e2e-test] client # [ 0.022447] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.
  518. 54.66 s [vm-test-run-centjes-e2e-test] client # [ 0.022447] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
  519. 54.67 s [vm-test-run-centjes-e2e-test] client # [ 0.022455] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  520. 54.67 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.454785] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
  521. 54.67 s [vm-test-run-centjes-e2e-test] client # [ 0.022456] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  522. 54.67 s [vm-test-run-centjes-e2e-test] client # [ 0.022457] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  523. 54.67 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.456785] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
  524. 54.67 s [vm-test-run-centjes-e2e-test] client # [ 0.025887] NR_IRQS: 24832, nr_irqs: 256, preallocated irqs: 16
  525. 54.67 s [vm-test-run-centjes-e2e-test] client # [ 0.026145] rcu: srcu_init: Setting srcu_struct sizes based on contention.
  526. 54.68 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.458785] x86/fpu: Supporting XSAVE feature 0x200: 'Protection Keys User registers'
  527. 54.68 s [vm-test-run-centjes-e2e-test] client # [ 0.026219] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)
  528. 54.68 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.460785] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256
  529. 54.68 s [vm-test-run-centjes-e2e-test] client # [ 0.038343] Console: colour VGA+ 80x25
  530. 54.68 s [vm-test-run-centjes-e2e-test] client # [ 0.038347] printk: legacy console [tty0] enabled
  531. 54.68 s [vm-test-run-centjes-e2e-test] client # [ 0.140901] printk: legacy console [ttyS0] enabled
  532. 54.68 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.462785] x86/fpu: xstate_offset[9]: 832, xstate_sizes[9]: 8
  533. 54.68 s [vm-test-run-centjes-e2e-test] client # [ 0.364925] ACPI: Core revision 20240827
  534. 54.69 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.464785] x86/fpu: Enabled xstate features 0x207, context size is 840 bytes, using 'compacted' format.
  535. 54.69 s [vm-test-run-centjes-e2e-test] client # [ 0.366865] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
  536. 54.69 s [vm-test-run-centjes-e2e-test] client # [ 0.370630] APIC: Switch to symmetric I/O mode setup
  537. 54.69 s [vm-test-run-centjes-e2e-test] client # [ 0.373490] x2apic enabled
  538. 54.69 s [vm-test-run-centjes-e2e-test] client # [ 0.375668] APIC: Switched APIC routing to: physical x2apic
  539. 54.70 s [vm-test-run-centjes-e2e-test] client # [ 0.381561] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
  540. 54.70 s [vm-test-run-centjes-e2e-test] client # [ 0.384081] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x31024b3bec5, max_idle_ns: 440795366697 ns
  541. 54.71 s [vm-test-run-centjes-e2e-test] client # [ 0.388320] Calibrating delay loop (skipped) preset value.. 6799.99 BogoMIPS (lpj=3399996)
  542. 54.71 s [vm-test-run-centjes-e2e-test] client # [ 0.390867] x86/cpu: User Mode Instruction Prevention (UMIP) activated
  543. 54.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.491070] Freeing SMP alternatives memory: 40K
  544. 54.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.491787] pid_max: default: 32768 minimum: 301
  545. 54.71 s [vm-test-run-centjes-e2e-test] client # [ 0.392731] Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127
  546. 54.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.493827] LSM: initializing lsm=capability,landlock,yama,bpf
  547. 54.72 s [vm-test-run-centjes-e2e-test] client # [ 0.394318] Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0
  548. 54.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.495856] landlock: Up and running.
  549. 54.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.497786] Yama: becoming mindful.
  550. 54.72 s [vm-test-run-centjes-e2e-test] client # [ 0.395328] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
  551. 54.72 s [vm-test-run-centjes-e2e-test] client # [ 0.397319] Spectre V2 : Mitigation: Retpolines
  552. 54.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.499974] LSM support for eBPF active
  553. 54.73 s [vm-test-run-centjes-e2e-test] client # [ 0.398318] Spectre V2 : Spectre v2 / SpectreRSB: Filling RSB on context switch and VMEXIT
  554. 54.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.501806] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
  555. 54.73 s [vm-test-run-centjes-e2e-test] client # [ 0.400318] Spectre V2 : Enabling Restricted Speculation for firmware calls
  556. 54.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.503787] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
  557. 54.73 s [vm-test-run-centjes-e2e-test] client # [ 0.402320] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
  558. 54.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.506146] smpboot: CPU0: AMD Ryzen 9 5950X 16-Core Processor (family: 0x19, model: 0x21, stepping: 0x0)
  559. 54.73 s [vm-test-run-centjes-e2e-test] client # [ 0.404319] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl
  560. 54.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.507998] Performance Events: Fam17h+ core perfctr, AMD PMU driver.
  561. 54.74 s [vm-test-run-centjes-e2e-test] client # [ 0.406318] active return thunk: srso_alias_return_thunk
  562. 54.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.509800] ... version: 0
  563. 54.74 s [vm-test-run-centjes-e2e-test] client # [ 0.407318] Speculative Return Stack Overflow: Mitigation: Safe RET
  564. 54.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.510793] ... bit width: 48
  565. 54.74 s [vm-test-run-centjes-e2e-test] client # [ 0.409318] Transient Scheduler Attacks: Forcing mitigation on in a VM
  566. 54.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.511793] ... generic registers: 6
  567. 54.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.512793] ... value mask: 0000ffffffffffff
  568. 54.75 s [vm-test-run-centjes-e2e-test] client # [ 0.411318] Transient Scheduler Attacks: Vulnerable: Clear CPU buffers attempted, no microcode
  569. 54.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.513793] ... max period: 00007fffffffffff
  570. 54.75 s [vm-test-run-centjes-e2e-test] client # [ 0.414354] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
  571. 54.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.514793] ... fixed-purpose events: 0
  572. 54.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.515793] ... event mask: 000000000000003f
  573. 54.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.516863] signal: max sigframe size: 3376
  574. 54.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.517823] rcu: Hierarchical SRCU implementation.
  575. 54.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.518794] rcu: Max phase no-delay instances is 400.
  576. 54.76 s [vm-test-run-centjes-e2e-test] client # [ 0.416318] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
  577. 54.76 s [vm-test-run-centjes-e2e-test] client # [ 0.418318] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
  578. 54.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.522819] smp: Bringing up secondary CPUs ...
  579. 54.77 s [vm-test-run-centjes-e2e-test] client # [ 0.419318] x86/fpu: Supporting XSAVE feature 0x200: 'Protection Keys User registers'
  580. 54.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.523803] smp: Brought up 1 node, 1 CPU
  581. 54.77 s [vm-test-run-centjes-e2e-test] client # [ 0.421318] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256
  582. 54.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.524795] smpboot: Total of 1 processors activated (6799.99 BogoMIPS)
  583. 54.77 s [vm-test-run-centjes-e2e-test] client # [ 0.423318] x86/fpu: xstate_offset[9]: 832, xstate_sizes[9]: 8
  584. 54.77 s [vm-test-run-centjes-e2e-test] client # [ 0.425318] x86/fpu: Enabled xstate features 0x207, context size is 840 bytes, using 'compacted' format.
  585. 54.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.526118] Memory: 962132K/1048036K available (16384K kernel code, 2645K rwdata, 12580K rodata, 3408K init, 3360K bss, 78836K reserved, 0K cma-reserved)
  586. 54.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.527876] devtmpfs: initialized
  587. 54.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.528842] x86/mm: Memory block size: 128MB
  588. 54.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.530214] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
  589. 54.79 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.531796] futex hash table entries: 256 (order: 2, 16384 bytes, linear)
  590. 54.79 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.532840] pinctrl core: initialized pinctrl subsystem
  591. 54.79 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.534114] PM: RTC time: 13:42:35, date: 2026-04-27
  592. 54.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.536361] NET: Registered PF_NETLINK/PF_ROUTE protocol family
  593. 54.80 s [vm-test-run-centjes-e2e-test] client # [ 0.451524] Freeing SMP alternatives memory: 40K
  594. 54.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.537924] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations
  595. 54.80 s [vm-test-run-centjes-e2e-test] client # [ 0.452320] pid_max: default: 32768 minimum: 301
  596. 54.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.539802] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
  597. 54.80 s [vm-test-run-centjes-e2e-test] client # [ 0.453365] LSM: initializing lsm=capability,landlock,yama,bpf
  598. 54.81 s [vm-test-run-centjes-e2e-test] client # [ 0.455395] landlock: Up and running.
  599. 54.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.541799] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
  600. 54.81 s [vm-test-run-centjes-e2e-test] client # [ 0.457318] Yama: becoming mindful.
  601. 54.81 s [vm-test-run-centjes-e2e-test] client # [ 0.459440] LSM support for eBPF active
  602. 54.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.543801] audit: initializing netlink subsys (disabled)
  603. 54.81 s [vm-test-run-centjes-e2e-test] client # [ 0.460342] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
  604. 54.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.544825] audit: type=2000 audit(1777297355.059:1): state=initialized audit_enabled=0 res=1
  605. 54.82 s [vm-test-run-centjes-e2e-test] client # [ 0.462320] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
  606. 54.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.546891] thermal_sys: Registered thermal governor 'bang_bang'
  607. 54.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.546893] thermal_sys: Registered thermal governor 'step_wise'
  608. 54.82 s [vm-test-run-centjes-e2e-test] client # [ 0.465626] smpboot: CPU0: AMD Ryzen 9 5950X 16-Core Processor (family: 0x19, model: 0x21, stepping: 0x0)
  609. 54.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.547794] thermal_sys: Registered thermal governor 'user_space'
  610. 54.82 s [vm-test-run-centjes-e2e-test] client # [ 0.467541] Performance Events: Fam17h+ core perfctr, AMD PMU driver.
  611. 54.82 s [vm-test-run-centjes-e2e-test] client # [ 0.469338] ... version: 0
  612. 54.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.548806] cpuidle: using governor menu
  613. 54.83 s [vm-test-run-centjes-e2e-test] client # [ 0.470326] ... bit width: 48
  614. 54.83 s [vm-test-run-centjes-e2e-test] client # [ 0.471326] ... generic registers: 6
  615. 54.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.552579] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
  616. 54.83 s [vm-test-run-centjes-e2e-test] client # [ 0.472326] ... value mask: 0000ffffffffffff
  617. 54.83 s [vm-test-run-centjes-e2e-test] client # [ 0.473326] ... max period: 00007fffffffffff
  618. 54.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.554021] PCI: Using configuration type 1 for base access
  619. 54.83 s [vm-test-run-centjes-e2e-test] client # [ 0.474326] ... fixed-purpose events: 0
  620. 54.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.555793] PCI: Using configuration type 1 for extended access
  621. 54.84 s [vm-test-run-centjes-e2e-test] client # [ 0.475326] ... event mask: 000000000000003f
  622. 54.84 s [vm-test-run-centjes-e2e-test] client # [ 0.476397] signal: max sigframe size: 3376
  623. 54.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.556920] kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible.
  624. 54.84 s [vm-test-run-centjes-e2e-test] client # [ 0.477354] rcu: Hierarchical SRCU implementation.
  625. 54.84 s [vm-test-run-centjes-e2e-test] client # [ 0.478327] rcu: Max phase no-delay instances is 400.
  626. 54.85 s [vm-test-run-centjes-e2e-test] client # [ 0.482191] smp: Bringing up secondary CPUs ...
  627. 54.85 s [vm-test-run-centjes-e2e-test] client # [ 0.483335] smp: Brought up 1 node, 1 CPU
  628. 54.85 s [vm-test-run-centjes-e2e-test] client # [ 0.484328] smpboot: Total of 1 processors activated (6799.99 BogoMIPS)
  629. 54.86 s [vm-test-run-centjes-e2e-test] client # [ 0.485785] Memory: 962140K/1048036K available (16384K kernel code, 2645K rwdata, 12580K rodata, 3408K init, 3360K bss, 78836K reserved, 0K cma-reserved)
  630. 54.86 s [vm-test-run-centjes-e2e-test] client # [ 0.487413] devtmpfs: initialized
  631. 54.86 s [vm-test-run-centjes-e2e-test] client # [ 0.488386] x86/mm: Memory block size: 128MB
  632. 54.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.577991] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages
  633. 54.86 s [vm-test-run-centjes-e2e-test] client # [ 0.489753] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
  634. 54.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.579793] HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page
  635. 54.87 s [vm-test-run-centjes-e2e-test] client # [ 0.491328] futex hash table entries: 256 (order: 2, 16384 bytes, linear)
  636. 54.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.580794] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
  637. 54.87 s [vm-test-run-centjes-e2e-test] client # [ 0.492378] pinctrl core: initialized pinctrl subsystem
  638. 54.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.581793] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page
  639. 54.87 s [vm-test-run-centjes-e2e-test] client # [ 0.493586] PM: RTC time: 13:42:34, date: 2026-04-27
  640. 54.87 s [vm-test-run-centjes-e2e-test] client # [ 0.494882] NET: Registered PF_NETLINK/PF_ROUTE protocol family
  641. 54.88 s [vm-test-run-centjes-e2e-test] client # [ 0.496478] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations
  642. 54.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.587445] ACPI: Added _OSI(Module Device)
  643. 54.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.588793] ACPI: Added _OSI(Processor Device)
  644. 54.88 s [vm-test-run-centjes-e2e-test] client # [ 0.498335] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
  645. 54.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.589794] ACPI: Added _OSI(Processor Aggregator Device)
  646. 54.88 s [vm-test-run-centjes-e2e-test] client # [ 0.499332] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
  647. 54.89 s [vm-test-run-centjes-e2e-test] client # [ 0.501333] audit: initializing netlink subsys (disabled)
  648. 54.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.592403] ACPI: 1 ACPI AML tables successfully acquired and loaded
  649. 54.89 s [vm-test-run-centjes-e2e-test] client # [ 0.502355] audit: type=2000 audit(1777297355.187:1): state=initialized audit_enabled=0 res=1
  650. 54.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.595006] ACPI: Interpreter enabled
  651. 54.89 s [vm-test-run-centjes-e2e-test] client # [ 0.504425] thermal_sys: Registered thermal governor 'bang_bang'
  652. 54.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.595806] ACPI: PM: (supports S0 S3 S4 S5)
  653. 54.89 s [vm-test-run-centjes-e2e-test] client # [ 0.504426] thermal_sys: Registered thermal governor 'step_wise'
  654. 54.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.596794] ACPI: Using IOAPIC for interrupt routing
  655. 54.90 s [vm-test-run-centjes-e2e-test] client # [ 0.505327] thermal_sys: Registered thermal governor 'user_space'
  656. 54.90 s [vm-test-run-centjes-e2e-test] client # [ 0.506338] cpuidle: using governor menu
  657. 54.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.597806] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
  658. 54.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.599793] PCI: Using E820 reservations for host bridge windows
  659. 54.90 s [vm-test-run-centjes-e2e-test] client # [ 0.509852] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
  660. 54.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.600938] ACPI: Enabled 2 GPEs in block 00 to 0F
  661. 54.91 s [vm-test-run-centjes-e2e-test] client # [ 0.511562] PCI: Using configuration type 1 for base access
  662. 54.91 s [vm-test-run-centjes-e2e-test] client # [ 0.512329] PCI: Using configuration type 1 for extended access
  663. 54.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.605356] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
  664. 54.91 s [vm-test-run-centjes-e2e-test] client # [ 0.513491] kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible.
  665. 54.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.606797] acpi PNP0A03:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3]
  666. 54.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.609100] acpiphp: Slot [3] registered
  667. 54.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.609832] acpiphp: Slot [4] registered
  668. 54.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.610831] acpiphp: Slot [5] registered
  669. 54.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.611829] acpiphp: Slot [6] registered
  670. 54.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.612830] acpiphp: Slot [7] registered
  671. 54.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.613830] acpiphp: Slot [8] registered
  672. 54.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.614831] acpiphp: Slot [9] registered
  673. 54.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.615853] acpiphp: Slot [10] registered
  674. 54.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.616830] acpiphp: Slot [11] registered
  675. 54.93 s [vm-test-run-centjes-e2e-test] client # [ 0.534403] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages
  676. 54.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.617830] acpiphp: Slot [12] registered
  677. 54.94 s [vm-test-run-centjes-e2e-test] client # [ 0.535326] HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page
  678. 54.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.618831] acpiphp: Slot [13] registered
  679. 54.94 s [vm-test-run-centjes-e2e-test] client # [ 0.536327] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
  680. 54.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.619829] acpiphp: Slot [14] registered
  681. 54.94 s [vm-test-run-centjes-e2e-test] client # [ 0.537326] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page
  682. 54.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.620829] acpiphp: Slot [15] registered
  683. 54.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.621831] acpiphp: Slot [16] registered
  684. 54.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.622830] acpiphp: Slot [17] registered
  685. 54.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.623829] acpiphp: Slot [18] registered
  686. 54.95 s [vm-test-run-centjes-e2e-test] client # [ 0.543419] ACPI: Added _OSI(Module Device)
  687. 54.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.624830] acpiphp: Slot [19] registered
  688. 54.95 s [vm-test-run-centjes-e2e-test] client # [ 0.544331] ACPI: Added _OSI(Processor Device)
  689. 54.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.625831] acpiphp: Slot [20] registered
  690. 54.95 s [vm-test-run-centjes-e2e-test] client # [ 0.545329] ACPI: Added _OSI(Processor Aggregator Device)
  691. 54.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.626852] acpiphp: Slot [21] registered
  692. 54.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.627831] acpiphp: Slot [22] registered
  693. 54.96 s [vm-test-run-centjes-e2e-test] client # [ 0.547958] ACPI: 1 ACPI AML tables successfully acquired and loaded
  694. 54.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.628830] acpiphp: Slot [23] registered
  695. 54.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.629831] acpiphp: Slot [24] registered
  696. 54.96 s [vm-test-run-centjes-e2e-test] client # [ 0.550537] ACPI: Interpreter enabled
  697. 54.96 s [vm-test-run-centjes-e2e-test] client # [ 0.551341] ACPI: PM: (supports S0 S3 S4 S5)
  698. 54.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.630829] acpiphp: Slot [25] registered
  699. 54.96 s [vm-test-run-centjes-e2e-test] client # [ 0.552335] ACPI: Using IOAPIC for interrupt routing
  700. 54.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.631830] acpiphp: Slot [26] registered
  701. 54.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.632829] acpiphp: Slot [27] registered
  702. 54.97 s [vm-test-run-centjes-e2e-test] client # [ 0.553345] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
  703. 54.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.633831] acpiphp: Slot [28] registered
  704. 54.97 s [vm-test-run-centjes-e2e-test] client # [ 0.555326] PCI: Using E820 reservations for host bridge windows
  705. 54.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.634829] acpiphp: Slot [29] registered
  706. 54.97 s [vm-test-run-centjes-e2e-test] client # [ 0.556464] ACPI: Enabled 2 GPEs in block 00 to 0F
  707. 54.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.635829] acpiphp: Slot [30] registered
  708. 54.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.636831] acpiphp: Slot [31] registered
  709. 54.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.637823] PCI host bridge to bus 0000:00
  710. 54.98 s [vm-test-run-centjes-e2e-test] client # [ 0.560729] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
  711. 54.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.638798] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]
  712. 54.98 s [vm-test-run-centjes-e2e-test] client # [ 0.562330] acpi PNP0A03:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3]
  713. 54.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.639794] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]
  714. 54.98 s [vm-test-run-centjes-e2e-test] client # [ 0.564616] acpiphp: Slot [3] registered
  715. 54.99 s [vm-test-run-centjes-e2e-test] client # [ 0.565358] acpiphp: Slot [4] registered
  716. 54.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.640794] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
  717. 54.99 s [vm-test-run-centjes-e2e-test] client # [ 0.566359] acpiphp: Slot [5] registered
  718. 54.99 s [vm-test-run-centjes-e2e-test] client # [ 0.567358] acpiphp: Slot [6] registered
  719. 54.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.642794] pci_bus 0000:00: root bus resource [mem 0x40000000-0xfebfffff window]
  720. 54.99 s [vm-test-run-centjes-e2e-test] client # [ 0.568357] acpiphp: Slot [7] registered
  721. 54.99 s [vm-test-run-centjes-e2e-test] client # [ 0.569358] acpiphp: Slot [8] registered
  722. 54.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.644794] pci_bus 0000:00: root bus resource [mem 0x100000000-0x17fffffff window]
  723. 54.99 s [vm-test-run-centjes-e2e-test] client # [ 0.570358] acpiphp: Slot [9] registered
  724. 55.00 s [vm-test-run-centjes-e2e-test] client # [ 0.571365] acpiphp: Slot [10] registered
  725. 55.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.646794] pci_bus 0000:00: root bus resource [bus 00-ff]
  726. 55.00 s [vm-test-run-centjes-e2e-test] client # [ 0.572359] acpiphp: Slot [11] registered
  727. 55.00 s [vm-test-run-centjes-e2e-test] client # [ 0.573373] acpiphp: Slot [12] registered
  728. 55.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.648274] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 conventional PCI endpoint
  729. 55.00 s [vm-test-run-centjes-e2e-test] client # [ 0.574391] acpiphp: Slot [13] registered
  730. 55.00 s [vm-test-run-centjes-e2e-test] client # [ 0.575364] acpiphp: Slot [14] registered
  731. 55.00 s [vm-test-run-centjes-e2e-test] client # [ 0.576370] acpiphp: Slot [15] registered
  732. 55.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.650945] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 conventional PCI endpoint
  733. 55.01 s [vm-test-run-centjes-e2e-test] client # [ 0.577364] acpiphp: Slot [16] registered
  734. 55.01 s [vm-test-run-centjes-e2e-test] client # [ 0.578363] acpiphp: Slot [17] registered
  735. 55.01 s [vm-test-run-centjes-e2e-test] client # [ 0.579362] acpiphp: Slot [18] registered
  736. 55.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.654384] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 conventional PCI endpoint
  737. 55.01 s [vm-test-run-centjes-e2e-test] client # [ 0.580365] acpiphp: Slot [19] registered
  738. 55.01 s [vm-test-run-centjes-e2e-test] client # [ 0.581367] acpiphp: Slot [20] registered
  739. 55.02 s [vm-test-run-centjes-e2e-test] client # [ 0.582365] acpiphp: Slot [21] registered
  740. 55.02 s [vm-test-run-centjes-e2e-test] client # [ 0.583364] acpiphp: Slot [22] registered
  741. 55.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.659293] pci 0000:00:01.1: BAR 4 [io 0xc1e0-0xc1ef]
  742. 55.02 s [vm-test-run-centjes-e2e-test] client # [ 0.584364] acpiphp: Slot [23] registered
  743. 55.02 s [vm-test-run-centjes-e2e-test] client # [ 0.585369] acpiphp: Slot [24] registered
  744. 55.02 s [vm-test-run-centjes-e2e-test] client # [ 0.586363] acpiphp: Slot [25] registered
  745. 55.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.662396] pci 0000:00:01.1: BAR 0 [io 0x01f0-0x01f7]: legacy IDE quirk
  746. 55.02 s [vm-test-run-centjes-e2e-test] client # [ 0.587365] acpiphp: Slot [26] registered
  747. 55.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.663794] pci 0000:00:01.1: BAR 1 [io 0x03f6]: legacy IDE quirk
  748. 55.03 s [vm-test-run-centjes-e2e-test] client # [ 0.588366] acpiphp: Slot [27] registered
  749. 55.03 s [vm-test-run-centjes-e2e-test] client # [ 0.589372] acpiphp: Slot [28] registered
  750. 55.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.664794] pci 0000:00:01.1: BAR 2 [io 0x0170-0x0177]: legacy IDE quirk
  751. 55.03 s [vm-test-run-centjes-e2e-test] client # [ 0.590372] acpiphp: Slot [29] registered
  752. 55.03 s [vm-test-run-centjes-e2e-test] client # [ 0.591372] acpiphp: Slot [30] registered
  753. 55.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.665794] pci 0000:00:01.1: BAR 3 [io 0x0376]: legacy IDE quirk
  754. 55.03 s [vm-test-run-centjes-e2e-test] client # [ 0.592371] acpiphp: Slot [31] registered
  755. 55.03 s [vm-test-run-centjes-e2e-test] client # [ 0.593354] PCI host bridge to bus 0000:00
  756. 55.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.667146] pci 0000:00:01.2: [8086:7020] type 00 class 0x0c0300 conventional PCI endpoint
  757. 55.04 s [vm-test-run-centjes-e2e-test] client # [ 0.594335] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]
  758. 55.04 s [vm-test-run-centjes-e2e-test] client # [ 0.595327] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]
  759. 55.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.671625] pci 0000:00:01.2: BAR 4 [io 0xc100-0xc11f]
  760. 55.04 s [vm-test-run-centjes-e2e-test] client # [ 0.596330] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
  761. 55.05 s [vm-test-run-centjes-e2e-test] client # [ 0.597330] pci_bus 0000:00: root bus resource [mem 0x40000000-0xfebfffff window]
  762. 55.05 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.675239] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 conventional PCI endpoint
  763. 55.05 s [vm-test-run-centjes-e2e-test] client # [ 0.599331] pci_bus 0000:00: root bus resource [mem 0x100000000-0x17fffffff window]
  764. 55.05 s [vm-test-run-centjes-e2e-test] client # [ 0.601330] pci_bus 0000:00: root bus resource [bus 00-ff]
  765. 55.05 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.678070] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI
  766. 55.06 s [vm-test-run-centjes-e2e-test] client # [ 0.602715] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 conventional PCI endpoint
  767. 55.06 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.679817] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB
  768. 55.06 s [vm-test-run-centjes-e2e-test] client # [ 0.605327] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 conventional PCI endpoint
  769. 55.06 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.681361] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000 conventional PCI endpoint
  770. 55.07 s [vm-test-run-centjes-e2e-test] client # [ 0.608787] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 conventional PCI endpoint
  771. 55.07 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.684487] pci 0000:00:02.0: BAR 0 [mem 0xfd000000-0xfdffffff pref]
  772. 55.07 s [vm-test-run-centjes-e2e-test] client # [ 0.614114] pci 0000:00:01.1: BAR 4 [io 0xc1e0-0xc1ef]
  773. 55.07 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.687816] pci 0000:00:02.0: BAR 2 [mem 0xfebd0000-0xfebd0fff]
  774. 55.08 s [vm-test-run-centjes-e2e-test] client # [ 0.616739] pci 0000:00:01.1: BAR 0 [io 0x01f0-0x01f7]: legacy IDE quirk
  775. 55.08 s [vm-test-run-centjes-e2e-test] client # [ 0.618330] pci 0000:00:01.1: BAR 1 [io 0x03f6]: legacy IDE quirk
  776. 55.08 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.692814] pci 0000:00:02.0: ROM [mem 0xfebc0000-0xfebcffff pref]
  777. 55.08 s [vm-test-run-centjes-e2e-test] client # [ 0.619327] pci 0000:00:01.1: BAR 2 [io 0x0170-0x0177]: legacy IDE quirk
  778. 55.08 s [vm-test-run-centjes-e2e-test] client # [ 0.620330] pci 0000:00:01.1: BAR 3 [io 0x0376]: legacy IDE quirk
  779. 55.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.693931] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
  780. 55.09 s [vm-test-run-centjes-e2e-test] client # [ 0.621658] pci 0000:00:01.2: [8086:7020] type 00 class 0x0c0300 conventional PCI endpoint
  781. 55.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.696517] pci 0000:00:03.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
  782. 55.20 s [vm-test-run-centjes-e2e-test] client # [ 0.626058] pci 0000:00:01.2: BAR 4 [io 0xc100-0xc11f]
  783. 55.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.698793] pci 0000:00:03.0: BAR 0 [io 0xc120-0xc13f]
  784. 55.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.700793] pci 0000:00:03.0: BAR 1 [mem 0xfebd1000-0xfebd1fff]
  785. 55.20 s [vm-test-run-centjes-e2e-test] client # [ 0.629402] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 conventional PCI endpoint
  786. 55.20 s [vm-test-run-centjes-e2e-test] client # [ 0.632365] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI
  787. 55.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.705793] pci 0000:00:03.0: BAR 4 [mem 0xfe000000-0xfe003fff 64bit pref]
  788. 55.20 s [vm-test-run-centjes-e2e-test] client # [ 0.634354] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB
  789. 55.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.707793] pci 0000:00:03.0: ROM [mem 0xfeb40000-0xfeb7ffff pref]
  790. 55.20 s [vm-test-run-centjes-e2e-test] client # [ 0.635814] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000 conventional PCI endpoint
  791. 55.20 s [vm-test-run-centjes-e2e-test] client # [ 0.639079] pci 0000:00:02.0: BAR 0 [mem 0xfd000000-0xfdffffff pref]
  792. 55.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.711350] pci 0000:00:04.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
  793. 55.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.713793] pci 0000:00:04.0: BAR 0 [io 0xc140-0xc15f]
  794. 55.20 s [vm-test-run-centjes-e2e-test] client # [ 0.642359] pci 0000:00:02.0: BAR 2 [mem 0xfebd0000-0xfebd0fff]
  795. 55.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.715794] pci 0000:00:04.0: BAR 1 [mem 0xfebd2000-0xfebd2fff]
  796. 55.20 s [vm-test-run-centjes-e2e-test] client # [ 0.648359] pci 0000:00:02.0: ROM [mem 0xfebc0000-0xfebcffff pref]
  797. 55.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.720478] pci 0000:00:04.0: BAR 4 [mem 0xfe004000-0xfe007fff 64bit pref]
  798. 55.20 s [vm-test-run-centjes-e2e-test] client # [ 0.649494] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
  799. 55.20 s [vm-test-run-centjes-e2e-test] client # [ 0.651952] pci 0000:00:03.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
  800. 55.20 s [vm-test-run-centjes-e2e-test] client # [ 0.654326] pci 0000:00:03.0: BAR 0 [io 0xc120-0xc13f]
  801. 55.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.725423] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  802. 55.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.727793] pci 0000:00:05.0: BAR 0 [io 0xc080-0xc0bf]
  803. 55.20 s [vm-test-run-centjes-e2e-test] client # [ 0.656326] pci 0000:00:03.0: BAR 1 [mem 0xfebd1000-0xfebd1fff]
  804. 55.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.729803] pci 0000:00:05.0: BAR 1 [mem 0xfebd3000-0xfebd3fff]
  805. 55.20 s [vm-test-run-centjes-e2e-test] client # [ 0.661342] pci 0000:00:03.0: BAR 4 [mem 0xfe000000-0xfe003fff 64bit pref]
  806. 55.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.733329] pci 0000:00:05.0: BAR 4 [mem 0xfe008000-0xfe00bfff 64bit pref]
  807. 55.20 s [vm-test-run-centjes-e2e-test] client # [ 0.664331] pci 0000:00:03.0: ROM [mem 0xfeb40000-0xfeb7ffff pref]
  808. 55.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.738336] pci 0000:00:06.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  809. 55.20 s [vm-test-run-centjes-e2e-test] client # [ 0.668567] pci 0000:00:04.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
  810. 55.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.740752] pci 0000:00:06.0: BAR 0 [io 0xc160-0xc17f]
  811. 55.20 s [vm-test-run-centjes-e2e-test] client # [ 0.671327] pci 0000:00:04.0: BAR 0 [io 0xc140-0xc15f]
  812. 55.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.742638] pci 0000:00:06.0: BAR 1 [mem 0xfebd4000-0xfebd4fff]
  813. 55.20 s [vm-test-run-centjes-e2e-test] client # [ 0.674326] pci 0000:00:04.0: BAR 1 [mem 0xfebd2000-0xfebd2fff]
  814. 55.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.746331] pci 0000:00:06.0: BAR 4 [mem 0xfe00c000-0xfe00ffff 64bit pref]
  815. 55.20 s [vm-test-run-centjes-e2e-test] client # [ 0.678326] pci 0000:00:04.0: BAR 4 [mem 0xfe004000-0xfe007fff 64bit pref]
  816. 55.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.751391] pci 0000:00:07.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  817. 55.20 s [vm-test-run-centjes-e2e-test] client # [ 0.683566] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  818. 55.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.753731] pci 0000:00:07.0: BAR 0 [io 0xc180-0xc19f]
  819. 55.20 s [vm-test-run-centjes-e2e-test] client # [ 0.686327] pci 0000:00:05.0: BAR 0 [io 0xc080-0xc0bf]
  820. 55.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.755711] pci 0000:00:07.0: BAR 1 [mem 0xfebd5000-0xfebd5fff]
  821. 55.20 s [vm-test-run-centjes-e2e-test] client # [ 0.689327] pci 0000:00:05.0: BAR 1 [mem 0xfebd3000-0xfebd3fff]
  822. 55.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.759320] pci 0000:00:07.0: BAR 4 [mem 0xfe010000-0xfe013fff 64bit pref]
  823. 55.20 s [vm-test-run-centjes-e2e-test] client # [ 0.693327] pci 0000:00:05.0: BAR 4 [mem 0xfe008000-0xfe00bfff 64bit pref]
  824. 55.21 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.765236] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint
  825. 55.21 s [vm-test-run-centjes-e2e-test] client # [ 0.698542] pci 0000:00:06.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  826. 55.21 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.767794] pci 0000:00:08.0: BAR 0 [io 0xc000-0xc07f]
  827. 55.21 s [vm-test-run-centjes-e2e-test] client # [ 0.701326] pci 0000:00:06.0: BAR 0 [io 0xc160-0xc17f]
  828. 55.21 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.769793] pci 0000:00:08.0: BAR 1 [mem 0xfebd6000-0xfebd6fff]
  829. 55.22 s [vm-test-run-centjes-e2e-test] client # [ 0.704327] pci 0000:00:06.0: BAR 1 [mem 0xfebd4000-0xfebd4fff]
  830. 55.22 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.773794] pci 0000:00:08.0: BAR 4 [mem 0xfe014000-0xfe017fff 64bit pref]
  831. 55.22 s [vm-test-run-centjes-e2e-test] client # [ 0.708326] pci 0000:00:06.0: BAR 4 [mem 0xfe00c000-0xfe00ffff 64bit pref]
  832. 55.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.778836] pci 0000:00:09.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
  833. 55.23 s [vm-test-run-centjes-e2e-test] client # [ 0.713520] pci 0000:00:07.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  834. 55.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.781793] pci 0000:00:09.0: BAR 0 [io 0xc1a0-0xc1bf]
  835. 55.23 s [vm-test-run-centjes-e2e-test] client # [ 0.716326] pci 0000:00:07.0: BAR 0 [io 0xc180-0xc19f]
  836. 55.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.783653] pci 0000:00:09.0: BAR 1 [mem 0xfebd7000-0xfebd7fff]
  837. 55.24 s [vm-test-run-centjes-e2e-test] client # [ 0.719326] pci 0000:00:07.0: BAR 1 [mem 0xfebd5000-0xfebd5fff]
  838. 55.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.787238] pci 0000:00:09.0: BAR 4 [mem 0xfe018000-0xfe01bfff 64bit pref]
  839. 55.24 s [vm-test-run-centjes-e2e-test] client # [ 0.723326] pci 0000:00:07.0: BAR 4 [mem 0xfe010000-0xfe013fff 64bit pref]
  840. 55.25 s [vm-test-run-centjes-e2e-test] client # [ 0.727552] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint
  841. 55.26 s [vm-test-run-centjes-e2e-test] client # [ 0.730326] pci 0000:00:08.0: BAR 0 [io 0xc000-0xc07f]
  842. 55.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.789699] pci 0000:00:09.0: ROM [mem 0xfeb80000-0xfebbffff pref]
  843. 55.26 s [vm-test-run-centjes-e2e-test] client # [ 0.733326] pci 0000:00:08.0: BAR 1 [mem 0xfebd6000-0xfebd6fff]
  844. 55.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.793448] pci 0000:00:0a.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint
  845. 55.27 s [vm-test-run-centjes-e2e-test] client # [ 0.737327] pci 0000:00:08.0: BAR 4 [mem 0xfe014000-0xfe017fff 64bit pref]
  846. 55.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.796149] pci 0000:00:0a.0: BAR 1 [mem 0xfebd8000-0xfebd8fff]
  847. 55.27 s [vm-test-run-centjes-e2e-test] client # [ 0.741612] pci 0000:00:09.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
  848. 55.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.799793] pci 0000:00:0a.0: BAR 4 [mem 0xfe01c000-0xfe01ffff 64bit pref]
  849. 55.28 s [vm-test-run-centjes-e2e-test] client # [ 0.744326] pci 0000:00:09.0: BAR 0 [io 0xc1a0-0xc1bf]
  850. 55.28 s [vm-test-run-centjes-e2e-test] client # [ 0.746304] pci 0000:00:09.0: BAR 1 [mem 0xfebd7000-0xfebd7fff]
  851. 55.28 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.804340] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint
  852. 55.28 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.806793] pci 0000:00:0b.0: BAR 0 [io 0xc0c0-0xc0ff]
  853. 55.29 s [vm-test-run-centjes-e2e-test] client # [ 0.749798] pci 0000:00:09.0: BAR 4 [mem 0xfe018000-0xfe01bfff 64bit pref]
  854. 55.29 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.808697] pci 0000:00:0b.0: BAR 1 [mem 0xfebd9000-0xfebd9fff]
  855. 55.29 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.812175] pci 0000:00:0b.0: BAR 4 [mem 0xfe020000-0xfe023fff 64bit pref]
  856. 55.30 s [vm-test-run-centjes-e2e-test] client # [ 0.752326] pci 0000:00:09.0: ROM [mem 0xfeb80000-0xfebbffff pref]
  857. 55.30 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.817836] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
  858. 55.31 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.820739] pci 0000:00:0c.0: BAR 0 [io 0xc1c0-0xc1df]
  859. 55.31 s [vm-test-run-centjes-e2e-test] client # [ 0.756520] pci 0000:00:0a.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint
  860. 55.31 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.822622] pci 0000:00:0c.0: BAR 1 [mem 0xfebda000-0xfebdafff]
  861. 55.31 s [vm-test-run-centjes-e2e-test] client # [ 0.759674] pci 0000:00:0a.0: BAR 1 [mem 0xfebd8000-0xfebd8fff]
  862. 55.32 s [vm-test-run-centjes-e2e-test] client # [ 0.763326] pci 0000:00:0a.0: BAR 4 [mem 0xfe01c000-0xfe01ffff 64bit pref]
  863. 55.32 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.826210] pci 0000:00:0c.0: BAR 4 [mem 0xfe024000-0xfe027fff 64bit pref]
  864. 55.32 s [vm-test-run-centjes-e2e-test] client # [ 0.767346] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint
  865. 55.32 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.832683] ACPI: PCI: Interrupt link LNKA configured for IRQ 10
  866. 55.33 s [vm-test-run-centjes-e2e-test] client # [ 0.770327] pci 0000:00:0b.0: BAR 0 [io 0xc0c0-0xc0ff]
  867. 55.33 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.834002] ACPI: PCI: Interrupt link LNKB configured for IRQ 10
  868. 55.33 s [vm-test-run-centjes-e2e-test] client # [ 0.772225] pci 0000:00:0b.0: BAR 1 [mem 0xfebd9000-0xfebd9fff]
  869. 55.33 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.835987] ACPI: PCI: Interrupt link LNKC configured for IRQ 11
  870. 55.33 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.837985] ACPI: PCI: Interrupt link LNKD configured for IRQ 11
  871. 55.34 s [vm-test-run-centjes-e2e-test] client # [ 0.775326] pci 0000:00:0b.0: BAR 4 [mem 0xfe020000-0xfe023fff 64bit pref]
  872. 55.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.839897] ACPI: PCI: Interrupt link LNKS configured for IRQ 9
  873. 55.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.841150] iommu: Default domain type: Translated
  874. 55.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.842793] iommu: DMA domain TLB invalidation policy: lazy mode
  875. 55.34 s [vm-test-run-centjes-e2e-test] client # [ 0.779481] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
  876. 55.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.843831] ACPI: bus type USB registered
  877. 55.35 s [vm-test-run-centjes-e2e-test] client # [ 0.782276] pci 0000:00:0c.0: BAR 0 [io 0xc1c0-0xc1df]
  878. 55.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.844827] usbcore: registered new interface driver usbfs
  879. 55.35 s [vm-test-run-centjes-e2e-test] client # [ 0.784118] pci 0000:00:0c.0: BAR 1 [mem 0xfebda000-0xfebdafff]
  880. 55.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.845805] usbcore: registered new interface driver hub
  881. 55.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.846806] usbcore: registered new device driver usb
  882. 55.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.848116] NetLabel: Initializing
  883. 55.36 s [vm-test-run-centjes-e2e-test] client # [ 0.788797] pci 0000:00:0c.0: BAR 4 [mem 0xfe024000-0xfe027fff 64bit pref]
  884. 55.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.848793] NetLabel: domain hash size = 128
  885. 55.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.849794] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO
  886. 55.36 s [vm-test-run-centjes-e2e-test] client # [ 0.793660] ACPI: PCI: Interrupt link LNKA configured for IRQ 10
  887. 55.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.850815] NetLabel: unlabeled traffic allowed by default
  888. 55.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.851795] PCI: Using ACPI for IRQ routing
  889. 55.36 s [vm-test-run-centjes-e2e-test] client # [ 0.795503] ACPI: PCI: Interrupt link LNKB configured for IRQ 10
  890. 55.37 s [vm-test-run-centjes-e2e-test] client # [ 0.797492] ACPI: PCI: Interrupt link LNKC configured for IRQ 11
  891. 55.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.853591] pci 0000:00:02.0: vgaarb: setting as boot VGA device
  892. 55.37 s [vm-test-run-centjes-e2e-test] client # [ 0.798491] ACPI: PCI: Interrupt link LNKD configured for IRQ 11
  893. 55.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.853783] pci 0000:00:02.0: vgaarb: bridge control possible
  894. 55.37 s [vm-test-run-centjes-e2e-test] client # [ 0.799417] ACPI: PCI: Interrupt link LNKS configured for IRQ 9
  895. 55.37 s [vm-test-run-centjes-e2e-test] client # [ 0.800688] iommu: Default domain type: Translated
  896. 55.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.853783] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
  897. 55.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.853797] vgaarb: loaded
  898. 55.38 s [vm-test-run-centjes-e2e-test] client # [ 0.802326] iommu: DMA domain TLB invalidation policy: lazy mode
  899. 55.38 s [vm-test-run-centjes-e2e-test] client # [ 0.803352] ACPI: bus type USB registered
  900. 55.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.854869] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
  901. 55.38 s [vm-test-run-centjes-e2e-test] client # [ 0.804347] usbcore: registered new interface driver usbfs
  902. 55.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.855794] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
  903. 55.38 s [vm-test-run-centjes-e2e-test] client # [ 0.805334] usbcore: registered new interface driver hub
  904. 55.39 s [vm-test-run-centjes-e2e-test] client # [ 0.806334] usbcore: registered new device driver usb
  905. 55.39 s [vm-test-run-centjes-e2e-test] client # [ 0.807605] NetLabel: Initializing
  906. 55.39 s [vm-test-run-centjes-e2e-test] client # [ 0.808326] NetLabel: domain hash size = 128
  907. 55.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.860826] clocksource: Switched to clocksource kvm-clock
  908. 55.39 s [vm-test-run-centjes-e2e-test] client # [ 0.809326] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO
  909. 55.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.864292] VFS: Disk quotas dquot_6.6.0
  910. 55.39 s [vm-test-run-centjes-e2e-test] client # [ 0.810350] NetLabel: unlabeled traffic allowed by default
  911. 55.40 s [vm-test-run-centjes-e2e-test] client # [ 0.811327] PCI: Using ACPI for IRQ routing
  912. 55.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.866298] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
  913. 55.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.869622] pnp: PnP ACPI init
  914. 55.40 s [vm-test-run-centjes-e2e-test] client # [ 0.812966] pci 0000:00:02.0: vgaarb: setting as boot VGA device
  915. 55.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.871748] pnp: PnP ACPI: found 6 devices
  916. 55.40 s [vm-test-run-centjes-e2e-test] client # [ 0.813316] pci 0000:00:02.0: vgaarb: bridge control possible
  917. 55.40 s [vm-test-run-centjes-e2e-test] client # [ 0.813316] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
  918. 55.41 s [vm-test-run-centjes-e2e-test] client # [ 0.813328] vgaarb: loaded
  919. 55.41 s [vm-test-run-centjes-e2e-test] client # [ 0.814395] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
  920. 55.41 s [vm-test-run-centjes-e2e-test] client # [ 0.815326] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
  921. 55.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.879705] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
  922. 55.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.883831] clocksource: Switched to clocksource acpi_pm
  923. 55.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.886551] NET: Registered PF_INET protocol family
  924. 55.42 s [vm-test-run-centjes-e2e-test] client # [ 0.819352] clocksource: Switched to clocksource kvm-clock
  925. 55.42 s [vm-test-run-centjes-e2e-test] client # [ 0.822560] VFS: Disk quotas dquot_6.6.0
  926. 55.42 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.888926] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
  927. 55.42 s [vm-test-run-centjes-e2e-test] client # [ 0.824285] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
  928. 55.42 s [vm-test-run-centjes-e2e-test] client # [ 0.827042] pnp: PnP ACPI init
  929. 55.42 s [vm-test-run-centjes-e2e-test] client # [ 0.828952] pnp: PnP ACPI: found 6 devices
  930. 55.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.901983] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)
  931. 55.43 s [vm-test-run-centjes-e2e-test] client # [ 0.837800] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
  932. 55.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.906063] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
  933. 55.44 s [vm-test-run-centjes-e2e-test] client # [ 0.841352] clocksource: Switched to clocksource acpi_pm
  934. 55.44 s [vm-test-run-centjes-e2e-test] client # [ 0.843631] NET: Registered PF_INET protocol family
  935. 55.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.909796] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)
  936. 55.44 s [vm-test-run-centjes-e2e-test] client # [ 0.845784] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
  937. 55.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.913606] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)
  938. 55.45 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.917341] TCP: Hash tables configured (established 8192 bind 8192)
  939. 55.45 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.920582] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)
  940. 55.45 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.924159] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
  941. 55.46 s [vm-test-run-centjes-e2e-test] client # [ 0.858128] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)
  942. 55.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.927307] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
  943. 55.46 s [vm-test-run-centjes-e2e-test] client # [ 0.861534] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
  944. 55.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.930701] NET: Registered PF_UNIX/PF_LOCAL protocol family
  945. 55.46 s [vm-test-run-centjes-e2e-test] client # [ 0.864734] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)
  946. 55.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.933455] NET: Registered PF_XDP protocol family
  947. 55.46 s [vm-test-run-centjes-e2e-test] client # [ 0.867909] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)
  948. 55.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.935811] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]
  949. 55.47 s [vm-test-run-centjes-e2e-test] client # [ 0.870918] TCP: Hash tables configured (established 8192 bind 8192)
  950. 55.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.938793] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]
  951. 55.47 s [vm-test-run-centjes-e2e-test] client # [ 0.873573] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)
  952. 55.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.941790] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
  953. 55.47 s [vm-test-run-centjes-e2e-test] client # [ 0.876657] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
  954. 55.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.945042] pci_bus 0000:00: resource 7 [mem 0x40000000-0xfebfffff window]
  955. 55.48 s [vm-test-run-centjes-e2e-test] client # [ 0.879378] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
  956. 55.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.948303] pci_bus 0000:00: resource 8 [mem 0x100000000-0x17fffffff window]
  957. 55.48 s [vm-test-run-centjes-e2e-test] client # [ 0.882268] NET: Registered PF_UNIX/PF_LOCAL protocol family
  958. 55.48 s [vm-test-run-centjes-e2e-test] client # [ 0.884611] NET: Registered PF_XDP protocol family
  959. 55.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.951744] pci 0000:00:01.0: PIIX3: Enabling Passive Release
  960. 55.48 s [vm-test-run-centjes-e2e-test] client # [ 0.886692] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]
  961. 55.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.954570] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
  962. 55.49 s [vm-test-run-centjes-e2e-test] client # [ 0.889269] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]
  963. 55.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.958749] ACPI: \_SB_.LNKD: Enabled at IRQ 11
  964. 55.49 s [vm-test-run-centjes-e2e-test] client # [ 0.891778] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
  965. 55.49 s [vm-test-run-centjes-e2e-test] client # [ 0.894598] pci_bus 0000:00: resource 7 [mem 0x40000000-0xfebfffff window]
  966. 55.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.963020] PCI: CLS 0 bytes, default 64
  967. 55.49 s [vm-test-run-centjes-e2e-test] client # [ 0.897411] pci_bus 0000:00: resource 8 [mem 0x100000000-0x17fffffff window]
  968. 55.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.965254] Trying to unpack rootfs image as initramfs...
  969. 55.50 s [vm-test-run-centjes-e2e-test] client # [ 0.900351] pci 0000:00:01.0: PIIX3: Enabling Passive Release
  970. 55.50 s [vm-test-run-centjes-e2e-test] client # [ 0.902728] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
  971. 55.50 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.969567] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x31024b3bec5, max_idle_ns: 440795366697 ns
  972. 55.50 s [vm-test-run-centjes-e2e-test] client # [ 0.906480] ACPI: \_SB_.LNKD: Enabled at IRQ 11
  973. 55.51 s [vm-test-run-centjes-e2e-test] client # [ 0.910380] PCI: CLS 0 bytes, default 64
  974. 55.51 s [vm-test-run-centjes-e2e-test] client # [ 0.912398] Trying to unpack rootfs image as initramfs...
  975. 55.52 s [vm-test-run-centjes-e2e-test] client # [ 0.918320] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x31024b3bec5, max_idle_ns: 440795366697 ns
  976. 55.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.001844] Initialise system trusted keyrings
  977. 55.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.007578] workingset: timestamp_bits=40 max_order=18 bucket_order=0
  978. 55.54 s [vm-test-run-centjes-e2e-test] client # [ 0.947557] Initialise system trusted keyrings
  979. 55.55 s [vm-test-run-centjes-e2e-test] client # [ 0.951336] workingset: timestamp_bits=40 max_order=18 bucket_order=0
  980. 55.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.032635] Key type asymmetric registered
  981. 55.57 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.038500] Asymmetric key parser 'x509' registered
  982. 55.57 s [vm-test-run-centjes-e2e-test] client # [ 0.975273] Key type asymmetric registered
  983. 55.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.045526] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
  984. 55.58 s [vm-test-run-centjes-e2e-test] client # [ 0.980240] Asymmetric key parser 'x509' registered
  985. 55.58 s [vm-test-run-centjes-e2e-test] client # [ 0.986319] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
  986. 55.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.054889] Freeing initrd memory: 12300K
  987. 55.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.057109] io scheduler mq-deadline registered
  988. 55.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.059484] io scheduler kyber registered
  989. 55.59 s [vm-test-run-centjes-e2e-test] client # [ 0.993324] io scheduler mq-deadline registered
  990. 55.59 s [vm-test-run-centjes-e2e-test] client # [ 0.995246] io scheduler kyber registered
  991. 55.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.061857] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
  992. 55.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.065305] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
  993. 55.60 s [vm-test-run-centjes-e2e-test] client # [ 1.001645] Freeing initrd memory: 12300K
  994. 55.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.070153] Linux agpgart interface v0.103
  995. 55.60 s [vm-test-run-centjes-e2e-test] client # [ 1.003786] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
  996. 55.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.072468] ACPI: bus type drm_connector registered
  997. 55.60 s [vm-test-run-centjes-e2e-test] client # [ 1.006897] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
  998. 55.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.075315] usbcore: registered new interface driver usbserial_generic
  999. 55.61 s [vm-test-run-centjes-e2e-test] client # [ 1.011324] Linux agpgart interface v0.103
  1000. 55.61 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.078721] usbserial: USB Serial support registered for generic
  1001. 55.61 s [vm-test-run-centjes-e2e-test] client # [ 1.013223] ACPI: bus type drm_connector registered
  1002. 55.61 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.081831] amd_pstate: the _CPC object is not present in SBIOS or ACPI disabled
  1003. 55.61 s [vm-test-run-centjes-e2e-test] client # [ 1.015724] usbcore: registered new interface driver usbserial_generic
  1004. 55.61 s [vm-test-run-centjes-e2e-test] client # [ 1.018606] usbserial: USB Serial support registered for generic
  1005. 55.61 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.085715] drop_monitor: Initializing network drop monitor service
  1006. 55.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.089031] NET: Registered PF_INET6 protocol family
  1007. 55.62 s [vm-test-run-centjes-e2e-test] client # [ 1.021292] amd_pstate: the _CPC object is not present in SBIOS or ACPI disabled
  1008. 55.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.092284] Segment Routing with IPv6
  1009. 55.62 s [vm-test-run-centjes-e2e-test] client # [ 1.024585] drop_monitor: Initializing network drop monitor service
  1010. 55.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.094484] In-situ OAM (IOAM) with IPv6
  1011. 55.62 s [vm-test-run-centjes-e2e-test] client # [ 1.027434] NET: Registered PF_INET6 protocol family
  1012. 55.63 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.096884] IPI shorthand broadcast: enabled
  1013. 55.63 s [vm-test-run-centjes-e2e-test] client # [ 1.030402] Segment Routing with IPv6
  1014. 55.63 s [vm-test-run-centjes-e2e-test] client # [ 1.032080] In-situ OAM (IOAM) with IPv6
  1015. 55.63 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.101290] registered taskstats version 1
  1016. 55.63 s [vm-test-run-centjes-e2e-test] client # [ 1.034268] IPI shorthand broadcast: enabled
  1017. 55.63 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.103615] Loading compiled-in X.509 certificates
  1018. 55.63 s [vm-test-run-centjes-e2e-test] client # [ 1.038250] registered taskstats version 1
  1019. 55.64 s [vm-test-run-centjes-e2e-test] client # [ 1.040337] Loading compiled-in X.509 certificates
  1020. 55.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.110574] Demotion targets for Node 0: null
  1021. 55.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.112808] Key type .fscrypt registered
  1022. 55.64 s [vm-test-run-centjes-e2e-test] client # [ 1.046822] Demotion targets for Node 0: null
  1023. 55.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.114850] Key type fscrypt-provisioning registered
  1024. 55.64 s [vm-test-run-centjes-e2e-test] client # [ 1.048853] Key type .fscrypt registered
  1025. 55.65 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.117483] PM: Magic number: 6:81:737
  1026. 55.65 s [vm-test-run-centjes-e2e-test] client # [ 1.050678] Key type fscrypt-provisioning registered
  1027. 55.65 s [vm-test-run-centjes-e2e-test] client # [ 1.052949] PM: Magic number: 6:81:737
  1028. 55.65 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.120044] RAS: Correctable Errors collector initialized.
  1029. 55.65 s [vm-test-run-centjes-e2e-test] client # [ 1.055437] RAS: Correctable Errors collector initialized.
  1030. 55.66 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.125577] Unstable clock detected, switching default tracing clock to "global"
  1031. 55.66 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.125577] If you want to keep using the local clock, then add:
  1032. 55.66 s [vm-test-run-centjes-e2e-test] client # [ 1.060564] Unstable clock detected, switching default tracing clock to "global"
  1033. 55.66 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.125577] "trace_clock=local"
  1034. 55.66 s [vm-test-run-centjes-e2e-test] client # [ 1.060564] If you want to keep using the local clock, then add:
  1035. 55.66 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.125577] on the kernel command line
  1036. 55.66 s [vm-test-run-centjes-e2e-test] client # [ 1.060564] "trace_clock=local"
  1037. 55.66 s [vm-test-run-centjes-e2e-test] client # [ 1.060564] on the kernel command line
  1038. 55.66 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.134563] clk: Disabling unused clocks
  1039. 55.66 s [vm-test-run-centjes-e2e-test] client # [ 1.068371] clk: Disabling unused clocks
  1040. 55.66 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.136555] PM: genpd: Disabling unused power domains
  1041. 55.67 s [vm-test-run-centjes-e2e-test] client # [ 1.070092] PM: genpd: Disabling unused power domains
  1042. 55.67 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.139949] Freeing unused decrypted memory: 2028K
  1043. 55.67 s [vm-test-run-centjes-e2e-test] client # [ 1.073225] Freeing unused decrypted memory: 2028K
  1044. 55.67 s [vm-test-run-centjes-e2e-test] client # [ 1.075570] Freeing unused kernel image (initmem) memory: 3408K
  1045. 55.67 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.142759] Freeing unused kernel image (initmem) memory: 3408K
  1046. 55.67 s [vm-test-run-centjes-e2e-test] client # [ 1.078077] Write protecting the kernel read-only data: 30720k
  1047. 55.67 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.145638] Write protecting the kernel read-only data: 30720k
  1048. 55.68 s [vm-test-run-centjes-e2e-test] client # [ 1.080857] Freeing unused kernel image (rodata/data gap) memory: 1756K
  1049. 55.68 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.148792] Freeing unused kernel image (rodata/data gap) memory: 1756K
  1050. 55.72 s [vm-test-run-centjes-e2e-test] client # [ 1.122657] x86/mm: Checked W+X mappings: passed, no W+X pages found.
  1051. 55.72 s [vm-test-run-centjes-e2e-test] client # [ 1.125436] Run /init as init process
  1052. 55.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.191846] x86/mm: Checked W+X mappings: passed, no W+X pages found.
  1053. 55.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.195025] Run /init as init process
  1054. 55.77 s [vm-test-run-centjes-e2e-test] client # [ 1.169028] device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@lists.linux.dev
  1055. 55.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.240893] device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@lists.linux.dev
  1056. 55.92 s [vm-test-run-centjes-e2e-test] client # [ 1.327555] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
  1057. 55.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.410816] ACPI: \_SB_.LNKC: Enabled at IRQ 10
  1058. 55.95 s [vm-test-run-centjes-e2e-test] client # [ 1.353567] serio: i8042 KBD port at 0x60,0x64 irq 1
  1059. 55.95 s [vm-test-run-centjes-e2e-test] client # [ 1.356374] SCSI subsystem initialized
  1060. 55.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.421951] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
  1061. 55.96 s [vm-test-run-centjes-e2e-test] client # [ 1.359628] ACPI: \_SB_.LNKC: Enabled at IRQ 10
  1062. 55.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.429180] uhci_hcd 0000:00:01.2: UHCI Host Controller
  1063. 55.96 s [vm-test-run-centjes-e2e-test] client # [ 1.365243] serio: i8042 AUX port at 0x60,0x64 irq 12
  1064. 55.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.436975] SCSI subsystem initialized
  1065. 55.97 s [vm-test-run-centjes-e2e-test] client # [ 1.373751] uhci_hcd 0000:00:01.2: UHCI Host Controller
  1066. 55.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.445828] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
  1067. 55.98 s [vm-test-run-centjes-e2e-test] client # [ 1.384259] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
  1068. 55.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.456247] serio: i8042 KBD port at 0x60,0x64 irq 1
  1069. 55.99 s [vm-test-run-centjes-e2e-test] client # [ 1.394635] ACPI: \_SB_.LNKA: Enabled at IRQ 10
  1070. 55.99 s [vm-test-run-centjes-e2e-test] client # [ 1.398600] uhci_hcd 0000:00:01.2: detected 2 ports
  1071. 56.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.468017] uhci_hcd 0000:00:01.2: detected 2 ports
  1072. 56.00 s [vm-test-run-centjes-e2e-test] client # [ 1.402105] scsi host0: ata_piix
  1073. 56.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.470509] serio: i8042 AUX port at 0x60,0x64 irq 12
  1074. 56.00 s [vm-test-run-centjes-e2e-test] client # [ 1.406485] uhci_hcd 0000:00:01.2: irq 11, io port 0x0000c100
  1075. 56.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.474323] ACPI: \_SB_.LNKA: Enabled at IRQ 10
  1076. 56.00 s [vm-test-run-centjes-e2e-test] client # [ 1.409140] scsi host1: ata_piix
  1077. 56.01 s [vm-test-run-centjes-e2e-test] client # [ 1.413447] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc1e0 irq 14 lpm-pol 0
  1078. 56.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.483794] uhci_hcd 0000:00:01.2: irq 11, io port 0x0000c100
  1079. 56.01 s [vm-test-run-centjes-e2e-test] client # [ 1.416784] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc1e8 irq 15 lpm-pol 0
  1080. 56.02 s [vm-test-run-centjes-e2e-test] client # [ 1.421677] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 6.12
  1081. 56.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.492837] ACPI: \_SB_.LNKB: Enabled at IRQ 11
  1082. 56.02 s [vm-test-run-centjes-e2e-test] client # [ 1.425317] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
  1083. 56.02 s [vm-test-run-centjes-e2e-test] client # [ 1.428551] usb usb1: Product: UHCI Host Controller
  1084. 56.03 s [vm-test-run-centjes-e2e-test] client # [ 1.430777] usb usb1: Manufacturer: Linux 6.12.62 uhci_hcd
  1085. 56.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.497668] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 6.12
  1086. 56.03 s [vm-test-run-centjes-e2e-test] client # [ 1.433268] usb usb1: SerialNumber: 0000:00:01.2
  1087. 56.03 s [vm-test-run-centjes-e2e-test] client # [ 1.435629] ACPI: \_SB_.LNKB: Enabled at IRQ 11
  1088. 56.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.501819] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
  1089. 56.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.505452] usb usb1: Product: UHCI Host Controller
  1090. 56.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.507954] usb usb1: Manufacturer: Linux 6.12.62 uhci_hcd
  1091. 56.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.510947] usb usb1: SerialNumber: 0000:00:01.2
  1092. 56.05 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.517593] scsi host0: ata_piix
  1093. 56.05 s [vm-test-run-centjes-e2e-test] client # [ 1.450137] hub 1-0:1.0: USB hub found
  1094. 56.05 s [vm-test-run-centjes-e2e-test] client # [ 1.455417] hub 1-0:1.0: 2 ports detected
  1095. 56.05 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.524736] scsi host1: ata_piix
  1096. 56.06 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.529762] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc1e0 irq 14 lpm-pol 0
  1097. 56.06 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.533606] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc1e8 irq 15 lpm-pol 0
  1098. 56.07 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.541834] hub 1-0:1.0: USB hub found
  1099. 56.08 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.547503] hub 1-0:1.0: 2 ports detected
  1100. 56.17 s [vm-test-run-centjes-e2e-test] client # [ 1.574948] ata2: found unknown device (class 0)
  1101. 56.17 s [vm-test-run-centjes-e2e-test] client # [ 1.577975] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100
  1102. 56.18 s [vm-test-run-centjes-e2e-test] client # [ 1.582133] scsi 1:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5
  1103. 56.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.697069] ata2: found unknown device (class 0)
  1104. 56.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.700797] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100
  1105. 56.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.706145] scsi 1:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5
  1106. 56.25 s [vm-test-run-centjes-e2e-test] client # [ 1.653567] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
  1107. 56.27 s [vm-test-run-centjes-e2e-test] client # [ 1.675689] virtio_blk virtio5: 1/0/0 default/read/poll queues
  1108. 56.27 s [vm-test-run-centjes-e2e-test] client # [ 1.678268] usb 1-1: new full-speed USB device number 2 using uhci_hcd
  1109. 56.30 s [vm-test-run-centjes-e2e-test] client # [ 1.703138] virtio_blk virtio5: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)
  1110. 56.31 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.776503] usb 1-1: new full-speed USB device number 2 using uhci_hcd
  1111. 56.32 s [vm-test-run-centjes-e2e-test] client # [ 1.725501] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray
  1112. 56.32 s [vm-test-run-centjes-e2e-test] client # [ 1.728454] cdrom: Uniform CD-ROM driver Revision: 3.20
  1113. 56.33 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.796027] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
  1114. 56.33 s [vm-test-run-centjes-e2e-test] client # [ 1.732457] netfs: FS-Cache loaded
  1115. 56.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.814902] virtio_blk virtio5: 1/0/0 default/read/poll queues
  1116. 56.34 s [vm-test-run-centjes-e2e-test] client # [ 1.749137] 9pnet: Installing 9P2000 support
  1117. 56.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.844528] virtio_blk virtio5: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)
  1118. 56.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.859130] netfs: FS-Cache loaded
  1119. 56.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.868156] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray
  1120. 56.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.871325] cdrom: Uniform CD-ROM driver Revision: 3.20
  1121. 56.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.879122] 9pnet: Installing 9P2000 support
  1122. 56.45 s [vm-test-run-centjes-e2e-test] client # [ 1.854771] usb 1-1: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00
  1123. 56.46 s [vm-test-run-centjes-e2e-test] client # [ 1.858956] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=10
  1124. 56.46 s [vm-test-run-centjes-e2e-test] client # [ 1.862768] usb 1-1: Product: QEMU USB Tablet
  1125. 56.46 s [vm-test-run-centjes-e2e-test] client # [ 1.865334] usb 1-1: Manufacturer: QEMU
  1126. 56.46 s [vm-test-run-centjes-e2e-test] client # [ 1.867333] usb 1-1: SerialNumber: 28754-0000:00:01.2-1
  1127. 56.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.950869] usb 1-1: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00
  1128. 56.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.954984] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=10
  1129. 56.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.958873] usb 1-1: Product: QEMU USB Tablet
  1130. 56.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.961252] usb 1-1: Manufacturer: QEMU
  1131. 56.49 s [vm-test-run-centjes-e2e-test] client # [ 1.885833] hid: raw HID events driver (C) Jiri Kosina
  1132. 56.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.963291] usb 1-1: SerialNumber: 28754-0000:00:01.2-1
  1133. 56.50 s [vm-test-run-centjes-e2e-test] client # [ 1.906389] usbcore: registered new interface driver usbhid
  1134. 56.50 s [vm-test-run-centjes-e2e-test] client # [ 1.909349] usbhid: USB HID core driver
  1135. 56.51 s [vm-test-run-centjes-e2e-test] client # [ 1.913338] 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
  1136. 56.52 s [vm-test-run-centjes-e2e-test] client # [ 1.919396] 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
  1137. 56.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.980878] hid: raw HID events driver (C) Jiri Kosina
  1138. 56.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.008689] usbcore: registered new interface driver usbhid
  1139. 56.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.011629] usbhid: USB HID core driver
  1140. 56.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.017131] 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
  1141. 56.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.022799] 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
  1142. 56.66 s [vm-test-run-centjes-e2e-test] client # [ 2.061882] EXT4-fs (vda): mounted filesystem 5bc27674-668d-4e8b-ab42-ceb2d700589d r/w with ordered data mode. Quota mode: none.
  1143. 56.68 s [vm-test-run-centjes-e2e-test] client # [ 2.083593] 9p: Installing v9fs 9p2000 file system support
  1144. 56.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.179575] EXT4-fs (vda): mounted filesystem 6e28e413-a81c-44a9-9ae4-e393375b3fa3 r/w with ordered data mode. Quota mode: none.
  1145. 56.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.201323] 9p: Installing v9fs 9p2000 file system support
  1146. 56.92 s [vm-test-run-centjes-e2e-test] client # [ 2.319292] EXT4-fs (vda): re-mounted 5bc27674-668d-4e8b-ab42-ceb2d700589d.
  1147. 56.92 s [vm-test-run-centjes-e2e-test] client # [ 2.324342] booting system configuration /nix/store/001k9r4jinw78ih5x5hxggb82ynlbkqn-nixos-system-client-test
  1148. 56.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.438548] EXT4-fs (vda): re-mounted 6e28e413-a81c-44a9-9ae4-e393375b3fa3.
  1149. 56.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.443861] booting system configuration /nix/store/hk9888llhk4kkgz98y983g2r70r1xhfp-nixos-system-docsserver-test
  1150. 58.56 s [vm-test-run-centjes-e2e-test] client # [ 3.967106] systemd[1]: Inserted module 'autofs4'
  1151. 58.62 s [vm-test-run-centjes-e2e-test] client # [ 4.012585] 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)
  1152. 58.62 s [vm-test-run-centjes-e2e-test] client # [ 4.027315] systemd[1]: Detected virtualization kvm.
  1153. 58.63 s [vm-test-run-centjes-e2e-test] client # [ 4.029805] systemd[1]: Detected architecture x86-64.
  1154. 58.63 s [vm-test-run-centjes-e2e-test] client # [ 4.032472] systemd[1]: Detected first boot.
  1155. 58.63 s [vm-test-run-centjes-e2e-test] client # [ 4.038120] systemd[1]: Initializing machine ID from random generator.
  1156. 58.66 s [vm-test-run-centjes-e2e-test] client # [ 4.059631] systemd[1]: Hostname set to <client>.
  1157. 58.67 s [vm-test-run-centjes-e2e-test] docsserver # [ 4.140969] systemd[1]: Inserted module 'autofs4'
  1158. 58.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 4.187092] 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)
  1159. 58.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 4.201715] systemd[1]: Detected virtualization kvm.
  1160. 58.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 4.204306] systemd[1]: Detected architecture x86-64.
  1161. 58.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 4.206957] systemd[1]: Detected first boot.
  1162. 58.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 4.212516] systemd[1]: Initializing machine ID from random generator.
  1163. 58.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 4.234731] systemd[1]: Hostname set to <docsserver>.
  1164. 58.77 s [vm-test-run-centjes-e2e-test] client # [ 4.171809] systemd[1]: bpf-restrict-fs: LSM BPF program attached
  1165. 58.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 4.340953] systemd[1]: bpf-restrict-fs: LSM BPF program attached
  1166. 58.94 s [vm-test-run-centjes-e2e-test] client # [ 4.342128] systemd[1]: Applying preset policy.
  1167. 59.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 4.493073] systemd[1]: Applying preset policy.
  1168. 59.47 s [vm-test-run-centjes-e2e-test] client # [ 4.874781] systemd[1]: Populated /etc with preset unit settings.
  1169. 59.57 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.043596] systemd[1]: Populated /etc with preset unit settings.
  1170. 59.96 s [vm-test-run-centjes-e2e-test] client # [ 5.364547] systemd[1]: Queued start job for default target Multi-User System.
  1171. 59.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.449146] systemd[1]: /etc/systemd/system/centjes-docs-site-production.service:3: Invalid URL, ignoring: /nix/store/181fxqzmzn69yk3i6hw52nnxqml2g4xz-settings-check
  1172. 59.99 s [vm-test-run-centjes-e2e-test] client # [ 5.396048] systemd[1]: Created slice Slice /system/getty.
  1173. 59.99 s [vm-test-run-centjes-e2e-test] client # [ 5.398999] systemd[1]: Created slice Slice /system/modprobe.
  1174. 60.00 s [vm-test-run-centjes-e2e-test] client # [ 5.401957] systemd[1]: Created slice User and Session Slice.
  1175. 60.00 s [vm-test-run-centjes-e2e-test] client # [ 5.405091] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
  1176. 60.00 s [vm-test-run-centjes-e2e-test] client # [ 5.408344] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
  1177. 60.01 s [vm-test-run-centjes-e2e-test] client # [ 5.411518] systemd[1]: Expecting device /dev/hvc0...
  1178. 60.01 s [vm-test-run-centjes-e2e-test] client # [ 5.413622] systemd[1]: Expecting device /dev/ttyS0...
  1179. 60.01 s [vm-test-run-centjes-e2e-test] client # [ 5.415766] systemd[1]: Expecting device /sys/subsystem/net/devices/eth1...
  1180. 60.01 s [vm-test-run-centjes-e2e-test] client # [ 5.418408] systemd[1]: Reached target Local Encrypted Volumes.
  1181. 60.02 s [vm-test-run-centjes-e2e-test] client # [ 5.420828] systemd[1]: Reached target Virtual Machines and Containers.
  1182. 60.02 s [vm-test-run-centjes-e2e-test] client # [ 5.423772] systemd[1]: Reached target Path Units.
  1183. 60.02 s [vm-test-run-centjes-e2e-test] client # [ 5.425893] systemd[1]: Reached target Remote File Systems.
  1184. 60.02 s [vm-test-run-centjes-e2e-test] client # [ 5.428284] systemd[1]: Reached target Slice Units.
  1185. 60.03 s [vm-test-run-centjes-e2e-test] client # [ 5.430352] systemd[1]: Reached target Swaps.
  1186. 60.03 s [vm-test-run-centjes-e2e-test] client # [ 5.436015] systemd[1]: Listening on Process Core Dump Socket.
  1187. 60.04 s [vm-test-run-centjes-e2e-test] client # [ 5.440709] systemd[1]: Listening on Credential Encryption/Decryption.
  1188. 60.04 s [vm-test-run-centjes-e2e-test] client # [ 5.443764] systemd[1]: Listening on Journal Audit Socket.
  1189. 60.04 s [vm-test-run-centjes-e2e-test] client # [ 5.446258] systemd[1]: Listening on Journal Socket (/dev/log).
  1190. 60.04 s [vm-test-run-centjes-e2e-test] client # [ 5.448663] systemd[1]: Listening on Journal Sockets.
  1191. 60.05 s [vm-test-run-centjes-e2e-test] client # [ 5.451144] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.
  1192. 60.05 s [vm-test-run-centjes-e2e-test] client # [ 5.454042] systemd[1]: Make TPM PCR Policy was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1193. 60.05 s [vm-test-run-centjes-e2e-test] client # [ 5.458348] systemd[1]: Listening on udev Control Socket.
  1194. 60.06 s [vm-test-run-centjes-e2e-test] client # [ 5.460578] systemd[1]: Listening on udev Kernel Socket.
  1195. 60.06 s [vm-test-run-centjes-e2e-test] client # [ 5.466880] systemd[1]: Mounting Huge Pages File System...
  1196. 60.07 s [vm-test-run-centjes-e2e-test] client # [ 5.472484] systemd[1]: Mounting POSIX Message Queue File System...
  1197. 60.08 s [vm-test-run-centjes-e2e-test] client # [ 5.481012] systemd[1]: Mounting Kernel Debug File System...
  1198. 60.08 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.555709] systemd[1]: Queued start job for default target Multi-User System.
  1199. 60.09 s [vm-test-run-centjes-e2e-test] client # [ 5.492804] systemd[1]: Mounting Kernel Trace File System...
  1200. 60.10 s [vm-test-run-centjes-e2e-test] client # [ 5.508607] systemd[1]: Starting Create List of Static Device Nodes...
  1201. 60.19 s [vm-test-run-centjes-e2e-test] client # [ 5.513555] systemd[1]: Load Kernel Module 9pnet_virtio was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!9pnet_virtio).
  1202. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.585169] systemd[1]: Created slice Slice /system/getty.
  1203. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.588211] systemd[1]: Created slice Slice /system/modprobe.
  1204. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.591171] systemd[1]: Created slice User and Session Slice.
  1205. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.594001] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
  1206. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.597107] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
  1207. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.600215] systemd[1]: Expecting device /dev/hvc0...
  1208. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.602342] systemd[1]: Expecting device /dev/ttyS0...
  1209. 60.19 s [vm-test-run-centjes-e2e-test] client # [ 5.535915] systemd[1]: Starting Load Kernel Module configfs...
  1210. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.604582] systemd[1]: Expecting device /sys/subsystem/net/devices/eth1...
  1211. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.607243] systemd[1]: Reached target Local Encrypted Volumes.
  1212. 60.19 s [vm-test-run-centjes-e2e-test] client # [ 5.538988] systemd[1]: Load Kernel Module drm was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!drm).
  1213. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.609666] systemd[1]: Reached target Virtual Machines and Containers.
  1214. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.612203] systemd[1]: Reached target Path Units.
  1215. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.614211] systemd[1]: Reached target Remote File Systems.
  1216. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.616575] systemd[1]: Reached target Slice Units.
  1217. 60.19 s [vm-test-run-centjes-e2e-test] client # [ 5.549833] systemd[1]: Starting Load Kernel Module efi_pstore...
  1218. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.618585] systemd[1]: Reached target Swaps.
  1219. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.624089] systemd[1]: Listening on Process Core Dump Socket.
  1220. 60.19 s [vm-test-run-centjes-e2e-test] client # [ 5.557771] systemd[1]: Starting Load Kernel Module fuse...
  1221. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.629034] systemd[1]: Listening on Credential Encryption/Decryption.
  1222. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.632015] systemd[1]: Listening on Journal Audit Socket.
  1223. 60.19 s [vm-test-run-centjes-e2e-test] client # [ 5.562791] systemd[1]: File System Check on Root Device was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/).
  1224. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.634476] systemd[1]: Listening on Journal Socket (/dev/log).
  1225. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.636989] systemd[1]: Listening on Journal Sockets.
  1226. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.639550] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.
  1227. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.642493] systemd[1]: Make TPM PCR Policy was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1228. 60.19 s [vm-test-run-centjes-e2e-test] client # [ 5.573660] 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).
  1229. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.646700] systemd[1]: Listening on udev Control Socket.
  1230. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.649016] systemd[1]: Listening on udev Kernel Socket.
  1231. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.654770] systemd[1]: Mounting Huge Pages File System...
  1232. 60.19 s [vm-test-run-centjes-e2e-test] client # [ 5.588944] systemd[1]: Starting Journal Service...
  1233. 60.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.660115] systemd[1]: Mounting POSIX Message Queue File System...
  1234. 60.19 s [vm-test-run-centjes-e2e-test] client # [ 5.597375] systemd[1]: Starting Load Kernel Modules...
  1235. 60.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.667745] systemd[1]: Mounting Kernel Debug File System...
  1236. 60.20 s [vm-test-run-centjes-e2e-test] client # [ 5.605906] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...
  1237. 60.21 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.678648] systemd[1]: Mounting Kernel Trace File System...
  1238. 60.21 s [vm-test-run-centjes-e2e-test] client # [ 5.616332] systemd[1]: Starting Remount Root and Kernel File Systems...
  1239. 60.22 s [vm-test-run-centjes-e2e-test] client # [ 5.621974] systemd[1]: Early TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1240. 60.22 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.694709] systemd[1]: Starting Create List of Static Device Nodes...
  1241. 60.23 s [vm-test-run-centjes-e2e-test] client # [ 5.635656] systemd[1]: Starting Coldplug All udev Devices...
  1242. 60.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.707298] systemd[1]: Load Kernel Module 9pnet_virtio was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!9pnet_virtio).
  1243. 60.24 s [vm-test-run-centjes-e2e-test] client # [ 5.647053] systemd[1]: Mounted Huge Pages File System.
  1244. 60.25 s [vm-test-run-centjes-e2e-test] client # [ 5.652876] systemd[1]: Mounted POSIX Message Queue File System.
  1245. 60.25 s [vm-test-run-centjes-e2e-test] client # [ 5.658500] systemd[1]: Mounted Kernel Debug File System.
  1246. 60.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.730320] systemd[1]: Starting Load Kernel Module configfs...
  1247. 60.26 s [vm-test-run-centjes-e2e-test] client # [ 5.664696] systemd[1]: Mounted Kernel Trace File System.
  1248. 60.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.732901] systemd[1]: Load Kernel Module drm was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!drm).
  1249. 60.27 s [vm-test-run-centjes-e2e-test] client # [ 5.674320] systemd[1]: Finished Create List of Static Device Nodes.
  1250. 60.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.742864] systemd[1]: Starting Load Kernel Module efi_pstore...
  1251. 60.28 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.750197] systemd[1]: Starting Load Kernel Module fuse...
  1252. 60.28 s [vm-test-run-centjes-e2e-test] client # [ 5.686790] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...
  1253. 60.29 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.755121] systemd[1]: File System Check on Root Device was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/).
  1254. 60.29 s [vm-test-run-centjes-e2e-test] client # [ 5.694571] systemd[1]: modprobe@efi_pstore.service: Deactivated successfully.
  1255. 60.30 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.764931] 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).
  1256. 60.30 s [vm-test-run-centjes-e2e-test] client # [ 5.702336] systemd[1]: Finished Load Kernel Module efi_pstore.
  1257. 60.30 s [vm-test-run-centjes-e2e-test] client # [ 5.707801] systemd[1]: modprobe@configfs.service: Deactivated successfully.
  1258. 60.31 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.781050] systemd[1]: Starting Journal Service...
  1259. 60.31 s [vm-test-run-centjes-e2e-test] client # [ 5.715882] systemd[1]: Finished Load Kernel Module configfs.
  1260. 60.32 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.789923] systemd[1]: Starting Load Kernel Modules...
  1261. 60.32 s [vm-test-run-centjes-e2e-test] client # [ 5.726387] systemd[1]: Mounting Kernel Configuration File System...
  1262. 60.33 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.798692] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...
  1263. 60.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.806952] systemd[1]: Starting Remount Root and Kernel File Systems...
  1264. 60.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.812655] systemd[1]: Early TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1265. 60.35 s [vm-test-run-centjes-e2e-test] client # [ 5.752980] systemd[1]: Mounted Kernel Configuration File System.
  1266. 60.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.828715] systemd[1]: Starting Coldplug All udev Devices...
  1267. 60.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.840594] systemd[1]: Mounted Huge Pages File System.
  1268. 60.37 s [vm-test-run-centjes-e2e-test] client # [ 5.777706] EXT4-fs (vda): re-mounted 5bc27674-668d-4e8b-ab42-ceb2d700589d.
  1269. 60.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.846721] systemd[1]: Mounted POSIX Message Queue File System.
  1270. 60.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.852781] systemd[1]: Mounted Kernel Debug File System.
  1271. 60.38 s [vm-test-run-centjes-e2e-test] client # [ 5.786682] fuse: init (API version 7.41)
  1272. 60.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.858225] systemd[1]: Mounted Kernel Trace File System.
  1273. 60.39 s [vm-test-run-centjes-e2e-test] client # [ 5.791447] systemd-journald[385]: Collecting audit messages is enabled.
  1274. 60.39 s [vm-test-run-centjes-e2e-test] client # [ 5.795659] loop: module loaded
  1275. 60.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.866699] systemd[1]: Finished Create List of Static Device Nodes.
  1276. 60.40 s [vm-test-run-centjes-e2e-test] client # [ 5.804121] systemd[1]: Finished Remount Root and Kernel File Systems.
  1277. 60.41 s [vm-test-run-centjes-e2e-test] client # [ 5.809810] systemd[1]: modprobe@fuse.service: Deactivated successfully.
  1278. 60.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.881012] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...
  1279. 60.41 s [vm-test-run-centjes-e2e-test] client # [ 5.818347] systemd[1]: Finished Load Kernel Module fuse.
  1280. 60.42 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.887966] systemd[1]: modprobe@efi_pstore.service: Deactivated successfully.
  1281. 60.42 s [vm-test-run-centjes-e2e-test] client # [ 5.826770] systemd[1]: Finished Load Kernel Modules.
  1282. 60.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.896816] systemd[1]: Finished Load Kernel Module efi_pstore.
  1283. 60.43 s [vm-test-run-centjes-e2e-test] client # [ 5.835912] systemd[1]: Mounting FUSE Control File System...
  1284. 60.44 s [vm-test-run-centjes-e2e-test] client # [ 5.847085] systemd[1]: Starting Firewall...
  1285. 60.45 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.917634] systemd[1]: modprobe@configfs.service: Deactivated successfully.
  1286. 60.45 s [vm-test-run-centjes-e2e-test] client # [ 5.850522] systemd[1]: Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore).
  1287. 60.45 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.924923] systemd[1]: Finished Load Kernel Module configfs.
  1288. 60.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.935546] systemd[1]: Mounting Kernel Configuration File System...
  1289. 60.47 s [vm-test-run-centjes-e2e-test] client # [ 5.872868] systemd[1]: Starting Load/Save OS Random Seed...
  1290. 60.48 s [vm-test-run-centjes-e2e-test] client # [ 5.888121] systemd[1]: Starting Apply Kernel Variables...
  1291. 60.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.957367] EXT4-fs (vda): re-mounted 6e28e413-a81c-44a9-9ae4-e393375b3fa3.
  1292. 60.49 s [vm-test-run-centjes-e2e-test] client # [ 5.891792] systemd[1]: TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1293. 60.50 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.967338] systemd[1]: Mounted Kernel Configuration File System.
  1294. 60.50 s [vm-test-run-centjes-e2e-test] client # [ 5.902776] systemd[1]: Mounted FUSE Control File System.
  1295. 60.50 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.973231] fuse: init (API version 7.41)
  1296. 60.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.989827] systemd[1]: modprobe@fuse.service: Deactivated successfully.
  1297. 60.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.993522] loop: module loaded
  1298. 60.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.995833] systemd[1]: Finished Load Kernel Module fuse.
  1299. 60.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.004985] systemd[1]: Mounting FUSE Control File System...
  1300. 60.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.011270] systemd-journald[381]: Collecting audit messages is enabled.
  1301. 60.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.014886] systemd[1]: Finished Remount Root and Kernel File Systems.
  1302. 60.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.019884] systemd[1]: Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore).
  1303. 60.57 s [vm-test-run-centjes-e2e-test] client # [ 5.972633] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.
  1304. 60.57 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.042163] systemd[1]: Starting Load/Save OS Random Seed...
  1305. 60.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.047295] systemd[1]: TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1306. 60.58 s [vm-test-run-centjes-e2e-test] client # [ 5.981442] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
  1307. 60.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.059875] systemd[1]: Finished Load Kernel Modules.
  1308. 60.59 s [vm-test-run-centjes-e2e-test] client # [ 5.993618] systemd[1]: Starting Create Static Device Nodes in /dev...
  1309. 60.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.065344] systemd[1]: Mounted FUSE Control File System.
  1310. 60.61 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.079089] systemd[1]: Starting Firewall...
  1311. 60.62 s [vm-test-run-centjes-e2e-test] client # [ 6.019467] systemd[1]: Finished Load/Save OS Random Seed.
  1312. 60.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.088626] systemd[1]: Starting Apply Kernel Variables...
  1313. 60.62 s [vm-test-run-centjes-e2e-test] client # [ 6.026682] systemd[1]: Reached target First Boot Complete.
  1314. 60.63 s [vm-test-run-centjes-e2e-test] client # [ 6.037723] systemd[1]: Finished Apply Kernel Variables.
  1315. 60.67 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.140111] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
  1316. 60.68 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.152234] systemd[1]: Starting Create Static Device Nodes in /dev...
  1317. 60.69 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.157776] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.
  1318. 60.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.185985] systemd[1]: Finished Load/Save OS Random Seed.
  1319. 60.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.191709] systemd[1]: Reached target First Boot Complete.
  1320. 60.73 s [vm-test-run-centjes-e2e-test] client # [ 6.133908] systemd[1]: Finished Create Static Device Nodes in /dev.
  1321. 60.74 s [vm-test-run-centjes-e2e-test] client # [ 6.139708] systemd[1]: Reached target Preparation for Local File Systems.
  1322. 60.75 s [vm-test-run-centjes-e2e-test] client # [ 6.150335] systemd[1]: Starting Rule-based Manager for Device Events and Files...
  1323. 60.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.231182] systemd[1]: Finished Apply Kernel Variables.
  1324. 60.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.289815] systemd[1]: Finished Create Static Device Nodes in /dev.
  1325. 60.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.295982] systemd[1]: Reached target Preparation for Local File Systems.
  1326. 60.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.305921] systemd[1]: Starting Rule-based Manager for Device Events and Files...
  1327. 60.91 s [vm-test-run-centjes-e2e-test] client # [ 6.311841] systemd[1]: Started Journal Service.
  1328. 60.92 s [vm-test-run-centjes-e2e-test] client # [ 5.960493] systemd-modules-load[386]: Inserted module 'loop'
  1329. 60.94 s [vm-test-run-centjes-e2e-test] client # [ 5.977379] systemd-oomd[387]: [0;1;38:5:185mNo swap; memory pressure usage will be degraded
  1330. 60.95 s [vm-test-run-centjes-e2e-test] client # [ 5.992412] systemd-udevd[412]: Using default interface naming scheme 'v258'.
  1331. 60.96 s [vm-test-run-centjes-e2e-test] client # [ 6.004351] systemd[1]: Starting Flush Journal to Persistent Storage...
  1332. 61.00 s [vm-test-run-centjes-e2e-test] client # [ 6.404033] systemd-journald[385]: Received client request to flush runtime journal.
  1333. 61.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.508057] systemd[1]: Started Journal Service.
  1334. 61.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.123234] systemd-modules-load[382]: Inserted module 'loop'
  1335. 61.07 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.135830] systemd-oomd[383]: [0;1;38:5:185mNo swap; memory pressure usage will be degraded
  1336. 61.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.158426] systemd-udevd[404]: Using default interface naming scheme 'v258'.
  1337. 61.10 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.176315] systemd[1]: Starting Flush Journal to Persistent Storage...
  1338. 61.15 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.618870] systemd-journald[381]: Received client request to flush runtime journal.
  1339. 61.22 s [vm-test-run-centjes-e2e-test] client # [ 6.267550] systemd[1]: Finished Coldplug All udev Devices.
  1340. 61.23 s [vm-test-run-centjes-e2e-test] client # [ 6.277294] systemd[1]: Started Rule-based Manager for Device Events and Files.
  1341. 61.24 s [vm-test-run-centjes-e2e-test] client # [ 6.285711] systemd[1]: Finished Flush Journal to Persistent Storage.
  1342. 61.25 s [vm-test-run-centjes-e2e-test] client # [ 6.297464] systemd[1]: Mounting /run/wrappers...
  1343. 61.29 s [vm-test-run-centjes-e2e-test] client # [ 6.332547] systemd[1]: Mounted /run/wrappers.
  1344. 61.29 s [vm-test-run-centjes-e2e-test] client # [ 6.344109] systemd[1]: Reached target Local File Systems.
  1345. 61.31 s [vm-test-run-centjes-e2e-test] client # [ 6.350628] systemd[1]: Listening on Boot Entries Service Socket.
  1346. 61.32 s [vm-test-run-centjes-e2e-test] client # [ 6.360499] systemd[1]: Starting Create SUID/SGID Wrappers...
  1347. 61.33 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.413287] systemd[1]: Finished Coldplug All udev Devices.
  1348. 61.34 s [vm-test-run-centjes-e2e-test] client # [ 6.370875] systemd[1]: Update Boot Loader Random Seed was skipped because no trigger condition checks were met.
  1349. 61.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.422357] systemd[1]: Started Rule-based Manager for Device Events and Files.
  1350. 61.35 s [vm-test-run-centjes-e2e-test] client # [ 6.388762] systemd[1]: Starting Save Transient machine-id to Disk...
  1351. 61.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.428723] systemd[1]: Finished Flush Journal to Persistent Storage.
  1352. 61.36 s [vm-test-run-centjes-e2e-test] client # [ 6.399770] systemd[1]: Starting Create System Files and Directories...
  1353. 61.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.454893] systemd[1]: Mounting /run/wrappers...
  1354. 61.42 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.495223] systemd[1]: Mounted /run/wrappers.
  1355. 61.42 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.501099] systemd[1]: Reached target Local File Systems.
  1356. 61.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.511251] systemd[1]: Listening on Boot Entries Service Socket.
  1357. 61.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.519474] systemd[1]: Starting Create SUID/SGID Wrappers...
  1358. 61.45 s [vm-test-run-centjes-e2e-test] client # [ 6.483894] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
  1359. 61.45 s [vm-test-run-centjes-e2e-test] client # [ 6.498941] systemd[1]: Finished Save Transient machine-id to Disk.
  1360. 61.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.528311] systemd[1]: Update Boot Loader Random Seed was skipped because no trigger condition checks were met.
  1361. 61.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.543346] systemd[1]: Starting Save Transient machine-id to Disk...
  1362. 61.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.551630] systemd[1]: Starting Create System Files and Directories...
  1363. 61.49 s [vm-test-run-centjes-e2e-test] client # [ 6.535253] systemd[1]: Finished Create System Files and Directories.
  1364. 61.50 s [vm-test-run-centjes-e2e-test] client # [ 6.545778] systemd[1]: Starting Rebuild Journal Catalog...
  1365. 61.52 s [vm-test-run-centjes-e2e-test] client # [ 6.558733] systemd[1]: Starting Record System Boot/Shutdown in UTMP...
  1366. 61.59 s [vm-test-run-centjes-e2e-test] client # [ 6.635951] systemd[1]: Finished Record System Boot/Shutdown in UTMP.
  1367. 61.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.674397] systemd[1]: Finished Create System Files and Directories.
  1368. 61.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.690226] systemd[1]: Starting Rebuild Journal Catalog...
  1369. 61.63 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.704498] systemd[1]: Starting Record System Boot/Shutdown in UTMP...
  1370. 61.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.715166] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
  1371. 61.65 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.723530] systemd[1]: Finished Save Transient machine-id to Disk.
  1372. 61.66 s [vm-test-run-centjes-e2e-test] client # [ 6.702549] systemd[1]: Finished Rebuild Journal Catalog.
  1373. 61.67 s [vm-test-run-centjes-e2e-test] client # [ 6.712464] systemd[1]: Starting Update is Completed...
  1374. 61.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.783246] systemd[1]: Finished Record System Boot/Shutdown in UTMP.
  1375. 61.74 s [vm-test-run-centjes-e2e-test] client # [ 6.782439] systemd[1]: Finished Update is Completed.
  1376. 61.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.847944] systemd[1]: Finished Rebuild Journal Catalog.
  1377. 61.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.853951] systemd[1]: Starting Update is Completed...
  1378. 61.84 s [vm-test-run-centjes-e2e-test] client # [ 6.883591] systemd[1]: Found device /dev/hvc0.
  1379. 61.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.922456] systemd[1]: Finished Update is Completed.
  1380. 61.88 s [vm-test-run-centjes-e2e-test] client # [ 6.924887] systemd[1]: Found device /dev/ttyS0.
  1381. 61.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.993514] systemd[1]: Found device /dev/hvc0.
  1382. 61.95 s [vm-test-run-centjes-e2e-test] client # [ 6.983179] (udev-worker)[484]: [0;1;38:5:185meth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.
  1383. 61.96 s [vm-test-run-centjes-e2e-test] client # [ 7.001261] (udev-worker)[484]: Network interface NamePolicy= disabled on kernel command line.
  1384. 61.97 s [vm-test-run-centjes-e2e-test] client # [ 7.012505] (udev-worker)[489]: Network interface NamePolicy= disabled on kernel command line.
  1385. 62.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.072556] (udev-worker)[472]: Network interface NamePolicy= disabled on kernel command line.
  1386. 62.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.086817] (udev-worker)[471]: [0;1;38:5:185meth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.
  1387. 62.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.114411] (udev-worker)[471]: Network interface NamePolicy= disabled on kernel command line.
  1388. 62.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.124448] systemd[1]: Found device /dev/ttyS0.
  1389. 62.15 s [vm-test-run-centjes-e2e-test] client # [ 7.190241] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.
  1390. 62.15 s [vm-test-run-centjes-e2e-test] client # [ 7.200631] systemd[1]: Finished Create SUID/SGID Wrappers.
  1391. 62.16 s [vm-test-run-centjes-e2e-test] client # [ 7.208348] systemd[1]: Reached target System Initialization.
  1392. 62.18 s [vm-test-run-centjes-e2e-test] client # [ 7.216595] systemd[1]: Started Discard unused filesystem blocks once a week.
  1393. 62.19 s [vm-test-run-centjes-e2e-test] client # [ 7.234272] systemd[1]: Started Daily Cleanup of Temporary Directories.
  1394. 62.21 s [vm-test-run-centjes-e2e-test] client # [ 7.247470] systemd[1]: Reached target Timer Units.
  1395. 62.22 s [vm-test-run-centjes-e2e-test] client # [ 7.262427] systemd[1]: Listening on D-Bus System Message Bus Socket.
  1396. 62.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.309557] systemd[1]: Found device Virtio network device.
  1397. 62.24 s [vm-test-run-centjes-e2e-test] client # [ 7.278427] systemd[1]: Listening on Nix Daemon Socket.
  1398. 62.25 s [vm-test-run-centjes-e2e-test] client # [ 7.293234] systemd[1]: Listening on Hostname Service Socket.
  1399. 62.27 s [vm-test-run-centjes-e2e-test] client # [ 7.307600] systemd[1]: Reached target Socket Units.
  1400. 62.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.347492] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.
  1401. 62.28 s [vm-test-run-centjes-e2e-test] client # [ 7.324232] systemd[1]: Reached target Basic System.
  1402. 62.28 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.360718] systemd[1]: Finished Create SUID/SGID Wrappers.
  1403. 62.29 s [vm-test-run-centjes-e2e-test] client # [ 7.334576] systemd[1]: Started backdoor.service.
  1404. 62.30 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.370544] systemd[1]: Reached target System Initialization.
  1405. 62.31 s [vm-test-run-centjes-e2e-test] client # [ 7.349963] systemd[1]: Starting Import lastlog data into lastlog2 database...
  1406. 62.32 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.382763] systemd[1]: Started Discard unused filesystem blocks once a week.
  1407. 62.32 s [vm-test-run-centjes-e2e-test] client # [ 7.363449] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
  1408. 62.33 s [vm-test-run-centjes-e2e-test] client # [ 7.373938] systemd[1]: Started Reset console on configuration changes.
  1409. 62.34 s [vm-test-run-centjes-e2e-test] client # [ 7.380724] systemd[1]: Starting resolvconf update...
  1410. 62.34 s [vm-test-run-centjes-e2e-test] client # connecting to host...
  1411. 62.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.406460] systemd[1]: Started Daily Cleanup of Temporary Directories.
  1412. 62.35 s [vm-test-run-centjes-e2e-test] client # [ 7.393688] systemd[1]: Found device Virtio network device.
  1413. 62.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.430496] systemd[1]: Reached target Timer Units.
  1414. 62.37 s [vm-test-run-centjes-e2e-test] client # [ 7.406845] systemd[1]: Starting D-Bus System Message Bus...
  1415. 62.38 s [vm-test-run-centjes-e2e-test] client # [ 7.424236] systemd[1]: Finished Firewall.
  1416. 62.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.444554] systemd[1]: Listening on D-Bus System Message Bus Socket.
  1417. 62.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.460739] systemd[1]: Listening on Nix Daemon Socket.
  1418. 62.39 s [vm-test-run-centjes-e2e-test] client # [ 7.428010] nsncd[621]: Apr 27 13:42:42.452 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
  1419. 62.41 s [vm-test-run-centjes-e2e-test] client # [ 7.450542] systemd[1]: Finished Import lastlog data into lastlog2 database.
  1420. 62.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.478792] systemd[1]: Listening on Hostname Service Socket.
  1421. 62.42 s [vm-test-run-centjes-e2e-test] client # [ 7.463299] systemd[1]: Started Name Service Cache Daemon (nsncd).
  1422. 62.43 s [vm-test-run-centjes-e2e-test] client # [ 7.475822] systemd[1]: Reached target Host and Network Name Lookups.
  1423. 62.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.510403] systemd[1]: Reached target Socket Units.
  1424. 62.45 s [vm-test-run-centjes-e2e-test] client # [ 7.489667] systemd[1]: Reached target User and Group Name Lookups.
  1425. 62.45 s [vm-test-run-centjes-e2e-test] client # [ 7.501192] systemd[1]: Starting User Login Management...
  1426. 62.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.528594] systemd[1]: Reached target Basic System.
  1427. 62.47 s [vm-test-run-centjes-e2e-test] client # [ 7.506952] dbus-daemon[625]: dbus[625]: Unknown username "systemd-timesync" in message bus configuration file
  1428. 62.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.544642] systemd[1]: Started backdoor.service.
  1429. 62.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.560454] systemd[1]: Starting Import lastlog data into lastlog2 database...
  1430. 62.50 s [vm-test-run-centjes-e2e-test] docsserver # connecting to host...
  1431. 62.52 s [vm-test-run-centjes-e2e-test] client # [ 7.557731] systemd[1]: Started D-Bus System Message Bus.
  1432. 62.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.585782] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
  1433. 62.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.608412] systemd[1]: Started Reset console on configuration changes.
  1434. 62.55 s [vm-test-run-centjes-e2e-test] client # [ 7.592856] systemd[1]: Stopped target Host and Network Name Lookups.
  1435. 62.57 s [vm-test-run-centjes-e2e-test] client # [ 7.604837] systemd[1]: Stopping Host and Network Name Lookups...
  1436. 62.57 s [vm-test-run-centjes-e2e-test] docsserver: Guest shell says: b'Spawning backdoor root shell...\n'
  1437. 62.58 s [vm-test-run-centjes-e2e-test] docsserver: connected to guest root shell
  1438. 62.58 s [vm-test-run-centjes-e2e-test] docsserver: (connecting took 8.67 seconds)
  1439. 62.58 s [vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for the VM to finish booting, in 8.67 seconds)
  1440. 62.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.623354] nsncd[617]: Apr 27 13:42:42.495 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
  1441. 62.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.660255] systemd[1]: Starting resolvconf update...
  1442. 62.58 s [vm-test-run-centjes-e2e-test] client # [ 7.618826] systemd[1]: Stopped target User and Group Name Lookups.
  1443. 62.58 s [vm-test-run-centjes-e2e-test] client # [ 7.626847] systemd[1]: Stopping User and Group Name Lookups...
  1444. 62.59 s [vm-test-run-centjes-e2e-test] client # [ 7.636554] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...
  1445. 62.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.669214] systemd[1]: Started Centjes docs site production Service.
  1446. 62.60 s [vm-test-run-centjes-e2e-test] client # [ 7.647956] systemd[1]: nscd.service: Deactivated successfully.
  1447. 62.61 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.684272] systemd[1]: Starting D-Bus System Message Bus...
  1448. 62.61 s [vm-test-run-centjes-e2e-test] client # [ 7.655795] systemd[1]: Stopped Name Service Cache Daemon (nsncd).
  1449. 62.62 s [vm-test-run-centjes-e2e-test] client # [ 7.666904] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
  1450. 62.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.698924] systemd[1]: Finished Firewall.
  1451. 62.63 s [vm-test-run-centjes-e2e-test] client # [ 7.678704] systemd-logind[649]: New seat seat0.
  1452. 62.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.709949] systemd[1]: Finished Import lastlog data into lastlog2 database.
  1453. 62.64 s [vm-test-run-centjes-e2e-test] client # [ 7.687619] systemd[1]: Started User Login Management.
  1454. 62.65 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.722443] systemd[1]: Started Name Service Cache Daemon (nsncd).
  1455. 62.65 s [vm-test-run-centjes-e2e-test] client # [ 7.696843] systemd[1]: Starting linger-users.service...
  1456. 62.66 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.735312] systemd[1]: Reached target Host and Network Name Lookups.
  1457. 62.68 s [vm-test-run-centjes-e2e-test] client # [ 7.711436] nsncd[687]: Apr 27 13:42:42.744 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
  1458. 62.68 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.746555] dbus-daemon[621]: dbus[621]: Unknown username "systemd-timesync" in message bus configuration file
  1459. 62.69 s [vm-test-run-centjes-e2e-test] client # [ 7.730659] systemd[1]: Started Name Service Cache Daemon (nsncd).
  1460. 62.69 s [vm-test-run-centjes-e2e-test] client # [ 7.738185] systemd[1]: Reached target Host and Network Name Lookups.
  1461. 62.69 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.768298] systemd[1]: Reached target User and Group Name Lookups.
  1462. 62.70 s [vm-test-run-centjes-e2e-test] client # [ 7.743676] systemd[1]: Reached target User and Group Name Lookups.
  1463. 62.70 s [vm-test-run-centjes-e2e-test] client # [ 8.104461] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input3
  1464. 62.70 s [vm-test-run-centjes-e2e-test] client # [ 7.752383] systemd[1]: linger-users.service: Deactivated successfully.
  1465. 62.70 s [vm-test-run-centjes-e2e-test] client # [ 7.754522] systemd[1]: Finished linger-users.service.
  1466. 62.70 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.778725] systemd[1]: Starting User Login Management...
  1467. 62.71 s [vm-test-run-centjes-e2e-test] client # [ 8.116482] mousedev: PS/2 mouse device common for all mice
  1468. 62.74 s [vm-test-run-centjes-e2e-test] client # [ 7.781532] systemd[1]: Finished resolvconf update.
  1469. 62.74 s [vm-test-run-centjes-e2e-test] client # [ 7.787345] systemd[1]: Reached target Preparation for Network.
  1470. 62.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.814486] systemd[1]: Stopped target Host and Network Name Lookups.
  1471. 62.75 s [vm-test-run-centjes-e2e-test] client # [ 7.793876] systemd[1]: Starting DHCP Client...
  1472. 62.76 s [vm-test-run-centjes-e2e-test] client # [ 7.802583] systemd[1]: Starting Address configuration of eth1...
  1473. 62.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.831446] systemd[1]: Stopping Host and Network Name Lookups...
  1474. 62.77 s [vm-test-run-centjes-e2e-test] client # [ 8.177097] ACPI: button: Power Button [PWRF]
  1475. 62.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.841887] systemd[1]: Stopped target User and Group Name Lookups.
  1476. 62.79 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.864418] systemd[1]: Stopping User and Group Name Lookups...
  1477. 62.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.872522] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...
  1478. 62.80 s [vm-test-run-centjes-e2e-test] client # [ 8.206407] rtc_cmos 00:05: RTC can wake from S4
  1479. 62.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.882409] systemd[1]: Started D-Bus System Message Bus.
  1480. 62.81 s [vm-test-run-centjes-e2e-test] client # [ 8.214769] Floppy drive(s): fd0 is 2.88M AMI BIOS
  1481. 62.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.890372] systemd[1]: nscd.service: Deactivated successfully.
  1482. 62.82 s [vm-test-run-centjes-e2e-test] client # [ 8.223923] parport_pc 00:03: reported by Plug and Play ACPI
  1483. 62.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.898636] systemd[1]: Stopped Name Service Cache Daemon (nsncd).
  1484. 62.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.918657] systemd-logind[642]: New seat seat0.
  1485. 62.85 s [vm-test-run-centjes-e2e-test] client # [ 8.253456] FDC 0 is a S82078B
  1486. 62.85 s [vm-test-run-centjes-e2e-test] client # [ 8.257036] rtc_cmos 00:05: registered as rtc0
  1487. 62.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.935206] systemd[1]: Started User Login Management.
  1488. 62.87 s [vm-test-run-centjes-e2e-test] client # [ 8.272321] parport0: PC-style at 0x378, irq 7 [PCSPP(,...)]
  1489. 62.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.948814] systemd[1]: Starting linger-users.service...
  1490. 62.88 s [vm-test-run-centjes-e2e-test] client # [ 7.927278] network-addresses-eth1-start[716]: adding address 192.168.1.1/24... done[ 8.284683] rtc_cmos 00:05: setting system clock to 2026-04-27T13:42:42 UTC (1777297362)
  1491. 62.88 s [vm-test-run-centjes-e2e-test] client #
  1492. 62.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.961106] systemd[1]: Starting Name Service Cache Daemon (nsncd)...[ 8.356992] mousedev: PS/2 mouse device common for all mice
  1493. 62.89 s [vm-test-run-centjes-e2e-test] docsserver #
  1494. 62.89 s [vm-test-run-centjes-e2e-test] client # [ 8.292699] systemd-journald[385]: Time jumped backwards, rotating.
  1495. 62.92 s [vm-test-run-centjes-e2e-test] client # [ 8.324759] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs
  1496. 62.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.005410] systemd[1]: Finished resolvconf update.
  1497. 62.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.013402] systemd[1]: Reached target Preparation for Network.
  1498. 62.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.024728] systemd[1]: Starting DHCP Client...
  1499. 62.96 s [vm-test-run-centjes-e2e-test] client # [ 7.992773] network-addresses-eth1-start[716]: adding address 2001:db8:1::1/64... done
  1500. 62.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.035342] systemd[1]: Starting Address configuration of eth1...
  1501. 62.97 s [vm-test-run-centjes-e2e-test] client # [ 8.012593] systemd[1]: Finished Address configuration of eth1.
  1502. 62.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.053315] systemd[1]: linger-users.service: Deactivated successfully.
  1503. 62.98 s [vm-test-run-centjes-e2e-test] client # [ 8.025782] systemd[1]: Starting Networking Setup...
  1504. 62.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.061651] systemd[1]: Finished linger-users.service.
  1505. 63.00 s [vm-test-run-centjes-e2e-test] client # [ 8.044366] dhcpcd[723]: dhcpcd-10.2.4 starting
  1506. 63.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.083858] systemd[1]: Started Name Service Cache Daemon (nsncd).
  1507. 63.01 s [vm-test-run-centjes-e2e-test] client # [ 8.057601] dhcpcd[736]: dev: loaded udev
  1508. 63.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.095684] nsncd[706]: Apr 27 13:42:42.986 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"[ 8.492805] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input3
  1509. 63.03 s [vm-test-run-centjes-e2e-test] client # [ 8.434854] 8021q: 802.1Q VLAN Support v1.8
  1510. 63.03 s [vm-test-run-centjes-e2e-test] docsserver #
  1511. 63.03 s [vm-test-run-centjes-e2e-test] client # [ 8.438605] 8021q: adding VLAN 0 to HW filter on device eth1
  1512. 63.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.121958] systemd[1]: Reached target Host and Network Name Lookups.
  1513. 63.06 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.129648] systemd[1]: Reached target User and Group Name Lookups.
  1514. 63.07 s [vm-test-run-centjes-e2e-test] client # [ 8.473371] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0
  1515. 63.10 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.571381] ACPI: button: Power Button [PWRF]
  1516. 63.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.193677] network-addresses-eth1-start[717]: adding address 192.168.1.2/24... done
  1517. 63.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.212215] network-addresses-eth1-start[717]: adding address 2001:db8:1::2/64... done
  1518. 63.15 s [vm-test-run-centjes-e2e-test] client # [ 8.550719] i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD
  1519. 63.17 s [vm-test-run-centjes-e2e-test] client # [ 8.570301] cfg80211: Loading compiled-in X.509 certificates for regulatory database
  1520. 63.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.243387] systemd[1]: Finished Address configuration of eth1.
  1521. 63.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.253294] systemd[1]: Starting Networking Setup...
  1522. 63.18 s [vm-test-run-centjes-e2e-test] client # [ 8.580438] input: QEMU Virtio Keyboard as /devices/pci0000:00/0000:00:0a.0/virtio7/input/input4
  1523. 63.20 s [vm-test-run-centjes-e2e-test] client # [ 8.605360] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
  1524. 63.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.676211] rtc_cmos 00:05: RTC can wake from S4
  1525. 63.21 s [vm-test-run-centjes-e2e-test] client # [ 8.256767] systemd[1]: Finished Networking Setup.[ 8.613428] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'
  1526. 63.22 s [vm-test-run-centjes-e2e-test] client # [ 8.620275] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
  1527. 63.22 s [vm-test-run-centjes-e2e-test] client #
  1528. 63.22 s [vm-test-run-centjes-e2e-test] client # [ 8.627247] cfg80211: failed to load regulatory.db
  1529. 63.23 s [vm-test-run-centjes-e2e-test] client # [ 8.274552] systemd[1]: Reached target Network.[ 8.631700] bochs-drm 0000:00:02.0: vgaarb: deactivate vga console
  1530. 63.23 s [vm-test-run-centjes-e2e-test] client #
  1531. 63.23 s [vm-test-run-centjes-e2e-test] client # [ 8.279687] systemd[1]: Starting Permit User Sessions...
  1532. 63.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.317974] dhcpcd[735]: dhcpcd-10.2.4 starting
  1533. 63.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.714889] parport_pc 00:03: reported by Plug and Play ACPI
  1534. 63.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.335859] dhcpcd[749]: dev: loaded udev
  1535. 63.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.736992] Floppy drive(s): fd0 is 2.88M AMI BIOS
  1536. 63.27 s [vm-test-run-centjes-e2e-test] client # [ 8.669766] cryptd: max_cpu_qlen set to 1000
  1537. 63.28 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.750373] 8021q: 802.1Q VLAN Support v1.8
  1538. 63.28 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.754613] 8021q: adding VLAN 0 to HW filter on device eth1
  1539. 63.29 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.762104] rtc_cmos 00:05: registered as rtc0
  1540. 63.29 s [vm-test-run-centjes-e2e-test] client # [ 8.342205] systemd[1]: Finished Permit User Sessions.
  1541. 63.30 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.770302] parport0: PC-style at 0x378, irq 7 [PCSPP(,...)]
  1542. 63.32 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.786809] rtc_cmos 00:05: setting system clock to 2026-04-27T13:42:43 UTC (1777297363)
  1543. 63.32 s [vm-test-run-centjes-e2e-test] client # [ 8.710153] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input6
  1544. 63.33 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.801746] FDC 0 is a S82078B
  1545. 63.35 s [vm-test-run-centjes-e2e-test] client # [ 8.710738] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input5
  1546. 63.36 s [vm-test-run-centjes-e2e-test] client # [ 8.724585] Console: switching to colour dummy device 80x25
  1547. 63.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.833821] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs
  1548. 63.37 s [vm-test-run-centjes-e2e-test] client # [ 8.738478] 8021q: adding VLAN 0 to HW filter on device eth0
  1549. 63.38 s [vm-test-run-centjes-e2e-test] client # [ 8.746006] AES CTR mode by8 optimization enabled
  1550. 63.39 s [vm-test-run-centjes-e2e-test] client # [ 8.383882] dhcpcd[736]: eth0: waiting for carrier
  1551. 63.39 s [vm-test-run-centjes-e2e-test] client # [ 8.441874] dhcpcd[736]: libudev: received NULL device
  1552. 63.40 s [vm-test-run-centjes-e2e-test] client # [ 8.445714] systemd[1]: Started Getty on tty1.[ 8.802746] [drm] Found bochs VGA, ID 0xb0c5.
  1553. 63.40 s [vm-test-run-centjes-e2e-test] client # [ 8.803885] [drm] Framebuffer size 16384 kB @ 0xfd000000, mmio @ 0xfebd0000.
  1554. 63.40 s [vm-test-run-centjes-e2e-test] client #
  1555. 63.40 s [vm-test-run-centjes-e2e-test] client # [ 8.450730] dhcpcd[736]: libudev: received NULL device
  1556. 63.40 s [vm-test-run-centjes-e2e-test] client # [ 8.452721] systemd[1]: Reached target Login Prompts.
  1557. 63.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.885022] cfg80211: Loading compiled-in X.509 certificates for regulatory database
  1558. 63.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.523601] systemd[1]: Finished Networking Setup.
  1559. 63.45 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.530689] systemd[1]: Reached target Network.
  1560. 63.45 s [vm-test-run-centjes-e2e-test] client # [ 8.500173] systemd[1]: Starting Virtual Console Setup...
  1561. 63.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.534687] systemd[1]: Starting Permit User Sessions...[ 8.928339] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
  1562. 63.46 s [vm-test-run-centjes-e2e-test] client # [ 8.862497] [drm] Found EDID data blob.
  1563. 63.46 s [vm-test-run-centjes-e2e-test] docsserver #
  1564. 63.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.931770] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'
  1565. 63.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.939626] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
  1566. 63.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.946509] cfg80211: failed to load regulatory.db
  1567. 63.48 s [vm-test-run-centjes-e2e-test] client # [ 8.524769] systemd-logind[649]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard)[ 8.883579] [drm] Initialized bochs-drm 1.0.0 for 0000:00:02.0 on minor 0
  1568. 63.49 s [vm-test-run-centjes-e2e-test] client #
  1569. 63.51 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.980266] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0
  1570. 63.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.609269] systemd[1]: Finished Permit User Sessions.
  1571. 63.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.616714] systemd[1]: Started Getty on tty1.
  1572. 63.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.623900] systemd[1]: Reached target Login Prompts.
  1573. 63.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.034115] i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD
  1574. 63.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.053082] 8021q: adding VLAN 0 to HW filter on device eth0
  1575. 63.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.667623] dhcpcd[749]: eth0: waiting for carrier
  1576. 63.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.063938] input: QEMU Virtio Keyboard as /devices/pci0000:00/0000:00:0a.0/virtio7/input/input4
  1577. 63.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.069730] bochs-drm 0000:00:02.0: vgaarb: deactivate vga console
  1578. 63.61 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.086305] cryptd: max_cpu_qlen set to 1000
  1579. 63.63 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.092952] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input6
  1580. 63.68 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.135156] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input5
  1581. 63.70 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.151373] Console: switching to colour dummy device 80x25
  1582. 63.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.153761] AES CTR mode by8 optimization enabled
  1583. 63.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.195273] [drm] Found bochs VGA, ID 0xb0c5.
  1584. 63.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.196365] [drm] Framebuffer size 16384 kB @ 0xfd000000, mmio @ 0xfebd0000.
  1585. 63.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.842370] systemd[1]: Starting Virtual Console Setup...
  1586. 63.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.255257] [drm] Found EDID data blob.
  1587. 63.79 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.259670] [drm] Initialized bochs-drm 1.0.0 for 0000:00:02.0 on minor 0
  1588. 63.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.880229] systemd-logind[642]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard)
  1589. 64.21 s [vm-test-run-centjes-e2e-test] client # [ 8.904046] fbcon: bochs-drmdrmfb (fb0) is primary device
  1590. 64.21 s [vm-test-run-centjes-e2e-test] client # [ 9.483459] Console: switching to colour frame buffer device 160x50
  1591. 64.21 s [vm-test-run-centjes-e2e-test] client # [ 9.617400] bochs-drm 0000:00:02.0: [drm] fb0: bochs-drmdrmfb frame buffer device
  1592. 64.21 s [vm-test-run-centjes-e2e-test] client # [ 9.106602] dhcpcd[736]: eth0: carrier acquired
  1593. 64.22 s [vm-test-run-centjes-e2e-test] client # [ 9.265901] dhcpcd[736]: DUID 00:01:00:01:31:82:24:53:52:54:00:12:34:56
  1594. 64.22 s [vm-test-run-centjes-e2e-test] client # [ 9.268241] dhcpcd[736]: eth0: IAID 00:12:34:56
  1595. 64.22 s [vm-test-run-centjes-e2e-test] client # [ 9.270298] dhcpcd[736]: eth0: adding address fe80::5054:ff:fe12:3456
  1596. 64.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.907970] systemd-logind[642]: Watching system buttons on /dev/input/event2 (Power Button)
  1597. 64.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.458282] dhcpcd[749]: eth0: carrier acquired
  1598. 64.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.473232] dhcpcd[749]: DUID 00:01:00:01:31:82:24:54:52:54:00:12:34:56
  1599. 64.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.475580] dhcpcd[749]: eth0: IAID 00:12:34:56
  1600. 64.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.477584] dhcpcd[749]: eth0: adding address fe80::5054:ff:fe12:3456
  1601. 64.42 s [vm-test-run-centjes-e2e-test] client # [ 9.461797] systemd-logind[649]: Watching system buttons on /dev/input/event2 (Power Button)
  1602. 64.42 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.492243] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
  1603. 64.43 s [vm-test-run-centjes-e2e-test] client # [ 9.839747] ppdev: user-space parallel port driver
  1604. 64.47 s [vm-test-run-centjes-e2e-test] client # [ 9.510475] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
  1605. 64.49 s [vm-test-run-centjes-e2e-test] client # [ 9.896980] kvm_amd: TSC scaling supported
  1606. 64.49 s [vm-test-run-centjes-e2e-test] client # [ 9.898054] kvm_amd: Nested Virtualization enabled
  1607. 64.49 s [vm-test-run-centjes-e2e-test] client # [ 9.899245] kvm_amd: Nested Paging enabled
  1608. 64.49 s [vm-test-run-centjes-e2e-test] client # [ 9.900274] kvm_amd: LBR virtualization supported
  1609. 64.53 s [vm-test-run-centjes-e2e-test] client # [ 9.936086] kvm_amd: Virtual VMLOAD VMSAVE supported
  1610. 64.53 s [vm-test-run-centjes-e2e-test] client # [ 9.937333] kvm_amd: Virtual GIF supported
  1611. 64.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.296364] fbcon: bochs-drmdrmfb (fb0) is primary device
  1612. 64.56 s [vm-test-run-centjes-e2e-test] client # [ 9.604750] systemd-logind[649]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)
  1613. 64.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.896730] Console: switching to colour frame buffer device 160x50
  1614. 64.57 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.039368] bochs-drm 0000:00:02.0: [drm] fb0: bochs-drmdrmfb frame buffer device
  1615. 64.59 s [vm-test-run-centjes-e2e-test] client # [ 9.630164] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
  1616. 64.59 s [vm-test-run-centjes-e2e-test] client # [ 9.639780] systemd[1]: Stopped Virtual Console Setup.
  1617. 64.60 s [vm-test-run-centjes-e2e-test] client # [ 9.646238] systemd[1]: Starting Virtual Console Setup...
  1618. 64.65 s [vm-test-run-centjes-e2e-test] client # [ 9.694809] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
  1619. 64.66 s [vm-test-run-centjes-e2e-test] client # [ 9.705291] systemd[1]: Stopped Virtual Console Setup.
  1620. 64.66 s [vm-test-run-centjes-e2e-test] client # [ 9.707599] systemd[1]: Starting Virtual Console Setup...
  1621. 64.67 s [vm-test-run-centjes-e2e-test] client # [ 10.072289] EDAC MC: Ver: 3.0.0
  1622. 64.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.268146] ppdev: user-space parallel port driver
  1623. 64.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.306805] kvm_amd: TSC scaling supported
  1624. 64.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.307860] kvm_amd: Nested Virtualization enabled
  1625. 64.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.308992] kvm_amd: Nested Paging enabled
  1626. 64.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.309993] kvm_amd: LBR virtualization supported
  1627. 64.86 s [vm-test-run-centjes-e2e-test] client # [ 9.906886] dhcpcd[736]: eth0: soliciting a DHCP lease
  1628. 64.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.340233] kvm_amd: Virtual VMLOAD VMSAVE supported
  1629. 64.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.341509] kvm_amd: Virtual GIF supported
  1630. 64.88 s [vm-test-run-centjes-e2e-test] client # [ 10.283298] NET: Registered PF_PACKET protocol family
  1631. 64.89 s [vm-test-run-centjes-e2e-test] client # [ 9.935939] dhcpcd[736]: eth0: offered 10.0.2.15 from 10.0.2.2
  1632. 64.89 s [vm-test-run-centjes-e2e-test] client # [ 9.939375] dhcpcd[736]: eth0: probing address 10.0.2.15/24
  1633. 64.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.998366] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
  1634. 64.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.008438] systemd[1]: Stopped Virtual Console Setup.
  1635. 64.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.015619] systemd[1]: Starting Virtual Console Setup...
  1636. 64.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.020563] systemd-logind[642]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)
  1637. 65.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.089696] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
  1638. 65.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.100792] systemd[1]: Stopped Virtual Console Setup.[ 10.496074] EDAC MC: Ver: 3.0.0
  1639. 65.02 s [vm-test-run-centjes-e2e-test] docsserver #
  1640. 65.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.108415] systemd[1]: Starting Virtual Console Setup...
  1641. 65.08 s [vm-test-run-centjes-e2e-test] client # [ 10.126173] systemd[1]: Finished Virtual Console Setup.
  1642. 65.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.244797] dhcpcd[749]: eth0: soliciting a DHCP lease
  1643. 65.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.655864] NET: Registered PF_PACKET protocol family
  1644. 65.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.275940] dhcpcd[749]: eth0: offered 10.0.2.15 from 10.0.2.2
  1645. 65.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.280398] dhcpcd[749]: eth0: probing address 10.0.2.15/24
  1646. 65.45 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.527195] systemd[1]: Finished Virtual Console Setup.
  1647. 65.83 s [vm-test-run-centjes-e2e-test] client # [ 10.878408] dhcpcd[736]: eth0: soliciting an IPv6 router
  1648. 65.83 s [vm-test-run-centjes-e2e-test] client # [ 10.880785] dhcpcd[736]: eth0: Router Advertisement from fe80::2
  1649. 65.83 s [vm-test-run-centjes-e2e-test] client # [ 10.882972] dhcpcd[736]: eth0: adding address fec0::5054:ff:fe12:3456/64
  1650. 65.84 s [vm-test-run-centjes-e2e-test] client # [ 10.885168] dhcpcd[736]: eth0: adding route to fec0::/64
  1651. 65.84 s [vm-test-run-centjes-e2e-test] client # [ 10.886854] dhcpcd[736]: eth0: adding default route via fe80::2
  1652. 66.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.125772] dhcpcd[749]: eth0: soliciting an IPv6 router
  1653. 66.05 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.128339] dhcpcd[749]: eth0: Router Advertisement from fe80::2
  1654. 66.05 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.130402] dhcpcd[749]: eth0: adding address fec0::5054:ff:fe12:3456/64
  1655. 66.05 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.132558] dhcpcd[749]: eth0: adding route to fec0::/64
  1656. 66.05 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.134525] dhcpcd[749]: eth0: adding default route via fe80::2
  1657. 69.63 s [vm-test-run-centjes-e2e-test] docsserver # [ 14.715463] dhcpcd[749]: eth0: leased 10.0.2.15 for 86400 seconds
  1658. 69.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 14.717916] dhcpcd[749]: eth0: adding route to 10.0.2.0/24
  1659. 69.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 14.720140] dhcpcd[749]: eth0: adding default route via 10.0.2.2
  1660. 69.73 s [vm-test-run-centjes-e2e-test] client # [ 14.774169] dhcpcd[736]: eth0: leased 10.0.2.15 for 86400 seconds
  1661. 69.73 s [vm-test-run-centjes-e2e-test] client # [ 14.776788] dhcpcd[736]: eth0: adding route to 10.0.2.0/24
  1662. 69.73 s [vm-test-run-centjes-e2e-test] client # [ 14.779294] dhcpcd[736]: eth0: adding default route via 10.0.2.2
  1663. 69.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 14.835983] systemd[1]: Started DHCP Client.
  1664. 69.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 14.840518] systemd[1]: Reached target Multi-User System.
  1665. 69.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 14.842990] systemd[1]: Startup finished in 3.700s (kernel) + 11.141s (userspace) = 14.841s.
  1666. 69.84 s [vm-test-run-centjes-e2e-test] client # [ 14.891799] systemd[1]: Started DHCP Client.
  1667. 69.85 s [vm-test-run-centjes-e2e-test] client # [ 14.896804] systemd[1]: Reached target Multi-User System.
  1668. 69.85 s [vm-test-run-centjes-e2e-test] client # [ 14.898692] systemd[1]: Startup finished in 3.562s (kernel) + 11.331s (userspace) = 14.894s.
  1669. 70.18 s [vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for unit default.target, in 16.27 seconds)
  1670. 70.18 s [vm-test-run-centjes-e2e-test] client: waiting for unit default.target
  1671. 70.21 s [vm-test-run-centjes-e2e-test] client: waiting for the VM to finish booting
  1672. 70.21 s [vm-test-run-centjes-e2e-test] client: Guest shell says: b'Spawning backdoor root shell...\n'
  1673. 70.21 s [vm-test-run-centjes-e2e-test] client: connected to guest root shell
  1674. 70.21 s [vm-test-run-centjes-e2e-test] client: (connecting took 0.00 seconds)
  1675. 70.21 s [vm-test-run-centjes-e2e-test] client: (finished: waiting for the VM to finish booting, in 0.00 seconds)
  1676. 70.31 s [vm-test-run-centjes-e2e-test] client: (finished: waiting for unit default.target, in 0.13 seconds)
  1677. 70.38 s [vm-test-run-centjes-e2e-test] docsserver: waiting for unit centjes-docs-site-production.service
  1678. 70.43 s [vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for unit centjes-docs-site-production.service, in 0.05 seconds)
  1679. 70.43 s [vm-test-run-centjes-e2e-test] docsserver: waiting for unit default.target
  1680. 70.48 s [vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for unit default.target, in 0.05 seconds)
  1681. 70.48 s [vm-test-run-centjes-e2e-test] docsserver: waiting for TCP port 8001 on localhost
  1682. 70.56 s [vm-test-run-centjes-e2e-test] docsserver # Connection to localhost (127.0.0.1) 8001 port [tcp/vcom-tunnel] succeeded!
  1683. 70.56 s [vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for TCP port 8001 on localhost, in 0.08 seconds)
  1684. 70.56 s [vm-test-run-centjes-e2e-test] client: must succeed: curl docsserver:8001
  1685. 70.65 s [vm-test-run-centjes-e2e-test] client # % Total % Received % Xferd Average Speed Time Time Time Current
  1686. 70.67 s [vm-test-run-centjes-e2e-test] client # Dload Upload Total Spent Left Speed
  1687. 70.69 s [vm-test-run-centjes-e2e-test] docsserver # [ 15.770847] centjes-docs-site-production-start[633]: 192.168.1.1 - - [27/Apr/2026:13:42:50 +0000] "GET / HTTP/1.1" 200 3595 "" "curl/8.17.0"
  1688. 70.71 s [vm-test-run-centjes-e2e-test] client # 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0100 3595 100 3595 0 0 60437 0 --:--:-- --:--:-- --:--:-- 61982
  1689. 70.71 s [vm-test-run-centjes-e2e-test] client: (finished: must succeed: curl docsserver:8001, in 0.15 seconds)
  1690. 70.71 s [vm-test-run-centjes-e2e-test] (finished: run the VM test script, in 17.12 seconds)
  1691. 70.87 s [vm-test-run-centjes-e2e-test] test script finished in 17.28s
  1692. 70.87 s [vm-test-run-centjes-e2e-test] cleanup
  1693. 70.87 s [vm-test-run-centjes-e2e-test] kill machine (pid 31)
  1694. 70.87 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)
  1695. 70.88 s [vm-test-run-centjes-e2e-test] kill machine (pid 9)
  1696. 70.88 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)
  1697. 70.89 s [vm-test-run-centjes-e2e-test] kill vlan (pid 7)
  1698. 70.89 s [vm-test-run-centjes-e2e-test] (finished: cleanup, in 0.03 seconds)
  1699. 70.99 s [post-build-hook] Uploading paths from nix-ci to cachix cache "centjes" /nix/store/46kxaa8yvw9cbyggqhq5clr29djacynn-vm-test-run-centjes-e2e-test
  1700. 71.37 s [post-build-hook] Pushing 1 paths (0 are already present) using zstd to cache centjes ⏳
  1701. 71.37 s [post-build-hook]
  1702. 71.74 s [post-build-hook] Pushing /nix/store/46kxaa8yvw9cbyggqhq5clr29djacynn-vm-test-run-centjes-e2e-test (96.00 B)
  1703. 72.74 s [post-build-hook]
  1704. 72.74 s [post-build-hook] All done.
  1705. 72.75 s [post-build-hook] Uploading paths from nix-ci to the NixCI staging cache /nix/store/46kxaa8yvw9cbyggqhq5clr29djacynn-vm-test-run-centjes-e2e-test
  1706. 72.79 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  1707. 72.80 s [post-build-hook] copying 1 paths...
  1708. 72.80 s [post-build-hook] copying path '/nix/store/46kxaa8yvw9cbyggqhq5clr29djacynn-vm-test-run-centjes-e2e-test' to 'https://cache.staging.nix-ci.com'...
  1709. 73.00 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  1710. 73.29 s [post-build-hook] copying 0 paths...
  1711. 73.32 s Progress: 10 of 11 built, 2 of 2 fetched
More Logs Raw Logs

Agent Instructions

Wait for completion, without logs:

curl --netrc -N https://staging.nix-ci.com/gh:NorfairKing:centjes/fix-price-change-not-counted-in-average/d9b7e0c6102bb9d29abf89ac5e2d1bc0f38016f4/1d3965dd-f07f-4519-8119-abcabd3148a1/wait

Latest logs, with timestamps (streams while running):

curl --netrc -N https://staging.nix-ci.com/gh:NorfairKing:centjes/fix-price-change-not-counted-in-average/d9b7e0c6102bb9d29abf89ac5e2d1bc0f38016f4/1d3965dd-f07f-4519-8119-abcabd3148a1/tail

All logs, with timestamps (available after completion):

curl --netrc https://staging.nix-ci.com/gh:NorfairKing:centjes/fix-price-change-not-counted-in-average/d9b7e0c6102bb9d29abf89ac5e2d1bc0f38016f4/1d3965dd-f07f-4519-8119-abcabd3148a1/logs

Raw logs, from the start (no timestamps):

curl --netrc -N https://staging.nix-ci.com/gh:NorfairKing:centjes/fix-price-change-not-counted-in-average/d9b7e0c6102bb9d29abf89ac5e2d1bc0f38016f4/1d3965dd-f07f-4519-8119-abcabd3148a1/raw-logs

Content types available for /logs and /tail (use Accept header):

Example:

curl --netrc -H "Accept: text/csv" https://staging.nix-ci.com/gh:NorfairKing:centjes/fix-price-change-not-counted-in-average/d9b7e0c6102bb9d29abf89ac5e2d1bc0f38016f4/1d3965dd-f07f-4519-8119-abcabd3148a1/logs

Reproduce locally: https://staging.nix-ci.com/gh:NorfairKing:centjes/fix-price-change-not-counted-in-average/d9b7e0c6102bb9d29abf89ac5e2d1bc0f38016f4/1d3965dd-f07f-4519-8119-abcabd3148a1/repro

For more instructions, fetch https://staging.nix-ci.com/instructions .