build checks.x86_64-linux.e2e-test

Reproduce this run
  1. 0.09 s $ /nix/store/vzx1mi9c0xfadmsm9dhd83d005cb1qs9-coreutils-9.8/bin/timeout --kill-after=15s 7200s /nix/store/86n4l5yri6hys3zk2mwy2azcv9prqb8j-nix-2.31.4/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=master&rev=fdf64ecd406db54f98fff6dc0f1717ee1a0702c1#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.11 s
  7. 3.37 s Downloading cached hosts from https://cache.staging.nix-ci.com
  8. 3.37 s Downloading cached system-units from https://cache.staging.nix-ci.com
  9. 3.45 s Building etc-hostname
  10. 3.46 s Downloading cached centjes-docs-site-config.yaml from https://cache.staging.nix-ci.com
  11. 3.48 s Building extra-hosts
  12. 3.50 s Building string-hosts
  13. 3.53 s Building unit-script-centjes-docs-site-production-start
  14. 3.54 s Progress: 0 of 18 built (4 building), 1 of 8 downloaded from cache (2 downloading)
  15. 3.54 s Progress: 0 of 18 built (4 building), 2 of 8 downloaded from cache (1 downloading)
  16. 3.55 s [post-build-hook] Uploading to cachix cache "centjes": /nix/store/76qndmwyzks6zi2n08i19w35jisawpss-etc-hostname
  17. 3.91 s [post-build-hook] Pushing 1 paths (0 are already present) using zstd to cache centjes ⏳
  18. 3.91 s [post-build-hook]
  19. 4.32 s [post-build-hook] Pushing /nix/store/76qndmwyzks6zi2n08i19w35jisawpss-etc-hostname (128.00 B)
  20. 5.35 s [post-build-hook]
  21. 5.35 s [post-build-hook] All done.
  22. 5.37 s [post-build-hook] Uploading to the NixCI staging cache: /nix/store/76qndmwyzks6zi2n08i19w35jisawpss-etc-hostname
  23. 5.58 s [post-build-hook] copying 1 paths...
  24. 5.58 s [post-build-hook] copying path '/nix/store/76qndmwyzks6zi2n08i19w35jisawpss-etc-hostname' to 'https://cache.staging.nix-ci.com'...
  25. 5.93 s [post-build-hook] copying 0 paths...
  26. 5.95 s Progress: 1 of 19 built (3 building), 2 of 8 downloaded from cache (1 downloading)
  27. 5.96 s [post-build-hook] Uploading to cachix cache "centjes": /nix/store/4zcwmgzv3icp68qdnrgc6f53xmvk5cfc-extra-hosts
  28. 6.33 s [post-build-hook] Pushing 1 paths (0 are already present) using zstd to cache centjes ⏳
  29. 6.33 s [post-build-hook]
  30. 6.72 s [post-build-hook] Pushing /nix/store/4zcwmgzv3icp68qdnrgc6f53xmvk5cfc-extra-hosts (200.00 B)
  31. 7.79 s [post-build-hook]
  32. 7.79 s [post-build-hook] All done.
  33. 7.81 s [post-build-hook] Uploading to the NixCI staging cache: /nix/store/4zcwmgzv3icp68qdnrgc6f53xmvk5cfc-extra-hosts
  34. 8.02 s [post-build-hook] copying 1 paths...
  35. 8.02 s [post-build-hook] copying path '/nix/store/4zcwmgzv3icp68qdnrgc6f53xmvk5cfc-extra-hosts' to 'https://cache.staging.nix-ci.com'...
  36. 9.06 s [post-build-hook] copying 0 paths...
  37. 9.20 s Progress: 2 of 20 built (2 building), 2 of 8 downloaded from cache (1 downloading)
  38. 10.15 s Building settings-check
  39. 10.15 s Progress: 2 of 17 built (3 building), 3 of 8 downloaded from cache
  40. 10.16 s [post-build-hook] Uploading to cachix cache "centjes": /nix/store/9q6hjlql04i6cb0xkmr0qcvc4n607bxh-string-hosts
  41. 10.52 s [post-build-hook] Pushing 1 paths (0 are already present) using zstd to cache centjes ⏳
  42. 10.52 s [post-build-hook]
  43. 11.08 s [post-build-hook] Pushing /nix/store/9q6hjlql04i6cb0xkmr0qcvc4n607bxh-string-hosts (136.00 B)
  44. 12.14 s [post-build-hook]
  45. 12.14 s [post-build-hook] All done.
  46. 12.16 s [post-build-hook] Uploading to the NixCI staging cache: /nix/store/9q6hjlql04i6cb0xkmr0qcvc4n607bxh-string-hosts
  47. 12.37 s [post-build-hook] copying 1 paths...
  48. 12.37 s [post-build-hook] copying path '/nix/store/9q6hjlql04i6cb0xkmr0qcvc4n607bxh-string-hosts' to 'https://cache.staging.nix-ci.com'...
  49. 12.74 s [post-build-hook] copying 0 paths...
  50. 12.75 s Progress: 3 of 18 built (2 building), 3 of 8 downloaded from cache
  51. 12.76 s [post-build-hook] Uploading to cachix cache "centjes": /nix/store/7yxk5pk9fcfr661sd5kg0al1a2srsv7y-unit-script-centjes-docs-site-production-start
  52. 13.12 s [post-build-hook] Pushing 1 paths (29 are already present) using zstd to cache centjes ⏳
  53. 13.12 s [post-build-hook]
  54. 13.52 s [post-build-hook] Pushing /nix/store/7yxk5pk9fcfr661sd5kg0al1a2srsv7y-unit-script-centjes-docs-site-production-start (680.00 B)
  55. 14.63 s [post-build-hook]
  56. 14.63 s [post-build-hook] All done.
  57. 14.64 s [post-build-hook] Uploading to the NixCI staging cache: /nix/store/7yxk5pk9fcfr661sd5kg0al1a2srsv7y-unit-script-centjes-docs-site-production-start
  58. 15.20 s [post-build-hook] copying 1 paths...
  59. 15.20 s [post-build-hook] copying path '/nix/store/7yxk5pk9fcfr661sd5kg0al1a2srsv7y-unit-script-centjes-docs-site-production-start' to 'https://cache.staging.nix-ci.com'...
  60. 17.36 s [post-build-hook] copying 1 paths...
  61. 17.36 s [post-build-hook] copying path '/nix/store/r33vkyvs13qfgm62l3ghwvlnhl835k38-unit-script-centjes-docs-site-production-start.drv' to 'https://cache.staging.nix-ci.com'...
  62. 18.12 s Progress: 4 of 19 built (1 building), 3 of 8 downloaded from cache
  63. 18.12 s Downloading cached etc from https://cache.staging.nix-ci.com
  64. 18.18 s Building hosts
  65. 18.18 s Progress: 4 of 17 built (2 building), 4 of 8 downloaded from cache
  66. 18.20 s [post-build-hook] Uploading to cachix cache "centjes": /nix/store/1xqd5gv05li62qyjyhg7zpysyq56vv46-settings-check
  67. 18.67 s [post-build-hook] Pushing 2 paths (29 are already present) using zstd to cache centjes ⏳
  68. 18.67 s [post-build-hook]
  69. 19.07 s [post-build-hook] Pushing /nix/store/vb9vv8cg7xwfa7010fyznaj7b5syrx63-centjes-docs-site-config.yaml (200.00 B)
  70. 19.10 s [post-build-hook] Pushing /nix/store/1xqd5gv05li62qyjyhg7zpysyq56vv46-settings-check (880.00 B)
  71. 20.61 s [post-build-hook]
  72. 20.61 s [post-build-hook] All done.
  73. 20.74 s [post-build-hook] Uploading to the NixCI staging cache: /nix/store/1xqd5gv05li62qyjyhg7zpysyq56vv46-settings-check
  74. 21.18 s [post-build-hook] copying 1 paths...
  75. 21.18 s [post-build-hook] copying path '/nix/store/1xqd5gv05li62qyjyhg7zpysyq56vv46-settings-check' to 'https://cache.staging.nix-ci.com'...
  76. 22.40 s [post-build-hook] copying 1 paths...
  77. 22.40 s [post-build-hook] copying path '/nix/store/gckdv8hyj7b229sfx2qq209l65qj5nzq-settings-check.drv' to 'https://cache.staging.nix-ci.com'...
  78. 23.04 s Progress: 5 of 18 built (1 building), 4 of 8 downloaded from cache
  79. 23.04 s Downloading cached nixos-system-client-test from https://cache.staging.nix-ci.com
  80. 23.06 s Building settings-check
  81. 23.08 s [post-build-hook] Uploading to cachix cache "centjes": /nix/store/d6l7x7bbk4r18hp4mr6m4xcqf59y7yx3-hosts
  82. 23.49 s [post-build-hook] Pushing 1 paths (0 are already present) using zstd to cache centjes ⏳
  83. 23.49 s [post-build-hook]
  84. 23.92 s [post-build-hook] Pushing /nix/store/d6l7x7bbk4r18hp4mr6m4xcqf59y7yx3-hosts (256.00 B)
  85. 25.17 s [post-build-hook]
  86. 25.17 s [post-build-hook] All done.
  87. 25.19 s [post-build-hook] Uploading to the NixCI staging cache: /nix/store/d6l7x7bbk4r18hp4mr6m4xcqf59y7yx3-hosts
  88. 25.30 s [post-build-hook] copying 0 paths...
  89. 25.44 s [post-build-hook] copying 0 paths...
  90. 25.45 s Progress: 6 of 18 built (1 building), 4 of 8 downloaded from cache (1 downloading)
  91. 25.45 s [settings-check] WithConfig: src/Centjes/Docs/Site/OptParse.hs:27:7 in centjes-docs-site:Centjes.Docs.Site.OptParse
  92. 25.45 s [settings-check] loading config
  93. 25.45 s [settings-check] Parser with check: src/Centjes/Docs/Site/OptParse.hs:27:7 in centjes-docs-site:Centjes.Docs.Site.OptParse
  94. 25.45 s [settings-check] parser
  95. 25.45 s [settings-check] Alt
  96. 25.45 s [settings-check] Trying left side.
  97. 25.45 s [settings-check] Parser with check: src/Centjes/Docs/Site/OptParse.hs:27:7 in centjes-docs-site:Centjes.Docs.Site.OptParse
  98. 25.45 s [settings-check] parser
  99. 25.45 s [settings-check] Setting: src/Centjes/Docs/Site/OptParse.hs:27:7 in centjes-docs-site:Centjes.Docs.Site.OptParse
  100. 25.45 s [settings-check] could not set based on options, no option: ["--config-file"]
  101. 25.45 s [settings-check] set based on env: "/nix/store/vb9vv8cg7xwfa7010fyznaj7b5syrx63-centjes-docs-site-config.yaml"
  102. 25.45 s [settings-check] check
  103. 25.45 s [settings-check] succeeded
  104. 25.45 s [settings-check] Left side succeeded.
  105. 25.45 s [settings-check] check
  106. 25.45 s [settings-check] succeeded
  107. 25.45 s [settings-check] with loaded config
  108. 25.45 s [settings-check] Ap
  109. 25.45 s [settings-check] Ap
  110. 25.45 s [settings-check] Parser with check: without srcLoc
  111. 25.45 s [settings-check] parser
  112. 25.45 s [settings-check] Setting: src/Centjes/Docs/Site/OptParse.hs:29:11 in centjes-docs-site:Centjes.Docs.Site.OptParse
  113. 25.45 s [settings-check] could not set based on options, no option: ["--port"]
  114. 25.45 s [settings-check] could not set based on env vars, no var: [EnvVarSetting {envVarSettingVar = "CENTJES_DOCS_SITE_PORT", envVarSettingAllowPrefix = True}]
  115. 25.45 s [settings-check] set based on config value: Number 8001.0
  116. 25.45 s [settings-check] check
  117. 25.45 s [settings-check] succeeded
  118. 25.45 s [settings-check] Alt
  119. 25.45 s [settings-check] Trying left side.
  120. 25.45 s [settings-check] Parser with check: without srcLoc
  121. 25.45 s [settings-check] parser
  122. 25.45 s [settings-check] Setting: src/Centjes/Docs/Site/OptParse.hs:38:13 in centjes-docs-site:Centjes.Docs.Site.OptParse
  123. 25.45 s [settings-check] could not set based on options, no option: ["--google-analytics-tracking"]
  124. 25.45 s [settings-check] could not set based on env vars, no var: [EnvVarSetting {envVarSettingVar = "CENTJES_DOCS_SITE_GOOGLE_ANALYTICS_TRACKING", envVarSettingAllowPrefix = True}]
  125. 25.45 s [settings-check] could not set based on config value, configured to nothing: ["google-analytics-tracking"]
  126. 25.45 s [settings-check] not found
  127. 25.45 s [settings-check] check
  128. 25.45 s [settings-check] Left side failed, trying right side.
  129. 25.45 s [settings-check] pure value
  130. 25.45 s [settings-check] Alt
  131. 25.45 s [settings-check] Trying left side.
  132. 25.45 s [settings-check] Parser with check: without srcLoc
  133. 25.45 s [settings-check] parser
  134. 25.45 s [settings-check] Setting: src/Centjes/Docs/Site/OptParse.hs:46:13 in centjes-docs-site:Centjes.Docs.Site.OptParse
  135. 25.45 s [settings-check] could not set based on options, no option: ["--google-search-console-verification"]
  136. 25.45 s [settings-check] could not set based on env vars, no var: [EnvVarSetting {envVarSettingVar = "CENTJES_DOCS_SITE_GOOGLE_SEARCH_CONSOLE_VERIFICATION", envVarSettingAllowPrefix = True}]
  137. 25.45 s [settings-check] could not set based on config value, configured to nothing: ["google-search-console-verification"]
  138. 25.45 s [settings-check] not found
  139. 25.45 s [settings-check] check
  140. 25.45 s [settings-check] Left side failed, trying right side.
  141. 25.45 s [settings-check] pure value
  142. 25.46 s Progress: 6 of 17 built (1 building), 5 of 8 downloaded from cache
  143. 25.46 s Downloading cached closure-info from https://cache.staging.nix-ci.com
  144. 25.61 s [post-build-hook] Uploading to cachix cache "centjes": /nix/store/9cdw05a8w5l5a9y4cw65nzhydn68gn0h-settings-check
  145. 25.97 s [post-build-hook] Pushing 1 paths (0 are already present) using zstd to cache centjes ⏳
  146. 25.97 s [post-build-hook]
  147. 26.45 s [post-build-hook] Pushing /nix/store/9cdw05a8w5l5a9y4cw65nzhydn68gn0h-settings-check (144.00 B)
  148. 27.60 s [post-build-hook]
  149. 27.63 s [post-build-hook] All done.
  150. 27.63 s [post-build-hook] Uploading to the NixCI staging cache: /nix/store/9cdw05a8w5l5a9y4cw65nzhydn68gn0h-settings-check
  151. 27.69 s [post-build-hook] copying 1 paths...
  152. 27.69 s [post-build-hook] copying path '/nix/store/9cdw05a8w5l5a9y4cw65nzhydn68gn0h-settings-check' to 'https://cache.staging.nix-ci.com'...
  153. 28.11 s [post-build-hook] copying 1 paths...
  154. 28.11 s [post-build-hook] copying path '/nix/store/0jibmdyh2wvxzsalnr9l2cz806dk90vs-settings-check.drv' to 'https://cache.staging.nix-ci.com'...
  155. 29.03 s Progress: 7 of 18 built, 5 of 8 downloaded from cache (1 downloading)
  156. 29.07 s Building unit-centjes-docs-site-production.service
  157. 29.07 s Progress: 7 of 17 built (1 building), 6 of 8 downloaded from cache
  158. 29.07 s Downloading cached run-nixos-vm from https://cache.staging.nix-ci.com
  159. 29.08 s Progress: 7 of 17 built (1 building), 7 of 8 downloaded from cache
  160. 29.08 s Downloading cached nixos-vm from https://cache.staging.nix-ci.com
  161. 29.09 s Progress: 7 of 17 built (1 building), 8 of 8 downloaded from cache
  162. 29.11 s [post-build-hook] Uploading to cachix cache "centjes": /nix/store/5myggvjhrizr3vx6vwl93gpibvhamy46-unit-centjes-docs-site-production.service
  163. 29.49 s [post-build-hook] Pushing 1 paths (91 are already present) using zstd to cache centjes ⏳
  164. 29.49 s [post-build-hook]
  165. 29.92 s [post-build-hook] Pushing /nix/store/5myggvjhrizr3vx6vwl93gpibvhamy46-unit-centjes-docs-site-production.service (1.62 KiB)
  166. 31.31 s [post-build-hook]
  167. 31.31 s [post-build-hook] All done.
  168. 31.33 s [post-build-hook] Uploading to the NixCI staging cache: /nix/store/5myggvjhrizr3vx6vwl93gpibvhamy46-unit-centjes-docs-site-production.service
  169. 31.57 s [post-build-hook] copying 1 paths...
  170. 31.57 s [post-build-hook] copying path '/nix/store/5myggvjhrizr3vx6vwl93gpibvhamy46-unit-centjes-docs-site-production.service' to 'https://cache.staging.nix-ci.com'...
  171. 32.73 s [post-build-hook] copying 1 paths...
  172. 32.73 s [post-build-hook] copying path '/nix/store/icbby8b58whds806mw1xhhfq2qppx648-unit-centjes-docs-site-production.service.drv' to 'https://cache.staging.nix-ci.com'...
  173. 33.45 s Progress: 8 of 17 built, 8 of 8 downloaded from cache
  174. 33.51 s Building system-units
  175. 34.43 s [post-build-hook] Uploading to cachix cache "centjes": /nix/store/gm05ccdgqiq27lnzsrk2dacdqa84rh9k-system-units
  176. 35.03 s [post-build-hook] Pushing 1 paths (450 are already present) using zstd to cache centjes ⏳
  177. 35.03 s [post-build-hook]
  178. 35.45 s [post-build-hook] Pushing /nix/store/gm05ccdgqiq27lnzsrk2dacdqa84rh9k-system-units (96.09 KiB)
  179. 36.50 s [post-build-hook]
  180. 36.50 s [post-build-hook] All done.
  181. 36.52 s [post-build-hook] Uploading to the NixCI staging cache: /nix/store/gm05ccdgqiq27lnzsrk2dacdqa84rh9k-system-units
  182. 36.76 s [post-build-hook] copying 1 paths...
  183. 36.76 s [post-build-hook] copying path '/nix/store/gm05ccdgqiq27lnzsrk2dacdqa84rh9k-system-units' to 'https://cache.staging.nix-ci.com'...
  184. 38.96 s [post-build-hook] copying 1 paths...
  185. 38.96 s [post-build-hook] copying path '/nix/store/zzzaj9yhi027xg9b5rvc0bxzahf48kvg-system-units.drv' to 'https://cache.staging.nix-ci.com'...
  186. 39.45 s Progress: 9 of 17 built, 8 of 8 downloaded from cache
  187. 39.61 s Building etc
  188. 40.03 s [post-build-hook] Uploading to cachix cache "centjes": /nix/store/6mnn0jla3zip026divvswr9fks04i3r0-etc
  189. 40.49 s [post-build-hook] Pushing 1 paths (546 are already present) using zstd to cache centjes ⏳
  190. 40.49 s [post-build-hook]
  191. 40.99 s [post-build-hook] Pushing /nix/store/6mnn0jla3zip026divvswr9fks04i3r0-etc (31.56 KiB)
  192. 42.07 s [post-build-hook]
  193. 42.07 s [post-build-hook] All done.
  194. 42.08 s [post-build-hook] Uploading to the NixCI staging cache: /nix/store/6mnn0jla3zip026divvswr9fks04i3r0-etc
  195. 42.32 s [post-build-hook] copying 1 paths...
  196. 42.32 s [post-build-hook] copying path '/nix/store/6mnn0jla3zip026divvswr9fks04i3r0-etc' to 'https://cache.staging.nix-ci.com'...
  197. 43.15 s [post-build-hook] copying 1 paths...
  198. 43.15 s [post-build-hook] copying path '/nix/store/alp34pi11balz8fpbv70ws0213mdkwv5-etc.drv' to 'https://cache.staging.nix-ci.com'...
  199. 43.74 s Progress: 10 of 17 built, 8 of 8 downloaded from cache
  200. 43.80 s Building nixos-system-docsserver-test
  201. 43.87 s [post-build-hook] Uploading to cachix cache "centjes": /nix/store/57k706qpi8bkrxj1r9ryxw2ip600h1j1-nixos-system-docsserver-test
  202. 44.30 s [post-build-hook] Pushing 1 paths (568 are already present) using zstd to cache centjes ⏳
  203. 44.30 s [post-build-hook]
  204. 44.78 s [post-build-hook] Pushing /nix/store/57k706qpi8bkrxj1r9ryxw2ip600h1j1-nixos-system-docsserver-test (17.26 KiB)
  205. 45.93 s [post-build-hook]
  206. 45.93 s [post-build-hook] All done.
  207. 45.95 s [post-build-hook] Uploading to the NixCI staging cache: /nix/store/57k706qpi8bkrxj1r9ryxw2ip600h1j1-nixos-system-docsserver-test
  208. 46.31 s [post-build-hook] copying 1 paths...
  209. 46.31 s [post-build-hook] copying path '/nix/store/57k706qpi8bkrxj1r9ryxw2ip600h1j1-nixos-system-docsserver-test' to 'https://cache.staging.nix-ci.com'...
  210. 47.15 s [post-build-hook] copying 1 paths...
  211. 47.15 s [post-build-hook] copying path '/nix/store/9clwvhpd61hqbd7mj1a2n8c5ac0bgwvh-nixos-system-docsserver-test.drv' to 'https://cache.staging.nix-ci.com'...
  212. 47.69 s Progress: 11 of 17 built, 8 of 8 downloaded from cache
  213. 48.12 s Building closure-info
  214. 48.12 s [closure-info] structuredAttrs is enabled
  215. 48.20 s [post-build-hook] Uploading to cachix cache "centjes": /nix/store/hck35cslr8whc3rwfz8bqfcbj6dm5wx6-closure-info
  216. 48.84 s [post-build-hook] Pushing 1 paths (569 are already present) using zstd to cache centjes ⏳
  217. 48.84 s [post-build-hook]
  218. 49.27 s [post-build-hook] Pushing /nix/store/hck35cslr8whc3rwfz8bqfcbj6dm5wx6-closure-info (228.66 KiB)
  219. 50.36 s [post-build-hook]
  220. 50.36 s [post-build-hook] All done.
  221. 50.38 s [post-build-hook] Uploading to the NixCI staging cache: /nix/store/hck35cslr8whc3rwfz8bqfcbj6dm5wx6-closure-info
  222. 50.48 s [post-build-hook] copying 1 paths...
  223. 50.48 s [post-build-hook] copying path '/nix/store/hck35cslr8whc3rwfz8bqfcbj6dm5wx6-closure-info' to 'https://cache.staging.nix-ci.com'...
  224. 51.60 s [post-build-hook] copying 1 paths...
  225. 51.60 s [post-build-hook] copying path '/nix/store/n357ncw4h93bdkxlma0ggf3c48a5vrnk-closure-info.drv' to 'https://cache.staging.nix-ci.com'...
  226. 52.13 s Progress: 12 of 17 built, 8 of 8 downloaded from cache
  227. 52.20 s Building run-nixos-vm
  228. 52.25 s [post-build-hook] Uploading to cachix cache "centjes": /nix/store/b0p1qjbnz1bs24awf9ghkbi1hfknlr03-run-nixos-vm
  229. 52.72 s [post-build-hook] Pushing 1 paths (580 are already present) using zstd to cache centjes ⏳
  230. 52.72 s [post-build-hook]
  231. 53.12 s [post-build-hook] Pushing /nix/store/b0p1qjbnz1bs24awf9ghkbi1hfknlr03-run-nixos-vm (2.94 KiB)
  232. 54.29 s [post-build-hook]
  233. 54.29 s [post-build-hook] All done.
  234. 54.31 s [post-build-hook] Uploading to the NixCI staging cache: /nix/store/b0p1qjbnz1bs24awf9ghkbi1hfknlr03-run-nixos-vm
  235. 54.56 s [post-build-hook] copying 1 paths...
  236. 54.56 s [post-build-hook] copying path '/nix/store/b0p1qjbnz1bs24awf9ghkbi1hfknlr03-run-nixos-vm' to 'https://cache.staging.nix-ci.com'...
  237. 55.54 s [post-build-hook] copying 1 paths...
  238. 55.54 s [post-build-hook] copying path '/nix/store/50fvl4aiq0md53nlg2jihh89r5bkx8xa-run-nixos-vm.drv' to 'https://cache.staging.nix-ci.com'...
  239. 56.21 s Progress: 13 of 17 built, 8 of 8 downloaded from cache
  240. 56.28 s Building nixos-vm
  241. 56.33 s [post-build-hook] Uploading to cachix cache "centjes": /nix/store/cy8x095q90bp2qc5sflx1zniwz71yyq4-nixos-vm
  242. 56.77 s [post-build-hook] Pushing 1 paths (581 are already present) using zstd to cache centjes ⏳
  243. 56.77 s [post-build-hook]
  244. 57.23 s [post-build-hook] Pushing /nix/store/cy8x095q90bp2qc5sflx1zniwz71yyq4-nixos-vm (776.00 B)
  245. 58.25 s [post-build-hook]
  246. 58.25 s [post-build-hook] All done.
  247. 58.27 s [post-build-hook] Uploading to the NixCI staging cache: /nix/store/cy8x095q90bp2qc5sflx1zniwz71yyq4-nixos-vm
  248. 58.36 s [post-build-hook] copying 1 paths...
  249. 58.37 s [post-build-hook] copying path '/nix/store/cy8x095q90bp2qc5sflx1zniwz71yyq4-nixos-vm' to 'https://cache.staging.nix-ci.com'...
  250. 59.39 s [post-build-hook] copying 1 paths...
  251. 59.39 s [post-build-hook] copying path '/nix/store/xsycagshbv4ncfmz5m0m8njanazcvrd0-nixos-vm.drv' to 'https://cache.staging.nix-ci.com'...
  252. 59.91 s Progress: 14 of 17 built, 8 of 8 downloaded from cache
  253. 59.99 s Building nixos-test-driver-centjes-e2e-test
  254. 60.13 s [nixos-test-driver-centjes-e2e-test] Running type check (enable/disable: config.skipTypeCheck)
  255. 60.13 s [nixos-test-driver-centjes-e2e-test] See https://nixos.org/manual/nixos/stable/#test-opt-skipTypeCheck
  256. 66.44 s [nixos-test-driver-centjes-e2e-test] Success: no issues found in 1 source file
  257. 66.83 s [nixos-test-driver-centjes-e2e-test] additionally exposed symbols:
  258. 66.83 s [nixos-test-driver-centjes-e2e-test] ,
  259. 66.83 s [nixos-test-driver-centjes-e2e-test] ,
  260. 66.83 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
  261. 66.90 s [nixos-test-driver-centjes-e2e-test] Linting test script (enable/disable: config.skipLint)
  262. 66.90 s [nixos-test-driver-centjes-e2e-test] See https://nixos.org/manual/nixos/stable/#test-opt-skipLint
  263. 67.94 s [post-build-hook] Uploading to cachix cache "centjes": /nix/store/pjkzvh1y80crx5r4ysjj50n423p33p3r-nixos-test-driver-centjes-e2e-test
  264. 68.58 s [post-build-hook] Pushing 7 paths (627 are already present) using zstd to cache centjes ⏳
  265. 68.58 s [post-build-hook]
  266. 68.99 s [post-build-hook] Pushing /nix/store/001k9r4jinw78ih5x5hxggb82ynlbkqn-nixos-system-client-test (17.23 KiB)
  267. 69.01 s [post-build-hook] Pushing /nix/store/vgn3mdyb33c0sgr7vmvdmbn8fmgayd8s-nixos-vm (768.00 B)
  268. 69.02 s [post-build-hook] Pushing /nix/store/xk5hwfrznx5h2fqw0iarxikhbs2b5dyy-run-nixos-vm (2.91 KiB)
  269. 69.02 s [post-build-hook] Pushing /nix/store/lfrkfcpcchldk57nxjcwkhr8sdgh61sp-etc (31.56 KiB)
  270. 69.04 s [post-build-hook] Pushing /nix/store/jbszgw67xhvsb56njfv0nfvk8g93knzs-hosts (256.00 B)
  271. 69.05 s [post-build-hook] Pushing /nix/store/j7kn31fka8vp5bhm6sw8hv64iyzix7xw-closure-info (226.36 KiB)
  272. 69.17 s [post-build-hook] Pushing /nix/store/pjkzvh1y80crx5r4ysjj50n423p33p3r-nixos-test-driver-centjes-e2e-test (1.84 KiB)
  273. 70.42 s [post-build-hook]
  274. 70.42 s [post-build-hook] All done.
  275. 70.44 s [post-build-hook] Uploading to the NixCI staging cache: /nix/store/pjkzvh1y80crx5r4ysjj50n423p33p3r-nixos-test-driver-centjes-e2e-test
  276. 70.53 s [post-build-hook] copying 1 paths...
  277. 70.53 s [post-build-hook] copying path '/nix/store/pjkzvh1y80crx5r4ysjj50n423p33p3r-nixos-test-driver-centjes-e2e-test' to 'https://cache.staging.nix-ci.com'...
  278. 71.71 s [post-build-hook] copying 2 paths...
  279. 71.72 s [post-build-hook] copying path '/nix/store/ywsn5a3vmrsfbfhrjnf7gvrcxh404gxi-nixos-test-driver-centjes-e2e-test.drv' to 'https://cache.staging.nix-ci.com'...
  280. 71.74 s [post-build-hook] copying path '/nix/store/ls7axvns5fyvyp1wz2y6wgyj19xsq552-system-units.drv' to 'https://cache.staging.nix-ci.com'...
  281. 72.37 s Progress: 15 of 17 built, 8 of 8 downloaded from cache
  282. 72.44 s Building vm-test-run-centjes-e2e-test
  283. 72.80 s [vm-test-run-centjes-e2e-test] Machine state will be reset. To keep it, pass --keep-vm-state
  284. 72.80 s [vm-test-run-centjes-e2e-test] start all VLans
  285. 72.80 s [vm-test-run-centjes-e2e-test] start vlan
  286. 72.80 s [vm-test-run-centjes-e2e-test] running vlan (pid 7; ctl /build/vde1.ctl)
  287. 72.80 s [vm-test-run-centjes-e2e-test] (finished: start all VLans, in 0.01 seconds)
  288. 72.81 s [vm-test-run-centjes-e2e-test] Test will time out and terminate in 3600 seconds
  289. 72.81 s [vm-test-run-centjes-e2e-test] run the VM test script
  290. 72.81 s [vm-test-run-centjes-e2e-test] additionally exposed symbols:
  291. 72.81 s [vm-test-run-centjes-e2e-test] client, docsserver,
  292. 72.81 s [vm-test-run-centjes-e2e-test] vlan1,
  293. 72.81 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
  294. 72.81 s [vm-test-run-centjes-e2e-test] docsserver: starting vm
  295. 72.83 s [vm-test-run-centjes-e2e-test] mke2fs 1.47.3 (8-Jul-2025)
  296. 73.09 s [vm-test-run-centjes-e2e-test] docsserver # Disk image does not exist, creating the virtualisation disk image...
  297. 73.09 s [vm-test-run-centjes-e2e-test] docsserver # Formatting '/build/vm-state-docsserver/tmp.6BdBax3rnb', fmt=raw size=1073741824
  298. 73.09 s [vm-test-run-centjes-e2e-test] docsserver # Discarding device blocks: 0/262144 done
  299. 73.09 s [vm-test-run-centjes-e2e-test] docsserver: QEMU running (pid 9)
  300. 73.09 s [vm-test-run-centjes-e2e-test] docsserver # Creating filesystem with 262144 4k blocks and 65536 inodes
  301. 73.09 s [vm-test-run-centjes-e2e-test] docsserver # Filesystem UUID: f4f559ea-093e-44f8-82ed-bc6d58a2eae9
  302. 73.09 s [vm-test-run-centjes-e2e-test] docsserver # Superblock backups stored on blocks:
  303. 73.09 s [vm-test-run-centjes-e2e-test] client: starting vm
  304. 73.09 s [vm-test-run-centjes-e2e-test] docsserver # 32768, 98304, 163840, 229376
  305. 73.09 s [vm-test-run-centjes-e2e-test] docsserver #
  306. 73.09 s [vm-test-run-centjes-e2e-test] docsserver # Allocating group tables: 0/8 done
  307. 73.09 s [vm-test-run-centjes-e2e-test] docsserver # Writing inode tables: 0/8 done
  308. 73.09 s [vm-test-run-centjes-e2e-test] docsserver # Creating journal (8192 blocks): done
  309. 73.09 s [vm-test-run-centjes-e2e-test] docsserver # Writing superblocks and filesystem accounting information: 0/8 done
  310. 73.09 s [vm-test-run-centjes-e2e-test] docsserver #
  311. 73.09 s [vm-test-run-centjes-e2e-test] docsserver # Virtualisation disk image created.
  312. 73.11 s [vm-test-run-centjes-e2e-test] mke2fs 1.47.3 (8-Jul-2025)
  313. 73.19 s [vm-test-run-centjes-e2e-test] docsserver # c[?7lSeaBIOS (version rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org)
  314. 73.23 s [vm-test-run-centjes-e2e-test] client: QEMU running (pid 31)
  315. 73.23 s [vm-test-run-centjes-e2e-test] client # Disk image does not exist, creating the virtualisation disk image...
  316. 73.23 s [vm-test-run-centjes-e2e-test] docsserver: waiting for unit default.target
  317. 73.23 s [vm-test-run-centjes-e2e-test] client # Formatting '/build/vm-state-client/tmp.YqZll2PZu1', fmt=raw size=1073741824
  318. 73.23 s [vm-test-run-centjes-e2e-test] docsserver: waiting for the VM to finish booting
  319. 73.23 s [vm-test-run-centjes-e2e-test] client # Discarding device blocks: 0/262144 done
  320. 73.23 s [vm-test-run-centjes-e2e-test] client # Creating filesystem with 262144 4k blocks and 65536 inodes
  321. 73.23 s [vm-test-run-centjes-e2e-test] client # Filesystem UUID: 6a88f2e0-c70f-4f2f-9d3a-7ec2a70745ff
  322. 73.23 s [vm-test-run-centjes-e2e-test] client # Superblock backups stored on blocks:
  323. 73.23 s [vm-test-run-centjes-e2e-test] client # 32768, 98304, 163840, 229376
  324. 73.23 s [vm-test-run-centjes-e2e-test] client #
  325. 73.23 s [vm-test-run-centjes-e2e-test] client # Allocating group tables: 0/8 done
  326. 73.23 s [vm-test-run-centjes-e2e-test] client # Writing inode tables: 0/8 done
  327. 73.23 s [vm-test-run-centjes-e2e-test] client # Creating journal (8192 blocks): done
  328. 73.23 s [vm-test-run-centjes-e2e-test] client # Writing superblocks and filesystem accounting information: 0/8 done
  329. 73.23 s [vm-test-run-centjes-e2e-test] client #
  330. 73.23 s [vm-test-run-centjes-e2e-test] client # Virtualisation disk image created.
  331. 73.29 s [vm-test-run-centjes-e2e-test] docsserver #
  332. 73.29 s [vm-test-run-centjes-e2e-test] docsserver #
  333. 73.30 s [vm-test-run-centjes-e2e-test] docsserver # iPXE (http://ipxe.org) 00:03.0 CA00 PCI2.10 PnP PMM+3EFD1920+3EF31920 CA00
  334. 73.31 s [vm-test-run-centjes-e2e-test] docsserver # Press Ctrl-B to configure iPXE (PCI 00:03.0)...
  335. 73.31 s [vm-test-run-centjes-e2e-test] docsserver #
  336. 73.31 s [vm-test-run-centjes-e2e-test] docsserver #
  337. 73.31 s [vm-test-run-centjes-e2e-test] docsserver #
  338. 73.31 s [vm-test-run-centjes-e2e-test] docsserver #
  339. 73.32 s [vm-test-run-centjes-e2e-test] docsserver # iPXE (http://ipxe.org) 00:09.0 CB00 PCI2.10 PnP PMM 3EFD1920 3EF31920 CB00
  340. 73.34 s [vm-test-run-centjes-e2e-test] docsserver # Press Ctrl-B to configure iPXE (PCI 00:09.0)...
  341. 73.34 s [vm-test-run-centjes-e2e-test] docsserver #
  342. 73.34 s [vm-test-run-centjes-e2e-test] docsserver #
  343. 73.35 s [vm-test-run-centjes-e2e-test] docsserver # Booting from ROM...
  344. 73.35 s [vm-test-run-centjes-e2e-test] docsserver # Probing EDD (edd=off to disable)... ok
  345. 73.38 s [vm-test-run-centjes-e2e-test] client # c[?7lSeaBIOS (version rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org)
  346. 73.44 s [vm-test-run-centjes-e2e-test] client #
  347. 73.44 s [vm-test-run-centjes-e2e-test] client #
  348. 73.44 s [vm-test-run-centjes-e2e-test] client # iPXE (http://ipxe.org) 00:03.0 CA00 PCI2.10 PnP PMM+3EFD1920+3EF31920 CA00
  349. 73.46 s [vm-test-run-centjes-e2e-test] client # Press Ctrl-B to configure iPXE (PCI 00:03.0)...
  350. 73.46 s [vm-test-run-centjes-e2e-test] client #
  351. 73.46 s [vm-test-run-centjes-e2e-test] client #
  352. 73.46 s [vm-test-run-centjes-e2e-test] client #
  353. 73.46 s [vm-test-run-centjes-e2e-test] client #
  354. 73.46 s [vm-test-run-centjes-e2e-test] client # iPXE (http://ipxe.org) 00:09.0 CB00 PCI2.10 PnP PMM 3EFD1920 3EF31920 CB00
  355. 73.48 s [vm-test-run-centjes-e2e-test] client # Press Ctrl-B to configure iPXE (PCI 00:09.0)...
  356. 73.48 s [vm-test-run-centjes-e2e-test] client #
  357. 73.48 s [vm-test-run-centjes-e2e-test] client #
  358. 73.49 s [vm-test-run-centjes-e2e-test] client # Booting from ROM...
  359. 73.69 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
  360. 73.70 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/57k706qpi8bkrxj1r9ryxw2ip600h1j1-nixos-system-docsserver-test/init regInfo=/nix/store/hck35cslr8whc3rwfz8bqfcbj6dm5wx6-closure-info/registration console=ttyS0,115200n8 console=tty0
  361. 73.70 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-provided physical RAM map:
  362. 73.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
  363. 73.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
  364. 73.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
  365. 73.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000003ffdafff] usable
  366. 73.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x000000003ffdb000-0x000000003fffffff] reserved
  367. 73.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
  368. 73.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
  369. 73.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x000000fd00000000-0x000000ffffffffff] reserved
  370. 73.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] NX (Execute Disable) protection: active
  371. 73.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] APIC: Static calls initialized
  372. 73.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] SMBIOS 2.8 present.
  373. 73.73 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
  374. 73.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] DMI: Memory slots populated: 1/1
  375. 73.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] Hypervisor detected: KVM
  376. 73.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
  377. 73.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
  378. 73.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] kvm-clock: using sched offset of 443045971 cycles
  379. 73.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000002] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
  380. 73.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000005] tsc: Detected 3399.998 MHz processor
  381. 73.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000733] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
  382. 73.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000971] MTRR map: 4 entries (3 fixed + 1 variable; max 19), built from 8 variable MTRRs
  383. 73.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000979] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT
  384. 73.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002902] found SMP MP-table at [mem 0x000f5470-0x000f547f]
  385. 73.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002914] Using GB pages for direct mapping
  386. 73.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002982] RAMDISK: [mem 0x3f3cd000-0x3ffcffff]
  387. 73.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003008] ACPI: Early table checksum verification disabled
  388. 73.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003011] ACPI: RSDP 0x00000000000F5290 000014 (v00 BOCHS )
  389. 73.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003015] ACPI: RSDT 0x000000003FFE23D9 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  390. 73.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003019] ACPI: FACP 0x000000003FFE228D 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  391. 73.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003022] ACPI: DSDT 0x000000003FFE0040 00224D (v01 BOCHS BXPC 00000001 BXPC 00000001)
  392. 73.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003024] ACPI: FACS 0x000000003FFE0000 000040
  393. 73.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003025] ACPI: APIC 0x000000003FFE2301 000078 (v03 BOCHS BXPC 00000001 BXPC 00000001)
  394. 73.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003027] ACPI: HPET 0x000000003FFE2379 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  395. 73.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003028] ACPI: WAET 0x000000003FFE23B1 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  396. 73.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003029] ACPI: Reserving FACP table memory at [mem 0x3ffe228d-0x3ffe2300]
  397. 73.79 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003030] ACPI: Reserving DSDT table memory at [mem 0x3ffe0040-0x3ffe228c]
  398. 73.79 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003031] ACPI: Reserving FACS table memory at [mem 0x3ffe0000-0x3ffe003f]
  399. 73.79 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003031] ACPI: Reserving APIC table memory at [mem 0x3ffe2301-0x3ffe2378]
  400. 73.79 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003032] ACPI: Reserving HPET table memory at [mem 0x3ffe2379-0x3ffe23b0]
  401. 73.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003032] ACPI: Reserving WAET table memory at [mem 0x3ffe23b1-0x3ffe23d8]
  402. 73.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003881] No NUMA configuration found
  403. 73.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003882] Faking a node at [mem 0x0000000000000000-0x000000003ffdafff]
  404. 73.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003884] NODE_DATA(0) allocated [mem 0x3ffd58c0-0x3ffdadff]
  405. 73.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003900] Zone ranges:
  406. 73.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003900] DMA [mem 0x0000000000001000-0x0000000000ffffff]
  407. 73.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003902] DMA32 [mem 0x0000000001000000-0x000000003ffdafff]
  408. 73.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003902] Normal empty
  409. 73.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003903] Device empty
  410. 73.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003904] Movable zone start for each node
  411. 73.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003904] Early memory node ranges
  412. 73.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003904] node 0: [mem 0x0000000000001000-0x000000000009efff]
  413. 73.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003905] node 0: [mem 0x0000000000100000-0x000000003ffdafff]
  414. 73.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003907] Initmem setup node 0 [mem 0x0000000000001000-0x000000003ffdafff]
  415. 73.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.004092] On node 0, zone DMA: 1 pages in unavailable ranges
  416. 73.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.004105] On node 0, zone DMA: 97 pages in unavailable ranges
  417. 73.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.006082] On node 0, zone DMA32: 37 pages in unavailable ranges
  418. 73.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007840] ACPI: PM-Timer IO Port: 0x608
  419. 73.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007871] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
  420. 73.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007966] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
  421. 73.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007968] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
  422. 73.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007969] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
  423. 73.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007970] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
  424. 73.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007971] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
  425. 73.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007972] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
  426. 73.84 s [vm-test-run-centjes-e2e-test] client # Probing EDD (edd=off to disable)... oc[?7lk[ 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
  427. 73.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007974] ACPI: Using ACPI (MADT) for SMP configuration information
  428. 73.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007974] ACPI: HPET id: 0x8086a201 base: 0xfed00000
  429. 73.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007979] TSC deadline timer available
  430. 73.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007983] CPU topo: Max. logical packages: 1
  431. 73.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007983] CPU topo: Max. logical dies: 1
  432. 73.85 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
  433. 73.86 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-provided physical RAM map:
  434. 73.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007984] CPU topo: Max. dies per package: 1
  435. 73.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007987] CPU topo: Max. threads per core: 1
  436. 73.86 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
  437. 73.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007987] CPU topo: Num. cores per package: 1
  438. 73.86 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
  439. 73.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007988] CPU topo: Num. threads per package: 1
  440. 73.86 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
  441. 73.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007988] CPU topo: Allowing 1 present CPUs plus 0 hotplug CPUs
  442. 73.87 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000003ffdafff] usable
  443. 73.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008021] kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write()
  444. 73.87 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x000000003ffdb000-0x000000003fffffff] reserved
  445. 73.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008084] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]
  446. 73.87 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
  447. 73.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008085] PM: hibernation: Registered nosave memory: [mem 0x0009f000-0x000fffff]
  448. 73.87 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
  449. 73.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008086] [mem 0x40000000-0xfeffbfff] available for PCI devices
  450. 73.88 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x000000fd00000000-0x000000ffffffffff] reserved
  451. 73.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008087] Booting paravirtualized kernel on KVM
  452. 73.88 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] NX (Execute Disable) protection: active
  453. 73.88 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] APIC: Static calls initialized
  454. 73.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.008089] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
  455. 73.88 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] SMBIOS 2.8 present.
  456. 73.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.011747] setup_percpu: NR_CPUS:384 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1
  457. 73.88 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
  458. 73.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.012057] percpu: Embedded 116 pages/cpu s294912 r65536 d114688 u2097152
  459. 73.88 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] DMI: Memory slots populated: 1/1
  460. 73.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.012141] kvm-guest: PV spinlocks disabled, single CPU
  461. 73.89 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] Hypervisor detected: KVM
  462. 73.89 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
  463. 73.89 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
  464. 73.89 s [vm-test-run-centjes-e2e-test] client # [ 0.000001] kvm-clock: using sched offset of 455943029 cycles
  465. 73.90 s [vm-test-run-centjes-e2e-test] client # [ 0.000002] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
  466. 73.90 s [vm-test-run-centjes-e2e-test] client # [ 0.000006] tsc: Detected 3399.998 MHz processor
  467. 73.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.012142] 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/57k706qpi8bkrxj1r9ryxw2ip600h1j1-nixos-system-docsserver-test/init regInfo=/nix/store/hck35cslr8whc3rwfz8bqfcbj6dm5wx6-closure-info/registration console=ttyS0,115200n8 console=tty0
  468. 73.90 s [vm-test-run-centjes-e2e-test] client # [ 0.000765] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
  469. 73.90 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
  470. 73.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.012220] Unknown kernel command line parameters "regInfo=/nix/store/hck35cslr8whc3rwfz8bqfcbj6dm5wx6-closure-info/registration", will be passed to user space.
  471. 73.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.012235] random: crng init done
  472. 73.90 s [vm-test-run-centjes-e2e-test] client # [ 0.000999] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT
  473. 73.91 s [vm-test-run-centjes-e2e-test] client # [ 0.002924] found SMP MP-table at [mem 0x000f5470-0x000f547f]
  474. 73.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.012303] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
  475. 73.91 s [vm-test-run-centjes-e2e-test] client # [ 0.002936] Using GB pages for direct mapping
  476. 73.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.012338] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)
  477. 73.91 s [vm-test-run-centjes-e2e-test] client # [ 0.003067] RAMDISK: [mem 0x3f3cd000-0x3ffcffff]
  478. 73.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.012379] Fallback order for Node 0: 0
  479. 73.91 s [vm-test-run-centjes-e2e-test] client # [ 0.003092] ACPI: Early table checksum verification disabled
  480. 73.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.012382] Built 1 zonelists, mobility grouping on. Total pages: 262009
  481. 73.91 s [vm-test-run-centjes-e2e-test] client # [ 0.003095] ACPI: RSDP 0x00000000000F5290 000014 (v00 BOCHS )
  482. 73.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.012383] Policy zone: DMA32
  483. 73.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.012622] mem auto-init: stack:all(zero), heap alloc:on, heap free:off
  484. 73.92 s [vm-test-run-centjes-e2e-test] client # [ 0.003098] ACPI: RSDT 0x000000003FFE23D9 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  485. 73.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.015220] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
  486. 73.92 s [vm-test-run-centjes-e2e-test] client # [ 0.003102] ACPI: FACP 0x000000003FFE228D 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  487. 73.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.015509] allocated 2097152 bytes of page_ext
  488. 73.92 s [vm-test-run-centjes-e2e-test] client # [ 0.003105] ACPI: DSDT 0x000000003FFE0040 00224D (v01 BOCHS BXPC 00000001 BXPC 00000001)
  489. 73.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.015524] ftrace: allocating 46208 entries in 181 pages
  490. 73.92 s [vm-test-run-centjes-e2e-test] client # [ 0.003107] ACPI: FACS 0x000000003FFE0000 000040
  491. 73.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.023916] ftrace: allocated 181 pages with 5 groups
  492. 73.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.024677] Dynamic Preempt: voluntary
  493. 73.93 s [vm-test-run-centjes-e2e-test] client # [ 0.003108] ACPI: APIC 0x000000003FFE2301 000078 (v03 BOCHS BXPC 00000001 BXPC 00000001)
  494. 73.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.024967] rcu: Preemptible hierarchical RCU implementation.
  495. 73.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.024967] rcu: RCU event tracing is enabled.
  496. 73.93 s [vm-test-run-centjes-e2e-test] client # [ 0.003110] ACPI: HPET 0x000000003FFE2379 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  497. 73.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.024968] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1.
  498. 73.93 s [vm-test-run-centjes-e2e-test] client # [ 0.003111] ACPI: WAET 0x000000003FFE23B1 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  499. 73.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.024969] Trampoline variant of Tasks RCU enabled.
  500. 73.94 s [vm-test-run-centjes-e2e-test] client # [ 0.003112] ACPI: Reserving FACP table memory at [mem 0x3ffe228d-0x3ffe2300]
  501. 73.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.024969] Rude variant of Tasks RCU enabled.
  502. 73.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.024970] Tracing variant of Tasks RCU enabled.
  503. 73.94 s [vm-test-run-centjes-e2e-test] client # [ 0.003113] ACPI: Reserving DSDT table memory at [mem 0x3ffe0040-0x3ffe228c]
  504. 73.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.024970] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.
  505. 73.94 s [vm-test-run-centjes-e2e-test] client # [ 0.003114] ACPI: Reserving FACS table memory at [mem 0x3ffe0000-0x3ffe003f]
  506. 73.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.024971] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
  507. 73.94 s [vm-test-run-centjes-e2e-test] client # [ 0.003114] ACPI: Reserving APIC table memory at [mem 0x3ffe2301-0x3ffe2378]
  508. 73.95 s [vm-test-run-centjes-e2e-test] client # [ 0.003115] ACPI: Reserving HPET table memory at [mem 0x3ffe2379-0x3ffe23b0]
  509. 73.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.024980] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  510. 73.95 s [vm-test-run-centjes-e2e-test] client # [ 0.003115] ACPI: Reserving WAET table memory at [mem 0x3ffe23b1-0x3ffe23d8]
  511. 73.95 s [vm-test-run-centjes-e2e-test] client # [ 0.003940] No NUMA configuration found
  512. 73.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.024981] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  513. 73.95 s [vm-test-run-centjes-e2e-test] client # [ 0.003941] Faking a node at [mem 0x0000000000000000-0x000000003ffdafff]
  514. 73.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.024983] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  515. 73.95 s [vm-test-run-centjes-e2e-test] client # [ 0.003943] NODE_DATA(0) allocated [mem 0x3ffd58c0-0x3ffdadff]
  516. 73.95 s [vm-test-run-centjes-e2e-test] client # [ 0.003960] Zone ranges:
  517. 73.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.028814] NR_IRQS: 24832, nr_irqs: 256, preallocated irqs: 16
  518. 73.96 s [vm-test-run-centjes-e2e-test] client # [ 0.003960] DMA [mem 0x0000000000001000-0x0000000000ffffff]
  519. 73.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.029111] rcu: srcu_init: Setting srcu_struct sizes based on contention.
  520. 73.96 s [vm-test-run-centjes-e2e-test] client # [ 0.003961] DMA32 [mem 0x0000000001000000-0x000000003ffdafff]
  521. 73.96 s [vm-test-run-centjes-e2e-test] client # [ 0.003962] Normal empty
  522. 73.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.029198] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)
  523. 73.96 s [vm-test-run-centjes-e2e-test] client # [ 0.003963] Device empty
  524. 73.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.043717] Console: colour VGA+ 80x25
  525. 73.96 s [vm-test-run-centjes-e2e-test] client # [ 0.003963] Movable zone start for each node
  526. 73.96 s [vm-test-run-centjes-e2e-test] client # [ 0.003964] Early memory node ranges
  527. 73.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.043723] printk: legacy console [tty0] enabled
  528. 73.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.158088] printk: legacy console [ttyS0] enabled
  529. 73.97 s [vm-test-run-centjes-e2e-test] client # [ 0.003964] node 0: [mem 0x0000000000001000-0x000000000009efff]
  530. 73.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.438058] ACPI: Core revision 20240827
  531. 73.97 s [vm-test-run-centjes-e2e-test] client # [ 0.003965] node 0: [mem 0x0000000000100000-0x000000003ffdafff]
  532. 73.97 s [vm-test-run-centjes-e2e-test] client # [ 0.003966] Initmem setup node 0 [mem 0x0000000000001000-0x000000003ffdafff]
  533. 73.97 s [vm-test-run-centjes-e2e-test] client # [ 0.004173] On node 0, zone DMA: 1 pages in unavailable ranges
  534. 73.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.440602] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
  535. 73.97 s [vm-test-run-centjes-e2e-test] client # [ 0.004187] On node 0, zone DMA: 97 pages in unavailable ranges
  536. 73.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.445438] APIC: Switch to symmetric I/O mode setup
  537. 73.98 s [vm-test-run-centjes-e2e-test] client # [ 0.006219] On node 0, zone DMA32: 37 pages in unavailable ranges
  538. 73.98 s [vm-test-run-centjes-e2e-test] client # [ 0.007936] ACPI: PM-Timer IO Port: 0x608
  539. 73.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.449012] x2apic enabled
  540. 73.98 s [vm-test-run-centjes-e2e-test] client # [ 0.007964] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
  541. 73.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.451661] APIC: Switched APIC routing to: physical x2apic
  542. 73.98 s [vm-test-run-centjes-e2e-test] client # [ 0.008079] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
  543. 73.98 s [vm-test-run-centjes-e2e-test] client # [ 0.008082] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
  544. 73.99 s [vm-test-run-centjes-e2e-test] client # [ 0.008083] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
  545. 73.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.458934] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
  546. 73.99 s [vm-test-run-centjes-e2e-test] client # [ 0.008084] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
  547. 73.99 s [vm-test-run-centjes-e2e-test] client # [ 0.008085] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
  548. 73.99 s [vm-test-run-centjes-e2e-test] client # [ 0.008086] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
  549. 74.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.462133] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x31024cfe468, max_idle_ns: 440795307017 ns
  550. 74.00 s [vm-test-run-centjes-e2e-test] client # [ 0.008088] ACPI: Using ACPI (MADT) for SMP configuration information
  551. 74.00 s [vm-test-run-centjes-e2e-test] client # [ 0.008088] ACPI: HPET id: 0x8086a201 base: 0xfed00000
  552. 74.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.467540] Calibrating delay loop (skipped) preset value.. 6799.99 BogoMIPS (lpj=3399998)
  553. 74.00 s [vm-test-run-centjes-e2e-test] client # [ 0.008092] TSC deadline timer available
  554. 74.00 s [vm-test-run-centjes-e2e-test] client # [ 0.008096] CPU topo: Max. logical packages: 1
  555. 74.00 s [vm-test-run-centjes-e2e-test] client # [ 0.008097] CPU topo: Max. logical dies: 1
  556. 74.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.470751] x86/cpu: User Mode Instruction Prevention (UMIP) activated
  557. 74.00 s [vm-test-run-centjes-e2e-test] client # [ 0.008097] CPU topo: Max. dies per package: 1
  558. 74.01 s [vm-test-run-centjes-e2e-test] client # [ 0.008100] CPU topo: Max. threads per core: 1
  559. 74.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.473902] Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127
  560. 74.01 s [vm-test-run-centjes-e2e-test] client # [ 0.008101] CPU topo: Num. cores per package: 1
  561. 74.01 s [vm-test-run-centjes-e2e-test] client # [ 0.008101] CPU topo: Num. threads per package: 1
  562. 74.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.475539] Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0
  563. 74.01 s [vm-test-run-centjes-e2e-test] client # [ 0.008101] CPU topo: Allowing 1 present CPUs plus 0 hotplug CPUs
  564. 74.02 s [vm-test-run-centjes-e2e-test] client # [ 0.008134] kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write()
  565. 74.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.477552] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
  566. 74.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.479539] Spectre V2 : Mitigation: Retpolines
  567. 74.02 s [vm-test-run-centjes-e2e-test] client # [ 0.008193] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]
  568. 74.02 s [vm-test-run-centjes-e2e-test] client # [ 0.008194] PM: hibernation: Registered nosave memory: [mem 0x0009f000-0x000fffff]
  569. 74.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.481538] Spectre V2 : Spectre v2 / SpectreRSB: Filling RSB on context switch and VMEXIT
  570. 74.02 s [vm-test-run-centjes-e2e-test] client # [ 0.008196] [mem 0x40000000-0xfeffbfff] available for PCI devices
  571. 74.03 s [vm-test-run-centjes-e2e-test] client # [ 0.008196] Booting paravirtualized kernel on KVM
  572. 74.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.483538] Spectre V2 : Enabling Restricted Speculation for firmware calls
  573. 74.03 s [vm-test-run-centjes-e2e-test] client # [ 0.008199] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
  574. 74.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.485542] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
  575. 74.03 s [vm-test-run-centjes-e2e-test] client # [ 0.011656] setup_percpu: NR_CPUS:384 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1
  576. 74.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.487539] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl
  577. 74.03 s [vm-test-run-centjes-e2e-test] client # [ 0.011969] percpu: Embedded 116 pages/cpu s294912 r65536 d114688 u2097152
  578. 74.04 s [vm-test-run-centjes-e2e-test] client # [ 0.012080] kvm-guest: PV spinlocks disabled, single CPU
  579. 74.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.489538] active return thunk: srso_alias_return_thunk
  580. 74.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.491538] Speculative Return Stack Overflow: Mitigation: Safe RET
  581. 74.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.492538] Transient Scheduler Attacks: Forcing mitigation on in a VM
  582. 74.05 s [vm-test-run-centjes-e2e-test] client # [ 0.012083] 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
  583. 74.05 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.494538] Transient Scheduler Attacks: Vulnerable: Clear CPU buffers attempted, no microcode
  584. 74.05 s [vm-test-run-centjes-e2e-test] client # [ 0.012159] Unknown kernel command line parameters "regInfo=/nix/store/j7kn31fka8vp5bhm6sw8hv64iyzix7xw-closure-info/registration", will be passed to user space.
  585. 74.05 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.497585] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
  586. 74.05 s [vm-test-run-centjes-e2e-test] client # [ 0.012173] random: crng init done
  587. 74.06 s [vm-test-run-centjes-e2e-test] client # [ 0.012228] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
  588. 74.06 s [vm-test-run-centjes-e2e-test] client # [ 0.012259] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)
  589. 74.06 s [vm-test-run-centjes-e2e-test] client # [ 0.012299] Fallback order for Node 0: 0
  590. 74.06 s [vm-test-run-centjes-e2e-test] client # [ 0.012301] Built 1 zonelists, mobility grouping on. Total pages: 262009
  591. 74.06 s [vm-test-run-centjes-e2e-test] client # [ 0.012302] Policy zone: DMA32
  592. 74.07 s [vm-test-run-centjes-e2e-test] client # [ 0.012543] mem auto-init: stack:all(zero), heap alloc:on, heap free:off
  593. 74.07 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.499538] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
  594. 74.07 s [vm-test-run-centjes-e2e-test] client # [ 0.014955] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
  595. 74.07 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.501538] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
  596. 74.07 s [vm-test-run-centjes-e2e-test] client # [ 0.015221] allocated 2097152 bytes of page_ext
  597. 74.07 s [vm-test-run-centjes-e2e-test] client # [ 0.015235] ftrace: allocating 46208 entries in 181 pages
  598. 74.07 s [vm-test-run-centjes-e2e-test] client # [ 0.023315] ftrace: allocated 181 pages with 5 groups
  599. 74.07 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.503538] x86/fpu: Supporting XSAVE feature 0x200: 'Protection Keys User registers'
  600. 74.07 s [vm-test-run-centjes-e2e-test] client # [ 0.024062] Dynamic Preempt: voluntary
  601. 74.08 s [vm-test-run-centjes-e2e-test] client # [ 0.024357] rcu: Preemptible hierarchical RCU implementation.
  602. 74.08 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.505538] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256
  603. 74.08 s [vm-test-run-centjes-e2e-test] client # [ 0.024358] rcu: RCU event tracing is enabled.
  604. 74.08 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.507538] x86/fpu: xstate_offset[9]: 832, xstate_sizes[9]: 8
  605. 74.08 s [vm-test-run-centjes-e2e-test] client # [ 0.024359] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1.
  606. 74.08 s [vm-test-run-centjes-e2e-test] client # [ 0.024361] Trampoline variant of Tasks RCU enabled.
  607. 74.08 s [vm-test-run-centjes-e2e-test] client # [ 0.024361] Rude variant of Tasks RCU enabled.
  608. 74.08 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.509538] x86/fpu: Enabled xstate features 0x207, context size is 840 bytes, using 'compacted' format.
  609. 74.08 s [vm-test-run-centjes-e2e-test] client # [ 0.024361] Tracing variant of Tasks RCU enabled.
  610. 74.09 s [vm-test-run-centjes-e2e-test] client # [ 0.024362] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.
  611. 74.09 s [vm-test-run-centjes-e2e-test] client # [ 0.024363] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
  612. 74.09 s [vm-test-run-centjes-e2e-test] client # [ 0.024372] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  613. 74.10 s [vm-test-run-centjes-e2e-test] client # [ 0.024374] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  614. 74.10 s [vm-test-run-centjes-e2e-test] client # [ 0.024374] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  615. 74.10 s [vm-test-run-centjes-e2e-test] client # [ 0.028145] NR_IRQS: 24832, nr_irqs: 256, preallocated irqs: 16
  616. 74.10 s [vm-test-run-centjes-e2e-test] client # [ 0.028403] rcu: srcu_init: Setting srcu_struct sizes based on contention.
  617. 74.11 s [vm-test-run-centjes-e2e-test] client # [ 0.028486] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)
  618. 74.11 s [vm-test-run-centjes-e2e-test] client # [ 0.043149] Console: colour VGA+ 80x25
  619. 74.11 s [vm-test-run-centjes-e2e-test] client # [ 0.043155] printk: legacy console [tty0] enabled
  620. 74.11 s [vm-test-run-centjes-e2e-test] client # [ 0.157579] printk: legacy console [ttyS0] enabled
  621. 74.11 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.538445] Freeing SMP alternatives memory: 40K
  622. 74.11 s [vm-test-run-centjes-e2e-test] client # [ 0.430093] ACPI: Core revision 20240827
  623. 74.11 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.539540] pid_max: default: 32768 minimum: 301
  624. 74.12 s [vm-test-run-centjes-e2e-test] client # [ 0.432529] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
  625. 74.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.541599] LSM: initializing lsm=capability,landlock,yama,bpf
  626. 74.12 s [vm-test-run-centjes-e2e-test] client # [ 0.437174] APIC: Switch to symmetric I/O mode setup
  627. 74.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.543622] landlock: Up and running.
  628. 74.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.544538] Yama: becoming mindful.
  629. 74.12 s [vm-test-run-centjes-e2e-test] client # [ 0.440660] x2apic enabled
  630. 74.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.545758] LSM support for eBPF active
  631. 74.13 s [vm-test-run-centjes-e2e-test] client # [ 0.443212] APIC: Switched APIC routing to: physical x2apic
  632. 74.13 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.546565] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
  633. 74.13 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.548541] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
  634. 74.13 s [vm-test-run-centjes-e2e-test] client # [ 0.450077] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
  635. 74.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.551024] smpboot: CPU0: AMD Ryzen 9 5950X 16-Core Processor (family: 0x19, model: 0x21, stepping: 0x0)
  636. 74.14 s [vm-test-run-centjes-e2e-test] client # [ 0.453164] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x31024cfe468, max_idle_ns: 440795307017 ns
  637. 74.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.552820] Performance Events: Fam17h+ core perfctr, AMD PMU driver.
  638. 74.14 s [vm-test-run-centjes-e2e-test] client # [ 0.458324] Calibrating delay loop (skipped) preset value.. 6799.99 BogoMIPS (lpj=3399998)
  639. 74.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.554555] ... version: 0
  640. 74.15 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.555547] ... bit width: 48
  641. 74.15 s [vm-test-run-centjes-e2e-test] client # [ 0.460924] x86/cpu: User Mode Instruction Prevention (UMIP) activated
  642. 74.15 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.556547] ... generic registers: 6
  643. 74.15 s [vm-test-run-centjes-e2e-test] client # [ 0.462772] Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127
  644. 74.15 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.557547] ... value mask: 0000ffffffffffff
  645. 74.15 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.558548] ... max period: 00007fffffffffff
  646. 74.15 s [vm-test-run-centjes-e2e-test] client # [ 0.464321] Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0
  647. 74.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.559547] ... fixed-purpose events: 0
  648. 74.16 s [vm-test-run-centjes-e2e-test] client # [ 0.466336] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
  649. 74.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.560547] ... event mask: 000000000000003f
  650. 74.16 s [vm-test-run-centjes-e2e-test] client # [ 0.468323] Spectre V2 : Mitigation: Retpolines
  651. 74.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.561652] signal: max sigframe size: 3376
  652. 74.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.562601] rcu: Hierarchical SRCU implementation.
  653. 74.16 s [vm-test-run-centjes-e2e-test] client # [ 0.469321] Spectre V2 : Spectre v2 / SpectreRSB: Filling RSB on context switch and VMEXIT
  654. 74.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.563547] rcu: Max phase no-delay instances is 400.
  655. 74.17 s [vm-test-run-centjes-e2e-test] client # [ 0.471322] Spectre V2 : Enabling Restricted Speculation for firmware calls
  656. 74.17 s [vm-test-run-centjes-e2e-test] client # [ 0.473326] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
  657. 74.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.568099] smp: Bringing up secondary CPUs ...
  658. 74.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.569576] smp: Brought up 1 node, 1 CPU
  659. 74.18 s [vm-test-run-centjes-e2e-test] client # [ 0.475322] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl
  660. 74.18 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.570549] smpboot: Total of 1 processors activated (6799.99 BogoMIPS)
  661. 74.18 s [vm-test-run-centjes-e2e-test] client # [ 0.477322] active return thunk: srso_alias_return_thunk
  662. 74.18 s [vm-test-run-centjes-e2e-test] client # [ 0.478322] Speculative Return Stack Overflow: Mitigation: Safe RET
  663. 74.18 s [vm-test-run-centjes-e2e-test] client # [ 0.480321] Transient Scheduler Attacks: Forcing mitigation on in a VM
  664. 74.18 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.571915] Memory: 962108K/1048036K available (16384K kernel code, 2645K rwdata, 12580K rodata, 3408K init, 3360K bss, 78836K reserved, 0K cma-reserved)
  665. 74.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.573698] devtmpfs: initialized
  666. 74.19 s [vm-test-run-centjes-e2e-test] client # [ 0.481321] Transient Scheduler Attacks: Vulnerable: Clear CPU buffers attempted, no microcode
  667. 74.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.574611] x86/mm: Memory block size: 128MB
  668. 74.19 s [vm-test-run-centjes-e2e-test] client # [ 0.483412] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
  669. 74.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.576019] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
  670. 74.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.577550] futex hash table entries: 256 (order: 2, 16384 bytes, linear)
  671. 74.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.578632] pinctrl core: initialized pinctrl subsystem
  672. 74.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.579891] PM: RTC time: 20:24:33, date: 2026-06-01
  673. 74.21 s [vm-test-run-centjes-e2e-test] client # [ 0.485330] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
  674. 74.21 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.582289] NET: Registered PF_NETLINK/PF_ROUTE protocol family
  675. 74.21 s [vm-test-run-centjes-e2e-test] client # [ 0.487324] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
  676. 74.21 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.583713] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations
  677. 74.21 s [vm-test-run-centjes-e2e-test] client # [ 0.489322] x86/fpu: Supporting XSAVE feature 0x200: 'Protection Keys User registers'
  678. 74.22 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.585558] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
  679. 74.22 s [vm-test-run-centjes-e2e-test] client # [ 0.491322] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256
  680. 74.22 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.587558] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
  681. 74.22 s [vm-test-run-centjes-e2e-test] client # [ 0.493321] x86/fpu: xstate_offset[9]: 832, xstate_sizes[9]: 8
  682. 74.22 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.589568] audit: initializing netlink subsys (disabled)
  683. 74.22 s [vm-test-run-centjes-e2e-test] client # [ 0.495321] x86/fpu: Enabled xstate features 0x207, context size is 840 bytes, using 'compacted' format.
  684. 74.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.590621] audit: type=2000 audit(1780345472.627:1): state=initialized audit_enabled=0 res=1
  685. 74.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.592733] thermal_sys: Registered thermal governor 'bang_bang'
  686. 74.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.592735] thermal_sys: Registered thermal governor 'step_wise'
  687. 74.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.594551] thermal_sys: Registered thermal governor 'user_space'
  688. 74.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.595564] cpuidle: using governor menu
  689. 74.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.599727] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
  690. 74.25 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.601913] PCI: Using configuration type 1 for base access
  691. 74.25 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.603557] PCI: Using configuration type 1 for extended access
  692. 74.25 s [vm-test-run-centjes-e2e-test] client # [ 0.521825] Freeing SMP alternatives memory: 40K
  693. 74.26 s [vm-test-run-centjes-e2e-test] client # [ 0.523325] pid_max: default: 32768 minimum: 301
  694. 74.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.604806] kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible.
  695. 74.26 s [vm-test-run-centjes-e2e-test] client # [ 0.525374] LSM: initializing lsm=capability,landlock,yama,bpf
  696. 74.26 s [vm-test-run-centjes-e2e-test] client # [ 0.527405] landlock: Up and running.
  697. 74.26 s [vm-test-run-centjes-e2e-test] client # [ 0.529322] Yama: becoming mindful.
  698. 74.26 s [vm-test-run-centjes-e2e-test] client # [ 0.531554] LSM support for eBPF active
  699. 74.27 s [vm-test-run-centjes-e2e-test] client # [ 0.533353] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
  700. 74.27 s [vm-test-run-centjes-e2e-test] client # [ 0.535325] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
  701. 74.28 s [vm-test-run-centjes-e2e-test] client # [ 0.537819] smpboot: CPU0: AMD Ryzen 9 5950X 16-Core Processor (family: 0x19, model: 0x21, stepping: 0x0)
  702. 74.28 s [vm-test-run-centjes-e2e-test] client # [ 0.539597] Performance Events: Fam17h+ core perfctr, AMD PMU driver.
  703. 74.28 s [vm-test-run-centjes-e2e-test] client # [ 0.541338] ... version: 0
  704. 74.28 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.629737] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages
  705. 74.28 s [vm-test-run-centjes-e2e-test] client # [ 0.542330] ... bit width: 48
  706. 74.29 s [vm-test-run-centjes-e2e-test] client # [ 0.543331] ... generic registers: 6
  707. 74.29 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.631552] HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page
  708. 74.29 s [vm-test-run-centjes-e2e-test] client # [ 0.544330] ... value mask: 0000ffffffffffff
  709. 74.29 s [vm-test-run-centjes-e2e-test] client # [ 0.545330] ... max period: 00007fffffffffff
  710. 74.29 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.633552] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
  711. 74.29 s [vm-test-run-centjes-e2e-test] client # [ 0.546330] ... fixed-purpose events: 0
  712. 74.30 s [vm-test-run-centjes-e2e-test] client # [ 0.547330] ... event mask: 000000000000003f
  713. 74.30 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.635548] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page
  714. 74.30 s [vm-test-run-centjes-e2e-test] client # [ 0.548436] signal: max sigframe size: 3376
  715. 74.30 s [vm-test-run-centjes-e2e-test] client # [ 0.549397] rcu: Hierarchical SRCU implementation.
  716. 74.30 s [vm-test-run-centjes-e2e-test] client # [ 0.550331] rcu: Max phase no-delay instances is 400.
  717. 74.31 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.645215] ACPI: Added _OSI(Module Device)
  718. 74.31 s [vm-test-run-centjes-e2e-test] client # [ 0.554769] smp: Bringing up secondary CPUs ...
  719. 74.31 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.646548] ACPI: Added _OSI(Processor Device)
  720. 74.31 s [vm-test-run-centjes-e2e-test] client # [ 0.556342] smp: Brought up 1 node, 1 CPU
  721. 74.31 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.647551] ACPI: Added _OSI(Processor Aggregator Device)
  722. 74.32 s [vm-test-run-centjes-e2e-test] client # [ 0.557333] smpboot: Total of 1 processors activated (6799.99 BogoMIPS)
  723. 74.32 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.651367] ACPI: 1 ACPI AML tables successfully acquired and loaded
  724. 74.32 s [vm-test-run-centjes-e2e-test] client # [ 0.558707] Memory: 962108K/1048036K available (16384K kernel code, 2645K rwdata, 12580K rodata, 3408K init, 3360K bss, 78836K reserved, 0K cma-reserved)
  725. 74.32 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.653827] ACPI: Interpreter enabled
  726. 74.32 s [vm-test-run-centjes-e2e-test] client # [ 0.560488] devtmpfs: initialized
  727. 74.33 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.654566] ACPI: PM: (supports S0 S3 S4 S5)
  728. 74.33 s [vm-test-run-centjes-e2e-test] client # [ 0.561393] x86/mm: Memory block size: 128MB
  729. 74.33 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.655548] ACPI: Using IOAPIC for interrupt routing
  730. 74.33 s [vm-test-run-centjes-e2e-test] client # [ 0.562847] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
  731. 74.33 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.656572] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
  732. 74.33 s [vm-test-run-centjes-e2e-test] client # [ 0.564334] futex hash table entries: 256 (order: 2, 16384 bytes, linear)
  733. 74.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.658554] PCI: Using E820 reservations for host bridge windows
  734. 74.34 s [vm-test-run-centjes-e2e-test] client # [ 0.565408] pinctrl core: initialized pinctrl subsystem
  735. 74.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.660825] ACPI: Enabled 2 GPEs in block 00 to 0F
  736. 74.34 s [vm-test-run-centjes-e2e-test] client # [ 0.566675] PM: RTC time: 20:24:33, date: 2026-06-01
  737. 74.34 s [vm-test-run-centjes-e2e-test] client # [ 0.569126] NET: Registered PF_NETLINK/PF_ROUTE protocol family
  738. 74.35 s [vm-test-run-centjes-e2e-test] client # [ 0.570498] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations
  739. 74.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.667363] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
  740. 74.35 s [vm-test-run-centjes-e2e-test] client # [ 0.572343] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
  741. 74.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.668554] acpi PNP0A03:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3]
  742. 74.36 s [vm-test-run-centjes-e2e-test] client # [ 0.574343] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
  743. 74.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.671047] acpiphp: Slot [3] registered
  744. 74.36 s [vm-test-run-centjes-e2e-test] client # [ 0.576350] audit: initializing netlink subsys (disabled)
  745. 74.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.672588] acpiphp: Slot [4] registered
  746. 74.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.673596] acpiphp: Slot [5] registered
  747. 74.36 s [vm-test-run-centjes-e2e-test] client # [ 0.577405] audit: type=2000 audit(1780345472.773:1): state=initialized audit_enabled=0 res=1
  748. 74.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.674586] acpiphp: Slot [6] registered
  749. 74.37 s [vm-test-run-centjes-e2e-test] client # [ 0.579472] thermal_sys: Registered thermal governor 'bang_bang'
  750. 74.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.675589] acpiphp: Slot [7] registered
  751. 74.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.676589] acpiphp: Slot [8] registered
  752. 74.37 s [vm-test-run-centjes-e2e-test] client # [ 0.579474] thermal_sys: Registered thermal governor 'step_wise'
  753. 74.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.677591] acpiphp: Slot [9] registered
  754. 74.37 s [vm-test-run-centjes-e2e-test] client # [ 0.581334] thermal_sys: Registered thermal governor 'user_space'
  755. 74.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.678587] acpiphp: Slot [10] registered
  756. 74.37 s [vm-test-run-centjes-e2e-test] client # [ 0.582348] cpuidle: using governor menu
  757. 74.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.679646] acpiphp: Slot [11] registered
  758. 74.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.680592] acpiphp: Slot [12] registered
  759. 74.38 s [vm-test-run-centjes-e2e-test] client # [ 0.586229] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
  760. 74.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.681599] acpiphp: Slot [13] registered
  761. 74.38 s [vm-test-run-centjes-e2e-test] client # [ 0.587603] PCI: Using configuration type 1 for base access
  762. 74.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.682593] acpiphp: Slot [14] registered
  763. 74.38 s [vm-test-run-centjes-e2e-test] client # [ 0.589331] PCI: Using configuration type 1 for extended access
  764. 74.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.683592] acpiphp: Slot [15] registered
  765. 74.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.684596] acpiphp: Slot [16] registered
  766. 74.39 s [vm-test-run-centjes-e2e-test] client # [ 0.590515] kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible.
  767. 74.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.685619] acpiphp: Slot [17] registered
  768. 74.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.686591] acpiphp: Slot [18] registered
  769. 74.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.687592] acpiphp: Slot [19] registered
  770. 74.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.688594] acpiphp: Slot [20] registered
  771. 74.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.689590] acpiphp: Slot [21] registered
  772. 74.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.690590] acpiphp: Slot [22] registered
  773. 74.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.691590] acpiphp: Slot [23] registered
  774. 74.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.692595] acpiphp: Slot [24] registered
  775. 74.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.693617] acpiphp: Slot [25] registered
  776. 74.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.694591] acpiphp: Slot [26] registered
  777. 74.41 s [vm-test-run-centjes-e2e-test] client # [ 0.612414] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages
  778. 74.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.695592] acpiphp: Slot [27] registered
  779. 74.42 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.696593] acpiphp: Slot [28] registered
  780. 74.42 s [vm-test-run-centjes-e2e-test] client # [ 0.614330] HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page
  781. 74.42 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.697596] acpiphp: Slot [29] registered
  782. 74.42 s [vm-test-run-centjes-e2e-test] client # [ 0.615331] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
  783. 74.42 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.698590] acpiphp: Slot [30] registered
  784. 74.42 s [vm-test-run-centjes-e2e-test] client # [ 0.616330] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page
  785. 74.42 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.699590] acpiphp: Slot [31] registered
  786. 74.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.700582] PCI host bridge to bus 0000:00
  787. 74.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.701555] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]
  788. 74.43 s [vm-test-run-centjes-e2e-test] client # [ 0.622203] ACPI: Added _OSI(Module Device)
  789. 74.43 s [vm-test-run-centjes-e2e-test] client # [ 0.623331] ACPI: Added _OSI(Processor Device)
  790. 74.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.703550] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]
  791. 74.43 s [vm-test-run-centjes-e2e-test] client # [ 0.624331] ACPI: Added _OSI(Processor Aggregator Device)
  792. 74.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.705550] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
  793. 74.44 s [vm-test-run-centjes-e2e-test] client # [ 0.627025] ACPI: 1 ACPI AML tables successfully acquired and loaded
  794. 74.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.707548] pci_bus 0000:00: root bus resource [mem 0x40000000-0xfebfffff window]
  795. 74.44 s [vm-test-run-centjes-e2e-test] client # [ 0.629577] ACPI: Interpreter enabled
  796. 74.45 s [vm-test-run-centjes-e2e-test] client # [ 0.630347] ACPI: PM: (supports S0 S3 S4 S5)
  797. 74.45 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.709548] pci_bus 0000:00: root bus resource [mem 0x100000000-0x17fffffff window]
  798. 74.45 s [vm-test-run-centjes-e2e-test] client # [ 0.631330] ACPI: Using IOAPIC for interrupt routing
  799. 74.45 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.711549] pci_bus 0000:00: root bus resource [bus 00-ff]
  800. 74.45 s [vm-test-run-centjes-e2e-test] client # [ 0.632356] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
  801. 74.45 s [vm-test-run-centjes-e2e-test] client # [ 0.634329] PCI: Using E820 reservations for host bridge windows
  802. 74.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.714238] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 conventional PCI endpoint
  803. 74.46 s [vm-test-run-centjes-e2e-test] client # [ 0.635524] ACPI: Enabled 2 GPEs in block 00 to 0F
  804. 74.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.717146] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 conventional PCI endpoint
  805. 74.46 s [vm-test-run-centjes-e2e-test] client # [ 0.640293] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
  806. 74.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.720380] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 conventional PCI endpoint
  807. 74.47 s [vm-test-run-centjes-e2e-test] client # [ 0.641335] acpi PNP0A03:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3]
  808. 74.47 s [vm-test-run-centjes-e2e-test] client # [ 0.643690] acpiphp: Slot [3] registered
  809. 74.47 s [vm-test-run-centjes-e2e-test] client # [ 0.645375] acpiphp: Slot [4] registered
  810. 74.48 s [vm-test-run-centjes-e2e-test] client # [ 0.646371] acpiphp: Slot [5] registered
  811. 74.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.725962] pci 0000:00:01.1: BAR 4 [io 0xc1e0-0xc1ef]
  812. 74.48 s [vm-test-run-centjes-e2e-test] client # [ 0.647371] acpiphp: Slot [6] registered
  813. 74.48 s [vm-test-run-centjes-e2e-test] client # [ 0.648371] acpiphp: Slot [7] registered
  814. 74.48 s [vm-test-run-centjes-e2e-test] client # [ 0.649370] acpiphp: Slot [8] registered
  815. 74.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.729596] pci 0000:00:01.1: BAR 0 [io 0x01f0-0x01f7]: legacy IDE quirk
  816. 74.48 s [vm-test-run-centjes-e2e-test] client # [ 0.650374] acpiphp: Slot [9] registered
  817. 74.49 s [vm-test-run-centjes-e2e-test] client # [ 0.651369] acpiphp: Slot [10] registered
  818. 74.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.731553] pci 0000:00:01.1: BAR 1 [io 0x03f6]: legacy IDE quirk
  819. 74.49 s [vm-test-run-centjes-e2e-test] client # [ 0.652369] acpiphp: Slot [11] registered
  820. 74.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.732551] pci 0000:00:01.1: BAR 2 [io 0x0170-0x0177]: legacy IDE quirk
  821. 74.49 s [vm-test-run-centjes-e2e-test] client # [ 0.653368] acpiphp: Slot [12] registered
  822. 74.49 s [vm-test-run-centjes-e2e-test] client # [ 0.654386] acpiphp: Slot [13] registered
  823. 74.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.734548] pci 0000:00:01.1: BAR 3 [io 0x0376]: legacy IDE quirk
  824. 74.49 s [vm-test-run-centjes-e2e-test] client # [ 0.655370] acpiphp: Slot [14] registered
  825. 74.50 s [vm-test-run-centjes-e2e-test] client # [ 0.656372] acpiphp: Slot [15] registered
  826. 74.50 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.736049] pci 0000:00:01.2: [8086:7020] type 00 class 0x0c0300 conventional PCI endpoint
  827. 74.50 s [vm-test-run-centjes-e2e-test] client # [ 0.657370] acpiphp: Slot [16] registered
  828. 74.50 s [vm-test-run-centjes-e2e-test] client # [ 0.658369] acpiphp: Slot [17] registered
  829. 74.50 s [vm-test-run-centjes-e2e-test] client # [ 0.659368] acpiphp: Slot [18] registered
  830. 74.50 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.740931] pci 0000:00:01.2: BAR 4 [io 0xc100-0xc11f]
  831. 74.50 s [vm-test-run-centjes-e2e-test] client # [ 0.660369] acpiphp: Slot [19] registered
  832. 74.51 s [vm-test-run-centjes-e2e-test] client # [ 0.661371] acpiphp: Slot [20] registered
  833. 74.51 s [vm-test-run-centjes-e2e-test] client # [ 0.662380] acpiphp: Slot [21] registered
  834. 74.51 s [vm-test-run-centjes-e2e-test] client # [ 0.663368] acpiphp: Slot [22] registered
  835. 74.51 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.745313] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 conventional PCI endpoint
  836. 74.51 s [vm-test-run-centjes-e2e-test] client # [ 0.664369] acpiphp: Slot [23] registered
  837. 74.51 s [vm-test-run-centjes-e2e-test] client # [ 0.665372] acpiphp: Slot [24] registered
  838. 74.52 s [vm-test-run-centjes-e2e-test] client # [ 0.666373] acpiphp: Slot [25] registered
  839. 74.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.748039] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI
  840. 74.52 s [vm-test-run-centjes-e2e-test] client # [ 0.667367] acpiphp: Slot [26] registered
  841. 74.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.749575] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB
  842. 74.52 s [vm-test-run-centjes-e2e-test] client # [ 0.668369] acpiphp: Slot [27] registered
  843. 74.52 s [vm-test-run-centjes-e2e-test] client # [ 0.669372] acpiphp: Slot [28] registered
  844. 74.53 s [vm-test-run-centjes-e2e-test] client # [ 0.670370] acpiphp: Slot [29] registered
  845. 74.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.752234] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000 conventional PCI endpoint
  846. 74.53 s [vm-test-run-centjes-e2e-test] client # [ 0.671368] acpiphp: Slot [30] registered
  847. 74.53 s [vm-test-run-centjes-e2e-test] client # [ 0.672374] acpiphp: Slot [31] registered
  848. 74.53 s [vm-test-run-centjes-e2e-test] client # [ 0.673364] PCI host bridge to bus 0000:00
  849. 74.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.755238] pci 0000:00:02.0: BAR 0 [mem 0xfd000000-0xfdffffff pref]
  850. 74.53 s [vm-test-run-centjes-e2e-test] client # [ 0.674341] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]
  851. 74.54 s [vm-test-run-centjes-e2e-test] client # [ 0.675332] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]
  852. 74.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.759235] pci 0000:00:02.0: BAR 2 [mem 0xfebd0000-0xfebd0fff]
  853. 74.54 s [vm-test-run-centjes-e2e-test] client # [ 0.676332] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
  854. 74.54 s [vm-test-run-centjes-e2e-test] client # [ 0.678331] pci_bus 0000:00: root bus resource [mem 0x40000000-0xfebfffff window]
  855. 74.55 s [vm-test-run-centjes-e2e-test] client # [ 0.680331] pci_bus 0000:00: root bus resource [mem 0x100000000-0x17fffffff window]
  856. 74.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.766359] pci 0000:00:02.0: ROM [mem 0xfebc0000-0xfebcffff pref]
  857. 74.55 s [vm-test-run-centjes-e2e-test] client # [ 0.682331] pci_bus 0000:00: root bus resource [bus 00-ff]
  858. 74.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.767791] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
  859. 74.56 s [vm-test-run-centjes-e2e-test] client # [ 0.683848] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 conventional PCI endpoint
  860. 74.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.770421] pci 0000:00:03.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
  861. 74.56 s [vm-test-run-centjes-e2e-test] client # [ 0.686570] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 conventional PCI endpoint
  862. 74.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.772548] pci 0000:00:03.0: BAR 0 [io 0xc120-0xc13f]
  863. 74.57 s [vm-test-run-centjes-e2e-test] client # [ 0.690022] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 conventional PCI endpoint
  864. 74.57 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.775548] pci 0000:00:03.0: BAR 1 [mem 0xfebd1000-0xfebd1fff]
  865. 74.57 s [vm-test-run-centjes-e2e-test] client # [ 0.695195] pci 0000:00:01.1: BAR 4 [io 0xc1e0-0xc1ef]
  866. 74.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.781190] pci 0000:00:03.0: BAR 4 [mem 0xfe000000-0xfe003fff 64bit pref]
  867. 74.58 s [vm-test-run-centjes-e2e-test] client # [ 0.697913] pci 0000:00:01.1: BAR 0 [io 0x01f0-0x01f7]: legacy IDE quirk
  868. 74.58 s [vm-test-run-centjes-e2e-test] client # [ 0.699347] pci 0000:00:01.1: BAR 1 [io 0x03f6]: legacy IDE quirk
  869. 74.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.783550] pci 0000:00:03.0: ROM [mem 0xfeb40000-0xfeb7ffff pref]
  870. 74.59 s [vm-test-run-centjes-e2e-test] client # [ 0.700336] pci 0000:00:01.1: BAR 2 [io 0x0170-0x0177]: legacy IDE quirk
  871. 74.59 s [vm-test-run-centjes-e2e-test] client # [ 0.702332] pci 0000:00:01.1: BAR 3 [io 0x0376]: legacy IDE quirk
  872. 74.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.787514] pci 0000:00:04.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
  873. 74.60 s [vm-test-run-centjes-e2e-test] client # [ 0.703811] pci 0000:00:01.2: [8086:7020] type 00 class 0x0c0300 conventional PCI endpoint
  874. 74.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.790163] pci 0000:00:04.0: BAR 0 [io 0xc140-0xc15f]
  875. 74.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.792549] pci 0000:00:04.0: BAR 1 [mem 0xfebd2000-0xfebd2fff]
  876. 74.60 s [vm-test-run-centjes-e2e-test] client # [ 0.709336] pci 0000:00:01.2: BAR 4 [io 0xc100-0xc11f]
  877. 74.61 s [vm-test-run-centjes-e2e-test] client # [ 0.713983] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 conventional PCI endpoint
  878. 74.61 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.796549] pci 0000:00:04.0: BAR 4 [mem 0xfe004000-0xfe007fff 64bit pref]
  879. 74.62 s [vm-test-run-centjes-e2e-test] client # [ 0.716729] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI
  880. 74.62 s [vm-test-run-centjes-e2e-test] client # [ 0.718367] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB
  881. 74.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.802549] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  882. 74.63 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.805548] pci 0000:00:05.0: BAR 0 [io 0xc080-0xc0bf]
  883. 74.63 s [vm-test-run-centjes-e2e-test] client # [ 0.720983] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000 conventional PCI endpoint
  884. 74.63 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.807548] pci 0000:00:05.0: BAR 1 [mem 0xfebd3000-0xfebd3fff]
  885. 74.63 s [vm-test-run-centjes-e2e-test] client # [ 0.723962] pci 0000:00:02.0: BAR 0 [mem 0xfd000000-0xfdffffff pref]
  886. 74.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.811549] pci 0000:00:05.0: BAR 4 [mem 0xfe008000-0xfe00bfff 64bit pref]
  887. 74.64 s [vm-test-run-centjes-e2e-test] client # [ 0.727945] pci 0000:00:02.0: BAR 2 [mem 0xfebd0000-0xfebd0fff]
  888. 74.65 s [vm-test-run-centjes-e2e-test] client # [ 0.734355] pci 0000:00:02.0: ROM [mem 0xfebc0000-0xfebcffff pref]
  889. 74.65 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.819312] pci 0000:00:06.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  890. 74.65 s [vm-test-run-centjes-e2e-test] client # [ 0.736522] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
  891. 74.65 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.822135] pci 0000:00:06.0: BAR 0 [io 0xc160-0xc17f]
  892. 74.66 s [vm-test-run-centjes-e2e-test] client # [ 0.739167] pci 0000:00:03.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
  893. 74.66 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.824549] pci 0000:00:06.0: BAR 1 [mem 0xfebd4000-0xfebd4fff]
  894. 74.66 s [vm-test-run-centjes-e2e-test] client # [ 0.741333] pci 0000:00:03.0: BAR 0 [io 0xc120-0xc13f]
  895. 74.67 s [vm-test-run-centjes-e2e-test] client # [ 0.743334] pci 0000:00:03.0: BAR 1 [mem 0xfebd1000-0xfebd1fff]
  896. 74.67 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.829276] pci 0000:00:06.0: BAR 4 [mem 0xfe00c000-0xfe00ffff 64bit pref]
  897. 74.68 s [vm-test-run-centjes-e2e-test] client # [ 0.749955] pci 0000:00:03.0: BAR 4 [mem 0xfe000000-0xfe003fff 64bit pref]
  898. 74.68 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.835035] pci 0000:00:07.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  899. 74.68 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.837549] pci 0000:00:07.0: BAR 0 [io 0xc180-0xc19f]
  900. 74.68 s [vm-test-run-centjes-e2e-test] client # [ 0.752336] pci 0000:00:03.0: ROM [mem 0xfeb40000-0xfeb7ffff pref]
  901. 74.69 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.840040] pci 0000:00:07.0: BAR 1 [mem 0xfebd5000-0xfebd5fff]
  902. 74.69 s [vm-test-run-centjes-e2e-test] client # [ 0.757614] pci 0000:00:04.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
  903. 74.70 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.844553] pci 0000:00:07.0: BAR 4 [mem 0xfe010000-0xfe013fff 64bit pref]
  904. 74.70 s [vm-test-run-centjes-e2e-test] client # [ 0.760332] pci 0000:00:04.0: BAR 0 [io 0xc140-0xc15f]
  905. 74.70 s [vm-test-run-centjes-e2e-test] client # [ 0.762336] pci 0000:00:04.0: BAR 1 [mem 0xfebd2000-0xfebd2fff]
  906. 74.70 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.850548] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint
  907. 74.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.854134] pci 0000:00:08.0: BAR 0 [io 0xc000-0xc07f]
  908. 74.71 s [vm-test-run-centjes-e2e-test] client # [ 0.767332] pci 0000:00:04.0: BAR 4 [mem 0xfe004000-0xfe007fff 64bit pref]
  909. 74.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.856548] pci 0000:00:08.0: BAR 1 [mem 0xfebd6000-0xfebd6fff]
  910. 74.72 s [vm-test-run-centjes-e2e-test] client # [ 0.773179] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  911. 74.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.861197] pci 0000:00:08.0: BAR 4 [mem 0xfe014000-0xfe017fff 64bit pref]
  912. 74.72 s [vm-test-run-centjes-e2e-test] client # [ 0.775331] pci 0000:00:05.0: BAR 0 [io 0xc080-0xc0bf]
  913. 74.73 s [vm-test-run-centjes-e2e-test] client # [ 0.777331] pci 0000:00:05.0: BAR 1 [mem 0xfebd3000-0xfebd3fff]
  914. 74.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.866666] pci 0000:00:09.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
  915. 74.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.869550] pci 0000:00:09.0: BAR 0 [io 0xc1a0-0xc1bf]
  916. 74.73 s [vm-test-run-centjes-e2e-test] client # [ 0.782035] pci 0000:00:05.0: BAR 4 [mem 0xfe008000-0xfe00bfff 64bit pref]
  917. 74.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.871548] pci 0000:00:09.0: BAR 1 [mem 0xfebd7000-0xfebd7fff]
  918. 74.74 s [vm-test-run-centjes-e2e-test] client # [ 0.788109] pci 0000:00:06.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  919. 74.75 s [vm-test-run-centjes-e2e-test] client # [ 0.790333] pci 0000:00:06.0: BAR 0 [io 0xc160-0xc17f]
  920. 74.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.876552] pci 0000:00:09.0: BAR 4 [mem 0xfe018000-0xfe01bfff 64bit pref]
  921. 74.75 s [vm-test-run-centjes-e2e-test] client # [ 0.792919] pci 0000:00:06.0: BAR 1 [mem 0xfebd4000-0xfebd4fff]
  922. 74.76 s [vm-test-run-centjes-e2e-test] client # [ 0.797332] pci 0000:00:06.0: BAR 4 [mem 0xfe00c000-0xfe00ffff 64bit pref]
  923. 74.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.879551] pci 0000:00:09.0: ROM [mem 0xfeb80000-0xfebbffff pref]
  924. 74.77 s [vm-test-run-centjes-e2e-test] client # [ 0.803177] pci 0000:00:07.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  925. 74.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.884549] pci 0000:00:0a.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint
  926. 74.77 s [vm-test-run-centjes-e2e-test] client # [ 0.805330] pci 0000:00:07.0: BAR 0 [io 0xc180-0xc19f]
  927. 74.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.888358] pci 0000:00:0a.0: BAR 1 [mem 0xfebd8000-0xfebd8fff]
  928. 74.78 s [vm-test-run-centjes-e2e-test] client # [ 0.808338] pci 0000:00:07.0: BAR 1 [mem 0xfebd5000-0xfebd5fff]
  929. 74.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.892056] pci 0000:00:0a.0: BAR 4 [mem 0xfe01c000-0xfe01ffff 64bit pref]
  930. 74.79 s [vm-test-run-centjes-e2e-test] client # [ 0.812331] pci 0000:00:07.0: BAR 4 [mem 0xfe010000-0xfe013fff 64bit pref]
  931. 74.79 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.897530] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint
  932. 74.79 s [vm-test-run-centjes-e2e-test] client # [ 0.818226] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint
  933. 74.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.900548] pci 0000:00:0b.0: BAR 0 [io 0xc0c0-0xc0ff]
  934. 74.80 s [vm-test-run-centjes-e2e-test] client # [ 0.820332] pci 0000:00:08.0: BAR 0 [io 0xc000-0xc07f]
  935. 74.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.902523] pci 0000:00:0b.0: BAR 1 [mem 0xfebd9000-0xfebd9fff]
  936. 74.80 s [vm-test-run-centjes-e2e-test] client # [ 0.822332] pci 0000:00:08.0: BAR 1 [mem 0xfebd6000-0xfebd6fff]
  937. 74.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.906549] pci 0000:00:0b.0: BAR 4 [mem 0xfe020000-0xfe023fff 64bit pref]
  938. 74.81 s [vm-test-run-centjes-e2e-test] client # [ 0.826986] pci 0000:00:08.0: BAR 4 [mem 0xfe014000-0xfe017fff 64bit pref]
  939. 74.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.912395] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
  940. 74.82 s [vm-test-run-centjes-e2e-test] client # [ 0.832777] pci 0000:00:09.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
  941. 74.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.914547] pci 0000:00:0c.0: BAR 0 [io 0xc1c0-0xc1df]
  942. 74.82 s [vm-test-run-centjes-e2e-test] client # [ 0.835331] pci 0000:00:09.0: BAR 0 [io 0xc1a0-0xc1bf]
  943. 74.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.916487] pci 0000:00:0c.0: BAR 1 [mem 0xfebda000-0xfebdafff]
  944. 74.83 s [vm-test-run-centjes-e2e-test] client # [ 0.837331] pci 0000:00:09.0: BAR 1 [mem 0xfebd7000-0xfebd7fff]
  945. 74.83 s [vm-test-run-centjes-e2e-test] client # [ 0.842331] pci 0000:00:09.0: BAR 4 [mem 0xfe018000-0xfe01bfff 64bit pref]
  946. 74.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.920555] pci 0000:00:0c.0: BAR 4 [mem 0xfe024000-0xfe027fff 64bit pref]
  947. 74.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.926957] ACPI: PCI: Interrupt link LNKA configured for IRQ 10
  948. 74.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.928789] ACPI: PCI: Interrupt link LNKB configured for IRQ 10
  949. 74.85 s [vm-test-run-centjes-e2e-test] client # [ 0.844331] pci 0000:00:09.0: ROM [mem 0xfeb80000-0xfebbffff pref]
  950. 74.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.930758] ACPI: PCI: Interrupt link LNKC configured for IRQ 11
  951. 74.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.932754] ACPI: PCI: Interrupt link LNKD configured for IRQ 11
  952. 74.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.934659] ACPI: PCI: Interrupt link LNKS configured for IRQ 9
  953. 74.86 s [vm-test-run-centjes-e2e-test] client # [ 0.849180] pci 0000:00:0a.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint
  954. 74.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.935949] iommu: Default domain type: Translated
  955. 74.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.937547] iommu: DMA domain TLB invalidation policy: lazy mode
  956. 74.86 s [vm-test-run-centjes-e2e-test] client # [ 0.852647] pci 0000:00:0a.0: BAR 1 [mem 0xfebd8000-0xfebd8fff]
  957. 74.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.938588] ACPI: bus type USB registered
  958. 74.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.939582] usbcore: registered new interface driver usbfs
  959. 74.87 s [vm-test-run-centjes-e2e-test] client # [ 0.856331] pci 0000:00:0a.0: BAR 4 [mem 0xfe01c000-0xfe01ffff 64bit pref]
  960. 74.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.940581] usbcore: registered new interface driver hub
  961. 74.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.941572] usbcore: registered new device driver usb
  962. 74.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.943916] NetLabel: Initializing
  963. 74.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.945547] NetLabel: domain hash size = 128
  964. 74.88 s [vm-test-run-centjes-e2e-test] client # [ 0.862959] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint
  965. 74.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.946547] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO
  966. 74.88 s [vm-test-run-centjes-e2e-test] client # [ 0.865334] pci 0000:00:0b.0: BAR 0 [io 0xc0c0-0xc0ff]
  967. 74.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.947569] NetLabel: unlabeled traffic allowed by default
  968. 74.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.948549] PCI: Using ACPI for IRQ routing
  969. 74.89 s [vm-test-run-centjes-e2e-test] client # [ 0.868337] pci 0000:00:0b.0: BAR 1 [mem 0xfebd9000-0xfebd9fff]
  970. 74.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.950433] pci 0000:00:02.0: vgaarb: setting as boot VGA device
  971. 74.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.950536] pci 0000:00:02.0: vgaarb: bridge control possible
  972. 74.90 s [vm-test-run-centjes-e2e-test] client # [ 0.872331] pci 0000:00:0b.0: BAR 4 [mem 0xfe020000-0xfe023fff 64bit pref]
  973. 74.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.950536] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
  974. 74.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.950551] vgaarb: loaded
  975. 74.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.951633] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
  976. 74.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.952547] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
  977. 74.91 s [vm-test-run-centjes-e2e-test] client # [ 0.878237] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
  978. 74.91 s [vm-test-run-centjes-e2e-test] client # [ 0.880331] pci 0000:00:0c.0: BAR 0 [io 0xc1c0-0xc1df]
  979. 74.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.956602] clocksource: Switched to clocksource kvm-clock
  980. 74.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.960505] VFS: Disk quotas dquot_6.6.0
  981. 74.92 s [vm-test-run-centjes-e2e-test] client # [ 0.882333] pci 0000:00:0c.0: BAR 1 [mem 0xfebda000-0xfebdafff]
  982. 74.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.962644] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
  983. 74.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.966335] pnp: PnP ACPI init
  984. 74.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.968717] pnp: PnP ACPI: found 6 devices
  985. 74.92 s [vm-test-run-centjes-e2e-test] client # [ 0.886334] pci 0000:00:0c.0: BAR 4 [mem 0xfe024000-0xfe027fff 64bit pref]
  986. 74.93 s [vm-test-run-centjes-e2e-test] client # [ 0.892213] ACPI: PCI: Interrupt link LNKA configured for IRQ 10
  987. 74.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.976948] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
  988. 74.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.981514] clocksource: Switched to clocksource acpi_pm
  989. 74.94 s [vm-test-run-centjes-e2e-test] client # [ 0.893640] ACPI: PCI: Interrupt link LNKB configured for IRQ 10
  990. 74.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.984509] NET: Registered PF_INET protocol family
  991. 74.94 s [vm-test-run-centjes-e2e-test] client # [ 0.895560] ACPI: PCI: Interrupt link LNKC configured for IRQ 11
  992. 74.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.987080] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
  993. 74.94 s [vm-test-run-centjes-e2e-test] client # [ 0.897594] ACPI: PCI: Interrupt link LNKD configured for IRQ 11
  994. 74.95 s [vm-test-run-centjes-e2e-test] client # [ 0.899453] ACPI: PCI: Interrupt link LNKS configured for IRQ 9
  995. 74.95 s [vm-test-run-centjes-e2e-test] client # [ 0.901787] iommu: Default domain type: Translated
  996. 74.95 s [vm-test-run-centjes-e2e-test] client # [ 0.903330] iommu: DMA domain TLB invalidation policy: lazy mode
  997. 74.95 s [vm-test-run-centjes-e2e-test] client # [ 0.904371] ACPI: bus type USB registered
  998. 74.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.001603] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)
  999. 74.96 s [vm-test-run-centjes-e2e-test] client # [ 0.905365] usbcore: registered new interface driver usbfs
  1000. 74.96 s [vm-test-run-centjes-e2e-test] client # [ 0.906343] usbcore: registered new interface driver hub
  1001. 74.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.005908] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
  1002. 74.96 s [vm-test-run-centjes-e2e-test] client # [ 0.907345] usbcore: registered new device driver usb
  1003. 74.96 s [vm-test-run-centjes-e2e-test] client # [ 0.908698] NetLabel: Initializing
  1004. 74.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.009996] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)
  1005. 74.97 s [vm-test-run-centjes-e2e-test] client # [ 0.909331] NetLabel: domain hash size = 128
  1006. 74.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.014052] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)
  1007. 74.97 s [vm-test-run-centjes-e2e-test] client # [ 0.910331] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO
  1008. 74.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.017834] TCP: Hash tables configured (established 8192 bind 8192)
  1009. 74.97 s [vm-test-run-centjes-e2e-test] client # [ 0.911358] NetLabel: unlabeled traffic allowed by default
  1010. 74.97 s [vm-test-run-centjes-e2e-test] client # [ 0.912333] PCI: Using ACPI for IRQ routing
  1011. 74.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.021168] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)
  1012. 74.98 s [vm-test-run-centjes-e2e-test] client # [ 0.914207] pci 0000:00:02.0: vgaarb: setting as boot VGA device
  1013. 74.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.025173] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
  1014. 74.98 s [vm-test-run-centjes-e2e-test] client # [ 0.914319] pci 0000:00:02.0: vgaarb: bridge control possible
  1015. 74.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.028561] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
  1016. 74.99 s [vm-test-run-centjes-e2e-test] client # [ 0.914319] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
  1017. 74.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.032201] NET: Registered PF_UNIX/PF_LOCAL protocol family
  1018. 74.99 s [vm-test-run-centjes-e2e-test] client # [ 0.914338] vgaarb: loaded
  1019. 74.99 s [vm-test-run-centjes-e2e-test] client # [ 0.915445] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
  1020. 74.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.035241] NET: Registered PF_XDP protocol family
  1021. 74.99 s [vm-test-run-centjes-e2e-test] client # [ 0.917334] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
  1022. 74.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.039658] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]
  1023. 75.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.043737] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]
  1024. 75.00 s [vm-test-run-centjes-e2e-test] client # [ 0.922396] clocksource: Switched to clocksource kvm-clock
  1025. 75.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.047250] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
  1026. 75.00 s [vm-test-run-centjes-e2e-test] client # [ 0.926325] VFS: Disk quotas dquot_6.6.0
  1027. 75.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.050823] pci_bus 0000:00: resource 7 [mem 0x40000000-0xfebfffff window]
  1028. 75.01 s [vm-test-run-centjes-e2e-test] client # [ 0.928603] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
  1029. 75.01 s [vm-test-run-centjes-e2e-test] client # [ 0.932365] pnp: PnP ACPI init
  1030. 75.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.054552] pci_bus 0000:00: resource 8 [mem 0x100000000-0x17fffffff window]
  1031. 75.01 s [vm-test-run-centjes-e2e-test] client # [ 0.934895] pnp: PnP ACPI: found 6 devices
  1032. 75.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.058605] pci 0000:00:01.0: PIIX3: Enabling Passive Release
  1033. 75.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.061819] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
  1034. 75.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.066706] ACPI: \_SB_.LNKD: Enabled at IRQ 11
  1035. 75.02 s [vm-test-run-centjes-e2e-test] client # [ 0.943540] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
  1036. 75.03 s [vm-test-run-centjes-e2e-test] client # [ 0.948134] clocksource: Switched to clocksource acpi_pm
  1037. 75.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.072329] PCI: CLS 0 bytes, default 64
  1038. 75.03 s [vm-test-run-centjes-e2e-test] client # [ 0.951106] NET: Registered PF_INET protocol family
  1039. 75.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.075370] Trying to unpack rootfs image as initramfs...
  1040. 75.03 s [vm-test-run-centjes-e2e-test] client # [ 0.953866] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
  1041. 75.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.081586] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x31024cfe468, max_idle_ns: 440795307017 ns
  1042. 75.05 s [vm-test-run-centjes-e2e-test] client # [ 0.967716] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)
  1043. 75.05 s [vm-test-run-centjes-e2e-test] client # [ 0.971984] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
  1044. 75.05 s [vm-test-run-centjes-e2e-test] client # [ 0.975973] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)
  1045. 75.06 s [vm-test-run-centjes-e2e-test] client # [ 0.979969] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)
  1046. 75.06 s [vm-test-run-centjes-e2e-test] client # [ 0.983787] TCP: Hash tables configured (established 8192 bind 8192)
  1047. 75.07 s [vm-test-run-centjes-e2e-test] client # [ 0.987153] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)
  1048. 75.07 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.114817] Initialise system trusted keyrings
  1049. 75.07 s [vm-test-run-centjes-e2e-test] client # [ 0.991080] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
  1050. 75.07 s [vm-test-run-centjes-e2e-test] client # [ 0.994492] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
  1051. 75.08 s [vm-test-run-centjes-e2e-test] client # [ 0.998160] NET: Registered PF_UNIX/PF_LOCAL protocol family
  1052. 75.08 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.121678] workingset: timestamp_bits=40 max_order=18 bucket_order=0
  1053. 75.08 s [vm-test-run-centjes-e2e-test] client # [ 1.001171] NET: Registered PF_XDP protocol family
  1054. 75.08 s [vm-test-run-centjes-e2e-test] client # [ 1.003801] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]
  1055. 75.09 s [vm-test-run-centjes-e2e-test] client # [ 1.007058] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]
  1056. 75.09 s [vm-test-run-centjes-e2e-test] client # [ 1.010235] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
  1057. 75.09 s [vm-test-run-centjes-e2e-test] client # [ 1.013826] pci_bus 0000:00: resource 7 [mem 0x40000000-0xfebfffff window]
  1058. 75.10 s [vm-test-run-centjes-e2e-test] client # [ 1.017494] pci_bus 0000:00: resource 8 [mem 0x100000000-0x17fffffff window]
  1059. 75.10 s [vm-test-run-centjes-e2e-test] client # [ 1.021212] pci 0000:00:01.0: PIIX3: Enabling Passive Release
  1060. 75.10 s [vm-test-run-centjes-e2e-test] client # [ 1.024309] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
  1061. 75.10 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.149620] Key type asymmetric registered
  1062. 75.11 s [vm-test-run-centjes-e2e-test] client # [ 1.029503] ACPI: \_SB_.LNKD: Enabled at IRQ 11
  1063. 75.11 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.156584] Asymmetric key parser 'x509' registered
  1064. 75.11 s [vm-test-run-centjes-e2e-test] client # [ 1.035499] PCI: CLS 0 bytes, default 64
  1065. 75.12 s [vm-test-run-centjes-e2e-test] client # [ 1.038592] Trying to unpack rootfs image as initramfs...
  1066. 75.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.164579] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
  1067. 75.12 s [vm-test-run-centjes-e2e-test] client # [ 1.042338] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x31024cfe468, max_idle_ns: 440795307017 ns
  1068. 75.13 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.174594] io scheduler mq-deadline registered
  1069. 75.13 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.177099] io scheduler kyber registered
  1070. 75.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.181808] Freeing initrd memory: 12300K
  1071. 75.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.184645] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
  1072. 75.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.188559] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
  1073. 75.15 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.194525] Linux agpgart interface v0.103
  1074. 75.15 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.196799] ACPI: bus type drm_connector registered
  1075. 75.15 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.199914] usbcore: registered new interface driver usbserial_generic
  1076. 75.16 s [vm-test-run-centjes-e2e-test] client # [ 1.078267] Initialise system trusted keyrings
  1077. 75.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.203543] usbserial: USB Serial support registered for generic
  1078. 75.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.207123] amd_pstate: the _CPC object is not present in SBIOS or ACPI disabled
  1079. 75.16 s [vm-test-run-centjes-e2e-test] client # [ 1.085209] workingset: timestamp_bits=40 max_order=18 bucket_order=0
  1080. 75.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.211701] drop_monitor: Initializing network drop monitor service
  1081. 75.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.215178] NET: Registered PF_INET6 protocol family
  1082. 75.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.218699] Segment Routing with IPv6
  1083. 75.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.220711] In-situ OAM (IOAM) with IPv6
  1084. 75.18 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.223129] IPI shorthand broadcast: enabled
  1085. 75.18 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.227750] registered taskstats version 1
  1086. 75.18 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.230377] Loading compiled-in X.509 certificates
  1087. 75.19 s [vm-test-run-centjes-e2e-test] client # [ 1.113089] Key type asymmetric registered
  1088. 75.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.238245] Demotion targets for Node 0: null
  1089. 75.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.240997] Key type .fscrypt registered
  1090. 75.20 s [vm-test-run-centjes-e2e-test] client # [ 1.117991] Asymmetric key parser 'x509' registered
  1091. 75.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.243318] Key type fscrypt-provisioning registered
  1092. 75.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.246171] PM: Magic number: 14:570:446
  1093. 75.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.249186] RAS: Correctable Errors collector initialized.
  1094. 75.20 s [vm-test-run-centjes-e2e-test] client # [ 1.125409] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
  1095. 75.21 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.255174] Unstable clock detected, switching default tracing clock to "global"
  1096. 75.21 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.255174] If you want to keep using the local clock, then add:
  1097. 75.21 s [vm-test-run-centjes-e2e-test] client # [ 1.136089] io scheduler mq-deadline registered
  1098. 75.21 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.255174] "trace_clock=local"
  1099. 75.22 s [vm-test-run-centjes-e2e-test] client # [ 1.138530] io scheduler kyber registered
  1100. 75.22 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.255174] on the kernel command line
  1101. 75.22 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.264888] clk: Disabling unused clocks
  1102. 75.22 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.267138] PM: genpd: Disabling unused power domains
  1103. 75.22 s [vm-test-run-centjes-e2e-test] client # [ 1.144544] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
  1104. 75.22 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.270881] Freeing unused decrypted memory: 2028K
  1105. 75.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.273909] Freeing unused kernel image (initmem) memory: 3408K
  1106. 75.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.277085] Write protecting the kernel read-only data: 30720k
  1107. 75.23 s [vm-test-run-centjes-e2e-test] client # [ 1.153618] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
  1108. 75.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.280612] Freeing unused kernel image (rodata/data gap) memory: 1756K
  1109. 75.24 s [vm-test-run-centjes-e2e-test] client # [ 1.162313] Freeing initrd memory: 12300K
  1110. 75.24 s [vm-test-run-centjes-e2e-test] client # [ 1.166139] Linux agpgart interface v0.103
  1111. 75.25 s [vm-test-run-centjes-e2e-test] client # [ 1.168438] ACPI: bus type drm_connector registered
  1112. 75.25 s [vm-test-run-centjes-e2e-test] client # [ 1.171540] usbcore: registered new interface driver usbserial_generic
  1113. 75.25 s [vm-test-run-centjes-e2e-test] client # [ 1.175065] usbserial: USB Serial support registered for generic
  1114. 75.26 s [vm-test-run-centjes-e2e-test] client # [ 1.178226] amd_pstate: the _CPC object is not present in SBIOS or ACPI disabled
  1115. 75.26 s [vm-test-run-centjes-e2e-test] client # [ 1.182127] drop_monitor: Initializing network drop monitor service
  1116. 75.26 s [vm-test-run-centjes-e2e-test] client # [ 1.185543] NET: Registered PF_INET6 protocol family
  1117. 75.27 s [vm-test-run-centjes-e2e-test] client # [ 1.188894] Segment Routing with IPv6
  1118. 75.27 s [vm-test-run-centjes-e2e-test] client # [ 1.191047] In-situ OAM (IOAM) with IPv6
  1119. 75.27 s [vm-test-run-centjes-e2e-test] client # [ 1.193503] IPI shorthand broadcast: enabled
  1120. 75.28 s [vm-test-run-centjes-e2e-test] client # [ 1.198272] registered taskstats version 1
  1121. 75.28 s [vm-test-run-centjes-e2e-test] client # [ 1.200898] Loading compiled-in X.509 certificates
  1122. 75.28 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.327628] x86/mm: Checked W+X mappings: passed, no W+X pages found.
  1123. 75.28 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.331135] Run /init as init process
  1124. 75.29 s [vm-test-run-centjes-e2e-test] client # [ 1.208782] Demotion targets for Node 0: null
  1125. 75.29 s [vm-test-run-centjes-e2e-test] client # [ 1.211375] Key type .fscrypt registered
  1126. 75.29 s [vm-test-run-centjes-e2e-test] client # [ 1.213736] Key type fscrypt-provisioning registered
  1127. 75.29 s [vm-test-run-centjes-e2e-test] client # [ 1.216658] PM: Magic number: 14:570:446
  1128. 75.30 s [vm-test-run-centjes-e2e-test] client # [ 1.219742] RAS: Correctable Errors collector initialized.
  1129. 75.31 s [vm-test-run-centjes-e2e-test] client # [ 1.226143] Unstable clock detected, switching default tracing clock to "global"
  1130. 75.31 s [vm-test-run-centjes-e2e-test] client # [ 1.226143] If you want to keep using the local clock, then add:
  1131. 75.31 s [vm-test-run-centjes-e2e-test] client # [ 1.226143] "trace_clock=local"
  1132. 75.31 s [vm-test-run-centjes-e2e-test] client # [ 1.226143] on the kernel command line
  1133. 75.31 s [vm-test-run-centjes-e2e-test] client # [ 1.236247] clk: Disabling unused clocks
  1134. 75.32 s [vm-test-run-centjes-e2e-test] client # [ 1.238504] PM: genpd: Disabling unused power domains
  1135. 75.32 s [vm-test-run-centjes-e2e-test] client # [ 1.242372] Freeing unused decrypted memory: 2028K
  1136. 75.32 s [vm-test-run-centjes-e2e-test] client # [ 1.245456] Freeing unused kernel image (initmem) memory: 3408K
  1137. 75.33 s [vm-test-run-centjes-e2e-test] client # [ 1.248619] Write protecting the kernel read-only data: 30720k
  1138. 75.33 s [vm-test-run-centjes-e2e-test] client # [ 1.252181] Freeing unused kernel image (rodata/data gap) memory: 1756K
  1139. 75.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.381668] device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@lists.linux.dev
  1140. 75.38 s [vm-test-run-centjes-e2e-test] client # [ 1.298074] x86/mm: Checked W+X mappings: passed, no W+X pages found.
  1141. 75.38 s [vm-test-run-centjes-e2e-test] client # [ 1.301552] Run /init as init process
  1142. 75.43 s [vm-test-run-centjes-e2e-test] client # [ 1.353250] device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@lists.linux.dev
  1143. 75.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.567974] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
  1144. 75.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.595959] SCSI subsystem initialized
  1145. 75.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.600232] serio: i8042 KBD port at 0x60,0x64 irq 1
  1146. 75.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.604977] ACPI: \_SB_.LNKC: Enabled at IRQ 10
  1147. 75.57 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.615168] serio: i8042 AUX port at 0x60,0x64 irq 12
  1148. 75.57 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.620357] uhci_hcd 0000:00:01.2: UHCI Host Controller
  1149. 75.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.636279] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
  1150. 75.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.647809] uhci_hcd 0000:00:01.2: detected 2 ports
  1151. 75.61 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.657947] ACPI: \_SB_.LNKA: Enabled at IRQ 10
  1152. 75.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.660845] uhci_hcd 0000:00:01.2: irq 11, io port 0x0000c100
  1153. 75.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.664739] scsi host0: ata_piix
  1154. 75.62 s [vm-test-run-centjes-e2e-test] client # [ 1.540768] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
  1155. 75.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.668829] scsi host1: ata_piix
  1156. 75.63 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.672820] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 6.12
  1157. 75.63 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.677231] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
  1158. 75.63 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.681196] usb usb1: Product: UHCI Host Controller
  1159. 75.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.683927] usb usb1: Manufacturer: Linux 6.12.62 uhci_hcd
  1160. 75.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.686931] usb usb1: SerialNumber: 0000:00:01.2
  1161. 75.65 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.689748] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc1e0 irq 14 lpm-pol 0
  1162. 75.65 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.693980] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc1e8 irq 15 lpm-pol 0
  1163. 75.65 s [vm-test-run-centjes-e2e-test] client # [ 1.574229] SCSI subsystem initialized
  1164. 75.66 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.702238] ACPI: \_SB_.LNKB: Enabled at IRQ 11
  1165. 75.66 s [vm-test-run-centjes-e2e-test] client # [ 1.578746] serio: i8042 KBD port at 0x60,0x64 irq 1
  1166. 75.66 s [vm-test-run-centjes-e2e-test] client # [ 1.582824] ACPI: \_SB_.LNKC: Enabled at IRQ 10
  1167. 75.67 s [vm-test-run-centjes-e2e-test] client # [ 1.587749] uhci_hcd 0000:00:01.2: UHCI Host Controller
  1168. 75.67 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.712905] hub 1-0:1.0: USB hub found
  1169. 75.67 s [vm-test-run-centjes-e2e-test] client # [ 1.594763] serio: i8042 AUX port at 0x60,0x64 irq 12
  1170. 75.67 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.719741] hub 1-0:1.0: 2 ports detected
  1171. 75.68 s [vm-test-run-centjes-e2e-test] client # [ 1.605043] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
  1172. 75.70 s [vm-test-run-centjes-e2e-test] client # [ 1.619271] uhci_hcd 0000:00:01.2: detected 2 ports
  1173. 75.70 s [vm-test-run-centjes-e2e-test] client # [ 1.625669] ACPI: \_SB_.LNKA: Enabled at IRQ 10
  1174. 75.71 s [vm-test-run-centjes-e2e-test] client # [ 1.631278] uhci_hcd 0000:00:01.2: irq 11, io port 0x0000c100
  1175. 75.72 s [vm-test-run-centjes-e2e-test] client # [ 1.643685] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 6.12
  1176. 75.73 s [vm-test-run-centjes-e2e-test] client # [ 1.647844] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
  1177. 75.73 s [vm-test-run-centjes-e2e-test] client # [ 1.651513] usb usb1: Product: UHCI Host Controller
  1178. 75.73 s [vm-test-run-centjes-e2e-test] client # [ 1.654054] usb usb1: Manufacturer: Linux 6.12.62 uhci_hcd
  1179. 75.74 s [vm-test-run-centjes-e2e-test] client # [ 1.657265] usb usb1: SerialNumber: 0000:00:01.2
  1180. 75.74 s [vm-test-run-centjes-e2e-test] client # [ 1.661004] ACPI: \_SB_.LNKB: Enabled at IRQ 11
  1181. 75.74 s [vm-test-run-centjes-e2e-test] client # [ 1.665077] scsi host0: ata_piix
  1182. 75.75 s [vm-test-run-centjes-e2e-test] client # [ 1.669092] scsi host1: ata_piix
  1183. 75.76 s [vm-test-run-centjes-e2e-test] client # [ 1.677888] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc1e0 irq 14 lpm-pol 0
  1184. 75.76 s [vm-test-run-centjes-e2e-test] client # [ 1.682000] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc1e8 irq 15 lpm-pol 0
  1185. 75.77 s [vm-test-run-centjes-e2e-test] client # [ 1.693279] hub 1-0:1.0: USB hub found
  1186. 75.78 s [vm-test-run-centjes-e2e-test] client # [ 1.698009] hub 1-0:1.0: 2 ports detected
  1187. 75.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.852673] ata2: found unknown device (class 0)
  1188. 75.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.858603] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100
  1189. 75.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.864746] scsi 1:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5
  1190. 75.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.947532] usb 1-1: new full-speed USB device number 2 using uhci_hcd
  1191. 75.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.957139] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
  1192. 75.92 s [vm-test-run-centjes-e2e-test] client # [ 1.845357] ata2: found unknown device (class 0)
  1193. 75.93 s [vm-test-run-centjes-e2e-test] client # [ 1.850347] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100
  1194. 75.94 s [vm-test-run-centjes-e2e-test] client # [ 1.856650] scsi 1:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5
  1195. 75.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.986824] virtio_blk virtio5: 1/0/0 default/read/poll queues
  1196. 75.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.020164] virtio_blk virtio5: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)
  1197. 75.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.033956] netfs: FS-Cache loaded
  1198. 76.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.041122] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray
  1199. 76.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.044640] cdrom: Uniform CD-ROM driver Revision: 3.20
  1200. 76.00 s [vm-test-run-centjes-e2e-test] client # [ 1.924020] usb 1-1: new full-speed USB device number 2 using uhci_hcd
  1201. 76.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.056289] 9pnet: Installing 9P2000 support
  1202. 76.03 s [vm-test-run-centjes-e2e-test] client # [ 1.954565] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
  1203. 76.05 s [vm-test-run-centjes-e2e-test] client # [ 1.969894] virtio_blk virtio5: 1/0/0 default/read/poll queues
  1204. 76.08 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.129366] usb 1-1: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00
  1205. 76.09 s [vm-test-run-centjes-e2e-test] client # [ 2.005881] virtio_blk virtio5: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)
  1206. 76.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.133704] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=10
  1207. 76.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.137916] usb 1-1: Product: QEMU USB Tablet
  1208. 76.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.140521] usb 1-1: Manufacturer: QEMU
  1209. 76.10 s [vm-test-run-centjes-e2e-test] client # [ 2.019500] netfs: FS-Cache loaded
  1210. 76.10 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.142676] usb 1-1: SerialNumber: 28754-0000:00:01.2-1
  1211. 76.12 s [vm-test-run-centjes-e2e-test] client # [ 2.045531] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray
  1212. 76.13 s [vm-test-run-centjes-e2e-test] client # [ 2.049239] cdrom: Uniform CD-ROM driver Revision: 3.20
  1213. 76.13 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.161927] hid: raw HID events driver (C) Jiri Kosina
  1214. 76.13 s [vm-test-run-centjes-e2e-test] client # [ 2.053634] 9pnet: Installing 9P2000 support
  1215. 76.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.187864] usbcore: registered new interface driver usbhid
  1216. 76.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.190950] usbhid: USB HID core driver
  1217. 76.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.199856] 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
  1218. 76.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.207359] 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
  1219. 76.19 s [vm-test-run-centjes-e2e-test] client # [ 2.105329] usb 1-1: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00
  1220. 76.19 s [vm-test-run-centjes-e2e-test] client # [ 2.110032] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=10
  1221. 76.19 s [vm-test-run-centjes-e2e-test] client # [ 2.113642] usb 1-1: Product: QEMU USB Tablet
  1222. 76.19 s [vm-test-run-centjes-e2e-test] client # [ 2.115977] usb 1-1: Manufacturer: QEMU
  1223. 76.20 s [vm-test-run-centjes-e2e-test] client # [ 2.117989] usb 1-1: SerialNumber: 28754-0000:00:01.2-1
  1224. 76.23 s [vm-test-run-centjes-e2e-test] client # [ 2.137496] hid: raw HID events driver (C) Jiri Kosina
  1225. 76.24 s [vm-test-run-centjes-e2e-test] client # [ 2.164573] usbcore: registered new interface driver usbhid
  1226. 76.24 s [vm-test-run-centjes-e2e-test] client # [ 2.167566] usbhid: USB HID core driver
  1227. 76.26 s [vm-test-run-centjes-e2e-test] client # [ 2.176064] 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
  1228. 76.26 s [vm-test-run-centjes-e2e-test] client # [ 2.182065] 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
  1229. 76.42 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.463117] EXT4-fs (vda): mounted filesystem f4f559ea-093e-44f8-82ed-bc6d58a2eae9 r/w with ordered data mode. Quota mode: none.
  1230. 76.44 s [vm-test-run-centjes-e2e-test] client # [ 2.358096] EXT4-fs (vda): mounted filesystem 6a88f2e0-c70f-4f2f-9d3a-7ec2a70745ff r/w with ordered data mode. Quota mode: none.
  1231. 76.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.487680] 9p: Installing v9fs 9p2000 file system support
  1232. 76.46 s [vm-test-run-centjes-e2e-test] client # [ 2.382808] 9p: Installing v9fs 9p2000 file system support
  1233. 76.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.772580] EXT4-fs (vda): re-mounted f4f559ea-093e-44f8-82ed-bc6d58a2eae9.
  1234. 76.73 s [vm-test-run-centjes-e2e-test] client # [ 2.655045] EXT4-fs (vda): re-mounted 6a88f2e0-c70f-4f2f-9d3a-7ec2a70745ff.
  1235. 76.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.778593] booting system configuration /nix/store/57k706qpi8bkrxj1r9ryxw2ip600h1j1-nixos-system-docsserver-test
  1236. 76.93 s [vm-test-run-centjes-e2e-test] client # [ 2.660651] booting system configuration /nix/store/001k9r4jinw78ih5x5hxggb82ynlbkqn-nixos-system-client-test
  1237. 78.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 4.893362] systemd[1]: Inserted module 'autofs4'
  1238. 78.86 s [vm-test-run-centjes-e2e-test] client # [ 4.777243] systemd[1]: Inserted module 'autofs4'
  1239. 78.96 s [vm-test-run-centjes-e2e-test] client # [ 4.870089] 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)
  1240. 78.97 s [vm-test-run-centjes-e2e-test] client # [ 4.888076] systemd[1]: Detected virtualization kvm.
  1241. 78.97 s [vm-test-run-centjes-e2e-test] client # [ 4.891886] systemd[1]: Detected architecture x86-64.
  1242. 78.98 s [vm-test-run-centjes-e2e-test] client # [ 4.896291] systemd[1]: Detected first boot.
  1243. 78.99 s [vm-test-run-centjes-e2e-test] client # [ 4.907583] systemd[1]: Initializing machine ID from random generator.
  1244. 79.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.031138] 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)
  1245. 79.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.053295] systemd[1]: Detected virtualization kvm.
  1246. 79.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.057711] systemd[1]: Detected architecture x86-64.
  1247. 79.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.061827] systemd[1]: Detected first boot.
  1248. 79.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.073084] systemd[1]: Initializing machine ID from random generator.
  1249. 79.03 s [vm-test-run-centjes-e2e-test] client # [ 4.951725] systemd[1]: Hostname set to <client>.
  1250. 79.07 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.110596] systemd[1]: Hostname set to <docsserver>.
  1251. 79.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.272216] systemd[1]: bpf-restrict-fs: LSM BPF program attached
  1252. 79.28 s [vm-test-run-centjes-e2e-test] client # [ 5.205120] systemd[1]: bpf-restrict-fs: LSM BPF program attached
  1253. 79.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.607904] systemd[1]: Applying preset policy.
  1254. 79.63 s [vm-test-run-centjes-e2e-test] client # [ 5.551131] systemd[1]: Applying preset policy.
  1255. 80.24 s [vm-test-run-centjes-e2e-test] client # [ 6.158626] systemd[1]: Populated /etc with preset unit settings.
  1256. 80.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.289094] systemd[1]: Populated /etc with preset unit settings.
  1257. 80.69 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.733038] systemd[1]: /etc/systemd/system/centjes-docs-site-production.service:3: Invalid URL, ignoring: /nix/store/9cdw05a8w5l5a9y4cw65nzhydn68gn0h-settings-check
  1258. 80.78 s [vm-test-run-centjes-e2e-test] client # [ 6.698759] systemd[1]: Queued start job for default target Multi-User System.
  1259. 80.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.851661] systemd[1]: Queued start job for default target Multi-User System.
  1260. 80.81 s [vm-test-run-centjes-e2e-test] client # [ 6.734085] systemd[1]: Created slice Slice /system/getty.
  1261. 80.82 s [vm-test-run-centjes-e2e-test] client # [ 6.738168] systemd[1]: Created slice Slice /system/modprobe.
  1262. 80.82 s [vm-test-run-centjes-e2e-test] client # [ 6.742210] systemd[1]: Created slice User and Session Slice.
  1263. 80.83 s [vm-test-run-centjes-e2e-test] client # [ 6.746028] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
  1264. 80.83 s [vm-test-run-centjes-e2e-test] client # [ 6.750409] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
  1265. 80.83 s [vm-test-run-centjes-e2e-test] client # [ 6.754313] systemd[1]: Expecting device /dev/hvc0...
  1266. 80.83 s [vm-test-run-centjes-e2e-test] client # [ 6.756617] systemd[1]: Expecting device /dev/ttyS0...
  1267. 80.84 s [vm-test-run-centjes-e2e-test] client # [ 6.758836] systemd[1]: Expecting device /sys/subsystem/net/devices/eth1...
  1268. 80.84 s [vm-test-run-centjes-e2e-test] client # [ 6.761686] systemd[1]: Reached target Local Encrypted Volumes.
  1269. 80.84 s [vm-test-run-centjes-e2e-test] client # [ 6.764210] systemd[1]: Reached target Virtual Machines and Containers.
  1270. 80.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.888739] systemd[1]: Created slice Slice /system/getty.
  1271. 80.84 s [vm-test-run-centjes-e2e-test] client # [ 6.767104] systemd[1]: Reached target Path Units.
  1272. 80.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.891951] systemd[1]: Created slice Slice /system/modprobe.
  1273. 80.85 s [vm-test-run-centjes-e2e-test] client # [ 6.769198] systemd[1]: Reached target Remote File Systems.
  1274. 80.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.895099] systemd[1]: Created slice User and Session Slice.
  1275. 80.85 s [vm-test-run-centjes-e2e-test] client # [ 6.771773] systemd[1]: Reached target Slice Units.
  1276. 80.85 s [vm-test-run-centjes-e2e-test] client # [ 6.774189] systemd[1]: Reached target Swaps.
  1277. 80.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.898197] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
  1278. 80.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.901711] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
  1279. 80.86 s [vm-test-run-centjes-e2e-test] client # [ 6.780785] systemd[1]: Listening on Process Core Dump Socket.
  1280. 80.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.906208] systemd[1]: Expecting device /dev/hvc0...
  1281. 80.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.908633] systemd[1]: Expecting device /dev/ttyS0...
  1282. 80.86 s [vm-test-run-centjes-e2e-test] client # [ 6.785744] systemd[1]: Listening on Credential Encryption/Decryption.
  1283. 80.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.911218] systemd[1]: Expecting device /sys/subsystem/net/devices/eth1...
  1284. 80.87 s [vm-test-run-centjes-e2e-test] client # [ 6.789046] systemd[1]: Listening on Journal Audit Socket.
  1285. 80.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.914245] systemd[1]: Reached target Local Encrypted Volumes.
  1286. 80.87 s [vm-test-run-centjes-e2e-test] client # [ 6.791475] systemd[1]: Listening on Journal Socket (/dev/log).
  1287. 80.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.916985] systemd[1]: Reached target Virtual Machines and Containers.
  1288. 80.87 s [vm-test-run-centjes-e2e-test] client # [ 6.794216] systemd[1]: Listening on Journal Sockets.
  1289. 80.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.919858] systemd[1]: Reached target Path Units.
  1290. 80.88 s [vm-test-run-centjes-e2e-test] client # [ 6.797173] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.
  1291. 80.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.922265] systemd[1]: Reached target Remote File Systems.
  1292. 80.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.924756] systemd[1]: Reached target Slice Units.
  1293. 80.88 s [vm-test-run-centjes-e2e-test] client # [ 6.800394] systemd[1]: Make TPM PCR Policy was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1294. 80.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.927055] systemd[1]: Reached target Swaps.
  1295. 80.88 s [vm-test-run-centjes-e2e-test] client # [ 6.805314] systemd[1]: Listening on udev Control Socket.
  1296. 80.89 s [vm-test-run-centjes-e2e-test] client # [ 6.808775] systemd[1]: Listening on udev Kernel Socket.
  1297. 80.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.934250] systemd[1]: Listening on Process Core Dump Socket.
  1298. 80.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.939793] systemd[1]: Listening on Credential Encryption/Decryption.
  1299. 80.89 s [vm-test-run-centjes-e2e-test] client # [ 6.816143] systemd[1]: Mounting Huge Pages File System...
  1300. 80.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.943235] systemd[1]: Listening on Journal Audit Socket.
  1301. 80.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.946342] systemd[1]: Listening on Journal Socket (/dev/log).
  1302. 80.90 s [vm-test-run-centjes-e2e-test] client # [ 6.822790] systemd[1]: Mounting POSIX Message Queue File System...
  1303. 80.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.949181] systemd[1]: Listening on Journal Sockets.
  1304. 80.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.952809] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.
  1305. 80.91 s [vm-test-run-centjes-e2e-test] client # [ 6.831897] systemd[1]: Mounting Kernel Debug File System...
  1306. 80.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.957151] systemd[1]: Make TPM PCR Policy was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1307. 80.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.962960] systemd[1]: Listening on udev Control Socket.
  1308. 80.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.966218] systemd[1]: Listening on udev Kernel Socket.
  1309. 80.92 s [vm-test-run-centjes-e2e-test] client # [ 6.847141] systemd[1]: Mounting Kernel Trace File System...
  1310. 80.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.975527] systemd[1]: Mounting Huge Pages File System...
  1311. 80.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.984316] systemd[1]: Mounting POSIX Message Queue File System...
  1312. 80.95 s [vm-test-run-centjes-e2e-test] client # [ 6.867729] systemd[1]: Starting Create List of Static Device Nodes...
  1313. 80.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.992845] systemd[1]: Mounting Kernel Debug File System...
  1314. 80.96 s [vm-test-run-centjes-e2e-test] client # [ 6.875262] systemd[1]: Load Kernel Module 9pnet_virtio was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!9pnet_virtio).
  1315. 80.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.006791] systemd[1]: Mounting Kernel Trace File System...
  1316. 80.98 s [vm-test-run-centjes-e2e-test] client # [ 6.898144] systemd[1]: Starting Load Kernel Module configfs...
  1317. 80.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.025861] systemd[1]: Starting Create List of Static Device Nodes...
  1318. 80.98 s [vm-test-run-centjes-e2e-test] client # [ 6.904160] systemd[1]: Load Kernel Module drm was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!drm).
  1319. 80.99 s [vm-test-run-centjes-e2e-test] client # [ 6.912727] systemd[1]: Starting Load Kernel Module efi_pstore...
  1320. 80.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.038160] systemd[1]: Load Kernel Module 9pnet_virtio was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!9pnet_virtio).
  1321. 81.00 s [vm-test-run-centjes-e2e-test] client # [ 6.921182] systemd[1]: Starting Load Kernel Module fuse...
  1322. 81.01 s [vm-test-run-centjes-e2e-test] client # [ 6.926100] systemd[1]: File System Check on Root Device was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/).
  1323. 81.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.055840] systemd[1]: Starting Load Kernel Module configfs...
  1324. 81.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.061365] systemd[1]: Load Kernel Module drm was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!drm).
  1325. 81.02 s [vm-test-run-centjes-e2e-test] client # [ 6.938315] 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).
  1326. 81.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.073567] systemd[1]: Starting Load Kernel Module efi_pstore...
  1327. 81.03 s [vm-test-run-centjes-e2e-test] client # [ 6.954251] systemd[1]: Starting Journal Service...
  1328. 81.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.081725] systemd[1]: Starting Load Kernel Module fuse...
  1329. 81.04 s [vm-test-run-centjes-e2e-test] client # [ 6.963448] systemd[1]: Starting Load Kernel Modules...
  1330. 81.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.087751] systemd[1]: File System Check on Root Device was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/).
  1331. 81.05 s [vm-test-run-centjes-e2e-test] client # [ 6.973732] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...
  1332. 81.06 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.099029] 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).
  1333. 81.07 s [vm-test-run-centjes-e2e-test] client # [ 6.986261] systemd[1]: Starting Remount Root and Kernel File Systems...
  1334. 81.07 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.118184] systemd[1]: Starting Journal Service...
  1335. 81.07 s [vm-test-run-centjes-e2e-test] client # [ 6.992888] systemd[1]: Early TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1336. 81.08 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.128731] systemd[1]: Starting Load Kernel Modules...
  1337. 81.09 s [vm-test-run-centjes-e2e-test] client # [ 7.010193] systemd[1]: Starting Coldplug All udev Devices...
  1338. 81.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.139610] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...
  1339. 81.10 s [vm-test-run-centjes-e2e-test] client # [ 7.026172] systemd[1]: Mounted Huge Pages File System.
  1340. 81.11 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.151698] systemd[1]: Starting Remount Root and Kernel File Systems...
  1341. 81.11 s [vm-test-run-centjes-e2e-test] client # [ 7.033679] systemd[1]: Mounted POSIX Message Queue File System.
  1342. 81.11 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.159565] systemd[1]: Early TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1343. 81.12 s [vm-test-run-centjes-e2e-test] client # [ 7.039556] systemd[1]: Mounted Kernel Debug File System.
  1344. 81.12 s [vm-test-run-centjes-e2e-test] client # [ 7.045341] systemd[1]: Mounted Kernel Trace File System.
  1345. 81.13 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.174956] systemd[1]: Starting Coldplug All udev Devices...
  1346. 81.13 s [vm-test-run-centjes-e2e-test] client # [ 7.054373] systemd[1]: Finished Create List of Static Device Nodes.
  1347. 81.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.189791] systemd[1]: Mounted Huge Pages File System.
  1348. 81.15 s [vm-test-run-centjes-e2e-test] client # [ 7.071184] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...
  1349. 81.15 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.196208] systemd[1]: Mounted POSIX Message Queue File System.
  1350. 81.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.201946] systemd[1]: Mounted Kernel Debug File System.
  1351. 81.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.208177] systemd[1]: Mounted Kernel Trace File System.
  1352. 81.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.217636] systemd[1]: Finished Create List of Static Device Nodes.
  1353. 81.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.232829] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...
  1354. 81.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.249156] systemd[1]: modprobe@configfs.service: Deactivated successfully.
  1355. 81.20 s [vm-test-run-centjes-e2e-test] client # [ 7.126314] systemd[1]: modprobe@configfs.service: Deactivated successfully.
  1356. 81.21 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.255824] systemd[1]: Finished Load Kernel Module configfs.
  1357. 81.21 s [vm-test-run-centjes-e2e-test] client # [ 7.133889] systemd[1]: Finished Load Kernel Module configfs.
  1358. 81.22 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.262172] systemd[1]: modprobe@efi_pstore.service: Deactivated successfully.
  1359. 81.22 s [vm-test-run-centjes-e2e-test] client # [ 7.144873] systemd[1]: Mounting Kernel Configuration File System...
  1360. 81.22 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.270394] systemd[1]: Finished Load Kernel Module efi_pstore.
  1361. 81.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.281790] systemd[1]: Mounting Kernel Configuration File System...
  1362. 81.25 s [vm-test-run-centjes-e2e-test] client # [ 7.171293] systemd[1]: modprobe@efi_pstore.service: Deactivated successfully.
  1363. 81.25 s [vm-test-run-centjes-e2e-test] client # [ 7.176485] EXT4-fs (vda): re-mounted 6a88f2e0-c70f-4f2f-9d3a-7ec2a70745ff.
  1364. 81.26 s [vm-test-run-centjes-e2e-test] client # [ 7.180771] systemd[1]: Finished Load Kernel Module efi_pstore.
  1365. 81.27 s [vm-test-run-centjes-e2e-test] client # [ 7.188865] systemd[1]: Mounted Kernel Configuration File System.
  1366. 81.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.318080] systemd[1]: Mounted Kernel Configuration File System.
  1367. 81.28 s [vm-test-run-centjes-e2e-test] client # [ 7.200131] loop: module loaded
  1368. 81.30 s [vm-test-run-centjes-e2e-test] client # [ 7.221702] systemd[1]: Finished Remount Root and Kernel File Systems.
  1369. 81.30 s [vm-test-run-centjes-e2e-test] client # [ 7.224750] systemd-journald[379]: Collecting audit messages is enabled.
  1370. 81.30 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.348748] EXT4-fs (vda): re-mounted f4f559ea-093e-44f8-82ed-bc6d58a2eae9.
  1371. 81.31 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.352926] fuse: init (API version 7.41)
  1372. 81.31 s [vm-test-run-centjes-e2e-test] client # [ 7.229593] systemd[1]: Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore).
  1373. 81.31 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.358719] loop: module loaded
  1374. 81.32 s [vm-test-run-centjes-e2e-test] client # [ 7.238672] fuse: init (API version 7.41)
  1375. 81.32 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.367243] systemd-journald[384]: Collecting audit messages is enabled.
  1376. 81.32 s [vm-test-run-centjes-e2e-test] client # [ 7.245252] systemd[1]: Starting Load/Save OS Random Seed...
  1377. 81.33 s [vm-test-run-centjes-e2e-test] client # [ 7.250724] systemd[1]: TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1378. 81.33 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.379066] systemd[1]: modprobe@fuse.service: Deactivated successfully.
  1379. 81.34 s [vm-test-run-centjes-e2e-test] client # [ 7.263105] systemd[1]: Finished Load Kernel Modules.
  1380. 81.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.386736] systemd[1]: Finished Load Kernel Module fuse.
  1381. 81.35 s [vm-test-run-centjes-e2e-test] client # [ 7.270680] systemd[1]: modprobe@fuse.service: Deactivated successfully.
  1382. 81.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.395670] systemd[1]: Finished Load Kernel Modules.
  1383. 81.36 s [vm-test-run-centjes-e2e-test] client # [ 7.278136] systemd[1]: Finished Load Kernel Module fuse.
  1384. 81.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.403842] systemd[1]: Finished Remount Root and Kernel File Systems.
  1385. 81.37 s [vm-test-run-centjes-e2e-test] client # [ 7.290131] systemd[1]: Mounting FUSE Control File System...
  1386. 81.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.415808] systemd[1]: Mounting FUSE Control File System...
  1387. 81.38 s [vm-test-run-centjes-e2e-test] client # [ 7.302495] systemd[1]: Starting Firewall...
  1388. 81.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.427217] systemd[1]: Starting Firewall...
  1389. 81.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.431949] systemd[1]: Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore).
  1390. 81.39 s [vm-test-run-centjes-e2e-test] client # [ 7.316770] systemd[1]: Starting Apply Kernel Variables...
  1391. 81.41 s [vm-test-run-centjes-e2e-test] client # [ 7.328632] systemd[1]: Mounted FUSE Control File System.
  1392. 81.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.453786] systemd[1]: Starting Load/Save OS Random Seed...
  1393. 81.42 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.469296] systemd[1]: Starting Apply Kernel Variables...
  1394. 81.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.475180] systemd[1]: TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1395. 81.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.489776] systemd[1]: Mounted FUSE Control File System.
  1396. 81.47 s [vm-test-run-centjes-e2e-test] client # [ 7.388696] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
  1397. 81.48 s [vm-test-run-centjes-e2e-test] client # [ 7.401551] systemd[1]: Starting Create Static Device Nodes in /dev...
  1398. 81.50 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.540948] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
  1399. 81.50 s [vm-test-run-centjes-e2e-test] client # [ 7.421795] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.
  1400. 81.51 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.553739] systemd[1]: Starting Create Static Device Nodes in /dev...
  1401. 81.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.576370] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.
  1402. 81.55 s [vm-test-run-centjes-e2e-test] client # [ 7.475516] systemd[1]: Finished Apply Kernel Variables.
  1403. 81.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.642278] systemd[1]: Finished Apply Kernel Variables.
  1404. 81.62 s [vm-test-run-centjes-e2e-test] client # [ 7.544780] systemd[1]: Finished Create Static Device Nodes in /dev.
  1405. 81.63 s [vm-test-run-centjes-e2e-test] client # [ 7.552211] systemd[1]: Reached target Preparation for Local File Systems.
  1406. 81.64 s [vm-test-run-centjes-e2e-test] client # [ 7.562414] systemd[1]: Starting Rule-based Manager for Device Events and Files...
  1407. 81.66 s [vm-test-run-centjes-e2e-test] client # [ 7.582608] systemd[1]: Finished Load/Save OS Random Seed.
  1408. 81.66 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.710601] systemd[1]: Finished Load/Save OS Random Seed.
  1409. 81.67 s [vm-test-run-centjes-e2e-test] client # [ 7.588487] systemd[1]: Reached target First Boot Complete.
  1410. 81.67 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.717000] systemd[1]: Reached target First Boot Complete.
  1411. 81.68 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.729793] systemd[1]: Finished Create Static Device Nodes in /dev.
  1412. 81.69 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.735996] systemd[1]: Reached target Preparation for Local File Systems.
  1413. 81.70 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.747627] systemd[1]: Starting Rule-based Manager for Device Events and Files...
  1414. 81.87 s [vm-test-run-centjes-e2e-test] client # [ 7.797464] systemd[1]: Started Journal Service.
  1415. 81.89 s [vm-test-run-centjes-e2e-test] client # [ 7.382180] systemd-modules-load[380]: Inserted module 'loop'
  1416. 81.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.943603] systemd[1]: Started Journal Service.
  1417. 81.94 s [vm-test-run-centjes-e2e-test] client # [ 7.389990] systemd-oomd[381]: [0;1;38:5:185mNo swap; memory pressure usage will be degraded
  1418. 81.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.517524] systemd-modules-load[385]: Inserted module 'loop'
  1419. 81.94 s [vm-test-run-centjes-e2e-test] client # [ 7.409455] systemd-udevd[403]: Using default interface naming scheme 'v258'.
  1420. 81.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.533428] systemd-oomd[386]: [0;1;38:5:185mNo swap; memory pressure usage will be degraded
  1421. 81.94 s [vm-test-run-centjes-e2e-test] client # [ 7.428785] systemd[1]: Starting Flush Journal to Persistent Storage...
  1422. 81.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.554654] systemd-udevd[409]: Using default interface naming scheme 'v258'.
  1423. 81.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.569736] systemd[1]: Starting Flush Journal to Persistent Storage...
  1424. 82.01 s [vm-test-run-centjes-e2e-test] client # [ 7.928203] systemd-journald[379]: Received client request to flush runtime journal.
  1425. 82.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.071860] systemd-journald[384]: Received client request to flush runtime journal.
  1426. 82.32 s [vm-test-run-centjes-e2e-test] client # [ 7.819460] systemd[1]: Finished Coldplug All udev Devices.
  1427. 82.34 s [vm-test-run-centjes-e2e-test] client # [ 7.834589] systemd[1]: Started Rule-based Manager for Device Events and Files.
  1428. 82.35 s [vm-test-run-centjes-e2e-test] client # [ 7.848536] systemd[1]: Mounting /run/wrappers...
  1429. 82.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.970600] systemd[1]: Finished Coldplug All udev Devices.
  1430. 82.36 s [vm-test-run-centjes-e2e-test] client # [ 7.860348] systemd[1]: Mounted /run/wrappers.
  1431. 82.37 s [vm-test-run-centjes-e2e-test] client # [ 7.866400] systemd[1]: Reached target Local File Systems.
  1432. 82.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.992888] systemd[1]: Started Rule-based Manager for Device Events and Files.
  1433. 82.38 s [vm-test-run-centjes-e2e-test] client # [ 7.876655] systemd[1]: Listening on Boot Entries Service Socket.
  1434. 82.39 s [vm-test-run-centjes-e2e-test] client # [ 7.888388] systemd[1]: Starting Create SUID/SGID Wrappers...
  1435. 82.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.007871] systemd[1]: Mounting /run/wrappers...
  1436. 82.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.020578] systemd[1]: Mounted /run/wrappers.
  1437. 82.41 s [vm-test-run-centjes-e2e-test] client # [ 7.896774] systemd[1]: Update Boot Loader Random Seed was skipped because no trigger condition checks were met.
  1438. 82.42 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.032330] systemd[1]: Reached target Local File Systems.
  1439. 82.43 s [vm-test-run-centjes-e2e-test] client # [ 7.918811] systemd[1]: Starting Save Transient machine-id to Disk...
  1440. 82.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.044278] systemd[1]: Listening on Boot Entries Service Socket.
  1441. 82.44 s [vm-test-run-centjes-e2e-test] client # [ 7.930344] systemd[1]: Finished Flush Journal to Persistent Storage.
  1442. 82.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.053607] systemd[1]: Starting Create SUID/SGID Wrappers...
  1443. 82.44 s [vm-test-run-centjes-e2e-test] client # [ 7.939338] systemd[1]: Starting Create System Files and Directories...
  1444. 82.45 s [vm-test-run-centjes-e2e-test] client # [ 7.949201] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
  1445. 82.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.063284] systemd[1]: Update Boot Loader Random Seed was skipped because no trigger condition checks were met.
  1446. 82.47 s [vm-test-run-centjes-e2e-test] client # [ 7.958797] systemd[1]: Finished Save Transient machine-id to Disk.
  1447. 82.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.084338] systemd[1]: Starting Save Transient machine-id to Disk...
  1448. 82.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.093875] systemd[1]: Finished Flush Journal to Persistent Storage.
  1449. 82.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.104345] systemd[1]: Starting Create System Files and Directories...
  1450. 82.50 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.112620] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
  1451. 82.51 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.123564] systemd[1]: Finished Save Transient machine-id to Disk.
  1452. 82.53 s [vm-test-run-centjes-e2e-test] client # [ 8.027169] systemd[1]: Finished Create System Files and Directories.
  1453. 82.54 s [vm-test-run-centjes-e2e-test] client # [ 8.036778] systemd[1]: Starting Rebuild Journal Catalog...
  1454. 82.56 s [vm-test-run-centjes-e2e-test] client # [ 8.048793] systemd[1]: Starting Record System Boot/Shutdown in UTMP...
  1455. 82.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.186516] systemd[1]: Finished Create System Files and Directories.
  1456. 82.67 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.280926] systemd[1]: Starting Rebuild Journal Catalog...
  1457. 82.67 s [vm-test-run-centjes-e2e-test] client # [ 8.162394] systemd[1]: Finished Record System Boot/Shutdown in UTMP.
  1458. 82.75 s [vm-test-run-centjes-e2e-test] client # [ 8.245233] systemd[1]: Finished Rebuild Journal Catalog.
  1459. 82.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.351614] systemd[1]: Starting Record System Boot/Shutdown in UTMP...
  1460. 82.76 s [vm-test-run-centjes-e2e-test] client # [ 8.253471] systemd[1]: Starting Update is Completed...
  1461. 82.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.376728] systemd[1]: Found device /dev/hvc0.
  1462. 82.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.388293] systemd[1]: Found device /dev/ttyS0.
  1463. 82.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.461741] systemd[1]: Finished Record System Boot/Shutdown in UTMP.
  1464. 82.85 s [vm-test-run-centjes-e2e-test] client # [ 8.348396] systemd[1]: Finished Update is Completed.
  1465. 82.87 s [vm-test-run-centjes-e2e-test] client # [ 8.364211] systemd[1]: Found device /dev/hvc0.
  1466. 82.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.539172] systemd[1]: Finished Rebuild Journal Catalog.
  1467. 82.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.546910] systemd[1]: Starting Update is Completed...
  1468. 82.96 s [vm-test-run-centjes-e2e-test] client # [ 8.460297] systemd[1]: Found device /dev/ttyS0.
  1469. 82.99 s [vm-test-run-centjes-e2e-test] client # [ 8.474990] (udev-worker)[488]: [0;1;38:5:185meth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.
  1470. 83.01 s [vm-test-run-centjes-e2e-test] client # [ 8.496985] (udev-worker)[488]: Network interface NamePolicy= disabled on kernel command line.
  1471. 83.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.625812] systemd[1]: Finished Update is Completed.
  1472. 83.03 s [vm-test-run-centjes-e2e-test] client # [ 8.520326] (udev-worker)[490]: Network interface NamePolicy= disabled on kernel command line.
  1473. 83.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.642529] (udev-worker)[504]: Network interface NamePolicy= disabled on kernel command line.
  1474. 83.06 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.661497] (udev-worker)[494]: [0;1;38:5:185meth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.
  1475. 83.07 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.679434] (udev-worker)[494]: Network interface NamePolicy= disabled on kernel command line.
  1476. 83.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.212015] mousedev: PS/2 mouse device common for all mice
  1477. 83.22 s [vm-test-run-centjes-e2e-test] client # [ 8.713868] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.
  1478. 83.23 s [vm-test-run-centjes-e2e-test] client # [ 8.727317] systemd[1]: Finished Create SUID/SGID Wrappers.
  1479. 83.24 s [vm-test-run-centjes-e2e-test] client # [ 8.735800] systemd[1]: Reached target System Initialization.
  1480. 83.27 s [vm-test-run-centjes-e2e-test] client # [ 8.749781] systemd[1]: Started Discard unused filesystem blocks once a week.
  1481. 83.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.886587] systemd[1]: Found device Virtio network device.
  1482. 83.29 s [vm-test-run-centjes-e2e-test] client # [ 8.774354] systemd[1]: Started Daily Cleanup of Temporary Directories.
  1483. 83.31 s [vm-test-run-centjes-e2e-test] client # [ 8.797336] systemd[1]: Reached target Timer Units.
  1484. 83.33 s [vm-test-run-centjes-e2e-test] client # [ 8.808584] systemd[1]: Listening on D-Bus System Message Bus Socket.
  1485. 83.34 s [vm-test-run-centjes-e2e-test] client # [ 8.827731] systemd[1]: Listening on Nix Daemon Socket.
  1486. 83.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.957294] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.
  1487. 83.36 s [vm-test-run-centjes-e2e-test] client # [ 8.843630] systemd[1]: Listening on Hostname Service Socket.
  1488. 83.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.973311] systemd[1]: Finished Create SUID/SGID Wrappers.
  1489. 83.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.981438] systemd[1]: Reached target System Initialization.
  1490. 83.39 s [vm-test-run-centjes-e2e-test] client # [ 8.873988] systemd[1]: Reached target Socket Units.
  1491. 83.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.992593] systemd[1]: Started Discard unused filesystem blocks once a week.
  1492. 83.41 s [vm-test-run-centjes-e2e-test] client # [ 8.895764] systemd[1]: Reached target Basic System.
  1493. 83.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.018612] systemd[1]: Started Daily Cleanup of Temporary Directories.[ 9.458298] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input3
  1494. 83.42 s [vm-test-run-centjes-e2e-test] docsserver #
  1495. 83.42 s [vm-test-run-centjes-e2e-test] client # [ 8.915276] systemd[1]: Started backdoor.service.
  1496. 83.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.041523] systemd[1]: Reached target Timer Units.
  1497. 83.45 s [vm-test-run-centjes-e2e-test] client # [ 8.932410] systemd[1]: Starting Import lastlog data into lastlog2 database...
  1498. 83.45 s [vm-test-run-centjes-e2e-test] client # connecting to host...
  1499. 83.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.058616] systemd[1]: Listening on D-Bus System Message Bus Socket.
  1500. 83.48 s [vm-test-run-centjes-e2e-test] client # [ 8.961688] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
  1501. 83.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.083486] systemd[1]: Listening on Nix Daemon Socket.
  1502. 83.50 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.106451] systemd[1]: Listening on Hostname Service Socket.
  1503. 83.51 s [vm-test-run-centjes-e2e-test] client # [ 8.995700] systemd[1]: Started Reset console on configuration changes.
  1504. 83.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.128588] systemd[1]: Reached target Socket Units.
  1505. 83.53 s [vm-test-run-centjes-e2e-test] client # [ 9.016671] systemd[1]: Starting resolvconf update...
  1506. 83.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.149905] systemd[1]: Reached target Basic System.
  1507. 83.56 s [vm-test-run-centjes-e2e-test] client # [ 9.034968] nsncd[608]: Jun 01 20:24:41.611 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
  1508. 83.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.164401] systemd[1]: Started backdoor.service.
  1509. 83.57 s [vm-test-run-centjes-e2e-test] client # [ 9.062539] systemd[1]: Starting D-Bus System Message Bus...
  1510. 83.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.183279] systemd[1]: Starting Import lastlog data into lastlog2 database...
  1511. 83.58 s [vm-test-run-centjes-e2e-test] docsserver # connecting to host...
  1512. 83.59 s [vm-test-run-centjes-e2e-test] client # [ 9.073709] dbus-daemon[612]: dbus[612]: Unknown username "systemd-timesync" in message bus configuration file
  1513. 83.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.200640] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
  1514. 83.60 s [vm-test-run-centjes-e2e-test] client # [ 9.093873] systemd[1]: Found device Virtio network device.
  1515. 83.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.225234] systemd[1]: Started Reset console on configuration changes.
  1516. 83.62 s [vm-test-run-centjes-e2e-test] client # [ 9.111220] systemd[1]: Finished Import lastlog data into lastlog2 database.
  1517. 83.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.245735] systemd[1]: Starting resolvconf update...[ 9.684726] ACPI: button: Power Button [PWRF]
  1518. 83.64 s [vm-test-run-centjes-e2e-test] docsserver #
  1519. 83.65 s [vm-test-run-centjes-e2e-test] client # [ 9.142179] systemd[1]: Started Name Service Cache Daemon (nsncd).
  1520. 83.65 s [vm-test-run-centjes-e2e-test] client # [ 9.149471] systemd[1]: Reached target Host and Network Name Lookups.
  1521. 83.66 s [vm-test-run-centjes-e2e-test] client # [ 9.155632] systemd[1]: Reached target User and Group Name Lookups.
  1522. 83.67 s [vm-test-run-centjes-e2e-test] docsserver: Guest shell says: b'Spawning backdoor root shell...\n'
  1523. 83.68 s [vm-test-run-centjes-e2e-test] docsserver: connected to guest root shell
  1524. 83.68 s [vm-test-run-centjes-e2e-test] docsserver: (connecting took 10.46 seconds)
  1525. 83.68 s [vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for the VM to finish booting, in 10.46 seconds)
  1526. 83.68 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.266751] nsncd[613]: Jun 01 20:24:41.701 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
  1527. 83.68 s [vm-test-run-centjes-e2e-test] client # [ 9.162585] systemd[1]: Starting User Login Management...
  1528. 83.68 s [vm-test-run-centjes-e2e-test] client # [ 9.172333] systemd[1]: Finished Firewall.
  1529. 83.70 s [vm-test-run-centjes-e2e-test] client # [ 9.188585] systemd[1]: Started D-Bus System Message Bus.
  1530. 83.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.306739] systemd[1]: Started Centjes docs site production Service.
  1531. 83.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.328588] dbus-daemon[618]: dbus[618]: Unknown username "systemd-timesync" in message bus configuration file
  1532. 83.75 s [vm-test-run-centjes-e2e-test] client # [ 9.241132] systemd[1]: Stopped target Host and Network Name Lookups.
  1533. 83.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.356876] systemd[1]: Starting D-Bus System Message Bus...
  1534. 83.76 s [vm-test-run-centjes-e2e-test] client # [ 9.250411] systemd[1]: Stopping Host and Network Name Lookups...
  1535. 83.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.378576] systemd[1]: Finished Import lastlog data into lastlog2 database.[ 9.811276] rtc_cmos 00:05: RTC can wake from S4
  1536. 83.77 s [vm-test-run-centjes-e2e-test] docsserver #
  1537. 83.78 s [vm-test-run-centjes-e2e-test] client # [ 9.266737] systemd[1]: Stopped target User and Group Name Lookups.
  1538. 83.79 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.394415] systemd[1]: Started Name Service Cache Daemon (nsncd).
  1539. 83.79 s [vm-test-run-centjes-e2e-test] client # [ 9.283508] systemd[1]: Stopping User and Group Name Lookups...
  1540. 83.80 s [vm-test-run-centjes-e2e-test] client # [ 9.293987] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...
  1541. 83.81 s [vm-test-run-centjes-e2e-test] client # [ 9.303362] systemd[1]: nscd.service: Deactivated successfully.
  1542. 83.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.415175] systemd[1]: Reached target Host and Network Name Lookups.
  1543. 83.82 s [vm-test-run-centjes-e2e-test] client # [ 9.312401] systemd[1]: Stopped Name Service Cache Daemon (nsncd).
  1544. 83.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.428988] systemd[1]: Reached target User and Group Name Lookups.
  1545. 83.83 s [vm-test-run-centjes-e2e-test] client # [ 9.321922] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
  1546. 83.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.441473] systemd[1]: Starting User Login Management...
  1547. 83.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.453964] systemd[1]: Finished Firewall.
  1548. 83.84 s [vm-test-run-centjes-e2e-test] client # [ 9.334781] systemd-logind[633]: New seat seat0.
  1549. 83.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.458865] systemd[1]: Started D-Bus System Message Bus.
  1550. 83.85 s [vm-test-run-centjes-e2e-test] client # [ 9.345669] systemd[1]: Started User Login Management.
  1551. 83.86 s [vm-test-run-centjes-e2e-test] client # [ 9.355379] systemd[1]: Starting linger-users.service...
  1552. 83.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.502692] systemd[1]: Stopped target Host and Network Name Lookups.[ 9.935202] rtc_cmos 00:05: registered as rtc0
  1553. 83.89 s [vm-test-run-centjes-e2e-test] docsserver #
  1554. 83.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.516218] systemd[1]: Stopping Host and Network Name Lookups...
  1555. 83.90 s [vm-test-run-centjes-e2e-test] client # [ 9.396274] systemd[1]: Started Name Service Cache Daemon (nsncd).
  1556. 83.91 s [vm-test-run-centjes-e2e-test] client # [ 9.407478] systemd[1]: Reached target Host and Network Name Lookups.
  1557. 83.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.530736] systemd[1]: Stopped target User and Group Name Lookups.[ 9.967047] parport_pc 00:03: reported by Plug and Play ACPI
  1558. 83.92 s [vm-test-run-centjes-e2e-test] docsserver #
  1559. 83.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.544983] systemd[1]: Stopping User and Group Name Lookups...
  1560. 83.93 s [vm-test-run-centjes-e2e-test] client # [ 9.416833] nsncd[679]: Jun 01 20:24:42.018 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
  1561. 83.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.556416] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...[ 9.987794] rtc_cmos 00:05: setting system clock to 2026-06-01T20:24:42 UTC (1780345482)
  1562. 83.94 s [vm-test-run-centjes-e2e-test] docsserver #
  1563. 83.94 s [vm-test-run-centjes-e2e-test] client # [ 9.438531] systemd[1]: Reached target User and Group Name Lookups.[ 9.866643] mousedev: PS/2 mouse device common for all mice
  1564. 83.94 s [vm-test-run-centjes-e2e-test] client #
  1565. 83.95 s [vm-test-run-centjes-e2e-test] client # [ 9.446729] systemd[1]: linger-users.service: Deactivated successfully.
  1566. 83.95 s [vm-test-run-centjes-e2e-test] client # [ 9.450153] systemd[1]: Finished linger-users.service.
  1567. 83.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.569983] systemd-logind[642]: New seat seat0.
  1568. 83.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.005158] Floppy drive(s): fd0 is 2.88M AMI BIOS
  1569. 83.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.015056] parport0: PC-style at 0x378, irq 7 [PCSPP(,...)]
  1570. 83.97 s [vm-test-run-centjes-e2e-test] client # [ 9.470213] systemd[1]: Finished resolvconf update.
  1571. 83.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.023363] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs
  1572. 83.98 s [vm-test-run-centjes-e2e-test] client # [ 9.476668] systemd[1]: Reached target Preparation for Network.[ 9.902739] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input3
  1573. 83.98 s [vm-test-run-centjes-e2e-test] client #
  1574. 83.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.600171] systemd[1]: Started User Login Management.
  1575. 83.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.603459] systemd[1]: nscd.service: Deactivated successfully.
  1576. 83.99 s [vm-test-run-centjes-e2e-test] client # [ 9.486617] systemd[1]: Starting DHCP Client...
  1577. 84.00 s [vm-test-run-centjes-e2e-test] client # [ 9.496449] systemd[1]: Starting Address configuration of eth1...
  1578. 84.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.615602] systemd[1]: Stopped Name Service Cache Daemon (nsncd).[ 10.051508] FDC 0 is a S82078B
  1579. 84.00 s [vm-test-run-centjes-e2e-test] docsserver #
  1580. 84.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.638211] systemd[1]: Starting linger-users.service...
  1581. 84.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.649468] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
  1582. 84.05 s [vm-test-run-centjes-e2e-test] client # [ 9.969796] ACPI: button: Power Button [PWRF]
  1583. 84.10 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.711899] systemd[1]: Finished resolvconf update.
  1584. 84.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.718898] systemd[1]: Reached target Preparation for Network.
  1585. 84.13 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.737305] systemd[1]: Starting DHCP Client...
  1586. 84.15 s [vm-test-run-centjes-e2e-test] client # [ 9.638281] network-addresses-eth1-start[709]: adding address 192.168.1.1/24... done
  1587. 84.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.764445] systemd[1]: Starting Address configuration of eth1...
  1588. 84.18 s [vm-test-run-centjes-e2e-test] client # [ 9.672204] network-addresses-eth1-start[709]: adding address 2001:db8:1::1/64... done
  1589. 84.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.788455] systemd[1]: linger-users.service: Deactivated successfully.
  1590. 84.21 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.811544] systemd[1]: Finished linger-users.service.
  1591. 84.23 s [vm-test-run-centjes-e2e-test] client # [ 9.716332] systemd[1]: Finished Address configuration of eth1.
  1592. 84.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.833319] systemd[1]: Started Name Service Cache Daemon (nsncd).
  1593. 84.23 s [vm-test-run-centjes-e2e-test] client # [ 9.728962] systemd[1]: Starting Networking Setup...
  1594. 84.25 s [vm-test-run-centjes-e2e-test] client # [ 10.175576] rtc_cmos 00:05: RTC can wake from S4
  1595. 84.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.855395] nsncd[708]: Jun 01 20:24:42.770 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
  1596. 84.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.884856] systemd[1]: Reached target Host and Network Name Lookups.
  1597. 84.29 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.898351] systemd[1]: Reached target User and Group Name Lookups.
  1598. 84.32 s [vm-test-run-centjes-e2e-test] client # [ 9.816261] dhcpcd[716]: dhcpcd-10.2.4 starting[ 10.241320] parport_pc 00:03: reported by Plug and Play ACPI
  1599. 84.32 s [vm-test-run-centjes-e2e-test] client #
  1600. 84.33 s [vm-test-run-centjes-e2e-test] client # [ 10.252206] rtc_cmos 00:05: registered as rtc0
  1601. 84.34 s [vm-test-run-centjes-e2e-test] client # [ 10.258215] Floppy drive(s): fd0 is 2.88M AMI BIOS
  1602. 84.35 s [vm-test-run-centjes-e2e-test] client # [ 10.269087] parport0: PC-style at 0x378, irq 7 [PCSPP(,...)]
  1603. 84.35 s [vm-test-run-centjes-e2e-test] client # [ 9.850757] dhcpcd[729]: dev: loaded udev
  1604. 84.37 s [vm-test-run-centjes-e2e-test] client # [ 10.290525] rtc_cmos 00:05: setting system clock to 2026-06-01T20:24:43 UTC (1780345483)
  1605. 84.38 s [vm-test-run-centjes-e2e-test] client # [ 10.304563] FDC 0 is a S82078B
  1606. 84.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.006691] network-addresses-eth1-start[720]: adding address 192.168.1.2/24... done
  1607. 84.40 s [vm-test-run-centjes-e2e-test] client # [ 10.324307] 8021q: 802.1Q VLAN Support v1.8
  1608. 84.41 s [vm-test-run-centjes-e2e-test] client # [ 10.328576] 8021q: adding VLAN 0 to HW filter on device eth1
  1609. 84.43 s [vm-test-run-centjes-e2e-test] client # [ 10.355302] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs
  1610. 84.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.052256] network-addresses-eth1-start[720]: adding address 2001:db8:1::2/64... done
  1611. 84.50 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.113581] systemd[1]: Finished Address configuration of eth1.
  1612. 84.51 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.123634] systemd[1]: Starting Networking Setup...
  1613. 84.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.567949] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0
  1614. 84.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.214498] dhcpcd[739]: dhcpcd-10.2.4 starting
  1615. 84.61 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.657674] i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD
  1616. 84.62 s [vm-test-run-centjes-e2e-test] client # [ 10.541886] cfg80211: Loading compiled-in X.509 certificates for regulatory database
  1617. 84.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.258563] dhcpcd[751]: dev: loaded udev
  1618. 84.65 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.701588] 8021q: 802.1Q VLAN Support v1.8
  1619. 84.66 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.706695] 8021q: adding VLAN 0 to HW filter on device eth1
  1620. 84.66 s [vm-test-run-centjes-e2e-test] client # [ 10.584778] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
  1621. 84.67 s [vm-test-run-centjes-e2e-test] client # [ 10.589157] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'
  1622. 84.68 s [vm-test-run-centjes-e2e-test] client # [ 10.598211] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
  1623. 84.68 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.723809] input: QEMU Virtio Keyboard as /devices/pci0000:00/0000:00:0a.0/virtio7/input/input4
  1624. 84.69 s [vm-test-run-centjes-e2e-test] client # [ 10.605687] cfg80211: failed to load regulatory.db
  1625. 84.70 s [vm-test-run-centjes-e2e-test] client # [ 10.624621] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0
  1626. 84.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.774902] bochs-drm 0000:00:02.0: vgaarb: deactivate vga console
  1627. 84.76 s [vm-test-run-centjes-e2e-test] client # [ 10.250516] systemd[1]: Finished Networking Setup.
  1628. 84.76 s [vm-test-run-centjes-e2e-test] client # [ 10.259134] systemd[1]: Reached target Network.
  1629. 84.77 s [vm-test-run-centjes-e2e-test] client # [ 10.690315] i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD
  1630. 84.78 s [vm-test-run-centjes-e2e-test] client # [ 10.277147] systemd[1]: Starting Permit User Sessions...
  1631. 84.81 s [vm-test-run-centjes-e2e-test] client # [ 10.727837] input: QEMU Virtio Keyboard as /devices/pci0000:00/0000:00:0a.0/virtio7/input/input4
  1632. 84.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.849784] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input6
  1633. 84.84 s [vm-test-run-centjes-e2e-test] client # [ 10.762538] bochs-drm 0000:00:02.0: vgaarb: deactivate vga console
  1634. 84.85 s [vm-test-run-centjes-e2e-test] client # [ 10.773199] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input6
  1635. 84.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.850628] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input5
  1636. 84.88 s [vm-test-run-centjes-e2e-test] client # [ 10.376560] dhcpcd[729]: eth0: waiting for carrier
  1637. 84.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.860601] cryptd: max_cpu_qlen set to 1000
  1638. 84.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.882704] Console: switching to colour dummy device 80x25
  1639. 84.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.893072] cfg80211: Loading compiled-in X.509 certificates for regulatory database
  1640. 84.90 s [vm-test-run-centjes-e2e-test] client # [ 10.397365] systemd[1]: Finished Permit User Sessions.
  1641. 84.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.938822] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
  1642. 84.91 s [vm-test-run-centjes-e2e-test] client # [ 10.791775] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input5
  1643. 84.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.938979] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'
  1644. 84.91 s [vm-test-run-centjes-e2e-test] client # [ 10.798399] 8021q: adding VLAN 0 to HW filter on device eth0
  1645. 84.92 s [vm-test-run-centjes-e2e-test] client # [ 10.803537] Console: switching to colour dummy device 80x25
  1646. 84.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.941610] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
  1647. 84.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.941619] cfg80211: failed to load regulatory.db
  1648. 84.92 s [vm-test-run-centjes-e2e-test] client # [ 10.421420] systemd[1]: Started Getty on tty1.[ 10.846201] [drm] Found bochs VGA, ID 0xb0c5.
  1649. 84.92 s [vm-test-run-centjes-e2e-test] client # [ 10.847376] [drm] Framebuffer size 16384 kB @ 0xfd000000, mmio @ 0xfebd0000.
  1650. 84.92 s [vm-test-run-centjes-e2e-test] client #
  1651. 84.93 s [vm-test-run-centjes-e2e-test] client # [ 10.427372] systemd[1]: Reached target Login Prompts.
  1652. 84.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.956894] AES CTR mode by8 optimization enabled
  1653. 84.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.977686] [drm] Found bochs VGA, ID 0xb0c5.
  1654. 84.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.978954] [drm] Framebuffer size 16384 kB @ 0xfd000000, mmio @ 0xfebd0000.
  1655. 84.94 s [vm-test-run-centjes-e2e-test] client # [ 10.861329] [drm] Found EDID data blob.
  1656. 84.94 s [vm-test-run-centjes-e2e-test] client # [ 10.867135] [drm] Initialized bochs-drm 1.0.0 for 0000:00:02.0 on minor 0
  1657. 84.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.569571] systemd[1]: Finished Networking Setup.
  1658. 84.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.577922] systemd[1]: Reached target Network.
  1659. 84.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.583668] systemd[1]: Starting Permit User Sessions...
  1660. 85.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.044322] [drm] Found EDID data blob.
  1661. 85.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.059320] [drm] Initialized bochs-drm 1.0.0 for 0000:00:02.0 on minor 0
  1662. 85.71 s [vm-test-run-centjes-e2e-test] client # [ 11.210912] dhcpcd[729]: eth0: carrier acquired
  1663. 85.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.429261] systemd[1]: Finished Permit User Sessions.
  1664. 85.90 s [vm-test-run-centjes-e2e-test] client # [ 10.876318] fbcon: bochs-drmdrmfb (fb0) is primary device
  1665. 85.90 s [vm-test-run-centjes-e2e-test] client # [ 11.643791] Console: switching to colour frame buffer device 160x50
  1666. 85.91 s [vm-test-run-centjes-e2e-test] client # [ 11.828602] bochs-drm 0000:00:02.0: [drm] fb0: bochs-drmdrmfb frame buffer device
  1667. 85.92 s [vm-test-run-centjes-e2e-test] client # [ 11.417622] dhcpcd[729]: DUID 00:01:00:01:31:b0:a7:0d:52:54:00:12:34:56
  1668. 85.92 s [vm-test-run-centjes-e2e-test] client # [ 11.421569] dhcpcd[729]: eth0: IAID 00:12:34:56
  1669. 85.93 s [vm-test-run-centjes-e2e-test] client # [ 11.425408] dhcpcd[729]: eth0: adding address fe80::5054:ff:fe12:3456
  1670. 85.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.435644] dhcpcd[751]: eth0: waiting for carrier[ 11.080316] fbcon: bochs-drmdrmfb (fb0) is primary device
  1671. 85.97 s [vm-test-run-centjes-e2e-test] docsserver #
  1672. 85.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.589212] dhcpcd[751]: libudev: received NULL device
  1673. 85.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.847166] 8021q: adding VLAN 0 to HW filter on device eth0
  1674. 85.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.595251] dhcpcd[751]: libudev: received NULL device
  1675. 85.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.599588] dhcpcd[751]: eth0: carrier acquired[ 11.868596] Console: switching to colour frame buffer device 160x50
  1676. 85.99 s [vm-test-run-centjes-e2e-test] docsserver #
  1677. 85.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.034775] bochs-drm 0000:00:02.0: [drm] fb0: bochs-drmdrmfb frame buffer device
  1678. 86.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.612551] systemd[1]: Started Getty on tty1.
  1679. 86.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.618425] systemd[1]: Reached target Login Prompts.
  1680. 86.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.625398] dhcpcd[751]: DUID 00:01:00:01:31:b0:a7:0c:52:54:00:12:34:56
  1681. 86.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.631754] dhcpcd[751]: eth0: IAID 00:12:34:56
  1682. 86.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.635953] dhcpcd[751]: eth0: adding address fe80::5054:ff:fe12:3456
  1683. 86.02 s [vm-test-run-centjes-e2e-test] client # [ 11.945668] cryptd: max_cpu_qlen set to 1000
  1684. 86.06 s [vm-test-run-centjes-e2e-test] client # [ 11.986304] AES CTR mode by8 optimization enabled
  1685. 86.13 s [vm-test-run-centjes-e2e-test] client # [ 11.630232] systemd[1]: Starting Virtual Console Setup...
  1686. 86.20 s [vm-test-run-centjes-e2e-test] client # [ 11.691799] systemd-logind[633]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard)
  1687. 86.21 s [vm-test-run-centjes-e2e-test] client # [ 11.703508] systemd-logind[633]: Watching system buttons on /dev/input/event2 (Power Button)
  1688. 86.25 s [vm-test-run-centjes-e2e-test] client # [ 12.172553] ppdev: user-space parallel port driver
  1689. 86.28 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.323208] kvm_amd: TSC scaling supported
  1690. 86.28 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.324334] kvm_amd: Nested Virtualization enabled
  1691. 86.28 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.325536] kvm_amd: Nested Paging enabled
  1692. 86.29 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.326627] kvm_amd: LBR virtualization supported
  1693. 86.29 s [vm-test-run-centjes-e2e-test] client # [ 11.777796] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
  1694. 86.31 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.922466] systemd[1]: Starting Virtual Console Setup...
  1695. 86.32 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.930511] systemd-logind[642]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard)
  1696. 86.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.956863] systemd-logind[642]: Watching system buttons on /dev/input/event2 (Power Button)[ 12.388552] kvm_amd: Virtual VMLOAD VMSAVE supported
  1697. 86.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.389834] kvm_amd: Virtual GIF supported
  1698. 86.35 s [vm-test-run-centjes-e2e-test] docsserver #
  1699. 86.39 s [vm-test-run-centjes-e2e-test] client # [ 11.885910] systemd-logind[633]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)
  1700. 86.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.454349] ppdev: user-space parallel port driver
  1701. 86.42 s [vm-test-run-centjes-e2e-test] client # [ 11.913888] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
  1702. 86.43 s [vm-test-run-centjes-e2e-test] client # [ 11.925614] systemd[1]: Stopped Virtual Console Setup.
  1703. 86.44 s [vm-test-run-centjes-e2e-test] client # [ 11.935560] systemd[1]: Starting Virtual Console Setup...
  1704. 86.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.067428] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
  1705. 86.47 s [vm-test-run-centjes-e2e-test] client # [ 11.965449] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
  1706. 86.48 s [vm-test-run-centjes-e2e-test] client # [ 11.975712] systemd[1]: Stopped Virtual Console Setup.
  1707. 86.49 s [vm-test-run-centjes-e2e-test] client # [ 11.985805] systemd[1]: Starting Virtual Console Setup...
  1708. 86.50 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.547058] EDAC MC: Ver: 3.0.0
  1709. 86.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.134852] systemd-logind[642]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)
  1710. 86.57 s [vm-test-run-centjes-e2e-test] client # [ 12.492618] kvm_amd: TSC scaling supported
  1711. 86.57 s [vm-test-run-centjes-e2e-test] client # [ 12.493847] kvm_amd: Nested Virtualization enabled
  1712. 86.57 s [vm-test-run-centjes-e2e-test] client # [ 12.495112] kvm_amd: Nested Paging enabled
  1713. 86.57 s [vm-test-run-centjes-e2e-test] client # [ 12.496233] kvm_amd: LBR virtualization supported
  1714. 86.58 s [vm-test-run-centjes-e2e-test] client # [ 12.504273] kvm_amd: Virtual VMLOAD VMSAVE supported
  1715. 86.58 s [vm-test-run-centjes-e2e-test] client # [ 12.505622] kvm_amd: Virtual GIF supported
  1716. 86.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.210599] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
  1717. 86.61 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.224371] systemd[1]: Stopped Virtual Console Setup.
  1718. 86.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.230529] systemd[1]: Starting Virtual Console Setup...
  1719. 86.64 s [vm-test-run-centjes-e2e-test] client # [ 12.560068] EDAC MC: Ver: 3.0.0
  1720. 86.66 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.267805] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
  1721. 86.66 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.276983] systemd[1]: Stopped Virtual Console Setup.
  1722. 86.66 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.279560] systemd[1]: Starting Virtual Console Setup...
  1723. 86.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.435334] dhcpcd[751]: eth0: soliciting a DHCP lease
  1724. 86.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.886774] NET: Registered PF_PACKET protocol family
  1725. 86.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.468288] dhcpcd[751]: eth0: offered 10.0.2.15 from 10.0.2.2
  1726. 86.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.472339] dhcpcd[751]: eth0: probing address 10.0.2.15/24
  1727. 87.01 s [vm-test-run-centjes-e2e-test] client # [ 12.512201] systemd[1]: Finished Virtual Console Setup.
  1728. 87.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 12.780926] systemd[1]: Finished Virtual Console Setup.
  1729. 87.52 s [vm-test-run-centjes-e2e-test] client # [ 13.021313] dhcpcd[729]: eth0: soliciting a DHCP lease
  1730. 87.54 s [vm-test-run-centjes-e2e-test] client # [ 13.466660] NET: Registered PF_PACKET protocol family
  1731. 87.55 s [vm-test-run-centjes-e2e-test] client # [ 13.053870] dhcpcd[729]: eth0: offered 10.0.2.15 from 10.0.2.2
  1732. 87.56 s [vm-test-run-centjes-e2e-test] client # [ 13.057381] dhcpcd[729]: eth0: probing address 10.0.2.15/24
  1733. 87.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.457118] dhcpcd[751]: eth0: soliciting an IPv6 router
  1734. 87.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.459977] dhcpcd[751]: eth0: Router Advertisement from fe80::2
  1735. 87.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.462334] dhcpcd[751]: eth0: adding address fec0::5054:ff:fe12:3456/64
  1736. 87.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.464599] dhcpcd[751]: eth0: adding route to fec0::/64
  1737. 87.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 13.466462] dhcpcd[751]: eth0: adding default route via fe80::2
  1738. 88.14 s [vm-test-run-centjes-e2e-test] client # [ 13.637413] dhcpcd[729]: eth0: soliciting an IPv6 router
  1739. 88.14 s [vm-test-run-centjes-e2e-test] client # [ 13.640352] dhcpcd[729]: eth0: Router Advertisement from fe80::2
  1740. 88.14 s [vm-test-run-centjes-e2e-test] client # [ 13.642467] dhcpcd[729]: eth0: adding address fec0::5054:ff:fe12:3456/64
  1741. 88.14 s [vm-test-run-centjes-e2e-test] client # [ 13.644644] dhcpcd[729]: eth0: adding route to fec0::/64
  1742. 88.15 s [vm-test-run-centjes-e2e-test] client # [ 13.646552] dhcpcd[729]: eth0: adding default route via fe80::2
  1743. 91.45 s [vm-test-run-centjes-e2e-test] docsserver # [ 17.067319] dhcpcd[751]: eth0: leased 10.0.2.15 for 86400 seconds
  1744. 91.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 17.071214] dhcpcd[751]: eth0: adding route to 10.0.2.0/24
  1745. 91.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 17.074454] dhcpcd[751]: eth0: adding default route via 10.0.2.2
  1746. 91.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 17.195529] systemd[1]: Started DHCP Client.
  1747. 91.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 17.199980] systemd[1]: Reached target Multi-User System.
  1748. 91.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 17.202154] systemd[1]: Startup finished in 4.372s (kernel) + 12.825s (userspace) = 17.197s.
  1749. 91.66 s [vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for unit default.target, in 18.43 seconds)
  1750. 91.66 s [vm-test-run-centjes-e2e-test] client: waiting for unit default.target
  1751. 91.66 s [vm-test-run-centjes-e2e-test] client: waiting for the VM to finish booting
  1752. 91.66 s [vm-test-run-centjes-e2e-test] client: Guest shell says: b'Spawning backdoor root shell...\n'
  1753. 91.66 s [vm-test-run-centjes-e2e-test] client: connected to guest root shell
  1754. 91.66 s [vm-test-run-centjes-e2e-test] client: (connecting took 0.00 seconds)
  1755. 91.66 s [vm-test-run-centjes-e2e-test] client: (finished: waiting for the VM to finish booting, in 0.00 seconds)
  1756. 92.40 s [vm-test-run-centjes-e2e-test] client # [ 17.897944] dhcpcd[729]: eth0: leased 10.0.2.15 for 86400 seconds
  1757. 92.42 s [vm-test-run-centjes-e2e-test] client # [ 17.900673] dhcpcd[729]: eth0: adding route to 10.0.2.0/24
  1758. 92.42 s [vm-test-run-centjes-e2e-test] client # [ 17.903441] dhcpcd[729]: eth0: adding default route via 10.0.2.2
  1759. 92.53 s [vm-test-run-centjes-e2e-test] client # [ 18.025323] systemd[1]: Started DHCP Client.
  1760. 92.53 s [vm-test-run-centjes-e2e-test] client # [ 18.031173] systemd[1]: Reached target Multi-User System.
  1761. 92.54 s [vm-test-run-centjes-e2e-test] client # [ 18.033353] systemd[1]: Startup finished in 4.269s (kernel) + 13.760s (userspace) = 18.029s.
  1762. 92.90 s [vm-test-run-centjes-e2e-test] client: (finished: waiting for unit default.target, in 1.24 seconds)
  1763. 92.98 s [vm-test-run-centjes-e2e-test] docsserver: waiting for unit centjes-docs-site-production.service
  1764. 93.03 s [vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for unit centjes-docs-site-production.service, in 0.06 seconds)
  1765. 93.03 s [vm-test-run-centjes-e2e-test] docsserver: waiting for unit default.target
  1766. 93.09 s [vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for unit default.target, in 0.06 seconds)
  1767. 93.09 s [vm-test-run-centjes-e2e-test] docsserver: waiting for TCP port 8001 on localhost
  1768. 93.17 s [vm-test-run-centjes-e2e-test] docsserver # Connection to localhost (127.0.0.1) 8001 port [tcp/vcom-tunnel] succeeded!
  1769. 93.17 s [vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for TCP port 8001 on localhost, in 0.08 seconds)
  1770. 93.17 s [vm-test-run-centjes-e2e-test] client: must succeed: curl docsserver:8001
  1771. 93.26 s [vm-test-run-centjes-e2e-test] client # % Total % Received % Xferd Average Speed Time Time Time Current
  1772. 93.28 s [vm-test-run-centjes-e2e-test] client # Dload Upload Total Spent Left Speed
  1773. 93.31 s [vm-test-run-centjes-e2e-test] docsserver # [ 18.920691] centjes-docs-site-production-start[627]: 192.168.1.1 - - [01/Jun/2026:20:24:51 +0000] "GET / HTTP/1.1" 200 3595 "" "curl/8.17.0"
  1774. 93.32 s [vm-test-run-centjes-e2e-test] client # 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0100 3595 100 3595 0 0 55161 0 --:--:-- --:--:-- --:--:-- 56171
  1775. 93.33 s [vm-test-run-centjes-e2e-test] client: (finished: must succeed: curl docsserver:8001, in 0.16 seconds)
  1776. 93.33 s [vm-test-run-centjes-e2e-test] (finished: run the VM test script, in 20.52 seconds)
  1777. 93.46 s [vm-test-run-centjes-e2e-test] test script finished in 20.65s
  1778. 93.46 s [vm-test-run-centjes-e2e-test] cleanup
  1779. 93.46 s [vm-test-run-centjes-e2e-test] kill machine (pid 31)
  1780. 93.46 s [vm-test-run-centjes-e2e-test] qemu-system-x86_64: terminating on signal 15 from pid 6 (/nix/store/jj6jldlw37r8yy9kc1smrax9dhnjm2x4-python3-3.13.9/bin/python3.13)
  1781. 93.47 s [vm-test-run-centjes-e2e-test] kill machine (pid 9)
  1782. 93.47 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)
  1783. 93.49 s [vm-test-run-centjes-e2e-test] kill vlan (pid 7)
  1784. 93.49 s [vm-test-run-centjes-e2e-test] (finished: cleanup, in 0.03 seconds)
  1785. 93.59 s [post-build-hook] Uploading to cachix cache "centjes": /nix/store/vc90d4rs5n8yc61v0bzwdq1jrqkdlfny-vm-test-run-centjes-e2e-test
  1786. 93.95 s [post-build-hook] Pushing 1 paths (0 are already present) using zstd to cache centjes ⏳
  1787. 93.95 s [post-build-hook]
  1788. 94.40 s [post-build-hook] Pushing /nix/store/vc90d4rs5n8yc61v0bzwdq1jrqkdlfny-vm-test-run-centjes-e2e-test (96.00 B)
  1789. 95.49 s [post-build-hook]
  1790. 95.49 s [post-build-hook] All done.
  1791. 95.50 s [post-build-hook] Uploading to the NixCI staging cache: /nix/store/vc90d4rs5n8yc61v0bzwdq1jrqkdlfny-vm-test-run-centjes-e2e-test
  1792. 95.56 s [post-build-hook] copying 1 paths...
  1793. 95.56 s [post-build-hook] copying path '/nix/store/vc90d4rs5n8yc61v0bzwdq1jrqkdlfny-vm-test-run-centjes-e2e-test' to 'https://cache.staging.nix-ci.com'...
  1794. 96.33 s [post-build-hook] copying 1 paths...
  1795. 96.34 s [post-build-hook] copying path '/nix/store/saxaa2rskvlg4j667qj2yvg60p9kgjw3-vm-test-run-centjes-e2e-test.drv' to 'https://cache.staging.nix-ci.com'...
  1796. 96.93 s Progress: 16 of 17 built, 8 of 8 downloaded from cache
More Logs Raw Logs

Agent Instructions

Wait for completion, without logs:

curl --netrc -N https://staging.nix-ci.com/gh:NorfairKing:centjes/master/fdf64ecd406db54f98fff6dc0f1717ee1a0702c1/014f72a6-8007-4a51-b75f-723c4f1bccc0/wait

Latest logs, with timestamps (streams while running):

curl --netrc -N https://staging.nix-ci.com/gh:NorfairKing:centjes/master/fdf64ecd406db54f98fff6dc0f1717ee1a0702c1/014f72a6-8007-4a51-b75f-723c4f1bccc0/tail

All logs, with timestamps (available after completion):

curl --netrc https://staging.nix-ci.com/gh:NorfairKing:centjes/master/fdf64ecd406db54f98fff6dc0f1717ee1a0702c1/014f72a6-8007-4a51-b75f-723c4f1bccc0/logs

Raw logs, from the start (no timestamps):

curl --netrc -N https://staging.nix-ci.com/gh:NorfairKing:centjes/master/fdf64ecd406db54f98fff6dc0f1717ee1a0702c1/014f72a6-8007-4a51-b75f-723c4f1bccc0/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/master/fdf64ecd406db54f98fff6dc0f1717ee1a0702c1/014f72a6-8007-4a51-b75f-723c4f1bccc0/logs

Reproduce locally: https://staging.nix-ci.com/gh:NorfairKing:centjes/master/fdf64ecd406db54f98fff6dc0f1717ee1a0702c1/014f72a6-8007-4a51-b75f-723c4f1bccc0/repro

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