build checks.x86_64-linux.nixos-test-read-proxy

Reproduce this run
  1. 0.12 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/niks3?ref=fix%2Fregister-completed-object&rev=1745e6d569d601fcc3650ef4d243e46c97487012#checks.x86_64-linux.nixos-test-read-proxy --print-build-logs
  2. 3.49 s
  3. 5.11 s Building /nix/store/k28k94dpvrzslxzm3kmac6fp5gb1gphg-test-script.drv
  4. 5.13 s Downloading cached initrd-linux from https://cache.staging.nix-ci.com
  5. 5.17 s Downloading cached users-groups.json from https://cache.staging.nix-ci.com
  6. 5.23 s Downloaded cached users-groups.json (18 KiB) in 58ms
  7. 5.27 s Building /nix/store/4cx9xf6kn7szdwdcn1cx21xf2mwd9lba-system-path.drv
  8. 5.31 s Building /nix/store/m55rs8653p7kx0d1pb4jyz71skmk0x43-nix.conf.drv
  9. 5.35 s Building /nix/store/iz5lcc3mlyqgh4v6pmgkyzhqdlls9n6j-extra-hosts.drv
  10. 5.39 s Building /nix/store/d5aimrv7rbclfg86xmwyrj1vgacpj77w-unit-niks3.service.drv
  11. 5.42 s Building /nix/store/rjk83k72svaiz4v0ipkcgfzy1chvybqq-unit-rustfs.service.drv
  12. 5.47 s Building /nix/store/g2mxgn4f2x2fq90adwk0555bza7l2myw-unit-script-rustfs-setup-start.drv
  13. 5.48 s Progress: 0 of 29 built (7 building), 1 of 3 downloaded from cache (1 downloading)
  14. 5.51 s Downloaded cached initrd-linux (28.8 MiB) in 382ms
  15. 5.51 s [extra-hosts:post-build] Uploading to the NixCI staging cache: /nix/store/2fzxacmhavk2apmsj70hqhxszbk66xmy-extra-hosts
  16. 5.57 s [extra-hosts:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  17. 5.63 s [extra-hosts:post-build] copying 0 paths...
  18. 5.69 s [extra-hosts:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  19. 5.76 s [extra-hosts:post-build] copying 0 paths...
  20. 5.78 s Uploaded extra-hosts in 276ms
  21. 5.78 s Progress: 1 of 30 built (6 building), 1 of 3 downloaded from cache (1 downloading)
  22. 5.78 s Built extra-hosts in 427ms
  23. 5.78 s [nix.conf] Validating generated nix.conf
  24. 5.78 s [system-path] structuredAttrs is enabled
  25. 5.82 s [test-script:post-build] Uploading to the NixCI staging cache: /nix/store/6fir08sdk7dzgivivxmbz0rccrr5cckc-test-script
  26. 5.87 s [test-script:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  27. 5.92 s [test-script:post-build] copying 0 paths...
  28. 5.99 s [test-script:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  29. 6.07 s [test-script:post-build] copying 0 paths...
  30. 6.09 s Uploaded test-script in 290ms
  31. 6.09 s Progress: 2 of 31 built (5 building), 1 of 3 downloaded from cache (1 downloading)
  32. 6.09 s Built test-script in 979ms
  33. 6.09 s [unit-niks3.service] structuredAttrs is enabled
  34. 6.09 s [unit-rustfs.service] structuredAttrs is enabled
  35. 6.09 s Downloading cached dry-activate from https://cache.staging.nix-ci.com
  36. 6.11 s Downloaded cached dry-activate (2384 B) in 16ms
  37. 6.14 s Building /nix/store/8wyr173zfz2hiisqz5hr41a8q0cn8gkk-hosts.drv
  38. 6.14 s Progress: 2 of 29 built (6 building), 2 of 3 downloaded from cache (1 downloading)
  39. 6.14 s Progress: 2 of 29 built (6 building), 3 of 3 downloaded from cache
  40. 6.16 s [nix.conf:post-build] Uploading to the NixCI staging cache: /nix/store/pjxvi2rhifk2snk873kg8lpvy164rm3m-nix.conf
  41. 6.21 s [nix.conf:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  42. 6.26 s [nix.conf:post-build] copying 0 paths...
  43. 6.33 s [nix.conf:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  44. 6.46 s [nix.conf:post-build] copying 0 paths...
  45. 6.48 s Uploaded nix.conf in 336ms
  46. 6.48 s Progress: 3 of 30 built (5 building), 3 of 3 downloaded from cache
  47. 6.48 s Built nix.conf in 1.1s
  48. 6.48 s [system-path] created 7298 symlinks in user environment
  49. 6.48 s [system-path] install-info: warning: no info dir entry in `/nix/store/bxhdy57r6hl031izqz6q75p6cqynykp8-system-path/share/info/notes.info'
  50. 6.53 s [unit-niks3.service:post-build] Uploading to the NixCI staging cache: /nix/store/9hdvf454vni3gzfix3px7dw8paysbgv8-unit-niks3.service
  51. 6.58 s [unit-niks3.service:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  52. 6.75 s [unit-niks3.service:post-build] copying 1 paths...
  53. 6.76 s [unit-niks3.service:post-build] copying path '/nix/store/9hdvf454vni3gzfix3px7dw8paysbgv8-unit-niks3.service' to 'https://cache.staging.nix-ci.com'...
  54. 6.96 s [unit-niks3.service:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  55. 7.20 s [unit-niks3.service:post-build] copying 1 paths...
  56. 7.20 s [unit-niks3.service:post-build] copying path '/nix/store/d5aimrv7rbclfg86xmwyrj1vgacpj77w-unit-niks3.service.drv' to 'https://cache.staging.nix-ci.com'...
  57. 7.38 s Uploaded unit-niks3.service in 857ms
  58. 7.38 s Progress: 4 of 31 built (4 building), 3 of 3 downloaded from cache
  59. 7.38 s Built unit-niks3.service in 1.9s
  60. 7.41 s [unit-rustfs.service:post-build] Uploading to the NixCI staging cache: /nix/store/caargjpqaqagfzn8zkg6bpc56312379a-unit-rustfs.service
  61. 7.46 s [unit-rustfs.service:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  62. 7.51 s [unit-rustfs.service:post-build] copying 0 paths...
  63. 7.57 s [unit-rustfs.service:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  64. 7.70 s [unit-rustfs.service:post-build] copying 0 paths...
  65. 7.72 s Uploaded unit-rustfs.service in 324ms
  66. 7.72 s Progress: 5 of 32 built (3 building), 3 of 3 downloaded from cache
  67. 7.72 s Built unit-rustfs.service in 2.3s
  68. 7.75 s [unit-script-rustfs-setup-start:post-build] Uploading to the NixCI staging cache: /nix/store/x3gka4bnb5nmljc3x9lqma6mymkhkm6l-unit-script-rustfs-setup-start
  69. 7.80 s [unit-script-rustfs-setup-start:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  70. 7.85 s [unit-script-rustfs-setup-start:post-build] copying 0 paths...
  71. 7.92 s [unit-script-rustfs-setup-start:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  72. 8.00 s [unit-script-rustfs-setup-start:post-build] copying 0 paths...
  73. 8.02 s Uploaded unit-script-rustfs-setup-start in 284ms
  74. 8.02 s Progress: 6 of 33 built (2 building), 3 of 3 downloaded from cache
  75. 8.02 s Built unit-script-rustfs-setup-start in 2.5s
  76. 8.05 s Building /nix/store/pd470krx770kv41ic0lzfrm5dzrszmk1-X-Restart-Triggers-nix-daemon.drv
  77. 8.07 s Building /nix/store/bk0snva2lls4qsnwgz99hvl85fsqlkms-boot.json.drv
  78. 8.09 s Building /nix/store/w4i9vw9k28nwy53qfz5cw6vh0vgq8adw-unit-rustfs-setup.service.drv
  79. 8.10 s [hosts:post-build] Uploading to the NixCI staging cache: /nix/store/55gvdf50drzl7wkhqq86lvj4jgpisd2v-hosts
  80. 8.16 s [hosts:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  81. 8.22 s [hosts:post-build] copying 0 paths...
  82. 8.29 s [hosts:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  83. 8.36 s [hosts:post-build] copying 0 paths...
  84. 8.37 s Uploaded hosts in 280ms
  85. 8.37 s Progress: 7 of 28 built (4 building), 3 of 3 downloaded from cache
  86. 8.38 s Built hosts in 2.2s
  87. 8.87 s [system-path:post-build] Uploading to the NixCI staging cache: /nix/store/bxhdy57r6hl031izqz6q75p6cqynykp8-system-path
  88. 8.92 s [system-path:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  89. 8.98 s [system-path:post-build] copying 0 paths...
  90. 9.05 s [system-path:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  91. 9.20 s [system-path:post-build] copying 0 paths...
  92. 9.22 s Uploaded system-path in 364ms
  93. 9.22 s Progress: 8 of 29 built (3 building), 3 of 3 downloaded from cache
  94. 9.22 s Built system-path in 3.9s
  95. 9.27 s Building /nix/store/ga9qnllcnw8md9g9k3iy4nar08j39pa1-dbus-1.drv
  96. 9.29 s [X-Restart-Triggers-nix-daemon:post-build] Uploading to the NixCI staging cache: /nix/store/v6sq0fcrsz5dp5pabl93l1gcrwwpqf87-X-Restart-Triggers-nix-daemon
  97. 9.35 s [X-Restart-Triggers-nix-daemon:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  98. 9.39 s [X-Restart-Triggers-nix-daemon:post-build] copying 0 paths...
  99. 9.46 s [X-Restart-Triggers-nix-daemon:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  100. 9.59 s [X-Restart-Triggers-nix-daemon:post-build] copying 0 paths...
  101. 9.61 s Uploaded X-Restart-Triggers-nix-daemon in 333ms
  102. 9.61 s Progress: 9 of 28 built (3 building), 3 of 3 downloaded from cache
  103. 9.61 s Built X-Restart-Triggers-nix-daemon in 1.5s
  104. 9.64 s [boot.json:post-build] Uploading to the NixCI staging cache: /nix/store/y4npcacc6nanl2b81rl70126xr3n70j4-boot.json
  105. 9.70 s [boot.json:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  106. 9.77 s [boot.json:post-build] copying 0 paths...
  107. 9.85 s [boot.json:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  108. 9.97 s [boot.json:post-build] copying 0 paths...
  109. 10.00 s Uploaded boot.json in 366ms
  110. 10.00 s Progress: 10 of 29 built (2 building), 3 of 3 downloaded from cache
  111. 10.00 s Built boot.json in 1.9s
  112. 10.00 s [unit-rustfs-setup.service] structuredAttrs is enabled
  113. 10.03 s Building /nix/store/whjycs6g2sv5c17nfkslsk7482kksqcm-unit-nix-daemon.service.drv
  114. 10.06 s [dbus:post-build] Uploading to the NixCI staging cache: /nix/store/89zgkxqrh528kiigyfy9frjbybnjkfch-dbus-1
  115. 10.12 s [dbus:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  116. 10.18 s [dbus:post-build] copying 0 paths...
  117. 10.25 s [dbus:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  118. 10.40 s [dbus:post-build] copying 0 paths...
  119. 10.43 s Uploaded dbus in 378ms
  120. 10.43 s Progress: 11 of 28 built (2 building), 3 of 3 downloaded from cache
  121. 10.43 s Built dbus in 1.1s
  122. 10.46 s [unit-rustfs-setup.service:post-build] Uploading to the NixCI staging cache: /nix/store/jcanwq3b60q205dijjbrvrsr9nw9ilrq-unit-rustfs-setup.service
  123. 10.53 s [unit-rustfs-setup.service:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  124. 10.58 s [unit-rustfs-setup.service:post-build] copying 0 paths...
  125. 10.65 s [unit-rustfs-setup.service:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  126. 10.78 s [unit-rustfs-setup.service:post-build] copying 0 paths...
  127. 10.80 s Uploaded unit-rustfs-setup.service in 350ms
  128. 10.80 s Progress: 12 of 29 built (1 building), 3 of 3 downloaded from cache
  129. 10.80 s Built unit-rustfs-setup.service in 2.7s
  130. 10.85 s Building /nix/store/r3vr2f0vy0f45zmpdkhzijx3rh80mk49-X-Restart-Triggers-dbus-broker.drv
  131. 10.85 s [unit-nix-daemon.service] structuredAttrs is enabled
  132. 10.87 s [unit-nix-daemon.service:post-build] Uploading to the NixCI staging cache: /nix/store/46b9v84z6zz971qndxjc9xbgv4gl3c1q-unit-nix-daemon.service
  133. 10.93 s [unit-nix-daemon.service:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  134. 10.98 s [unit-nix-daemon.service:post-build] copying 0 paths...
  135. 11.05 s [unit-nix-daemon.service:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  136. 11.21 s [unit-nix-daemon.service:post-build] copying 0 paths...
  137. 11.23 s Uploaded unit-nix-daemon.service in 376ms
  138. 11.23 s Progress: 13 of 28 built (1 building), 3 of 3 downloaded from cache
  139. 11.23 s Built unit-nix-daemon.service in 1.2s
  140. 11.27 s [X-Restart-Triggers-dbus-broker:post-build] Uploading to the NixCI staging cache: /nix/store/a5jwvssz64rax73k3g5lcvma0xhm7jql-X-Restart-Triggers-dbus-broker
  141. 11.33 s [X-Restart-Triggers-dbus-broker:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  142. 11.40 s [X-Restart-Triggers-dbus-broker:post-build] copying 0 paths...
  143. 11.48 s [X-Restart-Triggers-dbus-broker:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  144. 11.65 s [X-Restart-Triggers-dbus-broker:post-build] copying 0 paths...
  145. 11.68 s Uploaded X-Restart-Triggers-dbus-broker in 424ms
  146. 11.68 s Progress: 14 of 28 built, 3 of 3 downloaded from cache
  147. 11.68 s Built X-Restart-Triggers-dbus-broker in 838ms
  148. 11.74 s Building /nix/store/n9dxavfiw1mby6xjw5rgfpcnp05fv7zh-unit-dbus-broker.service.drv
  149. 11.79 s Building /nix/store/z9gra0x83f250znw0h7w4w5gislr15x6-unit-dbus-broker.service.drv
  150. 11.79 s [unit-dbus-broker.service] structuredAttrs is enabled
  151. 11.82 s [unit-dbus-broker.service:post-build] Uploading to the NixCI staging cache: /nix/store/zjaw6h2afl2dr3i5ydr751q06gcick2g-unit-dbus-broker.service
  152. 11.88 s [unit-dbus-broker.service:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  153. 11.94 s [unit-dbus-broker.service:post-build] copying 0 paths...
  154. 12.02 s [unit-dbus-broker.service:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  155. 12.19 s [unit-dbus-broker.service:post-build] copying 0 paths...
  156. 12.22 s Uploaded unit-dbus-broker.service in 414ms
  157. 12.22 s Progress: 15 of 28 built (1 building), 3 of 3 downloaded from cache
  158. 12.22 s Built unit-dbus-broker.service in 473ms
  159. 12.26 s Building /nix/store/9sbx4pkfpl66906ypi8lvj3x9r676zxb-user-units.drv
  160. 12.26 s [unit-dbus-broker.service] structuredAttrs is enabled
  161. 12.29 s [unit-dbus-broker.service:post-build] Uploading to the NixCI staging cache: /nix/store/0chhdamsh7aky6wqgzij8qpai8fyv8v7-unit-dbus-broker.service
  162. 12.35 s [unit-dbus-broker.service:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  163. 12.41 s [unit-dbus-broker.service:post-build] copying 0 paths...
  164. 12.50 s [unit-dbus-broker.service:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  165. 12.69 s [unit-dbus-broker.service:post-build] copying 0 paths...
  166. 12.74 s Uploaded unit-dbus-broker.service in 460ms
  167. 12.74 s Progress: 16 of 28 built (1 building), 3 of 3 downloaded from cache
  168. 12.74 s Built unit-dbus-broker.service in 950ms
  169. 12.80 s Building /nix/store/n9n1cfchjjhf5m34s56cpyk623qjnnhr-system-units.drv
  170. 12.83 s [user-units:post-build] Uploading to the NixCI staging cache: /nix/store/773mdkfmwvvdx83hi3a7w06fssrwzfcm-user-units
  171. 12.89 s [user-units:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  172. 12.95 s [user-units:post-build] copying 0 paths...
  173. 13.04 s [user-units:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  174. 13.18 s [user-units:post-build] copying 0 paths...
  175. 13.21 s Uploaded user-units in 393ms
  176. 13.21 s Progress: 17 of 28 built (1 building), 3 of 3 downloaded from cache
  177. 13.21 s Built user-units in 946ms
  178. 13.68 s [system-units:post-build] Uploading to the NixCI staging cache: /nix/store/rgknmnk2jd6790mj9pchrhx9yv5n8mpl-system-units
  179. 13.74 s [system-units:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  180. 13.95 s [system-units:post-build] copying 1 paths...
  181. 13.95 s [system-units:post-build] copying path '/nix/store/rgknmnk2jd6790mj9pchrhx9yv5n8mpl-system-units' to 'https://cache.staging.nix-ci.com'...
  182. 14.23 s [system-units:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  183. 14.52 s [system-units:post-build] copying 1 paths...
  184. 14.53 s [system-units:post-build] copying path '/nix/store/n9n1cfchjjhf5m34s56cpyk623qjnnhr-system-units.drv' to 'https://cache.staging.nix-ci.com'...
  185. 14.73 s Uploaded system-units in 1.0s
  186. 14.73 s Progress: 18 of 28 built, 3 of 3 downloaded from cache
  187. 14.73 s Built system-units in 1.9s
  188. 14.80 s Building /nix/store/30i35a25jf9qana6wsk1wdbkwmvca8i0-etc.drv
  189. 15.23 s [etc:post-build] Uploading to the NixCI staging cache: /nix/store/1lqz9i05jf3n2kjr07ljfb38z6xdfb15-etc
  190. 15.30 s [etc:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  191. 15.47 s [etc:post-build] copying 1 paths...
  192. 15.47 s [etc:post-build] copying path '/nix/store/1lqz9i05jf3n2kjr07ljfb38z6xdfb15-etc' to 'https://cache.staging.nix-ci.com'...
  193. 15.73 s [etc:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  194. 15.98 s [etc:post-build] copying 1 paths...
  195. 15.98 s [etc:post-build] copying path '/nix/store/30i35a25jf9qana6wsk1wdbkwmvca8i0-etc.drv' to 'https://cache.staging.nix-ci.com'...
  196. 16.19 s Uploaded etc in 979ms
  197. 16.19 s Progress: 19 of 28 built, 3 of 3 downloaded from cache
  198. 16.19 s Built etc in 1.3s
  199. 16.26 s Building /nix/store/4p8krcbahb76ndzvfi7yhmbb1fr4j3n7-activate.drv
  200. 16.33 s [activate:post-build] Uploading to the NixCI staging cache: /nix/store/z6kfx34j2rz2nypi8s5i0mmff6rm1h1b-activate
  201. 16.40 s [activate:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  202. 16.43 s [activate:post-build] copying 1 paths...
  203. 16.43 s [activate:post-build] copying path '/nix/store/z6kfx34j2rz2nypi8s5i0mmff6rm1h1b-activate' to 'https://cache.staging.nix-ci.com'...
  204. 16.71 s [activate:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  205. 16.97 s [activate:post-build] copying 1 paths...
  206. 16.97 s [activate:post-build] copying path '/nix/store/4p8krcbahb76ndzvfi7yhmbb1fr4j3n7-activate.drv' to 'https://cache.staging.nix-ci.com'...
  207. 17.15 s Uploaded activate in 839ms
  208. 17.16 s Progress: 20 of 28 built, 3 of 3 downloaded from cache
  209. 17.16 s Built activate in 899ms
  210. 17.23 s Building /nix/store/q25wqf6zyv3nd9zymj3fx21h319zp5mj-nixos-system-server-test.drv
  211. 17.23 s [nixos-system-server-test] structuredAttrs is enabled
  212. 17.31 s [nixos-system-server-test:post-build] Uploading to the NixCI staging cache: /nix/store/awn88pbhvb6ywvfwjvpjjmkvi94hd9hx-nixos-system-server-test
  213. 17.37 s [nixos-system-server-test:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  214. 17.57 s [nixos-system-server-test:post-build] copying 1 paths...
  215. 17.57 s [nixos-system-server-test:post-build] copying path '/nix/store/awn88pbhvb6ywvfwjvpjjmkvi94hd9hx-nixos-system-server-test' to 'https://cache.staging.nix-ci.com'...
  216. 17.90 s [nixos-system-server-test:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  217. 18.20 s [nixos-system-server-test:post-build] copying 1 paths...
  218. 18.20 s [nixos-system-server-test:post-build] copying path '/nix/store/q25wqf6zyv3nd9zymj3fx21h319zp5mj-nixos-system-server-test.drv' to 'https://cache.staging.nix-ci.com'...
  219. 18.39 s Uploaded nixos-system-server-test in 1.0s
  220. 18.39 s Progress: 21 of 28 built, 3 of 3 downloaded from cache
  221. 18.39 s Built nixos-system-server-test in 1.1s
  222. 18.99 s Building /nix/store/8x0dqmh9qvmlqpjw4hnmyxw5phv3h6m9-closure-info.drv
  223. 19.00 s [closure-info] structuredAttrs is enabled
  224. 19.16 s [closure-info:post-build] Uploading to the NixCI staging cache: /nix/store/qizsg8cj1scm7wdi1wwf22vik5b1nfas-closure-info
  225. 19.23 s [closure-info:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  226. 19.27 s [closure-info:post-build] copying 1 paths...
  227. 19.27 s [closure-info:post-build] copying path '/nix/store/qizsg8cj1scm7wdi1wwf22vik5b1nfas-closure-info' to 'https://cache.staging.nix-ci.com'...
  228. 19.60 s [closure-info:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  229. 19.90 s [closure-info:post-build] copying 1 paths...
  230. 19.90 s [closure-info:post-build] copying path '/nix/store/8x0dqmh9qvmlqpjw4hnmyxw5phv3h6m9-closure-info.drv' to 'https://cache.staging.nix-ci.com'...
  231. 20.08 s Uploaded closure-info in 935ms
  232. 20.08 s Progress: 22 of 28 built, 3 of 3 downloaded from cache
  233. 20.08 s Built closure-info in 1.0s
  234. 20.17 s Building /nix/store/2gr1cq7z6akqx3wf1a5qjfdw01fns93y-run-nixos-vm.drv
  235. 20.25 s [run-nixos-vm:post-build] Uploading to the NixCI staging cache: /nix/store/72yc3j8ffpr0kkd251wyafklyx3qrl59-run-nixos-vm
  236. 20.31 s [run-nixos-vm:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  237. 20.52 s [run-nixos-vm:post-build] copying 1 paths...
  238. 20.52 s [run-nixos-vm:post-build] copying path '/nix/store/72yc3j8ffpr0kkd251wyafklyx3qrl59-run-nixos-vm' to 'https://cache.staging.nix-ci.com'...
  239. 22.36 s [run-nixos-vm:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  240. 22.64 s [run-nixos-vm:post-build] copying 1 paths...
  241. 22.64 s [run-nixos-vm:post-build] copying path '/nix/store/2gr1cq7z6akqx3wf1a5qjfdw01fns93y-run-nixos-vm.drv' to 'https://cache.staging.nix-ci.com'...
  242. 22.87 s Uploaded run-nixos-vm in 2.6s
  243. 22.87 s Progress: 23 of 28 built, 3 of 3 downloaded from cache
  244. 22.87 s Built run-nixos-vm in 2.7s
  245. 23.21 s Building /nix/store/7fy39kqn83dvqp7wxfwyl5cil6v1xdc4-nixos-vm.drv
  246. 23.59 s [nixos-vm:post-build] Uploading to the NixCI staging cache: /nix/store/6np4pcfp33gk5azq1hgbjr2ajbylknav-nixos-vm
  247. 23.66 s [nixos-vm:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  248. 23.83 s [nixos-vm:post-build] copying 1 paths...
  249. 23.83 s [nixos-vm:post-build] copying path '/nix/store/6np4pcfp33gk5azq1hgbjr2ajbylknav-nixos-vm' to 'https://cache.staging.nix-ci.com'...
  250. 24.29 s [nixos-vm:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  251. 24.58 s [nixos-vm:post-build] copying 1 paths...
  252. 24.58 s [nixos-vm:post-build] copying path '/nix/store/7fy39kqn83dvqp7wxfwyl5cil6v1xdc4-nixos-vm.drv' to 'https://cache.staging.nix-ci.com'...
  253. 24.78 s Uploaded nixos-vm in 1.2s
  254. 24.78 s Progress: 24 of 28 built, 3 of 3 downloaded from cache
  255. 24.78 s Built nixos-vm in 1.5s
  256. 24.86 s Building /nix/store/ab8hbnqb3in6sy5wbb6cb6b209r6d74s-driverConfiguration.json.drv
  257. 24.86 s [driverConfiguration.json] structuredAttrs is enabled
  258. 24.93 s [driverConfiguration.json:post-build] Uploading to the NixCI staging cache: /nix/store/fir5qr9dli5jdlxfv2ryfbq7yq2fjsh7-driverConfiguration.json
  259. 24.99 s [driverConfiguration.json:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  260. 25.02 s [driverConfiguration.json:post-build] copying 1 paths...
  261. 25.02 s [driverConfiguration.json:post-build] copying path '/nix/store/fir5qr9dli5jdlxfv2ryfbq7yq2fjsh7-driverConfiguration.json' to 'https://cache.staging.nix-ci.com'...
  262. 25.35 s [driverConfiguration.json:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  263. 25.62 s [driverConfiguration.json:post-build] copying 1 paths...
  264. 25.63 s [driverConfiguration.json:post-build] copying path '/nix/store/ab8hbnqb3in6sy5wbb6cb6b209r6d74s-driverConfiguration.json.drv' to 'https://cache.staging.nix-ci.com'...
  265. 25.84 s Uploaded driverConfiguration.json in 915ms
  266. 25.84 s Progress: 25 of 28 built, 3 of 3 downloaded from cache
  267. 25.84 s Built driverConfiguration.json in 978ms
  268. 25.91 s Building /nix/store/z0rycdi0jdhdqfmg022npkm86036ikhd-nixos-test-driver-nixos-test-read-proxy.drv
  269. 26.03 s [nixos-test-driver-nixos-test-read-proxy] Running type check (enable/disable: config.skipTypeCheck)
  270. 26.03 s [nixos-test-driver-nixos-test-read-proxy] See https://nixos.org/manual/nixos/stable/#test-opt-skipTypeCheck
  271. 26.08 s [nixos-test-driver-nixos-test-read-proxy] All checks passed!
  272. 26.10 s [nixos-test-driver-nixos-test-read-proxy] Linting test script (enable/disable: config.skipLint)
  273. 26.10 s [nixos-test-driver-nixos-test-read-proxy] See https://nixos.org/manual/nixos/stable/#test-opt-skipLint
  274. 26.12 s [nixos-test-driver-nixos-test-read-proxy] All checks passed!
  275. 26.24 s [nixos-test-driver-nixos-test-read-proxy:post-build] Uploading to the NixCI staging cache: /nix/store/mnba0l0kbyq5z6hah63dy1p31nbv4d6n-nixos-test-driver-nixos-test-read-proxy
  276. 26.32 s [nixos-test-driver-nixos-test-read-proxy:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  277. 26.36 s [nixos-test-driver-nixos-test-read-proxy:post-build] copying 1 paths...
  278. 26.36 s [nixos-test-driver-nixos-test-read-proxy:post-build] copying path '/nix/store/mnba0l0kbyq5z6hah63dy1p31nbv4d6n-nixos-test-driver-nixos-test-read-proxy' to 'https://cache.staging.nix-ci.com'...
  279. 26.61 s [nixos-test-driver-nixos-test-read-proxy:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  280. 26.98 s [nixos-test-driver-nixos-test-read-proxy:post-build] copying 1 paths...
  281. 26.99 s [nixos-test-driver-nixos-test-read-proxy:post-build] copying path '/nix/store/z0rycdi0jdhdqfmg022npkm86036ikhd-nixos-test-driver-nixos-test-read-proxy.drv' to 'https://cache.staging.nix-ci.com'...
  282. 27.17 s Uploaded nixos-test-driver-nixos-test-read-proxy in 987ms
  283. 27.17 s Progress: 26 of 28 built, 3 of 3 downloaded from cache
  284. 27.17 s Built nixos-test-driver-nixos-test-read-proxy in 1.2s
  285. 27.96 s Building /nix/store/g7n25sym70q5ki7x9s0swj0k64iyzffg-vm-test-run-nixos-test-read-proxy.drv
  286. 28.42 s [vm-test-run-nixos-test-read-proxy] Machine state will be reset. To keep it, pass --keep-machine-state
  287. 28.42 s [vm-test-run-nixos-test-read-proxy] start all VLans
  288. 28.43 s [vm-test-run-nixos-test-read-proxy] (finished: start all VLans, in 0.01 seconds)
  289. 28.43 s [vm-test-run-nixos-test-read-proxy] Test will time out and terminate in 3600 seconds
  290. 28.43 s [vm-test-run-nixos-test-read-proxy] run the VM test script
  291. 28.43 s [vm-test-run-nixos-test-read-proxy] additionally exposed symbols:
  292. 28.43 s [vm-test-run-nixos-test-read-proxy] server,
  293. 28.43 s [vm-test-run-nixos-test-read-proxy] vlan1,
  294. 28.43 s [vm-test-run-nixos-test-read-proxy] start_all, test_script, machines, machines_qemu, machines_nspawn, vlans, driver, log, os, create_machine, subtest, run_tests, join_all, retry, serial_stdout_off, serial_stdout_on, polling_condition, BaseMachine, QemuMachine, NspawnMachine, t, debug, dump_machine_ssh
  295. 28.43 s [vm-test-run-nixos-test-read-proxy] server: waiting for unit niks3.service
  296. 28.43 s [vm-test-run-nixos-test-read-proxy] server: waiting for the VM to finish booting
  297. 28.43 s [vm-test-run-nixos-test-read-proxy] server: starting vm
  298. 29.62 s [vm-test-run-nixos-test-read-proxy] server # Disk image does not exist, creating the virtualisation disk image...
  299. 29.62 s [vm-test-run-nixos-test-read-proxy] server: QEMU running (pid 45)
  300. 29.62 s [vm-test-run-nixos-test-read-proxy] server # Formatting '/build/vm-state-server/tmp.Llksezwv8P', fmt=raw size=1073741824
  301. 29.62 s [vm-test-run-nixos-test-read-proxy] server # mke2fs 1.47.4 (6-Mar-2025)
  302. 29.62 s [vm-test-run-nixos-test-read-proxy] server # Discarding device blocks: 0/262144 done
  303. 29.62 s [vm-test-run-nixos-test-read-proxy] server # Creating filesystem with 262144 4k blocks and 65536 inodes
  304. 29.62 s [vm-test-run-nixos-test-read-proxy] server # Filesystem UUID: d3a20e6f-1204-4d5b-b42b-cb41f4d4d8ce
  305. 29.62 s [vm-test-run-nixos-test-read-proxy] server # Superblock backups stored on blocks:
  306. 29.62 s [vm-test-run-nixos-test-read-proxy] server # 32768, 98304, 163840, 229376
  307. 29.62 s [vm-test-run-nixos-test-read-proxy] server #
  308. 29.62 s [vm-test-run-nixos-test-read-proxy] server # Allocating group tables: 0/8 done
  309. 29.62 s [vm-test-run-nixos-test-read-proxy] server # Writing inode tables: 0/8 done
  310. 29.62 s [vm-test-run-nixos-test-read-proxy] server # Creating journal (8192 blocks): done
  311. 29.62 s [vm-test-run-nixos-test-read-proxy] server # Writing superblocks and filesystem accounting information: 0/8 done
  312. 29.62 s [vm-test-run-nixos-test-read-proxy] server #
  313. 29.62 s [vm-test-run-nixos-test-read-proxy] server # Virtualisation disk image created.
  314. 29.72 s [vm-test-run-nixos-test-read-proxy] server # c[?7lSeaBIOS (version rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org)
  315. 29.82 s [vm-test-run-nixos-test-read-proxy] server #
  316. 29.82 s [vm-test-run-nixos-test-read-proxy] server #
  317. 29.83 s [vm-test-run-nixos-test-read-proxy] server # iPXE (http://ipxe.org) 00:03.0 CA00 PCI2.10 PnP PMM+3EFD1920+3EF31920 CA00
  318. 29.84 s [vm-test-run-nixos-test-read-proxy] server # Press Ctrl-B to configure iPXE (PCI 00:03.0)...
  319. 29.84 s [vm-test-run-nixos-test-read-proxy] server #
  320. 29.84 s [vm-test-run-nixos-test-read-proxy] server #
  321. 29.84 s [vm-test-run-nixos-test-read-proxy] server #
  322. 29.84 s [vm-test-run-nixos-test-read-proxy] server #
  323. 29.84 s [vm-test-run-nixos-test-read-proxy] server # iPXE (http://ipxe.org) 00:09.0 CB00 PCI2.10 PnP PMM 3EFD1920 3EF31920 CB00
  324. 29.86 s [vm-test-run-nixos-test-read-proxy] server # Press Ctrl-B to configure iPXE (PCI 00:09.0)...
  325. 29.86 s [vm-test-run-nixos-test-read-proxy] server #
  326. 29.86 s [vm-test-run-nixos-test-read-proxy] server #
  327. 29.89 s [vm-test-run-nixos-test-read-proxy] server # Booting from ROM...
  328. 31.13 s [vm-test-run-nixos-test-read-proxy] server # Probing EDD (edd=off to disable)... oc[?7lk[ 0.000000] Linux version 6.18.38 (nixbld@localhost) (gcc (GCC) 15.2.0, GNU ld (GNU Binutils) 2.46) #1-NixOS SMP PREEMPT_DYNAMIC Sat Jul 4 11:44:22 UTC 2026
  329. 31.16 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] Command line: console=ttyS0 console=tty0 panic=1 boot.panic_on_fail clocksource=acpi_pm root=fstab loglevel=7 net.ifnames=0 lsm=landlock,yama,bpf init=/nix/store/awn88pbhvb6ywvfwjvpjjmkvi94hd9hx-nixos-system-server-test/init regInfo=/nix/store/qizsg8cj1scm7wdi1wwf22vik5b1nfas-closure-info/registration console=ttyS0,115200n8 console=tty0
  330. 31.16 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] x86 CPU feature dependency check failure: CPU0 has '18*32+31' enabled but '18*32+26' disabled. Kernel might be fine, but no guarantees.
  331. 31.16 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] BIOS-provided physical RAM map:
  332. 31.16 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
  333. 31.16 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
  334. 31.16 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
  335. 31.16 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000003ffdafff] usable
  336. 31.16 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] BIOS-e820: [mem 0x000000003ffdb000-0x000000003fffffff] reserved
  337. 31.16 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
  338. 31.16 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
  339. 31.16 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] BIOS-e820: [mem 0x000000fd00000000-0x000000ffffffffff] reserved
  340. 31.16 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] NX (Execute Disable) protection: active
  341. 31.16 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] APIC: Static calls initialized
  342. 31.16 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] SMBIOS 2.8 present.
  343. 31.22 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org 04/01/2014
  344. 31.22 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] DMI: Memory slots populated: 1/1
  345. 31.22 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] Hypervisor detected: KVM
  346. 31.22 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
  347. 31.22 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
  348. 31.22 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000001] kvm-clock: using sched offset of 1148018525 cycles
  349. 31.22 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000002] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
  350. 31.22 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000006] tsc: Detected 3399.998 MHz processor
  351. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000712] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
  352. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000940] MTRR map: 4 entries (3 fixed + 1 variable; max 19), built from 8 variable MTRRs
  353. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000948] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT
  354. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.002876] found SMP MP-table at [mem 0x000f5470-0x000f547f]
  355. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.002889] Using GB pages for direct mapping
  356. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.002996] RAMDISK: [mem 0x3e302000-0x3ffcffff]
  357. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.003024] ACPI: Early table checksum verification disabled
  358. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.003027] ACPI: RSDP 0x00000000000F5290 000014 (v00 BOCHS )
  359. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.003031] ACPI: RSDT 0x000000003FFE23CC 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  360. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.003035] ACPI: FACP 0x000000003FFE2280 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  361. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.003058] ACPI: DSDT 0x000000003FFE0040 002240 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  362. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.003060] ACPI: FACS 0x000000003FFE0000 000040
  363. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.003062] ACPI: APIC 0x000000003FFE22F4 000078 (v03 BOCHS BXPC 00000001 BXPC 00000001)
  364. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.003063] ACPI: HPET 0x000000003FFE236C 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  365. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.003065] ACPI: WAET 0x000000003FFE23A4 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  366. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.003066] ACPI: Reserving FACP table memory at [mem 0x3ffe2280-0x3ffe22f3]
  367. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.003067] ACPI: Reserving DSDT table memory at [mem 0x3ffe0040-0x3ffe227f]
  368. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.003068] ACPI: Reserving FACS table memory at [mem 0x3ffe0000-0x3ffe003f]
  369. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.003068] ACPI: Reserving APIC table memory at [mem 0x3ffe22f4-0x3ffe236b]
  370. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.003069] ACPI: Reserving HPET table memory at [mem 0x3ffe236c-0x3ffe23a3]
  371. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.003069] ACPI: Reserving WAET table memory at [mem 0x3ffe23a4-0x3ffe23cb]
  372. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.003884] No NUMA configuration found
  373. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.003885] Faking a node at [mem 0x0000000000000000-0x000000003ffdafff]
  374. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.003888] NODE_DATA(0) allocated [mem 0x3ffd5780-0x3ffdacff]
  375. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.004231] Zone ranges:
  376. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.004231] DMA [mem 0x0000000000001000-0x0000000000ffffff]
  377. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.004233] DMA32 [mem 0x0000000001000000-0x000000003ffdafff]
  378. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.004234] Normal empty
  379. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.004235] Device empty
  380. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.004235] Movable zone start for each node
  381. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.004236] Early memory node ranges
  382. 31.23 s [vm-test-run-nixos-test-read-proxy] server # [ 0.004236] node 0: [mem 0x0000000000001000-0x000000000009efff]
  383. 31.24 s [vm-test-run-nixos-test-read-proxy] server # [ 0.004237] node 0: [mem 0x0000000000100000-0x000000003ffdafff]
  384. 31.24 s [vm-test-run-nixos-test-read-proxy] server # [ 0.004238] Initmem setup node 0 [mem 0x0000000000001000-0x000000003ffdafff]
  385. 31.24 s [vm-test-run-nixos-test-read-proxy] server # [ 0.004305] On node 0, zone DMA: 1 pages in unavailable ranges
  386. 31.24 s [vm-test-run-nixos-test-read-proxy] server # [ 0.005982] On node 0, zone DMA: 97 pages in unavailable ranges
  387. 31.24 s [vm-test-run-nixos-test-read-proxy] server # [ 0.145485] On node 0, zone DMA32: 37 pages in unavailable ranges
  388. 31.24 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147081] ACPI: PM-Timer IO Port: 0x608
  389. 31.25 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147109] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
  390. 31.25 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147193] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
  391. 31.25 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147195] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
  392. 31.25 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147196] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
  393. 31.25 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147197] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
  394. 31.26 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147198] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
  395. 31.26 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147199] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
  396. 31.26 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147201] ACPI: Using ACPI (MADT) for SMP configuration information
  397. 31.26 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147201] ACPI: HPET id: 0x8086a201 base: 0xfed00000
  398. 31.26 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147206] TSC deadline timer available
  399. 31.26 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147210] CPU topo: Max. logical packages: 1
  400. 31.27 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147210] CPU topo: Max. logical dies: 1
  401. 31.27 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147211] CPU topo: Max. dies per package: 1
  402. 31.27 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147214] CPU topo: Max. threads per core: 1
  403. 31.27 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147214] CPU topo: Num. cores per package: 1
  404. 31.27 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147214] CPU topo: Num. threads per package: 1
  405. 31.27 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147215] CPU topo: Allowing 1 present CPUs plus 0 hotplug CPUs
  406. 31.27 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147247] kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write()
  407. 31.28 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147329] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]
  408. 31.28 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147330] PM: hibernation: Registered nosave memory: [mem 0x0009f000-0x000fffff]
  409. 31.28 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147331] [mem 0x40000000-0xfeffbfff] available for PCI devices
  410. 31.28 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147333] Booting paravirtualized kernel on KVM
  411. 31.29 s [vm-test-run-nixos-test-read-proxy] server # [ 0.147336] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
  412. 31.29 s [vm-test-run-nixos-test-read-proxy] server # [ 0.151427] setup_percpu: NR_CPUS:384 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1
  413. 31.29 s [vm-test-run-nixos-test-read-proxy] server # [ 0.168649] percpu: Embedded 98 pages/cpu s278528 r8192 d114688 u2097152
  414. 31.29 s [vm-test-run-nixos-test-read-proxy] server # [ 0.168758] kvm-guest: PV spinlocks disabled, single CPU
  415. 31.30 s [vm-test-run-nixos-test-read-proxy] server # [ 0.168760] Kernel command line: console=ttyS0 console=tty0 panic=1 boot.panic_on_fail clocksource=acpi_pm root=fstab loglevel=7 net.ifnames=0 lsm=landlock,yama,bpf init=/nix/store/awn88pbhvb6ywvfwjvpjjmkvi94hd9hx-nixos-system-server-test/init regInfo=/nix/store/qizsg8cj1scm7wdi1wwf22vik5b1nfas-closure-info/registration console=ttyS0,115200n8 console=tty0
  416. 31.30 s [vm-test-run-nixos-test-read-proxy] server # [ 0.168837] Unknown kernel command line parameters "regInfo=/nix/store/qizsg8cj1scm7wdi1wwf22vik5b1nfas-closure-info/registration", will be passed to user space.
  417. 31.31 s [vm-test-run-nixos-test-read-proxy] server # [ 0.168852] random: crng init done
  418. 31.31 s [vm-test-run-nixos-test-read-proxy] server # [ 0.168852] printk: log buffer data + meta data: 262144 + 917504 = 1179648 bytes
  419. 31.31 s [vm-test-run-nixos-test-read-proxy] server # [ 0.168892] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
  420. 31.31 s [vm-test-run-nixos-test-read-proxy] server # [ 0.171659] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)
  421. 31.31 s [vm-test-run-nixos-test-read-proxy] server # [ 0.171735] Fallback order for Node 0: 0
  422. 31.32 s [vm-test-run-nixos-test-read-proxy] server # [ 0.171737] Built 1 zonelists, mobility grouping on. Total pages: 262009
  423. 31.32 s [vm-test-run-nixos-test-read-proxy] server # [ 0.171738] Policy zone: DMA32
  424. 31.32 s [vm-test-run-nixos-test-read-proxy] server # [ 0.190786] mem auto-init: stack:all(zero), heap alloc:on, heap free:off
  425. 31.32 s [vm-test-run-nixos-test-read-proxy] server # [ 0.195804] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
  426. 31.32 s [vm-test-run-nixos-test-read-proxy] server # [ 0.212284] allocated 2097152 bytes of page_ext
  427. 31.32 s [vm-test-run-nixos-test-read-proxy] server # [ 0.227769] ftrace: allocating 48598 entries in 192 pages
  428. 31.33 s [vm-test-run-nixos-test-read-proxy] server # [ 0.227771] ftrace: allocated 192 pages with 2 groups
  429. 31.33 s [vm-test-run-nixos-test-read-proxy] server # [ 0.231854] Dynamic Preempt: lazy
  430. 31.33 s [vm-test-run-nixos-test-read-proxy] server # [ 0.233278] rcu: Preemptible hierarchical RCU implementation.
  431. 31.33 s [vm-test-run-nixos-test-read-proxy] server # [ 0.233278] rcu: RCU event tracing is enabled.
  432. 31.33 s [vm-test-run-nixos-test-read-proxy] server # [ 0.233279] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1.
  433. 31.33 s [vm-test-run-nixos-test-read-proxy] server # [ 0.233280] Trampoline variant of Tasks RCU enabled.
  434. 31.33 s [vm-test-run-nixos-test-read-proxy] server # [ 0.233281] Rude variant of Tasks RCU enabled.
  435. 31.34 s [vm-test-run-nixos-test-read-proxy] server # [ 0.233281] Tracing variant of Tasks RCU enabled.
  436. 31.34 s [vm-test-run-nixos-test-read-proxy] server # [ 0.233282] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.
  437. 31.34 s [vm-test-run-nixos-test-read-proxy] server # [ 0.233282] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
  438. 31.34 s [vm-test-run-nixos-test-read-proxy] server # [ 0.233380] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  439. 31.35 s [vm-test-run-nixos-test-read-proxy] server # [ 0.233381] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  440. 31.35 s [vm-test-run-nixos-test-read-proxy] server # [ 0.233382] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  441. 31.35 s [vm-test-run-nixos-test-read-proxy] server # [ 0.241145] NR_IRQS: 24832, nr_irqs: 256, preallocated irqs: 16
  442. 31.35 s [vm-test-run-nixos-test-read-proxy] server # [ 0.241874] rcu: srcu_init: Setting srcu_struct sizes based on contention.
  443. 31.35 s [vm-test-run-nixos-test-read-proxy] server # [ 0.241998] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)
  444. 31.36 s [vm-test-run-nixos-test-read-proxy] server # [ 0.255141] Console: colour VGA+ 80x25
  445. 31.36 s [vm-test-run-nixos-test-read-proxy] server # [ 0.255144] printk: legacy console [tty0] enabled
  446. 31.36 s [vm-test-run-nixos-test-read-proxy] server # [ 0.357900] printk: legacy console [ttyS0] enabled
  447. 31.36 s [vm-test-run-nixos-test-read-proxy] server # [ 0.593981] ACPI: Core revision 20250807
  448. 31.36 s [vm-test-run-nixos-test-read-proxy] server # [ 0.596302] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
  449. 31.37 s [vm-test-run-nixos-test-read-proxy] server # [ 0.600362] APIC: Switch to symmetric I/O mode setup
  450. 31.37 s [vm-test-run-nixos-test-read-proxy] server # [ 0.603439] x2apic enabled
  451. 31.37 s [vm-test-run-nixos-test-read-proxy] server # [ 0.605643] APIC: Switched APIC routing to: physical x2apic
  452. 31.70 s [vm-test-run-nixos-test-read-proxy] server # [ 0.929552] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
  453. 31.70 s [vm-test-run-nixos-test-read-proxy] server # [ 0.933294] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x31024cfe468, max_idle_ns: 440795307017 ns
  454. 31.71 s [vm-test-run-nixos-test-read-proxy] server # [ 0.939405] Calibrating delay loop (skipped) preset value.. 6799.99 BogoMIPS (lpj=3399998)
  455. 31.71 s [vm-test-run-nixos-test-read-proxy] server # [ 0.943032] x86/cpu: User Mode Instruction Prevention (UMIP) activated
  456. 31.72 s [vm-test-run-nixos-test-read-proxy] server # [ 0.945979] Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127
  457. 31.72 s [vm-test-run-nixos-test-read-proxy] server # [ 0.947402] Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0
  458. 31.72 s [vm-test-run-nixos-test-read-proxy] server # [ 0.949413] mitigations: Enabled attack vectors: user_kernel, user_user, guest_host, guest_guest, SMT mitigations: auto
  459. 31.73 s [vm-test-run-nixos-test-read-proxy] server # [ 0.951402] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl
  460. 31.73 s [vm-test-run-nixos-test-read-proxy] server # [ 0.953402] Spectre V2 : Mitigation: Retpolines
  461. 31.73 s [vm-test-run-nixos-test-read-proxy] server # [ 0.954402] Speculative Return Stack Overflow: Mitigation: Safe RET
  462. 31.74 s [vm-test-run-nixos-test-read-proxy] server # [ 0.956402] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
  463. 31.74 s [vm-test-run-nixos-test-read-proxy] server # [ 0.958402] Spectre V2 : Spectre v2 / SpectreRSB: Filling RSB on context switch and VMEXIT
  464. 31.74 s [vm-test-run-nixos-test-read-proxy] server # [ 0.960402] Spectre V2 : Enabling Restricted Speculation for firmware calls
  465. 31.75 s [vm-test-run-nixos-test-read-proxy] server # [ 0.962404] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
  466. 31.76 s [vm-test-run-nixos-test-read-proxy] server # [ 0.964403] active return thunk: srso_alias_return_thunk
  467. 31.76 s [vm-test-run-nixos-test-read-proxy] server # [ 0.966490] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
  468. 31.77 s [vm-test-run-nixos-test-read-proxy] server # [ 0.968406] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
  469. 31.77 s [vm-test-run-nixos-test-read-proxy] server # [ 0.970403] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
  470. 31.77 s [vm-test-run-nixos-test-read-proxy] server # [ 0.972403] x86/fpu: Supporting XSAVE feature 0x200: 'Protection Keys User registers'
  471. 31.78 s [vm-test-run-nixos-test-read-proxy] server # [ 0.974403] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256
  472. 31.78 s [vm-test-run-nixos-test-read-proxy] server # [ 0.976402] x86/fpu: xstate_offset[9]: 832, xstate_sizes[9]: 8
  473. 31.78 s [vm-test-run-nixos-test-read-proxy] server # [ 0.978402] x86/fpu: Enabled xstate features 0x207, context size is 840 bytes, using 'compacted' format.
  474. 31.81 s [vm-test-run-nixos-test-read-proxy] server # [ 1.009070] Freeing SMP alternatives memory: 44K
  475. 31.82 s [vm-test-run-nixos-test-read-proxy] server # [ 1.010405] pid_max: default: 32768 minimum: 301
  476. 31.82 s [vm-test-run-nixos-test-read-proxy] server # [ 1.013451] LSM: initializing lsm=capability,landlock,yama,bpf,ima
  477. 31.82 s [vm-test-run-nixos-test-read-proxy] server # [ 1.014527] landlock: Up and running.
  478. 31.82 s [vm-test-run-nixos-test-read-proxy] server # [ 1.016402] Yama: becoming mindful.
  479. 31.82 s [vm-test-run-nixos-test-read-proxy] server # [ 1.018641] LSM support for eBPF active
  480. 31.83 s [vm-test-run-nixos-test-read-proxy] server # [ 1.020707] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
  481. 31.83 s [vm-test-run-nixos-test-read-proxy] server # [ 1.023466] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
  482. 31.84 s [vm-test-run-nixos-test-read-proxy] server # [ 1.030721] smpboot: CPU0: AMD Ryzen 9 5950X 16-Core Processor (family: 0x19, model: 0x21, stepping: 0x0)
  483. 31.85 s [vm-test-run-nixos-test-read-proxy] server # [ 1.035040] Performance Events: Fam17h+ core perfctr, AMD PMU driver.
  484. 31.85 s [vm-test-run-nixos-test-read-proxy] server # [ 1.036416] ... version: 0
  485. 31.85 s [vm-test-run-nixos-test-read-proxy] server # [ 1.037610] ... bit width: 48
  486. 31.85 s [vm-test-run-nixos-test-read-proxy] server # [ 1.038408] ... generic counters: 6
  487. 31.86 s [vm-test-run-nixos-test-read-proxy] server # [ 1.039408] ... generic bitmap: 000000000000003f
  488. 31.86 s [vm-test-run-nixos-test-read-proxy] server # [ 1.040408] ... fixed-purpose counters: 0
  489. 31.86 s [vm-test-run-nixos-test-read-proxy] server # [ 1.041408] ... fixed-purpose bitmap: 0000000000000000
  490. 31.86 s [vm-test-run-nixos-test-read-proxy] server # [ 1.042424] ... value mask: 0000ffffffffffff
  491. 31.86 s [vm-test-run-nixos-test-read-proxy] server # [ 1.043408] ... max period: 00007fffffffffff
  492. 31.87 s [vm-test-run-nixos-test-read-proxy] server # [ 1.044409] ... global_ctrl mask: 000000000000003f
  493. 31.87 s [vm-test-run-nixos-test-read-proxy] server # [ 1.045511] signal: max sigframe size: 3376
  494. 31.87 s [vm-test-run-nixos-test-read-proxy] server # [ 1.046924] rcu: Hierarchical SRCU implementation.
  495. 31.87 s [vm-test-run-nixos-test-read-proxy] server # [ 1.048411] rcu: Max phase no-delay instances is 400.
  496. 31.88 s [vm-test-run-nixos-test-read-proxy] server # [ 1.055419] smp: Bringing up secondary CPUs ...
  497. 31.88 s [vm-test-run-nixos-test-read-proxy] server # [ 1.056416] smp: Brought up 1 node, 1 CPU
  498. 31.89 s [vm-test-run-nixos-test-read-proxy] server # [ 1.057414] smpboot: Total of 1 processors activated (6799.99 BogoMIPS)
  499. 31.89 s [vm-test-run-nixos-test-read-proxy] server # [ 1.059127] Memory: 942848K/1048036K available (17159K kernel code, 2721K rwdata, 13540K rodata, 3636K init, 3020K bss, 98000K reserved, 0K cma-reserved)
  500. 31.90 s [vm-test-run-nixos-test-read-proxy] server # [ 1.061165] devtmpfs: initialized
  501. 31.90 s [vm-test-run-nixos-test-read-proxy] server # [ 1.063365] x86/mm: Memory block size: 128MB
  502. 31.91 s [vm-test-run-nixos-test-read-proxy] server # [ 1.066745] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
  503. 31.91 s [vm-test-run-nixos-test-read-proxy] server # [ 1.068550] posixtimers hash table entries: 512 (order: 1, 8192 bytes, linear)
  504. 31.91 s [vm-test-run-nixos-test-read-proxy] server # [ 1.070659] futex hash table entries: 256 (16384 bytes on 1 NUMA nodes, total 16 KiB, linear).
  505. 31.92 s [vm-test-run-nixos-test-read-proxy] server # [ 1.072547] pinctrl core: initialized pinctrl subsystem
  506. 31.92 s [vm-test-run-nixos-test-read-proxy] server # [ 1.074304] PM: RTC time: 13:59:19, date: 2026-07-18
  507. 31.94 s [vm-test-run-nixos-test-read-proxy] server # [ 1.094218] NET: Registered PF_NETLINK/PF_ROUTE protocol family
  508. 31.95 s [vm-test-run-nixos-test-read-proxy] server # [ 1.096998] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations
  509. 31.95 s [vm-test-run-nixos-test-read-proxy] server # [ 1.098459] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
  510. 31.95 s [vm-test-run-nixos-test-read-proxy] server # [ 1.101618] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
  511. 31.96 s [vm-test-run-nixos-test-read-proxy] server # [ 1.103424] audit: initializing netlink subsys (disabled)
  512. 31.96 s [vm-test-run-nixos-test-read-proxy] server # [ 1.105410] audit: type=2000 audit(1784383158.710:1): state=initialized audit_enabled=0 res=1
  513. 31.96 s [vm-test-run-nixos-test-read-proxy] server # [ 1.107522] thermal_sys: Registered thermal governor 'fair_share'
  514. 31.97 s [vm-test-run-nixos-test-read-proxy] server # [ 1.107524] thermal_sys: Registered thermal governor 'bang_bang'
  515. 31.97 s [vm-test-run-nixos-test-read-proxy] server # [ 1.108409] thermal_sys: Registered thermal governor 'step_wise'
  516. 31.97 s [vm-test-run-nixos-test-read-proxy] server # [ 1.109413] thermal_sys: Registered thermal governor 'user_space'
  517. 31.98 s [vm-test-run-nixos-test-read-proxy] server # [ 1.110408] thermal_sys: Registered thermal governor 'power_allocator'
  518. 31.98 s [vm-test-run-nixos-test-read-proxy] server # [ 1.111428] cpuidle: using governor menu
  519. 31.98 s [vm-test-run-nixos-test-read-proxy] server # [ 1.115282] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
  520. 31.99 s [vm-test-run-nixos-test-read-proxy] server # [ 1.117771] PCI: Using configuration type 1 for base access
  521. 31.99 s [vm-test-run-nixos-test-read-proxy] server # [ 1.119408] PCI: Using configuration type 1 for extended access
  522. 31.99 s [vm-test-run-nixos-test-read-proxy] server # [ 1.120836] kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible.
  523. 32.01 s [vm-test-run-nixos-test-read-proxy] server # [ 1.133744] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages
  524. 32.02 s [vm-test-run-nixos-test-read-proxy] server # [ 1.139667] HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page
  525. 32.02 s [vm-test-run-nixos-test-read-proxy] server # [ 1.145415] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
  526. 32.03 s [vm-test-run-nixos-test-read-proxy] server # [ 1.151131] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page
  527. 32.04 s [vm-test-run-nixos-test-read-proxy] server # [ 1.162516] ACPI: Added _OSI(Module Device)
  528. 32.05 s [vm-test-run-nixos-test-read-proxy] server # [ 1.165410] ACPI: Added _OSI(Processor Device)
  529. 32.05 s [vm-test-run-nixos-test-read-proxy] server # [ 1.166412] ACPI: Added _OSI(Processor Aggregator Device)
  530. 32.06 s [vm-test-run-nixos-test-read-proxy] server # [ 1.173535] ACPI: 1 ACPI AML tables successfully acquired and loaded
  531. 32.06 s [vm-test-run-nixos-test-read-proxy] server # [ 1.176864] ACPI: Interpreter enabled
  532. 32.06 s [vm-test-run-nixos-test-read-proxy] server # [ 1.178425] ACPI: PM: (supports S0 S3 S4 S5)
  533. 32.07 s [vm-test-run-nixos-test-read-proxy] server # [ 1.179413] ACPI: Using IOAPIC for interrupt routing
  534. 32.07 s [vm-test-run-nixos-test-read-proxy] server # [ 1.180426] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
  535. 32.08 s [vm-test-run-nixos-test-read-proxy] server # [ 1.182409] PCI: Using E820 reservations for host bridge windows
  536. 32.08 s [vm-test-run-nixos-test-read-proxy] server # [ 1.184606] ACPI: Enabled 2 GPEs in block 00 to 0F
  537. 32.09 s [vm-test-run-nixos-test-read-proxy] server # [ 1.197080] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
  538. 32.10 s [vm-test-run-nixos-test-read-proxy] server # [ 1.198414] acpi PNP0A03:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3]
  539. 32.10 s [vm-test-run-nixos-test-read-proxy] server # [ 1.200865] acpiphp: Slot [3] registered
  540. 32.10 s [vm-test-run-nixos-test-read-proxy] server # [ 1.202509] acpiphp: Slot [4] registered
  541. 32.10 s [vm-test-run-nixos-test-read-proxy] server # [ 1.203449] acpiphp: Slot [5] registered
  542. 32.10 s [vm-test-run-nixos-test-read-proxy] server # [ 1.204450] acpiphp: Slot [6] registered
  543. 32.11 s [vm-test-run-nixos-test-read-proxy] server # [ 1.205453] acpiphp: Slot [7] registered
  544. 32.11 s [vm-test-run-nixos-test-read-proxy] server # [ 1.206509] acpiphp: Slot [8] registered
  545. 32.11 s [vm-test-run-nixos-test-read-proxy] server # [ 1.207451] acpiphp: Slot [9] registered
  546. 32.11 s [vm-test-run-nixos-test-read-proxy] server # [ 1.208450] acpiphp: Slot [10] registered
  547. 32.11 s [vm-test-run-nixos-test-read-proxy] server # [ 1.209450] acpiphp: Slot [11] registered
  548. 32.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.210534] acpiphp: Slot [12] registered
  549. 32.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.211463] acpiphp: Slot [13] registered
  550. 32.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.212448] acpiphp: Slot [14] registered
  551. 32.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.213449] acpiphp: Slot [15] registered
  552. 32.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.214514] acpiphp: Slot [16] registered
  553. 32.13 s [vm-test-run-nixos-test-read-proxy] server # [ 1.215447] acpiphp: Slot [17] registered
  554. 32.13 s [vm-test-run-nixos-test-read-proxy] server # [ 1.216448] acpiphp: Slot [18] registered
  555. 32.13 s [vm-test-run-nixos-test-read-proxy] server # [ 1.217511] acpiphp: Slot [19] registered
  556. 32.13 s [vm-test-run-nixos-test-read-proxy] server # [ 1.218447] acpiphp: Slot [20] registered
  557. 32.13 s [vm-test-run-nixos-test-read-proxy] server # [ 1.219452] acpiphp: Slot [21] registered
  558. 32.14 s [vm-test-run-nixos-test-read-proxy] server # [ 1.220448] acpiphp: Slot [22] registered
  559. 32.14 s [vm-test-run-nixos-test-read-proxy] server # [ 1.221563] acpiphp: Slot [23] registered
  560. 32.14 s [vm-test-run-nixos-test-read-proxy] server # [ 1.222448] acpiphp: Slot [24] registered
  561. 32.14 s [vm-test-run-nixos-test-read-proxy] server # [ 1.223449] acpiphp: Slot [25] registered
  562. 32.14 s [vm-test-run-nixos-test-read-proxy] server # [ 1.224449] acpiphp: Slot [26] registered
  563. 32.15 s [vm-test-run-nixos-test-read-proxy] server # [ 1.225508] acpiphp: Slot [27] registered
  564. 32.15 s [vm-test-run-nixos-test-read-proxy] server # [ 1.226447] acpiphp: Slot [28] registered
  565. 32.15 s [vm-test-run-nixos-test-read-proxy] server # [ 1.227505] acpiphp: Slot [29] registered
  566. 32.15 s [vm-test-run-nixos-test-read-proxy] server # [ 1.228448] acpiphp: Slot [30] registered
  567. 32.15 s [vm-test-run-nixos-test-read-proxy] server # [ 1.229506] acpiphp: Slot [31] registered
  568. 32.16 s [vm-test-run-nixos-test-read-proxy] server # [ 1.230441] PCI host bridge to bus 0000:00
  569. 32.16 s [vm-test-run-nixos-test-read-proxy] server # [ 1.231418] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]
  570. 32.16 s [vm-test-run-nixos-test-read-proxy] server # [ 1.232412] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]
  571. 32.17 s [vm-test-run-nixos-test-read-proxy] server # [ 1.233411] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
  572. 32.17 s [vm-test-run-nixos-test-read-proxy] server # [ 1.235410] pci_bus 0000:00: root bus resource [mem 0x40000000-0xfebfffff window]
  573. 32.17 s [vm-test-run-nixos-test-read-proxy] server # [ 1.237410] pci_bus 0000:00: root bus resource [mem 0x100000000-0x17fffffff window]
  574. 32.18 s [vm-test-run-nixos-test-read-proxy] server # [ 1.239426] pci_bus 0000:00: root bus resource [bus 00-ff]
  575. 32.18 s [vm-test-run-nixos-test-read-proxy] server # [ 1.240981] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 conventional PCI endpoint
  576. 32.18 s [vm-test-run-nixos-test-read-proxy] server # [ 1.243926] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 conventional PCI endpoint
  577. 32.19 s [vm-test-run-nixos-test-read-proxy] server # [ 1.247030] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 conventional PCI endpoint
  578. 32.19 s [vm-test-run-nixos-test-read-proxy] server # [ 1.249981] pci 0000:00:01.1: BAR 4 [io 0xc1e0-0xc1ef]
  579. 32.20 s [vm-test-run-nixos-test-read-proxy] server # [ 1.251522] pci 0000:00:01.1: BAR 0 [io 0x01f0-0x01f7]: legacy IDE quirk
  580. 32.20 s [vm-test-run-nixos-test-read-proxy] server # [ 1.252409] pci 0000:00:01.1: BAR 1 [io 0x03f6]: legacy IDE quirk
  581. 32.20 s [vm-test-run-nixos-test-read-proxy] server # [ 1.253409] pci 0000:00:01.1: BAR 2 [io 0x0170-0x0177]: legacy IDE quirk
  582. 32.21 s [vm-test-run-nixos-test-read-proxy] server # [ 1.254409] pci 0000:00:01.1: BAR 3 [io 0x0376]: legacy IDE quirk
  583. 32.21 s [vm-test-run-nixos-test-read-proxy] server # [ 1.256010] pci 0000:00:01.2: [8086:7020] type 00 class 0x0c0300 conventional PCI endpoint
  584. 32.21 s [vm-test-run-nixos-test-read-proxy] server # [ 1.258941] pci 0000:00:01.2: BAR 4 [io 0xc100-0xc11f]
  585. 32.22 s [vm-test-run-nixos-test-read-proxy] server # [ 1.261814] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 conventional PCI endpoint
  586. 32.22 s [vm-test-run-nixos-test-read-proxy] server # [ 1.264408] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI
  587. 32.23 s [vm-test-run-nixos-test-read-proxy] server # [ 1.266432] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB
  588. 32.23 s [vm-test-run-nixos-test-read-proxy] server # [ 1.268215] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000 conventional PCI endpoint
  589. 32.25 s [vm-test-run-nixos-test-read-proxy] server # [ 1.272661] pci 0000:00:02.0: BAR 0 [mem 0xfd000000-0xfdffffff pref]
  590. 32.25 s [vm-test-run-nixos-test-read-proxy] server # [ 1.274476] pci 0000:00:02.0: BAR 2 [mem 0xfebd0000-0xfebd0fff]
  591. 32.25 s [vm-test-run-nixos-test-read-proxy] server # [ 1.275494] pci 0000:00:02.0: ROM [mem 0xfebc0000-0xfebcffff pref]
  592. 32.26 s [vm-test-run-nixos-test-read-proxy] server # [ 1.278026] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
  593. 32.27 s [vm-test-run-nixos-test-read-proxy] server # [ 1.285752] pci 0000:00:03.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
  594. 32.27 s [vm-test-run-nixos-test-read-proxy] server # [ 1.289432] pci 0000:00:03.0: BAR 0 [io 0xc120-0xc13f]
  595. 32.27 s [vm-test-run-nixos-test-read-proxy] server # [ 1.290434] pci 0000:00:03.0: BAR 1 [mem 0xfebd1000-0xfebd1fff]
  596. 32.28 s [vm-test-run-nixos-test-read-proxy] server # [ 1.291507] pci 0000:00:03.0: BAR 4 [mem 0xfe000000-0xfe003fff 64bit pref]
  597. 32.28 s [vm-test-run-nixos-test-read-proxy] server # [ 1.292434] pci 0000:00:03.0: ROM [mem 0xfeb40000-0xfeb7ffff pref]
  598. 32.29 s [vm-test-run-nixos-test-read-proxy] server # [ 1.298898] pci 0000:00:04.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
  599. 32.30 s [vm-test-run-nixos-test-read-proxy] server # [ 1.302432] pci 0000:00:04.0: BAR 0 [io 0xc140-0xc15f]
  600. 32.30 s [vm-test-run-nixos-test-read-proxy] server # [ 1.303432] pci 0000:00:04.0: BAR 1 [mem 0xfebd2000-0xfebd2fff]
  601. 32.30 s [vm-test-run-nixos-test-read-proxy] server # [ 1.304498] pci 0000:00:04.0: BAR 4 [mem 0xfe004000-0xfe007fff 64bit pref]
  602. 32.31 s [vm-test-run-nixos-test-read-proxy] server # [ 1.308252] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  603. 32.31 s [vm-test-run-nixos-test-read-proxy] server # [ 1.311438] pci 0000:00:05.0: BAR 0 [io 0xc080-0xc0bf]
  604. 32.32 s [vm-test-run-nixos-test-read-proxy] server # [ 1.313435] pci 0000:00:05.0: BAR 1 [mem 0xfebd3000-0xfebd3fff]
  605. 32.32 s [vm-test-run-nixos-test-read-proxy] server # [ 1.315502] pci 0000:00:05.0: BAR 4 [mem 0xfe008000-0xfe00bfff 64bit pref]
  606. 32.33 s [vm-test-run-nixos-test-read-proxy] server # [ 1.320828] pci 0000:00:06.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  607. 32.34 s [vm-test-run-nixos-test-read-proxy] server # [ 1.324446] pci 0000:00:06.0: BAR 0 [io 0xc160-0xc17f]
  608. 32.34 s [vm-test-run-nixos-test-read-proxy] server # [ 1.326449] pci 0000:00:06.0: BAR 1 [mem 0xfebd4000-0xfebd4fff]
  609. 32.34 s [vm-test-run-nixos-test-read-proxy] server # [ 1.328791] pci 0000:00:06.0: BAR 4 [mem 0xfe00c000-0xfe00ffff 64bit pref]
  610. 32.35 s [vm-test-run-nixos-test-read-proxy] server # [ 1.333532] pci 0000:00:07.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  611. 32.36 s [vm-test-run-nixos-test-read-proxy] server # [ 1.337438] pci 0000:00:07.0: BAR 0 [io 0xc180-0xc19f]
  612. 32.36 s [vm-test-run-nixos-test-read-proxy] server # [ 1.338440] pci 0000:00:07.0: BAR 1 [mem 0xfebd5000-0xfebd5fff]
  613. 32.36 s [vm-test-run-nixos-test-read-proxy] server # [ 1.339509] pci 0000:00:07.0: BAR 4 [mem 0xfe010000-0xfe013fff 64bit pref]
  614. 32.38 s [vm-test-run-nixos-test-read-proxy] server # [ 1.344317] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint
  615. 32.39 s [vm-test-run-nixos-test-read-proxy] server # [ 1.349431] pci 0000:00:08.0: BAR 0 [io 0xc000-0xc07f]
  616. 32.39 s [vm-test-run-nixos-test-read-proxy] server # [ 1.350444] pci 0000:00:08.0: BAR 1 [mem 0xfebd6000-0xfebd6fff]
  617. 32.39 s [vm-test-run-nixos-test-read-proxy] server # [ 1.351519] pci 0000:00:08.0: BAR 4 [mem 0xfe014000-0xfe017fff 64bit pref]
  618. 32.40 s [vm-test-run-nixos-test-read-proxy] server # [ 1.358610] pci 0000:00:09.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
  619. 32.41 s [vm-test-run-nixos-test-read-proxy] server # [ 1.362432] pci 0000:00:09.0: BAR 0 [io 0xc1a0-0xc1bf]
  620. 32.41 s [vm-test-run-nixos-test-read-proxy] server # [ 1.363438] pci 0000:00:09.0: BAR 1 [mem 0xfebd7000-0xfebd7fff]
  621. 32.42 s [vm-test-run-nixos-test-read-proxy] server # [ 1.364508] pci 0000:00:09.0: BAR 4 [mem 0xfe018000-0xfe01bfff 64bit pref]
  622. 32.42 s [vm-test-run-nixos-test-read-proxy] server # [ 1.366438] pci 0000:00:09.0: ROM [mem 0xfeb80000-0xfebbffff pref]
  623. 32.43 s [vm-test-run-nixos-test-read-proxy] server # [ 1.370388] pci 0000:00:0a.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint
  624. 32.43 s [vm-test-run-nixos-test-read-proxy] server # [ 1.374454] pci 0000:00:0a.0: BAR 1 [mem 0xfebd8000-0xfebd8fff]
  625. 32.43 s [vm-test-run-nixos-test-read-proxy] server # [ 1.375511] pci 0000:00:0a.0: BAR 4 [mem 0xfe01c000-0xfe01ffff 64bit pref]
  626. 32.44 s [vm-test-run-nixos-test-read-proxy] server # [ 1.379369] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint
  627. 32.45 s [vm-test-run-nixos-test-read-proxy] server # [ 1.382432] pci 0000:00:0b.0: BAR 0 [io 0xc0c0-0xc0ff]
  628. 32.45 s [vm-test-run-nixos-test-read-proxy] server # [ 1.383438] pci 0000:00:0b.0: BAR 1 [mem 0xfebd9000-0xfebd9fff]
  629. 32.45 s [vm-test-run-nixos-test-read-proxy] server # [ 1.385544] pci 0000:00:0b.0: BAR 4 [mem 0xfe020000-0xfe023fff 64bit pref]
  630. 32.46 s [vm-test-run-nixos-test-read-proxy] server # [ 1.391014] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
  631. 32.47 s [vm-test-run-nixos-test-read-proxy] server # [ 1.394438] pci 0000:00:0c.0: BAR 0 [io 0xc1c0-0xc1df]
  632. 32.47 s [vm-test-run-nixos-test-read-proxy] server # [ 1.395436] pci 0000:00:0c.0: BAR 1 [mem 0xfebda000-0xfebdafff]
  633. 32.47 s [vm-test-run-nixos-test-read-proxy] server # [ 1.396514] pci 0000:00:0c.0: BAR 4 [mem 0xfe024000-0xfe027fff 64bit pref]
  634. 32.49 s [vm-test-run-nixos-test-read-proxy] server # [ 1.413321] ACPI: PCI: Interrupt link LNKA configured for IRQ 10
  635. 32.50 s [vm-test-run-nixos-test-read-proxy] server # [ 1.414664] ACPI: PCI: Interrupt link LNKB configured for IRQ 10
  636. 32.50 s [vm-test-run-nixos-test-read-proxy] server # [ 1.416638] ACPI: PCI: Interrupt link LNKC configured for IRQ 11
  637. 32.50 s [vm-test-run-nixos-test-read-proxy] server # [ 1.418635] ACPI: PCI: Interrupt link LNKD configured for IRQ 11
  638. 32.50 s [vm-test-run-nixos-test-read-proxy] server # [ 1.420540] ACPI: PCI: Interrupt link LNKS configured for IRQ 9
  639. 32.52 s [vm-test-run-nixos-test-read-proxy] server # [ 1.435235] iommu: Default domain type: Translated
  640. 32.52 s [vm-test-run-nixos-test-read-proxy] server # [ 1.436409] iommu: DMA domain TLB invalidation policy: lazy mode
  641. 32.53 s [vm-test-run-nixos-test-read-proxy] server # [ 1.440253] ACPI: bus type USB registered
  642. 32.53 s [vm-test-run-nixos-test-read-proxy] server # [ 1.441848] usbcore: registered new interface driver usbfs
  643. 32.54 s [vm-test-run-nixos-test-read-proxy] server # [ 1.443602] usbcore: registered new interface driver hub
  644. 32.54 s [vm-test-run-nixos-test-read-proxy] server # [ 1.444420] usbcore: registered new device driver usb
  645. 32.55 s [vm-test-run-nixos-test-read-proxy] server # [ 1.453137] NetLabel: Initializing
  646. 32.55 s [vm-test-run-nixos-test-read-proxy] server # [ 1.454409] NetLabel: domain hash size = 128
  647. 32.55 s [vm-test-run-nixos-test-read-proxy] server # [ 1.455409] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO
  648. 32.56 s [vm-test-run-nixos-test-read-proxy] server # [ 1.456742] NetLabel: unlabeled traffic allowed by default
  649. 32.56 s [vm-test-run-nixos-test-read-proxy] server # [ 1.458528] PCI: Using ACPI for IRQ routing
  650. 32.56 s [vm-test-run-nixos-test-read-proxy] server # [ 1.462093] pci 0000:00:02.0: vgaarb: setting as boot VGA device
  651. 32.57 s [vm-test-run-nixos-test-read-proxy] server # [ 1.462400] pci 0000:00:02.0: vgaarb: bridge control possible
  652. 32.57 s [vm-test-run-nixos-test-read-proxy] server # [ 1.462400] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
  653. 32.57 s [vm-test-run-nixos-test-read-proxy] server # [ 1.462414] vgaarb: loaded
  654. 32.58 s [vm-test-run-nixos-test-read-proxy] server # [ 1.465529] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
  655. 32.58 s [vm-test-run-nixos-test-read-proxy] server # [ 1.467412] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
  656. 32.59 s [vm-test-run-nixos-test-read-proxy] server # [ 1.473960] clocksource: Switched to clocksource kvm-clock
  657. 32.61 s [vm-test-run-nixos-test-read-proxy] server # [ 1.499641] VFS: Disk quotas dquot_6.6.0
  658. 32.62 s [vm-test-run-nixos-test-read-proxy] server # [ 1.501813] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
  659. 32.62 s [vm-test-run-nixos-test-read-proxy] server # [ 1.507842] pnp: PnP ACPI init
  660. 32.63 s [vm-test-run-nixos-test-read-proxy] server # [ 1.511491] pnp: PnP ACPI: found 6 devices
  661. 32.65 s [vm-test-run-nixos-test-read-proxy] server # [ 1.530359] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
  662. 32.65 s [vm-test-run-nixos-test-read-proxy] server # [ 1.534387] clocksource: Switched to clocksource acpi_pm
  663. 32.65 s [vm-test-run-nixos-test-read-proxy] server # [ 1.537627] NET: Registered PF_INET protocol family
  664. 32.66 s [vm-test-run-nixos-test-read-proxy] server # [ 1.541133] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
  665. 32.76 s [vm-test-run-nixos-test-read-proxy] server # [ 1.641479] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)
  666. 32.76 s [vm-test-run-nixos-test-read-proxy] server # [ 1.647417] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
  667. 32.77 s [vm-test-run-nixos-test-read-proxy] server # [ 1.651617] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)
  668. 32.77 s [vm-test-run-nixos-test-read-proxy] server # [ 1.655783] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)
  669. 32.78 s [vm-test-run-nixos-test-read-proxy] server # [ 1.659597] TCP: Hash tables configured (established 8192 bind 8192)
  670. 32.78 s [vm-test-run-nixos-test-read-proxy] server # [ 1.663919] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)
  671. 32.78 s [vm-test-run-nixos-test-read-proxy] server # [ 1.668367] UDP hash table entries: 512 (order: 3, 32768 bytes, linear)
  672. 32.79 s [vm-test-run-nixos-test-read-proxy] server # [ 1.672301] UDP-Lite hash table entries: 512 (order: 3, 32768 bytes, linear)
  673. 32.79 s [vm-test-run-nixos-test-read-proxy] server # [ 1.676488] NET: Registered PF_UNIX/PF_LOCAL protocol family
  674. 32.79 s [vm-test-run-nixos-test-read-proxy] server # [ 1.679711] NET: Registered PF_XDP protocol family
  675. 32.80 s [vm-test-run-nixos-test-read-proxy] server # [ 1.682380] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]
  676. 32.80 s [vm-test-run-nixos-test-read-proxy] server # [ 1.685792] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]
  677. 32.81 s [vm-test-run-nixos-test-read-proxy] server # [ 1.689267] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
  678. 32.81 s [vm-test-run-nixos-test-read-proxy] server # [ 1.693216] pci_bus 0000:00: resource 7 [mem 0x40000000-0xfebfffff window]
  679. 32.81 s [vm-test-run-nixos-test-read-proxy] server # [ 1.697260] pci_bus 0000:00: resource 8 [mem 0x100000000-0x17fffffff window]
  680. 32.82 s [vm-test-run-nixos-test-read-proxy] server # [ 1.702021] pci 0000:00:01.0: PIIX3: Enabling Passive Release
  681. 32.82 s [vm-test-run-nixos-test-read-proxy] server # [ 1.705753] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
  682. 32.83 s [vm-test-run-nixos-test-read-proxy] server # [ 1.712967] ACPI: \_SB_.LNKD: Enabled at IRQ 11
  683. 32.83 s [vm-test-run-nixos-test-read-proxy] server # [ 1.718505] PCI: CLS 0 bytes, default 64
  684. 32.84 s [vm-test-run-nixos-test-read-proxy] server # [ 1.722502] Trying to unpack rootfs image as initramfs...
  685. 32.84 s [vm-test-run-nixos-test-read-proxy] server # [ 1.726250] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x31024cfe468, max_idle_ns: 440795307017 ns
  686. 32.90 s [vm-test-run-nixos-test-read-proxy] server # [ 1.781244] Initialise system trusted keyrings
  687. 32.91 s [vm-test-run-nixos-test-read-proxy] server # [ 1.789151] workingset: timestamp_bits=40 max_order=18 bucket_order=0
  688. 32.94 s [vm-test-run-nixos-test-read-proxy] server # [ 1.820345] Key type asymmetric registered
  689. 32.94 s [vm-test-run-nixos-test-read-proxy] server # [ 1.824660] Asymmetric key parser 'x509' registered
  690. 32.94 s [vm-test-run-nixos-test-read-proxy] server # [ 1.827294] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 248)
  691. 32.96 s [vm-test-run-nixos-test-read-proxy] server # [ 1.840730] io scheduler mq-deadline registered
  692. 32.96 s [vm-test-run-nixos-test-read-proxy] server # [ 1.846606] io scheduler kyber registered
  693. 32.97 s [vm-test-run-nixos-test-read-proxy] server # [ 1.857668] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
  694. 32.98 s [vm-test-run-nixos-test-read-proxy] server # [ 1.866786] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
  695. 33.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.880681] Linux agpgart interface v0.103
  696. 33.01 s [vm-test-run-nixos-test-read-proxy] server # [ 1.887763] ACPI: bus type drm_connector registered
  697. 33.01 s [vm-test-run-nixos-test-read-proxy] server # [ 1.895176] usbcore: registered new interface driver usbserial_generic
  698. 33.02 s [vm-test-run-nixos-test-read-proxy] server # [ 1.903798] usbserial: USB Serial support registered for generic
  699. 33.03 s [vm-test-run-nixos-test-read-proxy] server # [ 1.909627] amd_pstate: the _CPC object is not present in SBIOS or ACPI disabled
  700. 33.03 s [vm-test-run-nixos-test-read-proxy] server # [ 1.919115] drop_monitor: Initializing network drop monitor service
  701. 33.04 s [vm-test-run-nixos-test-read-proxy] server # [ 1.925911] NET: Registered PF_INET6 protocol family
  702. 33.05 s [vm-test-run-nixos-test-read-proxy] server # [ 1.936398] Segment Routing with IPv6
  703. 33.06 s [vm-test-run-nixos-test-read-proxy] server # [ 1.940751] In-situ OAM (IOAM) with IPv6
  704. 33.06 s [vm-test-run-nixos-test-read-proxy] server # [ 1.947759] IPI shorthand broadcast: enabled
  705. 33.08 s [vm-test-run-nixos-test-read-proxy] server # [ 1.966924] registered taskstats version 1
  706. 33.09 s [vm-test-run-nixos-test-read-proxy] server # [ 1.972319] Loading compiled-in X.509 certificates
  707. 33.14 s [vm-test-run-nixos-test-read-proxy] server # [ 2.022946] Demotion targets for Node 0: null
  708. 33.14 s [vm-test-run-nixos-test-read-proxy] server # [ 2.029923] Key type .fscrypt registered
  709. 33.15 s [vm-test-run-nixos-test-read-proxy] server # [ 2.034624] Key type fscrypt-provisioning registered
  710. 33.15 s [vm-test-run-nixos-test-read-proxy] server # [ 2.037306] ima: No TPM chip found, activating TPM-bypass!
  711. 33.16 s [vm-test-run-nixos-test-read-proxy] server # [ 2.044598] ima: Allocated hash algorithm: sha1
  712. 33.16 s [vm-test-run-nixos-test-read-proxy] server # [ 2.047120] ima: No architecture policies found
  713. 33.17 s [vm-test-run-nixos-test-read-proxy] server # [ 2.054635] PM: Magic number: 2:181:989
  714. 33.18 s [vm-test-run-nixos-test-read-proxy] server # [ 2.060056] RAS: Correctable Errors collector initialized.
  715. 33.19 s [vm-test-run-nixos-test-read-proxy] server # [ 2.073681] Unstable clock detected, switching default tracing clock to "global"
  716. 33.19 s [vm-test-run-nixos-test-read-proxy] server # [ 2.073681] If you want to keep using the local clock, then add:
  717. 33.19 s [vm-test-run-nixos-test-read-proxy] server # [ 2.073681] "trace_clock=local"
  718. 33.20 s [vm-test-run-nixos-test-read-proxy] server # [ 2.073681] on the kernel command line
  719. 33.21 s [vm-test-run-nixos-test-read-proxy] server # [ 2.097064] clk: Disabling unused clocks
  720. 33.22 s [vm-test-run-nixos-test-read-proxy] server # [ 2.101703] PM: genpd: Disabling unused power domains
  721. 34.60 s [vm-test-run-nixos-test-read-proxy] server # [ 3.480247] Freeing initrd memory: 29496K
  722. 34.62 s [vm-test-run-nixos-test-read-proxy] server # [ 3.503220] Freeing unused decrypted memory: 2028K
  723. 34.65 s [vm-test-run-nixos-test-read-proxy] server # [ 3.532998] Freeing unused kernel image (initmem) memory: 3636K
  724. 34.65 s [vm-test-run-nixos-test-read-proxy] server # [ 3.537426] Write protecting the kernel read-only data: 32768k
  725. 34.67 s [vm-test-run-nixos-test-read-proxy] server # [ 3.554058] Freeing unused kernel image (text/rodata gap) memory: 1272K
  726. 34.68 s [vm-test-run-nixos-test-read-proxy] server # [ 3.568060] Freeing unused kernel image (rodata/data gap) memory: 796K
  727. 34.73 s [vm-test-run-nixos-test-read-proxy] server # [ 3.617049] x86/mm: Checked W+X mappings: passed, no W+X pages found.
  728. 34.73 s [vm-test-run-nixos-test-read-proxy] server # [ 3.620410] Run /init as init process
  729. 34.78 s [vm-test-run-nixos-test-read-proxy] server # [ 3.666150] systemd[1]: Inserted module 'autofs4'
  730. 34.80 s [vm-test-run-nixos-test-read-proxy] server # [ 3.690177] fuse: init (API version 7.45)
  731. 34.81 s [vm-test-run-nixos-test-read-proxy] server # [ 3.699404] ACPI: \_SB_.LNKC: Enabled at IRQ 10
  732. 34.83 s [vm-test-run-nixos-test-read-proxy] server # [ 3.712326] ACPI: \_SB_.LNKA: Enabled at IRQ 10
  733. 34.83 s [vm-test-run-nixos-test-read-proxy] server # [ 3.718622] ACPI: \_SB_.LNKB: Enabled at IRQ 11
  734. 34.90 s [vm-test-run-nixos-test-read-proxy] server # [ 3.789423] systemd[1]: Successfully made /usr/ read-only.
  735. 35.26 s [vm-test-run-nixos-test-read-proxy] server # [ 4.129223] systemd[1]: systemd 261 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)
  736. 35.26 s [vm-test-run-nixos-test-read-proxy] server # [ 4.143242] systemd[1]: Detected virtualization kvm.
  737. 35.26 s [vm-test-run-nixos-test-read-proxy] server # [ 4.145955] systemd[1]: Detected architecture x86-64.
  738. 35.26 s [vm-test-run-nixos-test-read-proxy] server # [ 4.148631] systemd[1]: Running in initrd.
  739. 35.27 s [vm-test-run-nixos-test-read-proxy] server # [ 4.151285] systemd[1]: Initializing machine ID from random generator.
  740. 35.27 s [vm-test-run-nixos-test-read-proxy] server # [ 4.154818] systemd[1]: Hostname set to <server>.
  741. 35.54 s [vm-test-run-nixos-test-read-proxy] server # [ 4.427984] systemd[1]: bpf-restrict-fs: LSM BPF program attached
  742. 35.59 s [vm-test-run-nixos-test-read-proxy] server # [ 4.473955] systemd[1]: Queued start job for default target Initrd Default Target.
  743. 35.60 s [vm-test-run-nixos-test-read-proxy] server # [ 4.483694] systemd[1]: Created slice Slice /system/modprobe.
  744. 35.60 s [vm-test-run-nixos-test-read-proxy] server # [ 4.486787] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
  745. 35.61 s [vm-test-run-nixos-test-read-proxy] server # [ 4.490670] systemd[1]: Expecting device /dev/disk/by-label/nixos...
  746. 35.61 s [vm-test-run-nixos-test-read-proxy] server # [ 4.493699] systemd[1]: Reached target Path Units.
  747. 35.61 s [vm-test-run-nixos-test-read-proxy] server # [ 4.496060] systemd[1]: Reached target Slice Units.
  748. 35.61 s [vm-test-run-nixos-test-read-proxy] server # [ 4.498923] systemd[1]: Reached target Swaps.
  749. 35.62 s [vm-test-run-nixos-test-read-proxy] server # [ 4.501181] systemd[1]: Reached target Timer Units.
  750. 35.62 s [vm-test-run-nixos-test-read-proxy] server # [ 4.503822] systemd[1]: Listening on D-Bus System Message Bus Socket.
  751. 35.62 s [vm-test-run-nixos-test-read-proxy] server # [ 4.507025] systemd[1]: Listening on Journal Socket (/dev/log).
  752. 35.63 s [vm-test-run-nixos-test-read-proxy] server # [ 4.510188] systemd[1]: Listening on Journal Sockets.
  753. 35.63 s [vm-test-run-nixos-test-read-proxy] server # [ 4.512884] systemd[1]: Listening on udev Control Socket.
  754. 35.63 s [vm-test-run-nixos-test-read-proxy] server # [ 4.515740] systemd[1]: Listening on udev Kernel Socket.
  755. 35.63 s [vm-test-run-nixos-test-read-proxy] server # [ 4.518334] systemd[1]: Reached target Socket Units.
  756. 35.64 s [vm-test-run-nixos-test-read-proxy] server # [ 4.522332] systemd[1]: Starting Create List of Static Device Nodes...
  757. 35.65 s [vm-test-run-nixos-test-read-proxy] server # [ 4.532829] systemd[1]: Starting Load Kernel Module 9pnet_virtio...
  758. 35.66 s [vm-test-run-nixos-test-read-proxy] server # [ 4.547863] systemd[1]: Starting Load Kernel Module configfs...
  759. 35.69 s [vm-test-run-nixos-test-read-proxy] server # [ 4.573725] systemd[1]: Starting Journal Service...
  760. 35.70 s [vm-test-run-nixos-test-read-proxy] server # [ 4.581899] netfs: FS-Cache loaded
  761. 35.71 s [vm-test-run-nixos-test-read-proxy] server # [ 4.590897] systemd[1]: Starting Load Kernel Modules...
  762. 35.72 s [vm-test-run-nixos-test-read-proxy] server # [ 4.601916] 9pnet: Installing 9P2000 support
  763. 35.73 s [vm-test-run-nixos-test-read-proxy] server # [ 4.608223] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os
  764. 35.74 s [vm-test-run-nixos-test-read-proxy] server # [ 4.621087] systemd-journald[68]: Collecting audit messages is disabled.
  765. 35.75 s [vm-test-run-nixos-test-read-proxy] server # [ 4.631964] systemd[1]: Starting Coldplug All udev Devices...
  766. 35.78 s [vm-test-run-nixos-test-read-proxy] server # [ 4.657325] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log.
  767. 35.78 s [vm-test-run-nixos-test-read-proxy] server # [ 4.663893] systemd[1]: Finished Create List of Static Device Nodes.
  768. 35.80 s [vm-test-run-nixos-test-read-proxy] server # [ 4.672130] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.
  769. 35.82 s [vm-test-run-nixos-test-read-proxy] server # [ 4.705634] device-mapper: ioctl: 4.50.0-ioctl (2025-04-28) initialised: dm-devel@lists.linux.dev
  770. 35.85 s [vm-test-run-nixos-test-read-proxy] server # [ 4.735655] systemd[1]: Finished Load Kernel Module 9pnet_virtio.
  771. 35.86 s [vm-test-run-nixos-test-read-proxy] server # [ 4.747235] systemd[1]: modprobe@configfs.service: Deactivated successfully.
  772. 35.88 s [vm-test-run-nixos-test-read-proxy] server # [ 4.761755] systemd[1]: Finished Load Kernel Module configfs.
  773. 35.89 s [vm-test-run-nixos-test-read-proxy] server # [ 4.774786] systemd[1]: Finished Load Kernel Modules.
  774. 35.90 s [vm-test-run-nixos-test-read-proxy] server # [ 4.786864] systemd[1]: Kernel Configuration File System skipped, unmet condition check ConditionPathExists=/sys/kernel/config
  775. 35.92 s [vm-test-run-nixos-test-read-proxy] server # [ 4.807990] systemd[1]: Starting Apply Kernel Variables...
  776. 35.94 s [vm-test-run-nixos-test-read-proxy] server # [ 4.131554] systemd-modules-load[69]: Inserted module 'dm_mod'
  777. 35.94 s [vm-test-run-nixos-test-read-proxy] server # [ 4.139756] systemd-modules-load[69]: Inserted module 'virtio_balloon'
  778. 35.95 s [vm-test-run-nixos-test-read-proxy] server # [ 4.833736] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...
  779. 35.95 s [vm-test-run-nixos-test-read-proxy] server # [ 4.150603] systemd-modules-load[69]: Inserted module 'virtio_gpu'
  780. 35.97 s [vm-test-run-nixos-test-read-proxy] server # [ 4.857047] systemd[1]: Started Journal Service.
  781. 35.99 s [vm-test-run-nixos-test-read-proxy] server # [ 4.183225] systemd[1]: Finished Apply Kernel Variables.
  782. 36.00 s [vm-test-run-nixos-test-read-proxy] server # [ 4.194445] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
  783. 36.01 s [vm-test-run-nixos-test-read-proxy] server # [ 4.202186] systemd[1]: Starting Create Static Device Nodes in /dev...
  784. 36.03 s [vm-test-run-nixos-test-read-proxy] server # [ 4.225457] systemd[1]: Finished Create Static Device Nodes in /dev.
  785. 36.03 s [vm-test-run-nixos-test-read-proxy] server # [ 4.229539] systemd[1]: Reached target Preparation for Local File Systems.
  786. 36.04 s [vm-test-run-nixos-test-read-proxy] server # [ 4.235395] systemd[1]: Reached target Local File Systems.
  787. 36.04 s [vm-test-run-nixos-test-read-proxy] server # [ 4.240467] systemd[1]: Starting Create System Files and Directories...
  788. 36.05 s [vm-test-run-nixos-test-read-proxy] server # [ 4.246378] systemd[1]: Starting Rule-based Manager for Device Events and Files...
  789. 36.08 s [vm-test-run-nixos-test-read-proxy] server # [ 4.277796] systemd[1]: Finished Create System Files and Directories.
  790. 36.10 s [vm-test-run-nixos-test-read-proxy] server # [ 4.299385] systemd-udevd[83]: Using default interface naming scheme 'v261'.
  791. 36.13 s [vm-test-run-nixos-test-read-proxy] server # [ 4.330312] systemd[1]: Finished Coldplug All udev Devices.
  792. 36.26 s [vm-test-run-nixos-test-read-proxy] server # [ 4.339187] systemd[1]: Started Rule-based Manager for Device Events and Files.
  793. 36.26 s [vm-test-run-nixos-test-read-proxy] server # [ 4.341850] systemd[1]: Reached target System Initialization.
  794. 36.26 s [vm-test-run-nixos-test-read-proxy] server # [ 4.346343] systemd[1]: Reached target Basic System.
  795. 36.49 s [vm-test-run-nixos-test-read-proxy] server # [ 5.370226] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
  796. 36.51 s [vm-test-run-nixos-test-read-proxy] server # [ 5.393818] virtio_blk virtio5: 1/0/0 default/read/poll queues
  797. 36.53 s [vm-test-run-nixos-test-read-proxy] server # [ 5.410803] serio: i8042 KBD port at 0x60,0x64 irq 1
  798. 36.53 s [vm-test-run-nixos-test-read-proxy] server # [ 5.414701] uhci_hcd 0000:00:01.2: UHCI Host Controller
  799. 36.53 s [vm-test-run-nixos-test-read-proxy] server # [ 5.416710] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
  800. 36.55 s [vm-test-run-nixos-test-read-proxy] server # [ 5.432338] SCSI subsystem initialized
  801. 36.55 s [vm-test-run-nixos-test-read-proxy] server # [ 5.436605] serio: i8042 AUX port at 0x60,0x64 irq 12
  802. 36.56 s [vm-test-run-nixos-test-read-proxy] server # [ 5.448227] uhci_hcd 0000:00:01.2: detected 2 ports
  803. 36.57 s [vm-test-run-nixos-test-read-proxy] server # [ 5.453703] virtio_blk virtio5: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)
  804. 36.59 s [vm-test-run-nixos-test-read-proxy] server # [ 5.471221] uhci_hcd 0000:00:01.2: irq 11, io port 0x0000c100
  805. 36.62 s [vm-test-run-nixos-test-read-proxy] server # [ 5.500353] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 6.18
  806. 36.64 s [vm-test-run-nixos-test-read-proxy] server # [ 5.526631] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
  807. 36.66 s [vm-test-run-nixos-test-read-proxy] server # [ 4.859875] systemd[1]: Starting Virtual Console Setup...
  808. 36.67 s [vm-test-run-nixos-test-read-proxy] server # [ 5.553976] usb usb1: Product: UHCI Host Controller
  809. 36.71 s [vm-test-run-nixos-test-read-proxy] server # [ 4.901944] systemd-vconsole-setup[99]: Configuration of first virtual console was skipped, ignoring remaining ones.
  810. 36.72 s [vm-test-run-nixos-test-read-proxy] server # [ 4.913984] (udev-worker)[87]: [0;1;38:5:185meth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.
  811. 36.72 s [vm-test-run-nixos-test-read-proxy] server # [ 5.608783] usb usb1: Manufacturer: Linux 6.18.38 uhci_hcd
  812. 36.73 s [vm-test-run-nixos-test-read-proxy] server # [ 5.610799] usb usb1: SerialNumber: 0000:00:01.2
  813. 36.73 s [vm-test-run-nixos-test-read-proxy] server # [ 4.928833] (udev-worker)[87]: Network interface NamePolicy= disabled on kernel command line.
  814. 36.74 s [vm-test-run-nixos-test-read-proxy] server # [ 4.934732] systemd[1]: Finished Virtual Console Setup.
  815. 36.74 s [vm-test-run-nixos-test-read-proxy] server # [ 4.940233] (udev-worker)[91]: Network interface NamePolicy= disabled on kernel command line.
  816. 36.75 s [vm-test-run-nixos-test-read-proxy] server # [ 5.632424] hub 1-0:1.0: USB hub found
  817. 36.76 s [vm-test-run-nixos-test-read-proxy] server # [ 5.644014] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
  818. 36.76 s [vm-test-run-nixos-test-read-proxy] server # [ 5.647486] hub 1-0:1.0: 2 ports detected
  819. 36.82 s [vm-test-run-nixos-test-read-proxy] server # [ 5.709952] scsi host0: ata_piix
  820. 36.83 s [vm-test-run-nixos-test-read-proxy] server # [ 5.715871] scsi host1: ata_piix
  821. 36.83 s [vm-test-run-nixos-test-read-proxy] server # [ 5.718960] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc1e0 irq 14 lpm-pol 0
  822. 36.84 s [vm-test-run-nixos-test-read-proxy] server # [ 5.724339] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc1e8 irq 15 lpm-pol 0
  823. 36.85 s [vm-test-run-nixos-test-read-proxy] server # [ 5.051244] systemd[1]: Found device /dev/disk/by-label/nixos.
  824. 36.86 s [vm-test-run-nixos-test-read-proxy] server # [ 5.053704] systemd[1]: Reached target Initrd Root Device.
  825. 36.86 s [vm-test-run-nixos-test-read-proxy] server # [ 5.058266] systemd[1]: Starting File System Check on /dev/disk/by-label/nixos...
  826. 36.88 s [vm-test-run-nixos-test-read-proxy] server # [ 5.080421] systemd-fsck[111]: nixos: clean, 12/65536 files, 13019/262144 blocks
  827. 36.91 s [vm-test-run-nixos-test-read-proxy] server # [ 5.102718] systemd[1]: Finished File System Check on /dev/disk/by-label/nixos.
  828. 36.92 s [vm-test-run-nixos-test-read-proxy] server # [ 5.113971] systemd[1]: Mounting /sysroot...
  829. 36.99 s [vm-test-run-nixos-test-read-proxy] server # [ 5.874753] usb 1-1: new full-speed USB device number 2 using uhci_hcd
  830. 37.00 s [vm-test-run-nixos-test-read-proxy] server # [ 5.883659] ata2: found unknown device (class 0)
  831. 37.00 s [vm-test-run-nixos-test-read-proxy] server # [ 5.887210] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100
  832. 37.01 s [vm-test-run-nixos-test-read-proxy] server # [ 5.893093] scsi 1:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5
  833. 37.07 s [vm-test-run-nixos-test-read-proxy] server # [ 5.954316] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray
  834. 37.09 s [vm-test-run-nixos-test-read-proxy] server # [ 5.977269] cdrom: Uniform CD-ROM driver Revision: 3.20
  835. 37.12 s [vm-test-run-nixos-test-read-proxy] server # [ 6.007137] EXT4-fs (vda): mounted filesystem d3a20e6f-1204-4d5b-b42b-cb41f4d4d8ce r/w with ordered data mode. Quota mode: none.
  836. 37.13 s [vm-test-run-nixos-test-read-proxy] server # [ 5.330212] systemd[1]: Mounted /sysroot.
  837. 37.14 s [vm-test-run-nixos-test-read-proxy] server # [ 5.333194] systemd[1]: Reached target Initrd Root File System.
  838. 37.14 s [vm-test-run-nixos-test-read-proxy] server # [ 5.338329] systemd[1]: Starting Mountpoints Configured in the Real Root...
  839. 37.16 s [vm-test-run-nixos-test-read-proxy] server # [ 6.047290] usb 1-1: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00
  840. 37.17 s [vm-test-run-nixos-test-read-proxy] server # [ 5.361883] systemd-sysroot-fstab-check[123]: /sysroot should be mounted in the initrd, will request daemon-reload.
  841. 37.17 s [vm-test-run-nixos-test-read-proxy] server # [ 6.055615] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=10
  842. 37.17 s [vm-test-run-nixos-test-read-proxy] server # [ 5.370112] systemd[1]: Reload requested from client PID 123 ('systemd-sysroot') (unit initrd-parse-etc.service)...
  843. 37.18 s [vm-test-run-nixos-test-read-proxy] server # [ 5.376767] systemd[1]: Reloading...
  844. 37.18 s [vm-test-run-nixos-test-read-proxy] server # [ 6.067826] usb 1-1: Product: QEMU USB Tablet
  845. 37.18 s [vm-test-run-nixos-test-read-proxy] server # [ 6.069466] usb 1-1: Manufacturer: QEMU
  846. 37.19 s [vm-test-run-nixos-test-read-proxy] server # [ 6.074625] usb 1-1: SerialNumber: 28754-0000:00:01.2-1
  847. 37.24 s [vm-test-run-nixos-test-read-proxy] server # [ 6.120400] hid: raw HID events driver (C) Jiri Kosina
  848. 37.26 s [vm-test-run-nixos-test-read-proxy] server # [ 6.143168] usbcore: registered new interface driver usbhid
  849. 37.27 s [vm-test-run-nixos-test-read-proxy] server # [ 6.151166] usbhid: USB HID core driver
  850. 37.28 s [vm-test-run-nixos-test-read-proxy] server # [ 6.166484] 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
  851. 37.30 s [vm-test-run-nixos-test-read-proxy] server # [ 6.182669] 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
  852. 37.34 s [vm-test-run-nixos-test-read-proxy] server # [ 5.538585] systemd[1]: Reloading finished in 171 ms.
  853. 37.37 s [vm-test-run-nixos-test-read-proxy] server # [ 5.559976] systemd-sysroot-fstab-check[123]: Requesting initrd-fs.target/start/replace...
  854. 37.38 s [vm-test-run-nixos-test-read-proxy] server # [ 5.572354] systemd[1]: Load Kernel Module 9pnet_virtio skipped, unmet condition check ConditionKernelModuleLoaded=!9pnet_virtio
  855. 37.38 s [vm-test-run-nixos-test-read-proxy] server # [ 5.579444] systemd-sysroot-fstab-check[123]: Requesting swap.target/start/replace...
  856. 37.39 s [vm-test-run-nixos-test-read-proxy] server # [ 5.582566] systemd[1]: initrd-parse-etc.service: Deactivated successfully.
  857. 37.39 s [vm-test-run-nixos-test-read-proxy] server # [ 5.584774] systemd[1]: Finished Mountpoints Configured in the Real Root.
  858. 37.39 s [vm-test-run-nixos-test-read-proxy] server # [ 5.586884] systemd[1]: initrd-parse-etc.service: Triggering OnSuccess= dependencies.
  859. 37.77 s [vm-test-run-nixos-test-read-proxy] server # [ 5.969217] systemd[1]: Mounting /sysroot/nix/.ro-store...
  860. 37.78 s [vm-test-run-nixos-test-read-proxy] server # [ 5.976168] systemd[1]: Mounting /sysroot/nix/.rw-store...
  861. 37.78 s [vm-test-run-nixos-test-read-proxy] server # [ 5.981263] systemd[1]: Mounting /sysroot/run...
  862. 37.79 s [vm-test-run-nixos-test-read-proxy] server # [ 5.987487] systemd[1]: Mounting /sysroot/tmp/shared...
  863. 37.81 s [vm-test-run-nixos-test-read-proxy] server # [ 6.005865] systemd[1]: Mounting /sysroot/tmp/xchg...
  864. 37.81 s [vm-test-run-nixos-test-read-proxy] server # [ 6.698270] 9p: Installing v9fs 9p2000 file system support
  865. 37.83 s [vm-test-run-nixos-test-read-proxy] server # [ 6.026657] systemd[1]: Mounted /sysroot/nix/.ro-store.
  866. 37.83 s [vm-test-run-nixos-test-read-proxy] server # [ 6.028786] systemd[1]: Mounted /sysroot/nix/.rw-store.
  867. 37.84 s [vm-test-run-nixos-test-read-proxy] server # [ 6.037890] systemd[1]: Starting rw-sysroot-nix-store.service...
  868. 37.84 s [vm-test-run-nixos-test-read-proxy] server # [ 6.042344] systemd[1]: Mounted /sysroot/run.
  869. 37.85 s [vm-test-run-nixos-test-read-proxy] server # [ 6.045410] systemd[1]: Mounted /sysroot/tmp/shared.
  870. 37.86 s [vm-test-run-nixos-test-read-proxy] server # [ 6.058690] systemd[1]: Mounted /sysroot/tmp/xchg.
  871. 37.87 s [vm-test-run-nixos-test-read-proxy] server # [ 6.064776] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.
  872. 37.87 s [vm-test-run-nixos-test-read-proxy] server # [ 6.069924] systemd[1]: Finished rw-sysroot-nix-store.service.
  873. 37.88 s [vm-test-run-nixos-test-read-proxy] server # [ 6.074623] systemd[1]: Mounting /sysroot/nix/store...
  874. 37.90 s [vm-test-run-nixos-test-read-proxy] server # [ 6.093784] systemd[1]: Mounted /sysroot/nix/store.
  875. 37.90 s [vm-test-run-nixos-test-read-proxy] server # [ 6.097253] systemd[1]: Reached target Initrd File Systems.
  876. 37.90 s [vm-test-run-nixos-test-read-proxy] server # [ 6.100397] systemd[1]: Starting Find NixOS closure...
  877. 37.91 s [vm-test-run-nixos-test-read-proxy] server # [ 6.106261] systemd[1]: Starting Create Volatile Files and Directories in the Real Root...
  878. 37.93 s [vm-test-run-nixos-test-read-proxy] server # [ 6.126419] systemd[1]: Finished Create Volatile Files and Directories in the Real Root.
  879. 37.94 s [vm-test-run-nixos-test-read-proxy] server # [ 6.138419] systemd[1]: Finished Find NixOS closure.
  880. 37.94 s [vm-test-run-nixos-test-read-proxy] server # [ 6.140949] systemd[1]: Reached target Initrd Default Target.
  881. 37.95 s [vm-test-run-nixos-test-read-proxy] server # [ 6.144195] systemd[1]: Starting Cleaning Up and Shutting Down Daemons...
  882. 37.97 s [vm-test-run-nixos-test-read-proxy] server # [ 6.162200] systemd[1]: Stopped target Initrd Default Target.
  883. 37.97 s [vm-test-run-nixos-test-read-proxy] server # [ 6.165601] systemd[1]: Stopped target Basic System.
  884. 37.97 s [vm-test-run-nixos-test-read-proxy] server # [ 6.169587] systemd[1]: Stopped target Initrd Root Device.
  885. 37.98 s [vm-test-run-nixos-test-read-proxy] server # [ 6.173423] systemd[1]: Stopped target Path Units.
  886. 37.98 s [vm-test-run-nixos-test-read-proxy] server # [ 6.177345] systemd[1]: systemd-ask-password-console.path: Deactivated successfully.
  887. 37.99 s [vm-test-run-nixos-test-read-proxy] server # [ 6.183518] systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.
  888. 37.99 s [vm-test-run-nixos-test-read-proxy] server # [ 6.191416] systemd[1]: Stopped target Slice Units.
  889. 38.00 s [vm-test-run-nixos-test-read-proxy] server # [ 6.198250] systemd[1]: Stopped target Socket Units.
  890. 38.01 s [vm-test-run-nixos-test-read-proxy] server # [ 6.204505] systemd[1]: Stopped target System Initialization.
  891. 38.01 s [vm-test-run-nixos-test-read-proxy] server # [ 6.208583] systemd[1]: Stopped target Swaps.
  892. 38.01 s [vm-test-run-nixos-test-read-proxy] server # [ 6.211469] systemd[1]: Stopped target Timer Units.
  893. 38.02 s [vm-test-run-nixos-test-read-proxy] server # [ 6.215550] systemd[1]: dbus.socket: Deactivated successfully.
  894. 38.02 s [vm-test-run-nixos-test-read-proxy] server # [ 6.219455] systemd[1]: Closed D-Bus System Message Bus Socket.
  895. 38.03 s [vm-test-run-nixos-test-read-proxy] server # [ 6.223436] systemd[1]: initrd-find-nixos-closure.service: Deactivated successfully.
  896. 38.03 s [vm-test-run-nixos-test-read-proxy] server # [ 6.228319] systemd[1]: Stopped Find NixOS closure.
  897. 38.03 s [vm-test-run-nixos-test-read-proxy] server # [ 6.230388] systemd[1]: Load Kernel Module 9pnet_virtio skipped, unmet condition check ConditionKernelModuleLoaded=!9pnet_virtio
  898. 38.04 s [vm-test-run-nixos-test-read-proxy] server # [ 6.233419] systemd[1]: Starting rw-sysroot-nix-store.service...
  899. 38.04 s [vm-test-run-nixos-test-read-proxy] server # [ 6.237947] systemd[1]: systemd-sysctl.service: Deactivated successfully.
  900. 38.04 s [vm-test-run-nixos-test-read-proxy] server # [ 6.241424] systemd[1]: Stopped Apply Kernel Variables.
  901. 38.05 s [vm-test-run-nixos-test-read-proxy] server # [ 6.244609] systemd[1]: systemd-modules-load.service: Deactivated successfully.
  902. 38.05 s [vm-test-run-nixos-test-read-proxy] server # [ 6.250481] systemd[1]: Stopped Load Kernel Modules.
  903. 38.06 s [vm-test-run-nixos-test-read-proxy] server # [ 6.253294] systemd[1]: systemd-tmpfiles-setup-sysroot.service: Deactivated successfully.
  904. 38.06 s [vm-test-run-nixos-test-read-proxy] server # [ 6.258795] systemd[1]: Stopped Create Volatile Files and Directories in the Real Root.
  905. 38.07 s [vm-test-run-nixos-test-read-proxy] server # [ 6.263399] systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully.
  906. 38.07 s [vm-test-run-nixos-test-read-proxy] server # [ 6.265515] systemd[1]: Stopped Create System Files and Directories.
  907. 38.07 s [vm-test-run-nixos-test-read-proxy] server # [ 6.270230] systemd[1]: Stopped target Local File Systems.
  908. 38.08 s [vm-test-run-nixos-test-read-proxy] server # [ 6.273410] systemd[1]: Stopped target Preparation for Local File Systems.
  909. 38.08 s [vm-test-run-nixos-test-read-proxy] server # [ 6.278578] systemd[1]: systemd-udev-trigger.service: Deactivated successfully.
  910. 38.08 s [vm-test-run-nixos-test-read-proxy] server # [ 6.281448] systemd[1]: Stopped Coldplug All udev Devices.
  911. 38.09 s [vm-test-run-nixos-test-read-proxy] server # [ 6.283614] systemd[1]: Stopping Rule-based Manager for Device Events and Files...
  912. 38.09 s [vm-test-run-nixos-test-read-proxy] server # [ 6.285950] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
  913. 38.09 s [vm-test-run-nixos-test-read-proxy] server # [ 6.288360] systemd[1]: Stopped Virtual Console Setup.
  914. 38.09 s [vm-test-run-nixos-test-read-proxy] server # [ 6.290278] systemd[1]: initrd-cleanup.service: Deactivated successfully.
  915. 38.10 s [vm-test-run-nixos-test-read-proxy] server # [ 6.292511] systemd[1]: Finished Cleaning Up and Shutting Down Daemons.
  916. 38.10 s [vm-test-run-nixos-test-read-proxy] server # [ 6.295259] systemd[1]: systemd-udevd.service: Deactivated successfully.
  917. 38.10 s [vm-test-run-nixos-test-read-proxy] server # [ 6.297979] systemd[1]: Stopped Rule-based Manager for Device Events and Files.
  918. 38.10 s [vm-test-run-nixos-test-read-proxy] server # [ 6.300382] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.
  919. 38.11 s [vm-test-run-nixos-test-read-proxy] server # [ 6.302917] systemd[1]: Finished rw-sysroot-nix-store.service.
  920. 38.11 s [vm-test-run-nixos-test-read-proxy] server # [ 6.305232] systemd[1]: systemd-udevd-control.socket: Deactivated successfully.
  921. 38.11 s [vm-test-run-nixos-test-read-proxy] server # [ 6.307657] systemd[1]: Closed udev Control Socket.
  922. 38.11 s [vm-test-run-nixos-test-read-proxy] server # [ 6.309661] systemd[1]: Starting Cleanup udev Database...
  923. 38.12 s [vm-test-run-nixos-test-read-proxy] server # [ 6.311810] systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully.
  924. 38.12 s [vm-test-run-nixos-test-read-proxy] server # [ 6.314505] systemd[1]: Stopped Create Static Device Nodes in /dev.
  925. 38.12 s [vm-test-run-nixos-test-read-proxy] server # [ 6.316730] systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully.
  926. 38.12 s [vm-test-run-nixos-test-read-proxy] server # [ 6.319590] systemd[1]: Stopped Create Static Device Nodes in /dev gracefully.
  927. 38.13 s [vm-test-run-nixos-test-read-proxy] server # [ 6.322159] systemd[1]: kmod-static-nodes.service: Deactivated successfully.
  928. 38.13 s [vm-test-run-nixos-test-read-proxy] server # [ 6.324525] systemd[1]: Stopped Create List of Static Device Nodes.
  929. 38.13 s [vm-test-run-nixos-test-read-proxy] server # [ 6.326803] systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully.
  930. 38.13 s [vm-test-run-nixos-test-read-proxy] server # [ 6.329305] systemd[1]: Finished Cleanup udev Database.
  931. 38.13 s [vm-test-run-nixos-test-read-proxy] server # [ 6.331401] systemd[1]: Reached target Switch Root.
  932. 38.14 s [vm-test-run-nixos-test-read-proxy] server # [ 6.333386] systemd[1]: Starting NixOS Activation...
  933. 38.26 s [vm-test-run-nixos-test-read-proxy] server # [ 6.454786] initrd-nixos-activation-start[176]: booting system configuration /nix/store/awn88pbhvb6ywvfwjvpjjmkvi94hd9hx-nixos-system-server-test
  934. 38.32 s [vm-test-run-nixos-test-read-proxy] server # [ 6.517316] initrd-nixos-activation-start[176]: running activation script...
  935. 38.71 s [vm-test-run-nixos-test-read-proxy] server # [ 6.905992] initrd-nixos-activation-start[199]: setting up /etc...
  936. 38.95 s [vm-test-run-nixos-test-read-proxy] server # [ 7.148671] systemd[1]: initrd-nixos-activation.service: Deactivated successfully.
  937. 38.96 s [vm-test-run-nixos-test-read-proxy] server # [ 7.154501] systemd[1]: Finished NixOS Activation.
  938. 38.96 s [vm-test-run-nixos-test-read-proxy] server # [ 7.158344] systemd[1]: Starting Switch Root...
  939. 38.97 s [vm-test-run-nixos-test-read-proxy] server # [ 7.170814] systemd[1]: Switching root.
  940. 39.11 s [vm-test-run-nixos-test-read-proxy] server # [ 7.992358] systemd-journald[68]: Received SIGTERM from PID 1 (systemd).
  941. 39.30 s [vm-test-run-nixos-test-read-proxy] server # [ 8.188706] NET: Registered PF_VSOCK protocol family
  942. 39.69 s [vm-test-run-nixos-test-read-proxy] server # [ 8.572263] systemd[1]: systemd 261 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP +LIBARCHIVE)
  943. 39.70 s [vm-test-run-nixos-test-read-proxy] server # [ 8.581904] systemd[1]: Detected virtualization kvm.
  944. 39.70 s [vm-test-run-nixos-test-read-proxy] server # [ 8.583838] systemd[1]: Detected architecture x86-64.
  945. 39.70 s [vm-test-run-nixos-test-read-proxy] server # [ 8.585825] systemd[1]: Detected first boot.
  946. 39.70 s [vm-test-run-nixos-test-read-proxy] server # [ 8.589902] systemd[1]: Initializing machine ID from random generator.
  947. 39.94 s [vm-test-run-nixos-test-read-proxy] server # [ 8.828696] systemd[1]: bpf-restrict-fs: LSM BPF program attached
  948. 40.09 s [vm-test-run-nixos-test-read-proxy] server # [ 8.977363] systemd[1]: Applying preset policy.
  949. 40.59 s [vm-test-run-nixos-test-read-proxy] server # [ 9.471935] systemd[1]: Populated /etc with preset unit settings.
  950. 41.12 s [vm-test-run-nixos-test-read-proxy] server # [ 10.006659] systemd[1]: initrd-switch-root.service: Deactivated successfully.
  951. 41.13 s [vm-test-run-nixos-test-read-proxy] server # [ 10.014820] systemd[1]: Stopped initrd-switch-root.service.
  952. 41.14 s [vm-test-run-nixos-test-read-proxy] server # [ 10.019778] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1.
  953. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.024119] systemd[1]: Created slice Slice /system/getty.
  954. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.026952] systemd[1]: Created slice User and Session Slice.
  955. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.029196] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
  956. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.032153] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
  957. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.034832] systemd[1]: Expecting device /dev/hvc0...
  958. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.036737] systemd[1]: Expecting device /dev/ttyS0...
  959. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.038694] systemd[1]: Reached target Local Encrypted Volumes.
  960. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.040775] systemd[1]: Stopped target initrd-fs.target.
  961. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.043090] systemd[1]: Stopped target initrd-root-fs.target.
  962. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.045195] systemd[1]: Stopped target initrd-switch-root.target.
  963. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.047469] systemd[1]: Reached target Virtual Machines and Containers.
  964. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.049902] systemd[1]: Reached target Path Units.
  965. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.051822] systemd[1]: Reached target Remote File Systems.
  966. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.053927] systemd[1]: Reached target Slice Units.
  967. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.055861] systemd[1]: Reached target Swaps.
  968. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.060354] systemd[1]: Listening on Query the User Interactively for a Password.
  969. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.065862] systemd[1]: Listening on Process Core Dump Socket.
  970. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.070278] systemd[1]: Listening on Credential Encryption/Decryption.
  971. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.074685] systemd[1]: Listening on Factory Reset Management.
  972. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.076924] systemd[1]: Listening on Hostname Service Socket.
  973. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.082283] systemd[1]: Starting Journal Log Access Socket...
  974. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.085394] systemd[1]: Listening on Journal Audit Socket.
  975. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.090327] systemd[1]: Listening on Console Output Muting Service Socket.
  976. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.093246] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.
  977. 41.21 s [vm-test-run-nixos-test-read-proxy] server # [ 10.096404] systemd[1]: TPM PCR Measurements skipped, unmet condition check ConditionSecurity=measured-os
  978. 41.22 s [vm-test-run-nixos-test-read-proxy] server # [ 10.099724] systemd[1]: Make TPM PCR Policy skipped, unmet condition check ConditionSecurity=measured-uki
  979. 41.23 s [vm-test-run-nixos-test-read-proxy] server # [ 10.111321] systemd[1]: Listening on Disk Repartitioning Service Socket.
  980. 41.23 s [vm-test-run-nixos-test-read-proxy] server # [ 10.114107] systemd[1]: Listening on udev Control Socket.
  981. 41.23 s [vm-test-run-nixos-test-read-proxy] server # [ 10.116656] systemd[1]: Listening on udev Varlink Socket.
  982. 41.24 s [vm-test-run-nixos-test-read-proxy] server # [ 10.122229] systemd[1]: Mounting Huge Pages File System...
  983. 41.24 s [vm-test-run-nixos-test-read-proxy] server # [ 10.129796] systemd[1]: Mounting POSIX Message Queue File System...
  984. 41.25 s [vm-test-run-nixos-test-read-proxy] server # [ 10.139467] systemd[1]: Mounting Kernel Debug File System...
  985. 41.26 s [vm-test-run-nixos-test-read-proxy] server # [ 10.150040] systemd[1]: Mounting Kernel Trace File System...
  986. 41.28 s [vm-test-run-nixos-test-read-proxy] server # [ 10.160999] systemd[1]: Starting Create List of Static Device Nodes...
  987. 41.28 s [vm-test-run-nixos-test-read-proxy] server # [ 10.166234] systemd[1]: Load Kernel Module 9pnet_virtio skipped, unmet condition check ConditionKernelModuleLoaded=!9pnet_virtio
  988. 41.30 s [vm-test-run-nixos-test-read-proxy] server # [ 10.188224] systemd[1]: Starting Load Kernel Module configfs...
  989. 41.32 s [vm-test-run-nixos-test-read-proxy] server # [ 10.203289] systemd[1]: Load Kernel Module drm skipped, unmet condition check ConditionKernelModuleLoaded=!drm
  990. 41.33 s [vm-test-run-nixos-test-read-proxy] server # [ 10.218437] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore
  991. 41.34 s [vm-test-run-nixos-test-read-proxy] server # [ 10.223496] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse
  992. 41.35 s [vm-test-run-nixos-test-read-proxy] server # [ 10.236692] systemd[1]: Mounting FUSE Control File System...
  993. 41.36 s [vm-test-run-nixos-test-read-proxy] server # [ 10.239665] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67
  994. 41.37 s [vm-test-run-nixos-test-read-proxy] server # [ 10.256103] systemd[1]: Starting Journal Service...
  995. 41.38 s [vm-test-run-nixos-test-read-proxy] server # [ 10.268955] systemd[1]: Starting Load Kernel Modules...
  996. 41.40 s [vm-test-run-nixos-test-read-proxy] server # [ 10.289304] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...
  997. 41.42 s [vm-test-run-nixos-test-read-proxy] server # [ 10.309032] systemd[1]: Starting Remount Root and Kernel File Systems...
  998. 41.43 s [vm-test-run-nixos-test-read-proxy] server # [ 10.318927] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os
  999. 41.45 s [vm-test-run-nixos-test-read-proxy] server # [ 10.331408] systemd-journald[269]: Collecting audit messages is enabled.
  1000. 41.46 s [vm-test-run-nixos-test-read-proxy] server # [ 10.342349] systemd[1]: Starting Coldplug All udev Devices...
  1001. 41.49 s [vm-test-run-nixos-test-read-proxy] server # [ 10.371996] loop: module loaded
  1002. 41.50 s [vm-test-run-nixos-test-read-proxy] server # [ 10.383315] systemd[1]: Listening on Journal Log Access Socket.
  1003. 41.51 s [vm-test-run-nixos-test-read-proxy] server # [ 10.395795] systemd[1]: Mounted Huge Pages File System.
  1004. 41.52 s [vm-test-run-nixos-test-read-proxy] server # [ 9.712907] systemd[1]: Queued start job for default target Multi-User System.[ 10.406194] systemd[1]: Started Journal Service.
  1005. 41.52 s [vm-test-run-nixos-test-read-proxy] server #
  1006. 41.53 s [vm-test-run-nixos-test-read-proxy] server # [ 9.720840] systemd[1]: systemd-journald.service: Deactivated successfully.[ 10.411092] EXT4-fs (vda): re-mounted d3a20e6f-1204-4d5b-b42b-cb41f4d4d8ce.
  1007. 41.53 s [vm-test-run-nixos-test-read-proxy] server #
  1008. 41.54 s [vm-test-run-nixos-test-read-proxy] server # [ 9.736619] systemd-modules-load[270]: Inserted module 'loop'
  1009. 41.55 s [vm-test-run-nixos-test-read-proxy] server # [ 9.746619] systemd[1]: Mounted POSIX Message Queue File System.
  1010. 41.56 s [vm-test-run-nixos-test-read-proxy] server # [ 9.754521] systemd[1]: Mounted Kernel Debug File System.
  1011. 41.57 s [vm-test-run-nixos-test-read-proxy] server # [ 9.762474] systemd[1]: Mounted Kernel Trace File System.
  1012. 41.57 s [vm-test-run-nixos-test-read-proxy] server # [ 9.770275] systemd[1]: Finished Create List of Static Device Nodes.
  1013. 41.58 s [vm-test-run-nixos-test-read-proxy] server # [ 9.777736] systemd[1]: modprobe@configfs.service: Deactivated successfully.
  1014. 41.59 s [vm-test-run-nixos-test-read-proxy] server # [ 9.786683] systemd[1]: Finished Load Kernel Module configfs.
  1015. 41.60 s [vm-test-run-nixos-test-read-proxy] server # [ 9.793747] systemd[1]: Mounted FUSE Control File System.
  1016. 41.60 s [vm-test-run-nixos-test-read-proxy] server # [ 9.801919] systemd[1]: Finished Load Kernel Modules.
  1017. 41.61 s [vm-test-run-nixos-test-read-proxy] server # [ 9.808608] systemd[1]: Finished Remount Root and Kernel File Systems.
  1018. 41.62 s [vm-test-run-nixos-test-read-proxy] server # [ 9.816356] systemd[1]: Listening on Disk Image Download Service Socket.
  1019. 41.63 s [vm-test-run-nixos-test-read-proxy] server # [ 9.821753] systemd-oomd[272]: [0;1;38:5:185mNo swap; memory pressure usage will be degraded
  1020. 41.64 s [vm-test-run-nixos-test-read-proxy] server # [ 9.832593] systemd[1]: Mounting Kernel Configuration File System...
  1021. 41.64 s [vm-test-run-nixos-test-read-proxy] server # [ 9.838464] systemd[1]: Starting Firewall...
  1022. 41.65 s [vm-test-run-nixos-test-read-proxy] server # [ 9.843704] systemd[1]: Starting Flush Journal to Persistent Storage...
  1023. 41.66 s [vm-test-run-nixos-test-read-proxy] server # [ 9.851377] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore
  1024. 41.67 s [vm-test-run-nixos-test-read-proxy] server # [ 9.861926] systemd[1]: Starting Load/Save OS Random Seed...
  1025. 41.67 s [vm-test-run-nixos-test-read-proxy] server # [ 9.868103] systemd[1]: Starting Apply Kernel Variables...
  1026. 41.69 s [vm-test-run-nixos-test-read-proxy] server # [ 9.886175] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...
  1027. 41.70 s [vm-test-run-nixos-test-read-proxy] server # [ 9.892423] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os
  1028. 41.71 s [vm-test-run-nixos-test-read-proxy] server # [ 9.903385] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.
  1029. 41.81 s [vm-test-run-nixos-test-read-proxy] server # [ 10.689863] systemd-journald[269]: Received client request to flush runtime journal.
  1030. 42.31 s [vm-test-run-nixos-test-read-proxy] server # [ 10.500547] systemd[1]: Mounted Kernel Configuration File System.
  1031. 42.32 s [vm-test-run-nixos-test-read-proxy] server # [ 10.514647] systemd[1]: Finished Load/Save OS Random Seed.
  1032. 42.33 s [vm-test-run-nixos-test-read-proxy] server # [ 10.530165] systemd[1]: Reached target First Boot Complete.
  1033. 42.35 s [vm-test-run-nixos-test-read-proxy] server # [ 10.537926] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
  1034. 42.35 s [vm-test-run-nixos-test-read-proxy] server # [ 10.550665] systemd[1]: Starting Create Static Device Nodes in /dev...
  1035. 42.37 s [vm-test-run-nixos-test-read-proxy] server # [ 10.565881] systemd[1]: Finished Apply Kernel Variables.
  1036. 42.38 s [vm-test-run-nixos-test-read-proxy] server # [ 10.575461] systemd[1]: Finished Create Static Device Nodes in /dev.
  1037. 42.40 s [vm-test-run-nixos-test-read-proxy] server # [ 10.598705] systemd[1]: Reached target Preparation for Local File Systems.
  1038. 42.41 s [vm-test-run-nixos-test-read-proxy] server # [ 10.611876] systemd[1]: Mounting /run/wrappers...
  1039. 42.43 s [vm-test-run-nixos-test-read-proxy] server # [ 10.621599] systemd[1]: Starting Rule-based Manager for Device Events and Files...
  1040. 42.44 s [vm-test-run-nixos-test-read-proxy] server # [ 10.636180] systemd[1]: Finished Coldplug All udev Devices.
  1041. 42.45 s [vm-test-run-nixos-test-read-proxy] server # [ 10.646965] systemd[1]: Mounted /run/wrappers.
  1042. 42.46 s [vm-test-run-nixos-test-read-proxy] server # [ 10.656115] systemd[1]: Reached target Local File Systems.
  1043. 42.46 s [vm-test-run-nixos-test-read-proxy] server # [ 10.658695] systemd[1]: Listening on Boot Loader Control Service Socket.
  1044. 42.46 s [vm-test-run-nixos-test-read-proxy] server # [ 10.660722] systemd[1]: Starting register-nix-paths.service...
  1045. 42.47 s [vm-test-run-nixos-test-read-proxy] server # [ 10.662625] systemd[1]: Starting Create SUID/SGID Wrappers...
  1046. 42.47 s [vm-test-run-nixos-test-read-proxy] server # [ 10.664597] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.
  1047. 42.48 s [vm-test-run-nixos-test-read-proxy] server # [ 10.672652] systemd[1]: Starting Save Transient machine-id to Disk...
  1048. 42.48 s [vm-test-run-nixos-test-read-proxy] server # [ 10.679669] systemd[1]: Finished Flush Journal to Persistent Storage.
  1049. 42.49 s [vm-test-run-nixos-test-read-proxy] server # [ 10.691662] systemd[1]: Starting Create System Files and Directories...
  1050. 42.50 s [vm-test-run-nixos-test-read-proxy] server # [ 10.701676] systemd-udevd[307]: Using default interface naming scheme 'v261'.
  1051. 42.54 s [vm-test-run-nixos-test-read-proxy] server # [ 10.738557] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
  1052. 42.56 s [vm-test-run-nixos-test-read-proxy] server # [ 10.758288] systemd[1]: Finished Save Transient machine-id to Disk.
  1053. 42.60 s [vm-test-run-nixos-test-read-proxy] server # [ 10.786837] systemd[1]: Finished Create System Files and Directories.
  1054. 42.60 s [vm-test-run-nixos-test-read-proxy] server # [ 10.801266] systemd[1]: Starting Rebuild Journal Catalog...
  1055. 42.62 s [vm-test-run-nixos-test-read-proxy] server # [ 10.814793] systemd[1]: Starting Record System Boot/Shutdown in UTMP...
  1056. 42.74 s [vm-test-run-nixos-test-read-proxy] server # [ 10.935286] systemd[1]: Finished Record System Boot/Shutdown in UTMP.
  1057. 42.77 s [vm-test-run-nixos-test-read-proxy] server # [ 10.963677] systemd[1]: Started Rule-based Manager for Device Events and Files.
  1058. 42.81 s [vm-test-run-nixos-test-read-proxy] server # [ 11.005583] systemd[1]: Finished Rebuild Journal Catalog.
  1059. 42.83 s [vm-test-run-nixos-test-read-proxy] server # [ 11.021927] systemd[1]: Starting Update is Completed...
  1060. 42.93 s [vm-test-run-nixos-test-read-proxy] server # [ 11.123816] systemd[1]: Finished Update is Completed.
  1061. 43.40 s [vm-test-run-nixos-test-read-proxy] server # [ 11.593244] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.
  1062. 43.41 s [vm-test-run-nixos-test-read-proxy] server # [ 11.602997] systemd[1]: Finished Create SUID/SGID Wrappers.
  1063. 43.48 s [vm-test-run-nixos-test-read-proxy] server # [ 11.678857] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse
  1064. 43.72 s [vm-test-run-nixos-test-read-proxy] server # [ 11.916969] systemd[1]: Condition check resulted in /dev/hvc0 being skipped.
  1065. 43.80 s [vm-test-run-nixos-test-read-proxy] server # [ 11.997325] systemd[1]: Condition check resulted in /dev/ttyS0 being skipped.
  1066. 43.84 s [vm-test-run-nixos-test-read-proxy] server # [ 12.021935] (udev-worker)[423]: [0;1;38:5:185meth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.
  1067. 43.84 s [vm-test-run-nixos-test-read-proxy] server # [ 12.035956] (udev-worker)[423]: Network interface NamePolicy= disabled on kernel command line.
  1068. 43.85 s [vm-test-run-nixos-test-read-proxy] server # [ 12.044761] (udev-worker)[415]: Network interface NamePolicy= disabled on kernel command line.
  1069. 44.09 s [vm-test-run-nixos-test-read-proxy] server # [ 12.290771] systemd[1]: Finished Firewall.
  1070. 44.12 s [vm-test-run-nixos-test-read-proxy] server # [ 12.312657] systemd[1]: Condition check resulted in Virtio network device being skipped.
  1071. 44.13 s [vm-test-run-nixos-test-read-proxy] server # [ 12.324347] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore
  1072. 44.14 s [vm-test-run-nixos-test-read-proxy] server # [ 12.334774] systemd[1]: Starting Create SUID/SGID Wrappers...
  1073. 44.15 s [vm-test-run-nixos-test-read-proxy] server # [ 12.342493] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.
  1074. 44.17 s [vm-test-run-nixos-test-read-proxy] server # [ 12.351939] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67
  1075. 44.17 s [vm-test-run-nixos-test-read-proxy] server # [ 12.366809] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore
  1076. 44.18 s [vm-test-run-nixos-test-read-proxy] server # [ 12.377180] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os
  1077. 44.19 s [vm-test-run-nixos-test-read-proxy] server # [ 12.385221] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os
  1078. 44.20 s [vm-test-run-nixos-test-read-proxy] server # [ 12.393180] systemd[1]: Finished register-nix-paths.service.
  1079. 44.28 s [vm-test-run-nixos-test-read-proxy] server # [ 13.165109] mousedev: PS/2 mouse device common for all mice
  1080. 44.34 s [vm-test-run-nixos-test-read-proxy] server # [ 13.220136] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input3
  1081. 44.38 s [vm-test-run-nixos-test-read-proxy] server # [ 13.264885] ACPI: button: Power Button [PWRF]
  1082. 44.40 s [vm-test-run-nixos-test-read-proxy] server # [ 13.286289] rtc_cmos 00:05: RTC can wake from S4
  1083. 44.41 s [vm-test-run-nixos-test-read-proxy] server # [ 13.297976] parport_pc 00:03: reported by Plug and Play ACPI
  1084. 44.44 s [vm-test-run-nixos-test-read-proxy] server # [ 13.326060] Floppy drive(s): fd0 is 2.88M AMI BIOS
  1085. 44.45 s [vm-test-run-nixos-test-read-proxy] server # [ 13.328470] rtc_cmos 00:05: registered as rtc0
  1086. 44.45 s [vm-test-run-nixos-test-read-proxy] server # [ 13.337337] rtc_cmos 00:05: setting system clock to 2026-07-18T13:59:31 UTC (1784383171)
  1087. 44.46 s [vm-test-run-nixos-test-read-proxy] server # [ 13.341458] parport0: PC-style at 0x378, irq 7 [PCSPP(,...)]
  1088. 44.47 s [vm-test-run-nixos-test-read-proxy] server # [ 13.357297] FDC 0 is a S82078B
  1089. 44.48 s [vm-test-run-nixos-test-read-proxy] server # [ 13.366433] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs
  1090. 44.56 s [vm-test-run-nixos-test-read-proxy] server # [ 13.436513] bochs-drm 0000:00:02.0: vgaarb: deactivate vga console
  1091. 44.58 s [vm-test-run-nixos-test-read-proxy] server # [ 13.466323] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0
  1092. 44.68 s [vm-test-run-nixos-test-read-proxy] server # [ 13.489165] input: QEMU Virtio Keyboard as /devices/pci0000:00/0000:00:0a.0/virtio7/input/input4
  1093. 44.70 s [vm-test-run-nixos-test-read-proxy] server # [ 12.892634] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.
  1094. 44.70 s [vm-test-run-nixos-test-read-proxy] server # [ 12.897529] systemd[1]: Finished Create SUID/SGID Wrappers.
  1095. 44.71 s [vm-test-run-nixos-test-read-proxy] server # [ 12.902762] systemd[1]: Reached target System Initialization.
  1096. 44.71 s [vm-test-run-nixos-test-read-proxy] server # [ 12.908462] systemd[1]: Started Discard unused filesystem blocks once a week.
  1097. 44.72 s [vm-test-run-nixos-test-read-proxy] server # [ 12.915259] systemd[1]: Started niks3 garbage collection timer.
  1098. 44.72 s [vm-test-run-nixos-test-read-proxy] server # [ 12.918844] systemd[1]: Started Daily Cleanup of Temporary Directories.
  1099. 44.73 s [vm-test-run-nixos-test-read-proxy] server # [ 12.925683] systemd[1]: Reached target Timer Units.
  1100. 44.73 s [vm-test-run-nixos-test-read-proxy] server # [ 12.930758] systemd[1]: Listening on D-Bus System Message Bus Socket.
  1101. 44.74 s [vm-test-run-nixos-test-read-proxy] server # [ 13.502344] i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD
  1102. 44.74 s [vm-test-run-nixos-test-read-proxy] server # [ 13.512667] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input6
  1103. 44.74 s [vm-test-run-nixos-test-read-proxy] server # [ 12.940323] systemd[1]: Listening on niks3 server socket.
  1104. 44.75 s [vm-test-run-nixos-test-read-proxy] server # [ 12.943193] systemd[1]: Listening on Nix Daemon Socket.
  1105. 44.75 s [vm-test-run-nixos-test-read-proxy] server # [ 12.946427] systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.
  1106. 44.76 s [vm-test-run-nixos-test-read-proxy] server # [ 12.955669] systemd[1]: Reached target Socket Units.
  1107. 44.77 s [vm-test-run-nixos-test-read-proxy] server # [ 12.964771] systemd[1]: Reached target Basic System.
  1108. 44.78 s [vm-test-run-nixos-test-read-proxy] server # [ 12.975312] systemd[1]: Started backdoor.service.
  1109. 44.79 s [vm-test-run-nixos-test-read-proxy] server # [ 12.981998] systemd[1]: Starting Import lastlog data into lastlog2 database...
  1110. 44.80 s [vm-test-run-nixos-test-read-proxy] server # [ 12.992193] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
  1111. 44.80 s [vm-test-run-nixos-test-read-proxy] server # [ 12.998440] systemd[1]: Starting Post-Boot Actions...
  1112. 44.82 s [vm-test-run-nixos-test-read-proxy] server # [ 13.012242] systemd[1]: Started Reset console on configuration changes.
  1113. 44.84 s [vm-test-run-nixos-test-read-proxy] server # [ 13.513699] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input5
  1114. 44.85 s [vm-test-run-nixos-test-read-proxy] server # [ 13.045276] systemd[1]: Starting resolvconf update...
  1115. 44.94 s [vm-test-run-nixos-test-read-proxy] server # connecting to host...
  1116. 44.95 s [vm-test-run-nixos-test-read-proxy] server # [ 13.569182] Console: switching to colour dummy device 80x25
  1117. 44.95 s [vm-test-run-nixos-test-read-proxy] server # [ 13.148919] systemd[1]: Starting D-Bus System Message Bus...
  1118. 44.98 s [vm-test-run-nixos-test-read-proxy] server # [ 13.181226] systemd[1]: Finished Post-Boot Actions.
  1119. 45.03 s [vm-test-run-nixos-test-read-proxy] server # [ 13.912654] [drm] Found bochs VGA, ID 0xb0c5.
  1120. 45.04 s [vm-test-run-nixos-test-read-proxy] server: Guest shell says: b'Spawning backdoor root shell...\n'
  1121. 45.05 s [vm-test-run-nixos-test-read-proxy] server # [ 13.246414] systemd[1]: Started Name Service Cache Daemon (nsncd).
  1122. 45.05 s [vm-test-run-nixos-test-read-proxy] server: connected to guest root shell
  1123. 45.05 s [vm-test-run-nixos-test-read-proxy] server: (connecting took 15.43 seconds)
  1124. 45.05 s [vm-test-run-nixos-test-read-proxy] server: (finished: waiting for the VM to finish booting, in 16.62 seconds)
  1125. 45.07 s [vm-test-run-nixos-test-read-proxy] server # [ 13.254430] systemd[1]: Reached target Host and Network Name Lookups.
  1126. 45.07 s [vm-test-run-nixos-test-read-proxy] server # [ 13.265717] nsncd[554]: Jul 18 13:59:32.092 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
  1127. 45.09 s [vm-test-run-nixos-test-read-proxy] server # [ 13.287956] systemd[1]: Reached target User and Group Name Lookups.
  1128. 45.10 s [vm-test-run-nixos-test-read-proxy] server # [ 13.295300] systemd[1]: Starting User Login Management...
  1129. 45.10 s [vm-test-run-nixos-test-read-proxy] server # [ 13.987676] [drm] Framebuffer size 16384 kB @ 0xfd000000, mmio @ 0xfebd0000.
  1130. 45.11 s [vm-test-run-nixos-test-read-proxy] server # [ 13.302682] systemd[1]: Finished Import lastlog data into lastlog2 database.
  1131. 45.14 s [vm-test-run-nixos-test-read-proxy] server # [ 13.339911] systemd[1]: Starting Virtual Console Setup...
  1132. 45.21 s [vm-test-run-nixos-test-read-proxy] server # [ 14.092327] bochs-drm 0000:00:02.0: [drm] Registered 1 planes with drm panic
  1133. 45.29 s [vm-test-run-nixos-test-read-proxy] server # [ 13.485757] dbus-broker-launch[564]: Looking up NSS user entry for 'systemd-timesync'...
  1134. 45.32 s [vm-test-run-nixos-test-read-proxy] server # [ 13.514513] dbus-broker-launch[564]: NSS returned no entry for 'systemd-timesync'
  1135. 45.33 s [vm-test-run-nixos-test-read-proxy] server # [ 13.527466] dbus-broker-launch[564]: Invalid user-name in /nix/store/bxhdy57r6hl031izqz6q75p6cqynykp8-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"
  1136. 45.34 s [vm-test-run-nixos-test-read-proxy] server # [ 14.221463] [drm] Initialized bochs-drm 1.0.0 for 0000:00:02.0 on minor 0
  1137. 45.37 s [vm-test-run-nixos-test-read-proxy] server # [ 13.569801] systemd[1]: Started D-Bus System Message Bus.
  1138. 45.39 s [vm-test-run-nixos-test-read-proxy] server # [ 13.583636] systemd-logind[579]: Watching system buttons on /dev/input/event2 (Power Button)
  1139. 45.40 s [vm-test-run-nixos-test-read-proxy] server # [ 13.599177] systemd-logind[579]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard)
  1140. 45.42 s [vm-test-run-nixos-test-read-proxy] server # [ 13.610829] systemd-logind[579]: New seat seat0.
  1141. 45.48 s [vm-test-run-nixos-test-read-proxy] server # [ 13.673952] dbus-broker-launch[564]: Ready
  1142. 45.48 s [vm-test-run-nixos-test-read-proxy] server # [ 13.681766] systemd[1]: Started User Login Management.
  1143. 45.53 s [vm-test-run-nixos-test-read-proxy] server # [ 13.722697] systemd[1]: Stopped target Host and Network Name Lookups.
  1144. 45.54 s [vm-test-run-nixos-test-read-proxy] server # [ 13.734457] systemd[1]: Stopping Host and Network Name Lookups...
  1145. 45.55 s [vm-test-run-nixos-test-read-proxy] server # [ 13.742728] systemd[1]: Stopped target User and Group Name Lookups.
  1146. 45.55 s [vm-test-run-nixos-test-read-proxy] server # [ 13.748993] systemd[1]: Stopping User and Group Name Lookups...
  1147. 45.56 s [vm-test-run-nixos-test-read-proxy] server # [ 13.753242] systemd[1]: Starting linger-users.service...
  1148. 45.56 s [vm-test-run-nixos-test-read-proxy] server # [ 13.759678] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...
  1149. 45.57 s [vm-test-run-nixos-test-read-proxy] server # [ 13.768817] systemd[1]: nscd.service: Deactivated successfully.
  1150. 45.58 s [vm-test-run-nixos-test-read-proxy] server # [ 13.776344] systemd[1]: Stopped Name Service Cache Daemon (nsncd).
  1151. 45.60 s [vm-test-run-nixos-test-read-proxy] server # [ 13.792361] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
  1152. 45.65 s [vm-test-run-nixos-test-read-proxy] server # [ 13.848607] systemd[1]: linger-users.service: Deactivated successfully.
  1153. 45.66 s [vm-test-run-nixos-test-read-proxy] server # [ 13.858502] systemd[1]: Finished linger-users.service.
  1154. 45.67 s [vm-test-run-nixos-test-read-proxy] server # [ 13.867371] systemd[1]: Finished resolvconf update.
  1155. 45.69 s [vm-test-run-nixos-test-read-proxy] server # [ 13.880798] systemd[1]: Reached target Preparation for Network.
  1156. 45.73 s [vm-test-run-nixos-test-read-proxy] server # [ 13.929342] systemd[1]: Starting DHCP Client...
  1157. 45.74 s [vm-test-run-nixos-test-read-proxy] server # [ 13.936290] systemd[1]: Starting Address configuration of eth1...
  1158. 45.76 s [vm-test-run-nixos-test-read-proxy] server # [ 13.948980] nsncd[643]: Jul 18 13:59:32.799 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"[ 14.334247] fbcon: bochs-drmdrmfb (fb0) is primary device
  1159. 45.77 s [vm-test-run-nixos-test-read-proxy] server #
  1160. 45.77 s [vm-test-run-nixos-test-read-proxy] server # [ 14.621935] Console: switching to colour frame buffer device 160x50
  1161. 45.77 s [vm-test-run-nixos-test-read-proxy] server # [ 13.968284] systemd[1]: Starting Extra networking commands....
  1162. 45.78 s [vm-test-run-nixos-test-read-proxy] server # [ 13.973447] systemd[1]: Started Name Service Cache Daemon (nsncd).[ 14.665170] bochs-drm 0000:00:02.0: [drm] fb0: bochs-drmdrmfb frame buffer device
  1163. 45.78 s [vm-test-run-nixos-test-read-proxy] server #
  1164. 45.81 s [vm-test-run-nixos-test-read-proxy] server # [ 14.008949] systemd[1]: Reached target Host and Network Name Lookups.
  1165. 45.82 s [vm-test-run-nixos-test-read-proxy] server # [ 14.014348] systemd[1]: Reached target User and Group Name Lookups.
  1166. 45.91 s [vm-test-run-nixos-test-read-proxy] server # [ 14.795715] kvm_amd: TSC scaling supported
  1167. 45.91 s [vm-test-run-nixos-test-read-proxy] server # [ 14.797480] kvm_amd: Nested Virtualization enabled
  1168. 45.92 s [vm-test-run-nixos-test-read-proxy] server # [ 14.114995] network-addresses-eth1-start[651]: adding address 192.168.1.1/24... done
  1169. 45.92 s [vm-test-run-nixos-test-read-proxy] server # [ 14.810223] kvm_amd: Nested Paging enabled
  1170. 45.93 s [vm-test-run-nixos-test-read-proxy] server # [ 14.817699] kvm_amd: LBR virtualization supported
  1171. 45.94 s [vm-test-run-nixos-test-read-proxy] server # [ 14.822908] kvm_amd: Virtual VMLOAD VMSAVE supported
  1172. 45.94 s [vm-test-run-nixos-test-read-proxy] server # [ 14.137750] network-addresses-eth1-start[651]: adding address 2001:db8:1::1/64... done
  1173. 45.94 s [vm-test-run-nixos-test-read-proxy] server # [ 14.829010] kvm_amd: Virtual GIF supported
  1174. 45.98 s [vm-test-run-nixos-test-read-proxy] server # [ 14.172293] systemd[1]: Finished Address configuration of eth1.
  1175. 46.07 s [vm-test-run-nixos-test-read-proxy] server # [ 14.957487] EDAC MC: Ver: 3.0.0
  1176. 46.10 s [vm-test-run-nixos-test-read-proxy] server # [ 14.300531] systemd[1]: Finished Extra networking commands..
  1177. 46.11 s [vm-test-run-nixos-test-read-proxy] server # [ 14.310611] systemd[1]: Reached target Network.
  1178. 46.12 s [vm-test-run-nixos-test-read-proxy] server # [ 14.315953] systemd[1]: Starting PostgreSQL Server...
  1179. 46.13 s [vm-test-run-nixos-test-read-proxy] server # [ 14.326535] systemd[1]: Started rustfs.service.[ 15.020070] ppdev: user-space parallel port driver
  1180. 46.14 s [vm-test-run-nixos-test-read-proxy] server #
  1181. 46.14 s [vm-test-run-nixos-test-read-proxy] server # [ 14.336896] dhcpcd[672]: dhcpcd-10.3.2 starting
  1182. 46.23 s [vm-test-run-nixos-test-read-proxy] server # [ 14.343837] systemd-vconsole-setup[592]: Configuration of first virtual console was skipped, ignoring remaining ones.
  1183. 46.23 s [vm-test-run-nixos-test-read-proxy] server # [ 14.360472] dhcpcd[730]: dev: loaded udev
  1184. 46.23 s [vm-test-run-nixos-test-read-proxy] server # [ 14.366655] systemd[1]: Starting rustfs-setup.service...
  1185. 46.23 s [vm-test-run-nixos-test-read-proxy] server # [ 14.375235] systemd[1]: Starting Permit User Sessions...
  1186. 46.23 s [vm-test-run-nixos-test-read-proxy] server # [ 14.390624] systemd[1]: Finished Virtual Console Setup.
  1187. 46.23 s [vm-test-run-nixos-test-read-proxy] server # [ 15.101242] 8021q: 802.1Q VLAN Support v1.8
  1188. 46.23 s [vm-test-run-nixos-test-read-proxy] server # [ 15.107959] 8021q: adding VLAN 0 to HW filter on device eth1
  1189. 46.31 s [vm-test-run-nixos-test-read-proxy] server # [ 14.511238] systemd[1]: Finished Permit User Sessions.
  1190. 46.33 s [vm-test-run-nixos-test-read-proxy] server # [ 14.531282] systemd[1]: Started Getty on tty1.
  1191. 46.35 s [vm-test-run-nixos-test-read-proxy] server # [ 14.534102] systemd[1]: Reached target Login Prompts.
  1192. 46.40 s [vm-test-run-nixos-test-read-proxy] server # [ 14.594344] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
  1193. 46.41 s [vm-test-run-nixos-test-read-proxy] server # [ 14.604354] systemd[1]: Stopped Virtual Console Setup.
  1194. 46.41 s [vm-test-run-nixos-test-read-proxy] server # [ 14.610943] systemd[1]: Stopping Virtual Console Setup...
  1195. 46.42 s [vm-test-run-nixos-test-read-proxy] server # [ 14.621202] systemd[1]: Starting Virtual Console Setup...
  1196. 46.61 s [vm-test-run-nixos-test-read-proxy] server # [ 14.801637] systemd-logind[579]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)
  1197. 46.74 s [vm-test-run-nixos-test-read-proxy] server # [ 15.628047] cfg80211: Loading compiled-in X.509 certificates for regulatory database
  1198. 46.84 s [vm-test-run-nixos-test-read-proxy] server # [ 15.723471] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
  1199. 46.85 s [vm-test-run-nixos-test-read-proxy] server # [ 15.736817] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'
  1200. 46.86 s [vm-test-run-nixos-test-read-proxy] server # [ 15.750297] faux_driver regulatory: Direct firmware load for regulatory.db failed with error -2
  1201. 46.87 s [vm-test-run-nixos-test-read-proxy] server # [ 15.752211] cfg80211: failed to load regulatory.db
  1202. 47.06 s [vm-test-run-nixos-test-read-proxy] server # [ 15.251898] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
  1203. 47.10 s [vm-test-run-nixos-test-read-proxy] server # [ 15.291798] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
  1204. 47.11 s [vm-test-run-nixos-test-read-proxy] server # [ 15.306703] systemd[1]: Stopped Virtual Console Setup.
  1205. 47.13 s [vm-test-run-nixos-test-read-proxy] server # [ 15.322831] postgresql-pre-start[755]: The files belonging to this database system will be owned by user "postgres".
  1206. 47.15 s [vm-test-run-nixos-test-read-proxy] server # [ 15.344683] postgresql-pre-start[755]: This user must also own the server process.
  1207. 47.18 s [vm-test-run-nixos-test-read-proxy] server # [ 15.357897] postgresql-pre-start[755]: The database cluster will be initialized with locale "en_US.UTF-8".
  1208. 47.18 s [vm-test-run-nixos-test-read-proxy] server # [ 15.375282] postgresql-pre-start[755]: The default database encoding has accordingly been set to "UTF8".
  1209. 47.19 s [vm-test-run-nixos-test-read-proxy] server # [ 16.071107] 8021q: adding VLAN 0 to HW filter on device eth0
  1210. 47.20 s [vm-test-run-nixos-test-read-proxy] server # [ 15.390584] postgresql-pre-start[755]: The default text search configuration will be set to "english".
  1211. 47.22 s [vm-test-run-nixos-test-read-proxy] server # [ 15.412544] postgresql-pre-start[755]: Data page checksums are enabled.
  1212. 47.23 s [vm-test-run-nixos-test-read-proxy] server # [ 15.426432] postgresql-pre-start[755]: fixing permissions on existing directory /var/lib/postgresql/18 ... ok
  1213. 47.25 s [vm-test-run-nixos-test-read-proxy] server # [ 15.444319] postgresql-pre-start[755]: creating subdirectories ... ok
  1214. 47.26 s [vm-test-run-nixos-test-read-proxy] server # [ 15.451751] postgresql-pre-start[755]: selecting dynamic shared memory implementation ... posix
  1215. 47.27 s [vm-test-run-nixos-test-read-proxy] server # [ 15.466565] systemd[1]: Starting Virtual Console Setup...
  1216. 47.28 s [vm-test-run-nixos-test-read-proxy] server # [ 15.475746] dhcpcd[730]: eth0: waiting for carrier
  1217. 47.30 s [vm-test-run-nixos-test-read-proxy] server # [ 15.484778] dhcpcd[730]: eth0: carrier acquired
  1218. 47.30 s [vm-test-run-nixos-test-read-proxy] server # [ 15.496099] dhcpcd[730]: DUID 00:01:00:01:31:ee:43:46:52:54:00:12:34:56
  1219. 47.31 s [vm-test-run-nixos-test-read-proxy] server # [ 15.502385] dhcpcd[730]: eth0: IAID 00:12:34:56
  1220. 47.32 s [vm-test-run-nixos-test-read-proxy] server # [ 15.506872] dhcpcd[730]: eth0: adding address fe80::5054:ff:fe12:3456
  1221. 47.63 s [vm-test-run-nixos-test-read-proxy] server # [ 15.823747] postgresql-pre-start[755]: selecting default "max_connections" ... 100
  1222. 47.73 s [vm-test-run-nixos-test-read-proxy] server # [ 15.929469] systemd-vconsole-setup[779]: Configuration of first virtual console was skipped, ignoring remaining ones.
  1223. 47.75 s [vm-test-run-nixos-test-read-proxy] server # [ 15.942507] systemd[1]: Finished Virtual Console Setup.
  1224. 47.98 s [vm-test-run-nixos-test-read-proxy] server # [ 16.173148] postgresql-pre-start[755]: selecting default "shared_buffers" ... 128MB
  1225. 48.19 s [vm-test-run-nixos-test-read-proxy] server # [ 16.363585] rustfs[728]: {"timestamp":"2026-07-18T13:59:35.211641562Z","level":"ERROR","fields":{"message":"list_path_raw: revjob err VolumeNotFound"},"target":"rustfs_ecstore::cache_value::metacache_set","filename":"crates/ecstore/src/cache_value/metacache_set.rs","line_number":486,"threadName":"rustfs-worker","threadId":"ThreadId(3)"}
  1226. 48.71 s [vm-test-run-nixos-test-read-proxy] server # [ 16.905848] dhcpcd[730]: eth0: soliciting a DHCP lease
  1227. 48.74 s [vm-test-run-nixos-test-read-proxy] server # [ 17.623125] NET: Registered PF_PACKET protocol family
  1228. 48.74 s [vm-test-run-nixos-test-read-proxy] server # [ 16.941203] dhcpcd[730]: eth0: offered 10.0.2.15 from 10.0.2.2
  1229. 48.75 s [vm-test-run-nixos-test-read-proxy] server # [ 16.944178] dhcpcd[730]: eth0: probing address 10.0.2.15/24
  1230. 49.41 s [vm-test-run-nixos-test-read-proxy] server # [ 17.603674] dhcpcd[730]: eth0: soliciting an IPv6 router
  1231. 49.41 s [vm-test-run-nixos-test-read-proxy] server # [ 17.606668] dhcpcd[730]: eth0: Router Advertisement from fe80::2
  1232. 49.41 s [vm-test-run-nixos-test-read-proxy] server # [ 17.608833] dhcpcd[730]: eth0: adding address fec0::5054:ff:fe12:3456/64
  1233. 49.41 s [vm-test-run-nixos-test-read-proxy] server # [ 17.610825] dhcpcd[730]: eth0: adding route to fec0::/64
  1234. 49.42 s [vm-test-run-nixos-test-read-proxy] server # [ 17.612625] dhcpcd[730]: eth0: adding default route via fe80::2
  1235. 50.18 s [vm-test-run-nixos-test-read-proxy] server # [ 18.377544] postgresql-pre-start[755]: selecting default time zone ... UTC
  1236. 50.19 s [vm-test-run-nixos-test-read-proxy] server # [ 18.385770] postgresql-pre-start[755]: creating configuration files ... ok
  1237. 50.81 s [vm-test-run-nixos-test-read-proxy] server # [ 19.007206] postgresql-pre-start[755]: running bootstrap script ... ok
  1238. 51.87 s [vm-test-run-nixos-test-read-proxy] server # [ 20.062609] postgresql-pre-start[755]: performing post-bootstrap initialization ... ok
  1239. 52.19 s [vm-test-run-nixos-test-read-proxy] server # [ 20.386668] postgresql-pre-start[755]: syncing data to disk ... ok
  1240. 52.19 s [vm-test-run-nixos-test-read-proxy] server # [ 20.388716] postgresql-pre-start[755]: initdb: warning: enabling "trust" authentication for local connections
  1241. 52.20 s [vm-test-run-nixos-test-read-proxy] server # [ 20.391811] postgresql-pre-start[755]: initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.
  1242. 52.20 s [vm-test-run-nixos-test-read-proxy] server # [ 20.396266] postgresql-pre-start[755]: Success. You can now start the database server using:
  1243. 52.20 s [vm-test-run-nixos-test-read-proxy] server # [ 20.398679] postgresql-pre-start[755]: pg_ctl -D /var/lib/postgresql/18 -l logfile start
  1244. 52.36 s [vm-test-run-nixos-test-read-proxy] server # [ 20.553935] postgres[850]: [850] LOG: starting PostgreSQL 18.4 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit
  1245. 52.37 s [vm-test-run-nixos-test-read-proxy] server # [ 20.563854] postgres[850]: [850] LOG: listening on IPv6 address "::1", port 5432
  1246. 52.37 s [vm-test-run-nixos-test-read-proxy] server # [ 20.566515] postgres[850]: [850] LOG: listening on IPv4 address "127.0.0.1", port 5432
  1247. 52.39 s [vm-test-run-nixos-test-read-proxy] server # [ 20.590189] postgres[850]: [850] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"
  1248. 52.51 s [vm-test-run-nixos-test-read-proxy] server # [ 20.704601] postgres[859]: [859] LOG: database system was shut down at 2026-07-18 13:59:38 GMT
  1249. 52.55 s [vm-test-run-nixos-test-read-proxy] server # [ 20.749320] postgres[850]: [850] LOG: database system is ready to accept connections
  1250. 52.58 s [vm-test-run-nixos-test-read-proxy] server # [ 20.780837] systemd[1]: Started PostgreSQL Server.
  1251. 52.59 s [vm-test-run-nixos-test-read-proxy] server # [ 20.790277] systemd[1]: Starting PostgreSQL Setup Scripts...
  1252. 52.93 s [vm-test-run-nixos-test-read-proxy] server # [ 21.125594] postgresql-setup-start[870]: CREATE DATABASE
  1253. 52.99 s [vm-test-run-nixos-test-read-proxy] server # [ 21.182615] postgresql-setup-start[884]: CREATE ROLE
  1254. 53.02 s [vm-test-run-nixos-test-read-proxy] server # [ 21.216603] postgresql-setup-start[886]: ALTER DATABASE
  1255. 53.03 s [vm-test-run-nixos-test-read-proxy] server # [ 21.227953] systemd[1]: Finished PostgreSQL Setup Scripts.
  1256. 53.03 s [vm-test-run-nixos-test-read-proxy] server # [ 21.231771] systemd[1]: Reached target PostgreSQL.
  1257. 53.08 s [vm-test-run-nixos-test-read-proxy] server # [ 21.273145] dhcpcd[730]: eth0: leased 10.0.2.15 for 86400 seconds
  1258. 53.08 s [vm-test-run-nixos-test-read-proxy] server # [ 21.278769] dhcpcd[730]: eth0: adding route to 10.0.2.0/24
  1259. 53.09 s [vm-test-run-nixos-test-read-proxy] server # [ 21.283144] dhcpcd[730]: eth0: adding default route via 10.0.2.2
  1260. 53.18 s [vm-test-run-nixos-test-read-proxy] server # [ 21.373165] systemd[1]: Started DHCP Client.
  1261. 64.02 s [vm-test-run-nixos-test-read-proxy] server # [ 32.217983] rustfs-setup-start[1029]: mb s3://niks3-test
  1262. 64.04 s [vm-test-run-nixos-test-read-proxy] server # [ 32.224628] systemd[1]: Finished rustfs-setup.service.
  1263. 64.04 s [vm-test-run-nixos-test-read-proxy] server # [ 32.231477] systemd[1]: Starting niks3 server...
  1264. 64.28 s [vm-test-run-nixos-test-read-proxy] server # [ 32.480641] postgres[1041]: [1041] ERROR: relation "goose_db_version" does not exist at character 36
  1265. 64.29 s [vm-test-run-nixos-test-read-proxy] server # [ 32.484328] postgres[1041]: [1041] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1266. 64.37 s [vm-test-run-nixos-test-read-proxy] server # [ 32.569756] niks3-server[1036]: 2026/07/18 13:59:51 OK 20241026095416_initial_model.sql (29.71ms)
  1267. 64.39 s [vm-test-run-nixos-test-read-proxy] server # [ 32.585871] niks3-server[1036]: 2026/07/18 13:59:51 OK 20251210153512_drop_unused_gin_index.sql (14.16ms)
  1268. 64.40 s [vm-test-run-nixos-test-read-proxy] server # [ 32.598453] niks3-server[1036]: 2026/07/18 13:59:51 OK 20251218171726_add_pins.sql (14.34ms)
  1269. 64.42 s [vm-test-run-nixos-test-read-proxy] server # [ 32.613659] niks3-server[1036]: 2026/07/18 13:59:51 OK 20260628120000_add_object_size_and_stats.sql (14.96ms)
  1270. 64.42 s [vm-test-run-nixos-test-read-proxy] server # [ 32.617624] niks3-server[1036]: 2026/07/18 13:59:51 goose: successfully migrated database to version: 20260628120000
  1271. 64.43 s [vm-test-run-nixos-test-read-proxy] server # [ 32.629786] niks3-server[1036]: 2026/07/18 13:59:51 OK 1_commit_pending_closure.sql (16.14ms)
  1272. 64.44 s [vm-test-run-nixos-test-read-proxy] server # [ 32.640847] niks3-server[1036]: 2026/07/18 13:59:51 OK 2_object_stats_trigger.sql (10.89ms)
  1273. 64.45 s [vm-test-run-nixos-test-read-proxy] server # [ 32.647769] niks3-server[1036]: 2026/07/18 13:59:51 goose: up to current file version: 2
  1274. 64.46 s [vm-test-run-nixos-test-read-proxy] server # [ 32.655631] niks3-server[1036]: 2026/07/18 13:59:51 INFO Loaded signing key name=niks3-test-1 path=/nix/store/ppgsr71bgq33llkbcbnvv6vis04xhnjd-niks3-signing-key
  1275. 64.55 s [vm-test-run-nixos-test-read-proxy] server # [ 32.736469] rustfs[728]: {"timestamp":"2026-07-18T13:59:51.584899335Z","level":"ERROR","fields":{"message":"system path read failed","path_kind":"data_usage","operation":"read_primary","reason":"config_not_found","object":"buckets/.usage.json","error":"Config not found"},"target":"rustfs_ecstore::data_usage","filename":"crates/ecstore/src/data_usage.rs","line_number":126,"threadName":"rustfs-worker","threadId":"ThreadId(3)"}
  1276. 64.56 s [vm-test-run-nixos-test-read-proxy] server # [ 32.755743] niks3-server[1036]: 2026/07/18 13:59:51 INFO Created nix-cache-info in bucket bucket=niks3-test
  1277. 64.57 s [vm-test-run-nixos-test-read-proxy] server # [ 32.765609] niks3-server[1036]: 2026/07/18 13:59:51 INFO Read proxy enabled — serving cache objects from S3
  1278. 64.58 s [vm-test-run-nixos-test-read-proxy] server # [ 32.776555] niks3-server[1036]: 2026/07/18 13:59:51 INFO Using socket-activated listener address=0.0.0.0:5751
  1279. 64.60 s [vm-test-run-nixos-test-read-proxy] server # [ 32.793138] niks3-server[1036]: 2026/07/18 13:59:51 INFO systemd watchdog enabled interval=15s
  1280. 64.60 s [vm-test-run-nixos-test-read-proxy] server # [ 32.799469] systemd[1]: Started niks3 server.
  1281. 64.61 s [vm-test-run-nixos-test-read-proxy] server # [ 32.804316] systemd[1]: Reached target Multi-User System.
  1282. 64.61 s [vm-test-run-nixos-test-read-proxy] server # [ 32.807392] niks3-server[1036]: 2026/07/18 13:59:51 INFO Starting HTTP server address=0.0.0.0:5751
  1283. 64.62 s [vm-test-run-nixos-test-read-proxy] server # [ 32.812425] systemd[1]: Startup finished in 2.940s (kernel) + 4.500s (initrd) + 25.359s (userspace) = 32.800s.
  1284. 64.65 s [vm-test-run-nixos-test-read-proxy] server: (finished: waiting for unit niks3.service, in 36.22 seconds)
  1285. 64.65 s [vm-test-run-nixos-test-read-proxy] server: waiting for TCP port 5751 on localhost
  1286. 64.72 s [vm-test-run-nixos-test-read-proxy] server # Connection to localhost (127.0.0.1) 5751 port [tcp/*] succeeded!
  1287. 64.73 s [vm-test-run-nixos-test-read-proxy] server: (finished: waiting for TCP port 5751 on localhost, in 0.08 seconds)
  1288. 64.73 s [vm-test-run-nixos-test-read-proxy] server: must succeed: curl -sf http://localhost:5751/nix-cache-info | grep StoreDir
  1289. 64.84 s [vm-test-run-nixos-test-read-proxy] server: (finished: must succeed: curl -sf http://localhost:5751/nix-cache-info | grep StoreDir, in 0.11 seconds)
  1290. 64.84 s [vm-test-run-nixos-test-read-proxy] server: must succeed: curl -sf http://localhost:5751/health | grep OK
  1291. 64.88 s [vm-test-run-nixos-test-read-proxy] server: (finished: must succeed: curl -sf http://localhost:5751/health | grep OK, in 0.05 seconds)
  1292. 64.88 s [vm-test-run-nixos-test-read-proxy] server: must succeed: echo -n 'test-token-that-is-at-least-36-characters-long' > /tmp/auth-token
  1293. 64.90 s [vm-test-run-nixos-test-read-proxy] server: (finished: must succeed: echo -n 'test-token-that-is-at-least-36-characters-long' > /tmp/auth-token, in 0.01 seconds)
  1294. 64.90 s [vm-test-run-nixos-test-read-proxy] server: must succeed: nix-build -E 'derivation { name="proxy-test"; system=builtins.currentSystem; builder="/bin/sh"; args=["-c" "echo hello-proxy > $out"]; }' --no-out-link > /tmp/proxy-path
  1295. 65.23 s [vm-test-run-nixos-test-read-proxy] server # warning: unable to download 'https://cache.nixos.org/nix-cache-info': Could not resolve hostname (6) Could not resolve host: cache.nixos.org; retrying in 262 ms (attempt 1/5)
  1296. 65.50 s [vm-test-run-nixos-test-read-proxy] server # warning: unable to download 'https://cache.nixos.org/nix-cache-info': Could not resolve hostname (6) Could not resolve host: cache.nixos.org; retrying in 533 ms (attempt 2/5)
  1297. 66.03 s [vm-test-run-nixos-test-read-proxy] server # warning: unable to download 'https://cache.nixos.org/nix-cache-info': Could not resolve hostname (6) Could not resolve host: cache.nixos.org; retrying in 1201 ms (attempt 3/5)
  1298. 67.24 s [vm-test-run-nixos-test-read-proxy] server # warning: unable to download 'https://cache.nixos.org/nix-cache-info': Could not resolve hostname (6) Could not resolve host: cache.nixos.org; retrying in 2380 ms (attempt 4/5)
  1299. 69.63 s [vm-test-run-nixos-test-read-proxy] server # warning: unable to download 'https://cache.nixos.org/nix-cache-info': Could not resolve hostname (6) Could not resolve host: cache.nixos.org
  1300. 69.66 s [vm-test-run-nixos-test-read-proxy] server # this derivation will be built:
  1301. 69.66 s [vm-test-run-nixos-test-read-proxy] server # /nix/store/hajfq20jdwgnk2z2v3dilxky8964cn2n-proxy-test.drv
  1302. 69.79 s [vm-test-run-nixos-test-read-proxy] server # building '/nix/store/hajfq20jdwgnk2z2v3dilxky8964cn2n-proxy-test.drv'...
  1303. 69.86 s [vm-test-run-nixos-test-read-proxy] server: (finished: must succeed: nix-build -E 'derivation { name="proxy-test"; system=builtins.currentSystem; builder="/bin/sh"; args=["-c" "echo hello-proxy > $out"]; }' --no-out-link > /tmp/proxy-path, in 4.96 seconds)
  1304. 69.86 s [vm-test-run-nixos-test-read-proxy] server: must succeed: NIKS3_SERVER_URL=http://localhost:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/auth-token /nix/store/54dd50j1xw1bk213pzqkcbjx85nrvwp0-niks3-1.7.0/bin/niks3 push $(cat /tmp/proxy-path)
  1305. 70.10 s [vm-test-run-nixos-test-read-proxy] server # [ 38.300679] niks3-server[1036]: 2026/07/18 13:59:57 INFO Received uploads request method=POST path=/api/pending_closures
  1306. 70.14 s [vm-test-run-nixos-test-read-proxy] server # time=2026-07-18T13:59:57.189Z level=INFO msg="Uploading 1 paths to localhost (0 already cached)"
  1307. 70.15 s [vm-test-run-nixos-test-read-proxy] server # time=2026-07-18T13:59:57.197Z level=INFO msg="Uploading npj0sp4cz1n2d3vd9f879njkf5gvikw4-proxy-test (128B)"
  1308. 70.18 s [vm-test-run-nixos-test-read-proxy] server # [ 38.376524] niks3-server[1036]: 2026/07/18 13:59:57 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign
  1309. 70.19 s [vm-test-run-nixos-test-read-proxy] server # [ 38.386347] niks3-server[1036]: 2026/07/18 13:59:57 INFO Signed narinfos id=1 count=1
  1310. 70.19 s [vm-test-run-nixos-test-read-proxy] server # time=2026-07-18T13:59:57.240Z level=INFO msg="Uploading 1 narinfos"
  1311. 70.20 s [vm-test-run-nixos-test-read-proxy] server # [ 38.397245] niks3-server[1036]: 2026/07/18 13:59:57 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete
  1312. 70.22 s [vm-test-run-nixos-test-read-proxy] server # [ 38.412987] niks3-server[1036]: 2026/07/18 13:59:57 INFO Completed upload id=1
  1313. 70.22 s [vm-test-run-nixos-test-read-proxy] server # time=2026-07-18T13:59:57.266Z level=INFO msg="Upload complete. (210ms)"
  1314. 70.22 s [vm-test-run-nixos-test-read-proxy] server: (finished: must succeed: NIKS3_SERVER_URL=http://localhost:5751 NIKS3_AUTH_TOKEN_FILE=/tmp/auth-token /nix/store/54dd50j1xw1bk213pzqkcbjx85nrvwp0-niks3-1.7.0/bin/niks3 push $(cat /tmp/proxy-path), in 0.36 seconds)
  1315. 70.22 s [vm-test-run-nixos-test-read-proxy] server: must succeed: nix copy --from http://localhost:5751 --to /tmp/proxy-store $(cat /tmp/proxy-path)
  1316. 70.51 s [vm-test-run-nixos-test-read-proxy] server # copying 1 paths...
  1317. 70.52 s [vm-test-run-nixos-test-read-proxy] server # copying path '/nix/store/npj0sp4cz1n2d3vd9f879njkf5gvikw4-proxy-test' from 'http://localhost:5751'...
  1318. 70.59 s [vm-test-run-nixos-test-read-proxy] server: (finished: must succeed: nix copy --from http://localhost:5751 --to /tmp/proxy-store $(cat /tmp/proxy-path), in 0.36 seconds)
  1319. 70.59 s [vm-test-run-nixos-test-read-proxy] server: must succeed: nix --store /tmp/proxy-store store cat $(cat /tmp/proxy-path) | grep hello-proxy
  1320. 70.70 s [vm-test-run-nixos-test-read-proxy] server: (finished: must succeed: nix --store /tmp/proxy-store store cat $(cat /tmp/proxy-path) | grep hello-proxy, in 0.11 seconds)
  1321. 70.70 s [vm-test-run-nixos-test-read-proxy] server: must succeed: test $(curl -so /dev/null -w '%{http_code}' http://localhost:5751/nonexistent) = 404
  1322. 70.75 s [vm-test-run-nixos-test-read-proxy] server: (finished: must succeed: test $(curl -so /dev/null -w '%{http_code}' http://localhost:5751/nonexistent) = 404, in 0.05 seconds)
  1323. 70.75 s [vm-test-run-nixos-test-read-proxy] (finished: run the VM test script, in 42.31 seconds)
  1324. 70.82 s [vm-test-run-nixos-test-read-proxy] test script finished in 42.39s
  1325. 70.82 s [vm-test-run-nixos-test-read-proxy] cleanup
  1326. 70.82 s [vm-test-run-nixos-test-read-proxy] kill QemuMachine (pid 45)
  1327. 70.82 s [vm-test-run-nixos-test-read-proxy] server # qemu-system-x86_64: terminating on signal 15 from pid 39 (/nix/store/jxyrvv4gbpnp3ap5iy7wxwl1sg4x2x88-python3-3.14.6/bin/python3.14)
  1328. 70.95 s [vm-test-run-nixos-test-read-proxy] (finished: cleanup, in 0.14 seconds)
  1329. 71.08 s [vm-test-run-nixos-test-read-proxy:post-build] Uploading to the NixCI staging cache: /nix/store/q2w9ifl4gam9ccs6kq3srn08iv9kga2f-vm-test-run-nixos-test-read-proxy
  1330. 71.13 s [vm-test-run-nixos-test-read-proxy:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  1331. 71.14 s [vm-test-run-nixos-test-read-proxy:post-build] copying 1 paths...
  1332. 71.14 s [vm-test-run-nixos-test-read-proxy:post-build] copying path '/nix/store/q2w9ifl4gam9ccs6kq3srn08iv9kga2f-vm-test-run-nixos-test-read-proxy' to 'https://cache.staging.nix-ci.com'...
  1333. 71.44 s [vm-test-run-nixos-test-read-proxy:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  1334. 71.75 s [vm-test-run-nixos-test-read-proxy:post-build] copying 1 paths...
  1335. 71.75 s [vm-test-run-nixos-test-read-proxy:post-build] copying path '/nix/store/g7n25sym70q5ki7x9s0swj0k64iyzffg-vm-test-run-nixos-test-read-proxy.drv' to 'https://cache.staging.nix-ci.com'...
  1336. 71.93 s Uploaded vm-test-run-nixos-test-read-proxy in 855ms
  1337. 71.93 s Progress: 27 of 28 built, 3 of 3 downloaded from cache
  1338. 71.93 s Built vm-test-run-nixos-test-read-proxy in 43.9s
  1339. 71.93 s Progress: 28 of 28 built, 3 of 3 downloaded from cache
  1340. 71.93 s /nix/store/q2w9ifl4gam9ccs6kq3srn08iv9kga2f-vm-test-run-nixos-test-read-proxy
  1341. 72.01 s Build succeeded.
More Logs Raw Logs

Agent Instructions

Wait for completion, without logs:

curl --netrc -N https://staging.nix-ci.com/gh:NorfairKing:niks3/fix%2Fregister-completed-object/1745e6d569d601fcc3650ef4d243e46c97487012/f8319b23-92d1-4236-b08f-9544b0432dbe/wait

Latest logs, with timestamps (streams while running):

curl --netrc -N https://staging.nix-ci.com/gh:NorfairKing:niks3/fix%2Fregister-completed-object/1745e6d569d601fcc3650ef4d243e46c97487012/f8319b23-92d1-4236-b08f-9544b0432dbe/tail

All logs, with timestamps (available after completion):

curl --netrc https://staging.nix-ci.com/gh:NorfairKing:niks3/fix%2Fregister-completed-object/1745e6d569d601fcc3650ef4d243e46c97487012/f8319b23-92d1-4236-b08f-9544b0432dbe/logs

Raw logs, from the start (no timestamps):

curl --netrc -N https://staging.nix-ci.com/gh:NorfairKing:niks3/fix%2Fregister-completed-object/1745e6d569d601fcc3650ef4d243e46c97487012/f8319b23-92d1-4236-b08f-9544b0432dbe/raw-logs

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

Example:

curl --netrc -H "Accept: text/csv" https://staging.nix-ci.com/gh:NorfairKing:niks3/fix%2Fregister-completed-object/1745e6d569d601fcc3650ef4d243e46c97487012/f8319b23-92d1-4236-b08f-9544b0432dbe/logs

Reproduce locally: https://staging.nix-ci.com/gh:NorfairKing:niks3/fix%2Fregister-completed-object/1745e6d569d601fcc3650ef4d243e46c97487012/f8319b23-92d1-4236-b08f-9544b0432dbe/repro

This page is also available in machine-friendly formats. Request one with the Accept header:

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