build checks.x86_64-linux.e2e-test

Reproduce this run
  1. 0.13 s $ /nix/store/9ypz3flqsrl5xl495mm8h645gadjsxi1-coreutils-9.11/bin/timeout --kill-after=15s 7200s /nix/store/23zk8sgzamrbmj1fday15szf7f2279s8-nix-2.34.7/bin/nix --extra-experimental-features nix-command --extra-experimental-features flakes --log-format internal-json build --no-link --print-out-paths git+https://github.com/NorfairKing/centjes?ref=virtual-assertions&rev=5b28b734206cf997a043907b38d89a39384fd866&shallow=1#checks.x86_64-linux.e2e-test --print-build-logs
  2. 0.15 s warning: ignoring untrusted flake configuration setting 'extra-substituters'.
  3. 0.15 s Pass '--accept-flake-config' to trust it
  4. 0.15 s warning: ignoring untrusted flake configuration setting 'extra-trusted-public-keys'.
  5. 0.15 s Pass '--accept-flake-config' to trust it
  6. 7.70 s
  7. 10.06 s Waiting for lock on centjes-switzerland-0.0.0-doc
  8. 55.12 s Waiting for lock on centjes-docs-site-source
  9. 60.15 s Waiting for lock on centjes-docs-site
  10. 80.26 s Building /nix/store/kajg1s0iqk2sbbv8w5sd5rla6cbxkxyi-settings-check.drv
  11. 80.28 s Building /nix/store/b8d6h6an01dczd8vr3vcnypb90b6j82k-unit-script-centjes-docs-site-production-start.drv
  12. 80.33 s [unit-script-centjes-docs-site-production-start:post-build] Uploading to cachix cache "centjes": /nix/store/33lh8aggac4by8xnrkp8mch5bby1aazv-unit-script-centjes-docs-site-production-start
  13. 80.69 s [unit-script-centjes-docs-site-production-start:post-build] Pushing 1 paths (29 are already present) using zstd to cache centjes ⏳
  14. 80.69 s [unit-script-centjes-docs-site-production-start:post-build]
  15. 81.05 s [unit-script-centjes-docs-site-production-start:post-build] Pushing /nix/store/33lh8aggac4by8xnrkp8mch5bby1aazv-unit-script-centjes-docs-site-production-start (680.00 B)
  16. 81.96 s [unit-script-centjes-docs-site-production-start:post-build]
  17. 81.96 s [unit-script-centjes-docs-site-production-start:post-build] All done.
  18. 81.98 s [unit-script-centjes-docs-site-production-start:post-build] Uploading to the NixCI staging cache: /nix/store/33lh8aggac4by8xnrkp8mch5bby1aazv-unit-script-centjes-docs-site-production-start
  19. 82.02 s [unit-script-centjes-docs-site-production-start:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  20. 82.26 s [unit-script-centjes-docs-site-production-start:post-build] copying 1 paths...
  21. 82.26 s [unit-script-centjes-docs-site-production-start:post-build] copying path '/nix/store/33lh8aggac4by8xnrkp8mch5bby1aazv-unit-script-centjes-docs-site-production-start' to 'https://cache.staging.nix-ci.com'...
  22. 82.46 s [unit-script-centjes-docs-site-production-start:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  23. 82.68 s [unit-script-centjes-docs-site-production-start:post-build] copying 1 paths...
  24. 82.68 s [unit-script-centjes-docs-site-production-start:post-build] copying path '/nix/store/b8d6h6an01dczd8vr3vcnypb90b6j82k-unit-script-centjes-docs-site-production-start.drv' to 'https://cache.staging.nix-ci.com'...
  25. 82.86 s Uploaded unit-script-centjes-docs-site-production-start in 2.5s
  26. 82.86 s Progress: 1 of 13 built (1 building)
  27. 82.86 s Built unit-script-centjes-docs-site-production-start in 2.5s
  28. 82.88 s [settings-check:post-build] Uploading to cachix cache "centjes": /nix/store/ig0311v4pin291dbyiwcgd2dri09a4k8-settings-check
  29. 83.28 s [settings-check:post-build] Pushing 1 paths (30 are already present) using zstd to cache centjes ⏳
  30. 83.28 s [settings-check:post-build]
  31. 83.65 s [settings-check:post-build] Pushing /nix/store/ig0311v4pin291dbyiwcgd2dri09a4k8-settings-check (880.00 B)
  32. 84.57 s [settings-check:post-build]
  33. 84.57 s [settings-check:post-build] All done.
  34. 84.58 s [settings-check:post-build] Uploading to the NixCI staging cache: /nix/store/ig0311v4pin291dbyiwcgd2dri09a4k8-settings-check
  35. 84.63 s [settings-check:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  36. 84.63 s [settings-check:post-build] copying 1 paths...
  37. 84.64 s [settings-check:post-build] copying path '/nix/store/ig0311v4pin291dbyiwcgd2dri09a4k8-settings-check' to 'https://cache.staging.nix-ci.com'...
  38. 84.86 s [settings-check:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  39. 85.34 s [settings-check:post-build] copying 1 paths...
  40. 85.36 s [settings-check:post-build] copying path '/nix/store/kajg1s0iqk2sbbv8w5sd5rla6cbxkxyi-settings-check.drv' to 'https://cache.staging.nix-ci.com'...
  41. 85.53 s Uploaded settings-check in 2.6s
  42. 85.53 s Progress: 2 of 13 built
  43. 85.53 s Built settings-check in 5.2s
  44. 85.55 s Building /nix/store/zcph62ggq8f7id593cy9y956niwn4apq-settings-check.drv
  45. 85.58 s [settings-check] WithConfig: src/Centjes/Docs/Site/OptParse.hs:27:7 in centjes-docs-site:Centjes.Docs.Site.OptParse
  46. 85.58 s [settings-check] loading config
  47. 85.59 s [settings-check] Parser with check: src/Centjes/Docs/Site/OptParse.hs:27:7 in centjes-docs-site:Centjes.Docs.Site.OptParse
  48. 85.59 s [settings-check] parser
  49. 85.59 s [settings-check] Alt
  50. 85.59 s [settings-check] Trying left side.
  51. 85.59 s [settings-check] Parser with check: src/Centjes/Docs/Site/OptParse.hs:27:7 in centjes-docs-site:Centjes.Docs.Site.OptParse
  52. 85.59 s [settings-check] parser
  53. 85.59 s [settings-check] Setting: src/Centjes/Docs/Site/OptParse.hs:27:7 in centjes-docs-site:Centjes.Docs.Site.OptParse
  54. 85.59 s [settings-check] could not set based on options, no option: ["--config-file"]
  55. 85.59 s [settings-check] set based on env: "/nix/store/vb9vv8cg7xwfa7010fyznaj7b5syrx63-centjes-docs-site-config.yaml"
  56. 85.59 s [settings-check] check
  57. 85.59 s [settings-check] succeeded
  58. 85.59 s [settings-check] Left side succeeded.
  59. 85.59 s [settings-check] check
  60. 85.59 s [settings-check] succeeded
  61. 85.59 s [settings-check] with loaded config
  62. 85.59 s [settings-check] Ap
  63. 85.59 s [settings-check] Ap
  64. 85.59 s [settings-check] Parser with check: without srcLoc
  65. 85.59 s [settings-check] parser
  66. 85.62 s [settings-check] Setting: src/Centjes/Docs/Site/OptParse.hs:29:11 in centjes-docs-site:Centjes.Docs.Site.OptParse
  67. 85.62 s [settings-check] could not set based on options, no option: ["--port"]
  68. 85.62 s [settings-check] could not set based on env vars, no var: [EnvVarSetting {envVarSettingVar = "CENTJES_DOCS_SITE_PORT", envVarSettingAllowPrefix = True}]
  69. 85.62 s [settings-check] set based on config value: Number 8001.0
  70. 85.62 s [settings-check] check
  71. 85.62 s [settings-check] succeeded
  72. 85.62 s [settings-check] Alt
  73. 85.62 s [settings-check] Trying left side.
  74. 85.62 s [settings-check] Parser with check: without srcLoc
  75. 85.62 s [settings-check] parser
  76. 85.62 s [settings-check] Setting: src/Centjes/Docs/Site/OptParse.hs:38:13 in centjes-docs-site:Centjes.Docs.Site.OptParse
  77. 85.62 s [settings-check] could not set based on options, no option: ["--google-analytics-tracking"]
  78. 85.62 s [settings-check] could not set based on env vars, no var: [EnvVarSetting {envVarSettingVar = "CENTJES_DOCS_SITE_GOOGLE_ANALYTICS_TRACKING", envVarSettingAllowPrefix = True}]
  79. 85.62 s [settings-check] could not set based on config value, configured to nothing: ["google-analytics-tracking"]
  80. 85.62 s [settings-check] not found
  81. 85.62 s [settings-check] check
  82. 85.62 s [settings-check] Left side failed, trying right side.
  83. 85.62 s [settings-check] pure value
  84. 85.62 s [settings-check] Alt
  85. 85.62 s [settings-check] Trying left side.
  86. 85.62 s [settings-check] Parser with check: without srcLoc
  87. 85.62 s [settings-check] parser
  88. 85.62 s [settings-check] Setting: src/Centjes/Docs/Site/OptParse.hs:46:13 in centjes-docs-site:Centjes.Docs.Site.OptParse
  89. 85.62 s [settings-check] could not set based on options, no option: ["--google-search-console-verification"]
  90. 85.62 s [settings-check] could not set based on env vars, no var: [EnvVarSetting {envVarSettingVar = "CENTJES_DOCS_SITE_GOOGLE_SEARCH_CONSOLE_VERIFICATION", envVarSettingAllowPrefix = True}]
  91. 85.62 s [settings-check] could not set based on config value, configured to nothing: ["google-search-console-verification"]
  92. 85.62 s [settings-check] not found
  93. 85.62 s [settings-check] check
  94. 85.66 s [settings-check] Left side failed, trying right side.
  95. 85.66 s [settings-check] pure value
  96. 85.68 s [settings-check:post-build] Uploading to cachix cache "centjes": /nix/store/bp7ak7r85za1cwc3snhzm6cz1ypyh3wv-settings-check
  97. 86.05 s [settings-check:post-build] Pushing 1 paths (0 are already present) using zstd to cache centjes ⏳
  98. 86.05 s [settings-check:post-build]
  99. 86.42 s [settings-check:post-build] Pushing /nix/store/bp7ak7r85za1cwc3snhzm6cz1ypyh3wv-settings-check (144.00 B)
  100. 87.31 s [settings-check:post-build]
  101. 87.31 s [settings-check:post-build] All done.
  102. 87.32 s [settings-check:post-build] Uploading to the NixCI staging cache: /nix/store/bp7ak7r85za1cwc3snhzm6cz1ypyh3wv-settings-check
  103. 87.37 s [settings-check:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  104. 87.37 s [settings-check:post-build] copying 1 paths...
  105. 87.37 s [settings-check:post-build] copying path '/nix/store/bp7ak7r85za1cwc3snhzm6cz1ypyh3wv-settings-check' to 'https://cache.staging.nix-ci.com'...
  106. 87.49 s [settings-check:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  107. 88.28 s [settings-check:post-build] copying 1 paths...
  108. 88.28 s [settings-check:post-build] copying path '/nix/store/zcph62ggq8f7id593cy9y956niwn4apq-settings-check.drv' to 'https://cache.staging.nix-ci.com'...
  109. 88.54 s Uploaded settings-check in 2.8s
  110. 88.54 s Progress: 3 of 13 built
  111. 88.54 s Built settings-check in 2.9s
  112. 88.57 s Building /nix/store/plqd0rvv12rdrkv364arn8j5sp2hyz22-unit-centjes-docs-site-production.service.drv
  113. 88.62 s [unit-centjes-docs-site-production.service:post-build] Uploading to cachix cache "centjes": /nix/store/9cz2hif6s9wka0byi75l7jpgn54q0r51-unit-centjes-docs-site-production.service
  114. 89.00 s [unit-centjes-docs-site-production.service:post-build] Pushing 1 paths (91 are already present) using zstd to cache centjes ⏳
  115. 89.00 s [unit-centjes-docs-site-production.service:post-build]
  116. 89.36 s [unit-centjes-docs-site-production.service:post-build] Pushing /nix/store/9cz2hif6s9wka0byi75l7jpgn54q0r51-unit-centjes-docs-site-production.service (1.62 KiB)
  117. 90.48 s [unit-centjes-docs-site-production.service:post-build]
  118. 90.48 s [unit-centjes-docs-site-production.service:post-build] All done.
  119. 90.51 s [unit-centjes-docs-site-production.service:post-build] Uploading to the NixCI staging cache: /nix/store/9cz2hif6s9wka0byi75l7jpgn54q0r51-unit-centjes-docs-site-production.service
  120. 90.54 s [unit-centjes-docs-site-production.service:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  121. 90.70 s [unit-centjes-docs-site-production.service:post-build] copying 1 paths...
  122. 90.70 s [unit-centjes-docs-site-production.service:post-build] copying path '/nix/store/9cz2hif6s9wka0byi75l7jpgn54q0r51-unit-centjes-docs-site-production.service' to 'https://cache.staging.nix-ci.com'...
  123. 90.91 s [unit-centjes-docs-site-production.service:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  124. 91.19 s [unit-centjes-docs-site-production.service:post-build] copying 1 paths...
  125. 91.20 s [unit-centjes-docs-site-production.service:post-build] copying path '/nix/store/plqd0rvv12rdrkv364arn8j5sp2hyz22-unit-centjes-docs-site-production.service.drv' to 'https://cache.staging.nix-ci.com'...
  126. 91.38 s Uploaded unit-centjes-docs-site-production.service in 2.7s
  127. 91.38 s Progress: 4 of 13 built
  128. 91.38 s Built unit-centjes-docs-site-production.service in 2.8s
  129. 91.44 s Building /nix/store/g9afyhhwm9vfiq99h1syk7rnzb1n46b5-system-units.drv
  130. 92.20 s [system-units:post-build] Uploading to cachix cache "centjes": /nix/store/hvhyvg8xna322m8k7kj41agw2ypnm0vz-system-units
  131. 92.80 s [system-units:post-build] Pushing 1 paths (450 are already present) using zstd to cache centjes ⏳
  132. 92.80 s [system-units:post-build]
  133. 93.25 s [system-units:post-build] Pushing /nix/store/hvhyvg8xna322m8k7kj41agw2ypnm0vz-system-units (96.09 KiB)
  134. 94.27 s [system-units:post-build]
  135. 94.27 s [system-units:post-build] All done.
  136. 94.29 s [system-units:post-build] Uploading to the NixCI staging cache: /nix/store/hvhyvg8xna322m8k7kj41agw2ypnm0vz-system-units
  137. 94.33 s [system-units:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  138. 94.51 s [system-units:post-build] copying 1 paths...
  139. 94.51 s [system-units:post-build] copying path '/nix/store/hvhyvg8xna322m8k7kj41agw2ypnm0vz-system-units' to 'https://cache.staging.nix-ci.com'...
  140. 94.73 s [system-units:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  141. 95.07 s [system-units:post-build] copying 1 paths...
  142. 95.07 s [system-units:post-build] copying path '/nix/store/g9afyhhwm9vfiq99h1syk7rnzb1n46b5-system-units.drv' to 'https://cache.staging.nix-ci.com'...
  143. 95.26 s Uploaded system-units in 3.0s
  144. 95.26 s Progress: 5 of 13 built
  145. 95.26 s Built system-units in 3.8s
  146. 95.31 s Building /nix/store/cnq1ph2w7rcap51ci0nwf5gmgarh2h57-etc.drv
  147. 95.69 s [etc:post-build] Uploading to cachix cache "centjes": /nix/store/183a1d9nfwb22r6xg7bgkl8c3rd25vbm-etc
  148. 96.29 s [etc:post-build] Pushing 1 paths (546 are already present) using zstd to cache centjes ⏳
  149. 96.32 s [etc:post-build]
  150. 96.66 s [etc:post-build] Pushing /nix/store/183a1d9nfwb22r6xg7bgkl8c3rd25vbm-etc (31.56 KiB)
  151. 97.73 s [etc:post-build]
  152. 97.73 s [etc:post-build] All done.
  153. 97.75 s [etc:post-build] Uploading to the NixCI staging cache: /nix/store/183a1d9nfwb22r6xg7bgkl8c3rd25vbm-etc
  154. 97.79 s [etc:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  155. 97.96 s [etc:post-build] copying 1 paths...
  156. 97.97 s [etc:post-build] copying path '/nix/store/183a1d9nfwb22r6xg7bgkl8c3rd25vbm-etc' to 'https://cache.staging.nix-ci.com'...
  157. 98.18 s [etc:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  158. 98.46 s [etc:post-build] copying 1 paths...
  159. 98.46 s [etc:post-build] copying path '/nix/store/cnq1ph2w7rcap51ci0nwf5gmgarh2h57-etc.drv' to 'https://cache.staging.nix-ci.com'...
  160. 98.67 s Uploaded etc in 2.9s
  161. 98.67 s Progress: 6 of 13 built
  162. 98.67 s Built etc in 3.3s
  163. 98.74 s Building /nix/store/n8rk19azj14a89dg7yh4j5nwp9zkrdp8-nixos-system-docsserver-test.drv
  164. 98.82 s [nixos-system-docsserver-test:post-build] Uploading to cachix cache "centjes": /nix/store/65s8l6c9brrb1g3yskvbz60cb4rmq4db-nixos-system-docsserver-test
  165. 99.51 s [nixos-system-docsserver-test:post-build] Pushing 1 paths (568 are already present) using zstd to cache centjes ⏳
  166. 99.51 s [nixos-system-docsserver-test:post-build]
  167. 99.97 s [nixos-system-docsserver-test:post-build] Pushing /nix/store/65s8l6c9brrb1g3yskvbz60cb4rmq4db-nixos-system-docsserver-test (17.26 KiB)
  168. 100.88 s [nixos-system-docsserver-test:post-build]
  169. 100.88 s [nixos-system-docsserver-test:post-build] All done.
  170. 100.90 s [nixos-system-docsserver-test:post-build] Uploading to the NixCI staging cache: /nix/store/65s8l6c9brrb1g3yskvbz60cb4rmq4db-nixos-system-docsserver-test
  171. 100.94 s [nixos-system-docsserver-test:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  172. 101.11 s [nixos-system-docsserver-test:post-build] copying 1 paths...
  173. 101.11 s [nixos-system-docsserver-test:post-build] copying path '/nix/store/65s8l6c9brrb1g3yskvbz60cb4rmq4db-nixos-system-docsserver-test' to 'https://cache.staging.nix-ci.com'...
  174. 101.33 s [nixos-system-docsserver-test:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  175. 101.62 s [nixos-system-docsserver-test:post-build] copying 1 paths...
  176. 101.62 s [nixos-system-docsserver-test:post-build] copying path '/nix/store/n8rk19azj14a89dg7yh4j5nwp9zkrdp8-nixos-system-docsserver-test.drv' to 'https://cache.staging.nix-ci.com'...
  177. 101.88 s Uploaded nixos-system-docsserver-test in 3.0s
  178. 101.88 s Progress: 7 of 13 built
  179. 101.88 s Built nixos-system-docsserver-test in 3.1s
  180. 102.28 s Building /nix/store/kbpvq91gx1i1bbk5jm33z6zkz7bfxj0y-closure-info.drv
  181. 102.29 s [closure-info] structuredAttrs is enabled
  182. 102.37 s [closure-info:post-build] Uploading to cachix cache "centjes": /nix/store/ildfwjvkp1mgxjlcmj4jd3l802909i52-closure-info
  183. 102.81 s [closure-info:post-build] Pushing 1 paths (569 are already present) using zstd to cache centjes ⏳
  184. 102.81 s [closure-info:post-build]
  185. 103.18 s [closure-info:post-build] Pushing /nix/store/ildfwjvkp1mgxjlcmj4jd3l802909i52-closure-info (228.66 KiB)
  186. 104.12 s [closure-info:post-build]
  187. 104.12 s [closure-info:post-build] All done.
  188. 104.14 s [closure-info:post-build] Uploading to the NixCI staging cache: /nix/store/ildfwjvkp1mgxjlcmj4jd3l802909i52-closure-info
  189. 104.18 s [closure-info:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  190. 104.21 s [closure-info:post-build] copying 1 paths...
  191. 104.22 s [closure-info:post-build] copying path '/nix/store/ildfwjvkp1mgxjlcmj4jd3l802909i52-closure-info' to 'https://cache.staging.nix-ci.com'...
  192. 104.53 s [closure-info:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  193. 104.84 s [closure-info:post-build] copying 1 paths...
  194. 104.84 s [closure-info:post-build] copying path '/nix/store/kbpvq91gx1i1bbk5jm33z6zkz7bfxj0y-closure-info.drv' to 'https://cache.staging.nix-ci.com'...
  195. 105.03 s Uploaded closure-info in 2.6s
  196. 105.03 s Progress: 8 of 13 built
  197. 105.03 s Built closure-info in 2.7s
  198. 105.08 s Building /nix/store/0ifg8fkfgd8w8mj74a4ipszqzh8w39ac-run-nixos-vm.drv
  199. 105.15 s [run-nixos-vm:post-build] Uploading to cachix cache "centjes": /nix/store/hm0jrf3h3g89wzzhyv95z64y4hkz4akx-run-nixos-vm
  200. 105.98 s [run-nixos-vm:post-build] Pushing 1 paths (580 are already present) using zstd to cache centjes ⏳
  201. 105.98 s [run-nixos-vm:post-build]
  202. 106.37 s [run-nixos-vm:post-build] Pushing /nix/store/hm0jrf3h3g89wzzhyv95z64y4hkz4akx-run-nixos-vm (2.94 KiB)
  203. 107.29 s [run-nixos-vm:post-build]
  204. 107.29 s [run-nixos-vm:post-build] All done.
  205. 107.31 s [run-nixos-vm:post-build] Uploading to the NixCI staging cache: /nix/store/hm0jrf3h3g89wzzhyv95z64y4hkz4akx-run-nixos-vm
  206. 107.35 s [run-nixos-vm:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  207. 107.52 s [run-nixos-vm:post-build] copying 1 paths...
  208. 107.53 s [run-nixos-vm:post-build] copying path '/nix/store/hm0jrf3h3g89wzzhyv95z64y4hkz4akx-run-nixos-vm' to 'https://cache.staging.nix-ci.com'...
  209. 107.73 s [run-nixos-vm:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  210. 107.98 s [run-nixos-vm:post-build] copying 1 paths...
  211. 107.99 s [run-nixos-vm:post-build] copying path '/nix/store/0ifg8fkfgd8w8mj74a4ipszqzh8w39ac-run-nixos-vm.drv' to 'https://cache.staging.nix-ci.com'...
  212. 108.18 s Uploaded run-nixos-vm in 3.0s
  213. 108.18 s Progress: 9 of 13 built
  214. 108.18 s Built run-nixos-vm in 3.0s
  215. 108.24 s Building /nix/store/9c6mc3gk5nm2fjzr6clvmyn037nsg8yl-nixos-vm.drv
  216. 108.30 s [nixos-vm:post-build] Uploading to cachix cache "centjes": /nix/store/9kzx216k2yx2k92fg96w4k0ii2v7msda-nixos-vm
  217. 109.13 s [nixos-vm:post-build] Pushing 1 paths (581 are already present) using zstd to cache centjes ⏳
  218. 109.13 s [nixos-vm:post-build]
  219. 109.57 s [nixos-vm:post-build] Pushing /nix/store/9kzx216k2yx2k92fg96w4k0ii2v7msda-nixos-vm (776.00 B)
  220. 110.49 s [nixos-vm:post-build]
  221. 110.49 s [nixos-vm:post-build] All done.
  222. 110.50 s [nixos-vm:post-build] Uploading to the NixCI staging cache: /nix/store/9kzx216k2yx2k92fg96w4k0ii2v7msda-nixos-vm
  223. 110.54 s [nixos-vm:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  224. 110.58 s [nixos-vm:post-build] copying 1 paths...
  225. 110.58 s [nixos-vm:post-build] copying path '/nix/store/9kzx216k2yx2k92fg96w4k0ii2v7msda-nixos-vm' to 'https://cache.staging.nix-ci.com'...
  226. 110.81 s [nixos-vm:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  227. 111.09 s [nixos-vm:post-build] copying 1 paths...
  228. 111.09 s [nixos-vm:post-build] copying path '/nix/store/9c6mc3gk5nm2fjzr6clvmyn037nsg8yl-nixos-vm.drv' to 'https://cache.staging.nix-ci.com'...
  229. 111.28 s Uploaded nixos-vm in 2.9s
  230. 111.28 s Progress: 10 of 13 built
  231. 111.28 s Built nixos-vm in 3.0s
  232. 111.34 s Building /nix/store/2nq014fj1ppaglffarcp1nspq67xb1qc-nixos-test-driver-centjes-e2e-test.drv
  233. 111.49 s [nixos-test-driver-centjes-e2e-test] Running type check (enable/disable: config.skipTypeCheck)
  234. 111.49 s [nixos-test-driver-centjes-e2e-test] See https://nixos.org/manual/nixos/stable/#test-opt-skipTypeCheck
  235. 117.46 s [nixos-test-driver-centjes-e2e-test] Success: no issues found in 1 source file
  236. 118.28 s [nixos-test-driver-centjes-e2e-test] additionally exposed symbols:
  237. 118.31 s [nixos-test-driver-centjes-e2e-test] ,
  238. 118.31 s [nixos-test-driver-centjes-e2e-test] ,
  239. 118.31 s [nixos-test-driver-centjes-e2e-test] start_all, test_script, machines, vlans, driver, log, os, create_machine, subtest, run_tests, join_all, retry, serial_stdout_off, serial_stdout_on, polling_condition, Machine, t, debug
  240. 118.33 s [nixos-test-driver-centjes-e2e-test] Linting test script (enable/disable: config.skipLint)
  241. 118.33 s [nixos-test-driver-centjes-e2e-test] See https://nixos.org/manual/nixos/stable/#test-opt-skipLint
  242. 118.46 s [nixos-test-driver-centjes-e2e-test:post-build] Uploading to cachix cache "centjes": /nix/store/kyip61120rsn9hriisbr4v2wjy9dknsq-nixos-test-driver-centjes-e2e-test
  243. 118.92 s [nixos-test-driver-centjes-e2e-test:post-build] Pushing 1 paths (633 are already present) using zstd to cache centjes ⏳
  244. 118.92 s [nixos-test-driver-centjes-e2e-test:post-build]
  245. 119.29 s [nixos-test-driver-centjes-e2e-test:post-build] Pushing /nix/store/kyip61120rsn9hriisbr4v2wjy9dknsq-nixos-test-driver-centjes-e2e-test (1.84 KiB)
  246. 120.48 s [nixos-test-driver-centjes-e2e-test:post-build]
  247. 120.48 s [nixos-test-driver-centjes-e2e-test:post-build] All done.
  248. 120.49 s [nixos-test-driver-centjes-e2e-test:post-build] Uploading to the NixCI staging cache: /nix/store/kyip61120rsn9hriisbr4v2wjy9dknsq-nixos-test-driver-centjes-e2e-test
  249. 120.54 s [nixos-test-driver-centjes-e2e-test:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  250. 120.58 s [nixos-test-driver-centjes-e2e-test:post-build] copying 1 paths...
  251. 120.58 s [nixos-test-driver-centjes-e2e-test:post-build] copying path '/nix/store/kyip61120rsn9hriisbr4v2wjy9dknsq-nixos-test-driver-centjes-e2e-test' to 'https://cache.staging.nix-ci.com'...
  252. 120.80 s [nixos-test-driver-centjes-e2e-test:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  253. 121.28 s [nixos-test-driver-centjes-e2e-test:post-build] copying 1 paths...
  254. 121.28 s [nixos-test-driver-centjes-e2e-test:post-build] copying path '/nix/store/2nq014fj1ppaglffarcp1nspq67xb1qc-nixos-test-driver-centjes-e2e-test.drv' to 'https://cache.staging.nix-ci.com'...
  255. 121.47 s Uploaded nixos-test-driver-centjes-e2e-test in 3.0s
  256. 121.47 s Progress: 11 of 13 built
  257. 121.47 s Built nixos-test-driver-centjes-e2e-test in 10.1s
  258. 121.54 s Building /nix/store/7i80czand4927npm2s8v8j9w554vlmcz-vm-test-run-centjes-e2e-test.drv
  259. 121.87 s [vm-test-run-centjes-e2e-test] Machine state will be reset. To keep it, pass --keep-vm-state
  260. 121.87 s [vm-test-run-centjes-e2e-test] start all VLans
  261. 121.87 s [vm-test-run-centjes-e2e-test] start vlan
  262. 121.87 s [vm-test-run-centjes-e2e-test] running vlan (pid 7; ctl /build/vde1.ctl)
  263. 121.87 s [vm-test-run-centjes-e2e-test] (finished: start all VLans, in 0.00 seconds)
  264. 121.87 s [vm-test-run-centjes-e2e-test] Test will time out and terminate in 3600 seconds
  265. 121.87 s [vm-test-run-centjes-e2e-test] run the VM test script
  266. 121.87 s [vm-test-run-centjes-e2e-test] additionally exposed symbols:
  267. 121.87 s [vm-test-run-centjes-e2e-test] client, docsserver,
  268. 121.87 s [vm-test-run-centjes-e2e-test] vlan1,
  269. 121.87 s [vm-test-run-centjes-e2e-test] start_all, test_script, machines, vlans, driver, log, os, create_machine, subtest, run_tests, join_all, retry, serial_stdout_off, serial_stdout_on, polling_condition, Machine, t, debug
  270. 121.87 s [vm-test-run-centjes-e2e-test] docsserver: starting vm
  271. 121.98 s [vm-test-run-centjes-e2e-test] mke2fs 1.47.3 (8-Jul-2025)
  272. 122.16 s [vm-test-run-centjes-e2e-test] docsserver # Disk image does not exist, creating the virtualisation disk image...
  273. 122.16 s [vm-test-run-centjes-e2e-test] docsserver: QEMU running (pid 9)
  274. 122.16 s [vm-test-run-centjes-e2e-test] docsserver # Formatting '/build/vm-state-docsserver/tmp.sGzkliwl0I', fmt=raw size=1073741824
  275. 122.16 s [vm-test-run-centjes-e2e-test] client: starting vm
  276. 122.16 s [vm-test-run-centjes-e2e-test] docsserver # Discarding device blocks: 0/262144 done
  277. 122.16 s [vm-test-run-centjes-e2e-test] docsserver # Creating filesystem with 262144 4k blocks and 65536 inodes
  278. 122.16 s [vm-test-run-centjes-e2e-test] docsserver # Filesystem UUID: 30ec696d-0ac4-40d1-ae34-d8585a77d8c1
  279. 122.16 s [vm-test-run-centjes-e2e-test] docsserver # Superblock backups stored on blocks:
  280. 122.16 s [vm-test-run-centjes-e2e-test] docsserver # 32768, 98304, 163840, 229376
  281. 122.18 s [vm-test-run-centjes-e2e-test] docsserver #
  282. 122.18 s [vm-test-run-centjes-e2e-test] docsserver # Allocating group tables: 0/8 done
  283. 122.18 s [vm-test-run-centjes-e2e-test] docsserver # Writing inode tables: 0/8 done
  284. 122.18 s [vm-test-run-centjes-e2e-test] docsserver # Creating journal (8192 blocks): done
  285. 122.18 s [vm-test-run-centjes-e2e-test] docsserver # Writing superblocks and filesystem accounting information: 0/8 done
  286. 122.18 s [vm-test-run-centjes-e2e-test] docsserver #
  287. 122.18 s [vm-test-run-centjes-e2e-test] docsserver # Virtualisation disk image created.
  288. 122.18 s [vm-test-run-centjes-e2e-test] mke2fs 1.47.3 (8-Jul-2025)
  289. 122.25 s [vm-test-run-centjes-e2e-test] docsserver # c[?7lSeaBIOS (version rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org)
  290. 122.29 s [vm-test-run-centjes-e2e-test] client # Disk image does not exist, creating the virtualisation disk image...
  291. 122.29 s [vm-test-run-centjes-e2e-test] client: QEMU running (pid 31)
  292. 122.29 s [vm-test-run-centjes-e2e-test] client # Formatting '/build/vm-state-client/tmp.qzWMICso0O', fmt=raw size=1073741824
  293. 122.29 s [vm-test-run-centjes-e2e-test] client # Discarding device blocks: 0/262144 done
  294. 122.29 s [vm-test-run-centjes-e2e-test] client # Creating filesystem with 262144 4k blocks and 65536 inodes
  295. 122.29 s [vm-test-run-centjes-e2e-test] client # Filesystem UUID: 4f1a6b4a-0db2-43fb-b27b-7012ebb0ac47
  296. 122.29 s [vm-test-run-centjes-e2e-test] client # Superblock backups stored on blocks:
  297. 122.29 s [vm-test-run-centjes-e2e-test] client # 32768, 98304, 163840, 229376
  298. 122.31 s [vm-test-run-centjes-e2e-test] docsserver: waiting for unit default.target
  299. 122.31 s [vm-test-run-centjes-e2e-test] client #
  300. 122.31 s [vm-test-run-centjes-e2e-test] docsserver: waiting for the VM to finish booting
  301. 122.31 s [vm-test-run-centjes-e2e-test] client # Allocating group tables: 0/8 done
  302. 122.31 s [vm-test-run-centjes-e2e-test] client # Writing inode tables: 0/8 done
  303. 122.31 s [vm-test-run-centjes-e2e-test] client # Creating journal (8192 blocks): done
  304. 122.31 s [vm-test-run-centjes-e2e-test] client # Writing superblocks and filesystem accounting information: 0/8 done
  305. 122.31 s [vm-test-run-centjes-e2e-test] client #
  306. 122.31 s [vm-test-run-centjes-e2e-test] client # Virtualisation disk image created.
  307. 122.35 s [vm-test-run-centjes-e2e-test] docsserver #
  308. 122.35 s [vm-test-run-centjes-e2e-test] docsserver #
  309. 122.36 s [vm-test-run-centjes-e2e-test] docsserver # iPXE (http://ipxe.org) 00:03.0 CA00 PCI2.10 PnP PMM+3EFD1920+3EF31920 CA00
  310. 122.37 s [vm-test-run-centjes-e2e-test] docsserver # Press Ctrl-B to configure iPXE (PCI 00:03.0)...
  311. 122.37 s [vm-test-run-centjes-e2e-test] docsserver #
  312. 122.37 s [vm-test-run-centjes-e2e-test] docsserver #
  313. 122.37 s [vm-test-run-centjes-e2e-test] docsserver #
  314. 122.37 s [vm-test-run-centjes-e2e-test] docsserver #
  315. 122.38 s [vm-test-run-centjes-e2e-test] docsserver # iPXE (http://ipxe.org) 00:09.0 CB00 PCI2.10 PnP PMM 3EFD1920 3EF31920 CB00
  316. 122.39 s [vm-test-run-centjes-e2e-test] client # c[?7lSeaBIOS (version rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org)
  317. 122.39 s [vm-test-run-centjes-e2e-test] docsserver # Press Ctrl-B to configure iPXE (PCI 00:09.0)...
  318. 122.39 s [vm-test-run-centjes-e2e-test] docsserver #
  319. 122.39 s [vm-test-run-centjes-e2e-test] docsserver #
  320. 122.41 s [vm-test-run-centjes-e2e-test] docsserver # Booting from ROM...
  321. 122.42 s [vm-test-run-centjes-e2e-test] docsserver # Probing EDD (edd=off to disable)... ok
  322. 122.49 s [vm-test-run-centjes-e2e-test] client #
  323. 122.49 s [vm-test-run-centjes-e2e-test] client #
  324. 122.49 s [vm-test-run-centjes-e2e-test] client # iPXE (http://ipxe.org) 00:03.0 CA00 PCI2.10 PnP PMM+3EFD1920+3EF31920 CA00
  325. 122.51 s [vm-test-run-centjes-e2e-test] client # Press Ctrl-B to configure iPXE (PCI 00:03.0)...
  326. 122.51 s [vm-test-run-centjes-e2e-test] client #
  327. 122.51 s [vm-test-run-centjes-e2e-test] client #
  328. 122.51 s [vm-test-run-centjes-e2e-test] client #
  329. 122.51 s [vm-test-run-centjes-e2e-test] client #
  330. 122.51 s [vm-test-run-centjes-e2e-test] client # iPXE (http://ipxe.org) 00:09.0 CB00 PCI2.10 PnP PMM 3EFD1920 3EF31920 CB00
  331. 122.53 s [vm-test-run-centjes-e2e-test] client # Press Ctrl-B to configure iPXE (PCI 00:09.0)...
  332. 122.53 s [vm-test-run-centjes-e2e-test] client #
  333. 122.53 s [vm-test-run-centjes-e2e-test] client #
  334. 122.57 s [vm-test-run-centjes-e2e-test] client # Booting from ROM...
  335. 122.72 s [vm-test-run-centjes-e2e-test] docsserver # c[?7l[ 0.000000] Linux version 6.12.62 (nixbld@localhost) (gcc (GCC) 14.3.0, GNU ld (GNU Binutils) 2.44) #1-NixOS SMP PREEMPT_DYNAMIC Fri Dec 12 17:37:22 UTC 2025
  336. 122.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] Command line: console=ttyS0 console=tty0 panic=1 boot.panic_on_fail clocksource=acpi_pm loglevel=7 net.ifnames=0 lsm=landlock,yama,bpf init=/nix/store/65s8l6c9brrb1g3yskvbz60cb4rmq4db-nixos-system-docsserver-test/init regInfo=/nix/store/ildfwjvkp1mgxjlcmj4jd3l802909i52-closure-info/registration console=ttyS0,115200n8 console=tty0
  337. 122.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-provided physical RAM map:
  338. 122.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
  339. 122.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
  340. 122.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
  341. 122.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000003ffdafff] usable
  342. 122.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x000000003ffdb000-0x000000003fffffff] reserved
  343. 122.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
  344. 122.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
  345. 122.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] BIOS-e820: [mem 0x000000fd00000000-0x000000ffffffffff] reserved
  346. 122.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] NX (Execute Disable) protection: active
  347. 122.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] APIC: Static calls initialized
  348. 122.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] SMBIOS 2.8 present.
  349. 122.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org 04/01/2014
  350. 122.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] DMI: Memory slots populated: 1/1
  351. 122.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] Hypervisor detected: KVM
  352. 122.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
  353. 122.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
  354. 122.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000000] kvm-clock: using sched offset of 420522404 cycles
  355. 122.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000002] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
  356. 122.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000005] tsc: Detected 3399.998 MHz processor
  357. 122.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000736] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
  358. 122.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000937] MTRR map: 4 entries (3 fixed + 1 variable; max 19), built from 8 variable MTRRs
  359. 122.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.000944] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT
  360. 122.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002765] found SMP MP-table at [mem 0x000f5470-0x000f547f]
  361. 122.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002776] Using GB pages for direct mapping
  362. 122.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002823] RAMDISK: [mem 0x3f3cd000-0x3ffcffff]
  363. 122.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002841] ACPI: Early table checksum verification disabled
  364. 122.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002844] ACPI: RSDP 0x00000000000F5290 000014 (v00 BOCHS )
  365. 122.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002847] ACPI: RSDT 0x000000003FFE23D9 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  366. 122.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002851] ACPI: FACP 0x000000003FFE228D 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  367. 122.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002854] ACPI: DSDT 0x000000003FFE0040 00224D (v01 BOCHS BXPC 00000001 BXPC 00000001)
  368. 122.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002856] ACPI: FACS 0x000000003FFE0000 000040
  369. 122.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002857] ACPI: APIC 0x000000003FFE2301 000078 (v03 BOCHS BXPC 00000001 BXPC 00000001)
  370. 122.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002859] ACPI: HPET 0x000000003FFE2379 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  371. 122.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002861] ACPI: WAET 0x000000003FFE23B1 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  372. 122.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002863] ACPI: Reserving FACP table memory at [mem 0x3ffe228d-0x3ffe2300]
  373. 122.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002865] ACPI: Reserving DSDT table memory at [mem 0x3ffe0040-0x3ffe228c]
  374. 122.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002865] ACPI: Reserving FACS table memory at [mem 0x3ffe0000-0x3ffe003f]
  375. 122.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002866] ACPI: Reserving APIC table memory at [mem 0x3ffe2301-0x3ffe2378]
  376. 122.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002866] ACPI: Reserving HPET table memory at [mem 0x3ffe2379-0x3ffe23b0]
  377. 122.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.002867] ACPI: Reserving WAET table memory at [mem 0x3ffe23b1-0x3ffe23d8]
  378. 122.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003594] No NUMA configuration found
  379. 122.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003595] Faking a node at [mem 0x0000000000000000-0x000000003ffdafff]
  380. 122.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003597] NODE_DATA(0) allocated [mem 0x3ffd58c0-0x3ffdadff]
  381. 122.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003612] Zone ranges:
  382. 122.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003612] DMA [mem 0x0000000000001000-0x0000000000ffffff]
  383. 122.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003613] DMA32 [mem 0x0000000001000000-0x000000003ffdafff]
  384. 122.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003614] Normal empty
  385. 122.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003615] Device empty
  386. 122.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003615] Movable zone start for each node
  387. 122.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003616] Early memory node ranges
  388. 122.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003616] node 0: [mem 0x0000000000001000-0x000000000009efff]
  389. 122.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003617] node 0: [mem 0x0000000000100000-0x000000003ffdafff]
  390. 122.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003618] Initmem setup node 0 [mem 0x0000000000001000-0x000000003ffdafff]
  391. 122.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003754] On node 0, zone DMA: 1 pages in unavailable ranges
  392. 122.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.003767] On node 0, zone DMA: 97 pages in unavailable ranges
  393. 122.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.005328] On node 0, zone DMA32: 37 pages in unavailable ranges
  394. 122.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.006873] ACPI: PM-Timer IO Port: 0x608
  395. 122.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.006902] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
  396. 122.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.006981] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
  397. 122.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.006983] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
  398. 122.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.006985] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
  399. 122.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.006985] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
  400. 122.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.006986] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
  401. 122.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.006987] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
  402. 122.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.006989] ACPI: Using ACPI (MADT) for SMP configuration information
  403. 122.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.006989] ACPI: HPET id: 0x8086a201 base: 0xfed00000
  404. 122.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.006992] TSC deadline timer available
  405. 122.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.006995] CPU topo: Max. logical packages: 1
  406. 122.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.006995] CPU topo: Max. logical dies: 1
  407. 122.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.006996] CPU topo: Max. dies per package: 1
  408. 122.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.006999] CPU topo: Max. threads per core: 1
  409. 122.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.006999] CPU topo: Num. cores per package: 1
  410. 122.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007000] CPU topo: Num. threads per package: 1
  411. 122.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007000] CPU topo: Allowing 1 present CPUs plus 0 hotplug CPUs
  412. 122.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007025] kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write()
  413. 122.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007075] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]
  414. 122.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007076] PM: hibernation: Registered nosave memory: [mem 0x0009f000-0x000fffff]
  415. 122.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007078] [mem 0x40000000-0xfeffbfff] available for PCI devices
  416. 122.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007078] Booting paravirtualized kernel on KVM
  417. 122.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.007080] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
  418. 122.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.010540] setup_percpu: NR_CPUS:384 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1
  419. 122.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.010770] percpu: Embedded 116 pages/cpu s294912 r65536 d114688 u2097152
  420. 122.91 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
  421. 122.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.010839] kvm-guest: PV spinlocks disabled, single CPU
  422. 122.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.010840] Kernel command line: console=ttyS0 console=tty0 panic=1 boot.panic_on_fail clocksource=acpi_pm loglevel=7 net.ifnames=0 lsm=landlock,yama,bpf init=/nix/store/65s8l6c9brrb1g3yskvbz60cb4rmq4db-nixos-system-docsserver-test/init regInfo=/nix/store/ildfwjvkp1mgxjlcmj4jd3l802909i52-closure-info/registration console=ttyS0,115200n8 console=tty0
  423. 122.91 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] Command line: console=ttyS0 console=tty0 panic=1 boot.panic_on_fail clocksource=acpi_pm loglevel=7 net.ifnames=0 lsm=landlock,yama,bpf init=/nix/store/001k9r4jinw78ih5x5hxggb82ynlbkqn-nixos-system-client-test/init regInfo=/nix/store/j7kn31fka8vp5bhm6sw8hv64iyzix7xw-closure-info/registration console=ttyS0,115200n8 console=tty0
  424. 122.91 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-provided physical RAM map:
  425. 122.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.010930] Unknown kernel command line parameters "regInfo=/nix/store/ildfwjvkp1mgxjlcmj4jd3l802909i52-closure-info/registration", will be passed to user space.
  426. 122.91 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
  427. 122.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.010943] random: crng init done
  428. 122.91 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
  429. 122.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.010997] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
  430. 122.91 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
  431. 122.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.011031] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)
  432. 122.91 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000003ffdafff] usable
  433. 122.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.011068] Fallback order for Node 0: 0
  434. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x000000003ffdb000-0x000000003fffffff] reserved
  435. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.011070] Built 1 zonelists, mobility grouping on. Total pages: 262009
  436. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.011071] Policy zone: DMA32
  437. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
  438. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.011275] mem auto-init: stack:all(zero), heap alloc:on, heap free:off
  439. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
  440. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.013079] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
  441. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] BIOS-e820: [mem 0x000000fd00000000-0x000000ffffffffff] reserved
  442. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.013291] allocated 2097152 bytes of page_ext
  443. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] NX (Execute Disable) protection: active
  444. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.013303] ftrace: allocating 46208 entries in 181 pages
  445. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] APIC: Static calls initialized
  446. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.021075] ftrace: allocated 181 pages with 5 groups
  447. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] SMBIOS 2.8 present.
  448. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.021848] Dynamic Preempt: voluntary
  449. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.022019] rcu: Preemptible hierarchical RCU implementation.
  450. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org 04/01/2014
  451. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.022019] rcu: RCU event tracing is enabled.
  452. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] DMI: Memory slots populated: 1/1
  453. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] Hypervisor detected: KVM
  454. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.022020] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1.
  455. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
  456. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.022021] Trampoline variant of Tasks RCU enabled.
  457. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
  458. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.022021] Rude variant of Tasks RCU enabled.
  459. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.022022] Tracing variant of Tasks RCU enabled.
  460. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.000000] kvm-clock: using sched offset of 451238282 cycles
  461. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.022022] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.
  462. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.000001] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
  463. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.022023] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
  464. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.000004] tsc: Detected 3399.998 MHz processor
  465. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.000727] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
  466. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.022030] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  467. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.000917] MTRR map: 4 entries (3 fixed + 1 variable; max 19), built from 8 variable MTRRs
  468. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.022031] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  469. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.000924] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT
  470. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.022032] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  471. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.002793] found SMP MP-table at [mem 0x000f5470-0x000f547f]
  472. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.002804] Using GB pages for direct mapping
  473. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.025473] NR_IRQS: 24832, nr_irqs: 256, preallocated irqs: 16
  474. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.002898] RAMDISK: [mem 0x3f3cd000-0x3ffcffff]
  475. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.025720] rcu: srcu_init: Setting srcu_struct sizes based on contention.
  476. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.002916] ACPI: Early table checksum verification disabled
  477. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.002919] ACPI: RSDP 0x00000000000F5290 000014 (v00 BOCHS )
  478. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.025789] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)
  479. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.038500] Console: colour VGA+ 80x25
  480. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.002922] ACPI: RSDT 0x000000003FFE23D9 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  481. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.038502] printk: legacy console [tty0] enabled
  482. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.002925] ACPI: FACP 0x000000003FFE228D 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  483. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.142490] printk: legacy console [ttyS0] enabled
  484. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.377445] ACPI: Core revision 20240827
  485. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.002928] ACPI: DSDT 0x000000003FFE0040 00224D (v01 BOCHS BXPC 00000001 BXPC 00000001)
  486. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.002930] ACPI: FACS 0x000000003FFE0000 000040
  487. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.379641] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
  488. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.002931] ACPI: APIC 0x000000003FFE2301 000078 (v03 BOCHS BXPC 00000001 BXPC 00000001)
  489. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.383813] APIC: Switch to symmetric I/O mode setup
  490. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.002933] ACPI: HPET 0x000000003FFE2379 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  491. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.386802] x2apic enabled
  492. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.002934] ACPI: WAET 0x000000003FFE23B1 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  493. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.002936] ACPI: Reserving FACP table memory at [mem 0x3ffe228d-0x3ffe2300]
  494. 122.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.388999] APIC: Switched APIC routing to: physical x2apic
  495. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.002937] ACPI: Reserving DSDT table memory at [mem 0x3ffe0040-0x3ffe228c]
  496. 122.97 s [vm-test-run-centjes-e2e-test] client # [ 0.002937] ACPI: Reserving FACS table memory at [mem 0x3ffe0000-0x3ffe003f]
  497. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.395008] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
  498. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.002938] ACPI: Reserving APIC table memory at [mem 0x3ffe2301-0x3ffe2378]
  499. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.002938] ACPI: Reserving HPET table memory at [mem 0x3ffe2379-0x3ffe23b0]
  500. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.397754] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x31024cfe468, max_idle_ns: 440795307017 ns
  501. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.002938] ACPI: Reserving WAET table memory at [mem 0x3ffe23b1-0x3ffe23d8]
  502. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.003716] No NUMA configuration found
  503. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.003717] Faking a node at [mem 0x0000000000000000-0x000000003ffdafff]
  504. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.402434] Calibrating delay loop (skipped) preset value.. 6799.99 BogoMIPS (lpj=3399998)
  505. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.003720] NODE_DATA(0) allocated [mem 0x3ffd58c0-0x3ffdadff]
  506. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.003734] Zone ranges:
  507. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.404975] x86/cpu: User Mode Instruction Prevention (UMIP) activated
  508. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.003734] DMA [mem 0x0000000000001000-0x0000000000ffffff]
  509. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.003736] DMA32 [mem 0x0000000001000000-0x000000003ffdafff]
  510. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.407595] Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127
  511. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.003737] Normal empty
  512. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.003738] Device empty
  513. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.003739] Movable zone start for each node
  514. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.408433] Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0
  515. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.003740] Early memory node ranges
  516. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.003740] node 0: [mem 0x0000000000001000-0x000000000009efff]
  517. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.410443] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
  518. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.003741] node 0: [mem 0x0000000000100000-0x000000003ffdafff]
  519. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.412434] Spectre V2 : Mitigation: Retpolines
  520. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.003743] Initmem setup node 0 [mem 0x0000000000001000-0x000000003ffdafff]
  521. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.003874] On node 0, zone DMA: 1 pages in unavailable ranges
  522. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.003889] On node 0, zone DMA: 97 pages in unavailable ranges
  523. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.414433] Spectre V2 : Spectre v2 / SpectreRSB: Filling RSB on context switch and VMEXIT
  524. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.005501] On node 0, zone DMA32: 37 pages in unavailable ranges
  525. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007130] ACPI: PM-Timer IO Port: 0x608
  526. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.416433] Spectre V2 : Enabling Restricted Speculation for firmware calls
  527. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007154] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
  528. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007235] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
  529. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.419435] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
  530. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007237] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
  531. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007239] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
  532. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.421434] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl
  533. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007240] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
  534. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.424433] active return thunk: srso_alias_return_thunk
  535. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007240] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
  536. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007241] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
  537. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.426433] Speculative Return Stack Overflow: Mitigation: Safe RET
  538. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007243] ACPI: Using ACPI (MADT) for SMP configuration information
  539. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.428433] Transient Scheduler Attacks: Forcing mitigation on in a VM
  540. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007244] ACPI: HPET id: 0x8086a201 base: 0xfed00000
  541. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007246] TSC deadline timer available
  542. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007250] CPU topo: Max. logical packages: 1
  543. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.429434] Transient Scheduler Attacks: Vulnerable: Clear CPU buffers attempted, no microcode
  544. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007251] CPU topo: Max. logical dies: 1
  545. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007251] CPU topo: Max. dies per package: 1
  546. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007254] CPU topo: Max. threads per core: 1
  547. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.432468] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
  548. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007255] CPU topo: Num. cores per package: 1
  549. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007255] CPU topo: Num. threads per package: 1
  550. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007255] CPU topo: Allowing 1 present CPUs plus 0 hotplug CPUs
  551. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007281] kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write()
  552. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007332] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]
  553. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007333] PM: hibernation: Registered nosave memory: [mem 0x0009f000-0x000fffff]
  554. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007334] [mem 0x40000000-0xfeffbfff] available for PCI devices
  555. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.434433] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
  556. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007335] Booting paravirtualized kernel on KVM
  557. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.007336] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
  558. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.436433] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
  559. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.010871] setup_percpu: NR_CPUS:384 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1
  560. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.438433] x86/fpu: Supporting XSAVE feature 0x200: 'Protection Keys User registers'
  561. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.011100] percpu: Embedded 116 pages/cpu s294912 r65536 d114688 u2097152
  562. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.011169] kvm-guest: PV spinlocks disabled, single CPU
  563. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.440433] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256
  564. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.442433] x86/fpu: xstate_offset[9]: 832, xstate_sizes[9]: 8
  565. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.444433] x86/fpu: Enabled xstate features 0x207, context size is 840 bytes, using 'compacted' format.
  566. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.011171] Kernel command line: console=ttyS0 console=tty0 panic=1 boot.panic_on_fail clocksource=acpi_pm loglevel=7 net.ifnames=0 lsm=landlock,yama,bpf init=/nix/store/001k9r4jinw78ih5x5hxggb82ynlbkqn-nixos-system-client-test/init regInfo=/nix/store/j7kn31fka8vp5bhm6sw8hv64iyzix7xw-closure-info/registration console=ttyS0,115200n8 console=tty0
  567. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.011244] Unknown kernel command line parameters "regInfo=/nix/store/j7kn31fka8vp5bhm6sw8hv64iyzix7xw-closure-info/registration", will be passed to user space.
  568. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.011259] random: crng init done
  569. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.011322] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
  570. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.011360] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)
  571. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.011409] Fallback order for Node 0: 0
  572. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.011412] Built 1 zonelists, mobility grouping on. Total pages: 262009
  573. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.011413] Policy zone: DMA32
  574. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.011609] mem auto-init: stack:all(zero), heap alloc:on, heap free:off
  575. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.013552] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
  576. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.013762] allocated 2097152 bytes of page_ext
  577. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.013774] ftrace: allocating 46208 entries in 181 pages
  578. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.021574] ftrace: allocated 181 pages with 5 groups
  579. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.022155] Dynamic Preempt: voluntary
  580. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.022335] rcu: Preemptible hierarchical RCU implementation.
  581. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.022336] rcu: RCU event tracing is enabled.
  582. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.472280] Freeing SMP alternatives memory: 40K
  583. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.022336] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1.
  584. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.473434] pid_max: default: 32768 minimum: 301
  585. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.022338] Trampoline variant of Tasks RCU enabled.
  586. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.022338] Rude variant of Tasks RCU enabled.
  587. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.022338] Tracing variant of Tasks RCU enabled.
  588. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.474497] LSM: initializing lsm=capability,landlock,yama,bpf
  589. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.476505] landlock: Up and running.
  590. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.022339] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.
  591. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.478434] Yama: becoming mindful.
  592. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.022339] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
  593. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.479623] LSM support for eBPF active
  594. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.022347] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  595. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.022349] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  596. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.480454] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
  597. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.022350] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  598. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.482435] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
  599. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.026090] NR_IRQS: 24832, nr_irqs: 256, preallocated irqs: 16
  600. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.026339] rcu: srcu_init: Setting srcu_struct sizes based on contention.
  601. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.484825] smpboot: CPU0: AMD Ryzen 9 5950X 16-Core Processor (family: 0x19, model: 0x21, stepping: 0x0)
  602. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.026409] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)
  603. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.039409] Console: colour VGA+ 80x25
  604. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.039412] printk: legacy console [tty0] enabled
  605. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.486652] Performance Events: Fam17h+ core perfctr, AMD PMU driver.
  606. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.142399] printk: legacy console [ttyS0] enabled
  607. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.488468] ... version: 0
  608. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.373084] ACPI: Core revision 20240827
  609. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.489439] ... bit width: 48
  610. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.490440] ... generic registers: 6
  611. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.375098] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
  612. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.491440] ... value mask: 0000ffffffffffff
  613. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.379135] APIC: Switch to symmetric I/O mode setup
  614. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.492440] ... max period: 00007fffffffffff
  615. 123.12 s [vm-test-run-centjes-e2e-test] client # [ 0.382464] x2apic enabled
  616. 123.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.493461] ... fixed-purpose events: 0
  617. 123.13 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.494441] ... event mask: 000000000000003f
  618. 123.13 s [vm-test-run-centjes-e2e-test] client # [ 0.384948] APIC: Switched APIC routing to: physical x2apic
  619. 123.13 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.495525] signal: max sigframe size: 3376
  620. 123.13 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.496486] rcu: Hierarchical SRCU implementation.
  621. 123.13 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.497442] rcu: Max phase no-delay instances is 400.
  622. 123.13 s [vm-test-run-centjes-e2e-test] client # [ 0.391950] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
  623. 123.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.501622] smp: Bringing up secondary CPUs ...
  624. 123.14 s [vm-test-run-centjes-e2e-test] client # [ 0.395008] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x31024cfe468, max_idle_ns: 440795307017 ns
  625. 123.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.502461] smp: Brought up 1 node, 1 CPU
  626. 123.14 s [vm-test-run-centjes-e2e-test] client # [ 0.399793] Calibrating delay loop (skipped) preset value.. 6799.99 BogoMIPS (lpj=3399998)
  627. 123.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.503443] smpboot: Total of 1 processors activated (6799.99 BogoMIPS)
  628. 123.15 s [vm-test-run-centjes-e2e-test] client # [ 0.403099] x86/cpu: User Mode Instruction Prevention (UMIP) activated
  629. 123.15 s [vm-test-run-centjes-e2e-test] client # [ 0.405197] Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127
  630. 123.15 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.504750] Memory: 962124K/1048036K available (16384K kernel code, 2645K rwdata, 12580K rodata, 3408K init, 3360K bss, 78836K reserved, 0K cma-reserved)
  631. 123.15 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.506543] devtmpfs: initialized
  632. 123.15 s [vm-test-run-centjes-e2e-test] client # [ 0.406791] Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0
  633. 123.15 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.507499] x86/mm: Memory block size: 128MB
  634. 123.16 s [vm-test-run-centjes-e2e-test] client # [ 0.408803] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
  635. 123.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.508903] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
  636. 123.16 s [vm-test-run-centjes-e2e-test] client # [ 0.410793] Spectre V2 : Mitigation: Retpolines
  637. 123.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.510445] futex hash table entries: 256 (order: 2, 16384 bytes, linear)
  638. 123.16 s [vm-test-run-centjes-e2e-test] client # [ 0.411792] Spectre V2 : Spectre v2 / SpectreRSB: Filling RSB on context switch and VMEXIT
  639. 123.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.511487] pinctrl core: initialized pinctrl subsystem
  640. 123.17 s [vm-test-run-centjes-e2e-test] client # [ 0.413792] Spectre V2 : Enabling Restricted Speculation for firmware calls
  641. 123.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.512738] PM: RTC time: 20:41:41, date: 2026-08-04
  642. 123.17 s [vm-test-run-centjes-e2e-test] client # [ 0.414794] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
  643. 123.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.514959] NET: Registered PF_NETLINK/PF_ROUTE protocol family
  644. 123.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.516617] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations
  645. 123.17 s [vm-test-run-centjes-e2e-test] client # [ 0.416792] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl
  646. 123.18 s [vm-test-run-centjes-e2e-test] client # [ 0.418792] active return thunk: srso_alias_return_thunk
  647. 123.18 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.518448] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
  648. 123.18 s [vm-test-run-centjes-e2e-test] client # [ 0.420792] Speculative Return Stack Overflow: Mitigation: Safe RET
  649. 123.18 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.520443] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
  650. 123.18 s [vm-test-run-centjes-e2e-test] client # [ 0.422792] Transient Scheduler Attacks: Forcing mitigation on in a VM
  651. 123.18 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.522446] audit: initializing netlink subsys (disabled)
  652. 123.19 s [vm-test-run-centjes-e2e-test] client # [ 0.423792] Transient Scheduler Attacks: Vulnerable: Clear CPU buffers attempted, no microcode
  653. 123.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.523468] audit: type=2000 audit(1785876100.954:1): state=initialized audit_enabled=0 res=1
  654. 123.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.525542] thermal_sys: Registered thermal governor 'bang_bang'
  655. 123.19 s [vm-test-run-centjes-e2e-test] client # [ 0.425871] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
  656. 123.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.525543] thermal_sys: Registered thermal governor 'step_wise'
  657. 123.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.526440] thermal_sys: Registered thermal governor 'user_space'
  658. 123.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.527458] cpuidle: using governor menu
  659. 123.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.531138] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
  660. 123.20 s [vm-test-run-centjes-e2e-test] client # [ 0.427791] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
  661. 123.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.532654] PCI: Using configuration type 1 for base access
  662. 123.20 s [vm-test-run-centjes-e2e-test] client # [ 0.429791] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
  663. 123.21 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.533439] PCI: Using configuration type 1 for extended access
  664. 123.21 s [vm-test-run-centjes-e2e-test] client # [ 0.431792] x86/fpu: Supporting XSAVE feature 0x200: 'Protection Keys User registers'
  665. 123.21 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.534587] kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible.
  666. 123.21 s [vm-test-run-centjes-e2e-test] client # [ 0.433792] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256
  667. 123.21 s [vm-test-run-centjes-e2e-test] client # [ 0.435793] x86/fpu: xstate_offset[9]: 832, xstate_sizes[9]: 8
  668. 123.22 s [vm-test-run-centjes-e2e-test] client # [ 0.437792] x86/fpu: Enabled xstate features 0x207, context size is 840 bytes, using 'compacted' format.
  669. 123.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.556457] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages
  670. 123.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.557457] HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page
  671. 123.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.558440] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
  672. 123.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.559439] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page
  673. 123.24 s [vm-test-run-centjes-e2e-test] client # [ 0.453790] Freeing SMP alternatives memory: 40K
  674. 123.25 s [vm-test-run-centjes-e2e-test] client # [ 0.453790] pid_max: default: 32768 minimum: 301
  675. 123.25 s [vm-test-run-centjes-e2e-test] client # [ 0.453790] LSM: initializing lsm=capability,landlock,yama,bpf
  676. 123.25 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.564065] ACPI: Added _OSI(Module Device)
  677. 123.25 s [vm-test-run-centjes-e2e-test] client # [ 0.453790] landlock: Up and running.
  678. 123.25 s [vm-test-run-centjes-e2e-test] client # [ 0.453790] Yama: becoming mindful.
  679. 123.25 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.566460] ACPI: Added _OSI(Processor Device)
  680. 123.25 s [vm-test-run-centjes-e2e-test] client # [ 0.453790] LSM support for eBPF active
  681. 123.25 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.567676] ACPI: Added _OSI(Processor Aggregator Device)
  682. 123.26 s [vm-test-run-centjes-e2e-test] client # [ 0.453790] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
  683. 123.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.571258] ACPI: 1 ACPI AML tables successfully acquired and loaded
  684. 123.26 s [vm-test-run-centjes-e2e-test] client # [ 0.453790] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
  685. 123.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.573682] ACPI: Interpreter enabled
  686. 123.26 s [vm-test-run-centjes-e2e-test] client # [ 0.453790] smpboot: CPU0: AMD Ryzen 9 5950X 16-Core Processor (family: 0x19, model: 0x21, stepping: 0x0)
  687. 123.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.574453] ACPI: PM: (supports S0 S3 S4 S5)
  688. 123.27 s [vm-test-run-centjes-e2e-test] client # [ 0.455021] Performance Events: Fam17h+ core perfctr, AMD PMU driver.
  689. 123.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.575444] ACPI: Using IOAPIC for interrupt routing
  690. 123.27 s [vm-test-run-centjes-e2e-test] client # [ 0.456806] ... version: 0
  691. 123.27 s [vm-test-run-centjes-e2e-test] client # [ 0.457798] ... bit width: 48
  692. 123.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.576464] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
  693. 123.27 s [vm-test-run-centjes-e2e-test] client # [ 0.458798] ... generic registers: 6
  694. 123.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.578439] PCI: Using E820 reservations for host bridge windows
  695. 123.28 s [vm-test-run-centjes-e2e-test] client # [ 0.459799] ... value mask: 0000ffffffffffff
  696. 123.28 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.579611] ACPI: Enabled 2 GPEs in block 00 to 0F
  697. 123.28 s [vm-test-run-centjes-e2e-test] client # [ 0.460798] ... max period: 00007fffffffffff
  698. 123.28 s [vm-test-run-centjes-e2e-test] client # [ 0.461798] ... fixed-purpose events: 0
  699. 123.28 s [vm-test-run-centjes-e2e-test] client # [ 0.462798] ... event mask: 000000000000003f
  700. 123.28 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.584363] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
  701. 123.36 s [vm-test-run-centjes-e2e-test] client # [ 0.463889] signal: max sigframe size: 3376
  702. 123.36 s [vm-test-run-centjes-e2e-test] client # [ 0.464840] rcu: Hierarchical SRCU implementation.
  703. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.585443] acpi PNP0A03:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3]
  704. 123.36 s [vm-test-run-centjes-e2e-test] client # [ 0.465799] rcu: Max phase no-delay instances is 400.
  705. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.587758] acpiphp: Slot [3] registered
  706. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.588504] acpiphp: Slot [4] registered
  707. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.589477] acpiphp: Slot [5] registered
  708. 123.36 s [vm-test-run-centjes-e2e-test] client # [ 0.469836] smp: Bringing up secondary CPUs ...
  709. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.590480] acpiphp: Slot [6] registered
  710. 123.36 s [vm-test-run-centjes-e2e-test] client # [ 0.470828] smp: Brought up 1 node, 1 CPU
  711. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.591478] acpiphp: Slot [7] registered
  712. 123.36 s [vm-test-run-centjes-e2e-test] client # [ 0.471801] smpboot: Total of 1 processors activated (6799.99 BogoMIPS)
  713. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.592477] acpiphp: Slot [8] registered
  714. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.593495] acpiphp: Slot [9] registered
  715. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.594483] acpiphp: Slot [10] registered
  716. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.595495] acpiphp: Slot [11] registered
  717. 123.36 s [vm-test-run-centjes-e2e-test] client # [ 0.473141] Memory: 962120K/1048036K available (16384K kernel code, 2645K rwdata, 12580K rodata, 3408K init, 3360K bss, 78840K reserved, 0K cma-reserved)
  718. 123.36 s [vm-test-run-centjes-e2e-test] client # [ 0.474895] devtmpfs: initialized
  719. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.596482] acpiphp: Slot [12] registered
  720. 123.36 s [vm-test-run-centjes-e2e-test] client # [ 0.475875] x86/mm: Memory block size: 128MB
  721. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.597483] acpiphp: Slot [13] registered
  722. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.598478] acpiphp: Slot [14] registered
  723. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.599506] acpiphp: Slot [15] registered
  724. 123.36 s [vm-test-run-centjes-e2e-test] client # [ 0.477289] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
  725. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.600479] acpiphp: Slot [16] registered
  726. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.601508] acpiphp: Slot [17] registered
  727. 123.36 s [vm-test-run-centjes-e2e-test] client # [ 0.478804] futex hash table entries: 256 (order: 2, 16384 bytes, linear)
  728. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.602479] acpiphp: Slot [18] registered
  729. 123.36 s [vm-test-run-centjes-e2e-test] client # [ 0.480852] pinctrl core: initialized pinctrl subsystem
  730. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.603481] acpiphp: Slot [19] registered
  731. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.604480] acpiphp: Slot [20] registered
  732. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.605477] acpiphp: Slot [21] registered
  733. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.606479] acpiphp: Slot [22] registered
  734. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.607480] acpiphp: Slot [23] registered
  735. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.608500] acpiphp: Slot [24] registered
  736. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.609502] acpiphp: Slot [25] registered
  737. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.610493] acpiphp: Slot [26] registered
  738. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.611477] acpiphp: Slot [27] registered
  739. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.612495] acpiphp: Slot [28] registered
  740. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.613476] acpiphp: Slot [29] registered
  741. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.614476] acpiphp: Slot [30] registered
  742. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.615509] acpiphp: Slot [31] registered
  743. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.616487] PCI host bridge to bus 0000:00
  744. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.617445] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]
  745. 123.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.618440] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]
  746. 123.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.619440] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
  747. 123.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.621440] pci_bus 0000:00: root bus resource [mem 0x40000000-0xfebfffff window]
  748. 123.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.623440] pci_bus 0000:00: root bus resource [mem 0x100000000-0x17fffffff window]
  749. 123.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.625440] pci_bus 0000:00: root bus resource [bus 00-ff]
  750. 123.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.626967] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 conventional PCI endpoint
  751. 123.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.629685] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 conventional PCI endpoint
  752. 123.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.633154] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 conventional PCI endpoint
  753. 123.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.639440] pci 0000:00:01.1: BAR 4 [io 0xc1e0-0xc1ef]
  754. 123.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.641921] pci 0000:00:01.1: BAR 0 [io 0x01f0-0x01f7]: legacy IDE quirk
  755. 123.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.643441] pci 0000:00:01.1: BAR 1 [io 0x03f6]: legacy IDE quirk
  756. 123.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.644439] pci 0000:00:01.1: BAR 2 [io 0x0170-0x0177]: legacy IDE quirk
  757. 123.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.645442] pci 0000:00:01.1: BAR 3 [io 0x0376]: legacy IDE quirk
  758. 123.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.646815] pci 0000:00:01.2: [8086:7020] type 00 class 0x0c0300 conventional PCI endpoint
  759. 123.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.651439] pci 0000:00:01.2: BAR 4 [io 0xc100-0xc11f]
  760. 123.42 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.654637] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 conventional PCI endpoint
  761. 123.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.657659] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI
  762. 123.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.659463] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB
  763. 123.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.661006] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000 conventional PCI endpoint
  764. 123.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.663979] pci 0000:00:02.0: BAR 0 [mem 0xfd000000-0xfdffffff pref]
  765. 123.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.668049] pci 0000:00:02.0: BAR 2 [mem 0xfebd0000-0xfebd0fff]
  766. 123.45 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.674302] pci 0000:00:02.0: ROM [mem 0xfebc0000-0xfebcffff pref]
  767. 123.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.675636] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
  768. 123.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.678198] pci 0000:00:03.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
  769. 123.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.680440] pci 0000:00:03.0: BAR 0 [io 0xc120-0xc13f]
  770. 123.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.682419] pci 0000:00:03.0: BAR 1 [mem 0xfebd1000-0xfebd1fff]
  771. 123.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.687439] pci 0000:00:03.0: BAR 4 [mem 0xfe000000-0xfe003fff 64bit pref]
  772. 123.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.690443] pci 0000:00:03.0: ROM [mem 0xfeb40000-0xfeb7ffff pref]
  773. 123.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.694189] pci 0000:00:04.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
  774. 123.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.696440] pci 0000:00:04.0: BAR 0 [io 0xc140-0xc15f]
  775. 123.50 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.698440] pci 0000:00:04.0: BAR 1 [mem 0xfebd2000-0xfebd2fff]
  776. 123.50 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.702322] pci 0000:00:04.0: BAR 4 [mem 0xfe004000-0xfe007fff 64bit pref]
  777. 123.51 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.707154] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  778. 123.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.709417] pci 0000:00:05.0: BAR 0 [io 0xc080-0xc0bf]
  779. 123.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.711439] pci 0000:00:05.0: BAR 1 [mem 0xfebd3000-0xfebd3fff]
  780. 123.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.716042] pci 0000:00:05.0: BAR 4 [mem 0xfe008000-0xfe00bfff 64bit pref]
  781. 123.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.721754] pci 0000:00:06.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  782. 123.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.724441] pci 0000:00:06.0: BAR 0 [io 0xc160-0xc17f]
  783. 123.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.726890] pci 0000:00:06.0: BAR 1 [mem 0xfebd4000-0xfebd4fff]
  784. 123.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.730964] pci 0000:00:06.0: BAR 4 [mem 0xfe00c000-0xfe00ffff 64bit pref]
  785. 123.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.736894] pci 0000:00:07.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  786. 123.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.739388] pci 0000:00:07.0: BAR 0 [io 0xc180-0xc19f]
  787. 123.57 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.741440] pci 0000:00:07.0: BAR 1 [mem 0xfebd5000-0xfebd5fff]
  788. 123.57 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.744884] pci 0000:00:07.0: BAR 4 [mem 0xfe010000-0xfe013fff 64bit pref]
  789. 123.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.750964] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint
  790. 123.58 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.753439] pci 0000:00:08.0: BAR 0 [io 0xc000-0xc07f]
  791. 123.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.755439] pci 0000:00:08.0: BAR 1 [mem 0xfebd6000-0xfebd6fff]
  792. 123.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.760161] pci 0000:00:08.0: BAR 4 [mem 0xfe014000-0xfe017fff 64bit pref]
  793. 123.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.764938] pci 0000:00:09.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
  794. 123.61 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.767439] pci 0000:00:09.0: BAR 0 [io 0xc1a0-0xc1bf]
  795. 123.61 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.770250] pci 0000:00:09.0: BAR 1 [mem 0xfebd7000-0xfebd7fff]
  796. 123.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.773841] pci 0000:00:09.0: BAR 4 [mem 0xfe018000-0xfe01bfff 64bit pref]
  797. 123.68 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.776280] pci 0000:00:09.0: ROM [mem 0xfeb80000-0xfebbffff pref]
  798. 123.69 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.780001] pci 0000:00:0a.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint
  799. 123.69 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.782766] pci 0000:00:0a.0: BAR 1 [mem 0xfebd8000-0xfebd8fff]
  800. 123.70 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.786412] pci 0000:00:0a.0: BAR 4 [mem 0xfe01c000-0xfe01ffff 64bit pref]
  801. 123.70 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.790990] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint
  802. 123.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.793439] pci 0000:00:0b.0: BAR 0 [io 0xc0c0-0xc0ff]
  803. 123.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.795439] pci 0000:00:0b.0: BAR 1 [mem 0xfebd9000-0xfebd9fff]
  804. 123.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.798851] pci 0000:00:0b.0: BAR 4 [mem 0xfe020000-0xfe023fff 64bit pref]
  805. 123.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.804797] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
  806. 123.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.807439] pci 0000:00:0c.0: BAR 0 [io 0xc1c0-0xc1df]
  807. 123.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.809403] pci 0000:00:0c.0: BAR 1 [mem 0xfebda000-0xfebdafff]
  808. 123.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.812853] pci 0000:00:0c.0: BAR 4 [mem 0xfe024000-0xfe027fff 64bit pref]
  809. 123.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.818984] ACPI: PCI: Interrupt link LNKA configured for IRQ 10
  810. 123.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.820645] ACPI: PCI: Interrupt link LNKB configured for IRQ 10
  811. 123.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.822615] ACPI: PCI: Interrupt link LNKC configured for IRQ 11
  812. 123.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.823622] ACPI: PCI: Interrupt link LNKD configured for IRQ 11
  813. 123.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.824536] ACPI: PCI: Interrupt link LNKS configured for IRQ 9
  814. 123.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.825827] iommu: Default domain type: Translated
  815. 123.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.827439] iommu: DMA domain TLB invalidation policy: lazy mode
  816. 123.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.828486] ACPI: bus type USB registered
  817. 123.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.829461] usbcore: registered new interface driver usbfs
  818. 123.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.830449] usbcore: registered new interface driver hub
  819. 123.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.831448] usbcore: registered new device driver usb
  820. 123.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.832752] NetLabel: Initializing
  821. 123.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.833439] NetLabel: domain hash size = 128
  822. 123.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.834443] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO
  823. 123.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.835458] NetLabel: unlabeled traffic allowed by default
  824. 123.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.836441] PCI: Using ACPI for IRQ routing
  825. 123.79 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.838227] pci 0000:00:02.0: vgaarb: setting as boot VGA device
  826. 123.79 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.838431] pci 0000:00:02.0: vgaarb: bridge control possible
  827. 123.79 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.838431] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
  828. 123.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.838441] vgaarb: loaded
  829. 123.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.839543] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
  830. 123.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.840439] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
  831. 123.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.843479] clocksource: Switched to clocksource kvm-clock
  832. 123.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.847170] VFS: Disk quotas dquot_6.6.0
  833. 123.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.849086] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
  834. 123.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.852210] pnp: PnP ACPI init
  835. 123.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.854445] pnp: PnP ACPI: found 6 devices
  836. 123.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.862667] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
  837. 123.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.866509] clocksource: Switched to clocksource acpi_pm
  838. 123.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.869136] NET: Registered PF_INET protocol family
  839. 123.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.871525] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
  840. 123.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.884039] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)
  841. 123.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.887792] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
  842. 123.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.891346] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)
  843. 123.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.894933] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)
  844. 123.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.898247] TCP: Hash tables configured (established 8192 bind 8192)
  845. 123.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.901238] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)
  846. 123.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.904561] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
  847. 123.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.907810] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
  848. 123.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.911311] NET: Registered PF_UNIX/PF_LOCAL protocol family
  849. 123.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.913910] NET: Registered PF_XDP protocol family
  850. 123.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.916176] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]
  851. 123.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.919140] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]
  852. 123.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.921988] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
  853. 123.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.925154] pci_bus 0000:00: resource 7 [mem 0x40000000-0xfebfffff window]
  854. 123.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.928373] pci_bus 0000:00: resource 8 [mem 0x100000000-0x17fffffff window]
  855. 123.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.931800] pci 0000:00:01.0: PIIX3: Enabling Passive Release
  856. 123.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.934521] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
  857. 123.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.938660] ACPI: \_SB_.LNKD: Enabled at IRQ 11
  858. 123.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.942889] PCI: CLS 0 bytes, default 64
  859. 123.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.944988] Trying to unpack rootfs image as initramfs...
  860. 123.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.949891] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x31024cfe468, max_idle_ns: 440795307017 ns
  861. 123.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.982002] Initialise system trusted keyrings
  862. 123.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 0.988922] workingset: timestamp_bits=40 max_order=18 bucket_order=0
  863. 123.96 s [vm-test-run-centjes-e2e-test] client # [ 1.108728] Reading current time from RTC took around 470 ms
  864. 123.97 s [vm-test-run-centjes-e2e-test] client # [ 1.109798] PM: RTC time: 20:41:41, date: 2026-08-04
  865. 123.97 s [vm-test-run-centjes-e2e-test] client # [ 1.111469] NET: Registered PF_NETLINK/PF_ROUTE protocol family
  866. 123.97 s [vm-test-run-centjes-e2e-test] client # [ 1.112957] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations
  867. 123.98 s [vm-test-run-centjes-e2e-test] client # [ 1.114807] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
  868. 123.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.014902] Key type asymmetric registered
  869. 123.98 s [vm-test-run-centjes-e2e-test] client # [ 1.116807] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
  870. 123.98 s [vm-test-run-centjes-e2e-test] client # [ 1.118811] audit: initializing netlink subsys (disabled)
  871. 123.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.019906] Asymmetric key parser 'x509' registered
  872. 123.98 s [vm-test-run-centjes-e2e-test] client # [ 1.119848] audit: type=2000 audit(1785876101.720:1): state=initialized audit_enabled=0 res=1
  873. 123.99 s [vm-test-run-centjes-e2e-test] client # [ 1.121929] thermal_sys: Registered thermal governor 'bang_bang'
  874. 123.99 s [vm-test-run-centjes-e2e-test] client # [ 1.121931] thermal_sys: Registered thermal governor 'step_wise'
  875. 123.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.026825] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
  876. 123.99 s [vm-test-run-centjes-e2e-test] client # [ 1.122799] thermal_sys: Registered thermal governor 'user_space'
  877. 123.99 s [vm-test-run-centjes-e2e-test] client # [ 1.123814] cpuidle: using governor menu
  878. 124.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.036223] Freeing initrd memory: 12300K
  879. 124.00 s [vm-test-run-centjes-e2e-test] client # [ 1.127470] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
  880. 124.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.038340] io scheduler mq-deadline registered
  881. 124.00 s [vm-test-run-centjes-e2e-test] client # [ 1.129061] PCI: Using configuration type 1 for base access
  882. 124.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.040566] io scheduler kyber registered
  883. 124.00 s [vm-test-run-centjes-e2e-test] client # [ 1.130797] PCI: Using configuration type 1 for extended access
  884. 124.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.043053] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
  885. 124.01 s [vm-test-run-centjes-e2e-test] client # [ 1.131948] kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible.
  886. 124.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.046423] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
  887. 124.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.051012] Linux agpgart interface v0.103
  888. 124.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.053104] ACPI: bus type drm_connector registered
  889. 124.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.055670] usbcore: registered new interface driver usbserial_generic
  890. 124.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.058627] usbserial: USB Serial support registered for generic
  891. 124.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.061664] amd_pstate: the _CPC object is not present in SBIOS or ACPI disabled
  892. 124.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.065285] drop_monitor: Initializing network drop monitor service
  893. 124.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.068315] NET: Registered PF_INET6 protocol family
  894. 124.03 s [vm-test-run-centjes-e2e-test] client # [ 1.153877] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages
  895. 124.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.071424] Segment Routing with IPv6
  896. 124.03 s [vm-test-run-centjes-e2e-test] client # [ 1.154798] HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page
  897. 124.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.073414] In-situ OAM (IOAM) with IPv6
  898. 124.04 s [vm-test-run-centjes-e2e-test] client # [ 1.155799] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
  899. 124.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.075823] IPI shorthand broadcast: enabled
  900. 124.04 s [vm-test-run-centjes-e2e-test] client # [ 1.156800] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page
  901. 124.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.080192] registered taskstats version 1
  902. 124.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.082916] Loading compiled-in X.509 certificates
  903. 124.05 s [vm-test-run-centjes-e2e-test] client # [ 1.162810] ACPI: Added _OSI(Module Device)
  904. 124.05 s [vm-test-run-centjes-e2e-test] client # [ 1.163813] ACPI: Added _OSI(Processor Device)
  905. 124.05 s [vm-test-run-centjes-e2e-test] client # [ 1.164802] ACPI: Added _OSI(Processor Aggregator Device)
  906. 124.05 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.090629] Demotion targets for Node 0: null
  907. 124.05 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.093088] Key type .fscrypt registered
  908. 124.06 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.095192] Key type fscrypt-provisioning registered
  909. 124.06 s [vm-test-run-centjes-e2e-test] client # [ 1.167804] ACPI: 1 ACPI AML tables successfully acquired and loaded
  910. 124.06 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.097787] PM: Magic number: 6:567:699
  911. 124.06 s [vm-test-run-centjes-e2e-test] client # [ 1.170066] ACPI: Interpreter enabled
  912. 124.06 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.100621] RAS: Correctable Errors collector initialized.
  913. 124.06 s [vm-test-run-centjes-e2e-test] client # [ 1.170816] ACPI: PM: (supports S0 S3 S4 S5)
  914. 124.07 s [vm-test-run-centjes-e2e-test] client # [ 1.171799] ACPI: Using IOAPIC for interrupt routing
  915. 124.07 s [vm-test-run-centjes-e2e-test] client # [ 1.172813] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
  916. 124.07 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.106963] Unstable clock detected, switching default tracing clock to "global"
  917. 124.07 s [vm-test-run-centjes-e2e-test] client # [ 1.174797] PCI: Using E820 reservations for host bridge windows
  918. 124.07 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.106963] If you want to keep using the local clock, then add:
  919. 124.07 s [vm-test-run-centjes-e2e-test] client # [ 1.175947] ACPI: Enabled 2 GPEs in block 00 to 0F
  920. 124.08 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.106963] "trace_clock=local"
  921. 124.08 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.106963] on the kernel command line
  922. 124.08 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.117001] clk: Disabling unused clocks
  923. 124.08 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.119127] PM: genpd: Disabling unused power domains
  924. 124.08 s [vm-test-run-centjes-e2e-test] client # [ 1.180506] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
  925. 124.08 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.122572] Freeing unused decrypted memory: 2028K
  926. 124.09 s [vm-test-run-centjes-e2e-test] client # [ 1.181802] acpi PNP0A03:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3]
  927. 124.09 s [vm-test-run-centjes-e2e-test] client # [ 1.184126] acpiphp: Slot [3] registered
  928. 124.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.125194] Freeing unused kernel image (initmem) memory: 3408K
  929. 124.09 s [vm-test-run-centjes-e2e-test] client # [ 1.184835] acpiphp: Slot [4] registered
  930. 124.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.127956] Write protecting the kernel read-only data: 30720k
  931. 124.09 s [vm-test-run-centjes-e2e-test] client # [ 1.185835] acpiphp: Slot [5] registered
  932. 124.09 s [vm-test-run-centjes-e2e-test] client # [ 1.186834] acpiphp: Slot [6] registered
  933. 124.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.131562] Freeing unused kernel image (rodata/data gap) memory: 1756K
  934. 124.09 s [vm-test-run-centjes-e2e-test] client # [ 1.187836] acpiphp: Slot [7] registered
  935. 124.10 s [vm-test-run-centjes-e2e-test] client # [ 1.188860] acpiphp: Slot [8] registered
  936. 124.10 s [vm-test-run-centjes-e2e-test] client # [ 1.189835] acpiphp: Slot [9] registered
  937. 124.10 s [vm-test-run-centjes-e2e-test] client # [ 1.190834] acpiphp: Slot [10] registered
  938. 124.10 s [vm-test-run-centjes-e2e-test] client # [ 1.191834] acpiphp: Slot [11] registered
  939. 124.10 s [vm-test-run-centjes-e2e-test] client # [ 1.192837] acpiphp: Slot [12] registered
  940. 124.11 s [vm-test-run-centjes-e2e-test] client # [ 1.193836] acpiphp: Slot [13] registered
  941. 124.11 s [vm-test-run-centjes-e2e-test] client # [ 1.194833] acpiphp: Slot [14] registered
  942. 124.11 s [vm-test-run-centjes-e2e-test] client # [ 1.195834] acpiphp: Slot [15] registered
  943. 124.11 s [vm-test-run-centjes-e2e-test] client # [ 1.196837] acpiphp: Slot [16] registered
  944. 124.11 s [vm-test-run-centjes-e2e-test] client # [ 1.197854] acpiphp: Slot [17] registered
  945. 124.12 s [vm-test-run-centjes-e2e-test] client # [ 1.198835] acpiphp: Slot [18] registered
  946. 124.12 s [vm-test-run-centjes-e2e-test] client # [ 1.199834] acpiphp: Slot [19] registered
  947. 124.12 s [vm-test-run-centjes-e2e-test] client # [ 1.200836] acpiphp: Slot [20] registered
  948. 124.12 s [vm-test-run-centjes-e2e-test] client # [ 1.201834] acpiphp: Slot [21] registered
  949. 124.12 s [vm-test-run-centjes-e2e-test] client # [ 1.202832] acpiphp: Slot [22] registered
  950. 124.13 s [vm-test-run-centjes-e2e-test] client # [ 1.203834] acpiphp: Slot [23] registered
  951. 124.13 s [vm-test-run-centjes-e2e-test] client # [ 1.204836] acpiphp: Slot [24] registered
  952. 124.13 s [vm-test-run-centjes-e2e-test] client # [ 1.205836] acpiphp: Slot [25] registered
  953. 124.13 s [vm-test-run-centjes-e2e-test] client # [ 1.206852] acpiphp: Slot [26] registered
  954. 124.13 s [vm-test-run-centjes-e2e-test] client # [ 1.207835] acpiphp: Slot [27] registered
  955. 124.13 s [vm-test-run-centjes-e2e-test] client # [ 1.208837] acpiphp: Slot [28] registered
  956. 124.14 s [vm-test-run-centjes-e2e-test] client # [ 1.209835] acpiphp: Slot [29] registered
  957. 124.14 s [vm-test-run-centjes-e2e-test] client # [ 1.210835] acpiphp: Slot [30] registered
  958. 124.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.176176] x86/mm: Checked W+X mappings: passed, no W+X pages found.
  959. 124.14 s [vm-test-run-centjes-e2e-test] client # [ 1.211837] acpiphp: Slot [31] registered
  960. 124.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.179117] Run /init as init process
  961. 124.14 s [vm-test-run-centjes-e2e-test] client # [ 1.212824] PCI host bridge to bus 0000:00
  962. 124.15 s [vm-test-run-centjes-e2e-test] client # [ 1.213805] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]
  963. 124.15 s [vm-test-run-centjes-e2e-test] client # [ 1.214801] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]
  964. 124.15 s [vm-test-run-centjes-e2e-test] client # [ 1.215804] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
  965. 124.15 s [vm-test-run-centjes-e2e-test] client # [ 1.216817] pci_bus 0000:00: root bus resource [mem 0x40000000-0xfebfffff window]
  966. 124.16 s [vm-test-run-centjes-e2e-test] client # [ 1.218800] pci_bus 0000:00: root bus resource [mem 0x100000000-0x17fffffff window]
  967. 124.16 s [vm-test-run-centjes-e2e-test] client # [ 1.220799] pci_bus 0000:00: root bus resource [bus 00-ff]
  968. 124.16 s [vm-test-run-centjes-e2e-test] client # [ 1.222240] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 conventional PCI endpoint
  969. 124.17 s [vm-test-run-centjes-e2e-test] client # [ 1.224921] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 conventional PCI endpoint
  970. 124.17 s [vm-test-run-centjes-e2e-test] client # [ 1.228442] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 conventional PCI endpoint
  971. 124.18 s [vm-test-run-centjes-e2e-test] client # [ 1.233209] pci 0000:00:01.1: BAR 4 [io 0xc1e0-0xc1ef]
  972. 124.19 s [vm-test-run-centjes-e2e-test] client # [ 1.236272] pci 0000:00:01.1: BAR 0 [io 0x01f0-0x01f7]: legacy IDE quirk
  973. 124.19 s [vm-test-run-centjes-e2e-test] client # [ 1.237798] pci 0000:00:01.1: BAR 1 [io 0x03f6]: legacy IDE quirk
  974. 124.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.226242] device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@lists.linux.dev
  975. 124.19 s [vm-test-run-centjes-e2e-test] client # [ 1.238799] pci 0000:00:01.1: BAR 2 [io 0x0170-0x0177]: legacy IDE quirk
  976. 124.19 s [vm-test-run-centjes-e2e-test] client # [ 1.239798] pci 0000:00:01.1: BAR 3 [io 0x0376]: legacy IDE quirk
  977. 124.20 s [vm-test-run-centjes-e2e-test] client # [ 1.241143] pci 0000:00:01.2: [8086:7020] type 00 class 0x0c0300 conventional PCI endpoint
  978. 124.20 s [vm-test-run-centjes-e2e-test] client # [ 1.245607] pci 0000:00:01.2: BAR 4 [io 0xc100-0xc11f]
  979. 124.21 s [vm-test-run-centjes-e2e-test] client # [ 1.249736] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 conventional PCI endpoint
  980. 124.21 s [vm-test-run-centjes-e2e-test] client # [ 1.251978] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI
  981. 124.22 s [vm-test-run-centjes-e2e-test] client # [ 1.253819] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB
  982. 124.22 s [vm-test-run-centjes-e2e-test] client # [ 1.255332] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000 conventional PCI endpoint
  983. 124.23 s [vm-test-run-centjes-e2e-test] client # [ 1.258375] pci 0000:00:02.0: BAR 0 [mem 0xfd000000-0xfdffffff pref]
  984. 124.23 s [vm-test-run-centjes-e2e-test] client # [ 1.262455] pci 0000:00:02.0: BAR 2 [mem 0xfebd0000-0xfebd0fff]
  985. 124.24 s [vm-test-run-centjes-e2e-test] client # [ 1.268773] pci 0000:00:02.0: ROM [mem 0xfebc0000-0xfebcffff pref]
  986. 124.25 s [vm-test-run-centjes-e2e-test] client # [ 1.269943] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
  987. 124.25 s [vm-test-run-centjes-e2e-test] client # [ 1.272554] pci 0000:00:03.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
  988. 124.25 s [vm-test-run-centjes-e2e-test] client # [ 1.274798] pci 0000:00:03.0: BAR 0 [io 0xc120-0xc13f]
  989. 124.26 s [vm-test-run-centjes-e2e-test] client # [ 1.276798] pci 0000:00:03.0: BAR 1 [mem 0xfebd1000-0xfebd1fff]
  990. 124.26 s [vm-test-run-centjes-e2e-test] client # [ 1.281271] pci 0000:00:03.0: BAR 4 [mem 0xfe000000-0xfe003fff 64bit pref]
  991. 124.27 s [vm-test-run-centjes-e2e-test] client # [ 1.283699] pci 0000:00:03.0: ROM [mem 0xfeb40000-0xfeb7ffff pref]
  992. 124.27 s [vm-test-run-centjes-e2e-test] client # [ 1.287624] pci 0000:00:04.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
  993. 124.28 s [vm-test-run-centjes-e2e-test] client # [ 1.289798] pci 0000:00:04.0: BAR 0 [io 0xc140-0xc15f]
  994. 124.28 s [vm-test-run-centjes-e2e-test] client # [ 1.291798] pci 0000:00:04.0: BAR 1 [mem 0xfebd2000-0xfebd2fff]
  995. 124.29 s [vm-test-run-centjes-e2e-test] client # [ 1.297739] pci 0000:00:04.0: BAR 4 [mem 0xfe004000-0xfe007fff 64bit pref]
  996. 124.30 s [vm-test-run-centjes-e2e-test] client # [ 1.302693] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  997. 124.30 s [vm-test-run-centjes-e2e-test] client # [ 1.304803] pci 0000:00:05.0: BAR 0 [io 0xc080-0xc0bf]
  998. 124.31 s [vm-test-run-centjes-e2e-test] client # [ 1.306631] pci 0000:00:05.0: BAR 1 [mem 0xfebd3000-0xfebd3fff]
  999. 124.31 s [vm-test-run-centjes-e2e-test] client # [ 1.310798] pci 0000:00:05.0: BAR 4 [mem 0xfe008000-0xfe00bfff 64bit pref]
  1000. 124.32 s [vm-test-run-centjes-e2e-test] client # [ 1.315102] pci 0000:00:06.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  1001. 124.32 s [vm-test-run-centjes-e2e-test] client # [ 1.317797] pci 0000:00:06.0: BAR 0 [io 0xc160-0xc17f]
  1002. 124.33 s [vm-test-run-centjes-e2e-test] client # [ 1.319631] pci 0000:00:06.0: BAR 1 [mem 0xfebd4000-0xfebd4fff]
  1003. 124.33 s [vm-test-run-centjes-e2e-test] client # [ 1.323547] pci 0000:00:06.0: BAR 4 [mem 0xfe00c000-0xfe00ffff 64bit pref]
  1004. 124.34 s [vm-test-run-centjes-e2e-test] client # [ 1.328128] pci 0000:00:07.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  1005. 124.34 s [vm-test-run-centjes-e2e-test] client # [ 1.330797] pci 0000:00:07.0: BAR 0 [io 0xc180-0xc19f]
  1006. 124.35 s [vm-test-run-centjes-e2e-test] client # [ 1.332654] pci 0000:00:07.0: BAR 1 [mem 0xfebd5000-0xfebd5fff]
  1007. 124.35 s [vm-test-run-centjes-e2e-test] client # [ 1.336304] pci 0000:00:07.0: BAR 4 [mem 0xfe010000-0xfe013fff 64bit pref]
  1008. 124.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.399082] ACPI: \_SB_.LNKC: Enabled at IRQ 10
  1009. 124.36 s [vm-test-run-centjes-e2e-test] client # [ 1.342315] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint
  1010. 124.37 s [vm-test-run-centjes-e2e-test] client # [ 1.344798] pci 0000:00:08.0: BAR 0 [io 0xc000-0xc07f]
  1011. 124.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.405677] uhci_hcd 0000:00:01.2: UHCI Host Controller
  1012. 124.37 s [vm-test-run-centjes-e2e-test] client # [ 1.347252] pci 0000:00:08.0: BAR 1 [mem 0xfebd6000-0xfebd6fff]
  1013. 124.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.408961] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
  1014. 124.38 s [vm-test-run-centjes-e2e-test] client # [ 1.351367] pci 0000:00:08.0: BAR 4 [mem 0xfe014000-0xfe017fff 64bit pref]
  1015. 124.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.417302] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
  1016. 124.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.423104] SCSI subsystem initialized
  1017. 124.39 s [vm-test-run-centjes-e2e-test] client # [ 1.356423] pci 0000:00:09.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
  1018. 124.39 s [vm-test-run-centjes-e2e-test] client # [ 1.358798] pci 0000:00:09.0: BAR 0 [io 0xc1a0-0xc1bf]
  1019. 124.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.429061] serio: i8042 KBD port at 0x60,0x64 irq 1
  1020. 124.39 s [vm-test-run-centjes-e2e-test] client # [ 1.361676] pci 0000:00:09.0: BAR 1 [mem 0xfebd7000-0xfebd7fff]
  1021. 124.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.434918] uhci_hcd 0000:00:01.2: detected 2 ports
  1022. 124.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.441148] ACPI: \_SB_.LNKA: Enabled at IRQ 10
  1023. 124.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.443430] serio: i8042 AUX port at 0x60,0x64 irq 12
  1024. 124.41 s [vm-test-run-centjes-e2e-test] client # [ 1.365347] pci 0000:00:09.0: BAR 4 [mem 0xfe018000-0xfe01bfff 64bit pref]
  1025. 124.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.448028] uhci_hcd 0000:00:01.2: irq 11, io port 0x0000c100
  1026. 124.41 s [vm-test-run-centjes-e2e-test] client # [ 1.367801] pci 0000:00:09.0: ROM [mem 0xfeb80000-0xfebbffff pref]
  1027. 124.42 s [vm-test-run-centjes-e2e-test] client # [ 1.371298] pci 0000:00:0a.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint
  1028. 124.42 s [vm-test-run-centjes-e2e-test] client # [ 1.374135] pci 0000:00:0a.0: BAR 1 [mem 0xfebd8000-0xfebd8fff]
  1029. 124.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.463286] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 6.12
  1030. 124.43 s [vm-test-run-centjes-e2e-test] client # [ 1.377798] pci 0000:00:0a.0: BAR 4 [mem 0xfe01c000-0xfe01ffff 64bit pref]
  1031. 124.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.467070] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
  1032. 124.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.470403] usb usb1: Product: UHCI Host Controller
  1033. 124.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.472910] usb usb1: Manufacturer: Linux 6.12.62 uhci_hcd
  1034. 124.44 s [vm-test-run-centjes-e2e-test] client # [ 1.382279] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint
  1035. 124.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.475463] usb usb1: SerialNumber: 0000:00:01.2
  1036. 124.44 s [vm-test-run-centjes-e2e-test] client # [ 1.384797] pci 0000:00:0b.0: BAR 0 [io 0xc0c0-0xc0ff]
  1037. 124.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.480810] ACPI: \_SB_.LNKB: Enabled at IRQ 11
  1038. 124.44 s [vm-test-run-centjes-e2e-test] client # [ 1.386643] pci 0000:00:0b.0: BAR 1 [mem 0xfebd9000-0xfebd9fff]
  1039. 124.45 s [vm-test-run-centjes-e2e-test] client # [ 1.390283] pci 0000:00:0b.0: BAR 4 [mem 0xfe020000-0xfe023fff 64bit pref]
  1040. 124.45 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.492619] scsi host0: ata_piix
  1041. 124.46 s [vm-test-run-centjes-e2e-test] client # [ 1.396142] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
  1042. 124.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.498899] scsi host1: ata_piix
  1043. 124.46 s [vm-test-run-centjes-e2e-test] client # [ 1.398797] pci 0000:00:0c.0: BAR 0 [io 0xc1c0-0xc1df]
  1044. 124.47 s [vm-test-run-centjes-e2e-test] client # [ 1.400626] pci 0000:00:0c.0: BAR 1 [mem 0xfebda000-0xfebdafff]
  1045. 124.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.507413] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc1e0 irq 14 lpm-pol 0
  1046. 124.47 s [vm-test-run-centjes-e2e-test] client # [ 1.404232] pci 0000:00:0c.0: BAR 4 [mem 0xfe024000-0xfe027fff 64bit pref]
  1047. 124.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.511197] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc1e8 irq 15 lpm-pol 0
  1048. 124.48 s [vm-test-run-centjes-e2e-test] client # [ 1.410218] ACPI: PCI: Interrupt link LNKA configured for IRQ 10
  1049. 124.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.520226] hub 1-0:1.0: USB hub found
  1050. 124.48 s [vm-test-run-centjes-e2e-test] client # [ 1.412004] ACPI: PCI: Interrupt link LNKB configured for IRQ 10
  1051. 124.49 s [vm-test-run-centjes-e2e-test] client # [ 1.413998] ACPI: PCI: Interrupt link LNKC configured for IRQ 11
  1052. 124.49 s [vm-test-run-centjes-e2e-test] client # [ 1.415998] ACPI: PCI: Interrupt link LNKD configured for IRQ 11
  1053. 124.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.528450] hub 1-0:1.0: 2 ports detected
  1054. 124.49 s [vm-test-run-centjes-e2e-test] client # [ 1.417903] ACPI: PCI: Interrupt link LNKS configured for IRQ 9
  1055. 124.49 s [vm-test-run-centjes-e2e-test] client # [ 1.420200] iommu: Default domain type: Translated
  1056. 124.50 s [vm-test-run-centjes-e2e-test] client # [ 1.421799] iommu: DMA domain TLB invalidation policy: lazy mode
  1057. 124.50 s [vm-test-run-centjes-e2e-test] client # [ 1.422826] ACPI: bus type USB registered
  1058. 124.50 s [vm-test-run-centjes-e2e-test] client # [ 1.423820] usbcore: registered new interface driver usbfs
  1059. 124.50 s [vm-test-run-centjes-e2e-test] client # [ 1.424814] usbcore: registered new interface driver hub
  1060. 124.51 s [vm-test-run-centjes-e2e-test] client # [ 1.425810] usbcore: registered new device driver usb
  1061. 124.51 s [vm-test-run-centjes-e2e-test] client # [ 1.427121] NetLabel: Initializing
  1062. 124.51 s [vm-test-run-centjes-e2e-test] client # [ 1.427798] NetLabel: domain hash size = 128
  1063. 124.51 s [vm-test-run-centjes-e2e-test] client # [ 1.428798] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO
  1064. 124.52 s [vm-test-run-centjes-e2e-test] client # [ 1.429821] NetLabel: unlabeled traffic allowed by default
  1065. 124.52 s [vm-test-run-centjes-e2e-test] client # [ 1.430799] PCI: Using ACPI for IRQ routing
  1066. 124.52 s [vm-test-run-centjes-e2e-test] client # [ 1.432613] pci 0000:00:02.0: vgaarb: setting as boot VGA device
  1067. 124.52 s [vm-test-run-centjes-e2e-test] client # [ 1.432790] pci 0000:00:02.0: vgaarb: bridge control possible
  1068. 124.53 s [vm-test-run-centjes-e2e-test] client # [ 1.432790] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
  1069. 124.53 s [vm-test-run-centjes-e2e-test] client # [ 1.432801] vgaarb: loaded
  1070. 124.53 s [vm-test-run-centjes-e2e-test] client # [ 1.433879] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
  1071. 124.54 s [vm-test-run-centjes-e2e-test] client # [ 1.434799] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
  1072. 124.54 s [vm-test-run-centjes-e2e-test] client # [ 1.438826] clocksource: Switched to clocksource kvm-clock
  1073. 124.54 s [vm-test-run-centjes-e2e-test] client # [ 1.442129] VFS: Disk quotas dquot_6.6.0
  1074. 124.55 s [vm-test-run-centjes-e2e-test] client # [ 1.444072] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
  1075. 124.55 s [vm-test-run-centjes-e2e-test] client # [ 1.447689] pnp: PnP ACPI init
  1076. 124.55 s [vm-test-run-centjes-e2e-test] client # [ 1.449925] pnp: PnP ACPI: found 6 devices
  1077. 124.56 s [vm-test-run-centjes-e2e-test] client # [ 1.458220] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
  1078. 124.56 s [vm-test-run-centjes-e2e-test] client # [ 1.461982] clocksource: Switched to clocksource acpi_pm
  1079. 124.57 s [vm-test-run-centjes-e2e-test] client # [ 1.464587] NET: Registered PF_INET protocol family
  1080. 124.57 s [vm-test-run-centjes-e2e-test] client # [ 1.466851] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
  1081. 124.58 s [vm-test-run-centjes-e2e-test] client # [ 1.479430] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)
  1082. 124.59 s [vm-test-run-centjes-e2e-test] client # [ 1.483050] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
  1083. 124.59 s [vm-test-run-centjes-e2e-test] client # [ 1.486487] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)
  1084. 124.59 s [vm-test-run-centjes-e2e-test] client # [ 1.489999] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)
  1085. 124.60 s [vm-test-run-centjes-e2e-test] client # [ 1.493287] TCP: Hash tables configured (established 8192 bind 8192)
  1086. 124.60 s [vm-test-run-centjes-e2e-test] client # [ 1.496145] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)
  1087. 124.60 s [vm-test-run-centjes-e2e-test] client # [ 1.499555] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
  1088. 124.61 s [vm-test-run-centjes-e2e-test] client # [ 1.502382] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
  1089. 124.61 s [vm-test-run-centjes-e2e-test] client # [ 1.505555] NET: Registered PF_UNIX/PF_LOCAL protocol family
  1090. 124.61 s [vm-test-run-centjes-e2e-test] client # [ 1.508108] NET: Registered PF_XDP protocol family
  1091. 124.61 s [vm-test-run-centjes-e2e-test] client # [ 1.510536] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]
  1092. 124.62 s [vm-test-run-centjes-e2e-test] client # [ 1.513565] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]
  1093. 124.62 s [vm-test-run-centjes-e2e-test] client # [ 1.516301] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
  1094. 124.62 s [vm-test-run-centjes-e2e-test] client # [ 1.519328] pci_bus 0000:00: resource 7 [mem 0x40000000-0xfebfffff window]
  1095. 124.63 s [vm-test-run-centjes-e2e-test] client # [ 1.522397] pci_bus 0000:00: resource 8 [mem 0x100000000-0x17fffffff window]
  1096. 124.63 s [vm-test-run-centjes-e2e-test] client # [ 1.525589] pci 0000:00:01.0: PIIX3: Enabling Passive Release
  1097. 124.63 s [vm-test-run-centjes-e2e-test] client # [ 1.528204] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
  1098. 124.63 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.669619] ata2: found unknown device (class 0)
  1099. 124.63 s [vm-test-run-centjes-e2e-test] client # [ 1.532324] ACPI: \_SB_.LNKD: Enabled at IRQ 11
  1100. 124.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.673033] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100
  1101. 124.64 s [vm-test-run-centjes-e2e-test] client # [ 1.536566] PCI: CLS 0 bytes, default 64
  1102. 124.64 s [vm-test-run-centjes-e2e-test] client # [ 1.538850] Trying to unpack rootfs image as initramfs...
  1103. 124.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.678347] scsi 1:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5
  1104. 124.65 s [vm-test-run-centjes-e2e-test] client # [ 1.544611] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x31024cfe468, max_idle_ns: 440795307017 ns
  1105. 124.68 s [vm-test-run-centjes-e2e-test] client # [ 1.573945] Initialise system trusted keyrings
  1106. 124.68 s [vm-test-run-centjes-e2e-test] client # [ 1.579706] workingset: timestamp_bits=40 max_order=18 bucket_order=0
  1107. 124.71 s [vm-test-run-centjes-e2e-test] client # [ 1.604591] Key type asymmetric registered
  1108. 124.71 s [vm-test-run-centjes-e2e-test] client # [ 1.609682] Asymmetric key parser 'x509' registered
  1109. 124.72 s [vm-test-run-centjes-e2e-test] client # [ 1.615584] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
  1110. 124.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.756812] usb 1-1: new full-speed USB device number 2 using uhci_hcd
  1111. 124.73 s [vm-test-run-centjes-e2e-test] client # [ 1.623600] io scheduler mq-deadline registered
  1112. 124.73 s [vm-test-run-centjes-e2e-test] client # [ 1.625664] io scheduler kyber registered
  1113. 124.73 s [vm-test-run-centjes-e2e-test] client # [ 1.631297] Freeing initrd memory: 12300K
  1114. 124.74 s [vm-test-run-centjes-e2e-test] client # [ 1.633691] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
  1115. 124.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.775959] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
  1116. 124.74 s [vm-test-run-centjes-e2e-test] client # [ 1.636941] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
  1117. 124.74 s [vm-test-run-centjes-e2e-test] client # [ 1.641393] Linux agpgart interface v0.103
  1118. 124.75 s [vm-test-run-centjes-e2e-test] client # [ 1.643379] ACPI: bus type drm_connector registered
  1119. 124.75 s [vm-test-run-centjes-e2e-test] client # [ 1.645958] usbcore: registered new interface driver usbserial_generic
  1120. 124.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.788516] virtio_blk virtio5: 1/0/0 default/read/poll queues
  1121. 124.75 s [vm-test-run-centjes-e2e-test] client # [ 1.649107] usbserial: USB Serial support registered for generic
  1122. 124.76 s [vm-test-run-centjes-e2e-test] client # [ 1.651820] amd_pstate: the _CPC object is not present in SBIOS or ACPI disabled
  1123. 124.76 s [vm-test-run-centjes-e2e-test] client # [ 1.655279] drop_monitor: Initializing network drop monitor service
  1124. 124.76 s [vm-test-run-centjes-e2e-test] client # [ 1.658201] NET: Registered PF_INET6 protocol family
  1125. 124.76 s [vm-test-run-centjes-e2e-test] client # [ 1.661109] Segment Routing with IPv6
  1126. 124.76 s [vm-test-run-centjes-e2e-test] client # [ 1.662955] In-situ OAM (IOAM) with IPv6
  1127. 124.77 s [vm-test-run-centjes-e2e-test] client # [ 1.665273] IPI shorthand broadcast: enabled
  1128. 124.77 s [vm-test-run-centjes-e2e-test] client # [ 1.669690] registered taskstats version 1
  1129. 124.77 s [vm-test-run-centjes-e2e-test] client # [ 1.671887] Loading compiled-in X.509 certificates
  1130. 124.78 s [vm-test-run-centjes-e2e-test] client # [ 1.679003] Demotion targets for Node 0: null
  1131. 124.78 s [vm-test-run-centjes-e2e-test] client # [ 1.681184] Key type .fscrypt registered
  1132. 124.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.820791] virtio_blk virtio5: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)
  1133. 124.79 s [vm-test-run-centjes-e2e-test] client # [ 1.683189] Key type fscrypt-provisioning registered
  1134. 124.79 s [vm-test-run-centjes-e2e-test] client # [ 1.685765] PM: Magic number: 6:567:699
  1135. 124.79 s [vm-test-run-centjes-e2e-test] client # [ 1.688333] RAS: Correctable Errors collector initialized.
  1136. 124.80 s [vm-test-run-centjes-e2e-test] client # [ 1.694089] Unstable clock detected, switching default tracing clock to "global"
  1137. 124.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.838358] netfs: FS-Cache loaded
  1138. 124.80 s [vm-test-run-centjes-e2e-test] client # [ 1.694089] If you want to keep using the local clock, then add:
  1139. 124.80 s [vm-test-run-centjes-e2e-test] client # [ 1.694089] "trace_clock=local"
  1140. 124.80 s [vm-test-run-centjes-e2e-test] client # [ 1.694089] on the kernel command line
  1141. 124.81 s [vm-test-run-centjes-e2e-test] client # [ 1.703104] clk: Disabling unused clocks
  1142. 124.81 s [vm-test-run-centjes-e2e-test] client # [ 1.705319] PM: genpd: Disabling unused power domains
  1143. 124.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.844441] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray
  1144. 124.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.848203] cdrom: Uniform CD-ROM driver Revision: 3.20
  1145. 124.81 s [vm-test-run-centjes-e2e-test] client # [ 1.708764] Freeing unused decrypted memory: 2028K
  1146. 124.81 s [vm-test-run-centjes-e2e-test] client # [ 1.711549] Freeing unused kernel image (initmem) memory: 3408K
  1147. 124.82 s [vm-test-run-centjes-e2e-test] client # [ 1.714280] Write protecting the kernel read-only data: 30720k
  1148. 124.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.858145] 9pnet: Installing 9P2000 support
  1149. 124.82 s [vm-test-run-centjes-e2e-test] client # [ 1.717361] Freeing unused kernel image (rodata/data gap) memory: 1756K
  1150. 124.86 s [vm-test-run-centjes-e2e-test] client # [ 1.761246] x86/mm: Checked W+X mappings: passed, no W+X pages found.
  1151. 124.87 s [vm-test-run-centjes-e2e-test] client # [ 1.764267] Run /init as init process
  1152. 124.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.932595] usb 1-1: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00
  1153. 124.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.936342] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=10
  1154. 124.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.939577] usb 1-1: Product: QEMU USB Tablet
  1155. 124.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.941658] usb 1-1: Manufacturer: QEMU
  1156. 124.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.943539] usb 1-1: SerialNumber: 28754-0000:00:01.2-1
  1157. 124.91 s [vm-test-run-centjes-e2e-test] client # [ 1.808183] device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@lists.linux.dev
  1158. 124.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.962220] hid: raw HID events driver (C) Jiri Kosina
  1159. 124.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.981173] usbcore: registered new interface driver usbhid
  1160. 124.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.983994] usbhid: USB HID core driver
  1161. 124.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.988531] input: QEMU QEMU USB Tablet as /devices/pci0000:00/0000:00:01.2/usb1/1-1/1-1:1.0/0003:0627:0001.0001/input/input2
  1162. 124.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 1.995023] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:01.2-1/input0
  1163. 125.09 s [vm-test-run-centjes-e2e-test] client # [ 1.985150] ACPI: \_SB_.LNKC: Enabled at IRQ 10
  1164. 125.09 s [vm-test-run-centjes-e2e-test] client # [ 1.988214] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
  1165. 125.09 s [vm-test-run-centjes-e2e-test] client # [ 1.992588] uhci_hcd 0000:00:01.2: UHCI Host Controller
  1166. 125.10 s [vm-test-run-centjes-e2e-test] client # [ 1.999655] SCSI subsystem initialized
  1167. 125.11 s [vm-test-run-centjes-e2e-test] client # [ 2.004541] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
  1168. 125.11 s [vm-test-run-centjes-e2e-test] client # [ 2.009856] serio: i8042 KBD port at 0x60,0x64 irq 1
  1169. 125.12 s [vm-test-run-centjes-e2e-test] client # [ 2.017535] serio: i8042 AUX port at 0x60,0x64 irq 12
  1170. 125.13 s [vm-test-run-centjes-e2e-test] client # [ 2.023557] uhci_hcd 0000:00:01.2: detected 2 ports
  1171. 125.13 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.163014] EXT4-fs (vda): mounted filesystem 30ec696d-0ac4-40d1-ae34-d8585a77d8c1 r/w with ordered data mode. Quota mode: none.
  1172. 125.13 s [vm-test-run-centjes-e2e-test] client # [ 2.031133] ACPI: \_SB_.LNKA: Enabled at IRQ 10
  1173. 125.14 s [vm-test-run-centjes-e2e-test] client # [ 2.038132] uhci_hcd 0000:00:01.2: irq 11, io port 0x0000c100
  1174. 125.15 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.190887] 9p: Installing v9fs 9p2000 file system support
  1175. 125.16 s [vm-test-run-centjes-e2e-test] client # [ 2.052716] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 6.12
  1176. 125.16 s [vm-test-run-centjes-e2e-test] client # [ 2.056499] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
  1177. 125.16 s [vm-test-run-centjes-e2e-test] client # [ 2.060063] usb usb1: Product: UHCI Host Controller
  1178. 125.17 s [vm-test-run-centjes-e2e-test] client # [ 2.062654] usb usb1: Manufacturer: Linux 6.12.62 uhci_hcd
  1179. 125.17 s [vm-test-run-centjes-e2e-test] client # [ 2.065293] usb usb1: SerialNumber: 0000:00:01.2
  1180. 125.17 s [vm-test-run-centjes-e2e-test] client # [ 2.071709] ACPI: \_SB_.LNKB: Enabled at IRQ 11
  1181. 125.18 s [vm-test-run-centjes-e2e-test] client # [ 2.083003] scsi host0: ata_piix
  1182. 125.19 s [vm-test-run-centjes-e2e-test] client # [ 2.090302] scsi host1: ata_piix
  1183. 125.20 s [vm-test-run-centjes-e2e-test] client # [ 2.096870] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc1e0 irq 14 lpm-pol 0
  1184. 125.21 s [vm-test-run-centjes-e2e-test] client # [ 2.100430] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc1e8 irq 15 lpm-pol 0
  1185. 125.21 s [vm-test-run-centjes-e2e-test] client # [ 2.111940] hub 1-0:1.0: USB hub found
  1186. 125.22 s [vm-test-run-centjes-e2e-test] client # [ 2.117540] hub 1-0:1.0: 2 ports detected
  1187. 125.37 s [vm-test-run-centjes-e2e-test] client # [ 2.265613] ata2: found unknown device (class 0)
  1188. 125.37 s [vm-test-run-centjes-e2e-test] client # [ 2.268873] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100
  1189. 125.38 s [vm-test-run-centjes-e2e-test] client # [ 2.273893] scsi 1:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5
  1190. 125.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.442855] EXT4-fs (vda): re-mounted 30ec696d-0ac4-40d1-ae34-d8585a77d8c1.
  1191. 125.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 2.447420] booting system configuration /nix/store/65s8l6c9brrb1g3yskvbz60cb4rmq4db-nixos-system-docsserver-test
  1192. 125.45 s [vm-test-run-centjes-e2e-test] client # [ 2.344550] usb 1-1: new full-speed USB device number 2 using uhci_hcd
  1193. 125.46 s [vm-test-run-centjes-e2e-test] client # [ 2.359992] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
  1194. 125.49 s [vm-test-run-centjes-e2e-test] client # [ 2.386422] virtio_blk virtio5: 1/0/0 default/read/poll queues
  1195. 125.52 s [vm-test-run-centjes-e2e-test] client # [ 2.412117] virtio_blk virtio5: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)
  1196. 125.52 s [vm-test-run-centjes-e2e-test] client # [ 2.422375] netfs: FS-Cache loaded
  1197. 125.54 s [vm-test-run-centjes-e2e-test] client # [ 2.437396] 9pnet: Installing 9P2000 support
  1198. 125.54 s [vm-test-run-centjes-e2e-test] client # [ 2.441760] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray
  1199. 125.55 s [vm-test-run-centjes-e2e-test] client # [ 2.444743] cdrom: Uniform CD-ROM driver Revision: 3.20
  1200. 125.62 s [vm-test-run-centjes-e2e-test] client # [ 2.519798] usb 1-1: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00
  1201. 125.63 s [vm-test-run-centjes-e2e-test] client # [ 2.523756] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=10
  1202. 125.63 s [vm-test-run-centjes-e2e-test] client # [ 2.527757] usb 1-1: Product: QEMU USB Tablet
  1203. 125.63 s [vm-test-run-centjes-e2e-test] client # [ 2.530174] usb 1-1: Manufacturer: QEMU
  1204. 125.64 s [vm-test-run-centjes-e2e-test] client # [ 2.532267] usb 1-1: SerialNumber: 28754-0000:00:01.2-1
  1205. 125.67 s [vm-test-run-centjes-e2e-test] client # [ 2.563846] hid: raw HID events driver (C) Jiri Kosina
  1206. 125.68 s [vm-test-run-centjes-e2e-test] client # [ 2.576561] usbcore: registered new interface driver usbhid
  1207. 125.68 s [vm-test-run-centjes-e2e-test] client # [ 2.579522] usbhid: USB HID core driver
  1208. 125.69 s [vm-test-run-centjes-e2e-test] client # [ 2.589341] input: QEMU QEMU USB Tablet as /devices/pci0000:00/0000:00:01.2/usb1/1-1/1-1:1.0/0003:0627:0001.0001/input/input2
  1209. 125.70 s [vm-test-run-centjes-e2e-test] client # [ 2.594625] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v0.01 Mouse [QEMU QEMU USB Tablet] on usb-0000:00:01.2-1/input0
  1210. 125.84 s [vm-test-run-centjes-e2e-test] client # [ 2.733629] EXT4-fs (vda): mounted filesystem 4f1a6b4a-0db2-43fb-b27b-7012ebb0ac47 r/w with ordered data mode. Quota mode: none.
  1211. 125.86 s [vm-test-run-centjes-e2e-test] client # [ 2.758637] 9p: Installing v9fs 9p2000 file system support
  1212. 126.10 s [vm-test-run-centjes-e2e-test] client # [ 2.996651] EXT4-fs (vda): re-mounted 4f1a6b4a-0db2-43fb-b27b-7012ebb0ac47.
  1213. 126.11 s [vm-test-run-centjes-e2e-test] client # [ 3.006141] booting system configuration /nix/store/001k9r4jinw78ih5x5hxggb82ynlbkqn-nixos-system-client-test
  1214. 127.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 4.272251] systemd[1]: Inserted module 'autofs4'
  1215. 127.30 s [vm-test-run-centjes-e2e-test] docsserver # [ 4.329462] systemd[1]: systemd 258.2 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN -IPTC +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP -SYSVINIT +LIBARCHIVE)
  1216. 127.31 s [vm-test-run-centjes-e2e-test] docsserver # [ 4.342998] systemd[1]: Detected virtualization kvm.
  1217. 127.31 s [vm-test-run-centjes-e2e-test] docsserver # [ 4.345870] systemd[1]: Detected architecture x86-64.
  1218. 127.31 s [vm-test-run-centjes-e2e-test] docsserver # [ 4.348478] systemd[1]: Detected first boot.
  1219. 127.32 s [vm-test-run-centjes-e2e-test] docsserver # [ 4.358687] systemd[1]: Initializing machine ID from random generator.
  1220. 127.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 4.385441] systemd[1]: Hostname set to <docsserver>.
  1221. 127.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 4.496854] systemd[1]: bpf-restrict-fs: LSM BPF program attached
  1222. 127.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 4.638281] systemd[1]: Applying preset policy.
  1223. 127.61 s [vm-test-run-centjes-e2e-test] client # [ 4.512244] systemd[1]: Inserted module 'autofs4'
  1224. 127.67 s [vm-test-run-centjes-e2e-test] client # [ 4.558866] systemd[1]: systemd 258.2 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN -IPTC +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP -SYSVINIT +LIBARCHIVE)
  1225. 127.68 s [vm-test-run-centjes-e2e-test] client # [ 4.572840] systemd[1]: Detected virtualization kvm.
  1226. 127.68 s [vm-test-run-centjes-e2e-test] client # [ 4.575295] systemd[1]: Detected architecture x86-64.
  1227. 127.68 s [vm-test-run-centjes-e2e-test] client # [ 4.577697] systemd[1]: Detected first boot.
  1228. 127.69 s [vm-test-run-centjes-e2e-test] client # [ 4.585141] systemd[1]: Initializing machine ID from random generator.
  1229. 127.71 s [vm-test-run-centjes-e2e-test] client # [ 4.608633] systemd[1]: Hostname set to <client>.
  1230. 127.82 s [vm-test-run-centjes-e2e-test] client # [ 4.720843] systemd[1]: bpf-restrict-fs: LSM BPF program attached
  1231. 127.96 s [vm-test-run-centjes-e2e-test] client # [ 4.857932] systemd[1]: Applying preset policy.
  1232. 128.13 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.170617] systemd[1]: Populated /etc with preset unit settings.
  1233. 128.47 s [vm-test-run-centjes-e2e-test] client # [ 5.363039] systemd[1]: Populated /etc with preset unit settings.
  1234. 128.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.577490] systemd[1]: /etc/systemd/system/centjes-docs-site-production.service:3: Invalid URL, ignoring: /nix/store/bp7ak7r85za1cwc3snhzm6cz1ypyh3wv-settings-check
  1235. 128.70 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.700174] systemd[1]: Queued start job for default target Multi-User System.
  1236. 128.70 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.731395] systemd[1]: Created slice Slice /system/getty.
  1237. 128.70 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.734159] systemd[1]: Created slice Slice /system/modprobe.
  1238. 128.70 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.737034] systemd[1]: Created slice User and Session Slice.
  1239. 128.70 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.739574] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
  1240. 128.70 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.742462] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
  1241. 128.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.745339] systemd[1]: Expecting device /dev/hvc0...
  1242. 128.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.747215] systemd[1]: Expecting device /dev/ttyS0...
  1243. 128.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.749147] systemd[1]: Expecting device /sys/subsystem/net/devices/eth1...
  1244. 128.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.751618] systemd[1]: Reached target Local Encrypted Volumes.
  1245. 128.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.753836] systemd[1]: Reached target Virtual Machines and Containers.
  1246. 128.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.756103] systemd[1]: Reached target Path Units.
  1247. 128.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.758292] systemd[1]: Reached target Remote File Systems.
  1248. 128.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.760372] systemd[1]: Reached target Slice Units.
  1249. 128.72 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.762328] systemd[1]: Reached target Swaps.
  1250. 128.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.767973] systemd[1]: Listening on Process Core Dump Socket.
  1251. 128.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.774974] systemd[1]: Listening on Credential Encryption/Decryption.
  1252. 128.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.777826] systemd[1]: Listening on Journal Audit Socket.
  1253. 128.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.780032] systemd[1]: Listening on Journal Socket (/dev/log).
  1254. 128.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.782410] systemd[1]: Listening on Journal Sockets.
  1255. 128.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.784796] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.
  1256. 128.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.787590] systemd[1]: Make TPM PCR Policy was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1257. 128.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.791509] systemd[1]: Listening on udev Control Socket.
  1258. 128.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.793897] systemd[1]: Listening on udev Kernel Socket.
  1259. 128.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.800861] systemd[1]: Mounting Huge Pages File System...
  1260. 128.77 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.806358] systemd[1]: Mounting POSIX Message Queue File System...
  1261. 128.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.814969] systemd[1]: Mounting Kernel Debug File System...
  1262. 128.79 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.827385] systemd[1]: Mounting Kernel Trace File System...
  1263. 128.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.841576] systemd[1]: Starting Create List of Static Device Nodes...
  1264. 128.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.848372] systemd[1]: Load Kernel Module 9pnet_virtio was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!9pnet_virtio).
  1265. 128.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.866525] systemd[1]: Starting Load Kernel Module configfs...
  1266. 128.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.869451] systemd[1]: Load Kernel Module drm was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!drm).
  1267. 128.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.882828] systemd[1]: Starting Load Kernel Module efi_pstore...
  1268. 128.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.890956] systemd[1]: Starting Load Kernel Module fuse...
  1269. 128.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.895879] systemd[1]: File System Check on Root Device was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/).
  1270. 128.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.901243] systemd[1]: Clear Stale Hibernate Storage Info was skipped because of an unmet condition check (ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67).
  1271. 128.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.912950] systemd[1]: Starting Journal Service...
  1272. 128.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.921806] systemd[1]: Starting Load Kernel Modules...
  1273. 128.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.932465] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...
  1274. 128.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.940890] systemd[1]: Starting Remount Root and Kernel File Systems...
  1275. 128.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.946231] systemd[1]: Early TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1276. 128.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.958235] systemd[1]: Starting Coldplug All udev Devices...
  1277. 128.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.967515] systemd[1]: Mounted Huge Pages File System.
  1278. 128.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.972004] systemd[1]: Mounted POSIX Message Queue File System.
  1279. 128.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.977434] systemd[1]: Mounted Kernel Debug File System.
  1280. 128.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.983475] systemd[1]: Mounted Kernel Trace File System.
  1281. 128.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 5.990054] systemd[1]: Finished Create List of Static Device Nodes.
  1282. 128.96 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.002569] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...
  1283. 128.99 s [vm-test-run-centjes-e2e-test] client # [ 5.883040] systemd[1]: Queued start job for default target Multi-User System.
  1284. 129.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.044228] systemd[1]: modprobe@configfs.service: Deactivated successfully.
  1285. 129.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.050608] systemd[1]: Finished Load Kernel Module configfs.
  1286. 129.01 s [vm-test-run-centjes-e2e-test] client # [ 5.911106] systemd[1]: Created slice Slice /system/getty.
  1287. 129.02 s [vm-test-run-centjes-e2e-test] client # [ 5.913815] systemd[1]: Created slice Slice /system/modprobe.
  1288. 129.02 s [vm-test-run-centjes-e2e-test] client # [ 5.916406] systemd[1]: Created slice User and Session Slice.
  1289. 129.02 s [vm-test-run-centjes-e2e-test] client # [ 5.919045] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
  1290. 129.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.059645] systemd[1]: Mounting Kernel Configuration File System...
  1291. 129.02 s [vm-test-run-centjes-e2e-test] client # [ 5.921854] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
  1292. 129.03 s [vm-test-run-centjes-e2e-test] client # [ 5.924776] systemd[1]: Expecting device /dev/hvc0...
  1293. 129.03 s [vm-test-run-centjes-e2e-test] client # [ 5.926667] systemd[1]: Expecting device /dev/ttyS0...
  1294. 129.03 s [vm-test-run-centjes-e2e-test] client # [ 5.928610] systemd[1]: Expecting device /sys/subsystem/net/devices/eth1...
  1295. 129.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.068669] systemd[1]: modprobe@efi_pstore.service: Deactivated successfully.
  1296. 129.03 s [vm-test-run-centjes-e2e-test] client # [ 5.931184] systemd[1]: Reached target Local Encrypted Volumes.
  1297. 129.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.073468] EXT4-fs (vda): re-mounted 30ec696d-0ac4-40d1-ae34-d8585a77d8c1.
  1298. 129.04 s [vm-test-run-centjes-e2e-test] client # [ 5.933604] systemd[1]: Reached target Virtual Machines and Containers.
  1299. 129.04 s [vm-test-run-centjes-e2e-test] client # [ 5.936189] systemd[1]: Reached target Path Units.
  1300. 129.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.076631] systemd[1]: Finished Load Kernel Module efi_pstore.
  1301. 129.04 s [vm-test-run-centjes-e2e-test] client # [ 5.938146] systemd[1]: Reached target Remote File Systems.
  1302. 129.04 s [vm-test-run-centjes-e2e-test] client # [ 5.940400] systemd[1]: Reached target Slice Units.
  1303. 129.04 s [vm-test-run-centjes-e2e-test] client # [ 5.942522] systemd[1]: Reached target Swaps.
  1304. 129.05 s [vm-test-run-centjes-e2e-test] client # [ 5.947799] systemd[1]: Listening on Process Core Dump Socket.
  1305. 129.06 s [vm-test-run-centjes-e2e-test] client # [ 5.953030] systemd[1]: Listening on Credential Encryption/Decryption.
  1306. 129.06 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.093520] systemd[1]: Mounted Kernel Configuration File System.
  1307. 129.06 s [vm-test-run-centjes-e2e-test] client # [ 5.955876] systemd[1]: Listening on Journal Audit Socket.
  1308. 129.06 s [vm-test-run-centjes-e2e-test] client # [ 5.958104] systemd[1]: Listening on Journal Socket (/dev/log).
  1309. 129.06 s [vm-test-run-centjes-e2e-test] client # [ 5.960429] systemd[1]: Listening on Journal Sockets.
  1310. 129.06 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.103673] loop: module loaded
  1311. 129.07 s [vm-test-run-centjes-e2e-test] client # [ 5.962823] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.
  1312. 129.07 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.105421] systemd-journald[383]: Collecting audit messages is enabled.
  1313. 129.07 s [vm-test-run-centjes-e2e-test] client # [ 5.965803] systemd[1]: Make TPM PCR Policy was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1314. 129.07 s [vm-test-run-centjes-e2e-test] client # [ 5.969834] systemd[1]: Listening on udev Control Socket.
  1315. 129.07 s [vm-test-run-centjes-e2e-test] client # [ 5.972104] systemd[1]: Listening on udev Kernel Socket.
  1316. 129.08 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.114172] systemd[1]: Finished Remount Root and Kernel File Systems.
  1317. 129.08 s [vm-test-run-centjes-e2e-test] client # [ 5.978147] systemd[1]: Mounting Huge Pages File System...
  1318. 129.08 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.119063] systemd[1]: Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore).
  1319. 129.09 s [vm-test-run-centjes-e2e-test] client # [ 5.983690] systemd[1]: Mounting POSIX Message Queue File System...
  1320. 129.09 s [vm-test-run-centjes-e2e-test] client # [ 5.991781] systemd[1]: Mounting Kernel Debug File System...
  1321. 129.10 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.135885] fuse: init (API version 7.41)
  1322. 129.10 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.140913] systemd[1]: Starting Load/Save OS Random Seed...
  1323. 129.11 s [vm-test-run-centjes-e2e-test] client # [ 6.003830] systemd[1]: Mounting Kernel Trace File System...
  1324. 129.11 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.146275] systemd[1]: TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1325. 129.12 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.158104] systemd[1]: Finished Load Kernel Modules.
  1326. 129.12 s [vm-test-run-centjes-e2e-test] client # [ 6.021303] systemd[1]: Starting Create List of Static Device Nodes...
  1327. 129.13 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.167596] systemd[1]: Starting Firewall...
  1328. 129.13 s [vm-test-run-centjes-e2e-test] client # [ 6.030127] systemd[1]: Load Kernel Module 9pnet_virtio was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!9pnet_virtio).
  1329. 129.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.175336] systemd[1]: Starting Apply Kernel Variables...
  1330. 129.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.179648] systemd[1]: modprobe@fuse.service: Deactivated successfully.
  1331. 129.15 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.186900] systemd[1]: Finished Load Kernel Module fuse.
  1332. 129.15 s [vm-test-run-centjes-e2e-test] client # [ 6.048089] systemd[1]: Starting Load Kernel Module configfs...
  1333. 129.16 s [vm-test-run-centjes-e2e-test] client # [ 6.051894] systemd[1]: Load Kernel Module drm was skipped because of an unmet condition check (ConditionKernelModuleLoaded=!drm).
  1334. 129.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.197471] systemd[1]: Mounting FUSE Control File System...
  1335. 129.16 s [vm-test-run-centjes-e2e-test] client # [ 6.060573] systemd[1]: Starting Load Kernel Module efi_pstore...
  1336. 129.17 s [vm-test-run-centjes-e2e-test] client # [ 6.069081] systemd[1]: Starting Load Kernel Module fuse...
  1337. 129.18 s [vm-test-run-centjes-e2e-test] client # [ 6.072639] systemd[1]: File System Check on Root Device was skipped because of an unmet condition check (ConditionPathIsReadWrite=!/).
  1338. 129.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.224469] systemd[1]: Mounted FUSE Control File System.
  1339. 129.19 s [vm-test-run-centjes-e2e-test] client # [ 6.081984] systemd[1]: Clear Stale Hibernate Storage Info was skipped because of an unmet condition check (ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67).
  1340. 129.20 s [vm-test-run-centjes-e2e-test] client # [ 6.094946] systemd[1]: Starting Journal Service...
  1341. 129.20 s [vm-test-run-centjes-e2e-test] client # [ 6.102148] systemd[1]: Starting Load Kernel Modules...
  1342. 129.21 s [vm-test-run-centjes-e2e-test] client # [ 6.111171] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...
  1343. 129.22 s [vm-test-run-centjes-e2e-test] client # [ 6.121605] systemd[1]: Starting Remount Root and Kernel File Systems...
  1344. 129.23 s [vm-test-run-centjes-e2e-test] client # [ 6.126694] systemd[1]: Early TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1345. 129.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.280154] systemd[1]: Finished Load/Save OS Random Seed.
  1346. 129.24 s [vm-test-run-centjes-e2e-test] client # [ 6.141922] systemd[1]: Starting Coldplug All udev Devices...
  1347. 129.25 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.284276] systemd[1]: Reached target First Boot Complete.
  1348. 129.25 s [vm-test-run-centjes-e2e-test] client # [ 6.152988] systemd[1]: Mounted Huge Pages File System.
  1349. 129.26 s [vm-test-run-centjes-e2e-test] client # [ 6.157369] systemd[1]: Mounted POSIX Message Queue File System.
  1350. 129.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.296133] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
  1351. 129.26 s [vm-test-run-centjes-e2e-test] client # [ 6.162214] systemd[1]: Mounted Kernel Debug File System.
  1352. 129.27 s [vm-test-run-centjes-e2e-test] client # [ 6.167384] systemd[1]: Mounted Kernel Trace File System.
  1353. 129.27 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.307939] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.
  1354. 129.28 s [vm-test-run-centjes-e2e-test] client # [ 6.174167] systemd[1]: Finished Create List of Static Device Nodes.
  1355. 129.28 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.322319] systemd[1]: Starting Create Static Device Nodes in /dev...
  1356. 129.29 s [vm-test-run-centjes-e2e-test] client # [ 6.185929] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...
  1357. 129.30 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.337653] systemd[1]: Finished Apply Kernel Variables.
  1358. 129.33 s [vm-test-run-centjes-e2e-test] client # [ 6.227134] systemd[1]: modprobe@configfs.service: Deactivated successfully.
  1359. 129.34 s [vm-test-run-centjes-e2e-test] client # [ 6.233297] systemd[1]: Finished Load Kernel Module configfs.
  1360. 129.34 s [vm-test-run-centjes-e2e-test] client # [ 6.242099] systemd[1]: Mounting Kernel Configuration File System...
  1361. 129.35 s [vm-test-run-centjes-e2e-test] client # [ 6.248351] EXT4-fs (vda): re-mounted 4f1a6b4a-0db2-43fb-b27b-7012ebb0ac47.
  1362. 129.37 s [vm-test-run-centjes-e2e-test] client # [ 6.271281] systemd[1]: Mounted Kernel Configuration File System.
  1363. 129.38 s [vm-test-run-centjes-e2e-test] client # [ 6.279631] loop: module loaded
  1364. 129.39 s [vm-test-run-centjes-e2e-test] client # [ 6.284008] systemd[1]: Finished Remount Root and Kernel File Systems.
  1365. 129.39 s [vm-test-run-centjes-e2e-test] client # [ 6.290008] systemd[1]: modprobe@efi_pstore.service: Deactivated successfully.
  1366. 129.40 s [vm-test-run-centjes-e2e-test] client # [ 6.297588] systemd[1]: Finished Load Kernel Module efi_pstore.
  1367. 129.40 s [vm-test-run-centjes-e2e-test] client # [ 6.300718] systemd-journald[383]: Collecting audit messages is enabled.
  1368. 129.41 s [vm-test-run-centjes-e2e-test] client # [ 6.303732] systemd[1]: Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore).
  1369. 129.42 s [vm-test-run-centjes-e2e-test] client # [ 6.318102] systemd[1]: Starting Load/Save OS Random Seed...
  1370. 129.43 s [vm-test-run-centjes-e2e-test] client # [ 6.322184] systemd[1]: TPM SRK Setup was skipped because of an unmet condition check (ConditionSecurity=measured-uki).
  1371. 129.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.464917] systemd[1]: Finished Create Static Device Nodes in /dev.
  1372. 129.43 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.472206] systemd[1]: Reached target Preparation for Local File Systems.
  1373. 129.44 s [vm-test-run-centjes-e2e-test] client # [ 6.333629] systemd[1]: Finished Load Kernel Modules.
  1374. 129.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.481522] systemd[1]: Starting Rule-based Manager for Device Events and Files...
  1375. 129.45 s [vm-test-run-centjes-e2e-test] client # [ 6.343802] fuse: init (API version 7.41)
  1376. 129.45 s [vm-test-run-centjes-e2e-test] client # [ 6.347191] systemd[1]: Starting Firewall...
  1377. 129.46 s [vm-test-run-centjes-e2e-test] client # [ 6.355730] systemd[1]: Starting Apply Kernel Variables...
  1378. 129.47 s [vm-test-run-centjes-e2e-test] client # [ 6.363928] systemd[1]: modprobe@fuse.service: Deactivated successfully.
  1379. 129.47 s [vm-test-run-centjes-e2e-test] client # [ 6.370534] systemd[1]: Finished Load Kernel Module fuse.
  1380. 129.48 s [vm-test-run-centjes-e2e-test] client # [ 6.379907] systemd[1]: Mounting FUSE Control File System...
  1381. 129.51 s [vm-test-run-centjes-e2e-test] client # [ 6.405722] systemd[1]: Mounted FUSE Control File System.
  1382. 129.56 s [vm-test-run-centjes-e2e-test] client # [ 6.453622] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
  1383. 129.57 s [vm-test-run-centjes-e2e-test] client # [ 6.465990] systemd[1]: Starting Create Static Device Nodes in /dev...
  1384. 129.57 s [vm-test-run-centjes-e2e-test] client # [ 6.471876] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.
  1385. 129.58 s [vm-test-run-centjes-e2e-test] client # [ 6.479414] systemd[1]: Finished Load/Save OS Random Seed.
  1386. 129.59 s [vm-test-run-centjes-e2e-test] client # [ 6.485097] systemd[1]: Reached target First Boot Complete.
  1387. 129.60 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.640522] systemd[1]: Started Journal Service.
  1388. 129.61 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.272648] systemd-modules-load[384]: Inserted module 'loop'
  1389. 129.62 s [vm-test-run-centjes-e2e-test] client # [ 6.513712] systemd[1]: Finished Apply Kernel Variables.
  1390. 129.62 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.288406] systemd-oomd[385]: [0;1;38:5:185mNo swap; memory pressure usage will be degraded
  1391. 129.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.303943] systemd-udevd[410]: Using default interface naming scheme 'v258'.
  1392. 129.65 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.314333] systemd[1]: Starting Flush Journal to Persistent Storage...
  1393. 129.70 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.741275] systemd-journald[383]: Received client request to flush runtime journal.
  1394. 129.70 s [vm-test-run-centjes-e2e-test] client # [ 6.602855] systemd[1]: Finished Create Static Device Nodes in /dev.
  1395. 129.71 s [vm-test-run-centjes-e2e-test] client # [ 6.607979] systemd[1]: Reached target Preparation for Local File Systems.
  1396. 129.72 s [vm-test-run-centjes-e2e-test] client # [ 6.617916] systemd[1]: Starting Rule-based Manager for Device Events and Files...
  1397. 129.91 s [vm-test-run-centjes-e2e-test] client # [ 6.812956] systemd[1]: Started Journal Service.
  1398. 129.92 s [vm-test-run-centjes-e2e-test] client # [ 6.453167] systemd-modules-load[384]: Inserted module 'loop'
  1399. 129.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.585366] systemd[1]: Finished Coldplug All udev Devices.
  1400. 129.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.593918] systemd[1]: Started Rule-based Manager for Device Events and Files.
  1401. 129.94 s [vm-test-run-centjes-e2e-test] client # [ 6.462695] systemd-oomd[385]: [0;1;38:5:185mNo swap; memory pressure usage will be degraded
  1402. 129.94 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.603882] systemd[1]: Finished Flush Journal to Persistent Storage.
  1403. 129.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.612697] systemd[1]: Mounting /run/wrappers...
  1404. 129.95 s [vm-test-run-centjes-e2e-test] client # [ 6.478247] systemd-udevd[409]: Using default interface naming scheme 'v258'.
  1405. 129.96 s [vm-test-run-centjes-e2e-test] client # [ 6.486646] systemd[1]: Starting Flush Journal to Persistent Storage...
  1406. 129.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.646202] systemd[1]: Mounted /run/wrappers.
  1407. 129.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.651385] systemd[1]: Reached target Local File Systems.
  1408. 130.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.658643] systemd[1]: Listening on Boot Entries Service Socket.
  1409. 130.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.668344] systemd[1]: Starting Create SUID/SGID Wrappers...
  1410. 130.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.680227] systemd[1]: Update Boot Loader Random Seed was skipped because no trigger condition checks were met.
  1411. 130.03 s [vm-test-run-centjes-e2e-test] client # [ 6.923903] systemd-journald[383]: Received client request to flush runtime journal.
  1412. 130.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.691186] systemd[1]: Starting Save Transient machine-id to Disk...
  1413. 130.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.699531] systemd[1]: Starting Create System Files and Directories...
  1414. 130.10 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.762426] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
  1415. 130.11 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.775087] systemd[1]: Finished Save Transient machine-id to Disk.
  1416. 130.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.831190] systemd[1]: Finished Create System Files and Directories.
  1417. 130.18 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.842596] systemd[1]: Starting Rebuild Journal Catalog...
  1418. 130.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.850499] systemd[1]: Starting Record System Boot/Shutdown in UTMP...
  1419. 130.21 s [vm-test-run-centjes-e2e-test] client # [ 6.740385] systemd[1]: Started Rule-based Manager for Device Events and Files.
  1420. 130.22 s [vm-test-run-centjes-e2e-test] client # [ 6.749385] systemd[1]: Finished Coldplug All udev Devices.
  1421. 130.23 s [vm-test-run-centjes-e2e-test] client # [ 6.754860] systemd[1]: Finished Flush Journal to Persistent Storage.
  1422. 130.26 s [vm-test-run-centjes-e2e-test] client # [ 6.790779] systemd[1]: Mounting /run/wrappers...
  1423. 130.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.926792] systemd[1]: Finished Record System Boot/Shutdown in UTMP.
  1424. 130.30 s [vm-test-run-centjes-e2e-test] client # [ 6.831892] systemd[1]: Mounted /run/wrappers.
  1425. 130.31 s [vm-test-run-centjes-e2e-test] client # [ 6.836784] systemd[1]: Reached target Local File Systems.
  1426. 130.32 s [vm-test-run-centjes-e2e-test] client # [ 6.843962] systemd[1]: Listening on Boot Entries Service Socket.
  1427. 130.32 s [vm-test-run-centjes-e2e-test] client # [ 6.852419] systemd[1]: Starting Create SUID/SGID Wrappers...
  1428. 130.33 s [vm-test-run-centjes-e2e-test] docsserver # [ 6.995213] systemd[1]: Finished Rebuild Journal Catalog.
  1429. 130.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.002390] systemd[1]: Starting Update is Completed...
  1430. 130.34 s [vm-test-run-centjes-e2e-test] client # [ 6.860365] systemd[1]: Update Boot Loader Random Seed was skipped because no trigger condition checks were met.
  1431. 130.35 s [vm-test-run-centjes-e2e-test] client # [ 6.876297] systemd[1]: Starting Save Transient machine-id to Disk...
  1432. 130.36 s [vm-test-run-centjes-e2e-test] client # [ 6.886651] systemd[1]: Starting Create System Files and Directories...
  1433. 130.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.078400] systemd[1]: Finished Update is Completed.
  1434. 130.44 s [vm-test-run-centjes-e2e-test] client # [ 6.961224] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
  1435. 130.45 s [vm-test-run-centjes-e2e-test] client # [ 6.976281] systemd[1]: Finished Save Transient machine-id to Disk.
  1436. 130.51 s [vm-test-run-centjes-e2e-test] client # [ 7.036299] systemd[1]: Finished Create System Files and Directories.
  1437. 130.52 s [vm-test-run-centjes-e2e-test] client # [ 7.044324] systemd[1]: Starting Rebuild Journal Catalog...
  1438. 130.53 s [vm-test-run-centjes-e2e-test] client # [ 7.055418] systemd[1]: Starting Record System Boot/Shutdown in UTMP...
  1439. 130.59 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.250713] systemd[1]: Found device /dev/hvc0.
  1440. 130.60 s [vm-test-run-centjes-e2e-test] client # [ 7.132649] systemd[1]: Finished Record System Boot/Shutdown in UTMP.
  1441. 130.64 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.303754] systemd[1]: Found device /dev/ttyS0.
  1442. 130.67 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.323703] (udev-worker)[504]: [0;1;38:5:185meth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.
  1443. 130.68 s [vm-test-run-centjes-e2e-test] client # [ 7.206327] systemd[1]: Finished Rebuild Journal Catalog.
  1444. 130.68 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.346547] (udev-worker)[504]: Network interface NamePolicy= disabled on kernel command line.
  1445. 130.69 s [vm-test-run-centjes-e2e-test] client # [ 7.216158] systemd[1]: Starting Update is Completed...
  1446. 130.70 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.359657] (udev-worker)[499]: Network interface NamePolicy= disabled on kernel command line.
  1447. 130.75 s [vm-test-run-centjes-e2e-test] client # [ 7.281212] systemd[1]: Finished Update is Completed.
  1448. 130.80 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.463902] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.
  1449. 130.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.471934] systemd[1]: Finished Create SUID/SGID Wrappers.
  1450. 130.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.478479] systemd[1]: Reached target System Initialization.
  1451. 130.82 s [vm-test-run-centjes-e2e-test] client # [ 7.350738] systemd[1]: Found device /dev/hvc0.
  1452. 130.83 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.485761] systemd[1]: Started Discard unused filesystem blocks once a week.
  1453. 130.85 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.498658] systemd[1]: Started Daily Cleanup of Temporary Directories.
  1454. 130.86 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.520195] systemd[1]: Reached target Timer Units.
  1455. 130.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.534619] systemd[1]: Listening on D-Bus System Message Bus Socket.
  1456. 130.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.549461] systemd[1]: Listening on Nix Daemon Socket.
  1457. 130.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.563865] systemd[1]: Listening on Hostname Service Socket.
  1458. 130.91 s [vm-test-run-centjes-e2e-test] client # [ 7.442864] systemd[1]: Found device /dev/ttyS0.
  1459. 130.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.589214] systemd[1]: Reached target Socket Units.
  1460. 130.93 s [vm-test-run-centjes-e2e-test] client # [ 7.458773] (udev-worker)[485]: Network interface NamePolicy= disabled on kernel command line.
  1461. 130.95 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.601300] systemd[1]: Reached target Basic System.
  1462. 130.96 s [vm-test-run-centjes-e2e-test] client # [ 7.480898] (udev-worker)[483]: [0;1;38:5:185meth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.
  1463. 130.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.627350] systemd[1]: System is tainted: support-ended
  1464. 130.97 s [vm-test-run-centjes-e2e-test] client # [ 7.496734] (udev-worker)[483]: Network interface NamePolicy= disabled on kernel command line.
  1465. 130.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.646401] systemd[1]: Started backdoor.service.
  1466. 131.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.660251] systemd[1]: Starting Import lastlog data into lastlog2 database...
  1467. 131.02 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.676797] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
  1468. 131.04 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.690871] systemd[1]: Started Reset console on configuration changes.
  1469. 131.05 s [vm-test-run-centjes-e2e-test] docsserver # connecting to host...
  1470. 131.05 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.712855] systemd[1]: Starting resolvconf update...
  1471. 131.07 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.727203] systemd[1]: Started Centjes docs site production Service.
  1472. 131.08 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.736791] systemd[1]: Starting D-Bus System Message Bus...
  1473. 131.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.752890] systemd[1]: Finished Firewall.
  1474. 131.10 s [vm-test-run-centjes-e2e-test] client # [ 7.634226] systemd[1]: Finished Firewall.
  1475. 131.11 s [vm-test-run-centjes-e2e-test] docsserver: Guest shell says: b'Spawning backdoor root shell...\n'
  1476. 131.12 s [vm-test-run-centjes-e2e-test] docsserver: connected to guest root shell
  1477. 131.12 s [vm-test-run-centjes-e2e-test] docsserver: (connecting took 8.83 seconds)
  1478. 131.12 s [vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for the VM to finish booting, in 8.83 seconds)
  1479. 131.13 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.763991] nsncd[617]: Aug 04 20:41:48.544 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
  1480. 131.14 s [vm-test-run-centjes-e2e-test] client # [ 7.664756] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.
  1481. 131.14 s [vm-test-run-centjes-e2e-test] client # [ 7.674302] systemd[1]: Finished Create SUID/SGID Wrappers.
  1482. 131.14 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.801093] systemd[1]: Finished Import lastlog data into lastlog2 database.
  1483. 131.15 s [vm-test-run-centjes-e2e-test] client # [ 7.680119] systemd[1]: Reached target System Initialization.
  1484. 131.16 s [vm-test-run-centjes-e2e-test] client # [ 7.684663] systemd[1]: Started Discard unused filesystem blocks once a week.
  1485. 131.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.813877] dbus-daemon[622]: dbus[622]: Unknown username "systemd-timesync" in message bus configuration file
  1486. 131.18 s [vm-test-run-centjes-e2e-test] client # [ 7.696811] systemd[1]: Started Daily Cleanup of Temporary Directories.
  1487. 131.18 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.836311] systemd[1]: Started Name Service Cache Daemon (nsncd).
  1488. 131.19 s [vm-test-run-centjes-e2e-test] client # [ 7.714276] systemd[1]: Reached target Timer Units.
  1489. 131.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.847715] systemd[1]: Reached target Host and Network Name Lookups.
  1490. 131.20 s [vm-test-run-centjes-e2e-test] client # [ 7.723138] systemd[1]: Listening on D-Bus System Message Bus Socket.
  1491. 131.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.863663] systemd[1]: Reached target User and Group Name Lookups.
  1492. 131.21 s [vm-test-run-centjes-e2e-test] client # [ 7.732362] systemd[1]: Listening on Nix Daemon Socket.
  1493. 131.21 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.875374] systemd[1]: Starting User Login Management...
  1494. 131.22 s [vm-test-run-centjes-e2e-test] client # [ 7.747325] systemd[1]: Listening on Hostname Service Socket.
  1495. 131.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.882664] systemd[1]: Found device Virtio network device.
  1496. 131.23 s [vm-test-run-centjes-e2e-test] client # [ 7.757680] systemd[1]: Reached target Socket Units.
  1497. 131.24 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.898917] systemd[1]: Started D-Bus System Message Bus.
  1498. 131.25 s [vm-test-run-centjes-e2e-test] client # [ 7.770911] systemd[1]: Reached target Basic System.
  1499. 131.26 s [vm-test-run-centjes-e2e-test] client # [ 7.788210] systemd[1]: System is tainted: support-ended
  1500. 131.27 s [vm-test-run-centjes-e2e-test] client # [ 7.799816] systemd[1]: Started backdoor.service.
  1501. 131.29 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.948232] systemd[1]: Stopped target Host and Network Name Lookups.
  1502. 131.29 s [vm-test-run-centjes-e2e-test] client # [ 7.815352] systemd[1]: Starting Import lastlog data into lastlog2 database...
  1503. 131.30 s [vm-test-run-centjes-e2e-test] client # [ 7.826457] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
  1504. 131.30 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.962169] systemd[1]: Stopping Host and Network Name Lookups...
  1505. 131.30 s [vm-test-run-centjes-e2e-test] client # connecting to host...
  1506. 131.31 s [vm-test-run-centjes-e2e-test] client # [ 7.841105] systemd[1]: Started Reset console on configuration changes.
  1507. 131.31 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.971899] systemd[1]: Stopped target User and Group Name Lookups.
  1508. 131.33 s [vm-test-run-centjes-e2e-test] client # [ 7.853866] systemd[1]: Starting resolvconf update...
  1509. 131.33 s [vm-test-run-centjes-e2e-test] docsserver # [ 7.989820] systemd[1]: Stopping User and Group Name Lookups...
  1510. 131.33 s [vm-test-run-centjes-e2e-test] client # [ 7.863197] systemd[1]: Found device Virtio network device.
  1511. 131.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.001717] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...
  1512. 131.34 s [vm-test-run-centjes-e2e-test] client # [ 7.871771] systemd[1]: Starting D-Bus System Message Bus...
  1513. 131.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.009542] systemd[1]: nscd.service: Deactivated successfully.
  1514. 131.36 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.021859] systemd[1]: Stopped Name Service Cache Daemon (nsncd).
  1515. 131.37 s [vm-test-run-centjes-e2e-test] client # [ 7.884631] nsncd[621]: Aug 04 20:41:48.834 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
  1516. 131.38 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.035456] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
  1517. 131.38 s [vm-test-run-centjes-e2e-test] client # [ 7.903476] systemd[1]: Finished Import lastlog data into lastlog2 database.
  1518. 131.39 s [vm-test-run-centjes-e2e-test] client # [ 7.913488] systemd[1]: Started Name Service Cache Daemon (nsncd).
  1519. 131.40 s [vm-test-run-centjes-e2e-test] client # [ 7.920674] systemd[1]: Reached target Host and Network Name Lookups.
  1520. 131.40 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.055722] systemd-logind[644]: New seat seat0.
  1521. 131.41 s [vm-test-run-centjes-e2e-test] client # [ 7.933388] dbus-daemon[624]: dbus[624]: Unknown username "systemd-timesync" in message bus configuration file
  1522. 131.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.066777] systemd[1]: Started User Login Management.
  1523. 131.42 s [vm-test-run-centjes-e2e-test] client # [ 7.944887] systemd[1]: Reached target User and Group Name Lookups.
  1524. 131.42 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.079932] systemd[1]: Starting linger-users.service...
  1525. 131.43 s [vm-test-run-centjes-e2e-test] client # [ 7.958346] systemd[1]: Starting User Login Management...
  1526. 131.45 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.112780] systemd[1]: Started Name Service Cache Daemon (nsncd).
  1527. 131.46 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.123295] systemd[1]: Reached target Host and Network Name Lookups.
  1528. 131.47 s [vm-test-run-centjes-e2e-test] client # [ 7.994678] systemd[1]: Started D-Bus System Message Bus.
  1529. 131.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.131873] nsncd[695]: Aug 04 20:41:48.919 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
  1530. 131.49 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.149857] systemd[1]: Reached target User and Group Name Lookups.
  1531. 131.50 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.160800] systemd[1]: linger-users.service: Deactivated successfully.
  1532. 131.51 s [vm-test-run-centjes-e2e-test] client # [ 8.038397] systemd[1]: Stopped target Host and Network Name Lookups.
  1533. 131.51 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.174826] systemd[1]: Finished linger-users.service.
  1534. 131.52 s [vm-test-run-centjes-e2e-test] client # [ 8.048948] systemd[1]: Stopping Host and Network Name Lookups...
  1535. 131.53 s [vm-test-run-centjes-e2e-test] client # [ 8.055250] systemd[1]: Stopped target User and Group Name Lookups.
  1536. 131.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.193686] systemd[1]: Finished resolvconf update.
  1537. 131.54 s [vm-test-run-centjes-e2e-test] client # [ 8.065719] systemd[1]: Stopping User and Group Name Lookups...
  1538. 131.54 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.203260] systemd[1]: Reached target Preparation for Network.
  1539. 131.55 s [vm-test-run-centjes-e2e-test] client # [ 8.072577] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...
  1540. 131.55 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.215179] systemd[1]: Starting DHCP Client...
  1541. 131.56 s [vm-test-run-centjes-e2e-test] client # [ 8.081572] systemd[1]: nscd.service: Deactivated successfully.
  1542. 131.56 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.220361] systemd[1]: Starting Address configuration of eth1...
  1543. 131.57 s [vm-test-run-centjes-e2e-test] client # [ 8.091861] systemd[1]: Stopped Name Service Cache Daemon (nsncd).
  1544. 131.58 s [vm-test-run-centjes-e2e-test] client # [ 8.103735] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
  1545. 131.59 s [vm-test-run-centjes-e2e-test] client # [ 8.116737] systemd-logind[640]: New seat seat0.
  1546. 131.59 s [vm-test-run-centjes-e2e-test] client # [ 8.126162] systemd[1]: Started User Login Management.
  1547. 131.60 s [vm-test-run-centjes-e2e-test] client # [ 8.131817] systemd[1]: Starting linger-users.service...[ 8.499279] mousedev: PS/2 mouse device common for all mice
  1548. 131.61 s [vm-test-run-centjes-e2e-test] client #
  1549. 131.65 s [vm-test-run-centjes-e2e-test] client # [ 8.164628] nsncd[684]: Aug 04 20:41:49.121 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
  1550. 131.65 s [vm-test-run-centjes-e2e-test] client # [ 8.181790] systemd[1]: Started Name Service Cache Daemon (nsncd).
  1551. 131.66 s [vm-test-run-centjes-e2e-test] client # [ 8.191467] systemd[1]: Reached target Host and Network Name Lookups.
  1552. 131.67 s [vm-test-run-centjes-e2e-test] client # [ 8.197865] systemd[1]: Reached target User and Group Name Lookups.
  1553. 131.67 s [vm-test-run-centjes-e2e-test] client # [ 8.202184] systemd[1]: linger-users.service: Deactivated successfully.
  1554. 131.67 s [vm-test-run-centjes-e2e-test] client # [ 8.205995] systemd[1]: Finished linger-users.service.
  1555. 131.69 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.346512] network-addresses-eth1-start[730]: adding address 192.168.1.2/24... done
  1556. 131.69 s [vm-test-run-centjes-e2e-test] client # [ 8.590054] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input3
  1557. 131.70 s [vm-test-run-centjes-e2e-test] client # [ 8.233303] systemd[1]: Finished resolvconf update.
  1558. 131.71 s [vm-test-run-centjes-e2e-test] client # [ 8.237934] systemd[1]: Reached target Preparation for Network.
  1559. 131.71 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.367925] network-addresses-eth1-start[730]: adding address 2001:db8:1::2/64... done[ 8.745853] mousedev: PS/2 mouse device common for all mice
  1560. 131.71 s [vm-test-run-centjes-e2e-test] docsserver #
  1561. 131.71 s [vm-test-run-centjes-e2e-test] client # [ 8.243245] systemd[1]: Starting DHCP Client...
  1562. 131.72 s [vm-test-run-centjes-e2e-test] client # [ 8.247935] systemd[1]: Starting Address configuration of eth1...
  1563. 131.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.404189] systemd[1]: Finished Address configuration of eth1.
  1564. 131.75 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.409990] systemd[1]: Starting Networking Setup...
  1565. 131.75 s [vm-test-run-centjes-e2e-test] client # [ 8.648902] ACPI: button: Power Button [PWRF]
  1566. 131.76 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.794467] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input3
  1567. 131.77 s [vm-test-run-centjes-e2e-test] client # [ 8.673267] rtc_cmos 00:05: RTC can wake from S4
  1568. 131.80 s [vm-test-run-centjes-e2e-test] client # [ 8.698355] parport_pc 00:03: reported by Plug and Play ACPI
  1569. 131.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.473816] dhcpcd[737]: dhcpcd-10.2.4 starting
  1570. 131.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.851956] ACPI: button: Power Button [PWRF]
  1571. 131.83 s [vm-test-run-centjes-e2e-test] client # [ 8.362451] network-addresses-eth1-start[714]: adding address 192.168.1.1/24... done[ 8.730705] Floppy drive(s): fd0 is 2.88M AMI BIOS
  1572. 131.84 s [vm-test-run-centjes-e2e-test] client #
  1573. 131.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.503659] dhcpcd[750]: dev: loaded udev
  1574. 131.84 s [vm-test-run-centjes-e2e-test] client # [ 8.736998] parport0: PC-style at 0x378, irq 7 [PCSPP(,...)]
  1575. 131.84 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.878677] rtc_cmos 00:05: RTC can wake from S4
  1576. 131.85 s [vm-test-run-centjes-e2e-test] client # [ 8.745623] rtc_cmos 00:05: registered as rtc0
  1577. 131.86 s [vm-test-run-centjes-e2e-test] client # [ 8.386670] network-addresses-eth1-start[714]: adding address 2001:db8:1::1/64... done
  1578. 131.87 s [vm-test-run-centjes-e2e-test] client # [ 8.765794] rtc_cmos 00:05: setting system clock to 2026-08-04T20:41:49 UTC (1785876109)
  1579. 131.87 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.911393] 8021q: 802.1Q VLAN Support v1.8
  1580. 131.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.913955] Floppy drive(s): fd0 is 2.88M AMI BIOS
  1581. 131.88 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.915790] 8021q: adding VLAN 0 to HW filter on device eth1
  1582. 131.89 s [vm-test-run-centjes-e2e-test] client # [ 8.415445] systemd[1]: Finished Address configuration of eth1.
  1583. 131.89 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.926081] parport_pc 00:03: reported by Plug and Play ACPI
  1584. 131.89 s [vm-test-run-centjes-e2e-test] client # [ 8.420826] systemd[1]: Starting Networking Setup...
  1585. 131.90 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.935064] rtc_cmos 00:05: registered as rtc0
  1586. 131.90 s [vm-test-run-centjes-e2e-test] client # [ 8.795594] FDC 0 is a S82078B
  1587. 131.91 s [vm-test-run-centjes-e2e-test] client # [ 8.808240] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs
  1588. 131.91 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.950504] parport0: PC-style at 0x378, irq 7 [PCSPP(,...)]
  1589. 131.92 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.961994] rtc_cmos 00:05: setting system clock to 2026-08-04T20:41:49 UTC (1785876109)
  1590. 131.93 s [vm-test-run-centjes-e2e-test] client # [ 8.459760] dhcpcd[720]: dhcpcd-10.2.4 starting
  1591. 131.93 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.971551] FDC 0 is a S82078B
  1592. 131.94 s [vm-test-run-centjes-e2e-test] client # [ 8.472938] dhcpcd[733]: dev: loaded udev
  1593. 131.96 s [vm-test-run-centjes-e2e-test] client # [ 8.861186] 8021q: 802.1Q VLAN Support v1.8
  1594. 131.97 s [vm-test-run-centjes-e2e-test] client # [ 8.865540] 8021q: adding VLAN 0 to HW filter on device eth1
  1595. 131.97 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.006317] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs
  1596. 132.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.653740] systemd[1]: Finished Networking Setup.
  1597. 132.00 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.666546] systemd[1]: Reached target Network.
  1598. 132.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.676240] systemd[1]: Starting Permit User Sessions...
  1599. 132.03 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.067822] cfg80211: Loading compiled-in X.509 certificates for regulatory database
  1600. 132.06 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.099566] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
  1601. 132.07 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.103444] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'
  1602. 132.07 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.110818] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
  1603. 132.08 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.115974] cfg80211: failed to load regulatory.db
  1604. 132.08 s [vm-test-run-centjes-e2e-test] client # [ 8.981754] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0
  1605. 132.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.753109] systemd[1]: Finished Permit User Sessions.
  1606. 132.09 s [vm-test-run-centjes-e2e-test] client # [ 8.985619] cfg80211: Loading compiled-in X.509 certificates for regulatory database
  1607. 132.09 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.761245] systemd[1]: Started Getty on tty1.
  1608. 132.10 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.766685] systemd[1]: Reached target Login Prompts.
  1609. 132.12 s [vm-test-run-centjes-e2e-test] client # [ 9.015385] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
  1610. 132.12 s [vm-test-run-centjes-e2e-test] client # [ 9.018829] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'
  1611. 132.13 s [vm-test-run-centjes-e2e-test] client # [ 9.026870] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
  1612. 132.13 s [vm-test-run-centjes-e2e-test] client # [ 9.031891] cfg80211: failed to load regulatory.db
  1613. 132.15 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.185864] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0
  1614. 132.15 s [vm-test-run-centjes-e2e-test] client # [ 8.682377] systemd[1]: Finished Networking Setup.
  1615. 132.16 s [vm-test-run-centjes-e2e-test] client # [ 8.687482] systemd[1]: Reached target Network.
  1616. 132.16 s [vm-test-run-centjes-e2e-test] client # [ 8.694215] systemd[1]: Starting Permit User Sessions...
  1617. 132.17 s [vm-test-run-centjes-e2e-test] client # [ 9.071933] i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD
  1618. 132.18 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.214171] 8021q: adding VLAN 0 to HW filter on device eth0
  1619. 132.18 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.849222] dhcpcd[750]: eth0: waiting for carrier
  1620. 132.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.852913] dhcpcd[750]: libudev: received NULL device[ 9.227376] i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD
  1621. 132.19 s [vm-test-run-centjes-e2e-test] docsserver #
  1622. 132.19 s [vm-test-run-centjes-e2e-test] client # [ 9.088310] input: QEMU Virtio Keyboard as /devices/pci0000:00/0000:00:0a.0/virtio7/input/input4
  1623. 132.19 s [vm-test-run-centjes-e2e-test] docsserver # [ 8.859689] dhcpcd[750]: libudev: received NULL device
  1624. 132.20 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.234869] input: QEMU Virtio Keyboard as /devices/pci0000:00/0000:00:0a.0/virtio7/input/input4
  1625. 132.20 s [vm-test-run-centjes-e2e-test] client # [ 9.099134] bochs-drm 0000:00:02.0: vgaarb: deactivate vga console
  1626. 132.22 s [vm-test-run-centjes-e2e-test] client # [ 8.750560] systemd[1]: Finished Permit User Sessions.
  1627. 132.22 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.247481] bochs-drm 0000:00:02.0: vgaarb: deactivate vga console
  1628. 132.22 s [vm-test-run-centjes-e2e-test] client # [ 8.757252] systemd[1]: Started Getty on tty1.
  1629. 132.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.265016] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input6
  1630. 132.23 s [vm-test-run-centjes-e2e-test] client # [ 8.760621] systemd[1]: Reached target Login Prompts.
  1631. 132.23 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.268595] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input5
  1632. 132.24 s [vm-test-run-centjes-e2e-test] client # [ 9.134817] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input6
  1633. 132.25 s [vm-test-run-centjes-e2e-test] client # [ 9.139031] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input5
  1634. 132.26 s [vm-test-run-centjes-e2e-test] client # [ 9.159795] 8021q: adding VLAN 0 to HW filter on device eth0
  1635. 132.26 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.300552] cryptd: max_cpu_qlen set to 1000
  1636. 132.27 s [vm-test-run-centjes-e2e-test] client # [ 8.798206] dhcpcd[733]: eth0: waiting for carrier
  1637. 132.28 s [vm-test-run-centjes-e2e-test] client # [ 8.801565] dhcpcd[733]: libudev: received NULL device
  1638. 132.28 s [vm-test-run-centjes-e2e-test] client # [ 8.814325] dhcpcd[733]: libudev: received NULL device
  1639. 132.28 s [vm-test-run-centjes-e2e-test] client # [ 8.815858] dhcpcd[733]: eth0: carrier acquired
  1640. 132.30 s [vm-test-run-centjes-e2e-test] client # [ 8.826725] dhcpcd[733]: DUID 00:01:00:01:32:05:0b:0d:52:54:00:12:34:56
  1641. 132.30 s [vm-test-run-centjes-e2e-test] client # [ 8.830704] dhcpcd[733]: eth0: IAID 00:12:34:56
  1642. 132.30 s [vm-test-run-centjes-e2e-test] client # [ 8.834412] dhcpcd[733]: eth0: adding address fe80::5054:ff:fe12:3456
  1643. 132.32 s [vm-test-run-centjes-e2e-test] client # [ 9.208120] cryptd: max_cpu_qlen set to 1000
  1644. 132.32 s [vm-test-run-centjes-e2e-test] client # [ 9.214652] Console: switching to colour dummy device 80x25
  1645. 132.33 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.335967] AES CTR mode by8 optimization enabled
  1646. 132.33 s [vm-test-run-centjes-e2e-test] client # [ 9.229277] AES CTR mode by8 optimization enabled
  1647. 132.34 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.368078] Console: switching to colour dummy device 80x25
  1648. 132.34 s [vm-test-run-centjes-e2e-test] client # [ 9.239831] [drm] Found bochs VGA, ID 0xb0c5.
  1649. 132.34 s [vm-test-run-centjes-e2e-test] client # [ 9.240778] [drm] Framebuffer size 16384 kB @ 0xfd000000, mmio @ 0xfebd0000.
  1650. 132.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.389406] [drm] Found bochs VGA, ID 0xb0c5.
  1651. 132.35 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.390329] [drm] Framebuffer size 16384 kB @ 0xfd000000, mmio @ 0xfebd0000.
  1652. 132.37 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.033334] systemd[1]: Starting Virtual Console Setup...
  1653. 132.39 s [vm-test-run-centjes-e2e-test] client # [ 9.289323] [drm] Found EDID data blob.
  1654. 132.41 s [vm-test-run-centjes-e2e-test] client # [ 8.936600] systemd[1]: Starting Virtual Console Setup...
  1655. 132.41 s [vm-test-run-centjes-e2e-test] client # [ 9.308285] [drm] Initialized bochs-drm 1.0.0 for 0000:00:02.0 on minor 0
  1656. 132.42 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.459406] [drm] Found EDID data blob.
  1657. 132.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.101765] systemd-logind[644]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard)[ 9.475852] [drm] Initialized bochs-drm 1.0.0 for 0000:00:02.0 on minor 0
  1658. 132.44 s [vm-test-run-centjes-e2e-test] docsserver #
  1659. 132.45 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.109910] systemd-logind[644]: Watching system buttons on /dev/input/event2 (Power Button)
  1660. 132.98 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.126215] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
  1661. 132.99 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.656529] dhcpcd[750]: eth0: carrier acquired
  1662. 133.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.675397] dhcpcd[750]: DUID 00:01:00:01:32:05:0b:0e:52:54:00:12:34:56
  1663. 133.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.678182] dhcpcd[750]: eth0: IAID 00:12:34:56
  1664. 133.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.679684] dhcpcd[750]: eth0: adding address fe80::5054:ff:fe12:3456
  1665. 133.12 s [vm-test-run-centjes-e2e-test] client # [ 9.337628] fbcon: bochs-drmdrmfb (fb0) is primary device
  1666. 133.12 s [vm-test-run-centjes-e2e-test] client # [ 9.887795] Console: switching to colour frame buffer device 160x50
  1667. 133.13 s [vm-test-run-centjes-e2e-test] client # [ 10.024976] bochs-drm 0000:00:02.0: [drm] fb0: bochs-drmdrmfb frame buffer device
  1668. 133.13 s [vm-test-run-centjes-e2e-test] client # [ 9.655469] systemd-logind[640]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard)
  1669. 133.16 s [vm-test-run-centjes-e2e-test] docsserver # [ 9.493953] fbcon: bochs-drmdrmfb (fb0) is primary device
  1670. 133.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.064468] Console: switching to colour frame buffer device 160x50
  1671. 133.17 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.207064] bochs-drm 0000:00:02.0: [drm] fb0: bochs-drmdrmfb frame buffer device
  1672. 133.32 s [vm-test-run-centjes-e2e-test] client # [ 9.851256] systemd-logind[640]: Watching system buttons on /dev/input/event2 (Power Button)
  1673. 133.32 s [vm-test-run-centjes-e2e-test] client # [ 10.223826] ppdev: user-space parallel port driver
  1674. 133.37 s [vm-test-run-centjes-e2e-test] client # [ 9.898438] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
  1675. 133.39 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.426961] ppdev: user-space parallel port driver
  1676. 133.45 s [vm-test-run-centjes-e2e-test] client # [ 10.345701] kvm_amd: TSC scaling supported
  1677. 133.45 s [vm-test-run-centjes-e2e-test] client # [ 10.346632] kvm_amd: Nested Virtualization enabled
  1678. 133.45 s [vm-test-run-centjes-e2e-test] client # [ 10.347725] kvm_amd: Nested Paging enabled
  1679. 133.45 s [vm-test-run-centjes-e2e-test] client # [ 10.348657] kvm_amd: LBR virtualization supported
  1680. 133.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.513139] kvm_amd: TSC scaling supported
  1681. 133.47 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.514123] kvm_amd: Nested Virtualization enabled
  1682. 133.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.515395] kvm_amd: Nested Paging enabled
  1683. 133.48 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.516324] kvm_amd: LBR virtualization supported
  1684. 133.48 s [vm-test-run-centjes-e2e-test] client # [ 10.006640] systemd-logind[640]: Watching system buttons on /dev/input/event5 (QEMU Virtio Keyboard)
  1685. 133.49 s [vm-test-run-centjes-e2e-test] client # [ 10.020452] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
  1686. 133.50 s [vm-test-run-centjes-e2e-test] client # [ 10.029749] systemd[1]: Stopped Virtual Console Setup.
  1687. 133.50 s [vm-test-run-centjes-e2e-test] client # [ 10.036250] systemd[1]: Starting Virtual Console Setup...
  1688. 133.51 s [vm-test-run-centjes-e2e-test] client # [ 10.411548] kvm_amd: Virtual VMLOAD VMSAVE supported
  1689. 133.51 s [vm-test-run-centjes-e2e-test] client # [ 10.412625] kvm_amd: Virtual GIF supported
  1690. 133.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.183479] systemd-logind[644]: Watching system buttons on /dev/input/event5 (QEMU Virtio Keyboard)
  1691. 133.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.570131] kvm_amd: Virtual VMLOAD VMSAVE supported
  1692. 133.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.571511] kvm_amd: Virtual GIF supported
  1693. 133.57 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.229960] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
  1694. 133.57 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.237316] systemd[1]: Stopped Virtual Console Setup.
  1695. 133.74 s [vm-test-run-centjes-e2e-test] client # [ 10.102649] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
  1696. 133.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.241984] systemd[1]: Starting Virtual Console Setup...
  1697. 133.74 s [vm-test-run-centjes-e2e-test] client # [ 10.112503] systemd[1]: Stopped Virtual Console Setup.
  1698. 133.74 s [vm-test-run-centjes-e2e-test] client # [ 10.118418] systemd[1]: Starting Virtual Console Setup...
  1699. 133.74 s [vm-test-run-centjes-e2e-test] client # [ 10.500104] EDAC MC: Ver: 3.0.0
  1700. 133.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.272984] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
  1701. 133.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.278878] systemd[1]: Stopped Virtual Console Setup.
  1702. 133.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.283420] systemd[1]: Starting Virtual Console Setup...
  1703. 133.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.680940] EDAC MC: Ver: 3.0.0
  1704. 133.78 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.445979] dhcpcd[750]: eth0: soliciting a DHCP lease
  1705. 133.81 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.845230] NET: Registered PF_PACKET protocol family
  1706. 133.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.484707] dhcpcd[750]: eth0: offered 10.0.2.15 from 10.0.2.2
  1707. 133.82 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.489402] dhcpcd[750]: eth0: probing address 10.0.2.15/24
  1708. 134.01 s [vm-test-run-centjes-e2e-test] docsserver # [ 10.676171] systemd[1]: Finished Virtual Console Setup.
  1709. 134.01 s [vm-test-run-centjes-e2e-test] client # [ 10.542418] systemd[1]: Finished Virtual Console Setup.
  1710. 134.06 s [vm-test-run-centjes-e2e-test] client # [ 10.593313] dhcpcd[733]: eth0: soliciting a DHCP lease
  1711. 134.08 s [vm-test-run-centjes-e2e-test] client # [ 10.981299] NET: Registered PF_PACKET protocol family
  1712. 134.09 s [vm-test-run-centjes-e2e-test] client # [ 10.624936] dhcpcd[733]: eth0: offered 10.0.2.15 from 10.0.2.2
  1713. 134.10 s [vm-test-run-centjes-e2e-test] client # [ 10.628365] dhcpcd[733]: eth0: probing address 10.0.2.15/24
  1714. 134.12 s [vm-test-run-centjes-e2e-test] client # [ 10.652887] dhcpcd[733]: eth0: soliciting an IPv6 router
  1715. 134.12 s [vm-test-run-centjes-e2e-test] client # [ 10.654956] dhcpcd[733]: eth0: Router Advertisement from fe80::2
  1716. 134.12 s [vm-test-run-centjes-e2e-test] client # [ 10.656813] dhcpcd[733]: eth0: adding address fec0::5054:ff:fe12:3456/64
  1717. 134.13 s [vm-test-run-centjes-e2e-test] client # [ 10.658788] dhcpcd[733]: eth0: adding route to fec0::/64
  1718. 134.13 s [vm-test-run-centjes-e2e-test] client # [ 10.660451] dhcpcd[733]: eth0: adding default route via fe80::2
  1719. 134.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.400513] dhcpcd[750]: eth0: soliciting an IPv6 router
  1720. 134.73 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.402597] dhcpcd[750]: eth0: Router Advertisement from fe80::2
  1721. 134.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.404711] dhcpcd[750]: eth0: adding address fec0::5054:ff:fe12:3456/64
  1722. 134.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.406735] dhcpcd[750]: eth0: adding route to fec0::/64
  1723. 134.74 s [vm-test-run-centjes-e2e-test] docsserver # [ 11.408463] dhcpcd[750]: eth0: adding default route via fe80::2
  1724. 139.41 s [vm-test-run-centjes-e2e-test] docsserver # [ 16.080220] dhcpcd[750]: eth0: leased 10.0.2.15 for 86400 seconds
  1725. 139.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 16.082479] dhcpcd[750]: eth0: adding route to 10.0.2.0/24
  1726. 139.44 s [vm-test-run-centjes-e2e-test] docsserver # [ 16.084495] dhcpcd[750]: eth0: adding default route via 10.0.2.2
  1727. 139.52 s [vm-test-run-centjes-e2e-test] docsserver # [ 16.191240] systemd[1]: Started DHCP Client.
  1728. 139.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 16.194546] systemd[1]: Reached target Multi-User System.
  1729. 139.53 s [vm-test-run-centjes-e2e-test] docsserver # [ 16.196941] systemd[1]: Startup finished in 3.834s (kernel) + 12.359s (userspace) = 16.193s.
  1730. 139.73 s [vm-test-run-centjes-e2e-test] client # [ 16.267177] dhcpcd[733]: eth0: leased 10.0.2.15 for 86400 seconds
  1731. 139.74 s [vm-test-run-centjes-e2e-test] client # [ 16.269456] dhcpcd[733]: eth0: adding route to 10.0.2.0/24
  1732. 139.74 s [vm-test-run-centjes-e2e-test] client # [ 16.271490] dhcpcd[733]: eth0: adding default route via 10.0.2.2
  1733. 139.81 s [vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for unit default.target, in 17.52 seconds)
  1734. 139.81 s [vm-test-run-centjes-e2e-test] client: waiting for unit default.target
  1735. 139.81 s [vm-test-run-centjes-e2e-test] client: waiting for the VM to finish booting
  1736. 139.81 s [vm-test-run-centjes-e2e-test] client: Guest shell says: b'Spawning backdoor root shell...\n'
  1737. 139.81 s [vm-test-run-centjes-e2e-test] client: connected to guest root shell
  1738. 139.81 s [vm-test-run-centjes-e2e-test] client: (connecting took 0.00 seconds)
  1739. 139.81 s [vm-test-run-centjes-e2e-test] client: (finished: waiting for the VM to finish booting, in 0.00 seconds)
  1740. 139.87 s [vm-test-run-centjes-e2e-test] client # [ 16.406158] systemd[1]: Started DHCP Client.
  1741. 139.88 s [vm-test-run-centjes-e2e-test] client # [ 16.407771] systemd[1]: Reached target Multi-User System.
  1742. 139.88 s [vm-test-run-centjes-e2e-test] client # [ 16.411911] systemd[1]: Startup finished in 4.101s (kernel) + 12.303s (userspace) = 16.405s.
  1743. 139.95 s [vm-test-run-centjes-e2e-test] client: (finished: waiting for unit default.target, in 0.13 seconds)
  1744. 140.02 s [vm-test-run-centjes-e2e-test] docsserver: waiting for unit centjes-docs-site-production.service
  1745. 140.07 s [vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for unit centjes-docs-site-production.service, in 0.05 seconds)
  1746. 140.07 s [vm-test-run-centjes-e2e-test] docsserver: waiting for unit default.target
  1747. 140.12 s [vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for unit default.target, in 0.05 seconds)
  1748. 140.12 s [vm-test-run-centjes-e2e-test] docsserver: waiting for TCP port 8001 on localhost
  1749. 140.21 s [vm-test-run-centjes-e2e-test] docsserver # Connection to localhost (127.0.0.1) 8001 port [tcp/vcom-tunnel] succeeded!
  1750. 140.21 s [vm-test-run-centjes-e2e-test] docsserver: (finished: waiting for TCP port 8001 on localhost, in 0.09 seconds)
  1751. 140.21 s [vm-test-run-centjes-e2e-test] client: must succeed: curl docsserver:8001
  1752. 140.29 s [vm-test-run-centjes-e2e-test] client # % Total % Received % Xferd Average Speed Time Time Time Current
  1753. 140.30 s [vm-test-run-centjes-e2e-test] client # Dload Upload Total Spent Left Speed
  1754. 140.32 s [vm-test-run-centjes-e2e-test] docsserver # [ 16.991448] centjes-docs-site-production-start[633]: 192.168.1.1 - - [04/Aug/2026:20:41:57 +0000] "GET / HTTP/1.1" 200 3595 "" "curl/8.17.0"
  1755. 140.34 s [vm-test-run-centjes-e2e-test] client # 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0100 3595 100 3595 0 0 59622 0 --:--:-- --:--:-- --:--:-- 60932
  1756. 140.35 s [vm-test-run-centjes-e2e-test] client: (finished: must succeed: curl docsserver:8001, in 0.14 seconds)
  1757. 140.35 s [vm-test-run-centjes-e2e-test] (finished: run the VM test script, in 18.48 seconds)
  1758. 140.46 s [vm-test-run-centjes-e2e-test] test script finished in 18.59s
  1759. 140.46 s [vm-test-run-centjes-e2e-test] cleanup
  1760. 140.46 s [vm-test-run-centjes-e2e-test] kill machine (pid 31)
  1761. 140.46 s [vm-test-run-centjes-e2e-test] qemu-system-x86_64: terminating on signal 15 from pid 6 (/nix/store/jj6jldlw37r8yy9kc1smrax9dhnjm2x4-python3-3.13.9/bin/python3.13)
  1762. 140.46 s [vm-test-run-centjes-e2e-test] kill machine (pid 9)
  1763. 140.46 s [vm-test-run-centjes-e2e-test] qemu-system-x86_64: terminating on signal 15 from pid 6 (/nix/store/jj6jldlw37r8yy9kc1smrax9dhnjm2x4-python3-3.13.9/bin/python3.13)
  1764. 140.47 s [vm-test-run-centjes-e2e-test] kill vlan (pid 7)
  1765. 140.47 s [vm-test-run-centjes-e2e-test] (finished: cleanup, in 0.02 seconds)
  1766. 140.56 s [vm-test-run-centjes-e2e-test:post-build] Uploading to cachix cache "centjes": /nix/store/c0bj8pmwm676biix4cdd80lkb98crl0p-vm-test-run-centjes-e2e-test
  1767. 140.91 s [vm-test-run-centjes-e2e-test:post-build] Pushing 1 paths (0 are already present) using zstd to cache centjes ⏳
  1768. 140.91 s [vm-test-run-centjes-e2e-test:post-build]
  1769. 141.27 s [vm-test-run-centjes-e2e-test:post-build] Pushing /nix/store/c0bj8pmwm676biix4cdd80lkb98crl0p-vm-test-run-centjes-e2e-test (96.00 B)
  1770. 142.16 s [vm-test-run-centjes-e2e-test:post-build]
  1771. 142.16 s [vm-test-run-centjes-e2e-test:post-build] All done.
  1772. 142.18 s [vm-test-run-centjes-e2e-test:post-build] Uploading to the NixCI staging cache: /nix/store/c0bj8pmwm676biix4cdd80lkb98crl0p-vm-test-run-centjes-e2e-test
  1773. 142.22 s [vm-test-run-centjes-e2e-test:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  1774. 142.23 s [vm-test-run-centjes-e2e-test:post-build] copying 1 paths...
  1775. 142.23 s [vm-test-run-centjes-e2e-test:post-build] copying path '/nix/store/c0bj8pmwm676biix4cdd80lkb98crl0p-vm-test-run-centjes-e2e-test' to 'https://cache.staging.nix-ci.com'...
  1776. 142.42 s [vm-test-run-centjes-e2e-test:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  1777. 142.70 s [vm-test-run-centjes-e2e-test:post-build] copying 1 paths...
  1778. 142.70 s [vm-test-run-centjes-e2e-test:post-build] copying path '/nix/store/7i80czand4927npm2s8v8j9w554vlmcz-vm-test-run-centjes-e2e-test.drv' to 'https://cache.staging.nix-ci.com'...
  1779. 142.89 s Uploaded vm-test-run-centjes-e2e-test in 2.3s
  1780. 142.89 s Progress: 12 of 13 built
  1781. 142.89 s Built vm-test-run-centjes-e2e-test in 21.3s
  1782. 142.89 s Progress: 13 of 13 built
  1783. 142.89 s /nix/store/c0bj8pmwm676biix4cdd80lkb98crl0p-vm-test-run-centjes-e2e-test
  1784. 143.03 s Build succeeded.