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=refs%2Fpull%2F2%2Fmerge&rev=a5ac38ca38a8ee4de9eabeebe725de50cf47e5f3#checks.x86_64-linux.e2e-test --print-build-logs
  2. 0.11 s warning: ignoring untrusted flake configuration setting 'extra-substituters'.
  3. 0.11 s Pass '--accept-flake-config' to trust it
  4. 0.11 s warning: ignoring untrusted flake configuration setting 'extra-trusted-public-keys'.
  5. 0.11 s Pass '--accept-flake-config' to trust it
  6. 0.12 s
  7. 1.68 s Substituting unit-script-centjes-docs-site-production-start from https://cache.staging.nix-ci.com
  8. 1.70 s Progress: 0 of 2 built, 1 of 9 fetched
  9. 1.83 s Substituting settings-check from https://cache.staging.nix-ci.com
  10. 1.85 s Progress: 0 of 11 built, 2 of 2 fetched
  11. 1.98 s Building settings-check
  12. 2.03 s [settings-check] WithConfig: src/Centjes/Docs/Site/OptParse.hs:27:7 in centjes-docs-site:Centjes.Docs.Site.OptParse
  13. 2.03 s [settings-check] loading config
  14. 2.03 s [settings-check] Parser with check: src/Centjes/Docs/Site/OptParse.hs:27:7 in centjes-docs-site:Centjes.Docs.Site.OptParse
  15. 2.03 s [settings-check] parser
  16. 2.03 s [settings-check] Alt
  17. 2.03 s [settings-check] Trying left side.
  18. 2.03 s [settings-check] Parser with check: src/Centjes/Docs/Site/OptParse.hs:27:7 in centjes-docs-site:Centjes.Docs.Site.OptParse
  19. 2.03 s [settings-check] parser
  20. 2.03 s [settings-check] Setting: src/Centjes/Docs/Site/OptParse.hs:27:7 in centjes-docs-site:Centjes.Docs.Site.OptParse
  21. 2.03 s [settings-check] could not set based on options, no option: ["--config-file"]
  22. 2.03 s [settings-check] set based on env: "/nix/store/vb9vv8cg7xwfa7010fyznaj7b5syrx63-centjes-docs-site-config.yaml"
  23. 2.04 s [settings-check] check
  24. 2.04 s [settings-check] succeeded
  25. 2.04 s [settings-check] Left side succeeded.
  26. 2.04 s [settings-check] check
  27. 2.04 s [settings-check] succeeded
  28. 2.04 s [settings-check] with loaded config
  29. 2.04 s [settings-check] Ap
  30. 2.04 s [settings-check] Ap
  31. 2.04 s [settings-check] Parser with check: without srcLoc
  32. 2.04 s [settings-check] parser
  33. 2.04 s [settings-check] Setting: src/Centjes/Docs/Site/OptParse.hs:29:11 in centjes-docs-site:Centjes.Docs.Site.OptParse
  34. 2.04 s [settings-check] could not set based on options, no option: ["--port"]
  35. 2.04 s [settings-check] could not set based on env vars, no var: [EnvVarSetting {envVarSettingVar = "CENTJES_DOCS_SITE_PORT", envVarSettingAllowPrefix = True}]
  36. 2.04 s [settings-check] set based on config value: Number 8001.0
  37. 2.04 s [settings-check] check
  38. 2.04 s [settings-check] succeeded
  39. 2.04 s [settings-check] Alt
  40. 2.04 s [settings-check] Trying left side.
  41. 2.04 s [settings-check] Parser with check: without srcLoc
  42. 2.04 s [settings-check] parser
  43. 2.04 s [settings-check] Setting: src/Centjes/Docs/Site/OptParse.hs:38:13 in centjes-docs-site:Centjes.Docs.Site.OptParse
  44. 2.04 s [settings-check] could not set based on options, no option: ["--google-analytics-tracking"]
  45. 2.04 s [settings-check] could not set based on env vars, no var: [EnvVarSetting {envVarSettingVar = "CENTJES_DOCS_SITE_GOOGLE_ANALYTICS_TRACKING", envVarSettingAllowPrefix = True}]
  46. 2.04 s [settings-check] could not set based on config value, configured to nothing: ["google-analytics-tracking"]
  47. 2.04 s [settings-check] not found
  48. 2.04 s [settings-check] check
  49. 2.04 s [settings-check] Left side failed, trying right side.
  50. 2.04 s [settings-check] pure value
  51. 2.04 s [settings-check] Alt
  52. 2.04 s [settings-check] Trying left side.
  53. 2.04 s [settings-check] Parser with check: without srcLoc
  54. 2.04 s [settings-check] parser
  55. 2.04 s [settings-check] Setting: src/Centjes/Docs/Site/OptParse.hs:46:13 in centjes-docs-site:Centjes.Docs.Site.OptParse
  56. 2.04 s [settings-check] could not set based on options, no option: ["--google-search-console-verification"]
  57. 2.04 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.04 s [settings-check] could not set based on config value, configured to nothing: ["google-search-console-verification"]
  59. 2.04 s [settings-check] not found
  60. 2.04 s [settings-check] check
  61. 2.05 s [settings-check] Left side failed, trying right side.
  62. 2.05 s [settings-check] pure value
  63. 2.06 s [post-build-hook] Uploading paths from nix-ci to cachix cache "centjes" /nix/store/pfg8hayvf5qq1axqbh3zkfrk33031syf-settings-check
  64. 2.48 s [post-build-hook] Pushing 1 paths (0 are already present) using zstd to cache centjes ⏳
  65. 2.48 s [post-build-hook]
  66. 2.88 s [post-build-hook] Pushing /nix/store/pfg8hayvf5qq1axqbh3zkfrk33031syf-settings-check (144.00 B)
  67. 3.90 s [post-build-hook]
  68. 3.90 s [post-build-hook] All done.
  69. 3.92 s [post-build-hook] Uploading paths from nix-ci to the NixCI staging cache /nix/store/pfg8hayvf5qq1axqbh3zkfrk33031syf-settings-check
  70. 3.97 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  71. 3.99 s [post-build-hook] copying 1 paths...
  72. 3.99 s [post-build-hook] copying path '/nix/store/pfg8hayvf5qq1axqbh3zkfrk33031syf-settings-check' to 'https://cache.staging.nix-ci.com'...
  73. 4.12 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  74. 4.32 s [post-build-hook] copying 0 paths...
  75. 4.35 s Progress: 1 of 11 built, 2 of 2 fetched
  76. 4.41 s Building unit-centjes-docs-site-production.service
  77. 4.47 s [post-build-hook] Uploading paths from nix-ci to cachix cache "centjes" /nix/store/6hbdzqdw69aadrd9hh7a372dxwdl6cxf-unit-centjes-docs-site-production.service
  78. 4.95 s [post-build-hook] Pushing 2 paths (90 are already present) using zstd to cache centjes ⏳
  79. 4.95 s [post-build-hook]
  80. 5.36 s [post-build-hook] Pushing /nix/store/6hbdzqdw69aadrd9hh7a372dxwdl6cxf-unit-centjes-docs-site-production.service (1.62 KiB)
  81. 5.40 s [post-build-hook] Pushing /nix/store/f1crdx2m27wb32drgd0j57ad53pjpn1j-unit-script-centjes-docs-site-production-start (680.00 B)
  82. 6.68 s [post-build-hook]
  83. 6.68 s [post-build-hook] All done.
  84. 6.70 s [post-build-hook] Uploading paths from nix-ci to the NixCI staging cache /nix/store/6hbdzqdw69aadrd9hh7a372dxwdl6cxf-unit-centjes-docs-site-production.service
  85. 6.76 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  86. 6.78 s [post-build-hook] copying 0 paths...
  87. 6.85 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  88. 7.39 s [post-build-hook] copying 0 paths...
  89. 7.43 s Progress: 2 of 11 built, 2 of 2 fetched
  90. 7.50 s Building system-units
  91. 8.44 s [post-build-hook] Uploading paths from nix-ci to cachix cache "centjes" /nix/store/jnirg3gqxy9g8l8gagj1cwq9r385hcjs-system-units
  92. 9.12 s [post-build-hook] Pushing 1 paths (450 are already present) using zstd to cache centjes ⏳
  93. 9.12 s [post-build-hook]
  94. 9.52 s [post-build-hook] Pushing /nix/store/jnirg3gqxy9g8l8gagj1cwq9r385hcjs-system-units (96.09 KiB)
  95. 10.48 s [post-build-hook]
  96. 10.48 s [post-build-hook] All done.
  97. 10.50 s [post-build-hook] Uploading paths from nix-ci to the NixCI staging cache /nix/store/jnirg3gqxy9g8l8gagj1cwq9r385hcjs-system-units
  98. 10.56 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  99. 10.60 s [post-build-hook] copying 0 paths...
  100. 10.67 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  101. 10.91 s [post-build-hook] copying 0 paths...
  102. 10.94 s Progress: 3 of 11 built, 2 of 2 fetched
  103. 11.04 s Building etc
  104. 11.63 s [post-build-hook] Uploading paths from nix-ci to cachix cache "centjes" /nix/store/dj7drq2wfn99iwkdhq5qgc6gd05ik7g2-etc
  105. 12.20 s [post-build-hook] Pushing 1 paths (546 are already present) using zstd to cache centjes ⏳
  106. 12.20 s [post-build-hook]
  107. 12.72 s [post-build-hook] Pushing /nix/store/dj7drq2wfn99iwkdhq5qgc6gd05ik7g2-etc (31.56 KiB)
  108. 13.74 s [post-build-hook]
  109. 13.74 s [post-build-hook] All done.
  110. 13.76 s [post-build-hook] Uploading paths from nix-ci to the NixCI staging cache /nix/store/dj7drq2wfn99iwkdhq5qgc6gd05ik7g2-etc
  111. 13.82 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  112. 13.88 s [post-build-hook] copying 0 paths...
  113. 13.95 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  114. 14.27 s [post-build-hook] copying 0 paths...
  115. 14.32 s Progress: 4 of 11 built, 2 of 2 fetched
  116. 14.42 s Building nixos-system-docsserver-test
  117. 14.56 s [post-build-hook] Uploading paths from nix-ci to cachix cache "centjes" /nix/store/aycj65q2vjaiwwbk57wba4kaxs7226vn-nixos-system-docsserver-test
  118. 15.27 s [post-build-hook] Pushing 1 paths (568 are already present) using zstd to cache centjes ⏳
  119. 15.27 s [post-build-hook]
  120. 15.68 s [post-build-hook] Pushing /nix/store/aycj65q2vjaiwwbk57wba4kaxs7226vn-nixos-system-docsserver-test (17.26 KiB)
  121. 16.66 s [post-build-hook]
  122. 16.66 s [post-build-hook] All done.
  123. 16.68 s [post-build-hook] Uploading paths from nix-ci to the NixCI staging cache /nix/store/aycj65q2vjaiwwbk57wba4kaxs7226vn-nixos-system-docsserver-test
  124. 16.74 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  125. 16.79 s [post-build-hook] copying 0 paths...
  126. 16.87 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  127. 17.51 s [post-build-hook] copying 0 paths...
  128. 17.55 s Progress: 5 of 11 built, 2 of 2 fetched
  129. 18.18 s Building closure-info
  130. 18.18 s [closure-info] structuredAttrs is enabled
  131. 18.35 s [post-build-hook] Uploading paths from nix-ci to cachix cache "centjes" /nix/store/c7vwm5q2a9xvn7hzifddkzzbr1s7yinr-closure-info
  132. 18.94 s [post-build-hook] Pushing 1 paths (569 are already present) using zstd to cache centjes ⏳
  133. 18.94 s [post-build-hook]
  134. 19.33 s [post-build-hook] Pushing /nix/store/c7vwm5q2a9xvn7hzifddkzzbr1s7yinr-closure-info (228.66 KiB)
  135. 20.41 s [post-build-hook]
  136. 20.41 s [post-build-hook] All done.
  137. 20.43 s [post-build-hook] Uploading paths from nix-ci to the NixCI staging cache /nix/store/c7vwm5q2a9xvn7hzifddkzzbr1s7yinr-closure-info
  138. 20.48 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  139. 20.52 s [post-build-hook] copying 0 paths...
  140. 20.58 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  141. 20.85 s [post-build-hook] copying 0 paths...
  142. 20.89 s Progress: 6 of 11 built, 2 of 2 fetched
  143. 21.00 s Building run-nixos-vm
  144. 21.09 s [post-build-hook] Uploading paths from nix-ci to cachix cache "centjes" /nix/store/mkd791xnc7ji087bbydjm2ps1al6dlfj-run-nixos-vm
  145. 22.16 s [post-build-hook] Pushing 1 paths (580 are already present) using zstd to cache centjes ⏳
  146. 22.16 s [post-build-hook]
  147. 22.80 s [post-build-hook] Pushing /nix/store/mkd791xnc7ji087bbydjm2ps1al6dlfj-run-nixos-vm (2.94 KiB)
  148. 23.80 s [post-build-hook]
  149. 23.80 s [post-build-hook] All done.
  150. 23.82 s [post-build-hook] Uploading paths from nix-ci to the NixCI staging cache /nix/store/mkd791xnc7ji087bbydjm2ps1al6dlfj-run-nixos-vm
  151. 23.88 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  152. 23.93 s [post-build-hook] copying 0 paths...
  153. 24.00 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  154. 24.29 s [post-build-hook] copying 0 paths...
  155. 24.33 s Progress: 7 of 11 built, 2 of 2 fetched
  156. 24.42 s Building nixos-vm
  157. 24.51 s [post-build-hook] Uploading paths from nix-ci to cachix cache "centjes" /nix/store/l6ghf1y7jb40r81ixn986qvrj01y1nyx-nixos-vm
  158. 25.90 s [post-build-hook] Pushing 1 paths (581 are already present) using zstd to cache centjes ⏳
  159. 25.90 s [post-build-hook]
  160. 26.42 s [post-build-hook] Pushing /nix/store/l6ghf1y7jb40r81ixn986qvrj01y1nyx-nixos-vm (776.00 B)
  161. 27.43 s [post-build-hook]
  162. 27.43 s [post-build-hook] All done.
  163. 27.46 s [post-build-hook] Uploading paths from nix-ci to the NixCI staging cache /nix/store/l6ghf1y7jb40r81ixn986qvrj01y1nyx-nixos-vm
  164. 27.52 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  165. 27.57 s [post-build-hook] copying 0 paths...
  166. 27.64 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  167. 27.95 s [post-build-hook] copying 0 paths...
  168. 27.99 s Progress: 8 of 11 built, 2 of 2 fetched
  169. 28.09 s Building nixos-test-driver-centjes-e2e-test
  170. 28.33 s [nixos-test-driver-centjes-e2e-test] Running type check (enable/disable: config.skipTypeCheck)
  171. 28.33 s [nixos-test-driver-centjes-e2e-test] See https://nixos.org/manual/nixos/stable/#test-opt-skipTypeCheck
  172. 36.03 s [nixos-test-driver-centjes-e2e-test] Success: no issues found in 1 source file
  173. 36.50 s [nixos-test-driver-centjes-e2e-test] additionally exposed symbols:
  174. 36.50 s [nixos-test-driver-centjes-e2e-test] ,
  175. 36.50 s [nixos-test-driver-centjes-e2e-test] ,
  176. 36.50 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
  177. 36.56 s [nixos-test-driver-centjes-e2e-test] Linting test script (enable/disable: config.skipLint)
  178. 36.56 s [nixos-test-driver-centjes-e2e-test] See https://nixos.org/manual/nixos/stable/#test-opt-skipLint
  179. 36.77 s [post-build-hook] Uploading paths from nix-ci to cachix cache "centjes" /nix/store/0ac838496b06q422qk2nvdhbixqlkib7-nixos-test-driver-centjes-e2e-test
  180. 37.35 s [post-build-hook] Pushing 2 paths (632 are already present) using zstd to cache centjes ⏳
  181. 37.35 s [post-build-hook]
  182. 37.73 s [post-build-hook] Pushing /nix/store/0ac838496b06q422qk2nvdhbixqlkib7-nixos-test-driver-centjes-e2e-test (1.84 KiB)
  183. 37.81 s [post-build-hook] Pushing /nix/store/rwj0jbi98wrrg4c4k8a5s63cp8r7s8a9-which-2.23 (46.29 KiB)
  184. 38.83 s [post-build-hook]
  185. 38.83 s [post-build-hook] All done.
  186. 38.85 s [post-build-hook] Uploading paths from nix-ci to the NixCI staging cache /nix/store/0ac838496b06q422qk2nvdhbixqlkib7-nixos-test-driver-centjes-e2e-test
  187. 38.90 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  188. 38.95 s [post-build-hook] copying 0 paths...
  189. 39.03 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  190. 39.29 s [post-build-hook] copying 0 paths...
  191. 39.33 s Progress: 9 of 11 built, 2 of 2 fetched
  192. 39.42 s Building vm-test-run-centjes-e2e-test
  193. 39.83 s [vm-test-run-centjes-e2e-test] Machine state will be reset. To keep it, pass --keep-vm-state
  194. 39.83 s [vm-test-run-centjes-e2e-test] start all VLans
  195. 39.83 s [vm-test-run-centjes-e2e-test] start vlan
  196. 39.83 s [vm-test-run-centjes-e2e-test] running vlan (pid 7; ctl /build/vde1.ctl)
  197. 39.83 s [vm-test-run-centjes-e2e-test] (finished: start all VLans, in 0.00 seconds)
  198. 39.83 s [vm-test-run-centjes-e2e-test] Test will time out and terminate in 3600 seconds
  199. 39.83 s [vm-test-run-centjes-e2e-test] run the VM test script
  200. 39.83 s [vm-test-run-centjes-e2e-test] additionally exposed symbols:
  201. 39.83 s [vm-test-run-centjes-e2e-test] client, docsserver,
  202. 39.83 s [vm-test-run-centjes-e2e-test] vlan1,
  203. 39.83 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
  204. 39.83 s [vm-test-run-centjes-e2e-test] docsserver: starting vm
  205. 39.87 s [vm-test-run-centjes-e2e-test] mke2fs 1.47.3 (8-Jul-2025)
  206. 40.02 s [vm-test-run-centjes-e2e-test] docsserver # Disk image does not exist, creating the virtualisation disk image...
  207. 40.02 s [vm-test-run-centjes-e2e-test] docsserver # Formatting '/build/vm-state-docsserver/tmp.XpVzYk7Gcb', fmt=raw size=1073741824
  208. 40.02 s [vm-test-run-centjes-e2e-test] docsserver: QEMU running (pid 9)
  209. 40.02 s [vm-test-run-centjes-e2e-test] docsserver # Discarding device blocks: 0/262144 done
  210. 40.02 s [vm-test-run-centjes-e2e-test] docsserver # Creating filesystem with 262144 4k blocks and 65536 inodes
  211. 40.02 s [vm-test-run-centjes-e2e-test] docsserver # Filesystem UUID: 069dba71-c190-4124-a059-4338a1e8327d
  212. 40.02 s [vm-test-run-centjes-e2e-test] docsserver # Superblock backups stored on blocks:
  213. 40.02 s [vm-test-run-centjes-e2e-test] docsserver # 32768, 98304, 163840, 229376
  214. 40.02 s [vm-test-run-centjes-e2e-test] docsserver #
  215. 40.02 s [vm-test-run-centjes-e2e-test] docsserver # Allocating group tables: 0/8 done
  216. 40.02 s [vm-test-run-centjes-e2e-test] docsserver # Writing inode tables: 0/8 done
  217. 40.02 s [vm-test-run-centjes-e2e-test] docsserver # Creating journal (8192 blocks): done
  218. 40.02 s [vm-test-run-centjes-e2e-test] client: starting vm
  219. 40.02 s [vm-test-run-centjes-e2e-test] docsserver # Writing superblocks and filesystem accounting information: 0/8 done
  220. 40.02 s [vm-test-run-centjes-e2e-test] docsserver #
  221. 40.02 s [vm-test-run-centjes-e2e-test] docsserver # Virtualisation disk image created.
  222. 40.05 s [vm-test-run-centjes-e2e-test] mke2fs 1.47.3 (8-Jul-2025)
  223. 40.18 s [vm-test-run-centjes-e2e-test] docsserver # c[?7lSeaBIOS (version rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org)
  224. 40.21 s [vm-test-run-centjes-e2e-test] client: QEMU running (pid 31)
  225. 40.21 s [vm-test-run-centjes-e2e-test] client # Disk image does not exist, creating the virtualisation disk image...
  226. 40.21 s [vm-test-run-centjes-e2e-test] client # Formatting '/build/vm-state-client/tmp.QAiUugYhmP', fmt=raw size=1073741824
  227. 40.21 s [vm-test-run-centjes-e2e-test] docsserver: waiting for unit default.target
  228. 40.21 s [vm-test-run-centjes-e2e-test] client # Discarding device blocks: 0/262144 done
  229. 40.21 s [vm-test-run-centjes-e2e-test] docsserver: waiting for the VM to finish booting
  230. 40.21 s [vm-test-run-centjes-e2e-test] client # Creating filesystem with 262144 4k blocks and 65536 inodes
  231. 40.21 s [vm-test-run-centjes-e2e-test] client # Filesystem UUID: 2bf68771-21da-49aa-8efa-0256cf5823b1
  232. 40.21 s [vm-test-run-centjes-e2e-test] client # Superblock backups stored on blocks:
  233. 40.21 s [vm-test-run-centjes-e2e-test] client # 32768, 98304, 163840, 229376
  234. 40.21 s [vm-test-run-centjes-e2e-test] client #
  235. 40.21 s [vm-test-run-centjes-e2e-test] client # Allocating group tables: 0/8 done
  236. 40.21 s [vm-test-run-centjes-e2e-test] client # Writing inode tables: 0/8 done
  237. 40.21 s [vm-test-run-centjes-e2e-test] client # Creating journal (8192 blocks): done
  238. 40.21 s [vm-test-run-centjes-e2e-test] client # Writing superblocks and filesystem accounting information: 0/8 done
  239. 40.21 s [vm-test-run-centjes-e2e-test] client #
  240. 40.21 s [vm-test-run-centjes-e2e-test] client # Virtualisation disk image created.
  241. 40.24 s [vm-test-run-centjes-e2e-test] docsserver #
  242. 40.24 s [vm-test-run-centjes-e2e-test] docsserver #
  243. 40.25 s [vm-test-run-centjes-e2e-test] docsserver # iPXE (http://ipxe.org) 00:03.0 CA00 PCI2.10 PnP PMM+3EFD1920+3EF31920 CA00
  244. 40.27 s [vm-test-run-centjes-e2e-test] docsserver # Press Ctrl-B to configure iPXE (PCI 00:03.0)...
  245. 40.27 s [vm-test-run-centjes-e2e-test] docsserver #
  246. 40.27 s [vm-test-run-centjes-e2e-test] docsserver #
  247. 40.27 s [vm-test-run-centjes-e2e-test] docsserver #
  248. 40.27 s [vm-test-run-centjes-e2e-test] docsserver #
  249. 40.28 s [vm-test-run-centjes-e2e-test] docsserver # iPXE (http://ipxe.org) 00:09.0 CB00 PCI2.10 PnP PMM 3EFD1920 3EF31920 CB00
  250. 40.29 s [vm-test-run-centjes-e2e-test] docsserver # Press Ctrl-B to configure iPXE (PCI 00:09.0)...
  251. 40.30 s [vm-test-run-centjes-e2e-test] docsserver #
  252. 40.30 s [vm-test-run-centjes-e2e-test] docsserver #
  253. 40.32 s [vm-test-run-centjes-e2e-test] docsserver # Booting from ROM...
  254. 40.35 s [vm-test-run-centjes-e2e-test] docsserver # Probing EDD (edd=off to disable)... ok
  255. 40.37 s [vm-test-run-centjes-e2e-test] client # c[?7lSeaBIOS (version rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org)
  256. 40.43 s [vm-test-run-centjes-e2e-test] client #
  257. 40.43 s [vm-test-run-centjes-e2e-test] client #
  258. 40.44 s [vm-test-run-centjes-e2e-test] client # iPXE (http://ipxe.org) 00:03.0 CA00 PCI2.10 PnP PMM+3EFD1920+3EF31920 CA00
  259. 40.46 s [vm-test-run-centjes-e2e-test] client # Press Ctrl-B to configure iPXE (PCI 00:03.0)...
  260. 40.46 s [vm-test-run-centjes-e2e-test] client #
  261. 40.46 s [vm-test-run-centjes-e2e-test] client #
  262. 40.46 s [vm-test-run-centjes-e2e-test] client #
  263. 40.46 s [vm-test-run-centjes-e2e-test] client #
  264. 40.46 s [vm-test-run-centjes-e2e-test] client # iPXE (http://ipxe.org) 00:09.0 CB00 PCI2.10 PnP PMM 3EFD1920 3EF31920 CB00
  265. 40.49 s [vm-test-run-centjes-e2e-test] client # Press Ctrl-B to configure iPXE (PCI 00:09.0)...
  266. 40.49 s [vm-test-run-centjes-e2e-test] client #
  267. 40.49 s [vm-test-run-centjes-e2e-test] client #
  268. 40.50 s [vm-test-run-centjes-e2e-test] client # Booting from ROM...
  269. 40.54 s [vm-test-run-centjes-e2e-test] client # Probing EDD (edd=off to disable)... ok
  270. 40.71 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
  271. 40.72 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/aycj65q2vjaiwwbk57wba4kaxs7226vn-nixos-system-docsserver-test/init regInfo=/nix/store/c7vwm5q2a9xvn7hzifddkzzbr1s7yinr-closure-info/registration console=ttyS0,115200n8 console=tty0
  272. 40.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-provided physical RAM map:
  273. 40.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
  274. 40.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
  275. 40.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
  276. 40.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000003ffdafff] usable
  277. 40.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x000000003ffdb000-0x000000003fffffff] reserved
  278. 40.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
  279. 40.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
  280. 40.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x000000fd00000000-0x000000ffffffffff] reserved
  281. 40.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] NX (Execute Disable) protection: active
  282. 40.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] APIC: Static calls initialized
  283. 40.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] SMBIOS 2.8 present.
  284. 40.75 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
  285. 40.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] DMI: Memory slots populated: 1/1
  286. 40.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] Hypervisor detected: KVM
  287. 40.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
  288. 40.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
  289. 40.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000001] kvm-clock: using sched offset of 510857512 cycles
  290. 40.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000002] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
  291. 40.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000005] tsc: Detected 3399.996 MHz processor
  292. 40.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000816] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
  293. 40.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.001067] MTRR map: 4 entries (3 fixed + 1 variable; max 19), built from 8 variable MTRRs
  294. 40.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.001076] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT
  295. 40.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003144] found SMP MP-table at [mem 0x000f5470-0x000f547f]
  296. 40.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003157] Using GB pages for direct mapping
  297. 40.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003301] RAMDISK: [mem 0x3f3cd000-0x3ffcffff]
  298. 40.79 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003330] ACPI: Early table checksum verification disabled
  299. 40.79 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003333] ACPI: RSDP 0x00000000000F5290 000014 (v00 BOCHS )
  300. 40.79 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003337] ACPI: RSDT 0x000000003FFE23D9 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  301. 40.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003342] ACPI: FACP 0x000000003FFE228D 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  302. 40.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003346] ACPI: DSDT 0x000000003FFE0040 00224D (v01 BOCHS BXPC 00000001 BXPC 00000001)
  303. 40.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003348] ACPI: FACS 0x000000003FFE0000 000040
  304. 40.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003350] ACPI: APIC 0x000000003FFE2301 000078 (v03 BOCHS BXPC 00000001 BXPC 00000001)
  305. 40.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003352] ACPI: HPET 0x000000003FFE2379 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  306. 40.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003353] ACPI: WAET 0x000000003FFE23B1 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  307. 40.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003354] ACPI: Reserving FACP table memory at [mem 0x3ffe228d-0x3ffe2300]
  308. 40.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003356] ACPI: Reserving DSDT table memory at [mem 0x3ffe0040-0x3ffe228c]
  309. 40.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003356] ACPI: Reserving FACS table memory at [mem 0x3ffe0000-0x3ffe003f]
  310. 40.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003357] ACPI: Reserving APIC table memory at [mem 0x3ffe2301-0x3ffe2378]
  311. 40.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003357] ACPI: Reserving HPET table memory at [mem 0x3ffe2379-0x3ffe23b0]
  312. 40.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003358] ACPI: Reserving WAET table memory at [mem 0x3ffe23b1-0x3ffe23d8]
  313. 40.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.004242] No NUMA configuration found
  314. 40.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.004243] Faking a node at [mem 0x0000000000000000-0x000000003ffdafff]
  315. 40.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.004247] NODE_DATA(0) allocated [mem 0x3ffd58c0-0x3ffdadff]
  316. 40.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.004297] Zone ranges:
  317. 40.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.004298] DMA [mem 0x0000000000001000-0x0000000000ffffff]
  318. 40.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.004300] DMA32 [mem 0x0000000001000000-0x000000003ffdafff]
  319. 40.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.004301] Normal empty
  320. 40.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.004302] Device empty
  321. 40.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.004303] Movable zone start for each node
  322. 40.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.004304] Early memory node ranges
  323. 40.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.004304] node 0: [mem 0x0000000000001000-0x000000000009efff]
  324. 40.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.004305] node 0: [mem 0x0000000000100000-0x000000003ffdafff]
  325. 40.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.004307] Initmem setup node 0 [mem 0x0000000000001000-0x000000003ffdafff]
  326. 40.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.004528] On node 0, zone DMA: 1 pages in unavailable ranges
  327. 40.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.004542] On node 0, zone DMA: 97 pages in unavailable ranges
  328. 40.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.006705] On node 0, zone DMA32: 37 pages in unavailable ranges
  329. 40.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008818] ACPI: PM-Timer IO Port: 0x608
  330. 40.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008857] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
  331. 40.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008969] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
  332. 40.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008972] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
  333. 40.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008974] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
  334. 40.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008975] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
  335. 40.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008975] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
  336. 40.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008976] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
  337. 40.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008979] ACPI: Using ACPI (MADT) for SMP configuration information
  338. 40.90 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
  339. 40.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008979] ACPI: HPET id: 0x8086a201 base: 0xfed00000
  340. 40.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008983] TSC deadline timer available
  341. 40.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008987] CPU topo: Max. logical packages: 1
  342. 40.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008988] CPU topo: Max. logical dies: 1
  343. 40.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008988] CPU topo: Max. dies per package: 1
  344. 40.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008992] CPU topo: Max. threads per core: 1
  345. 40.91 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] Command line: console=ttyS0 console=tty0 panic=1 boot.panic_on_fail clocksource=acpi_pm loglevel=7 net.ifnames=0 lsm=landlock,yama,bpf init=/nix/store/001k9r4jinw78ih5x5hxggb82ynlbkqn-nixos-system-client-test/init regInfo=/nix/store/j7kn31fka8vp5bhm6sw8hv64iyzix7xw-closure-info/registration console=ttyS0,115200n8 console=tty0
  346. 40.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008992] CPU topo: Num. cores per package: 1
  347. 40.92 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-provided physical RAM map:
  348. 40.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008992] CPU topo: Num. threads per package: 1
  349. 40.92 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
  350. 40.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008993] CPU topo: Allowing 1 present CPUs plus 0 hotplug CPUs
  351. 40.92 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
  352. 40.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.009027] kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write()
  353. 40.93 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
  354. 40.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.009090] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]
  355. 40.93 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000003ffdafff] usable
  356. 40.93 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x000000003ffdb000-0x000000003fffffff] reserved
  357. 40.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.009092] PM: hibernation: Registered nosave memory: [mem 0x0009f000-0x000fffff]
  358. 40.93 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
  359. 40.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.009093] [mem 0x40000000-0xfeffbfff] available for PCI devices
  360. 40.94 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
  361. 40.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.009094] Booting paravirtualized kernel on KVM
  362. 40.94 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x000000fd00000000-0x000000ffffffffff] reserved
  363. 40.94 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] NX (Execute Disable) protection: active
  364. 40.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.009096] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
  365. 40.94 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] APIC: Static calls initialized
  366. 40.94 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] SMBIOS 2.8 present.
  367. 40.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.013014] setup_percpu: NR_CPUS:384 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1
  368. 40.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.013415] percpu: Embedded 116 pages/cpu s294912 r65536 d114688 u2097152
  369. 40.95 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
  370. 40.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.013503] kvm-guest: PV spinlocks disabled, single CPU
  371. 40.95 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] DMI: Memory slots populated: 1/1
  372. 40.95 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] Hypervisor detected: KVM
  373. 40.96 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
  374. 40.96 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
  375. 40.96 s [vm-test-run-centjes-e2e-test] client # [ 0.000001] kvm-clock: using sched offset of 517859417 cycles
  376. 40.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.013505] 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/aycj65q2vjaiwwbk57wba4kaxs7226vn-nixos-system-docsserver-test/init regInfo=/nix/store/c7vwm5q2a9xvn7hzifddkzzbr1s7yinr-closure-info/registration console=ttyS0,115200n8 console=tty0
  377. 40.97 s [vm-test-run-centjes-e2e-test] client # [ 0.000002] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
  378. 40.97 s [vm-test-run-centjes-e2e-test] client # [ 0.000005] tsc: Detected 3399.996 MHz processor
  379. 40.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.013587] Unknown kernel command line parameters "regInfo=/nix/store/c7vwm5q2a9xvn7hzifddkzzbr1s7yinr-closure-info/registration", will be passed to user space.
  380. 40.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.013601] random: crng init done
  381. 40.97 s [vm-test-run-centjes-e2e-test] client # [ 0.000746] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
  382. 40.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.013664] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
  383. 40.97 s [vm-test-run-centjes-e2e-test] client # [ 0.000990] MTRR map: 4 entries (3 fixed + 1 variable; max 19), built from 8 variable MTRRs
  384. 40.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.013698] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)
  385. 40.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.013740] Fallback order for Node 0: 0
  386. 40.98 s [vm-test-run-centjes-e2e-test] client # [ 0.000999] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT
  387. 40.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.013742] Built 1 zonelists, mobility grouping on. Total pages: 262009
  388. 40.98 s [vm-test-run-centjes-e2e-test] client # [ 0.002980] found SMP MP-table at [mem 0x000f5470-0x000f547f]
  389. 40.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.013743] Policy zone: DMA32
  390. 40.98 s [vm-test-run-centjes-e2e-test] client # [ 0.002992] Using GB pages for direct mapping
  391. 40.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.014055] mem auto-init: stack:all(zero), heap alloc:on, heap free:off
  392. 40.99 s [vm-test-run-centjes-e2e-test] client # [ 0.003062] RAMDISK: [mem 0x3f3cd000-0x3ffcffff]
  393. 40.99 s [vm-test-run-centjes-e2e-test] client # [ 0.003083] ACPI: Early table checksum verification disabled
  394. 40.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.016749] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
  395. 40.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.017081] allocated 2097152 bytes of page_ext
  396. 40.99 s [vm-test-run-centjes-e2e-test] client # [ 0.003085] ACPI: RSDP 0x00000000000F5290 000014 (v00 BOCHS )
  397. 40.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.017097] ftrace: allocating 46208 entries in 181 pages
  398. 40.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.025657] ftrace: allocated 181 pages with 5 groups
  399. 41.00 s [vm-test-run-centjes-e2e-test] client # [ 0.003088] ACPI: RSDT 0x000000003FFE23D9 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  400. 41.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.026342] Dynamic Preempt: voluntary
  401. 41.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.026612] rcu: Preemptible hierarchical RCU implementation.
  402. 41.00 s [vm-test-run-centjes-e2e-test] client # [ 0.003093] ACPI: FACP 0x000000003FFE228D 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  403. 41.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.026613] rcu: RCU event tracing is enabled.
  404. 41.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.026614] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1.
  405. 41.00 s [vm-test-run-centjes-e2e-test] client # [ 0.003096] ACPI: DSDT 0x000000003FFE0040 00224D (v01 BOCHS BXPC 00000001 BXPC 00000001)
  406. 41.01 s [vm-test-run-centjes-e2e-test] client # [ 0.003098] ACPI: FACS 0x000000003FFE0000 000040
  407. 41.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.026615] Trampoline variant of Tasks RCU enabled.
  408. 41.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.026615] Rude variant of Tasks RCU enabled.
  409. 41.01 s [vm-test-run-centjes-e2e-test] client # [ 0.003099] ACPI: APIC 0x000000003FFE2301 000078 (v03 BOCHS BXPC 00000001 BXPC 00000001)
  410. 41.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.026616] Tracing variant of Tasks RCU enabled.
  411. 41.01 s [vm-test-run-centjes-e2e-test] client # [ 0.003101] ACPI: HPET 0x000000003FFE2379 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  412. 41.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.026616] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.
  413. 41.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.026617] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
  414. 41.02 s [vm-test-run-centjes-e2e-test] client # [ 0.003103] ACPI: WAET 0x000000003FFE23B1 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  415. 41.02 s [vm-test-run-centjes-e2e-test] client # [ 0.003104] ACPI: Reserving FACP table memory at [mem 0x3ffe228d-0x3ffe2300]
  416. 41.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.026624] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  417. 41.02 s [vm-test-run-centjes-e2e-test] client # [ 0.003105] ACPI: Reserving DSDT table memory at [mem 0x3ffe0040-0x3ffe228c]
  418. 41.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.026626] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  419. 41.03 s [vm-test-run-centjes-e2e-test] client # [ 0.003105] ACPI: Reserving FACS table memory at [mem 0x3ffe0000-0x3ffe003f]
  420. 41.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.026627] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  421. 41.03 s [vm-test-run-centjes-e2e-test] client # [ 0.003106] ACPI: Reserving APIC table memory at [mem 0x3ffe2301-0x3ffe2378]
  422. 41.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.030889] NR_IRQS: 24832, nr_irqs: 256, preallocated irqs: 16
  423. 41.03 s [vm-test-run-centjes-e2e-test] client # [ 0.003106] ACPI: Reserving HPET table memory at [mem 0x3ffe2379-0x3ffe23b0]
  424. 41.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.031182] rcu: srcu_init: Setting srcu_struct sizes based on contention.
  425. 41.09 s [vm-test-run-centjes-e2e-test] client # [ 0.003107] ACPI: Reserving WAET table memory at [mem 0x3ffe23b1-0x3ffe23d8]
  426. 41.09 s [vm-test-run-centjes-e2e-test] client # [ 0.003961] No NUMA configuration found
  427. 41.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.031303] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)
  428. 41.09 s [vm-test-run-centjes-e2e-test] client # [ 0.003962] Faking a node at [mem 0x0000000000000000-0x000000003ffdafff]
  429. 41.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.048037] Console: colour VGA+ 80x25
  430. 41.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.048043] printk: legacy console [tty0] enabled
  431. 41.09 s [vm-test-run-centjes-e2e-test] client # [ 0.003965] NODE_DATA(0) allocated [mem 0x3ffd58c0-0x3ffdadff]
  432. 41.09 s [vm-test-run-centjes-e2e-test] client # [ 0.003981] Zone ranges:
  433. 41.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.172891] printk: legacy console [ttyS0] enabled
  434. 41.09 s [vm-test-run-centjes-e2e-test] client # [ 0.003981] DMA [mem 0x0000000000001000-0x0000000000ffffff]
  435. 41.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.518482] ACPI: Core revision 20240827
  436. 41.09 s [vm-test-run-centjes-e2e-test] client # [ 0.003982] DMA32 [mem 0x0000000001000000-0x000000003ffdafff]
  437. 41.09 s [vm-test-run-centjes-e2e-test] client # [ 0.003983] Normal empty
  438. 41.09 s [vm-test-run-centjes-e2e-test] client # [ 0.003984] Device empty
  439. 41.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.522046] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
  440. 41.09 s [vm-test-run-centjes-e2e-test] client # [ 0.003985] Movable zone start for each node
  441. 41.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.528182] APIC: Switch to symmetric I/O mode setup
  442. 41.09 s [vm-test-run-centjes-e2e-test] client # [ 0.003985] Early memory node ranges
  443. 41.09 s [vm-test-run-centjes-e2e-test] client # [ 0.003985] node 0: [mem 0x0000000000001000-0x000000000009efff]
  444. 41.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.532423] x2apic enabled
  445. 41.09 s [vm-test-run-centjes-e2e-test] client # [ 0.003986] node 0: [mem 0x0000000000100000-0x000000003ffdafff]
  446. 41.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.535788] APIC: Switched APIC routing to: physical x2apic
  447. 41.09 s [vm-test-run-centjes-e2e-test] client # [ 0.003987] Initmem setup node 0 [mem 0x0000000000001000-0x000000003ffdafff]
  448. 41.09 s [vm-test-run-centjes-e2e-test] client # [ 0.004190] On node 0, zone DMA: 1 pages in unavailable ranges
  449. 41.09 s [vm-test-run-centjes-e2e-test] client # [ 0.004203] On node 0, zone DMA: 97 pages in unavailable ranges
  450. 41.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.544744] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
  451. 41.09 s [vm-test-run-centjes-e2e-test] client # [ 0.006197] On node 0, zone DMA32: 37 pages in unavailable ranges
  452. 41.09 s [vm-test-run-centjes-e2e-test] client # [ 0.007995] ACPI: PM-Timer IO Port: 0x608
  453. 41.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.548815] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x31024b3bec5, max_idle_ns: 440795366697 ns
  454. 41.09 s [vm-test-run-centjes-e2e-test] client # [ 0.008022] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
  455. 41.09 s [vm-test-run-centjes-e2e-test] client # [ 0.008116] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
  456. 41.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.555553] Calibrating delay loop (skipped) preset value.. 6799.99 BogoMIPS (lpj=3399996)
  457. 41.10 s [vm-test-run-centjes-e2e-test] client # [ 0.008118] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
  458. 41.10 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.558362] x86/cpu: User Mode Instruction Prevention (UMIP) activated
  459. 41.10 s [vm-test-run-centjes-e2e-test] client # [ 0.008120] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
  460. 41.10 s [vm-test-run-centjes-e2e-test] client # [ 0.008120] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
  461. 41.10 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.560160] Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127
  462. 41.10 s [vm-test-run-centjes-e2e-test] client # [ 0.008121] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
  463. 41.10 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.561551] Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0
  464. 41.11 s [vm-test-run-centjes-e2e-test] client # [ 0.008122] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
  465. 41.11 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.563565] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
  466. 41.11 s [vm-test-run-centjes-e2e-test] client # [ 0.008124] ACPI: Using ACPI (MADT) for SMP configuration information
  467. 41.11 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.565553] Spectre V2 : Mitigation: Retpolines
  468. 41.11 s [vm-test-run-centjes-e2e-test] client # [ 0.008125] ACPI: HPET id: 0x8086a201 base: 0xfed00000
  469. 41.12 s [vm-test-run-centjes-e2e-test] client # [ 0.008127] TSC deadline timer available
  470. 41.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.567551] Spectre V2 : Spectre v2 / SpectreRSB: Filling RSB on context switch and VMEXIT
  471. 41.12 s [vm-test-run-centjes-e2e-test] client # [ 0.008131] CPU topo: Max. logical packages: 1
  472. 41.12 s [vm-test-run-centjes-e2e-test] client # [ 0.008132] CPU topo: Max. logical dies: 1
  473. 41.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.569551] Spectre V2 : Enabling Restricted Speculation for firmware calls
  474. 41.12 s [vm-test-run-centjes-e2e-test] client # [ 0.008132] CPU topo: Max. dies per package: 1
  475. 41.13 s [vm-test-run-centjes-e2e-test] client # [ 0.008135] CPU topo: Max. threads per core: 1
  476. 41.13 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.571555] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
  477. 41.13 s [vm-test-run-centjes-e2e-test] client # [ 0.008136] CPU topo: Num. cores per package: 1
  478. 41.13 s [vm-test-run-centjes-e2e-test] client # [ 0.008136] CPU topo: Num. threads per package: 1
  479. 41.13 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.573552] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl
  480. 41.13 s [vm-test-run-centjes-e2e-test] client # [ 0.008137] CPU topo: Allowing 1 present CPUs plus 0 hotplug CPUs
  481. 41.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.575552] active return thunk: srso_alias_return_thunk
  482. 41.14 s [vm-test-run-centjes-e2e-test] client # [ 0.008167] kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write()
  483. 41.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.577551] Speculative Return Stack Overflow: Mitigation: Safe RET
  484. 41.14 s [vm-test-run-centjes-e2e-test] client # [ 0.008226] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]
  485. 41.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.579551] Transient Scheduler Attacks: Forcing mitigation on in a VM
  486. 41.15 s [vm-test-run-centjes-e2e-test] client # [ 0.008228] PM: hibernation: Registered nosave memory: [mem 0x0009f000-0x000fffff]
  487. 41.15 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.581551] Transient Scheduler Attacks: Vulnerable: Clear CPU buffers attempted, no microcode
  488. 41.15 s [vm-test-run-centjes-e2e-test] client # [ 0.008229] [mem 0x40000000-0xfeffbfff] available for PCI devices
  489. 41.15 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.583648] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
  490. 41.15 s [vm-test-run-centjes-e2e-test] client # [ 0.008230] Booting paravirtualized kernel on KVM
  491. 41.16 s [vm-test-run-centjes-e2e-test] client # [ 0.008232] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
  492. 41.16 s [vm-test-run-centjes-e2e-test] client # [ 0.011912] setup_percpu: NR_CPUS:384 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1
  493. 41.17 s [vm-test-run-centjes-e2e-test] client # [ 0.012211] percpu: Embedded 116 pages/cpu s294912 r65536 d114688 u2097152
  494. 41.17 s [vm-test-run-centjes-e2e-test] client # [ 0.012289] kvm-guest: PV spinlocks disabled, single CPU
  495. 41.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.585551] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
  496. 41.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.587553] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
  497. 41.18 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.589552] x86/fpu: Supporting XSAVE feature 0x200: 'Protection Keys User registers'
  498. 41.18 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.591552] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256
  499. 41.18 s [vm-test-run-centjes-e2e-test] client # [ 0.012290] 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
  500. 41.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.593551] x86/fpu: xstate_offset[9]: 832, xstate_sizes[9]: 8
  501. 41.19 s [vm-test-run-centjes-e2e-test] client # [ 0.012369] Unknown kernel command line parameters "regInfo=/nix/store/j7kn31fka8vp5bhm6sw8hv64iyzix7xw-closure-info/registration", will be passed to user space.
  502. 41.19 s [vm-test-run-centjes-e2e-test] client # [ 0.012383] random: crng init done
  503. 41.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.595553] x86/fpu: Enabled xstate features 0x207, context size is 840 bytes, using 'compacted' format.
  504. 41.20 s [vm-test-run-centjes-e2e-test] client # [ 0.012440] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
  505. 41.20 s [vm-test-run-centjes-e2e-test] client # [ 0.012469] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)
  506. 41.20 s [vm-test-run-centjes-e2e-test] client # [ 0.012507] Fallback order for Node 0: 0
  507. 41.21 s [vm-test-run-centjes-e2e-test] client # [ 0.012510] Built 1 zonelists, mobility grouping on. Total pages: 262009
  508. 41.21 s [vm-test-run-centjes-e2e-test] client # [ 0.012510] Policy zone: DMA32
  509. 41.21 s [vm-test-run-centjes-e2e-test] client # [ 0.012784] mem auto-init: stack:all(zero), heap alloc:on, heap free:off
  510. 41.21 s [vm-test-run-centjes-e2e-test] client # [ 0.014984] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
  511. 41.22 s [vm-test-run-centjes-e2e-test] client # [ 0.015266] allocated 2097152 bytes of page_ext
  512. 41.22 s [vm-test-run-centjes-e2e-test] client # [ 0.015279] ftrace: allocating 46208 entries in 181 pages
  513. 41.22 s [vm-test-run-centjes-e2e-test] client # [ 0.023450] ftrace: allocated 181 pages with 5 groups
  514. 41.22 s [vm-test-run-centjes-e2e-test] client # [ 0.024116] Dynamic Preempt: voluntary
  515. 41.23 s [vm-test-run-centjes-e2e-test] client # [ 0.024379] rcu: Preemptible hierarchical RCU implementation.
  516. 41.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.629903] Freeing SMP alternatives memory: 40K
  517. 41.23 s [vm-test-run-centjes-e2e-test] client # [ 0.024380] rcu: RCU event tracing is enabled.
  518. 41.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.632552] pid_max: default: 32768 minimum: 301
  519. 41.23 s [vm-test-run-centjes-e2e-test] client # [ 0.024381] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1.
  520. 41.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.633616] LSM: initializing lsm=capability,landlock,yama,bpf
  521. 41.24 s [vm-test-run-centjes-e2e-test] client # [ 0.024382] Trampoline variant of Tasks RCU enabled.
  522. 41.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.636629] landlock: Up and running.
  523. 41.24 s [vm-test-run-centjes-e2e-test] client # [ 0.024382] Rude variant of Tasks RCU enabled.
  524. 41.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.637552] Yama: becoming mindful.
  525. 41.24 s [vm-test-run-centjes-e2e-test] client # [ 0.024382] Tracing variant of Tasks RCU enabled.
  526. 41.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.639814] LSM support for eBPF active
  527. 41.25 s [vm-test-run-centjes-e2e-test] client # [ 0.024383] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.
  528. 41.25 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.641595] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
  529. 41.25 s [vm-test-run-centjes-e2e-test] client # [ 0.024384] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
  530. 41.25 s [vm-test-run-centjes-e2e-test] client # [ 0.024392] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  531. 41.25 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.643554] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
  532. 41.26 s [vm-test-run-centjes-e2e-test] client # [ 0.024394] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  533. 41.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.646103] smpboot: CPU0: AMD Ryzen 9 5950X 16-Core Processor (family: 0x19, model: 0x21, stepping: 0x0)
  534. 41.26 s [vm-test-run-centjes-e2e-test] client # [ 0.024395] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  535. 41.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.647830] Performance Events: Fam17h+ core perfctr, AMD PMU driver.
  536. 41.26 s [vm-test-run-centjes-e2e-test] client # [ 0.028350] NR_IRQS: 24832, nr_irqs: 256, preallocated irqs: 16
  537. 41.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.649572] ... version: 0
  538. 41.27 s [vm-test-run-centjes-e2e-test] client # [ 0.028629] rcu: srcu_init: Setting srcu_struct sizes based on contention.
  539. 41.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.650563] ... bit width: 48
  540. 41.27 s [vm-test-run-centjes-e2e-test] client # [ 0.028706] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)
  541. 41.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.651563] ... generic registers: 6
  542. 41.27 s [vm-test-run-centjes-e2e-test] client # [ 0.044365] Console: colour VGA+ 80x25
  543. 41.28 s [vm-test-run-centjes-e2e-test] client # [ 0.044370] printk: legacy console [tty0] enabled
  544. 41.28 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.652563] ... value mask: 0000ffffffffffff
  545. 41.28 s [vm-test-run-centjes-e2e-test] client # [ 0.173277] printk: legacy console [ttyS0] enabled
  546. 41.28 s [vm-test-run-centjes-e2e-test] client # [ 0.556319] ACPI: Core revision 20240827
  547. 41.28 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.654562] ... max period: 00007fffffffffff
  548. 41.28 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.655561] ... fixed-purpose events: 0
  549. 41.28 s [vm-test-run-centjes-e2e-test] client # [ 0.559009] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
  550. 41.29 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.656561] ... event mask: 000000000000003f
  551. 41.29 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.657659] signal: max sigframe size: 3376
  552. 41.29 s [vm-test-run-centjes-e2e-test] client # [ 0.564173] APIC: Switch to symmetric I/O mode setup
  553. 41.29 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.658656] rcu: Hierarchical SRCU implementation.
  554. 41.29 s [vm-test-run-centjes-e2e-test] client # [ 0.568577] x2apic enabled
  555. 41.29 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.659561] rcu: Max phase no-delay instances is 400.
  556. 41.30 s [vm-test-run-centjes-e2e-test] client # [ 0.571547] APIC: Switched APIC routing to: physical x2apic
  557. 41.30 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.665112] smp: Bringing up secondary CPUs ...
  558. 41.30 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.666580] smp: Brought up 1 node, 1 CPU
  559. 41.31 s [vm-test-run-centjes-e2e-test] client # [ 0.580426] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
  560. 41.31 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.668564] smpboot: Total of 1 processors activated (6799.99 BogoMIPS)
  561. 41.31 s [vm-test-run-centjes-e2e-test] client # [ 0.584147] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x31024b3bec5, max_idle_ns: 440795366697 ns
  562. 41.32 s [vm-test-run-centjes-e2e-test] client # [ 0.590913] Calibrating delay loop (skipped) preset value.. 6799.99 BogoMIPS (lpj=3399996)
  563. 41.32 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.670999] Memory: 962120K/1048036K available (16384K kernel code, 2645K rwdata, 12580K rodata, 3408K init, 3360K bss, 78836K reserved, 0K cma-reserved)
  564. 41.32 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.672763] devtmpfs: initialized
  565. 41.32 s [vm-test-run-centjes-e2e-test] client # [ 0.594612] x86/cpu: User Mode Instruction Prevention (UMIP) activated
  566. 41.32 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.673639] x86/mm: Memory block size: 128MB
  567. 41.33 s [vm-test-run-centjes-e2e-test] client # [ 0.598427] Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127
  568. 41.33 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.675140] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
  569. 41.33 s [vm-test-run-centjes-e2e-test] client # [ 0.599911] Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0
  570. 41.33 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.676568] futex hash table entries: 256 (order: 2, 16384 bytes, linear)
  571. 41.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.678647] pinctrl core: initialized pinctrl subsystem
  572. 41.34 s [vm-test-run-centjes-e2e-test] client # [ 0.601926] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
  573. 41.34 s [vm-test-run-centjes-e2e-test] client # [ 0.603915] Spectre V2 : Mitigation: Retpolines
  574. 41.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.680998] PM: RTC time: 17:49:40, date: 2026-04-27
  575. 41.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.683388] NET: Registered PF_NETLINK/PF_ROUTE protocol family
  576. 41.34 s [vm-test-run-centjes-e2e-test] client # [ 0.605912] Spectre V2 : Spectre v2 / SpectreRSB: Filling RSB on context switch and VMEXIT
  577. 41.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.684803] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations
  578. 41.35 s [vm-test-run-centjes-e2e-test] client # [ 0.607912] Spectre V2 : Enabling Restricted Speculation for firmware calls
  579. 41.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.686575] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
  580. 41.36 s [vm-test-run-centjes-e2e-test] client # [ 0.609916] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
  581. 41.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.688573] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
  582. 41.36 s [vm-test-run-centjes-e2e-test] client # [ 0.611913] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl
  583. 41.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.690579] audit: initializing netlink subsys (disabled)
  584. 41.36 s [vm-test-run-centjes-e2e-test] client # [ 0.613912] active return thunk: srso_alias_return_thunk
  585. 41.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.692630] audit: type=2000 audit(1777312180.119:1): state=initialized audit_enabled=0 res=1
  586. 41.37 s [vm-test-run-centjes-e2e-test] client # [ 0.615911] Speculative Return Stack Overflow: Mitigation: Safe RET
  587. 41.37 s [vm-test-run-centjes-e2e-test] client # [ 0.617911] Transient Scheduler Attacks: Forcing mitigation on in a VM
  588. 41.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.694720] thermal_sys: Registered thermal governor 'bang_bang'
  589. 41.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.694723] thermal_sys: Registered thermal governor 'step_wise'
  590. 41.38 s [vm-test-run-centjes-e2e-test] client # [ 0.619912] Transient Scheduler Attacks: Vulnerable: Clear CPU buffers attempted, no microcode
  591. 41.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.696572] thermal_sys: Registered thermal governor 'user_space'
  592. 41.38 s [vm-test-run-centjes-e2e-test] client # [ 0.622027] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
  593. 41.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.698588] cpuidle: using governor menu
  594. 41.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.703976] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
  595. 41.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.705880] PCI: Using configuration type 1 for base access
  596. 41.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.707577] PCI: Using configuration type 1 for extended access
  597. 41.40 s [vm-test-run-centjes-e2e-test] client # [ 0.623912] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
  598. 41.40 s [vm-test-run-centjes-e2e-test] client # [ 0.625914] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
  599. 41.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.708830] kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible.
  600. 41.40 s [vm-test-run-centjes-e2e-test] client # [ 0.627912] x86/fpu: Supporting XSAVE feature 0x200: 'Protection Keys User registers'
  601. 41.41 s [vm-test-run-centjes-e2e-test] client # [ 0.629913] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256
  602. 41.41 s [vm-test-run-centjes-e2e-test] client # [ 0.631912] x86/fpu: xstate_offset[9]: 832, xstate_sizes[9]: 8
  603. 41.42 s [vm-test-run-centjes-e2e-test] client # [ 0.633912] x86/fpu: Enabled xstate features 0x207, context size is 840 bytes, using 'compacted' format.
  604. 41.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.733683] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages
  605. 41.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.735566] HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page
  606. 41.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.737565] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
  607. 41.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.739568] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page
  608. 41.45 s [vm-test-run-centjes-e2e-test] client # [ 0.664372] Freeing SMP alternatives memory: 40K
  609. 41.45 s [vm-test-run-centjes-e2e-test] client # [ 0.665914] pid_max: default: 32768 minimum: 301
  610. 41.45 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.749820] ACPI: Added _OSI(Module Device)
  611. 41.45 s [vm-test-run-centjes-e2e-test] client # [ 0.667969] LSM: initializing lsm=capability,landlock,yama,bpf
  612. 41.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.751562] ACPI: Added _OSI(Processor Device)
  613. 41.46 s [vm-test-run-centjes-e2e-test] client # [ 0.670011] landlock: Up and running.
  614. 41.46 s [vm-test-run-centjes-e2e-test] client # [ 0.670913] Yama: becoming mindful.
  615. 41.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.753565] ACPI: Added _OSI(Processor Aggregator Device)
  616. 41.46 s [vm-test-run-centjes-e2e-test] client # [ 0.674170] LSM support for eBPF active
  617. 41.47 s [vm-test-run-centjes-e2e-test] client # [ 0.676929] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
  618. 41.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.758210] ACPI: 1 ACPI AML tables successfully acquired and loaded
  619. 41.47 s [vm-test-run-centjes-e2e-test] client # [ 0.678915] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
  620. 41.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.761929] ACPI: Interpreter enabled
  621. 41.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.763586] ACPI: PM: (supports S0 S3 S4 S5)
  622. 41.48 s [vm-test-run-centjes-e2e-test] client # [ 0.681470] smpboot: CPU0: AMD Ryzen 9 5950X 16-Core Processor (family: 0x19, model: 0x21, stepping: 0x0)
  623. 41.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.765565] ACPI: Using IOAPIC for interrupt routing
  624. 41.48 s [vm-test-run-centjes-e2e-test] client # [ 0.683268] Performance Events: Fam17h+ core perfctr, AMD PMU driver.
  625. 41.48 s [vm-test-run-centjes-e2e-test] client # [ 0.684929] ... version: 0
  626. 41.49 s [vm-test-run-centjes-e2e-test] client # [ 0.685921] ... bit width: 48
  627. 41.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.767614] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
  628. 41.49 s [vm-test-run-centjes-e2e-test] client # [ 0.686921] ... generic registers: 6
  629. 41.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.769566] PCI: Using E820 reservations for host bridge windows
  630. 41.49 s [vm-test-run-centjes-e2e-test] client # [ 0.687923] ... value mask: 0000ffffffffffff
  631. 41.50 s [vm-test-run-centjes-e2e-test] client # [ 0.689923] ... max period: 00007fffffffffff
  632. 41.50 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.771872] ACPI: Enabled 2 GPEs in block 00 to 0F
  633. 41.50 s [vm-test-run-centjes-e2e-test] client # [ 0.690921] ... fixed-purpose events: 0
  634. 41.50 s [vm-test-run-centjes-e2e-test] client # [ 0.691920] ... event mask: 000000000000003f
  635. 41.50 s [vm-test-run-centjes-e2e-test] client # [ 0.693048] signal: max sigframe size: 3376
  636. 41.51 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.779411] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
  637. 41.51 s [vm-test-run-centjes-e2e-test] client # [ 0.695004] rcu: Hierarchical SRCU implementation.
  638. 41.51 s [vm-test-run-centjes-e2e-test] client # [ 0.696921] rcu: Max phase no-delay instances is 400.
  639. 41.51 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.780573] acpi PNP0A03:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3]
  640. 41.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.783085] acpiphp: Slot [3] registered
  641. 41.52 s [vm-test-run-centjes-e2e-test] client # [ 0.701947] smp: Bringing up secondary CPUs ...
  642. 41.52 s [vm-test-run-centjes-e2e-test] client # [ 0.703937] smp: Brought up 1 node, 1 CPU
  643. 41.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.784656] acpiphp: Slot [4] registered
  644. 41.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.786628] acpiphp: Slot [5] registered
  645. 41.52 s [vm-test-run-centjes-e2e-test] client # [ 0.704927] smpboot: Total of 1 processors activated (6799.99 BogoMIPS)
  646. 41.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.788628] acpiphp: Slot [6] registered
  647. 41.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.790623] acpiphp: Slot [7] registered
  648. 41.53 s [vm-test-run-centjes-e2e-test] client # [ 0.707297] Memory: 962112K/1048036K available (16384K kernel code, 2645K rwdata, 12580K rodata, 3408K init, 3360K bss, 78836K reserved, 0K cma-reserved)
  649. 41.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.792622] acpiphp: Slot [8] registered
  650. 41.53 s [vm-test-run-centjes-e2e-test] client # [ 0.709090] devtmpfs: initialized
  651. 41.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.794627] acpiphp: Slot [9] registered
  652. 41.54 s [vm-test-run-centjes-e2e-test] client # [ 0.709998] x86/mm: Memory block size: 128MB
  653. 41.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.796623] acpiphp: Slot [10] registered
  654. 41.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.798643] acpiphp: Slot [11] registered
  655. 41.54 s [vm-test-run-centjes-e2e-test] client # [ 0.711500] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
  656. 41.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.800624] acpiphp: Slot [12] registered
  657. 41.55 s [vm-test-run-centjes-e2e-test] client # [ 0.712925] futex hash table entries: 256 (order: 2, 16384 bytes, linear)
  658. 41.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.802628] acpiphp: Slot [13] registered
  659. 41.55 s [vm-test-run-centjes-e2e-test] client # [ 0.714998] pinctrl core: initialized pinctrl subsystem
  660. 41.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.804620] acpiphp: Slot [14] registered
  661. 41.55 s [vm-test-run-centjes-e2e-test] client # [ 0.716286] PM: RTC time: 17:49:40, date: 2026-04-27
  662. 41.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.806624] acpiphp: Slot [15] registered
  663. 41.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.808633] acpiphp: Slot [16] registered
  664. 41.56 s [vm-test-run-centjes-e2e-test] client # [ 0.718804] NET: Registered PF_NETLINK/PF_ROUTE protocol family
  665. 41.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.810622] acpiphp: Slot [17] registered
  666. 41.56 s [vm-test-run-centjes-e2e-test] client # [ 0.720139] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations
  667. 41.57 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.812625] acpiphp: Slot [18] registered
  668. 41.57 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.814624] acpiphp: Slot [19] registered
  669. 41.57 s [vm-test-run-centjes-e2e-test] client # [ 0.721941] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
  670. 41.57 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.816628] acpiphp: Slot [20] registered
  671. 41.57 s [vm-test-run-centjes-e2e-test] client # [ 0.723934] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
  672. 41.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.818622] acpiphp: Slot [21] registered
  673. 41.58 s [vm-test-run-centjes-e2e-test] client # [ 0.725937] audit: initializing netlink subsys (disabled)
  674. 41.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.820622] acpiphp: Slot [22] registered
  675. 41.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.822621] acpiphp: Slot [23] registered
  676. 41.58 s [vm-test-run-centjes-e2e-test] client # [ 0.726981] audit: type=2000 audit(1777312180.309:1): state=initialized audit_enabled=0 res=1
  677. 41.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.824625] acpiphp: Slot [24] registered
  678. 41.59 s [vm-test-run-centjes-e2e-test] client # [ 0.729078] thermal_sys: Registered thermal governor 'bang_bang'
  679. 41.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.826623] acpiphp: Slot [25] registered
  680. 41.59 s [vm-test-run-centjes-e2e-test] client # [ 0.729081] thermal_sys: Registered thermal governor 'step_wise'
  681. 41.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.828650] acpiphp: Slot [26] registered
  682. 41.59 s [vm-test-run-centjes-e2e-test] client # [ 0.730924] thermal_sys: Registered thermal governor 'user_space'
  683. 41.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.830627] acpiphp: Slot [27] registered
  684. 41.60 s [vm-test-run-centjes-e2e-test] client # [ 0.731935] cpuidle: using governor menu
  685. 41.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.832628] acpiphp: Slot [28] registered
  686. 41.60 s [vm-test-run-centjes-e2e-test] client # [ 0.737215] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
  687. 41.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.834622] acpiphp: Slot [29] registered
  688. 41.61 s [vm-test-run-centjes-e2e-test] client # [ 0.739268] PCI: Using configuration type 1 for base access
  689. 41.61 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.836625] acpiphp: Slot [30] registered
  690. 41.61 s [vm-test-run-centjes-e2e-test] client # [ 0.740924] PCI: Using configuration type 1 for extended access
  691. 41.61 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.838629] acpiphp: Slot [31] registered
  692. 41.61 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.840632] PCI host bridge to bus 0000:00
  693. 41.61 s [vm-test-run-centjes-e2e-test] client # [ 0.743092] kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible.
  694. 41.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.842576] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]
  695. 41.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.844565] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]
  696. 41.63 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.846565] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
  697. 41.63 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.848566] pci_bus 0000:00: root bus resource [mem 0x40000000-0xfebfffff window]
  698. 41.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.850566] pci_bus 0000:00: root bus resource [mem 0x100000000-0x17fffffff window]
  699. 41.64 s [vm-test-run-centjes-e2e-test] client # [ 0.770156] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages
  700. 41.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.852569] pci_bus 0000:00: root bus resource [bus 00-ff]
  701. 41.65 s [vm-test-run-centjes-e2e-test] client # [ 0.771922] HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page
  702. 41.65 s [vm-test-run-centjes-e2e-test] client # [ 0.773924] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
  703. 41.65 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.855355] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 conventional PCI endpoint
  704. 41.65 s [vm-test-run-centjes-e2e-test] client # [ 0.775921] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page
  705. 41.66 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.858447] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 conventional PCI endpoint
  706. 41.66 s [vm-test-run-centjes-e2e-test] client # [ 0.784776] ACPI: Added _OSI(Module Device)
  707. 41.67 s [vm-test-run-centjes-e2e-test] client # [ 0.785921] ACPI: Added _OSI(Processor Device)
  708. 41.67 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.862194] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 conventional PCI endpoint
  709. 41.67 s [vm-test-run-centjes-e2e-test] client # [ 0.786924] ACPI: Added _OSI(Processor Aggregator Device)
  710. 41.68 s [vm-test-run-centjes-e2e-test] client # [ 0.790826] ACPI: 1 ACPI AML tables successfully acquired and loaded
  711. 41.68 s [vm-test-run-centjes-e2e-test] client # [ 0.793178] ACPI: Interpreter enabled
  712. 41.68 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.869339] pci 0000:00:01.1: BAR 4 [io 0xc1e0-0xc1ef]
  713. 41.68 s [vm-test-run-centjes-e2e-test] client # [ 0.794947] ACPI: PM: (supports S0 S3 S4 S5)
  714. 41.69 s [vm-test-run-centjes-e2e-test] client # [ 0.795922] ACPI: Using IOAPIC for interrupt routing
  715. 41.69 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.872666] pci 0000:00:01.1: BAR 0 [io 0x01f0-0x01f7]: legacy IDE quirk
  716. 41.69 s [vm-test-run-centjes-e2e-test] client # [ 0.796947] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
  717. 41.69 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.874565] pci 0000:00:01.1: BAR 1 [io 0x03f6]: legacy IDE quirk
  718. 41.69 s [vm-test-run-centjes-e2e-test] client # [ 0.798922] PCI: Using E820 reservations for host bridge windows
  719. 41.70 s [vm-test-run-centjes-e2e-test] client # [ 0.800149] ACPI: Enabled 2 GPEs in block 00 to 0F
  720. 41.70 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.876565] pci 0000:00:01.1: BAR 2 [io 0x0170-0x0177]: legacy IDE quirk
  721. 41.70 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.878565] pci 0000:00:01.1: BAR 3 [io 0x0376]: legacy IDE quirk
  722. 41.71 s [vm-test-run-centjes-e2e-test] client # [ 0.806711] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
  723. 41.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.881202] pci 0000:00:01.2: [8086:7020] type 00 class 0x0c0300 conventional PCI endpoint
  724. 41.71 s [vm-test-run-centjes-e2e-test] client # [ 0.807926] acpi PNP0A03:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3]
  725. 41.71 s [vm-test-run-centjes-e2e-test] client # [ 0.810310] acpiphp: Slot [3] registered
  726. 41.72 s [vm-test-run-centjes-e2e-test] client # [ 0.811990] acpiphp: Slot [4] registered
  727. 41.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.887254] pci 0000:00:01.2: BAR 4 [io 0xc100-0xc11f]
  728. 41.72 s [vm-test-run-centjes-e2e-test] client # [ 0.812987] acpiphp: Slot [5] registered
  729. 41.72 s [vm-test-run-centjes-e2e-test] client # [ 0.814986] acpiphp: Slot [6] registered
  730. 41.73 s [vm-test-run-centjes-e2e-test] client # [ 0.815987] acpiphp: Slot [7] registered
  731. 41.73 s [vm-test-run-centjes-e2e-test] client # [ 0.816987] acpiphp: Slot [8] registered
  732. 41.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.892905] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 conventional PCI endpoint
  733. 41.73 s [vm-test-run-centjes-e2e-test] client # [ 0.817992] acpiphp: Slot [9] registered
  734. 41.73 s [vm-test-run-centjes-e2e-test] client # [ 0.819986] acpiphp: Slot [10] registered
  735. 41.74 s [vm-test-run-centjes-e2e-test] client # [ 0.820969] acpiphp: Slot [11] registered
  736. 41.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.896874] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI
  737. 41.74 s [vm-test-run-centjes-e2e-test] client # [ 0.821980] acpiphp: Slot [12] registered
  738. 41.74 s [vm-test-run-centjes-e2e-test] client # [ 0.822973] acpiphp: Slot [13] registered
  739. 41.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.898603] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB
  740. 41.75 s [vm-test-run-centjes-e2e-test] client # [ 0.823998] acpiphp: Slot [14] registered
  741. 41.75 s [vm-test-run-centjes-e2e-test] client # [ 0.824980] acpiphp: Slot [15] registered
  742. 41.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.901429] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000 conventional PCI endpoint
  743. 41.75 s [vm-test-run-centjes-e2e-test] client # [ 0.826018] acpiphp: Slot [16] registered
  744. 41.75 s [vm-test-run-centjes-e2e-test] client # [ 0.826985] acpiphp: Slot [17] registered
  745. 41.76 s [vm-test-run-centjes-e2e-test] client # [ 0.827982] acpiphp: Slot [18] registered
  746. 41.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.904605] pci 0000:00:02.0: BAR 0 [mem 0xfd000000-0xfdffffff pref]
  747. 41.76 s [vm-test-run-centjes-e2e-test] client # [ 0.828981] acpiphp: Slot [19] registered
  748. 41.76 s [vm-test-run-centjes-e2e-test] client # [ 0.829972] acpiphp: Slot [20] registered
  749. 41.76 s [vm-test-run-centjes-e2e-test] client # [ 0.830967] acpiphp: Slot [21] registered
  750. 41.77 s [vm-test-run-centjes-e2e-test] client # [ 0.831980] acpiphp: Slot [22] registered
  751. 41.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.910531] pci 0000:00:02.0: BAR 2 [mem 0xfebd0000-0xfebd0fff]
  752. 41.77 s [vm-test-run-centjes-e2e-test] client # [ 0.832966] acpiphp: Slot [23] registered
  753. 41.77 s [vm-test-run-centjes-e2e-test] client # [ 0.833970] acpiphp: Slot [24] registered
  754. 41.77 s [vm-test-run-centjes-e2e-test] client # [ 0.834966] acpiphp: Slot [25] registered
  755. 41.77 s [vm-test-run-centjes-e2e-test] client # [ 0.835967] acpiphp: Slot [26] registered
  756. 41.78 s [vm-test-run-centjes-e2e-test] client # [ 0.836981] acpiphp: Slot [27] registered
  757. 41.78 s [vm-test-run-centjes-e2e-test] client # [ 0.837971] acpiphp: Slot [28] registered
  758. 41.78 s [vm-test-run-centjes-e2e-test] client # [ 0.838967] acpiphp: Slot [29] registered
  759. 41.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.918606] pci 0000:00:02.0: ROM [mem 0xfebc0000-0xfebcffff pref]
  760. 41.78 s [vm-test-run-centjes-e2e-test] client # [ 0.839967] acpiphp: Slot [30] registered
  761. 41.79 s [vm-test-run-centjes-e2e-test] client # [ 0.840969] acpiphp: Slot [31] registered
  762. 41.79 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.920819] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
  763. 41.79 s [vm-test-run-centjes-e2e-test] client # [ 0.841957] PCI host bridge to bus 0000:00
  764. 41.79 s [vm-test-run-centjes-e2e-test] client # [ 0.842930] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]
  765. 41.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.923754] pci 0000:00:03.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
  766. 41.80 s [vm-test-run-centjes-e2e-test] client # [ 0.844922] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]
  767. 41.80 s [vm-test-run-centjes-e2e-test] client # [ 0.846922] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
  768. 41.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.927482] pci 0000:00:03.0: BAR 0 [io 0xc120-0xc13f]
  769. 41.81 s [vm-test-run-centjes-e2e-test] client # [ 0.848922] pci_bus 0000:00: root bus resource [mem 0x40000000-0xfebfffff window]
  770. 41.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.930564] pci 0000:00:03.0: BAR 1 [mem 0xfebd1000-0xfebd1fff]
  771. 41.81 s [vm-test-run-centjes-e2e-test] client # [ 0.850926] pci_bus 0000:00: root bus resource [mem 0x100000000-0x17fffffff window]
  772. 41.81 s [vm-test-run-centjes-e2e-test] client # [ 0.852923] pci_bus 0000:00: root bus resource [bus 00-ff]
  773. 41.82 s [vm-test-run-centjes-e2e-test] client # [ 0.855635] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 conventional PCI endpoint
  774. 41.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.936567] pci 0000:00:03.0: BAR 4 [mem 0xfe000000-0xfe003fff 64bit pref]
  775. 41.83 s [vm-test-run-centjes-e2e-test] client # [ 0.858632] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 conventional PCI endpoint
  776. 41.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.940412] pci 0000:00:03.0: ROM [mem 0xfeb40000-0xfeb7ffff pref]
  777. 41.84 s [vm-test-run-centjes-e2e-test] client # [ 0.862142] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 conventional PCI endpoint
  778. 41.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.944882] pci 0000:00:04.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
  779. 41.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.948566] pci 0000:00:04.0: BAR 0 [io 0xc140-0xc15f]
  780. 41.84 s [vm-test-run-centjes-e2e-test] client # [ 0.868885] pci 0000:00:01.1: BAR 4 [io 0xc1e0-0xc1ef]
  781. 41.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.952482] pci 0000:00:04.0: BAR 1 [mem 0xfebd2000-0xfebd2fff]
  782. 41.85 s [vm-test-run-centjes-e2e-test] client # [ 0.872633] pci 0000:00:01.1: BAR 0 [io 0x01f0-0x01f7]: legacy IDE quirk
  783. 41.86 s [vm-test-run-centjes-e2e-test] client # [ 0.873928] pci 0000:00:01.1: BAR 1 [io 0x03f6]: legacy IDE quirk
  784. 41.86 s [vm-test-run-centjes-e2e-test] client # [ 0.875926] pci 0000:00:01.1: BAR 2 [io 0x0170-0x0177]: legacy IDE quirk
  785. 41.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.957566] pci 0000:00:04.0: BAR 4 [mem 0xfe004000-0xfe007fff 64bit pref]
  786. 41.87 s [vm-test-run-centjes-e2e-test] client # [ 0.877926] pci 0000:00:01.1: BAR 3 [io 0x0376]: legacy IDE quirk
  787. 41.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.963924] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  788. 41.88 s [vm-test-run-centjes-e2e-test] client # [ 0.880606] pci 0000:00:01.2: [8086:7020] type 00 class 0x0c0300 conventional PCI endpoint
  789. 41.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.966561] pci 0000:00:05.0: BAR 0 [io 0xc080-0xc0bf]
  790. 41.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.968562] pci 0000:00:05.0: BAR 1 [mem 0xfebd3000-0xfebd3fff]
  791. 41.89 s [vm-test-run-centjes-e2e-test] client # [ 0.886928] pci 0000:00:01.2: BAR 4 [io 0xc100-0xc11f]
  792. 41.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.973561] pci 0000:00:05.0: BAR 4 [mem 0xfe008000-0xfe00bfff 64bit pref]
  793. 41.90 s [vm-test-run-centjes-e2e-test] client # [ 0.893257] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 conventional PCI endpoint
  794. 41.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.980000] pci 0000:00:06.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  795. 41.91 s [vm-test-run-centjes-e2e-test] client # [ 0.897398] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI
  796. 41.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.983434] pci 0000:00:06.0: BAR 0 [io 0xc160-0xc17f]
  797. 41.91 s [vm-test-run-centjes-e2e-test] client # [ 0.898970] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB
  798. 41.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.985563] pci 0000:00:06.0: BAR 1 [mem 0xfebd4000-0xfebd4fff]
  799. 41.92 s [vm-test-run-centjes-e2e-test] client # [ 0.901926] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000 conventional PCI endpoint
  800. 41.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.991565] pci 0000:00:06.0: BAR 4 [mem 0xfe00c000-0xfe00ffff 64bit pref]
  801. 41.93 s [vm-test-run-centjes-e2e-test] client # [ 0.905989] pci 0000:00:02.0: BAR 0 [mem 0xfd000000-0xfdffffff pref]
  802. 41.94 s [vm-test-run-centjes-e2e-test] client # [ 0.912016] pci 0000:00:02.0: BAR 2 [mem 0xfebd0000-0xfebd0fff]
  803. 41.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.998762] pci 0000:00:07.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  804. 41.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.002131] pci 0000:00:07.0: BAR 0 [io 0xc180-0xc19f]
  805. 41.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.004563] pci 0000:00:07.0: BAR 1 [mem 0xfebd5000-0xfebd5fff]
  806. 41.96 s [vm-test-run-centjes-e2e-test] client # [ 0.920989] pci 0000:00:02.0: ROM [mem 0xfebc0000-0xfebcffff pref]
  807. 41.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.009589] pci 0000:00:07.0: BAR 4 [mem 0xfe010000-0xfe013fff 64bit pref]
  808. 41.96 s [vm-test-run-centjes-e2e-test] client # [ 0.923178] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
  809. 41.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.015876] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint
  810. 41.97 s [vm-test-run-centjes-e2e-test] client # [ 0.926176] pci 0000:00:03.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
  811. 41.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.018561] pci 0000:00:08.0: BAR 0 [io 0xc000-0xc07f]
  812. 41.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.020561] pci 0000:00:08.0: BAR 1 [mem 0xfebd6000-0xfebd6fff]
  813. 41.98 s [vm-test-run-centjes-e2e-test] client # [ 0.929926] pci 0000:00:03.0: BAR 0 [io 0xc120-0xc13f]
  814. 41.98 s [vm-test-run-centjes-e2e-test] client # [ 0.933926] pci 0000:00:03.0: BAR 1 [mem 0xfebd1000-0xfebd1fff]
  815. 41.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.025350] pci 0000:00:08.0: BAR 4 [mem 0xfe014000-0xfe017fff 64bit pref]
  816. 42.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.031314] pci 0000:00:09.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
  817. 42.00 s [vm-test-run-centjes-e2e-test] client # [ 0.940928] pci 0000:00:03.0: BAR 4 [mem 0xfe000000-0xfe003fff 64bit pref]
  818. 42.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.033560] pci 0000:00:09.0: BAR 0 [io 0xc1a0-0xc1bf]
  819. 42.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.035560] pci 0000:00:09.0: BAR 1 [mem 0xfebd7000-0xfebd7fff]
  820. 42.01 s [vm-test-run-centjes-e2e-test] client # [ 0.944827] pci 0000:00:03.0: ROM [mem 0xfeb40000-0xfeb7ffff pref]
  821. 42.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.039561] pci 0000:00:09.0: BAR 4 [mem 0xfe018000-0xfe01bfff 64bit pref]
  822. 42.02 s [vm-test-run-centjes-e2e-test] client # [ 0.950363] pci 0000:00:04.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
  823. 42.02 s [vm-test-run-centjes-e2e-test] client # [ 0.953926] pci 0000:00:04.0: BAR 0 [io 0xc140-0xc15f]
  824. 42.03 s [vm-test-run-centjes-e2e-test] client # [ 0.957787] pci 0000:00:04.0: BAR 1 [mem 0xfebd2000-0xfebd2fff]
  825. 42.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.042560] pci 0000:00:09.0: ROM [mem 0xfeb80000-0xfebbffff pref]
  826. 42.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.048311] pci 0000:00:0a.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint
  827. 42.04 s [vm-test-run-centjes-e2e-test] client # [ 0.963927] pci 0000:00:04.0: BAR 4 [mem 0xfe004000-0xfe007fff 64bit pref]
  828. 42.05 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.052001] pci 0000:00:0a.0: BAR 1 [mem 0xfebd8000-0xfebd8fff]
  829. 42.06 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.056564] pci 0000:00:0a.0: BAR 4 [mem 0xfe01c000-0xfe01ffff 64bit pref]
  830. 42.06 s [vm-test-run-centjes-e2e-test] client # [ 0.972489] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  831. 42.06 s [vm-test-run-centjes-e2e-test] client # [ 0.974922] pci 0000:00:05.0: BAR 0 [io 0xc080-0xc0bf]
  832. 42.07 s [vm-test-run-centjes-e2e-test] client # [ 0.976921] pci 0000:00:05.0: BAR 1 [mem 0xfebd3000-0xfebd3fff]
  833. 42.07 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.062833] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint
  834. 42.07 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.066374] pci 0000:00:0b.0: BAR 0 [io 0xc0c0-0xc0ff]
  835. 42.08 s [vm-test-run-centjes-e2e-test] client # [ 0.982922] pci 0000:00:05.0: BAR 4 [mem 0xfe008000-0xfe00bfff 64bit pref]
  836. 42.08 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.069267] pci 0000:00:0b.0: BAR 1 [mem 0xfebd9000-0xfebd9fff]
  837. 42.09 s [vm-test-run-centjes-e2e-test] client # [ 0.990035] pci 0000:00:06.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  838. 42.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.074565] pci 0000:00:0b.0: BAR 4 [mem 0xfe020000-0xfe023fff 64bit pref]
  839. 42.09 s [vm-test-run-centjes-e2e-test] client # [ 0.992921] pci 0000:00:06.0: BAR 0 [io 0xc160-0xc17f]
  840. 42.10 s [vm-test-run-centjes-e2e-test] client # [ 0.995924] pci 0000:00:06.0: BAR 1 [mem 0xfebd4000-0xfebd4fff]
  841. 42.10 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.080821] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
  842. 42.10 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.083563] pci 0000:00:0c.0: BAR 0 [io 0xc1c0-0xc1df]
  843. 42.11 s [vm-test-run-centjes-e2e-test] client # [ 1.001889] pci 0000:00:06.0: BAR 4 [mem 0xfe00c000-0xfe00ffff 64bit pref]
  844. 42.11 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.086541] pci 0000:00:0c.0: BAR 1 [mem 0xfebda000-0xfebdafff]
  845. 42.12 s [vm-test-run-centjes-e2e-test] client # [ 1.008218] pci 0000:00:07.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  846. 42.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.092563] pci 0000:00:0c.0: BAR 4 [mem 0xfe024000-0xfe027fff 64bit pref]
  847. 42.13 s [vm-test-run-centjes-e2e-test] client # [ 1.011646] pci 0000:00:07.0: BAR 0 [io 0xc180-0xc19f]
  848. 42.13 s [vm-test-run-centjes-e2e-test] client # [ 1.013923] pci 0000:00:07.0: BAR 1 [mem 0xfebd5000-0xfebd5fff]
  849. 42.13 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.100070] ACPI: PCI: Interrupt link LNKA configured for IRQ 10
  850. 42.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.101860] ACPI: PCI: Interrupt link LNKB configured for IRQ 10
  851. 42.14 s [vm-test-run-centjes-e2e-test] client # [ 1.019922] pci 0000:00:07.0: BAR 4 [mem 0xfe010000-0xfe013fff 64bit pref]
  852. 42.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.103899] ACPI: PCI: Interrupt link LNKC configured for IRQ 11
  853. 42.15 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.105847] ACPI: PCI: Interrupt link LNKD configured for IRQ 11
  854. 42.15 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.107723] ACPI: PCI: Interrupt link LNKS configured for IRQ 9
  855. 42.15 s [vm-test-run-centjes-e2e-test] client # [ 1.027573] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint
  856. 42.15 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.110139] iommu: Default domain type: Translated
  857. 42.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.111563] iommu: DMA domain TLB invalidation policy: lazy mode
  858. 42.16 s [vm-test-run-centjes-e2e-test] client # [ 1.030877] pci 0000:00:08.0: BAR 0 [io 0xc000-0xc07f]
  859. 42.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.113603] ACPI: bus type USB registered
  860. 42.16 s [vm-test-run-centjes-e2e-test] client # [ 1.032923] pci 0000:00:08.0: BAR 1 [mem 0xfebd6000-0xfebd6fff]
  861. 42.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.115599] usbcore: registered new interface driver usbfs
  862. 42.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.117580] usbcore: registered new interface driver hub
  863. 42.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.119578] usbcore: registered new device driver usb
  864. 42.17 s [vm-test-run-centjes-e2e-test] client # [ 1.038820] pci 0000:00:08.0: BAR 4 [mem 0xfe014000-0xfe017fff 64bit pref]
  865. 42.18 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.122053] NetLabel: Initializing
  866. 42.18 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.123593] NetLabel: domain hash size = 128
  867. 42.18 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.125563] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO
  868. 42.19 s [vm-test-run-centjes-e2e-test] client # [ 1.046469] pci 0000:00:09.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
  869. 42.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.127593] NetLabel: unlabeled traffic allowed by default
  870. 42.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.129564] PCI: Using ACPI for IRQ routing
  871. 42.19 s [vm-test-run-centjes-e2e-test] client # [ 1.049725] pci 0000:00:09.0: BAR 0 [io 0xc1a0-0xc1bf]
  872. 42.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.132740] pci 0000:00:02.0: vgaarb: setting as boot VGA device
  873. 42.20 s [vm-test-run-centjes-e2e-test] client # [ 1.051924] pci 0000:00:09.0: BAR 1 [mem 0xfebd7000-0xfebd7fff]
  874. 42.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.133548] pci 0000:00:02.0: vgaarb: bridge control possible
  875. 42.21 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.133548] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
  876. 42.21 s [vm-test-run-centjes-e2e-test] client # [ 1.056921] pci 0000:00:09.0: BAR 4 [mem 0xfe018000-0xfe01bfff 64bit pref]
  877. 42.21 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.133568] vgaarb: loaded
  878. 42.21 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.134674] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
  879. 42.22 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.136562] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
  880. 42.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.141626] clocksource: Switched to clocksource kvm-clock
  881. 42.23 s [vm-test-run-centjes-e2e-test] client # [ 1.060736] pci 0000:00:09.0: ROM [mem 0xfeb80000-0xfebbffff pref]
  882. 42.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.147188] VFS: Disk quotas dquot_6.6.0
  883. 42.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.150435] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
  884. 42.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.155678] pnp: PnP ACPI init
  885. 42.24 s [vm-test-run-centjes-e2e-test] client # [ 1.065697] pci 0000:00:0a.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint
  886. 42.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.159106] pnp: PnP ACPI: found 6 devices
  887. 42.24 s [vm-test-run-centjes-e2e-test] client # [ 1.068877] pci 0000:00:0a.0: BAR 1 [mem 0xfebd8000-0xfebd8fff]
  888. 42.25 s [vm-test-run-centjes-e2e-test] client # [ 1.072523] pci 0000:00:0a.0: BAR 4 [mem 0xfe01c000-0xfe01ffff 64bit pref]
  889. 42.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.169235] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
  890. 42.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.175828] clocksource: Switched to clocksource acpi_pm
  891. 42.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.180130] NET: Registered PF_INET protocol family
  892. 42.26 s [vm-test-run-centjes-e2e-test] client # [ 1.078660] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint
  893. 42.27 s [vm-test-run-centjes-e2e-test] client # [ 1.080922] pci 0000:00:0b.0: BAR 0 [io 0xc0c0-0xc0ff]
  894. 42.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.184262] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
  895. 42.28 s [vm-test-run-centjes-e2e-test] client # [ 1.083923] pci 0000:00:0b.0: BAR 1 [mem 0xfebd9000-0xfebd9fff]
  896. 42.29 s [vm-test-run-centjes-e2e-test] client # [ 1.088922] pci 0000:00:0b.0: BAR 4 [mem 0xfe020000-0xfe023fff 64bit pref]
  897. 42.29 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.206531] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)
  898. 42.30 s [vm-test-run-centjes-e2e-test] client # [ 1.095572] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
  899. 42.30 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.212784] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
  900. 42.30 s [vm-test-run-centjes-e2e-test] client # [ 1.098538] pci 0000:00:0c.0: BAR 0 [io 0xc1c0-0xc1df]
  901. 42.30 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.218770] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)
  902. 42.31 s [vm-test-run-centjes-e2e-test] client # [ 1.100920] pci 0000:00:0c.0: BAR 1 [mem 0xfebda000-0xfebdafff]
  903. 42.31 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.224712] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)
  904. 42.31 s [vm-test-run-centjes-e2e-test] client # [ 1.104923] pci 0000:00:0c.0: BAR 4 [mem 0xfe024000-0xfe027fff 64bit pref]
  905. 42.31 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.230522] TCP: Hash tables configured (established 8192 bind 8192)
  906. 42.32 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.235569] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)
  907. 42.33 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.241288] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
  908. 42.33 s [vm-test-run-centjes-e2e-test] client # [ 1.113735] ACPI: PCI: Interrupt link LNKA configured for IRQ 10
  909. 42.33 s [vm-test-run-centjes-e2e-test] client # [ 1.115147] ACPI: PCI: Interrupt link LNKB configured for IRQ 10
  910. 42.33 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.246539] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
  911. 42.33 s [vm-test-run-centjes-e2e-test] client # [ 1.117235] ACPI: PCI: Interrupt link LNKC configured for IRQ 11
  912. 42.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.251958] NET: Registered PF_UNIX/PF_LOCAL protocol family
  913. 42.34 s [vm-test-run-centjes-e2e-test] client # [ 1.119239] ACPI: PCI: Interrupt link LNKD configured for IRQ 11
  914. 42.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.256494] NET: Registered PF_XDP protocol family
  915. 42.34 s [vm-test-run-centjes-e2e-test] client # [ 1.121090] ACPI: PCI: Interrupt link LNKS configured for IRQ 9
  916. 42.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.260525] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]
  917. 42.35 s [vm-test-run-centjes-e2e-test] client # [ 1.123500] iommu: Default domain type: Translated
  918. 42.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.265258] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]
  919. 42.35 s [vm-test-run-centjes-e2e-test] client # [ 1.124921] iommu: DMA domain TLB invalidation policy: lazy mode
  920. 42.35 s [vm-test-run-centjes-e2e-test] client # [ 1.126956] ACPI: bus type USB registered
  921. 42.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.269992] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
  922. 42.36 s [vm-test-run-centjes-e2e-test] client # [ 1.127958] usbcore: registered new interface driver usbfs
  923. 42.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.275305] pci_bus 0000:00: resource 7 [mem 0x40000000-0xfebfffff window]
  924. 42.36 s [vm-test-run-centjes-e2e-test] client # [ 1.128947] usbcore: registered new interface driver hub
  925. 42.36 s [vm-test-run-centjes-e2e-test] client # [ 1.130939] usbcore: registered new device driver usb
  926. 42.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.280527] pci_bus 0000:00: resource 8 [mem 0x100000000-0x17fffffff window]
  927. 42.37 s [vm-test-run-centjes-e2e-test] client # [ 1.132408] NetLabel: Initializing
  928. 42.37 s [vm-test-run-centjes-e2e-test] client # [ 1.133920] NetLabel: domain hash size = 128
  929. 42.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.285918] pci 0000:00:01.0: PIIX3: Enabling Passive Release
  930. 42.37 s [vm-test-run-centjes-e2e-test] client # [ 1.134924] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO
  931. 42.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.290547] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
  932. 42.38 s [vm-test-run-centjes-e2e-test] client # [ 1.136958] NetLabel: unlabeled traffic allowed by default
  933. 42.38 s [vm-test-run-centjes-e2e-test] client # [ 1.138923] PCI: Using ACPI for IRQ routing
  934. 42.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.297532] ACPI: \_SB_.LNKD: Enabled at IRQ 11
  935. 42.38 s [vm-test-run-centjes-e2e-test] client # [ 1.141092] pci 0000:00:02.0: vgaarb: setting as boot VGA device
  936. 42.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.304671] PCI: CLS 0 bytes, default 64
  937. 42.39 s [vm-test-run-centjes-e2e-test] client # [ 1.141909] pci 0000:00:02.0: vgaarb: bridge control possible
  938. 42.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.307285] Trying to unpack rootfs image as initramfs...
  939. 42.39 s [vm-test-run-centjes-e2e-test] client # [ 1.141909] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
  940. 42.39 s [vm-test-run-centjes-e2e-test] client # [ 1.141932] vgaarb: loaded
  941. 42.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.312557] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x31024b3bec5, max_idle_ns: 440795366697 ns
  942. 42.40 s [vm-test-run-centjes-e2e-test] client # [ 1.143044] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
  943. 42.40 s [vm-test-run-centjes-e2e-test] client # [ 1.144923] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
  944. 42.41 s [vm-test-run-centjes-e2e-test] client # [ 1.148988] clocksource: Switched to clocksource kvm-clock
  945. 42.41 s [vm-test-run-centjes-e2e-test] client # [ 1.153018] VFS: Disk quotas dquot_6.6.0
  946. 42.42 s [vm-test-run-centjes-e2e-test] client # [ 1.155671] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
  947. 42.42 s [vm-test-run-centjes-e2e-test] client # [ 1.159732] pnp: PnP ACPI init
  948. 42.42 s [vm-test-run-centjes-e2e-test] client # [ 1.162469] pnp: PnP ACPI: found 6 devices
  949. 42.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.348754] Initialise system trusted keyrings
  950. 42.43 s [vm-test-run-centjes-e2e-test] client # [ 1.171241] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
  951. 42.44 s [vm-test-run-centjes-e2e-test] client # [ 1.176540] clocksource: Switched to clocksource acpi_pm
  952. 42.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.354714] workingset: timestamp_bits=40 max_order=18 bucket_order=0
  953. 42.44 s [vm-test-run-centjes-e2e-test] client # [ 1.179823] NET: Registered PF_INET protocol family
  954. 42.44 s [vm-test-run-centjes-e2e-test] client # [ 1.183231] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
  955. 42.46 s [vm-test-run-centjes-e2e-test] client # [ 1.198103] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)
  956. 42.46 s [vm-test-run-centjes-e2e-test] client # [ 1.202958] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
  957. 42.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.384497] Key type asymmetric registered
  958. 42.47 s [vm-test-run-centjes-e2e-test] client # [ 1.207630] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)
  959. 42.47 s [vm-test-run-centjes-e2e-test] client # [ 1.212445] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)
  960. 42.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.392486] Asymmetric key parser 'x509' registered
  961. 42.48 s [vm-test-run-centjes-e2e-test] client # [ 1.216996] TCP: Hash tables configured (established 8192 bind 8192)
  962. 42.48 s [vm-test-run-centjes-e2e-test] client # [ 1.220767] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)
  963. 42.48 s [vm-test-run-centjes-e2e-test] client # [ 1.225107] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
  964. 42.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.402516] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
  965. 42.49 s [vm-test-run-centjes-e2e-test] client # [ 1.229049] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
  966. 42.49 s [vm-test-run-centjes-e2e-test] client # [ 1.233367] NET: Registered PF_UNIX/PF_LOCAL protocol family
  967. 42.50 s [vm-test-run-centjes-e2e-test] client # [ 1.236696] NET: Registered PF_XDP protocol family
  968. 42.50 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.415582] io scheduler mq-deadline registered
  969. 42.50 s [vm-test-run-centjes-e2e-test] client # [ 1.239649] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]
  970. 42.50 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.418897] io scheduler kyber registered
  971. 42.50 s [vm-test-run-centjes-e2e-test] client # [ 1.243425] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]
  972. 42.51 s [vm-test-run-centjes-e2e-test] client # [ 1.247216] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
  973. 42.51 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.426589] Freeing initrd memory: 12300K
  974. 42.51 s [vm-test-run-centjes-e2e-test] client # [ 1.251158] pci_bus 0000:00: resource 7 [mem 0x40000000-0xfebfffff window]
  975. 42.51 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.429946] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
  976. 42.52 s [vm-test-run-centjes-e2e-test] client # [ 1.255160] pci_bus 0000:00: resource 8 [mem 0x100000000-0x17fffffff window]
  977. 42.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.434616] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
  978. 42.52 s [vm-test-run-centjes-e2e-test] client # [ 1.259499] pci 0000:00:01.0: PIIX3: Enabling Passive Release
  979. 42.52 s [vm-test-run-centjes-e2e-test] client # [ 1.262955] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
  980. 42.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.440739] Linux agpgart interface v0.103
  981. 42.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.443534] ACPI: bus type drm_connector registered
  982. 42.53 s [vm-test-run-centjes-e2e-test] client # [ 1.268059] ACPI: \_SB_.LNKD: Enabled at IRQ 11
  983. 42.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.447111] usbcore: registered new interface driver usbserial_generic
  984. 42.53 s [vm-test-run-centjes-e2e-test] client # [ 1.273639] PCI: CLS 0 bytes, default 64
  985. 42.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.450910] usbserial: USB Serial support registered for generic
  986. 42.54 s [vm-test-run-centjes-e2e-test] client # [ 1.276495] Trying to unpack rootfs image as initramfs...
  987. 42.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.454669] amd_pstate: the _CPC object is not present in SBIOS or ACPI disabled
  988. 42.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.459578] drop_monitor: Initializing network drop monitor service
  989. 42.54 s [vm-test-run-centjes-e2e-test] client # [ 1.281475] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x31024b3bec5, max_idle_ns: 440795366697 ns
  990. 42.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.463320] NET: Registered PF_INET6 protocol family
  991. 42.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.467330] Segment Routing with IPv6
  992. 42.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.469929] In-situ OAM (IOAM) with IPv6
  993. 42.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.472886] IPI shorthand broadcast: enabled
  994. 42.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.478147] registered taskstats version 1
  995. 42.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.481135] Loading compiled-in X.509 certificates
  996. 42.57 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.489800] Demotion targets for Node 0: null
  997. 42.57 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.492615] Key type .fscrypt registered
  998. 42.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.495057] Key type fscrypt-provisioning registered
  999. 42.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.498188] PM: Magic number: 6:608:846
  1000. 42.58 s [vm-test-run-centjes-e2e-test] client # [ 1.321860] Initialise system trusted keyrings
  1001. 42.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.501788] RAS: Correctable Errors collector initialized.
  1002. 42.59 s [vm-test-run-centjes-e2e-test] client # [ 1.328487] workingset: timestamp_bits=40 max_order=18 bucket_order=0
  1003. 42.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.508686] Unstable clock detected, switching default tracing clock to "global"
  1004. 42.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.508686] If you want to keep using the local clock, then add:
  1005. 42.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.508686] "trace_clock=local"
  1006. 42.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.508686] on the kernel command line
  1007. 42.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.519710] clk: Disabling unused clocks
  1008. 42.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.522513] PM: genpd: Disabling unused power domains
  1009. 42.61 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.526837] Freeing unused decrypted memory: 2028K
  1010. 42.61 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.530157] Freeing unused kernel image (initmem) memory: 3408K
  1011. 42.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.533710] Write protecting the kernel read-only data: 30720k
  1012. 42.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.537689] Freeing unused kernel image (rodata/data gap) memory: 1756K
  1013. 42.62 s [vm-test-run-centjes-e2e-test] client # [ 1.365556] Key type asymmetric registered
  1014. 42.63 s [vm-test-run-centjes-e2e-test] client # [ 1.374399] Asymmetric key parser 'x509' registered
  1015. 42.65 s [vm-test-run-centjes-e2e-test] client # [ 1.384729] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
  1016. 42.66 s [vm-test-run-centjes-e2e-test] client # [ 1.398469] io scheduler mq-deadline registered
  1017. 42.66 s [vm-test-run-centjes-e2e-test] client # [ 1.402035] io scheduler kyber registered
  1018. 42.67 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.588131] x86/mm: Checked W+X mappings: passed, no W+X pages found.
  1019. 42.67 s [vm-test-run-centjes-e2e-test] client # [ 1.412646] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
  1020. 42.67 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.591915] Run /init as init process
  1021. 42.69 s [vm-test-run-centjes-e2e-test] client # [ 1.425966] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
  1022. 42.69 s [vm-test-run-centjes-e2e-test] client # [ 1.434180] Freeing initrd memory: 12300K
  1023. 42.70 s [vm-test-run-centjes-e2e-test] client # [ 1.439633] Linux agpgart interface v0.103
  1024. 42.70 s [vm-test-run-centjes-e2e-test] client # [ 1.443024] ACPI: bus type drm_connector registered
  1025. 42.71 s [vm-test-run-centjes-e2e-test] client # [ 1.447476] usbcore: registered new interface driver usbserial_generic
  1026. 42.71 s [vm-test-run-centjes-e2e-test] client # [ 1.451610] usbserial: USB Serial support registered for generic
  1027. 42.72 s [vm-test-run-centjes-e2e-test] client # [ 1.455918] amd_pstate: the _CPC object is not present in SBIOS or ACPI disabled
  1028. 42.72 s [vm-test-run-centjes-e2e-test] client # [ 1.461028] drop_monitor: Initializing network drop monitor service
  1029. 42.72 s [vm-test-run-centjes-e2e-test] client # [ 1.465177] NET: Registered PF_INET6 protocol family
  1030. 42.73 s [vm-test-run-centjes-e2e-test] client # [ 1.469540] Segment Routing with IPv6
  1031. 42.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.645920] device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@lists.linux.dev
  1032. 42.73 s [vm-test-run-centjes-e2e-test] client # [ 1.472396] In-situ OAM (IOAM) with IPv6
  1033. 42.73 s [vm-test-run-centjes-e2e-test] client # [ 1.475830] IPI shorthand broadcast: enabled
  1034. 42.74 s [vm-test-run-centjes-e2e-test] client # [ 1.481708] registered taskstats version 1
  1035. 42.74 s [vm-test-run-centjes-e2e-test] client # [ 1.485115] Loading compiled-in X.509 certificates
  1036. 42.75 s [vm-test-run-centjes-e2e-test] client # [ 1.494208] Demotion targets for Node 0: null
  1037. 42.76 s [vm-test-run-centjes-e2e-test] client # [ 1.497036] Key type .fscrypt registered
  1038. 42.76 s [vm-test-run-centjes-e2e-test] client # [ 1.499539] Key type fscrypt-provisioning registered
  1039. 42.76 s [vm-test-run-centjes-e2e-test] client # [ 1.502761] PM: Magic number: 6:608:846
  1040. 42.77 s [vm-test-run-centjes-e2e-test] client # [ 1.506182] RAS: Correctable Errors collector initialized.
  1041. 42.78 s [vm-test-run-centjes-e2e-test] client # [ 1.513695] Unstable clock detected, switching default tracing clock to "global"
  1042. 42.78 s [vm-test-run-centjes-e2e-test] client # [ 1.513695] If you want to keep using the local clock, then add:
  1043. 42.78 s [vm-test-run-centjes-e2e-test] client # [ 1.513695] "trace_clock=local"
  1044. 42.78 s [vm-test-run-centjes-e2e-test] client # [ 1.513695] on the kernel command line
  1045. 42.79 s [vm-test-run-centjes-e2e-test] client # [ 1.526474] clk: Disabling unused clocks
  1046. 42.79 s [vm-test-run-centjes-e2e-test] client # [ 1.529363] PM: genpd: Disabling unused power domains
  1047. 42.79 s [vm-test-run-centjes-e2e-test] client # [ 1.533969] Freeing unused decrypted memory: 2028K
  1048. 42.80 s [vm-test-run-centjes-e2e-test] client # [ 1.537539] Freeing unused kernel image (initmem) memory: 3408K
  1049. 42.80 s [vm-test-run-centjes-e2e-test] client # [ 1.541118] Write protecting the kernel read-only data: 30720k
  1050. 42.81 s [vm-test-run-centjes-e2e-test] client # [ 1.545621] Freeing unused kernel image (rodata/data gap) memory: 1756K
  1051. 42.86 s [vm-test-run-centjes-e2e-test] client # [ 1.597543] x86/mm: Checked W+X mappings: passed, no W+X pages found.
  1052. 42.86 s [vm-test-run-centjes-e2e-test] client # [ 1.601556] Run /init as init process
  1053. 42.92 s [vm-test-run-centjes-e2e-test] client # [ 1.655398] device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@lists.linux.dev
  1054. 42.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.864795] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
  1055. 42.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.888174] uhci_hcd 0000:00:01.2: UHCI Host Controller
  1056. 42.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.892052] SCSI subsystem initialized
  1057. 42.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.906543] serio: i8042 KBD port at 0x60,0x64 irq 1
  1058. 42.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.910082] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
  1059. 43.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.917232] ACPI: \_SB_.LNKC: Enabled at IRQ 10
  1060. 43.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.927566] uhci_hcd 0000:00:01.2: detected 2 ports
  1061. 43.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.931034] serio: i8042 AUX port at 0x60,0x64 irq 12
  1062. 43.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.946620] uhci_hcd 0000:00:01.2: irq 11, io port 0x0000c100
  1063. 43.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.959729] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 6.12
  1064. 43.05 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.965560] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
  1065. 43.05 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.970497] usb usb1: Product: UHCI Host Controller
  1066. 43.06 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.974052] usb usb1: Manufacturer: Linux 6.12.62 uhci_hcd
  1067. 43.06 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.977994] usb usb1: SerialNumber: 0000:00:01.2
  1068. 43.07 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.988652] ACPI: \_SB_.LNKA: Enabled at IRQ 10
  1069. 43.08 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.995306] scsi host0: ata_piix
  1070. 43.08 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.002524] scsi host1: ata_piix
  1071. 43.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.008707] ACPI: \_SB_.LNKB: Enabled at IRQ 11
  1072. 43.10 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.011746] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc1e0 irq 14 lpm-pol 0
  1073. 43.10 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.016565] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc1e8 irq 15 lpm-pol 0
  1074. 43.11 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.024650] hub 1-0:1.0: USB hub found
  1075. 43.11 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.030693] hub 1-0:1.0: 2 ports detected
  1076. 43.15 s [vm-test-run-centjes-e2e-test] client # [ 1.894146] ACPI: \_SB_.LNKC: Enabled at IRQ 10
  1077. 43.16 s [vm-test-run-centjes-e2e-test] client # [ 1.897658] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
  1078. 43.19 s [vm-test-run-centjes-e2e-test] client # [ 1.928846] SCSI subsystem initialized
  1079. 43.20 s [vm-test-run-centjes-e2e-test] client # [ 1.938139] uhci_hcd 0000:00:01.2: UHCI Host Controller
  1080. 43.21 s [vm-test-run-centjes-e2e-test] client # [ 1.950944] serio: i8042 KBD port at 0x60,0x64 irq 1
  1081. 43.22 s [vm-test-run-centjes-e2e-test] client # [ 1.960423] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
  1082. 43.22 s [vm-test-run-centjes-e2e-test] client # [ 1.965087] serio: i8042 AUX port at 0x60,0x64 irq 12
  1083. 43.24 s [vm-test-run-centjes-e2e-test] client # [ 1.979243] ACPI: \_SB_.LNKA: Enabled at IRQ 10
  1084. 43.25 s [vm-test-run-centjes-e2e-test] client # [ 1.987916] uhci_hcd 0000:00:01.2: detected 2 ports
  1085. 43.25 s [vm-test-run-centjes-e2e-test] client # [ 1.994668] uhci_hcd 0000:00:01.2: irq 11, io port 0x0000c100
  1086. 43.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.181954] ata2: found unknown device (class 0)
  1087. 43.27 s [vm-test-run-centjes-e2e-test] client # [ 2.007507] ACPI: \_SB_.LNKB: Enabled at IRQ 11
  1088. 43.27 s [vm-test-run-centjes-e2e-test] client # [ 2.010573] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 6.12
  1089. 43.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.187815] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100
  1090. 43.28 s [vm-test-run-centjes-e2e-test] client # [ 2.015619] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
  1091. 43.28 s [vm-test-run-centjes-e2e-test] client # [ 2.019859] usb usb1: Product: UHCI Host Controller
  1092. 43.28 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.196055] scsi 1:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5
  1093. 43.28 s [vm-test-run-centjes-e2e-test] client # [ 2.022804] usb usb1: Manufacturer: Linux 6.12.62 uhci_hcd
  1094. 43.28 s [vm-test-run-centjes-e2e-test] client # [ 2.026048] usb usb1: SerialNumber: 0000:00:01.2
  1095. 43.29 s [vm-test-run-centjes-e2e-test] client # [ 2.031401] scsi host0: ata_piix
  1096. 43.29 s [vm-test-run-centjes-e2e-test] client # [ 2.035624] scsi host1: ata_piix
  1097. 43.31 s [vm-test-run-centjes-e2e-test] client # [ 2.044902] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc1e0 irq 14 lpm-pol 0
  1098. 43.31 s [vm-test-run-centjes-e2e-test] client # [ 2.049357] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc1e8 irq 15 lpm-pol 0
  1099. 43.32 s [vm-test-run-centjes-e2e-test] client # [ 2.061155] hub 1-0:1.0: USB hub found
  1100. 43.33 s [vm-test-run-centjes-e2e-test] client # [ 2.069707] hub 1-0:1.0: 2 ports detected
  1101. 43.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.260662] usb 1-1: new full-speed USB device number 2 using uhci_hcd
  1102. 43.42 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.331637] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
  1103. 43.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.373921] virtio_blk virtio5: 1/0/0 default/read/poll queues
  1104. 43.47 s [vm-test-run-centjes-e2e-test] client # [ 2.207770] ata2: found unknown device (class 0)
  1105. 43.47 s [vm-test-run-centjes-e2e-test] client # [ 2.213248] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100
  1106. 43.48 s [vm-test-run-centjes-e2e-test] client # [ 2.221142] scsi 1:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5
  1107. 43.50 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.413014] virtio_blk virtio5: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)
  1108. 43.50 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.422251] netfs: FS-Cache loaded
  1109. 43.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.436128] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray
  1110. 43.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.440508] cdrom: Uniform CD-ROM driver Revision: 3.20
  1111. 43.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.452506] usb 1-1: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00
  1112. 43.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.457466] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=10
  1113. 43.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.461809] usb 1-1: Product: QEMU USB Tablet
  1114. 43.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.464608] usb 1-1: Manufacturer: QEMU
  1115. 43.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.468339] usb 1-1: SerialNumber: 28754-0000:00:01.2-1
  1116. 43.55 s [vm-test-run-centjes-e2e-test] client # [ 2.294451] usb 1-1: new full-speed USB device number 2 using uhci_hcd
  1117. 43.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.472252] 9pnet: Installing 9P2000 support
  1118. 43.61 s [vm-test-run-centjes-e2e-test] client # [ 2.347560] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
  1119. 43.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.522690] hid: raw HID events driver (C) Jiri Kosina
  1120. 43.63 s [vm-test-run-centjes-e2e-test] client # [ 2.371684] virtio_blk virtio5: 1/0/0 default/read/poll queues
  1121. 43.63 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.549534] usbcore: registered new interface driver usbhid
  1122. 43.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.553019] usbhid: USB HID core driver
  1123. 43.65 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.559919] 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
  1124. 43.66 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.574815] 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
  1125. 43.66 s [vm-test-run-centjes-e2e-test] client # [ 2.405893] netfs: FS-Cache loaded
  1126. 43.67 s [vm-test-run-centjes-e2e-test] client # [ 2.408986] virtio_blk virtio5: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)
  1127. 43.71 s [vm-test-run-centjes-e2e-test] client # [ 2.452090] 9pnet: Installing 9P2000 support
  1128. 43.72 s [vm-test-run-centjes-e2e-test] client # [ 2.461903] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray
  1129. 43.73 s [vm-test-run-centjes-e2e-test] client # [ 2.467020] cdrom: Uniform CD-ROM driver Revision: 3.20
  1130. 43.73 s [vm-test-run-centjes-e2e-test] client # [ 2.471527] usb 1-1: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00
  1131. 43.74 s [vm-test-run-centjes-e2e-test] client # [ 2.478056] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=10
  1132. 43.74 s [vm-test-run-centjes-e2e-test] client # [ 2.483803] usb 1-1: Product: QEMU USB Tablet
  1133. 43.75 s [vm-test-run-centjes-e2e-test] client # [ 2.487490] usb 1-1: Manufacturer: QEMU
  1134. 43.75 s [vm-test-run-centjes-e2e-test] client # [ 2.490874] usb 1-1: SerialNumber: 28754-0000:00:01.2-1
  1135. 43.82 s [vm-test-run-centjes-e2e-test] client # [ 2.546152] hid: raw HID events driver (C) Jiri Kosina
  1136. 43.84 s [vm-test-run-centjes-e2e-test] client # [ 2.577906] usbcore: registered new interface driver usbhid
  1137. 43.84 s [vm-test-run-centjes-e2e-test] client # [ 2.581168] usbhid: USB HID core driver
  1138. 43.85 s [vm-test-run-centjes-e2e-test] client # [ 2.585953] 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
  1139. 43.86 s [vm-test-run-centjes-e2e-test] client # [ 2.600708] 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
  1140. 44.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 3.099224] EXT4-fs (vda): mounted filesystem 069dba71-c190-4124-a059-4338a1e8327d r/w with ordered data mode. Quota mode: none.
  1141. 44.20 s [vm-test-run-centjes-e2e-test] client # [ 2.935661] EXT4-fs (vda): mounted filesystem 2bf68771-21da-49aa-8efa-0256cf5823b1 r/w with ordered data mode. Quota mode: none.
  1142. 44.21 s [vm-test-run-centjes-e2e-test] docsserver # [ 3.126738] 9p: Installing v9fs 9p2000 file system support
  1143. 44.23 s [vm-test-run-centjes-e2e-test] client # [ 2.967213] 9p: Installing v9fs 9p2000 file system support
  1144. 44.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 3.460520] EXT4-fs (vda): re-mounted 069dba71-c190-4124-a059-4338a1e8327d.
  1145. 44.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 3.466615] booting system configuration /nix/store/aycj65q2vjaiwwbk57wba4kaxs7226vn-nixos-system-docsserver-test
  1146. 44.56 s [vm-test-run-centjes-e2e-test] client # [ 3.302575] EXT4-fs (vda): re-mounted 2bf68771-21da-49aa-8efa-0256cf5823b1.
  1147. 44.57 s [vm-test-run-centjes-e2e-test] client # [ 3.310179] booting system configuration /nix/store/001k9r4jinw78ih5x5hxggb82ynlbkqn-nixos-system-client-test
  1148. 46.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.777190] systemd[1]: Inserted module 'autofs4'
  1149. 46.87 s [vm-test-run-centjes-e2e-test] client # [ 5.608614] systemd[1]: Inserted module 'autofs4'
  1150. 46.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.842937] 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)
  1151. 46.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.861681] systemd[1]: Detected virtualization kvm.
  1152. 46.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.865335] systemd[1]: Detected architecture x86-64.
  1153. 46.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.869058] systemd[1]: Detected first boot.
  1154. 46.97 s [vm-test-run-centjes-e2e-test] client # [ 5.680435] 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)
  1155. 46.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.876894] systemd[1]: Initializing machine ID from random generator.
  1156. 46.97 s [vm-test-run-centjes-e2e-test] client # [ 5.703492] systemd[1]: Detected virtualization kvm.
  1157. 46.97 s [vm-test-run-centjes-e2e-test] client # [ 5.707516] systemd[1]: Detected architecture x86-64.
  1158. 46.97 s [vm-test-run-centjes-e2e-test] client # [ 5.711484] systemd[1]: Detected first boot.
  1159. 46.98 s [vm-test-run-centjes-e2e-test] client # [ 5.722156] systemd[1]: Initializing machine ID from random generator.
  1160. 46.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.905212] systemd[1]: Hostname set to <docsserver>.
  1161. 47.00 s [vm-test-run-centjes-e2e-test] client # [ 5.744502] systemd[1]: Hostname set to <client>.
  1162. 47.13 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.051626] systemd[1]: bpf-restrict-fs: LSM BPF program attached
  1163. 47.15 s [vm-test-run-centjes-e2e-test] client # [ 5.885804] systemd[1]: bpf-restrict-fs: LSM BPF program attached
  1164. 47.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.259921] systemd[1]: Applying preset policy.
  1165. 47.34 s [vm-test-run-centjes-e2e-test] client # [ 6.086368] systemd[1]: Applying preset policy.
  1166. 48.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.086300] systemd[1]: Populated /etc with preset unit settings.
  1167. 48.18 s [vm-test-run-centjes-e2e-test] client # [ 6.919362] systemd[1]: Populated /etc with preset unit settings.
  1168. 48.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.673588] systemd[1]: /etc/systemd/system/centjes-docs-site-production.service:3: Invalid URL, ignoring: /nix/store/pfg8hayvf5qq1axqbh3zkfrk33031syf-settings-check
  1169. 48.87 s [vm-test-run-centjes-e2e-test] client # [ 7.612089] systemd[1]: Queued start job for default target Multi-User System.
  1170. 48.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.825265] systemd[1]: Queued start job for default target Multi-User System.
  1171. 48.92 s [vm-test-run-centjes-e2e-test] client # [ 7.659746] systemd[1]: Created slice Slice /system/getty.
  1172. 48.92 s [vm-test-run-centjes-e2e-test] client # [ 7.664226] systemd[1]: Created slice Slice /system/modprobe.
  1173. 48.93 s [vm-test-run-centjes-e2e-test] client # [ 7.668467] systemd[1]: Created slice User and Session Slice.
  1174. 48.93 s [vm-test-run-centjes-e2e-test] client # [ 7.672535] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
  1175. 48.94 s [vm-test-run-centjes-e2e-test] client # [ 7.676871] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
  1176. 48.94 s [vm-test-run-centjes-e2e-test] client # [ 7.680869] systemd[1]: Expecting device /dev/hvc0...
  1177. 48.94 s [vm-test-run-centjes-e2e-test] client # [ 7.683666] systemd[1]: Expecting device /dev/ttyS0...
  1178. 48.95 s [vm-test-run-centjes-e2e-test] client # [ 7.686961] systemd[1]: Expecting device /sys/subsystem/net/devices/eth1...
  1179. 48.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.866035] systemd[1]: Created slice Slice /system/getty.
  1180. 48.95 s [vm-test-run-centjes-e2e-test] client # [ 7.691423] systemd[1]: Reached target Local Encrypted Volumes.
  1181. 48.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.870597] systemd[1]: Created slice Slice /system/modprobe.
  1182. 48.96 s [vm-test-run-centjes-e2e-test] client # [ 7.695190] systemd[1]: Reached target Virtual Machines and Containers.
  1183. 48.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.875065] systemd[1]: Created slice User and Session Slice.
  1184. 48.96 s [vm-test-run-centjes-e2e-test] client # [ 7.699527] systemd[1]: Reached target Path Units.
  1185. 48.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.879253] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
  1186. 48.96 s [vm-test-run-centjes-e2e-test] client # [ 7.702940] systemd[1]: Reached target Remote File Systems.
  1187. 48.97 s [vm-test-run-centjes-e2e-test] client # [ 7.706601] systemd[1]: Reached target Slice Units.
  1188. 48.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.883089] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
  1189. 48.97 s [vm-test-run-centjes-e2e-test] client # [ 7.709768] systemd[1]: Reached target Swaps.
  1190. 48.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.887631] systemd[1]: Expecting device /dev/hvc0...
  1191. 48.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.890301] systemd[1]: Expecting device /dev/ttyS0...
  1192. 48.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.893312] systemd[1]: Expecting device /sys/subsystem/net/devices/eth1...
  1193. 48.98 s [vm-test-run-centjes-e2e-test] client # [ 7.719030] systemd[1]: Listening on Process Core Dump Socket.
  1194. 48.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.896939] systemd[1]: Reached target Local Encrypted Volumes.
  1195. 48.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.900612] systemd[1]: Reached target Virtual Machines and Containers.
  1196. 48.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.903852] systemd[1]: Reached target Path Units.
  1197. 48.99 s [vm-test-run-centjes-e2e-test] client # [ 7.726634] systemd[1]: Listening on Credential Encryption/Decryption.
  1198. 48.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.906631] systemd[1]: Reached target Remote File Systems.
  1199. 48.99 s [vm-test-run-centjes-e2e-test] client # [ 7.731510] systemd[1]: Listening on Journal Audit Socket.
  1200. 48.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.909930] systemd[1]: Reached target Slice Units.
  1201. 48.99 s [vm-test-run-centjes-e2e-test] client # [ 7.735113] systemd[1]: Listening on Journal Socket (/dev/log).
  1202. 48.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.912621] systemd[1]: Reached target Swaps.
  1203. 49.00 s [vm-test-run-centjes-e2e-test] client # [ 7.738746] systemd[1]: Listening on Journal Sockets.
  1204. 49.00 s [vm-test-run-centjes-e2e-test] client # [ 7.742488] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.
  1205. 49.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.921112] systemd[1]: Listening on Process Core Dump Socket.
  1206. 49.01 s [vm-test-run-centjes-e2e-test] client # [ 7.746519] systemd[1]: Make TPM PCR Policy was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1207. 49.01 s [vm-test-run-centjes-e2e-test] client # [ 7.751751] systemd[1]: Listening on udev Control Socket.
  1208. 49.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.928327] systemd[1]: Listening on Credential Encryption/Decryption.
  1209. 49.01 s [vm-test-run-centjes-e2e-test] client # [ 7.754854] systemd[1]: Listening on udev Kernel Socket.
  1210. 49.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.932827] systemd[1]: Listening on Journal Audit Socket.
  1211. 49.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.936534] systemd[1]: Listening on Journal Socket (/dev/log).
  1212. 49.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.939991] systemd[1]: Listening on Journal Sockets.
  1213. 49.02 s [vm-test-run-centjes-e2e-test] client # [ 7.764551] systemd[1]: Mounting Huge Pages File System...
  1214. 49.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.943325] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.
  1215. 49.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.946907] systemd[1]: Make TPM PCR Policy was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1216. 49.03 s [vm-test-run-centjes-e2e-test] client # [ 7.773626] systemd[1]: Mounting POSIX Message Queue File System...
  1217. 49.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.952621] systemd[1]: Listening on udev Control Socket.
  1218. 49.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.955727] systemd[1]: Listening on udev Kernel Socket.
  1219. 49.05 s [vm-test-run-centjes-e2e-test] client # [ 7.786408] systemd[1]: Mounting Kernel Debug File System...
  1220. 49.05 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.963616] systemd[1]: Mounting Huge Pages File System...
  1221. 49.05 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.971651] systemd[1]: Mounting POSIX Message Queue File System...
  1222. 49.06 s [vm-test-run-centjes-e2e-test] client # [ 7.801813] systemd[1]: Mounting Kernel Trace File System...
  1223. 49.06 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.980768] systemd[1]: Mounting Kernel Debug File System...
  1224. 49.08 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.998616] systemd[1]: Mounting Kernel Trace File System...
  1225. 49.08 s [vm-test-run-centjes-e2e-test] client # [ 7.821693] systemd[1]: Starting Create List of Static Device Nodes...
  1226. 49.09 s [vm-test-run-centjes-e2e-test] client # [ 7.827573] systemd[1]: Load Kernel Module 9pnet_virtio was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!9pnet_virtio).
  1227. 49.10 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.012931] systemd[1]: Starting Create List of Static Device Nodes...
  1228. 49.10 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.018817] systemd[1]: Load Kernel Module 9pnet_virtio was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!9pnet_virtio).
  1229. 49.11 s [vm-test-run-centjes-e2e-test] client # [ 7.856205] systemd[1]: Starting Load Kernel Module configfs...
  1230. 49.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.035633] systemd[1]: Starting Load Kernel Module configfs...
  1231. 49.12 s [vm-test-run-centjes-e2e-test] client # [ 7.860916] systemd[1]: Load Kernel Module drm was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!drm).
  1232. 49.13 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.042152] systemd[1]: Load Kernel Module drm was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!drm).
  1233. 49.13 s [vm-test-run-centjes-e2e-test] client # [ 7.872554] systemd[1]: Starting Load Kernel Module efi_pstore...
  1234. 49.14 s [vm-test-run-centjes-e2e-test] client # [ 7.883038] systemd[1]: Starting Load Kernel Module fuse...
  1235. 49.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.061865] systemd[1]: Starting Load Kernel Module efi_pstore...
  1236. 49.15 s [vm-test-run-centjes-e2e-test] client # [ 7.888892] systemd[1]: File System Check on Root Device was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/).
  1237. 49.15 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.072734] systemd[1]: Starting Load Kernel Module fuse...
  1238. 49.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.078309] systemd[1]: File System Check on Root Device was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/).
  1239. 49.17 s [vm-test-run-centjes-e2e-test] client # [ 7.901559] 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).
  1240. 49.18 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.087795] 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).
  1241. 49.18 s [vm-test-run-centjes-e2e-test] client # [ 7.924993] systemd[1]: Starting Journal Service...
  1242. 49.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.110658] systemd[1]: Starting Journal Service...
  1243. 49.20 s [vm-test-run-centjes-e2e-test] client # [ 7.936845] systemd[1]: Starting Load Kernel Modules...
  1244. 49.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.121571] systemd[1]: Starting Load Kernel Modules...
  1245. 49.21 s [vm-test-run-centjes-e2e-test] client # [ 7.950510] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...
  1246. 49.21 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.132043] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...
  1247. 49.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.144599] systemd[1]: Starting Remount Root and Kernel File Systems...
  1248. 49.23 s [vm-test-run-centjes-e2e-test] client # [ 7.968062] systemd[1]: Starting Remount Root and Kernel File Systems...
  1249. 49.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.151487] systemd[1]: Early TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1250. 49.24 s [vm-test-run-centjes-e2e-test] client # [ 7.975501] systemd[1]: Early TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1251. 49.25 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.166964] systemd[1]: Starting Coldplug All udev Devices...
  1252. 49.25 s [vm-test-run-centjes-e2e-test] client # [ 7.993501] systemd[1]: Starting Coldplug All udev Devices...
  1253. 49.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.181730] systemd[1]: Mounted Huge Pages File System.
  1254. 49.27 s [vm-test-run-centjes-e2e-test] client # [ 8.010054] systemd[1]: Mounted Huge Pages File System.
  1255. 49.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.188112] systemd[1]: Mounted POSIX Message Queue File System.
  1256. 49.28 s [vm-test-run-centjes-e2e-test] client # [ 8.017190] systemd[1]: Mounted POSIX Message Queue File System.
  1257. 49.28 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.194810] systemd[1]: Mounted Kernel Debug File System.
  1258. 49.28 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.200461] systemd[1]: Mounted Kernel Trace File System.
  1259. 49.28 s [vm-test-run-centjes-e2e-test] client # [ 8.023870] systemd[1]: Mounted Kernel Debug File System.
  1260. 49.29 s [vm-test-run-centjes-e2e-test] client # [ 8.030724] systemd[1]: Mounted Kernel Trace File System.
  1261. 49.30 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.213618] systemd[1]: Finished Create List of Static Device Nodes.
  1262. 49.30 s [vm-test-run-centjes-e2e-test] client # [ 8.041982] systemd[1]: Finished Create List of Static Device Nodes.
  1263. 49.30 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.221002] systemd[1]: modprobe@efi_pstore.service: Deactivated successfully.
  1264. 49.31 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.230083] systemd[1]: Finished Load Kernel Module efi_pstore.
  1265. 49.32 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.237603] systemd[1]: modprobe@configfs.service: Deactivated successfully.
  1266. 49.32 s [vm-test-run-centjes-e2e-test] client # [ 8.060694] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...
  1267. 49.33 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.247105] systemd[1]: Finished Load Kernel Module configfs.
  1268. 49.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.261699] systemd[1]: Mounting Kernel Configuration File System...
  1269. 49.36 s [vm-test-run-centjes-e2e-test] client # [ 8.096049] systemd[1]: modprobe@configfs.service: Deactivated successfully.
  1270. 49.36 s [vm-test-run-centjes-e2e-test] client # [ 8.105576] systemd[1]: Finished Load Kernel Module configfs.
  1271. 49.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.281233] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...
  1272. 49.38 s [vm-test-run-centjes-e2e-test] client # [ 8.118048] systemd[1]: Mounting Kernel Configuration File System...
  1273. 49.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.306330] systemd[1]: Mounted Kernel Configuration File System.
  1274. 49.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.324033] fuse: init (API version 7.41)
  1275. 49.41 s [vm-test-run-centjes-e2e-test] client # [ 8.152455] systemd[1]: Mounted Kernel Configuration File System.
  1276. 49.42 s [vm-test-run-centjes-e2e-test] client # [ 8.160647] systemd[1]: modprobe@efi_pstore.service: Deactivated successfully.
  1277. 49.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.342674] EXT4-fs (vda): re-mounted 069dba71-c190-4124-a059-4338a1e8327d.
  1278. 49.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.347066] loop: module loaded
  1279. 49.43 s [vm-test-run-centjes-e2e-test] client # [ 8.172508] systemd[1]: Finished Load Kernel Module efi_pstore.
  1280. 49.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.353068] systemd[1]: modprobe@fuse.service: Deactivated successfully.
  1281. 49.45 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.363060] systemd[1]: Finished Load Kernel Module fuse.
  1282. 49.46 s [vm-test-run-centjes-e2e-test] client # [ 8.196551] EXT4-fs (vda): re-mounted 2bf68771-21da-49aa-8efa-0256cf5823b1.
  1283. 49.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.375675] systemd[1]: Mounting FUSE Control File System...
  1284. 49.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.378328] systemd-journald[384]: Collecting audit messages is enabled.
  1285. 49.47 s [vm-test-run-centjes-e2e-test] client # [ 8.211219] fuse: init (API version 7.41)
  1286. 49.47 s [vm-test-run-centjes-e2e-test] client # [ 8.214546] loop: module loaded
  1287. 49.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.392054] systemd[1]: Finished Load Kernel Modules.
  1288. 49.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.402874] systemd[1]: Finished Remount Root and Kernel File Systems.
  1289. 49.49 s [vm-test-run-centjes-e2e-test] client # [ 8.234902] systemd[1]: Finished Remount Root and Kernel File Systems.
  1290. 49.50 s [vm-test-run-centjes-e2e-test] client # [ 8.240078] systemd-journald[381]: Collecting audit messages is enabled.
  1291. 49.50 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.421210] systemd[1]: Starting Firewall...
  1292. 49.51 s [vm-test-run-centjes-e2e-test] client # [ 8.246107] systemd[1]: modprobe@fuse.service: Deactivated successfully.
  1293. 49.51 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.426662] systemd[1]: Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore).
  1294. 49.51 s [vm-test-run-centjes-e2e-test] client # [ 8.254609] systemd[1]: Finished Load Kernel Module fuse.
  1295. 49.52 s [vm-test-run-centjes-e2e-test] client # [ 8.265176] systemd[1]: Finished Load Kernel Modules.
  1296. 49.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.449814] systemd[1]: Starting Load/Save OS Random Seed...
  1297. 49.54 s [vm-test-run-centjes-e2e-test] client # [ 8.279234] systemd[1]: Mounting FUSE Control File System...
  1298. 49.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.464313] systemd[1]: Starting Apply Kernel Variables...
  1299. 49.55 s [vm-test-run-centjes-e2e-test] client # [ 8.293906] systemd[1]: Starting Firewall...
  1300. 49.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.470847] systemd[1]: TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1301. 49.56 s [vm-test-run-centjes-e2e-test] client # [ 8.300440] systemd[1]: Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore).
  1302. 49.57 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.487888] systemd[1]: Mounted FUSE Control File System.
  1303. 49.59 s [vm-test-run-centjes-e2e-test] client # [ 8.327197] systemd[1]: Starting Load/Save OS Random Seed...
  1304. 49.60 s [vm-test-run-centjes-e2e-test] client # [ 8.341254] systemd[1]: Starting Apply Kernel Variables...
  1305. 49.61 s [vm-test-run-centjes-e2e-test] client # [ 8.346920] systemd[1]: TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1306. 49.62 s [vm-test-run-centjes-e2e-test] client # [ 8.359701] systemd[1]: Mounted FUSE Control File System.
  1307. 49.68 s [vm-test-run-centjes-e2e-test] client # [ 8.416549] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
  1308. 49.69 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.608656] systemd[1]: Finished Load/Save OS Random Seed.
  1309. 49.69 s [vm-test-run-centjes-e2e-test] client # [ 8.434512] systemd[1]: Starting Create Static Device Nodes in /dev...
  1310. 49.70 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.616929] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.
  1311. 49.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.628727] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
  1312. 49.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.643192] systemd[1]: Reached target First Boot Complete.
  1313. 49.73 s [vm-test-run-centjes-e2e-test] client # [ 8.473016] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.
  1314. 49.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.658178] systemd[1]: Starting Create Static Device Nodes in /dev...
  1315. 49.75 s [vm-test-run-centjes-e2e-test] client # [ 8.492938] systemd[1]: Finished Load/Save OS Random Seed.
  1316. 49.76 s [vm-test-run-centjes-e2e-test] client # [ 8.501127] systemd[1]: Reached target First Boot Complete.
  1317. 49.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.684116] systemd[1]: Finished Apply Kernel Variables.
  1318. 49.80 s [vm-test-run-centjes-e2e-test] client # [ 8.543127] systemd[1]: Finished Apply Kernel Variables.
  1319. 49.91 s [vm-test-run-centjes-e2e-test] client # [ 8.647561] systemd[1]: Finished Create Static Device Nodes in /dev.
  1320. 49.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.827647] systemd[1]: Finished Create Static Device Nodes in /dev.
  1321. 49.92 s [vm-test-run-centjes-e2e-test] client # [ 8.655827] systemd[1]: Reached target Preparation for Local File Systems.
  1322. 49.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.835040] systemd[1]: Reached target Preparation for Local File Systems.
  1323. 49.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.849614] systemd[1]: Starting Rule-based Manager for Device Events and Files...
  1324. 49.93 s [vm-test-run-centjes-e2e-test] client # [ 8.672474] systemd[1]: Starting Rule-based Manager for Device Events and Files...
  1325. 50.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.081796] systemd[1]: Started Journal Service.
  1326. 50.18 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.575805] systemd-modules-load[385]: Inserted module 'loop'
  1327. 50.19 s [vm-test-run-centjes-e2e-test] client # [ 8.929187] systemd[1]: Started Journal Service.
  1328. 50.20 s [vm-test-run-centjes-e2e-test] client # [ 8.381582] systemd-modules-load[382]: Inserted module 'loop'
  1329. 50.21 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.596412] systemd-oomd[386]: [0;1;38:5:185mNo swap; memory pressure usage will be degraded
  1330. 50.22 s [vm-test-run-centjes-e2e-test] client # [ 8.395534] systemd-oomd[383]: [0;1;38:5:185mNo swap; memory pressure usage will be degraded
  1331. 50.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.621461] systemd-udevd[414]: Using default interface naming scheme 'v258'.
  1332. 50.23 s [vm-test-run-centjes-e2e-test] client # [ 8.416461] systemd-udevd[406]: Using default interface naming scheme 'v258'.
  1333. 50.25 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.640175] systemd[1]: Starting Flush Journal to Persistent Storage...
  1334. 50.25 s [vm-test-run-centjes-e2e-test] client # [ 8.432216] systemd[1]: Starting Flush Journal to Persistent Storage...
  1335. 50.28 s [vm-test-run-centjes-e2e-test] client # [ 8.466311] systemd[1]: Mounting /run/wrappers...
  1336. 50.29 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.679697] systemd[1]: Mounting /run/wrappers...
  1337. 50.32 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.234205] systemd-journald[384]: Received client request to flush runtime journal.
  1338. 50.32 s [vm-test-run-centjes-e2e-test] client # [ 9.061888] systemd-journald[381]: Received client request to flush runtime journal.
  1339. 50.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.121374] systemd[1]: Mounted /run/wrappers.
  1340. 50.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.135962] systemd[1]: Reached target Local File Systems.
  1341. 50.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.152406] systemd[1]: Listening on Boot Entries Service Socket.
  1342. 50.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.164611] systemd[1]: Starting Create SUID/SGID Wrappers...
  1343. 50.79 s [vm-test-run-centjes-e2e-test] client # [ 8.970863] systemd[1]: Mounted /run/wrappers.
  1344. 50.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.182764] systemd[1]: Update Boot Loader Random Seed was skipped because no trigger condition checks were met.
  1345. 50.81 s [vm-test-run-centjes-e2e-test] client # [ 8.991701] systemd[1]: Reached target Local File Systems.
  1346. 50.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.207936] systemd[1]: Starting Save Transient machine-id to Disk...
  1347. 50.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.226782] systemd[1]: Finished Coldplug All udev Devices.
  1348. 50.83 s [vm-test-run-centjes-e2e-test] client # [ 9.013340] systemd[1]: Listening on Boot Entries Service Socket.
  1349. 50.85 s [vm-test-run-centjes-e2e-test] client # [ 9.026838] systemd[1]: Starting Create SUID/SGID Wrappers...
  1350. 50.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.245360] systemd[1]: Started Rule-based Manager for Device Events and Files.
  1351. 50.87 s [vm-test-run-centjes-e2e-test] client # [ 9.046516] systemd[1]: Update Boot Loader Random Seed was skipped because no trigger condition checks were met.
  1352. 50.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.266289] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
  1353. 50.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.281645] systemd[1]: Finished Save Transient machine-id to Disk.
  1354. 50.89 s [vm-test-run-centjes-e2e-test] client # [ 9.068342] systemd[1]: Starting Save Transient machine-id to Disk...
  1355. 50.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.298521] systemd[1]: Finished Flush Journal to Persistent Storage.
  1356. 50.91 s [vm-test-run-centjes-e2e-test] client # [ 9.084585] systemd[1]: Started Rule-based Manager for Device Events and Files.
  1357. 50.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.312391] systemd[1]: Starting Create System Files and Directories...
  1358. 50.92 s [vm-test-run-centjes-e2e-test] client # [ 9.105235] systemd[1]: Finished Coldplug All udev Devices.
  1359. 50.94 s [vm-test-run-centjes-e2e-test] client # [ 9.117321] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
  1360. 50.95 s [vm-test-run-centjes-e2e-test] client # [ 9.136193] systemd[1]: Finished Save Transient machine-id to Disk.
  1361. 50.97 s [vm-test-run-centjes-e2e-test] client # [ 9.148562] systemd[1]: Finished Flush Journal to Persistent Storage.
  1362. 50.99 s [vm-test-run-centjes-e2e-test] client # [ 9.163764] systemd[1]: Starting Create System Files and Directories...
  1363. 51.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.386359] systemd[1]: Finished Create System Files and Directories.
  1364. 51.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.404533] systemd[1]: Starting Rebuild Journal Catalog...
  1365. 51.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.422609] systemd[1]: Starting Record System Boot/Shutdown in UTMP...
  1366. 51.06 s [vm-test-run-centjes-e2e-test] client # [ 9.242735] systemd[1]: Finished Create System Files and Directories.
  1367. 51.08 s [vm-test-run-centjes-e2e-test] client # [ 9.261509] systemd[1]: Starting Rebuild Journal Catalog...
  1368. 51.09 s [vm-test-run-centjes-e2e-test] client # [ 9.276350] systemd[1]: Starting Record System Boot/Shutdown in UTMP...
  1369. 51.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.546753] systemd[1]: Finished Record System Boot/Shutdown in UTMP.
  1370. 51.21 s [vm-test-run-centjes-e2e-test] client # [ 9.391643] systemd[1]: Finished Record System Boot/Shutdown in UTMP.
  1371. 51.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.654680] systemd[1]: Finished Rebuild Journal Catalog.
  1372. 51.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.664794] systemd[1]: Starting Update is Completed...
  1373. 51.33 s [vm-test-run-centjes-e2e-test] client # [ 9.503808] systemd[1]: Finished Rebuild Journal Catalog.
  1374. 51.34 s [vm-test-run-centjes-e2e-test] client # [ 9.521677] systemd[1]: Starting Update is Completed...
  1375. 51.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.780643] systemd[1]: Finished Update is Completed.
  1376. 51.41 s [vm-test-run-centjes-e2e-test] client # [ 9.598880] systemd[1]: Finished Update is Completed.
  1377. 51.63 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.031852] systemd[1]: Found device /dev/hvc0.
  1378. 51.68 s [vm-test-run-centjes-e2e-test] client # [ 9.867506] systemd[1]: Found device /dev/hvc0.
  1379. 51.73 s [vm-test-run-centjes-e2e-test] client # [ 9.908744] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.
  1380. 51.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.129928] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.
  1381. 51.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.142305] systemd[1]: Finished Create SUID/SGID Wrappers.
  1382. 51.75 s [vm-test-run-centjes-e2e-test] client # [ 9.926319] systemd[1]: Finished Create SUID/SGID Wrappers.
  1383. 51.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.148514] systemd[1]: Reached target System Initialization.
  1384. 51.76 s [vm-test-run-centjes-e2e-test] client # [ 9.938598] systemd[1]: Reached target System Initialization.
  1385. 51.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.158475] systemd[1]: Started Discard unused filesystem blocks once a week.
  1386. 51.80 s [vm-test-run-centjes-e2e-test] client # [ 9.956558] systemd[1]: Started Discard unused filesystem blocks once a week.
  1387. 51.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.177604] systemd[1]: Started Daily Cleanup of Temporary Directories.
  1388. 51.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.211760] systemd[1]: Reached target Timer Units.
  1389. 51.84 s [vm-test-run-centjes-e2e-test] client # [ 9.992153] systemd[1]: Started Daily Cleanup of Temporary Directories.
  1390. 51.85 s [vm-test-run-centjes-e2e-test] client # [ 10.029268] systemd[1]: Reached target Timer Units.
  1391. 51.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.247454] systemd[1]: Listening on D-Bus System Message Bus Socket.
  1392. 51.94 s [vm-test-run-centjes-e2e-test] client # [ 10.045939] systemd[1]: Listening on D-Bus System Message Bus Socket.
  1393. 51.94 s [vm-test-run-centjes-e2e-test] client # [ 10.077158] systemd[1]: Listening on Nix Daemon Socket.
  1394. 51.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.285472] systemd[1]: Listening on Nix Daemon Socket.
  1395. 51.94 s [vm-test-run-centjes-e2e-test] client # [ 10.096804] systemd[1]: Listening on Hostname Service Socket.
  1396. 51.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.325842] systemd[1]: Listening on Hostname Service Socket.
  1397. 51.96 s [vm-test-run-centjes-e2e-test] client # [ 10.135878] systemd[1]: Reached target Socket Units.
  1398. 51.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.367570] systemd[1]: Reached target Socket Units.
  1399. 51.98 s [vm-test-run-centjes-e2e-test] client # [ 10.156826] systemd[1]: Reached target Basic System.
  1400. 52.01 s [vm-test-run-centjes-e2e-test] client # [ 10.185429] systemd[1]: Starting Import lastlog data into lastlog2 database...
  1401. 52.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.398847] systemd[1]: Reached target Basic System.
  1402. 52.04 s [vm-test-run-centjes-e2e-test] client # [ 10.213154] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
  1403. 52.06 s [vm-test-run-centjes-e2e-test] client # [ 10.235933] systemd[1]: Started Reset console on configuration changes.
  1404. 52.06 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.430628] systemd[1]: Starting Import lastlog data into lastlog2 database...
  1405. 52.08 s [vm-test-run-centjes-e2e-test] client # [ 10.264164] systemd[1]: Starting resolvconf update...
  1406. 52.10 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.477771] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
  1407. 52.11 s [vm-test-run-centjes-e2e-test] client # [ 10.277567] systemd[1]: Starting D-Bus System Message Bus...
  1408. 52.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.524755] systemd[1]: Started Reset console on configuration changes.
  1409. 52.15 s [vm-test-run-centjes-e2e-test] client # [ 10.303513] (udev-worker)[515]: [0;1;38:5:185meth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.
  1410. 52.15 s [vm-test-run-centjes-e2e-test] docsserver # connecting to host...
  1411. 52.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.558272] systemd[1]: Starting resolvconf update...
  1412. 52.18 s [vm-test-run-centjes-e2e-test] client # [ 10.342616] nsncd[590]: Apr 27 17:49:50.420 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
  1413. 52.20 s [vm-test-run-centjes-e2e-test] client # [ 10.371651] systemd[1]: Finished Import lastlog data into lastlog2 database.
  1414. 52.22 s [vm-test-run-centjes-e2e-test] client # [ 10.395630] systemd[1]: Found device /dev/ttyS0.
  1415. 52.22 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.573910] nsncd[600]: Apr 27 17:49:50.453 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
  1416. 52.25 s [vm-test-run-centjes-e2e-test] client # [ 10.421325] dbus-daemon[594]: dbus[594]: Unknown username "systemd-timesync" in message bus configuration file
  1417. 52.25 s [vm-test-run-centjes-e2e-test] docsserver: Guest shell says: b'Spawning backdoor root shell...\n'
  1418. 52.27 s [vm-test-run-centjes-e2e-test] docsserver: connected to guest root shell
  1419. 52.27 s [vm-test-run-centjes-e2e-test] docsserver: (connecting took 12.07 seconds)
  1420. 52.27 s [vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for the VM to finish booting, in 12.07 seconds)
  1421. 52.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.639668] systemd[1]: Started Centjes docs site production Service.
  1422. 52.27 s [vm-test-run-centjes-e2e-test] client # [ 10.448400] (udev-worker)[515]: Network interface NamePolicy= disabled on kernel command line.
  1423. 52.29 s [vm-test-run-centjes-e2e-test] client # [ 10.467371] systemd[1]: Started backdoor.service.
  1424. 52.30 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.672673] dbus-daemon[604]: dbus[604]: Unknown username "systemd-timesync" in message bus configuration file
  1425. 52.31 s [vm-test-run-centjes-e2e-test] client # [ 10.481747] (udev-worker)[524]: Network interface NamePolicy= disabled on kernel command line.
  1426. 52.32 s [vm-test-run-centjes-e2e-test] client # connecting to host...
  1427. 52.33 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.714332] systemd[1]: Starting D-Bus System Message Bus...
  1428. 52.34 s [vm-test-run-centjes-e2e-test] client # [ 10.509710] systemd[1]: Started Name Service Cache Daemon (nsncd).
  1429. 52.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.740795] systemd[1]: Found device /dev/ttyS0.
  1430. 52.36 s [vm-test-run-centjes-e2e-test] client # [ 10.535199] systemd[1]: Reached target Host and Network Name Lookups.
  1431. 52.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.765954] systemd[1]: Started backdoor.service.
  1432. 52.39 s [vm-test-run-centjes-e2e-test] client # [ 10.554836] systemd[1]: Reached target User and Group Name Lookups.
  1433. 52.41 s [vm-test-run-centjes-e2e-test] client # [ 10.586781] systemd[1]: Starting User Login Management...
  1434. 52.43 s [vm-test-run-centjes-e2e-test] client # [ 10.601504] systemd[1]: Started D-Bus System Message Bus.
  1435. 52.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.805650] (udev-worker)[515]: [0;1;38:5:185meth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.
  1436. 52.44 s [vm-test-run-centjes-e2e-test] client # [ 10.625256] systemd[1]: Stopped target Host and Network Name Lookups.
  1437. 52.46 s [vm-test-run-centjes-e2e-test] client # [ 10.640905] systemd[1]: Stopping Host and Network Name Lookups...
  1438. 52.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.849394] (udev-worker)[515]: Network interface NamePolicy= disabled on kernel command line.
  1439. 52.48 s [vm-test-run-centjes-e2e-test] client # [ 10.653740] systemd[1]: Stopped target User and Group Name Lookups.
  1440. 52.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.876854] (udev-worker)[529]: Network interface NamePolicy= disabled on kernel command line.
  1441. 52.50 s [vm-test-run-centjes-e2e-test] client # [ 10.675828] systemd[1]: Stopping User and Group Name Lookups...
  1442. 52.52 s [vm-test-run-centjes-e2e-test] client # [ 10.689519] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...
  1443. 52.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.900639] systemd[1]: Finished Import lastlog data into lastlog2 database.
  1444. 52.54 s [vm-test-run-centjes-e2e-test] client # [ 10.709798] systemd[1]: nscd.service: Deactivated successfully.
  1445. 52.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.934927] systemd[1]: Started Name Service Cache Daemon (nsncd).
  1446. 52.56 s [vm-test-run-centjes-e2e-test] client # [ 10.735875] systemd[1]: Stopped Name Service Cache Daemon (nsncd).
  1447. 52.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.949410] systemd[1]: Reached target Host and Network Name Lookups.
  1448. 52.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.966406] systemd[1]: Reached target User and Group Name Lookups.
  1449. 52.58 s [vm-test-run-centjes-e2e-test] client # [ 10.752587] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
  1450. 52.59 s [vm-test-run-centjes-e2e-test] client # [ 10.773571] systemd-logind[620]: New seat seat0.
  1451. 52.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.982796] systemd[1]: Starting User Login Management...
  1452. 52.61 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.000329] systemd[1]: Started D-Bus System Message Bus.
  1453. 52.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.011920] systemd[1]: Stopped target Host and Network Name Lookups.
  1454. 52.62 s [vm-test-run-centjes-e2e-test] client # [ 10.787215] nsncd[674]: Apr 27 17:49:50.899 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
  1455. 52.63 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.024920] systemd[1]: Stopping Host and Network Name Lookups...
  1456. 52.64 s [vm-test-run-centjes-e2e-test] client # [ 10.816738] systemd[1]: Started User Login Management.
  1457. 52.65 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.041300] systemd[1]: Stopped target User and Group Name Lookups.
  1458. 52.65 s [vm-test-run-centjes-e2e-test] client # [ 10.833205] systemd[1]: Starting linger-users.service...
  1459. 52.66 s [vm-test-run-centjes-e2e-test] client # [ 10.840607] systemd[1]: Started Name Service Cache Daemon (nsncd).
  1460. 52.67 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.059347] systemd[1]: Stopping User and Group Name Lookups...
  1461. 52.67 s [vm-test-run-centjes-e2e-test] client # [ 10.853614] systemd[1]: Reached target Host and Network Name Lookups.
  1462. 52.68 s [vm-test-run-centjes-e2e-test] client # [ 10.864316] systemd[1]: Reached target User and Group Name Lookups.
  1463. 52.69 s [vm-test-run-centjes-e2e-test] client # [ 10.874767] systemd[1]: Finished Firewall.
  1464. 52.69 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.082427] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...
  1465. 52.70 s [vm-test-run-centjes-e2e-test] client # [ 10.880411] systemd[1]: linger-users.service: Deactivated successfully.
  1466. 52.70 s [vm-test-run-centjes-e2e-test] client # [ 10.887336] systemd[1]: Finished linger-users.service.
  1467. 52.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.097411] systemd[1]: nscd.service: Deactivated successfully.
  1468. 52.72 s [vm-test-run-centjes-e2e-test] client # [ 10.909246] systemd[1]: Finished resolvconf update.
  1469. 52.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.112905] systemd[1]: Stopped Name Service Cache Daemon (nsncd).
  1470. 52.73 s [vm-test-run-centjes-e2e-test] client # [ 10.913443] systemd[1]: Reached target Preparation for Network.
  1471. 52.74 s [vm-test-run-centjes-e2e-test] client # [ 10.921876] systemd[1]: Starting DHCP Client...
  1472. 52.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.136817] systemd[1]: Finished Firewall.
  1473. 52.75 s [vm-test-run-centjes-e2e-test] client # [ 10.935679] systemd[1]: Found device Virtio network device.
  1474. 52.76 s [vm-test-run-centjes-e2e-test] client # [ 10.945432] systemd[1]: Starting Address configuration of eth1...
  1475. 52.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.150281] nsncd[696]: Apr 27 17:49:51.068 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
  1476. 52.79 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.180373] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
  1477. 52.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.194701] systemd-logind[633]: New seat seat0.
  1478. 52.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.216749] systemd[1]: Started User Login Management.
  1479. 52.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.235754] systemd[1]: Starting linger-users.service...
  1480. 52.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.246666] systemd[1]: Started Name Service Cache Daemon (nsncd).
  1481. 52.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.259827] systemd[1]: Reached target Host and Network Name Lookups.
  1482. 52.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.278367] systemd[1]: Reached target User and Group Name Lookups.
  1483. 52.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.289621] systemd[1]: Found device Virtio network device.
  1484. 52.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.302591] systemd[1]: Finished resolvconf update.
  1485. 52.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.311453] systemd[1]: Reached target Preparation for Network.
  1486. 52.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.323823] systemd[1]: Starting DHCP Client...
  1487. 52.94 s [vm-test-run-centjes-e2e-test] client # [ 11.113490] network-addresses-eth1-start[711]: adding address 192.168.1.1/24... done
  1488. 52.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.336249] systemd[1]: Starting Address configuration of eth1...
  1489. 52.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.346751] systemd[1]: linger-users.service: Deactivated successfully.
  1490. 52.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.359506] systemd[1]: Finished linger-users.service.
  1491. 52.97 s [vm-test-run-centjes-e2e-test] client # [ 11.143414] network-addresses-eth1-start[711]: adding address 2001:db8:1::1/64... done
  1492. 53.01 s [vm-test-run-centjes-e2e-test] client # [ 11.189429] systemd[1]: Finished Address configuration of eth1.
  1493. 53.02 s [vm-test-run-centjes-e2e-test] client # [ 11.201556] systemd[1]: Starting Networking Setup...
  1494. 53.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.428859] network-addresses-eth1-start[731]: adding address 192.168.1.2/24... done
  1495. 53.07 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.458814] network-addresses-eth1-start[731]: adding address 2001:db8:1::2/64... done
  1496. 53.07 s [vm-test-run-centjes-e2e-test] client # [ 11.249700] dhcpcd[716]: dhcpcd-10.2.4 starting
  1497. 53.09 s [vm-test-run-centjes-e2e-test] client # [ 11.272634] dhcpcd[730]: dev: loaded udev
  1498. 53.11 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.497269] systemd[1]: Finished Address configuration of eth1.
  1499. 53.12 s [vm-test-run-centjes-e2e-test] client # [ 11.859492] mousedev: PS/2 mouse device common for all mice
  1500. 53.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.517750] systemd[1]: Starting Networking Setup...
  1501. 53.12 s [vm-test-run-centjes-e2e-test] client # [ 11.864769] 8021q: 802.1Q VLAN Support v1.8
  1502. 53.13 s [vm-test-run-centjes-e2e-test] client # [ 11.867660] 8021q: adding VLAN 0 to HW filter on device eth1
  1503. 53.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.589167] dhcpcd[739]: dhcpcd-10.2.4 starting
  1504. 53.21 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.613929] dhcpcd[752]: dev: loaded udev
  1505. 53.25 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.168703] 8021q: 802.1Q VLAN Support v1.8
  1506. 53.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.175218] 8021q: adding VLAN 0 to HW filter on device eth1
  1507. 53.30 s [vm-test-run-centjes-e2e-test] client # [ 12.042000] cfg80211: Loading compiled-in X.509 certificates for regulatory database
  1508. 53.34 s [vm-test-run-centjes-e2e-test] client # [ 12.084437] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
  1509. 53.35 s [vm-test-run-centjes-e2e-test] client # [ 12.090023] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'
  1510. 53.36 s [vm-test-run-centjes-e2e-test] client # [ 12.098739] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
  1511. 53.37 s [vm-test-run-centjes-e2e-test] client # [ 12.109749] cfg80211: failed to load regulatory.db
  1512. 53.38 s [vm-test-run-centjes-e2e-test] client # [ 11.555310] systemd[1]: Finished Networking Setup.
  1513. 53.38 s [vm-test-run-centjes-e2e-test] client # [ 11.569348] systemd[1]: Reached target Network.
  1514. 53.39 s [vm-test-run-centjes-e2e-test] client # [ 11.574616] systemd[1]: Starting Permit User Sessions...
  1515. 53.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.331642] cfg80211: Loading compiled-in X.509 certificates for regulatory database
  1516. 53.45 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.844942] systemd[1]: Finished Networking Setup.
  1517. 53.46 s [vm-test-run-centjes-e2e-test] client # [ 11.642144] systemd[1]: Finished Permit User Sessions.
  1518. 53.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.860315] systemd[1]: Reached target Network.
  1519. 53.46 s [vm-test-run-centjes-e2e-test] client # [ 11.650466] systemd[1]: Started Getty on tty1.[ 12.205514] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input3
  1520. 53.47 s [vm-test-run-centjes-e2e-test] client #
  1521. 53.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.865838] systemd[1]: Starting Permit User Sessions...
  1522. 53.47 s [vm-test-run-centjes-e2e-test] client # [ 11.658235] systemd[1]: Reached target Login Prompts.
  1523. 53.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.403002] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
  1524. 53.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.410655] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'
  1525. 53.51 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.421782] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
  1526. 53.51 s [vm-test-run-centjes-e2e-test] client # [ 12.247610] ACPI: button: Power Button [PWRF]
  1527. 53.51 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.430502] cfg80211: failed to load regulatory.db
  1528. 53.51 s [vm-test-run-centjes-e2e-test] client # [ 12.254667] 8021q: adding VLAN 0 to HW filter on device eth0
  1529. 53.52 s [vm-test-run-centjes-e2e-test] client # [ 11.707836] dhcpcd[730]: eth0: waiting for carrier
  1530. 53.53 s [vm-test-run-centjes-e2e-test] client # [ 11.712822] dhcpcd[730]: libudev: received NULL device
  1531. 53.53 s [vm-test-run-centjes-e2e-test] client # [ 11.720519] dhcpcd[730]: libudev: received NULL device
  1532. 53.54 s [vm-test-run-centjes-e2e-test] client # [ 12.279246] rtc_cmos 00:05: RTC can wake from S4
  1533. 53.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.459644] mousedev: PS/2 mouse device common for all mice
  1534. 53.55 s [vm-test-run-centjes-e2e-test] client # [ 12.293724] Floppy drive(s): fd0 is 2.88M AMI BIOS
  1535. 53.56 s [vm-test-run-centjes-e2e-test] client # [ 12.299089] parport_pc 00:03: reported by Plug and Play ACPI
  1536. 53.57 s [vm-test-run-centjes-e2e-test] client # [ 12.309711] rtc_cmos 00:05: registered as rtc0
  1537. 53.57 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.968919] systemd[1]: Finished Permit User Sessions.
  1538. 53.58 s [vm-test-run-centjes-e2e-test] client # [ 12.321238] parport0: PC-style at 0x378, irq 7 [PCSPP(,...)]
  1539. 53.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.979495] systemd[1]: Started Getty on tty1.
  1540. 53.59 s [vm-test-run-centjes-e2e-test] client # [ 12.327869] rtc_cmos 00:05: setting system clock to 2026-04-27T17:49:52 UTC (1777312192)
  1541. 53.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.989717] systemd[1]: Reached target Login Prompts.
  1542. 53.59 s [vm-test-run-centjes-e2e-test] client # [ 12.336051] FDC 0 is a S82078B
  1543. 53.61 s [vm-test-run-centjes-e2e-test] client # [ 12.348898] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs
  1544. 53.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.554582] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input3
  1545. 53.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.561135] 8021q: adding VLAN 0 to HW filter on device eth0
  1546. 53.65 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.049984] dhcpcd[752]: eth0: waiting for carrier
  1547. 53.66 s [vm-test-run-centjes-e2e-test] client # [ 12.395965] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0
  1548. 53.68 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.600709] ACPI: button: Power Button [PWRF]
  1549. 53.68 s [vm-test-run-centjes-e2e-test] client # [ 12.424715] i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD
  1550. 53.69 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.609931] rtc_cmos 00:05: RTC can wake from S4
  1551. 53.70 s [vm-test-run-centjes-e2e-test] client # [ 12.436141] input: QEMU Virtio Keyboard as /devices/pci0000:00/0000:00:0a.0/virtio7/input/input4
  1552. 53.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.627553] parport_pc 00:03: reported by Plug and Play ACPI
  1553. 53.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.630750] Floppy drive(s): fd0 is 2.88M AMI BIOS
  1554. 53.72 s [vm-test-run-centjes-e2e-test] client # [ 12.457970] bochs-drm 0000:00:02.0: vgaarb: deactivate vga console
  1555. 53.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.642243] rtc_cmos 00:05: registered as rtc0
  1556. 53.73 s [vm-test-run-centjes-e2e-test] client # [ 12.467504] cryptd: max_cpu_qlen set to 1000
  1557. 53.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.648153] parport0: PC-style at 0x378, irq 7 [PCSPP(,...)]
  1558. 53.73 s [vm-test-run-centjes-e2e-test] client # [ 12.472813] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input6
  1559. 53.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.651566] rtc_cmos 00:05: setting system clock to 2026-04-27T17:49:52 UTC (1777312192)
  1560. 53.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.661852] FDC 0 is a S82078B
  1561. 53.75 s [vm-test-run-centjes-e2e-test] client # [ 12.483150] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input5
  1562. 53.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.677747] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs
  1563. 53.77 s [vm-test-run-centjes-e2e-test] client # [ 12.510865] Console: switching to colour dummy device 80x25
  1564. 53.77 s [vm-test-run-centjes-e2e-test] client # [ 12.513056] [drm] Found bochs VGA, ID 0xb0c5.
  1565. 53.77 s [vm-test-run-centjes-e2e-test] client # [ 12.514393] [drm] Framebuffer size 16384 kB @ 0xfd000000, mmio @ 0xfebd0000.
  1566. 53.79 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.702498] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0
  1567. 53.79 s [vm-test-run-centjes-e2e-test] client # [ 12.534922] AES CTR mode by8 optimization enabled
  1568. 53.81 s [vm-test-run-centjes-e2e-test] client # [ 12.554418] [drm] Found EDID data blob.
  1569. 53.82 s [vm-test-run-centjes-e2e-test] client # [ 12.563840] [drm] Initialized bochs-drm 1.0.0 for 0000:00:02.0 on minor 0
  1570. 53.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.739148] i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD
  1571. 53.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.774677] input: QEMU Virtio Keyboard as /devices/pci0000:00/0000:00:0a.0/virtio7/input/input4
  1572. 53.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.780678] bochs-drm 0000:00:02.0: vgaarb: deactivate vga console
  1573. 53.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.789718] cryptd: max_cpu_qlen set to 1000
  1574. 53.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.796101] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input6
  1575. 53.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.844700] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input5
  1576. 53.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.865959] AES CTR mode by8 optimization enabled
  1577. 54.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.400727] dhcpcd[752]: eth0: carrier acquired
  1578. 54.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.872131] Console: switching to colour dummy device 80x25
  1579. 54.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.424465] dhcpcd[752]: DUID 00:01:00:01:31:82:5e:40:52:54:00:12:34:56
  1580. 54.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.430781] dhcpcd[752]: eth0: IAID 00:12:34:56
  1581. 54.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.439442] dhcpcd[752]: eth0: adding address fe80::5054:ff:fe12:3456
  1582. 54.05 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.966318] [drm] Found bochs VGA, ID 0xb0c5.
  1583. 54.05 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.967742] [drm] Framebuffer size 16384 kB @ 0xfd000000, mmio @ 0xfebd0000.
  1584. 54.10 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.024060] [drm] Found EDID data blob.
  1585. 54.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.038950] [drm] Initialized bochs-drm 1.0.0 for 0000:00:02.0 on minor 0
  1586. 54.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.538247] systemd[1]: Starting Virtual Console Setup...
  1587. 54.44 s [vm-test-run-centjes-e2e-test] client # [ 12.626898] dhcpcd[730]: eth0: carrier acquired
  1588. 54.46 s [vm-test-run-centjes-e2e-test] client # [ 12.645103] dhcpcd[730]: DUID 00:01:00:01:31:82:5e:41:52:54:00:12:34:56
  1589. 54.46 s [vm-test-run-centjes-e2e-test] client # [ 12.647628] dhcpcd[730]: eth0: IAID 00:12:34:56
  1590. 54.47 s [vm-test-run-centjes-e2e-test] client # [ 12.650966] dhcpcd[730]: eth0: adding address fe80::5054:ff:fe12:3456
  1591. 54.55 s [vm-test-run-centjes-e2e-test] client # [ 12.726497] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
  1592. 54.60 s [vm-test-run-centjes-e2e-test] client # [ 12.775802] systemd-logind[620]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard)
  1593. 54.60 s [vm-test-run-centjes-e2e-test] client # [ 12.786973] systemd-logind[620]: Watching system buttons on /dev/input/event2 (Power Button)
  1594. 54.63 s [vm-test-run-centjes-e2e-test] client # [ 12.808802] systemd[1]: Starting Virtual Console Setup...
  1595. 54.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.167342] dhcpcd[752]: eth0: soliciting a DHCP lease
  1596. 54.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.174523] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
  1597. 54.80 s [vm-test-run-centjes-e2e-test] client # [ 12.591750] fbcon: bochs-drmdrmfb (fb0) is primary device
  1598. 54.82 s [vm-test-run-centjes-e2e-test] client # [ 13.389104] ppdev: user-space parallel port driver
  1599. 54.83 s [vm-test-run-centjes-e2e-test] client # [ 13.417072] Console: switching to colour frame buffer device 160x50
  1600. 54.85 s [vm-test-run-centjes-e2e-test] client # [ 13.588758] bochs-drm 0000:00:02.0: [drm] fb0: bochs-drmdrmfb frame buffer device
  1601. 54.90 s [vm-test-run-centjes-e2e-test] client # [ 13.087193] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
  1602. 54.91 s [vm-test-run-centjes-e2e-test] client # [ 13.091864] systemd[1]: Stopped Virtual Console Setup.
  1603. 54.92 s [vm-test-run-centjes-e2e-test] client # [ 13.098643] systemd-logind[620]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)
  1604. 54.93 s [vm-test-run-centjes-e2e-test] client # [ 13.114294] systemd[1]: Starting Virtual Console Setup...
  1605. 54.96 s [vm-test-run-centjes-e2e-test] client # [ 13.142630] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
  1606. 54.97 s [vm-test-run-centjes-e2e-test] client # [ 13.152917] systemd[1]: Stopped Virtual Console Setup.
  1607. 54.98 s [vm-test-run-centjes-e2e-test] client # [ 13.159638] systemd[1]: Starting Virtual Console Setup...
  1608. 55.07 s [vm-test-run-centjes-e2e-test] client # [ 13.812228] kvm_amd: TSC scaling supported
  1609. 55.07 s [vm-test-run-centjes-e2e-test] client # [ 13.813574] kvm_amd: Nested Virtualization enabled
  1610. 55.07 s [vm-test-run-centjes-e2e-test] client # [ 13.815005] kvm_amd: Nested Paging enabled
  1611. 55.07 s [vm-test-run-centjes-e2e-test] client # [ 13.816152] kvm_amd: LBR virtualization supported
  1612. 55.08 s [vm-test-run-centjes-e2e-test] client # [ 13.822941] kvm_amd: Virtual VMLOAD VMSAVE supported
  1613. 55.08 s [vm-test-run-centjes-e2e-test] client # [ 13.824579] kvm_amd: Virtual GIF supported
  1614. 55.10 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.091038] fbcon: bochs-drmdrmfb (fb0) is primary device
  1615. 55.10 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.713619] NET: Registered PF_PACKET protocol family
  1616. 55.11 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.807914] ppdev: user-space parallel port driver
  1617. 55.11 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.879522] Console: switching to colour frame buffer device 160x50
  1618. 55.11 s [vm-test-run-centjes-e2e-test] docsserver # [ 14.027694] bochs-drm 0000:00:02.0: [drm] fb0: bochs-drmdrmfb frame buffer device
  1619. 55.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.202971] dhcpcd[752]: eth0: offered 10.0.2.15 from 10.0.2.2
  1620. 55.13 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.524294] systemd-logind[633]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard)
  1621. 55.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.533845] dhcpcd[752]: eth0: probing address 10.0.2.15/24
  1622. 55.14 s [vm-test-run-centjes-e2e-test] client # [ 13.882880] EDAC MC: Ver: 3.0.0
  1623. 55.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.539667] systemd-logind[633]: Watching system buttons on /dev/input/event2 (Power Button)
  1624. 55.15 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.547709] systemd-logind[633]: Watching system buttons on /dev/input/event5 (QEMU Virtio Keyboard)
  1625. 55.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.564572] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
  1626. 55.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.569737] systemd[1]: Stopped Virtual Console Setup.
  1627. 55.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.603403] systemd[1]: Starting Virtual Console Setup...
  1628. 55.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 14.177166] kvm_amd: TSC scaling supported
  1629. 55.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 14.178851] kvm_amd: Nested Virtualization enabled
  1630. 55.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 14.180603] kvm_amd: Nested Paging enabled
  1631. 55.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 14.182078] kvm_amd: LBR virtualization supported
  1632. 55.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 14.192253] kvm_amd: Virtual VMLOAD VMSAVE supported
  1633. 55.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 14.194021] kvm_amd: Virtual GIF supported
  1634. 55.30 s [vm-test-run-centjes-e2e-test] client # [ 13.484224] dhcpcd[730]: eth0: soliciting a DHCP lease
  1635. 55.32 s [vm-test-run-centjes-e2e-test] client # [ 14.066938] NET: Registered PF_PACKET protocol family
  1636. 55.34 s [vm-test-run-centjes-e2e-test] client # [ 13.525231] dhcpcd[730]: eth0: offered 10.0.2.15 from 10.0.2.2
  1637. 55.34 s [vm-test-run-centjes-e2e-test] client # [ 13.530436] dhcpcd[730]: eth0: probing address 10.0.2.15/24
  1638. 55.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 14.272686] EDAC MC: Ver: 3.0.0
  1639. 55.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.992193] dhcpcd[752]: eth0: soliciting an IPv6 router
  1640. 55.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.995819] dhcpcd[752]: eth0: Router Advertisement from fe80::2
  1641. 55.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.998499] dhcpcd[752]: eth0: adding address fec0::5054:ff:fe12:3456/64
  1642. 55.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 14.001616] dhcpcd[752]: eth0: adding route to fec0::/64
  1643. 55.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 14.005698] dhcpcd[752]: eth0: adding default route via fe80::2
  1644. 55.71 s [vm-test-run-centjes-e2e-test] client # [ 13.898771] systemd[1]: Finished Virtual Console Setup.
  1645. 55.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 14.362676] systemd[1]: Finished Virtual Console Setup.
  1646. 56.79 s [vm-test-run-centjes-e2e-test] client # [ 14.981606] dhcpcd[730]: eth0: soliciting an IPv6 router
  1647. 56.80 s [vm-test-run-centjes-e2e-test] client # [ 14.985587] dhcpcd[730]: eth0: Router Advertisement from fe80::2
  1648. 56.80 s [vm-test-run-centjes-e2e-test] client # [ 14.989296] dhcpcd[730]: eth0: adding address fec0::5054:ff:fe12:3456/64
  1649. 56.80 s [vm-test-run-centjes-e2e-test] client # [ 14.992849] dhcpcd[730]: eth0: adding route to fec0::/64
  1650. 56.81 s [vm-test-run-centjes-e2e-test] client # [ 14.995703] dhcpcd[730]: eth0: adding default route via fe80::2
  1651. 60.46 s [vm-test-run-centjes-e2e-test] client # [ 18.648587] dhcpcd[730]: eth0: leased 10.0.2.15 for 86400 seconds
  1652. 60.46 s [vm-test-run-centjes-e2e-test] client # [ 18.652814] dhcpcd[730]: eth0: adding route to 10.0.2.0/24
  1653. 60.52 s [vm-test-run-centjes-e2e-test] client # [ 18.656360] dhcpcd[730]: eth0: adding default route via 10.0.2.2
  1654. 60.63 s [vm-test-run-centjes-e2e-test] client # [ 18.812152] systemd[1]: Started DHCP Client.
  1655. 60.63 s [vm-test-run-centjes-e2e-test] client # [ 18.816967] systemd[1]: Reached target Multi-User System.
  1656. 60.63 s [vm-test-run-centjes-e2e-test] client # [ 18.819656] systemd[1]: Startup finished in 4.978s (kernel) + 13.836s (userspace) = 18.814s.
  1657. 60.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 19.197579] dhcpcd[752]: eth0: leased 10.0.2.15 for 86400 seconds
  1658. 60.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 19.201815] dhcpcd[752]: eth0: adding route to 10.0.2.0/24
  1659. 60.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 19.204893] dhcpcd[752]: eth0: adding default route via 10.0.2.2
  1660. 60.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 19.361656] systemd[1]: Started DHCP Client.
  1661. 60.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 19.367774] systemd[1]: Reached target Multi-User System.
  1662. 60.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 19.370824] systemd[1]: Startup finished in 5.189s (kernel) + 14.176s (userspace) = 19.366s.
  1663. 61.28 s [vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for unit default.target, in 21.07 seconds)
  1664. 61.28 s [vm-test-run-centjes-e2e-test] client: waiting for unit default.target
  1665. 61.28 s [vm-test-run-centjes-e2e-test] client: waiting for the VM to finish booting
  1666. 61.28 s [vm-test-run-centjes-e2e-test] client: Guest shell says: b'Spawning backdoor root shell...\n'
  1667. 61.28 s [vm-test-run-centjes-e2e-test] client: connected to guest root shell
  1668. 61.28 s [vm-test-run-centjes-e2e-test] client: (connecting took 0.00 seconds)
  1669. 61.28 s [vm-test-run-centjes-e2e-test] client: (finished: waiting for the VM to finish booting, in 0.00 seconds)
  1670. 61.44 s [vm-test-run-centjes-e2e-test] client: (finished: waiting for unit default.target, in 0.16 seconds)
  1671. 61.53 s [vm-test-run-centjes-e2e-test] docsserver: waiting for unit centjes-docs-site-production.service
  1672. 61.60 s [vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for unit centjes-docs-site-production.service, in 0.07 seconds)
  1673. 61.60 s [vm-test-run-centjes-e2e-test] docsserver: waiting for unit default.target
  1674. 61.66 s [vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for unit default.target, in 0.06 seconds)
  1675. 61.66 s [vm-test-run-centjes-e2e-test] docsserver: waiting for TCP port 8001 on localhost
  1676. 61.75 s [vm-test-run-centjes-e2e-test] docsserver # Connection to localhost (127.0.0.1) 8001 port [tcp/vcom-tunnel] succeeded!
  1677. 61.75 s [vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for TCP port 8001 on localhost, in 0.10 seconds)
  1678. 61.75 s [vm-test-run-centjes-e2e-test] client: must succeed: curl docsserver:8001
  1679. 61.87 s [vm-test-run-centjes-e2e-test] client # % Total % Received % Xferd Average Speed Time Time Time Current
  1680. 61.89 s [vm-test-run-centjes-e2e-test] client # Dload Upload Total Spent Left Speed
  1681. 61.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 20.318366] centjes-docs-site-production-start[612]: 192.168.1.1 - - [27/Apr/2026:17:50:00 +0000] "GET / HTTP/1.1" 200 3595 "" "curl/8.17.0"
  1682. 61.94 s [vm-test-run-centjes-e2e-test] client # 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0100 3595 100 3595 0 0 50446 0 --:--:-- --:--:-- --:--:-- 51357
  1683. 61.94 s [vm-test-run-centjes-e2e-test] client: (finished: must succeed: curl docsserver:8001, in 0.19 seconds)
  1684. 61.94 s [vm-test-run-centjes-e2e-test] (finished: run the VM test script, in 22.11 seconds)
  1685. 62.09 s [vm-test-run-centjes-e2e-test] test script finished in 22.26s
  1686. 62.09 s [vm-test-run-centjes-e2e-test] cleanup
  1687. 62.09 s [vm-test-run-centjes-e2e-test] kill machine (pid 31)
  1688. 62.09 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)
  1689. 62.10 s [vm-test-run-centjes-e2e-test] kill machine (pid 9)
  1690. 62.10 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)
  1691. 62.11 s [vm-test-run-centjes-e2e-test] kill vlan (pid 7)
  1692. 62.11 s [vm-test-run-centjes-e2e-test] (finished: cleanup, in 0.02 seconds)
  1693. 62.25 s [post-build-hook] Uploading paths from nix-ci to cachix cache "centjes" /nix/store/hw5s85pl0wzkl3walw63rlv9c8kpv17b-vm-test-run-centjes-e2e-test
  1694. 74.58 s [post-build-hook] Pushing 1 paths (0 are already present) using zstd to cache centjes ⏳
  1695. 74.58 s [post-build-hook]
  1696. 81.24 s [post-build-hook] Pushing /nix/store/hw5s85pl0wzkl3walw63rlv9c8kpv17b-vm-test-run-centjes-e2e-test (96.00 B)
  1697. 95.50 s [post-build-hook]
  1698. 95.50 s [post-build-hook] All done.
  1699. 95.51 s [post-build-hook] Uploading paths from nix-ci to the NixCI staging cache /nix/store/hw5s85pl0wzkl3walw63rlv9c8kpv17b-vm-test-run-centjes-e2e-test
  1700. 95.56 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  1701. 95.56 s [post-build-hook] copying 1 paths...
  1702. 95.56 s [post-build-hook] copying path '/nix/store/hw5s85pl0wzkl3walw63rlv9c8kpv17b-vm-test-run-centjes-e2e-test' to 'https://cache.staging.nix-ci.com'...
  1703. 95.76 s [post-build-hook] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  1704. 96.05 s [post-build-hook] copying 0 paths...
  1705. 96.08 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/refs%2Fpull%2F2%2Fmerge/a5ac38ca38a8ee4de9eabeebe725de50cf47e5f3/f1e75b75-cc86-4dd1-b218-29eccacb9d36/wait

Latest logs, with timestamps (streams while running):

curl --netrc -N https://staging.nix-ci.com/gh:NorfairKing:centjes/refs%2Fpull%2F2%2Fmerge/a5ac38ca38a8ee4de9eabeebe725de50cf47e5f3/f1e75b75-cc86-4dd1-b218-29eccacb9d36/tail

All logs, with timestamps (available after completion):

curl --netrc https://staging.nix-ci.com/gh:NorfairKing:centjes/refs%2Fpull%2F2%2Fmerge/a5ac38ca38a8ee4de9eabeebe725de50cf47e5f3/f1e75b75-cc86-4dd1-b218-29eccacb9d36/logs

Raw logs, from the start (no timestamps):

curl --netrc -N https://staging.nix-ci.com/gh:NorfairKing:centjes/refs%2Fpull%2F2%2Fmerge/a5ac38ca38a8ee4de9eabeebe725de50cf47e5f3/f1e75b75-cc86-4dd1-b218-29eccacb9d36/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/refs%2Fpull%2F2%2Fmerge/a5ac38ca38a8ee4de9eabeebe725de50cf47e5f3/f1e75b75-cc86-4dd1-b218-29eccacb9d36/logs

Reproduce locally: https://staging.nix-ci.com/gh:NorfairKing:centjes/refs%2Fpull%2F2%2Fmerge/a5ac38ca38a8ee4de9eabeebe725de50cf47e5f3/f1e75b75-cc86-4dd1-b218-29eccacb9d36/repro

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