1. 0.11 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=eefd861c77d20afa94829bc1a8c5d32eb3380e2d#checks.x86_64-linux.nixos-test-read-proxy --print-build-logs
  2. 0.13 s error (ignored): SQLite database '/var/cache/nix-ci-worker/eval-cache-v6/0916b3902447a65411a5be80f4931c12c8f6797170d994422823758d10214c86.sqlite' is busy
  3. 3.85 s
  4. 5.39 s Building /nix/store/zj0ym7cljqz3m2dsq1jhrjg4k20yi916-unit-niks3.service.drv
  5. 5.41 s [unit-niks3.service] structuredAttrs is enabled
  6. 5.45 s [unit-niks3.service:post-build] Uploading to the NixCI staging cache: /nix/store/4sh1ka3gazf97hpdxsnmn0vhlinxnv6h-unit-niks3.service
  7. 5.50 s [unit-niks3.service:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  8. 5.66 s [unit-niks3.service:post-build] copying 1 paths...
  9. 5.66 s [unit-niks3.service:post-build] copying path '/nix/store/4sh1ka3gazf97hpdxsnmn0vhlinxnv6h-unit-niks3.service' to 'https://cache.staging.nix-ci.com'...
  10. 5.88 s [unit-niks3.service:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  11. 6.14 s [unit-niks3.service:post-build] copying 1 paths...
  12. 6.15 s [unit-niks3.service:post-build] copying path '/nix/store/zj0ym7cljqz3m2dsq1jhrjg4k20yi916-unit-niks3.service.drv' to 'https://cache.staging.nix-ci.com'...
  13. 6.33 s Uploaded unit-niks3.service in 891ms
  14. 6.33 s Progress: 1 of 12 built
  15. 6.33 s Built unit-niks3.service in 935ms
  16. 6.40 s Building /nix/store/i9hnv8p30m9ypcmg2lg6b6q9b3f17a46-system-units.drv
  17. 10.75 s [system-units:post-build] Uploading to the NixCI staging cache: /nix/store/8kpbhiipij3zgzlmrf91bwzvzw39i94d-system-units
  18. 10.82 s [system-units:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  19. 11.00 s [system-units:post-build] copying 1 paths...
  20. 11.00 s [system-units:post-build] copying path '/nix/store/8kpbhiipij3zgzlmrf91bwzvzw39i94d-system-units' to 'https://cache.staging.nix-ci.com'...
  21. 11.25 s [system-units:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  22. 11.57 s [system-units:post-build] copying 1 paths...
  23. 11.80 s [system-units:post-build] copying path '/nix/store/i9hnv8p30m9ypcmg2lg6b6q9b3f17a46-system-units.drv' to 'https://cache.staging.nix-ci.com'...
  24. 11.89 s Uploaded system-units in 1.1s
  25. 11.89 s Progress: 2 of 12 built
  26. 11.89 s Built system-units in 5.4s
  27. 11.95 s Building /nix/store/a72vfdp0hxdxy560gklsa8h8k6ymflil-etc.drv
  28. 12.38 s [etc:post-build] Uploading to the NixCI staging cache: /nix/store/ykps6s3pmgkdrd5lmpq3j6xz3zx52gwz-etc
  29. 12.60 s [etc:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  30. 12.66 s [etc:post-build] copying 1 paths...
  31. 12.66 s [etc:post-build] copying path '/nix/store/ykps6s3pmgkdrd5lmpq3j6xz3zx52gwz-etc' to 'https://cache.staging.nix-ci.com'...
  32. 12.94 s [etc:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  33. 13.22 s [etc:post-build] copying 1 paths...
  34. 13.22 s [etc:post-build] copying path '/nix/store/a72vfdp0hxdxy560gklsa8h8k6ymflil-etc.drv' to 'https://cache.staging.nix-ci.com'...
  35. 13.44 s Uploaded etc in 1.0s
  36. 13.44 s Progress: 3 of 12 built
  37. 13.44 s Built etc in 1.4s
  38. 13.51 s Building /nix/store/yppvwhzmmmd0v7a2ga717dq3p1ykzy7s-activate.drv
  39. 13.59 s [activate:post-build] Uploading to the NixCI staging cache: /nix/store/3chcd4va24jfkifdy0bp912g0m6bqa9r-activate
  40. 13.63 s [activate:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  41. 13.67 s [activate:post-build] copying 1 paths...
  42. 13.67 s [activate:post-build] copying path '/nix/store/3chcd4va24jfkifdy0bp912g0m6bqa9r-activate' to 'https://cache.staging.nix-ci.com'...
  43. 13.96 s [activate:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  44. 14.38 s [activate:post-build] copying 1 paths...
  45. 14.38 s [activate:post-build] copying path '/nix/store/yppvwhzmmmd0v7a2ga717dq3p1ykzy7s-activate.drv' to 'https://cache.staging.nix-ci.com'...
  46. 14.57 s Uploaded activate in 994ms
  47. 14.57 s Progress: 4 of 12 built
  48. 14.57 s Built activate in 1.0s
  49. 14.63 s Building /nix/store/z749356q4ib8px6ykf6gacbsjpyp641f-nixos-system-server-test.drv
  50. 14.64 s [nixos-system-server-test] structuredAttrs is enabled
  51. 14.73 s [nixos-system-server-test:post-build] Uploading to the NixCI staging cache: /nix/store/n4h28d1k4sk3abz7hk7704rbifdvfpi4-nixos-system-server-test
  52. 14.78 s [nixos-system-server-test:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  53. 14.99 s [nixos-system-server-test:post-build] copying 1 paths...
  54. 14.99 s [nixos-system-server-test:post-build] copying path '/nix/store/n4h28d1k4sk3abz7hk7704rbifdvfpi4-nixos-system-server-test' to 'https://cache.staging.nix-ci.com'...
  55. 15.29 s [nixos-system-server-test:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  56. 15.62 s [nixos-system-server-test:post-build] copying 1 paths...
  57. 15.62 s [nixos-system-server-test:post-build] copying path '/nix/store/z749356q4ib8px6ykf6gacbsjpyp641f-nixos-system-server-test.drv' to 'https://cache.staging.nix-ci.com'...
  58. 15.81 s Uploaded nixos-system-server-test in 1.0s
  59. 15.84 s Progress: 5 of 12 built
  60. 15.84 s Built nixos-system-server-test in 1.2s
  61. 16.27 s Building /nix/store/y47fj3ik2wzh1dhfqycv33sr195q53i7-closure-info.drv
  62. 16.28 s [closure-info] structuredAttrs is enabled
  63. 16.37 s [closure-info:post-build] Uploading to the NixCI staging cache: /nix/store/szgfkawz7p3g491k1f7ggmg5sw37xkqz-closure-info
  64. 16.42 s [closure-info:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  65. 16.46 s [closure-info:post-build] copying 1 paths...
  66. 16.46 s [closure-info:post-build] copying path '/nix/store/szgfkawz7p3g491k1f7ggmg5sw37xkqz-closure-info' to 'https://cache.staging.nix-ci.com'...
  67. 16.78 s [closure-info:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  68. 17.12 s [closure-info:post-build] copying 1 paths...
  69. 17.12 s [closure-info:post-build] copying path '/nix/store/y47fj3ik2wzh1dhfqycv33sr195q53i7-closure-info.drv' to 'https://cache.staging.nix-ci.com'...
  70. 17.31 s Uploaded closure-info in 947ms
  71. 17.31 s Progress: 6 of 12 built
  72. 17.31 s Built closure-info in 1.0s
  73. 17.41 s Building /nix/store/wlrxa7104s4vg8n4irgidawks7g7kw6f-run-nixos-vm.drv
  74. 17.48 s [run-nixos-vm:post-build] Uploading to the NixCI staging cache: /nix/store/ismkjy49lydqv9v9yhz6nsbnnw330rfb-run-nixos-vm
  75. 17.53 s [run-nixos-vm:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  76. 17.74 s [run-nixos-vm:post-build] copying 1 paths...
  77. 17.74 s [run-nixos-vm:post-build] copying path '/nix/store/ismkjy49lydqv9v9yhz6nsbnnw330rfb-run-nixos-vm' to 'https://cache.staging.nix-ci.com'...
  78. 18.00 s [run-nixos-vm:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  79. 18.35 s [run-nixos-vm:post-build] copying 1 paths...
  80. 18.35 s [run-nixos-vm:post-build] copying path '/nix/store/wlrxa7104s4vg8n4irgidawks7g7kw6f-run-nixos-vm.drv' to 'https://cache.staging.nix-ci.com'...
  81. 18.57 s Uploaded run-nixos-vm in 1.0s
  82. 18.57 s Progress: 7 of 12 built
  83. 18.57 s Built run-nixos-vm in 1.1s
  84. 18.65 s Building /nix/store/hnfkl7kp76asxiyzhd9l7pavis92fvzr-nixos-vm.drv
  85. 18.72 s [nixos-vm:post-build] Uploading to the NixCI staging cache: /nix/store/7qzhj5np4s46g335b58xks5rbsc2dwqs-nixos-vm
  86. 18.78 s [nixos-vm:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  87. 18.82 s [nixos-vm:post-build] copying 1 paths...
  88. 18.82 s [nixos-vm:post-build] copying path '/nix/store/7qzhj5np4s46g335b58xks5rbsc2dwqs-nixos-vm' to 'https://cache.staging.nix-ci.com'...
  89. 19.08 s [nixos-vm:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  90. 19.37 s [nixos-vm:post-build] copying 1 paths...
  91. 19.38 s [nixos-vm:post-build] copying path '/nix/store/hnfkl7kp76asxiyzhd9l7pavis92fvzr-nixos-vm.drv' to 'https://cache.staging.nix-ci.com'...
  92. 19.60 s Uploaded nixos-vm in 889ms
  93. 19.60 s Progress: 8 of 12 built
  94. 19.60 s Built nixos-vm in 952ms
  95. 19.67 s Building /nix/store/4fn36asdqb7psxdzkm6j1x6076xy9ycr-driverConfiguration.json.drv
  96. 19.67 s [driverConfiguration.json] structuredAttrs is enabled
  97. 19.75 s [driverConfiguration.json:post-build] Uploading to the NixCI staging cache: /nix/store/j9r17sdpp41y1wqzzgwj8w468zfnknwx-driverConfiguration.json
  98. 19.81 s [driverConfiguration.json:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  99. 19.86 s [driverConfiguration.json:post-build] copying 1 paths...
  100. 19.86 s [driverConfiguration.json:post-build] copying path '/nix/store/j9r17sdpp41y1wqzzgwj8w468zfnknwx-driverConfiguration.json' to 'https://cache.staging.nix-ci.com'...
  101. 20.11 s [driverConfiguration.json:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  102. 20.40 s [driverConfiguration.json:post-build] copying 1 paths...
  103. 20.40 s [driverConfiguration.json:post-build] copying path '/nix/store/4fn36asdqb7psxdzkm6j1x6076xy9ycr-driverConfiguration.json.drv' to 'https://cache.staging.nix-ci.com'...
  104. 20.59 s Uploaded driverConfiguration.json in 845ms
  105. 20.59 s Progress: 9 of 12 built
  106. 20.59 s Built driverConfiguration.json in 919ms
  107. 20.66 s Building /nix/store/p8z2lr73w78lvpz8i8qxcm78i6dmcrb8-nixos-test-driver-nixos-test-read-proxy.drv
  108. 20.81 s [nixos-test-driver-nixos-test-read-proxy] Running type check (enable/disable: config.skipTypeCheck)
  109. 20.81 s [nixos-test-driver-nixos-test-read-proxy] See https://nixos.org/manual/nixos/stable/#test-opt-skipTypeCheck
  110. 20.86 s [nixos-test-driver-nixos-test-read-proxy] All checks passed!
  111. 20.90 s [nixos-test-driver-nixos-test-read-proxy] Linting test script (enable/disable: config.skipLint)
  112. 20.90 s [nixos-test-driver-nixos-test-read-proxy] See https://nixos.org/manual/nixos/stable/#test-opt-skipLint
  113. 20.90 s [nixos-test-driver-nixos-test-read-proxy] All checks passed!
  114. 20.92 s [nixos-test-driver-nixos-test-read-proxy:post-build] Uploading to the NixCI staging cache: /nix/store/fzjvgqir60fk4l8igiscxqispscrvwxj-nixos-test-driver-nixos-test-read-proxy
  115. 20.98 s [nixos-test-driver-nixos-test-read-proxy:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  116. 21.03 s [nixos-test-driver-nixos-test-read-proxy:post-build] copying 1 paths...
  117. 21.03 s [nixos-test-driver-nixos-test-read-proxy:post-build] copying path '/nix/store/fzjvgqir60fk4l8igiscxqispscrvwxj-nixos-test-driver-nixos-test-read-proxy' to 'https://cache.staging.nix-ci.com'...
  118. 21.31 s [nixos-test-driver-nixos-test-read-proxy:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  119. 21.71 s [nixos-test-driver-nixos-test-read-proxy:post-build] copying 1 paths...
  120. 21.71 s [nixos-test-driver-nixos-test-read-proxy:post-build] copying path '/nix/store/p8z2lr73w78lvpz8i8qxcm78i6dmcrb8-nixos-test-driver-nixos-test-read-proxy.drv' to 'https://cache.staging.nix-ci.com'...
  121. 21.93 s Uploaded nixos-test-driver-nixos-test-read-proxy in 1.0s
  122. 21.93 s Progress: 10 of 12 built
  123. 21.93 s Built nixos-test-driver-nixos-test-read-proxy in 1.2s
  124. 22.09 s Building /nix/store/ms2p1iciz03jp3bhxqbvssr7qz4wvq26-vm-test-run-nixos-test-read-proxy.drv
  125. 22.63 s [vm-test-run-nixos-test-read-proxy] Machine state will be reset. To keep it, pass --keep-machine-state
  126. 22.63 s [vm-test-run-nixos-test-read-proxy] start all VLans
  127. 22.63 s [vm-test-run-nixos-test-read-proxy] (finished: start all VLans, in 0.00 seconds)
  128. 22.63 s [vm-test-run-nixos-test-read-proxy] Test will time out and terminate in 3600 seconds
  129. 22.63 s [vm-test-run-nixos-test-read-proxy] run the VM test script
  130. 22.63 s [vm-test-run-nixos-test-read-proxy] additionally exposed symbols:
  131. 22.63 s [vm-test-run-nixos-test-read-proxy] server,
  132. 22.63 s [vm-test-run-nixos-test-read-proxy] vlan1,
  133. 22.63 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
  134. 22.63 s [vm-test-run-nixos-test-read-proxy] server: waiting for unit niks3.service
  135. 22.63 s [vm-test-run-nixos-test-read-proxy] server: waiting for the VM to finish booting
  136. 22.63 s [vm-test-run-nixos-test-read-proxy] server: starting vm
  137. 23.00 s [vm-test-run-nixos-test-read-proxy] server # Disk image does not exist, creating the virtualisation disk image...
  138. 23.00 s [vm-test-run-nixos-test-read-proxy] server # Formatting '/build/vm-state-server/tmp.QeUp8x21AD', fmt=raw size=1073741824
  139. 23.00 s [vm-test-run-nixos-test-read-proxy] server # mke2fs 1.47.4 (6-Mar-2025)
  140. 23.00 s [vm-test-run-nixos-test-read-proxy] server: QEMU running (pid 45)
  141. 23.00 s [vm-test-run-nixos-test-read-proxy] server # Discarding device blocks: 0/262144 done
  142. 23.00 s [vm-test-run-nixos-test-read-proxy] server # Creating filesystem with 262144 4k blocks and 65536 inodes
  143. 23.00 s [vm-test-run-nixos-test-read-proxy] server # Filesystem UUID: 3b7a8533-f130-4ace-9f7b-f504742e46c2
  144. 23.00 s [vm-test-run-nixos-test-read-proxy] server # Superblock backups stored on blocks:
  145. 23.00 s [vm-test-run-nixos-test-read-proxy] server # 32768, 98304, 163840, 229376
  146. 23.00 s [vm-test-run-nixos-test-read-proxy] server #
  147. 23.00 s [vm-test-run-nixos-test-read-proxy] server # Allocating group tables: 0/8 done
  148. 23.00 s [vm-test-run-nixos-test-read-proxy] server # Writing inode tables: 0/8 done
  149. 23.00 s [vm-test-run-nixos-test-read-proxy] server # Creating journal (8192 blocks): done
  150. 23.00 s [vm-test-run-nixos-test-read-proxy] server # Writing superblocks and filesystem accounting information: 0/8 done
  151. 23.00 s [vm-test-run-nixos-test-read-proxy] server #
  152. 23.00 s [vm-test-run-nixos-test-read-proxy] server # Virtualisation disk image created.
  153. 23.31 s [vm-test-run-nixos-test-read-proxy] server # c[?7lSeaBIOS (version rel-1.17.0-0-gb52ca86e094d-prebuilt.qemu.org)
  154. 23.36 s [vm-test-run-nixos-test-read-proxy] server #
  155. 23.36 s [vm-test-run-nixos-test-read-proxy] server #
  156. 23.37 s [vm-test-run-nixos-test-read-proxy] server # iPXE (http://ipxe.org) 00:03.0 CA00 PCI2.10 PnP PMM+3EFD1920+3EF31920 CA00
  157. 23.39 s [vm-test-run-nixos-test-read-proxy] server # Press Ctrl-B to configure iPXE (PCI 00:03.0)...
  158. 23.39 s [vm-test-run-nixos-test-read-proxy] server #
  159. 23.39 s [vm-test-run-nixos-test-read-proxy] server #
  160. 23.39 s [vm-test-run-nixos-test-read-proxy] server #
  161. 23.39 s [vm-test-run-nixos-test-read-proxy] server #
  162. 23.39 s [vm-test-run-nixos-test-read-proxy] server # iPXE (http://ipxe.org) 00:09.0 CB00 PCI2.10 PnP PMM 3EFD1920 3EF31920 CB00
  163. 23.41 s [vm-test-run-nixos-test-read-proxy] server # Press Ctrl-B to configure iPXE (PCI 00:09.0)...
  164. 23.41 s [vm-test-run-nixos-test-read-proxy] server #
  165. 23.41 s [vm-test-run-nixos-test-read-proxy] server #
  166. 23.42 s [vm-test-run-nixos-test-read-proxy] server # Booting from ROM...
  167. 23.47 s [vm-test-run-nixos-test-read-proxy] server # Probing EDD (edd=off to disable)... ok
  168. 24.84 s [vm-test-run-nixos-test-read-proxy] server # c[?7l[ 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
  169. 24.85 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/n4h28d1k4sk3abz7hk7704rbifdvfpi4-nixos-system-server-test/init regInfo=/nix/store/szgfkawz7p3g491k1f7ggmg5sw37xkqz-closure-info/registration console=ttyS0,115200n8 console=tty0
  170. 24.85 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.
  171. 24.86 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] BIOS-provided physical RAM map:
  172. 24.86 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
  173. 24.86 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
  174. 24.86 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
  175. 24.86 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000003ffdafff] usable
  176. 24.87 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] BIOS-e820: [mem 0x000000003ffdb000-0x000000003fffffff] reserved
  177. 24.87 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
  178. 24.87 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
  179. 24.87 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] BIOS-e820: [mem 0x000000fd00000000-0x000000ffffffffff] reserved
  180. 24.87 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] NX (Execute Disable) protection: active
  181. 24.88 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] APIC: Static calls initialized
  182. 24.88 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] SMBIOS 2.8 present.
  183. 24.88 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
  184. 24.88 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] DMI: Memory slots populated: 1/1
  185. 24.88 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] Hypervisor detected: KVM
  186. 24.88 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
  187. 24.89 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
  188. 24.89 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000001] kvm-clock: using sched offset of 1638375614 cycles
  189. 24.89 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000002] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
  190. 24.89 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000006] tsc: Detected 3399.998 MHz processor
  191. 24.89 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000696] last_pfn = 0x3ffdb max_arch_pfn = 0x400000000
  192. 24.90 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000910] MTRR map: 4 entries (3 fixed + 1 variable; max 19), built from 8 variable MTRRs
  193. 24.90 s [vm-test-run-nixos-test-read-proxy] server # [ 0.000918] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT
  194. 24.90 s [vm-test-run-nixos-test-read-proxy] server # [ 0.002742] found SMP MP-table at [mem 0x000f5470-0x000f547f]
  195. 24.90 s [vm-test-run-nixos-test-read-proxy] server # [ 0.002755] Using GB pages for direct mapping
  196. 24.90 s [vm-test-run-nixos-test-read-proxy] server # [ 0.002806] RAMDISK: [mem 0x3e302000-0x3ffcffff]
  197. 24.91 s [vm-test-run-nixos-test-read-proxy] server # [ 0.002847] ACPI: Early table checksum verification disabled
  198. 24.91 s [vm-test-run-nixos-test-read-proxy] server # [ 0.002850] ACPI: RSDP 0x00000000000F5290 000014 (v00 BOCHS )
  199. 24.91 s [vm-test-run-nixos-test-read-proxy] server # [ 0.002853] ACPI: RSDT 0x000000003FFE23CC 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  200. 24.91 s [vm-test-run-nixos-test-read-proxy] server # [ 0.002858] ACPI: FACP 0x000000003FFE2280 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  201. 24.91 s [vm-test-run-nixos-test-read-proxy] server # [ 0.002880] ACPI: DSDT 0x000000003FFE0040 002240 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  202. 24.92 s [vm-test-run-nixos-test-read-proxy] server # [ 0.002882] ACPI: FACS 0x000000003FFE0000 000040
  203. 24.92 s [vm-test-run-nixos-test-read-proxy] server # [ 0.002884] ACPI: APIC 0x000000003FFE22F4 000078 (v03 BOCHS BXPC 00000001 BXPC 00000001)
  204. 24.92 s [vm-test-run-nixos-test-read-proxy] server # [ 0.002885] ACPI: HPET 0x000000003FFE236C 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  205. 24.92 s [vm-test-run-nixos-test-read-proxy] server # [ 0.002886] ACPI: WAET 0x000000003FFE23A4 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001)
  206. 24.93 s [vm-test-run-nixos-test-read-proxy] server # [ 0.002888] ACPI: Reserving FACP table memory at [mem 0x3ffe2280-0x3ffe22f3]
  207. 24.93 s [vm-test-run-nixos-test-read-proxy] server # [ 0.002889] ACPI: Reserving DSDT table memory at [mem 0x3ffe0040-0x3ffe227f]
  208. 24.93 s [vm-test-run-nixos-test-read-proxy] server # [ 0.002889] ACPI: Reserving FACS table memory at [mem 0x3ffe0000-0x3ffe003f]
  209. 24.93 s [vm-test-run-nixos-test-read-proxy] server # [ 0.002890] ACPI: Reserving APIC table memory at [mem 0x3ffe22f4-0x3ffe236b]
  210. 24.94 s [vm-test-run-nixos-test-read-proxy] server # [ 0.002890] ACPI: Reserving HPET table memory at [mem 0x3ffe236c-0x3ffe23a3]
  211. 24.94 s [vm-test-run-nixos-test-read-proxy] server # [ 0.002890] ACPI: Reserving WAET table memory at [mem 0x3ffe23a4-0x3ffe23cb]
  212. 24.94 s [vm-test-run-nixos-test-read-proxy] server # [ 0.003630] No NUMA configuration found
  213. 24.94 s [vm-test-run-nixos-test-read-proxy] server # [ 0.003631] Faking a node at [mem 0x0000000000000000-0x000000003ffdafff]
  214. 24.94 s [vm-test-run-nixos-test-read-proxy] server # [ 0.003633] NODE_DATA(0) allocated [mem 0x3ffd5780-0x3ffdacff]
  215. 24.95 s [vm-test-run-nixos-test-read-proxy] server # [ 0.004122] Zone ranges:
  216. 24.95 s [vm-test-run-nixos-test-read-proxy] server # [ 0.004123] DMA [mem 0x0000000000001000-0x0000000000ffffff]
  217. 24.95 s [vm-test-run-nixos-test-read-proxy] server # [ 0.004124] DMA32 [mem 0x0000000001000000-0x000000003ffdafff]
  218. 24.95 s [vm-test-run-nixos-test-read-proxy] server # [ 0.004125] Normal empty
  219. 24.95 s [vm-test-run-nixos-test-read-proxy] server # [ 0.004126] Device empty
  220. 24.95 s [vm-test-run-nixos-test-read-proxy] server # [ 0.004126] Movable zone start for each node
  221. 24.95 s [vm-test-run-nixos-test-read-proxy] server # [ 0.004127] Early memory node ranges
  222. 24.96 s [vm-test-run-nixos-test-read-proxy] server # [ 0.004127] node 0: [mem 0x0000000000001000-0x000000000009efff]
  223. 24.96 s [vm-test-run-nixos-test-read-proxy] server # [ 0.004128] node 0: [mem 0x0000000000100000-0x000000003ffdafff]
  224. 24.96 s [vm-test-run-nixos-test-read-proxy] server # [ 0.004129] Initmem setup node 0 [mem 0x0000000000001000-0x000000003ffdafff]
  225. 24.96 s [vm-test-run-nixos-test-read-proxy] server # [ 0.004195] On node 0, zone DMA: 1 pages in unavailable ranges
  226. 24.96 s [vm-test-run-nixos-test-read-proxy] server # [ 0.005354] On node 0, zone DMA: 97 pages in unavailable ranges
  227. 24.97 s [vm-test-run-nixos-test-read-proxy] server # [ 0.156034] On node 0, zone DMA32: 37 pages in unavailable ranges
  228. 24.97 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157657] ACPI: PM-Timer IO Port: 0x608
  229. 24.97 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157687] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
  230. 24.97 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157775] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
  231. 24.97 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157777] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
  232. 24.97 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157779] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
  233. 24.98 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157780] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
  234. 24.98 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157780] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
  235. 24.98 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157781] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
  236. 24.98 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157783] ACPI: Using ACPI (MADT) for SMP configuration information
  237. 24.99 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157784] ACPI: HPET id: 0x8086a201 base: 0xfed00000
  238. 24.99 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157789] TSC deadline timer available
  239. 24.99 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157793] CPU topo: Max. logical packages: 1
  240. 24.99 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157794] CPU topo: Max. logical dies: 1
  241. 24.99 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157794] CPU topo: Max. dies per package: 1
  242. 24.99 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157797] CPU topo: Max. threads per core: 1
  243. 24.99 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157798] CPU topo: Num. cores per package: 1
  244. 25.00 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157798] CPU topo: Num. threads per package: 1
  245. 25.00 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157798] CPU topo: Allowing 1 present CPUs plus 0 hotplug CPUs
  246. 25.00 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157846] kvm-guest: APIC: eoi() replaced with kvm_guest_apic_eoi_write()
  247. 25.00 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157935] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]
  248. 25.00 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157936] PM: hibernation: Registered nosave memory: [mem 0x0009f000-0x000fffff]
  249. 25.01 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157937] [mem 0x40000000-0xfeffbfff] available for PCI devices
  250. 25.01 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157939] Booting paravirtualized kernel on KVM
  251. 25.01 s [vm-test-run-nixos-test-read-proxy] server # [ 0.157942] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
  252. 25.01 s [vm-test-run-nixos-test-read-proxy] server # [ 0.161788] setup_percpu: NR_CPUS:384 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1
  253. 25.02 s [vm-test-run-nixos-test-read-proxy] server # [ 0.183579] percpu: Embedded 98 pages/cpu s278528 r8192 d114688 u2097152
  254. 25.02 s [vm-test-run-nixos-test-read-proxy] server # [ 0.183739] kvm-guest: PV spinlocks disabled, single CPU
  255. 25.03 s [vm-test-run-nixos-test-read-proxy] server # [ 0.183741] 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/n4h28d1k4sk3abz7hk7704rbifdvfpi4-nixos-system-server-test/init regInfo=/nix/store/szgfkawz7p3g491k1f7ggmg5sw37xkqz-closure-info/registration console=ttyS0,115200n8 console=tty0
  256. 25.03 s [vm-test-run-nixos-test-read-proxy] server # [ 0.183843] Unknown kernel command line parameters "regInfo=/nix/store/szgfkawz7p3g491k1f7ggmg5sw37xkqz-closure-info/registration", will be passed to user space.
  257. 25.03 s [vm-test-run-nixos-test-read-proxy] server # [ 0.183860] random: crng init done
  258. 25.04 s [vm-test-run-nixos-test-read-proxy] server # [ 0.183861] printk: log buffer data + meta data: 262144 + 917504 = 1179648 bytes
  259. 25.04 s [vm-test-run-nixos-test-read-proxy] server # [ 0.183907] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
  260. 25.04 s [vm-test-run-nixos-test-read-proxy] server # [ 0.187162] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)
  261. 25.04 s [vm-test-run-nixos-test-read-proxy] server # [ 0.187244] Fallback order for Node 0: 0
  262. 25.04 s [vm-test-run-nixos-test-read-proxy] server # [ 0.187247] Built 1 zonelists, mobility grouping on. Total pages: 262009
  263. 25.05 s [vm-test-run-nixos-test-read-proxy] server # [ 0.187248] Policy zone: DMA32
  264. 25.05 s [vm-test-run-nixos-test-read-proxy] server # [ 0.206776] mem auto-init: stack:all(zero), heap alloc:on, heap free:off
  265. 25.05 s [vm-test-run-nixos-test-read-proxy] server # [ 0.211947] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
  266. 25.05 s [vm-test-run-nixos-test-read-proxy] server # [ 0.231442] allocated 2097152 bytes of page_ext
  267. 25.05 s [vm-test-run-nixos-test-read-proxy] server # [ 0.250367] ftrace: allocating 48598 entries in 192 pages
  268. 25.05 s [vm-test-run-nixos-test-read-proxy] server # [ 0.250369] ftrace: allocated 192 pages with 2 groups
  269. 25.06 s [vm-test-run-nixos-test-read-proxy] server # [ 0.254943] Dynamic Preempt: lazy
  270. 25.06 s [vm-test-run-nixos-test-read-proxy] server # [ 0.256399] rcu: Preemptible hierarchical RCU implementation.
  271. 25.06 s [vm-test-run-nixos-test-read-proxy] server # [ 0.256399] rcu: RCU event tracing is enabled.
  272. 25.06 s [vm-test-run-nixos-test-read-proxy] server # [ 0.256400] rcu: RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=1.
  273. 25.06 s [vm-test-run-nixos-test-read-proxy] server # [ 0.256401] Trampoline variant of Tasks RCU enabled.
  274. 25.06 s [vm-test-run-nixos-test-read-proxy] server # [ 0.256402] Rude variant of Tasks RCU enabled.
  275. 25.07 s [vm-test-run-nixos-test-read-proxy] server # [ 0.256402] Tracing variant of Tasks RCU enabled.
  276. 25.07 s [vm-test-run-nixos-test-read-proxy] server # [ 0.256402] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.
  277. 25.07 s [vm-test-run-nixos-test-read-proxy] server # [ 0.256403] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
  278. 25.07 s [vm-test-run-nixos-test-read-proxy] server # [ 0.256512] RCU Tasks: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  279. 25.08 s [vm-test-run-nixos-test-read-proxy] server # [ 0.256513] RCU Tasks Rude: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  280. 25.08 s [vm-test-run-nixos-test-read-proxy] server # [ 0.256514] RCU Tasks Trace: Setting shift to 0 and lim to 1 rcu_task_cb_adjust=1 rcu_task_cpu_ids=1.
  281. 25.08 s [vm-test-run-nixos-test-read-proxy] server # [ 0.265336] NR_IRQS: 24832, nr_irqs: 256, preallocated irqs: 16
  282. 25.08 s [vm-test-run-nixos-test-read-proxy] server # [ 0.266156] rcu: srcu_init: Setting srcu_struct sizes based on contention.
  283. 25.09 s [vm-test-run-nixos-test-read-proxy] server # [ 0.266275] kfence: initialized - using 2097152 bytes for 255 objects at 0x(____ptrval____)-0x(____ptrval____)
  284. 25.09 s [vm-test-run-nixos-test-read-proxy] server # [ 0.280338] Console: colour VGA+ 80x25
  285. 25.09 s [vm-test-run-nixos-test-read-proxy] server # [ 0.280341] printk: legacy console [tty0] enabled
  286. 25.09 s [vm-test-run-nixos-test-read-proxy] server # [ 0.387900] printk: legacy console [ttyS0] enabled
  287. 25.09 s [vm-test-run-nixos-test-read-proxy] server # [ 0.644544] ACPI: Core revision 20250807
  288. 25.10 s [vm-test-run-nixos-test-read-proxy] server # [ 0.647190] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
  289. 25.10 s [vm-test-run-nixos-test-read-proxy] server # [ 0.651596] APIC: Switch to symmetric I/O mode setup
  290. 25.10 s [vm-test-run-nixos-test-read-proxy] server # [ 0.654940] x2apic enabled
  291. 25.11 s [vm-test-run-nixos-test-read-proxy] server # [ 0.657342] APIC: Switched APIC routing to: physical x2apic
  292. 25.42 s [vm-test-run-nixos-test-read-proxy] server # [ 0.969337] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
  293. 25.42 s [vm-test-run-nixos-test-read-proxy] server # [ 0.972058] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x31024cfe468, max_idle_ns: 440795307017 ns
  294. 25.43 s [vm-test-run-nixos-test-read-proxy] server # [ 0.976624] Calibrating delay loop (skipped) preset value.. 6799.99 BogoMIPS (lpj=3399998)
  295. 25.43 s [vm-test-run-nixos-test-read-proxy] server # [ 0.979931] x86/cpu: User Mode Instruction Prevention (UMIP) activated
  296. 25.43 s [vm-test-run-nixos-test-read-proxy] server # [ 0.982309] Last level iTLB entries: 4KB 512, 2MB 255, 4MB 127
  297. 25.44 s [vm-test-run-nixos-test-read-proxy] server # [ 0.983622] Last level dTLB entries: 4KB 512, 2MB 255, 4MB 127, 1GB 0
  298. 25.44 s [vm-test-run-nixos-test-read-proxy] server # [ 0.985633] mitigations: Enabled attack vectors: user_kernel, user_user, guest_host, guest_guest, SMT mitigations: auto
  299. 25.45 s [vm-test-run-nixos-test-read-proxy] server # [ 0.987622] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl
  300. 25.45 s [vm-test-run-nixos-test-read-proxy] server # [ 0.989622] Spectre V2 : Mitigation: Retpolines
  301. 25.45 s [vm-test-run-nixos-test-read-proxy] server # [ 0.990623] Speculative Return Stack Overflow: Mitigation: Safe RET
  302. 25.45 s [vm-test-run-nixos-test-read-proxy] server # [ 0.992622] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
  303. 25.46 s [vm-test-run-nixos-test-read-proxy] server # [ 0.994622] Spectre V2 : Spectre v2 / SpectreRSB: Filling RSB on context switch and VMEXIT
  304. 25.46 s [vm-test-run-nixos-test-read-proxy] server # [ 0.996622] Spectre V2 : Enabling Restricted Speculation for firmware calls
  305. 25.46 s [vm-test-run-nixos-test-read-proxy] server # [ 0.998625] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
  306. 25.48 s [vm-test-run-nixos-test-read-proxy] server # [ 1.000623] active return thunk: srso_alias_return_thunk
  307. 25.48 s [vm-test-run-nixos-test-read-proxy] server # [ 1.002704] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
  308. 25.48 s [vm-test-run-nixos-test-read-proxy] server # [ 1.004622] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
  309. 25.49 s [vm-test-run-nixos-test-read-proxy] server # [ 1.006622] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
  310. 25.49 s [vm-test-run-nixos-test-read-proxy] server # [ 1.008622] x86/fpu: Supporting XSAVE feature 0x200: 'Protection Keys User registers'
  311. 25.49 s [vm-test-run-nixos-test-read-proxy] server # [ 1.010622] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256
  312. 25.50 s [vm-test-run-nixos-test-read-proxy] server # [ 1.012623] x86/fpu: xstate_offset[9]: 832, xstate_sizes[9]: 8
  313. 25.50 s [vm-test-run-nixos-test-read-proxy] server # [ 1.014623] x86/fpu: Enabled xstate features 0x207, context size is 840 bytes, using 'compacted' format.
  314. 25.53 s [vm-test-run-nixos-test-read-proxy] server # [ 1.047782] Freeing SMP alternatives memory: 44K
  315. 25.54 s [vm-test-run-nixos-test-read-proxy] server # [ 1.048625] pid_max: default: 32768 minimum: 301
  316. 25.54 s [vm-test-run-nixos-test-read-proxy] server # [ 1.050803] LSM: initializing lsm=capability,landlock,yama,bpf,ima
  317. 25.54 s [vm-test-run-nixos-test-read-proxy] server # [ 1.052726] landlock: Up and running.
  318. 25.54 s [vm-test-run-nixos-test-read-proxy] server # [ 1.053622] Yama: becoming mindful.
  319. 25.54 s [vm-test-run-nixos-test-read-proxy] server # [ 1.054847] LSM support for eBPF active
  320. 25.55 s [vm-test-run-nixos-test-read-proxy] server # [ 1.057755] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
  321. 25.55 s [vm-test-run-nixos-test-read-proxy] server # [ 1.059795] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
  322. 25.56 s [vm-test-run-nixos-test-read-proxy] server # [ 1.066850] smpboot: CPU0: AMD Ryzen 9 5950X 16-Core Processor (family: 0x19, model: 0x21, stepping: 0x0)
  323. 25.57 s [vm-test-run-nixos-test-read-proxy] server # [ 1.071548] Performance Events: Fam17h+ core perfctr, AMD PMU driver.
  324. 25.57 s [vm-test-run-nixos-test-read-proxy] server # [ 1.072635] ... version: 0
  325. 25.57 s [vm-test-run-nixos-test-read-proxy] server # [ 1.073825] ... bit width: 48
  326. 25.57 s [vm-test-run-nixos-test-read-proxy] server # [ 1.074628] ... generic counters: 6
  327. 25.58 s [vm-test-run-nixos-test-read-proxy] server # [ 1.075628] ... generic bitmap: 000000000000003f
  328. 25.58 s [vm-test-run-nixos-test-read-proxy] server # [ 1.076627] ... fixed-purpose counters: 0
  329. 25.58 s [vm-test-run-nixos-test-read-proxy] server # [ 1.077628] ... fixed-purpose bitmap: 0000000000000000
  330. 25.58 s [vm-test-run-nixos-test-read-proxy] server # [ 1.078628] ... value mask: 0000ffffffffffff
  331. 25.59 s [vm-test-run-nixos-test-read-proxy] server # [ 1.079628] ... max period: 00007fffffffffff
  332. 25.59 s [vm-test-run-nixos-test-read-proxy] server # [ 1.080628] ... global_ctrl mask: 000000000000003f
  333. 25.59 s [vm-test-run-nixos-test-read-proxy] server # [ 1.081739] signal: max sigframe size: 3376
  334. 25.59 s [vm-test-run-nixos-test-read-proxy] server # [ 1.083183] rcu: Hierarchical SRCU implementation.
  335. 25.60 s [vm-test-run-nixos-test-read-proxy] server # [ 1.084634] rcu: Max phase no-delay instances is 400.
  336. 25.60 s [vm-test-run-nixos-test-read-proxy] server # [ 1.091997] smp: Bringing up secondary CPUs ...
  337. 25.61 s [vm-test-run-nixos-test-read-proxy] server # [ 1.093640] smp: Brought up 1 node, 1 CPU
  338. 25.61 s [vm-test-run-nixos-test-read-proxy] server # [ 1.094630] smpboot: Total of 1 processors activated (6799.99 BogoMIPS)
  339. 25.62 s [vm-test-run-nixos-test-read-proxy] server # [ 1.096539] Memory: 942840K/1048036K available (17159K kernel code, 2721K rwdata, 13540K rodata, 3636K init, 3020K bss, 98000K reserved, 0K cma-reserved)
  340. 25.62 s [vm-test-run-nixos-test-read-proxy] server # [ 1.098473] devtmpfs: initialized
  341. 25.62 s [vm-test-run-nixos-test-read-proxy] server # [ 1.100845] x86/mm: Memory block size: 128MB
  342. 25.63 s [vm-test-run-nixos-test-read-proxy] server # [ 1.104570] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
  343. 25.63 s [vm-test-run-nixos-test-read-proxy] server # [ 1.105746] posixtimers hash table entries: 512 (order: 1, 8192 bytes, linear)
  344. 25.64 s [vm-test-run-nixos-test-read-proxy] server # [ 1.107826] futex hash table entries: 256 (16384 bytes on 1 NUMA nodes, total 16 KiB, linear).
  345. 25.64 s [vm-test-run-nixos-test-read-proxy] server # [ 1.109805] pinctrl core: initialized pinctrl subsystem
  346. 25.64 s [vm-test-run-nixos-test-read-proxy] server # [ 1.111392] PM: RTC time: 09:28:29, date: 2026-07-19
  347. 25.66 s [vm-test-run-nixos-test-read-proxy] server # [ 1.130947] NET: Registered PF_NETLINK/PF_ROUTE protocol family
  348. 25.67 s [vm-test-run-nixos-test-read-proxy] server # [ 1.134051] DMA: preallocated 128 KiB GFP_KERNEL pool for atomic allocations
  349. 25.67 s [vm-test-run-nixos-test-read-proxy] server # [ 1.135694] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
  350. 25.68 s [vm-test-run-nixos-test-read-proxy] server # [ 1.138466] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
  351. 25.68 s [vm-test-run-nixos-test-read-proxy] server # [ 1.139645] audit: initializing netlink subsys (disabled)
  352. 25.68 s [vm-test-run-nixos-test-read-proxy] server # [ 1.141631] audit: type=2000 audit(1784453309.080:1): state=initialized audit_enabled=0 res=1
  353. 25.69 s [vm-test-run-nixos-test-read-proxy] server # [ 1.143827] thermal_sys: Registered thermal governor 'fair_share'
  354. 25.69 s [vm-test-run-nixos-test-read-proxy] server # [ 1.143829] thermal_sys: Registered thermal governor 'bang_bang'
  355. 25.69 s [vm-test-run-nixos-test-read-proxy] server # [ 1.145634] thermal_sys: Registered thermal governor 'step_wise'
  356. 25.70 s [vm-test-run-nixos-test-read-proxy] server # [ 1.146628] thermal_sys: Registered thermal governor 'user_space'
  357. 25.70 s [vm-test-run-nixos-test-read-proxy] server # [ 1.147628] thermal_sys: Registered thermal governor 'power_allocator'
  358. 25.70 s [vm-test-run-nixos-test-read-proxy] server # [ 1.148695] cpuidle: using governor menu
  359. 25.70 s [vm-test-run-nixos-test-read-proxy] server # [ 1.152489] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
  360. 25.71 s [vm-test-run-nixos-test-read-proxy] server # [ 1.154732] PCI: Using configuration type 1 for base access
  361. 25.71 s [vm-test-run-nixos-test-read-proxy] server # [ 1.155628] PCI: Using configuration type 1 for extended access
  362. 25.72 s [vm-test-run-nixos-test-read-proxy] server # [ 1.156972] kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible.
  363. 25.73 s [vm-test-run-nixos-test-read-proxy] server # [ 1.169738] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages
  364. 25.74 s [vm-test-run-nixos-test-read-proxy] server # [ 1.175628] HugeTLB: 16380 KiB vmemmap can be freed for a 1.00 GiB page
  365. 25.74 s [vm-test-run-nixos-test-read-proxy] server # [ 1.176633] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
  366. 25.75 s [vm-test-run-nixos-test-read-proxy] server # [ 1.181629] HugeTLB: 28 KiB vmemmap can be freed for a 2.00 MiB page
  367. 25.76 s [vm-test-run-nixos-test-read-proxy] server # [ 1.192502] ACPI: Added _OSI(Module Device)
  368. 25.76 s [vm-test-run-nixos-test-read-proxy] server # [ 1.195630] ACPI: Added _OSI(Processor Device)
  369. 25.77 s [vm-test-run-nixos-test-read-proxy] server # [ 1.196629] ACPI: Added _OSI(Processor Aggregator Device)
  370. 25.78 s [vm-test-run-nixos-test-read-proxy] server # [ 1.203845] ACPI: 1 ACPI AML tables successfully acquired and loaded
  371. 25.78 s [vm-test-run-nixos-test-read-proxy] server # [ 1.207251] ACPI: Interpreter enabled
  372. 25.78 s [vm-test-run-nixos-test-read-proxy] server # [ 1.208646] ACPI: PM: (supports S0 S3 S4 S5)
  373. 25.78 s [vm-test-run-nixos-test-read-proxy] server # [ 1.209629] ACPI: Using IOAPIC for interrupt routing
  374. 25.79 s [vm-test-run-nixos-test-read-proxy] server # [ 1.210652] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
  375. 25.79 s [vm-test-run-nixos-test-read-proxy] server # [ 1.212628] PCI: Using E820 reservations for host bridge windows
  376. 25.79 s [vm-test-run-nixos-test-read-proxy] server # [ 1.213807] ACPI: Enabled 2 GPEs in block 00 to 0F
  377. 25.81 s [vm-test-run-nixos-test-read-proxy] server # [ 1.222969] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
  378. 25.81 s [vm-test-run-nixos-test-read-proxy] server # [ 1.224633] acpi PNP0A03:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3]
  379. 25.81 s [vm-test-run-nixos-test-read-proxy] server # [ 1.227087] acpiphp: Slot [3] registered
  380. 25.81 s [vm-test-run-nixos-test-read-proxy] server # [ 1.228748] acpiphp: Slot [4] registered
  381. 25.82 s [vm-test-run-nixos-test-read-proxy] server # [ 1.229668] acpiphp: Slot [5] registered
  382. 25.82 s [vm-test-run-nixos-test-read-proxy] server # [ 1.230668] acpiphp: Slot [6] registered
  383. 25.82 s [vm-test-run-nixos-test-read-proxy] server # [ 1.231667] acpiphp: Slot [7] registered
  384. 25.82 s [vm-test-run-nixos-test-read-proxy] server # [ 1.232794] acpiphp: Slot [8] registered
  385. 25.82 s [vm-test-run-nixos-test-read-proxy] server # [ 1.233667] acpiphp: Slot [9] registered
  386. 25.82 s [vm-test-run-nixos-test-read-proxy] server # [ 1.234673] acpiphp: Slot [10] registered
  387. 25.83 s [vm-test-run-nixos-test-read-proxy] server # [ 1.235668] acpiphp: Slot [11] registered
  388. 25.83 s [vm-test-run-nixos-test-read-proxy] server # [ 1.236724] acpiphp: Slot [12] registered
  389. 25.83 s [vm-test-run-nixos-test-read-proxy] server # [ 1.237667] acpiphp: Slot [13] registered
  390. 25.83 s [vm-test-run-nixos-test-read-proxy] server # [ 1.238666] acpiphp: Slot [14] registered
  391. 25.83 s [vm-test-run-nixos-test-read-proxy] server # [ 1.239666] acpiphp: Slot [15] registered
  392. 25.84 s [vm-test-run-nixos-test-read-proxy] server # [ 1.240722] acpiphp: Slot [16] registered
  393. 25.84 s [vm-test-run-nixos-test-read-proxy] server # [ 1.241667] acpiphp: Slot [17] registered
  394. 25.84 s [vm-test-run-nixos-test-read-proxy] server # [ 1.242669] acpiphp: Slot [18] registered
  395. 25.84 s [vm-test-run-nixos-test-read-proxy] server # [ 1.243723] acpiphp: Slot [19] registered
  396. 25.84 s [vm-test-run-nixos-test-read-proxy] server # [ 1.244667] acpiphp: Slot [20] registered
  397. 25.85 s [vm-test-run-nixos-test-read-proxy] server # [ 1.245668] acpiphp: Slot [21] registered
  398. 25.85 s [vm-test-run-nixos-test-read-proxy] server # [ 1.246683] acpiphp: Slot [22] registered
  399. 25.85 s [vm-test-run-nixos-test-read-proxy] server # [ 1.247750] acpiphp: Slot [23] registered
  400. 25.85 s [vm-test-run-nixos-test-read-proxy] server # [ 1.248666] acpiphp: Slot [24] registered
  401. 25.85 s [vm-test-run-nixos-test-read-proxy] server # [ 1.249666] acpiphp: Slot [25] registered
  402. 25.86 s [vm-test-run-nixos-test-read-proxy] server # [ 1.250667] acpiphp: Slot [26] registered
  403. 25.86 s [vm-test-run-nixos-test-read-proxy] server # [ 1.251727] acpiphp: Slot [27] registered
  404. 25.99 s [vm-test-run-nixos-test-read-proxy] server # [ 1.252669] acpiphp: Slot [28] registered
  405. 25.99 s [vm-test-run-nixos-test-read-proxy] server # [ 1.253666] acpiphp: Slot [29] registered
  406. 25.99 s [vm-test-run-nixos-test-read-proxy] server # [ 1.254727] acpiphp: Slot [30] registered
  407. 25.99 s [vm-test-run-nixos-test-read-proxy] server # [ 1.255725] acpiphp: Slot [31] registered
  408. 25.99 s [vm-test-run-nixos-test-read-proxy] server # [ 1.256660] PCI host bridge to bus 0000:00
  409. 25.99 s [vm-test-run-nixos-test-read-proxy] server # [ 1.257637] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]
  410. 25.99 s [vm-test-run-nixos-test-read-proxy] server # [ 1.258629] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]
  411. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.259629] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
  412. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.261628] pci_bus 0000:00: root bus resource [mem 0x40000000-0xfebfffff window]
  413. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.263628] pci_bus 0000:00: root bus resource [mem 0x100000000-0x17fffffff window]
  414. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.265629] pci_bus 0000:00: root bus resource [bus 00-ff]
  415. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.267593] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000 conventional PCI endpoint
  416. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.270183] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100 conventional PCI endpoint
  417. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.273093] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180 conventional PCI endpoint
  418. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.276187] pci 0000:00:01.1: BAR 4 [io 0xc1e0-0xc1ef]
  419. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.277765] pci 0000:00:01.1: BAR 0 [io 0x01f0-0x01f7]: legacy IDE quirk
  420. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.279628] pci 0000:00:01.1: BAR 1 [io 0x03f6]: legacy IDE quirk
  421. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.280635] pci 0000:00:01.1: BAR 2 [io 0x0170-0x0177]: legacy IDE quirk
  422. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.281628] pci 0000:00:01.1: BAR 3 [io 0x0376]: legacy IDE quirk
  423. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.283265] pci 0000:00:01.2: [8086:7020] type 00 class 0x0c0300 conventional PCI endpoint
  424. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.286314] pci 0000:00:01.2: BAR 4 [io 0xc100-0xc11f]
  425. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.289258] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000 conventional PCI endpoint
  426. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.291628] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI
  427. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.293652] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB
  428. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.295343] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000 conventional PCI endpoint
  429. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.299344] pci 0000:00:02.0: BAR 0 [mem 0xfd000000-0xfdffffff pref]
  430. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.301694] pci 0000:00:02.0: BAR 2 [mem 0xfebd0000-0xfebd0fff]
  431. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.302732] pci 0000:00:02.0: ROM [mem 0xfebc0000-0xfebcffff pref]
  432. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.305328] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
  433. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.312916] pci 0000:00:03.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
  434. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.316651] pci 0000:00:03.0: BAR 0 [io 0xc120-0xc13f]
  435. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.317652] pci 0000:00:03.0: BAR 1 [mem 0xfebd1000-0xfebd1fff]
  436. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.318710] pci 0000:00:03.0: BAR 4 [mem 0xfe000000-0xfe003fff 64bit pref]
  437. 26.00 s [vm-test-run-nixos-test-read-proxy] server # [ 1.319681] pci 0000:00:03.0: ROM [mem 0xfeb40000-0xfeb7ffff pref]
  438. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.327060] pci 0000:00:04.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
  439. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.330665] pci 0000:00:04.0: BAR 0 [io 0xc140-0xc15f]
  440. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.331661] pci 0000:00:04.0: BAR 1 [mem 0xfebd2000-0xfebd2fff]
  441. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.332715] pci 0000:00:04.0: BAR 4 [mem 0xfe004000-0xfe007fff 64bit pref]
  442. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.336831] pci 0000:00:05.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  443. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.340902] pci 0000:00:05.0: BAR 0 [io 0xc080-0xc0bf]
  444. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.342676] pci 0000:00:05.0: BAR 1 [mem 0xfebd3000-0xfebd3fff]
  445. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.343718] pci 0000:00:05.0: BAR 4 [mem 0xfe008000-0xfe00bfff 64bit pref]
  446. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.348531] pci 0000:00:06.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  447. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.351651] pci 0000:00:06.0: BAR 0 [io 0xc160-0xc17f]
  448. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.352651] pci 0000:00:06.0: BAR 1 [mem 0xfebd4000-0xfebd4fff]
  449. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.353726] pci 0000:00:06.0: BAR 4 [mem 0xfe00c000-0xfe00ffff 64bit pref]
  450. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.357425] pci 0000:00:07.0: [1af4:1009] type 00 class 0x000200 conventional PCI endpoint
  451. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.360655] pci 0000:00:07.0: BAR 0 [io 0xc180-0xc19f]
  452. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.362653] pci 0000:00:07.0: BAR 1 [mem 0xfebd5000-0xfebd5fff]
  453. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.363744] pci 0000:00:07.0: BAR 4 [mem 0xfe010000-0xfe013fff 64bit pref]
  454. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.369190] pci 0000:00:08.0: [1af4:1001] type 00 class 0x010000 conventional PCI endpoint
  455. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.372654] pci 0000:00:08.0: BAR 0 [io 0xc000-0xc07f]
  456. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.373653] pci 0000:00:08.0: BAR 1 [mem 0xfebd6000-0xfebd6fff]
  457. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.374713] pci 0000:00:08.0: BAR 4 [mem 0xfe014000-0xfe017fff 64bit pref]
  458. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.379433] pci 0000:00:09.0: [1af4:1000] type 00 class 0x020000 conventional PCI endpoint
  459. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.382662] pci 0000:00:09.0: BAR 0 [io 0xc1a0-0xc1bf]
  460. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.385277] pci 0000:00:09.0: BAR 1 [mem 0xfebd7000-0xfebd7fff]
  461. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.387160] pci 0000:00:09.0: BAR 4 [mem 0xfe018000-0xfe01bfff 64bit pref]
  462. 26.12 s [vm-test-run-nixos-test-read-proxy] server # [ 1.388651] pci 0000:00:09.0: ROM [mem 0xfeb80000-0xfebbffff pref]
  463. 26.13 s [vm-test-run-nixos-test-read-proxy] server # [ 1.393923] pci 0000:00:0a.0: [1af4:1052] type 00 class 0x090000 conventional PCI endpoint
  464. 26.13 s [vm-test-run-nixos-test-read-proxy] server # [ 1.397670] pci 0000:00:0a.0: BAR 1 [mem 0xfebd8000-0xfebd8fff]
  465. 26.13 s [vm-test-run-nixos-test-read-proxy] server # [ 1.398711] pci 0000:00:0a.0: BAR 4 [mem 0xfe01c000-0xfe01ffff 64bit pref]
  466. 26.14 s [vm-test-run-nixos-test-read-proxy] server # [ 1.402512] pci 0000:00:0b.0: [1af4:1003] type 00 class 0x078000 conventional PCI endpoint
  467. 26.15 s [vm-test-run-nixos-test-read-proxy] server # [ 1.405668] pci 0000:00:0b.0: BAR 0 [io 0xc0c0-0xc0ff]
  468. 26.15 s [vm-test-run-nixos-test-read-proxy] server # [ 1.406651] pci 0000:00:0b.0: BAR 1 [mem 0xfebd9000-0xfebd9fff]
  469. 26.15 s [vm-test-run-nixos-test-read-proxy] server # [ 1.407714] pci 0000:00:0b.0: BAR 4 [mem 0xfe020000-0xfe023fff 64bit pref]
  470. 26.16 s [vm-test-run-nixos-test-read-proxy] server # [ 1.412419] pci 0000:00:0c.0: [1af4:1005] type 00 class 0x00ff00 conventional PCI endpoint
  471. 26.16 s [vm-test-run-nixos-test-read-proxy] server # [ 1.415663] pci 0000:00:0c.0: BAR 0 [io 0xc1c0-0xc1df]
  472. 26.17 s [vm-test-run-nixos-test-read-proxy] server # [ 1.416651] pci 0000:00:0c.0: BAR 1 [mem 0xfebda000-0xfebdafff]
  473. 26.17 s [vm-test-run-nixos-test-read-proxy] server # [ 1.417713] pci 0000:00:0c.0: BAR 4 [mem 0xfe024000-0xfe027fff 64bit pref]
  474. 26.19 s [vm-test-run-nixos-test-read-proxy] server # [ 1.433228] ACPI: PCI: Interrupt link LNKA configured for IRQ 10
  475. 26.19 s [vm-test-run-nixos-test-read-proxy] server # [ 1.434890] ACPI: PCI: Interrupt link LNKB configured for IRQ 10
  476. 26.19 s [vm-test-run-nixos-test-read-proxy] server # [ 1.436833] ACPI: PCI: Interrupt link LNKC configured for IRQ 11
  477. 26.20 s [vm-test-run-nixos-test-read-proxy] server # [ 1.438854] ACPI: PCI: Interrupt link LNKD configured for IRQ 11
  478. 26.20 s [vm-test-run-nixos-test-read-proxy] server # [ 1.440744] ACPI: PCI: Interrupt link LNKS configured for IRQ 9
  479. 26.21 s [vm-test-run-nixos-test-read-proxy] server # [ 1.449693] iommu: Default domain type: Translated
  480. 26.21 s [vm-test-run-nixos-test-read-proxy] server # [ 1.450662] iommu: DMA domain TLB invalidation policy: lazy mode
  481. 26.22 s [vm-test-run-nixos-test-read-proxy] server # [ 1.454196] ACPI: bus type USB registered
  482. 26.22 s [vm-test-run-nixos-test-read-proxy] server # [ 1.456026] usbcore: registered new interface driver usbfs
  483. 26.22 s [vm-test-run-nixos-test-read-proxy] server # [ 1.457778] usbcore: registered new interface driver hub
  484. 26.23 s [vm-test-run-nixos-test-read-proxy] server # [ 1.458640] usbcore: registered new device driver usb
  485. 26.23 s [vm-test-run-nixos-test-read-proxy] server # [ 1.465449] NetLabel: Initializing
  486. 26.24 s [vm-test-run-nixos-test-read-proxy] server # [ 1.466628] NetLabel: domain hash size = 128
  487. 26.24 s [vm-test-run-nixos-test-read-proxy] server # [ 1.467628] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO
  488. 26.24 s [vm-test-run-nixos-test-read-proxy] server # [ 1.468869] NetLabel: unlabeled traffic allowed by default
  489. 26.24 s [vm-test-run-nixos-test-read-proxy] server # [ 1.470693] PCI: Using ACPI for IRQ routing
  490. 26.25 s [vm-test-run-nixos-test-read-proxy] server # [ 1.473802] pci 0000:00:02.0: vgaarb: setting as boot VGA device
  491. 26.25 s [vm-test-run-nixos-test-read-proxy] server # [ 1.474619] pci 0000:00:02.0: vgaarb: bridge control possible
  492. 26.26 s [vm-test-run-nixos-test-read-proxy] server # [ 1.474619] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
  493. 26.26 s [vm-test-run-nixos-test-read-proxy] server # [ 1.474630] vgaarb: loaded
  494. 26.26 s [vm-test-run-nixos-test-read-proxy] server # [ 1.477486] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
  495. 26.26 s [vm-test-run-nixos-test-read-proxy] server # [ 1.478629] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
  496. 26.27 s [vm-test-run-nixos-test-read-proxy] server # [ 1.484120] clocksource: Switched to clocksource kvm-clock
  497. 26.29 s [vm-test-run-nixos-test-read-proxy] server # [ 1.501890] VFS: Disk quotas dquot_6.6.0
  498. 26.29 s [vm-test-run-nixos-test-read-proxy] server # [ 1.506004] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
  499. 26.30 s [vm-test-run-nixos-test-read-proxy] server # [ 1.511120] pnp: PnP ACPI init
  500. 26.30 s [vm-test-run-nixos-test-read-proxy] server # [ 1.515030] pnp: PnP ACPI: found 6 devices
  501. 26.32 s [vm-test-run-nixos-test-read-proxy] server # [ 1.531246] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
  502. 26.32 s [vm-test-run-nixos-test-read-proxy] server # [ 1.535378] clocksource: Switched to clocksource acpi_pm
  503. 26.33 s [vm-test-run-nixos-test-read-proxy] server # [ 1.538667] NET: Registered PF_INET protocol family
  504. 26.33 s [vm-test-run-nixos-test-read-proxy] server # [ 1.543071] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
  505. 26.43 s [vm-test-run-nixos-test-read-proxy] server # [ 1.640050] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 8192 bytes, linear)
  506. 26.44 s [vm-test-run-nixos-test-read-proxy] server # [ 1.645177] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
  507. 26.44 s [vm-test-run-nixos-test-read-proxy] server # [ 1.650275] TCP established hash table entries: 8192 (order: 4, 65536 bytes, linear)
  508. 26.44 s [vm-test-run-nixos-test-read-proxy] server # [ 1.654322] TCP bind hash table entries: 8192 (order: 6, 262144 bytes, linear)
  509. 26.45 s [vm-test-run-nixos-test-read-proxy] server # [ 1.658552] TCP: Hash tables configured (established 8192 bind 8192)
  510. 26.45 s [vm-test-run-nixos-test-read-proxy] server # [ 1.662591] MPTCP token hash table entries: 1024 (order: 3, 24576 bytes, linear)
  511. 26.46 s [vm-test-run-nixos-test-read-proxy] server # [ 1.666796] UDP hash table entries: 512 (order: 3, 32768 bytes, linear)
  512. 26.46 s [vm-test-run-nixos-test-read-proxy] server # [ 1.670559] UDP-Lite hash table entries: 512 (order: 3, 32768 bytes, linear)
  513. 26.46 s [vm-test-run-nixos-test-read-proxy] server # [ 1.674974] NET: Registered PF_UNIX/PF_LOCAL protocol family
  514. 26.47 s [vm-test-run-nixos-test-read-proxy] server # [ 1.678547] NET: Registered PF_XDP protocol family
  515. 26.47 s [vm-test-run-nixos-test-read-proxy] server # [ 1.681553] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]
  516. 26.47 s [vm-test-run-nixos-test-read-proxy] server # [ 1.685211] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]
  517. 26.48 s [vm-test-run-nixos-test-read-proxy] server # [ 1.688351] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
  518. 26.48 s [vm-test-run-nixos-test-read-proxy] server # [ 1.691765] pci_bus 0000:00: resource 7 [mem 0x40000000-0xfebfffff window]
  519. 26.48 s [vm-test-run-nixos-test-read-proxy] server # [ 1.695231] pci_bus 0000:00: resource 8 [mem 0x100000000-0x17fffffff window]
  520. 26.49 s [vm-test-run-nixos-test-read-proxy] server # [ 1.699045] pci 0000:00:01.0: PIIX3: Enabling Passive Release
  521. 26.49 s [vm-test-run-nixos-test-read-proxy] server # [ 1.702231] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
  522. 26.50 s [vm-test-run-nixos-test-read-proxy] server # [ 1.709230] ACPI: \_SB_.LNKD: Enabled at IRQ 11
  523. 26.50 s [vm-test-run-nixos-test-read-proxy] server # [ 1.713821] PCI: CLS 0 bytes, default 64
  524. 26.51 s [vm-test-run-nixos-test-read-proxy] server # [ 1.717264] Trying to unpack rootfs image as initramfs...
  525. 26.52 s [vm-test-run-nixos-test-read-proxy] server # [ 1.727067] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x31024cfe468, max_idle_ns: 440795307017 ns
  526. 26.56 s [vm-test-run-nixos-test-read-proxy] server # [ 1.772899] Initialise system trusted keyrings
  527. 26.57 s [vm-test-run-nixos-test-read-proxy] server # [ 1.780586] workingset: timestamp_bits=40 max_order=18 bucket_order=0
  528. 26.60 s [vm-test-run-nixos-test-read-proxy] server # [ 1.810867] Key type asymmetric registered
  529. 26.60 s [vm-test-run-nixos-test-read-proxy] server # [ 1.815589] Asymmetric key parser 'x509' registered
  530. 26.61 s [vm-test-run-nixos-test-read-proxy] server # [ 1.823648] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 248)
  531. 26.62 s [vm-test-run-nixos-test-read-proxy] server # [ 1.832723] io scheduler mq-deadline registered
  532. 26.63 s [vm-test-run-nixos-test-read-proxy] server # [ 1.838549] io scheduler kyber registered
  533. 26.64 s [vm-test-run-nixos-test-read-proxy] server # [ 1.850360] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
  534. 26.65 s [vm-test-run-nixos-test-read-proxy] server # [ 1.858814] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
  535. 26.66 s [vm-test-run-nixos-test-read-proxy] server # [ 1.873130] Linux agpgart interface v0.103
  536. 26.67 s [vm-test-run-nixos-test-read-proxy] server # [ 1.878732] ACPI: bus type drm_connector registered
  537. 26.68 s [vm-test-run-nixos-test-read-proxy] server # [ 1.888156] usbcore: registered new interface driver usbserial_generic
  538. 26.68 s [vm-test-run-nixos-test-read-proxy] server # [ 1.894627] usbserial: USB Serial support registered for generic
  539. 26.69 s [vm-test-run-nixos-test-read-proxy] server # [ 1.902545] amd_pstate: the _CPC object is not present in SBIOS or ACPI disabled
  540. 26.70 s [vm-test-run-nixos-test-read-proxy] server # [ 1.911918] drop_monitor: Initializing network drop monitor service
  541. 26.71 s [vm-test-run-nixos-test-read-proxy] server # [ 1.919109] NET: Registered PF_INET6 protocol family
  542. 26.72 s [vm-test-run-nixos-test-read-proxy] server # [ 1.932272] Segment Routing with IPv6
  543. 26.72 s [vm-test-run-nixos-test-read-proxy] server # [ 1.936585] In-situ OAM (IOAM) with IPv6
  544. 26.73 s [vm-test-run-nixos-test-read-proxy] server # [ 1.942697] IPI shorthand broadcast: enabled
  545. 26.75 s [vm-test-run-nixos-test-read-proxy] server # [ 1.963925] registered taskstats version 1
  546. 26.76 s [vm-test-run-nixos-test-read-proxy] server # [ 1.969341] Loading compiled-in X.509 certificates
  547. 26.81 s [vm-test-run-nixos-test-read-proxy] server # [ 2.021620] Demotion targets for Node 0: null
  548. 26.82 s [vm-test-run-nixos-test-read-proxy] server # [ 2.027962] Key type .fscrypt registered
  549. 26.82 s [vm-test-run-nixos-test-read-proxy] server # [ 2.034590] Key type fscrypt-provisioning registered
  550. 26.83 s [vm-test-run-nixos-test-read-proxy] server # [ 2.039553] ima: No TPM chip found, activating TPM-bypass!
  551. 26.83 s [vm-test-run-nixos-test-read-proxy] server # [ 2.042231] ima: Allocated hash algorithm: sha1
  552. 26.84 s [vm-test-run-nixos-test-read-proxy] server # [ 2.049871] ima: No architecture policies found
  553. 26.84 s [vm-test-run-nixos-test-read-proxy] server # [ 2.056181] PM: Magic number: 2:314:475
  554. 26.85 s [vm-test-run-nixos-test-read-proxy] server # [ 2.063116] RAS: Correctable Errors collector initialized.
  555. 26.87 s [vm-test-run-nixos-test-read-proxy] server # [ 2.079006] Unstable clock detected, switching default tracing clock to "global"
  556. 26.87 s [vm-test-run-nixos-test-read-proxy] server # [ 2.079006] If you want to keep using the local clock, then add:
  557. 26.87 s [vm-test-run-nixos-test-read-proxy] server # [ 2.079006] "trace_clock=local"
  558. 26.87 s [vm-test-run-nixos-test-read-proxy] server # [ 2.079006] on the kernel command line
  559. 26.89 s [vm-test-run-nixos-test-read-proxy] server # [ 2.103667] clk: Disabling unused clocks
  560. 26.89 s [vm-test-run-nixos-test-read-proxy] server # [ 2.105785] PM: genpd: Disabling unused power domains
  561. 28.16 s [vm-test-run-nixos-test-read-proxy] server # [ 3.371106] Freeing initrd memory: 29496K
  562. 28.18 s [vm-test-run-nixos-test-read-proxy] server # [ 3.394141] Freeing unused decrypted memory: 2028K
  563. 28.22 s [vm-test-run-nixos-test-read-proxy] server # [ 3.430124] Freeing unused kernel image (initmem) memory: 3636K
  564. 28.22 s [vm-test-run-nixos-test-read-proxy] server # [ 3.435609] Write protecting the kernel read-only data: 32768k
  565. 28.24 s [vm-test-run-nixos-test-read-proxy] server # [ 3.451022] Freeing unused kernel image (text/rodata gap) memory: 1272K
  566. 28.25 s [vm-test-run-nixos-test-read-proxy] server # [ 3.465882] Freeing unused kernel image (rodata/data gap) memory: 796K
  567. 28.31 s [vm-test-run-nixos-test-read-proxy] server # [ 3.518883] x86/mm: Checked W+X mappings: passed, no W+X pages found.
  568. 28.31 s [vm-test-run-nixos-test-read-proxy] server # [ 3.522911] Run /init as init process
  569. 28.36 s [vm-test-run-nixos-test-read-proxy] server # [ 3.567124] systemd[1]: Inserted module 'autofs4'
  570. 28.38 s [vm-test-run-nixos-test-read-proxy] server # [ 3.592894] fuse: init (API version 7.45)
  571. 28.39 s [vm-test-run-nixos-test-read-proxy] server # [ 3.602219] ACPI: \_SB_.LNKC: Enabled at IRQ 10
  572. 28.40 s [vm-test-run-nixos-test-read-proxy] server # [ 3.616014] ACPI: \_SB_.LNKA: Enabled at IRQ 10
  573. 28.41 s [vm-test-run-nixos-test-read-proxy] server # [ 3.622265] ACPI: \_SB_.LNKB: Enabled at IRQ 11
  574. 28.48 s [vm-test-run-nixos-test-read-proxy] server # [ 3.692657] systemd[1]: Successfully made /usr/ read-only.
  575. 28.83 s [vm-test-run-nixos-test-read-proxy] server # [ 4.032988] 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)
  576. 28.84 s [vm-test-run-nixos-test-read-proxy] server # [ 4.049907] systemd[1]: Detected virtualization kvm.
  577. 28.84 s [vm-test-run-nixos-test-read-proxy] server # [ 4.052999] systemd[1]: Detected architecture x86-64.
  578. 28.84 s [vm-test-run-nixos-test-read-proxy] server # [ 4.056150] systemd[1]: Running in initrd.
  579. 28.85 s [vm-test-run-nixos-test-read-proxy] server # [ 4.058901] systemd[1]: Initializing machine ID from random generator.
  580. 28.85 s [vm-test-run-nixos-test-read-proxy] server # [ 4.062444] systemd[1]: Hostname set to <server>.
  581. 29.12 s [vm-test-run-nixos-test-read-proxy] server # [ 4.331809] systemd[1]: bpf-restrict-fs: LSM BPF program attached
  582. 29.17 s [vm-test-run-nixos-test-read-proxy] server # [ 4.379591] systemd[1]: Queued start job for default target Initrd Default Target.
  583. 29.18 s [vm-test-run-nixos-test-read-proxy] server # [ 4.391096] systemd[1]: Created slice Slice /system/modprobe.
  584. 29.18 s [vm-test-run-nixos-test-read-proxy] server # [ 4.394855] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
  585. 29.19 s [vm-test-run-nixos-test-read-proxy] server # [ 4.399710] systemd[1]: Expecting device /dev/disk/by-label/nixos...
  586. 29.19 s [vm-test-run-nixos-test-read-proxy] server # [ 4.403307] systemd[1]: Reached target Path Units.
  587. 29.19 s [vm-test-run-nixos-test-read-proxy] server # [ 4.406213] systemd[1]: Reached target Slice Units.
  588. 29.20 s [vm-test-run-nixos-test-read-proxy] server # [ 4.408946] systemd[1]: Reached target Swaps.
  589. 29.20 s [vm-test-run-nixos-test-read-proxy] server # [ 4.411577] systemd[1]: Reached target Timer Units.
  590. 29.20 s [vm-test-run-nixos-test-read-proxy] server # [ 4.414662] systemd[1]: Listening on D-Bus System Message Bus Socket.
  591. 29.21 s [vm-test-run-nixos-test-read-proxy] server # [ 4.418117] systemd[1]: Listening on Journal Socket (/dev/log).
  592. 29.21 s [vm-test-run-nixos-test-read-proxy] server # [ 4.421945] systemd[1]: Listening on Journal Sockets.
  593. 29.21 s [vm-test-run-nixos-test-read-proxy] server # [ 4.425099] systemd[1]: Listening on udev Control Socket.
  594. 29.22 s [vm-test-run-nixos-test-read-proxy] server # [ 4.428008] systemd[1]: Listening on udev Kernel Socket.
  595. 29.22 s [vm-test-run-nixos-test-read-proxy] server # [ 4.430856] systemd[1]: Reached target Socket Units.
  596. 29.22 s [vm-test-run-nixos-test-read-proxy] server # [ 4.435161] systemd[1]: Starting Create List of Static Device Nodes...
  597. 29.23 s [vm-test-run-nixos-test-read-proxy] server # [ 4.445954] systemd[1]: Starting Load Kernel Module 9pnet_virtio...
  598. 29.25 s [vm-test-run-nixos-test-read-proxy] server # [ 4.461582] systemd[1]: Starting Load Kernel Module configfs...
  599. 29.28 s [vm-test-run-nixos-test-read-proxy] server # [ 4.488627] systemd[1]: Starting Journal Service...
  600. 29.28 s [vm-test-run-nixos-test-read-proxy] server # [ 4.495745] netfs: FS-Cache loaded
  601. 29.30 s [vm-test-run-nixos-test-read-proxy] server # [ 4.508159] systemd[1]: Starting Load Kernel Modules...
  602. 29.30 s [vm-test-run-nixos-test-read-proxy] server # [ 4.514174] 9pnet: Installing 9P2000 support
  603. 29.31 s [vm-test-run-nixos-test-read-proxy] server # [ 4.521268] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os
  604. 29.32 s [vm-test-run-nixos-test-read-proxy] server # [ 4.532827] systemd-journald[68]: Collecting audit messages is disabled.
  605. 29.33 s [vm-test-run-nixos-test-read-proxy] server # [ 4.546108] systemd[1]: Starting Coldplug All udev Devices...
  606. 29.36 s [vm-test-run-nixos-test-read-proxy] server # [ 4.572670] systemd[1]: Finished Create List of Static Device Nodes.
  607. 29.37 s [vm-test-run-nixos-test-read-proxy] server # [ 4.576712] device-mapper: core: CONFIG_IMA_DISABLE_HTABLE is disabled. Duplicate IMA measurements will not be recorded in the IMA log.
  608. 29.39 s [vm-test-run-nixos-test-read-proxy] server # [ 4.589887] systemd[1]: modprobe@9pnet_virtio.service: Deactivated successfully.
  609. 29.41 s [vm-test-run-nixos-test-read-proxy] server # [ 4.617560] device-mapper: ioctl: 4.50.0-ioctl (2025-04-28) initialised: dm-devel@lists.linux.dev
  610. 29.44 s [vm-test-run-nixos-test-read-proxy] server # [ 4.651650] systemd[1]: Finished Load Kernel Module 9pnet_virtio.
  611. 29.45 s [vm-test-run-nixos-test-read-proxy] server # [ 4.662244] systemd[1]: modprobe@configfs.service: Deactivated successfully.
  612. 29.46 s [vm-test-run-nixos-test-read-proxy] server # [ 4.675627] systemd[1]: Finished Load Kernel Module configfs.
  613. 29.48 s [vm-test-run-nixos-test-read-proxy] server # [ 4.689744] systemd[1]: Finished Load Kernel Modules.
  614. 29.49 s [vm-test-run-nixos-test-read-proxy] server # [ 4.701653] systemd[1]: Kernel Configuration File System skipped, unmet condition check ConditionPathExists=/sys/kernel/config
  615. 29.51 s [vm-test-run-nixos-test-read-proxy] server # [ 4.722869] systemd[1]: Starting Apply Kernel Variables...
  616. 29.53 s [vm-test-run-nixos-test-read-proxy] server # [ 4.038474] systemd-modules-load[69]: Inserted module 'dm_mod'
  617. 29.54 s [vm-test-run-nixos-test-read-proxy] server # [ 4.046728] systemd-modules-load[69]: Inserted module 'virtio_balloon'
  618. 29.54 s [vm-test-run-nixos-test-read-proxy] server # [ 4.751135] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...
  619. 29.55 s [vm-test-run-nixos-test-read-proxy] server # [ 4.057821] systemd-modules-load[69]: Inserted module 'virtio_gpu'
  620. 29.55 s [vm-test-run-nixos-test-read-proxy] server # [ 4.765145] systemd[1]: Started Journal Service.
  621. 29.57 s [vm-test-run-nixos-test-read-proxy] server # [ 4.079217] systemd[1]: Finished Apply Kernel Variables.
  622. 29.59 s [vm-test-run-nixos-test-read-proxy] server # [ 4.097514] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
  623. 29.60 s [vm-test-run-nixos-test-read-proxy] server # [ 4.105721] systemd[1]: Starting Create Static Device Nodes in /dev...
  624. 29.62 s [vm-test-run-nixos-test-read-proxy] server # [ 4.127174] systemd[1]: Finished Create Static Device Nodes in /dev.
  625. 29.62 s [vm-test-run-nixos-test-read-proxy] server # [ 4.130369] systemd[1]: Reached target Preparation for Local File Systems.
  626. 29.63 s [vm-test-run-nixos-test-read-proxy] server # [ 4.137362] systemd[1]: Reached target Local File Systems.
  627. 29.63 s [vm-test-run-nixos-test-read-proxy] server # [ 4.142450] systemd[1]: Starting Create System Files and Directories...
  628. 29.64 s [vm-test-run-nixos-test-read-proxy] server # [ 4.148369] systemd[1]: Starting Rule-based Manager for Device Events and Files...
  629. 29.67 s [vm-test-run-nixos-test-read-proxy] server # [ 4.180973] systemd[1]: Finished Create System Files and Directories.
  630. 29.69 s [vm-test-run-nixos-test-read-proxy] server # [ 4.203607] systemd-udevd[83]: Using default interface naming scheme 'v261'.
  631. 29.73 s [vm-test-run-nixos-test-read-proxy] server # [ 4.243724] systemd[1]: Started Rule-based Manager for Device Events and Files.
  632. 29.74 s [vm-test-run-nixos-test-read-proxy] server # [ 4.249490] systemd[1]: Finished Coldplug All udev Devices.
  633. 29.74 s [vm-test-run-nixos-test-read-proxy] server # [ 4.254344] systemd[1]: Reached target System Initialization.
  634. 29.75 s [vm-test-run-nixos-test-read-proxy] server # [ 4.257322] systemd[1]: Reached target Basic System.
  635. 30.06 s [vm-test-run-nixos-test-read-proxy] server # [ 5.275658] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
  636. 30.10 s [vm-test-run-nixos-test-read-proxy] server # [ 5.314007] serio: i8042 KBD port at 0x60,0x64 irq 1
  637. 30.11 s [vm-test-run-nixos-test-read-proxy] server # [ 5.323174] virtio_blk virtio5: 1/0/0 default/read/poll queues
  638. 30.13 s [vm-test-run-nixos-test-read-proxy] server # [ 5.339660] serio: i8042 AUX port at 0x60,0x64 irq 12
  639. 30.15 s [vm-test-run-nixos-test-read-proxy] server # [ 5.365106] virtio_blk virtio5: [vda] 2097152 512-byte logical blocks (1.07 GB/1.00 GiB)
  640. 30.16 s [vm-test-run-nixos-test-read-proxy] server # [ 5.372533] uhci_hcd 0000:00:01.2: UHCI Host Controller
  641. 30.18 s [vm-test-run-nixos-test-read-proxy] server # [ 5.390609] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
  642. 30.19 s [vm-test-run-nixos-test-read-proxy] server # [ 5.406136] SCSI subsystem initialized
  643. 30.20 s [vm-test-run-nixos-test-read-proxy] server # [ 5.409663] uhci_hcd 0000:00:01.2: detected 2 ports
  644. 30.21 s [vm-test-run-nixos-test-read-proxy] server # [ 5.423793] uhci_hcd 0000:00:01.2: irq 11, io port 0x0000c100
  645. 30.24 s [vm-test-run-nixos-test-read-proxy] server # [ 4.747890] systemd[1]: Starting Virtual Console Setup...
  646. 30.25 s [vm-test-run-nixos-test-read-proxy] server # [ 5.458696] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
  647. 30.25 s [vm-test-run-nixos-test-read-proxy] server # [ 4.761194] (udev-worker)[88]: [0;1;38:5:185meth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.
  648. 30.26 s [vm-test-run-nixos-test-read-proxy] server # [ 5.468710] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 6.18
  649. 30.26 s [vm-test-run-nixos-test-read-proxy] server # [ 5.471650] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
  650. 30.27 s [vm-test-run-nixos-test-read-proxy] server # [ 4.780459] (udev-worker)[90]: Network interface NamePolicy= disabled on kernel command line.
  651. 30.28 s [vm-test-run-nixos-test-read-proxy] server # [ 4.790649] (udev-worker)[88]: Network interface NamePolicy= disabled on kernel command line.
  652. 30.31 s [vm-test-run-nixos-test-read-proxy] server # [ 4.811116] systemd-vconsole-setup[99]: Configuration of first virtual console was skipped, ignoring remaining ones.
  653. 30.31 s [vm-test-run-nixos-test-read-proxy] server # [ 4.821481] systemd[1]: Finished Virtual Console Setup.
  654. 30.32 s [vm-test-run-nixos-test-read-proxy] server # [ 5.528991] usb usb1: Product: UHCI Host Controller
  655. 30.33 s [vm-test-run-nixos-test-read-proxy] server # [ 5.543044] usb usb1: Manufacturer: Linux 6.18.38 uhci_hcd
  656. 30.34 s [vm-test-run-nixos-test-read-proxy] server # [ 5.549217] usb usb1: SerialNumber: 0000:00:01.2
  657. 30.35 s [vm-test-run-nixos-test-read-proxy] server # [ 5.558696] hub 1-0:1.0: USB hub found
  658. 30.35 s [vm-test-run-nixos-test-read-proxy] server # [ 5.568053] hub 1-0:1.0: 2 ports detected
  659. 30.40 s [vm-test-run-nixos-test-read-proxy] server # [ 5.614630] scsi host0: ata_piix
  660. 30.41 s [vm-test-run-nixos-test-read-proxy] server # [ 4.914337] systemd[1]: Found device /dev/disk/by-label/nixos.
  661. 30.41 s [vm-test-run-nixos-test-read-proxy] server # [ 4.917337] systemd[1]: Reached target Initrd Root Device.
  662. 30.42 s [vm-test-run-nixos-test-read-proxy] server # [ 4.920241] systemd[1]: Starting File System Check on /dev/disk/by-label/nixos...
  663. 30.42 s [vm-test-run-nixos-test-read-proxy] server # [ 5.629682] scsi host1: ata_piix
  664. 30.42 s [vm-test-run-nixos-test-read-proxy] server # [ 5.635817] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc1e0 irq 14 lpm-pol 0
  665. 30.43 s [vm-test-run-nixos-test-read-proxy] server # [ 5.642661] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc1e8 irq 15 lpm-pol 0
  666. 30.44 s [vm-test-run-nixos-test-read-proxy] server # [ 4.954888] systemd-fsck[111]: nixos: clean, 12/65536 files, 13019/262144 blocks
  667. 30.47 s [vm-test-run-nixos-test-read-proxy] server # [ 4.976387] systemd[1]: Finished File System Check on /dev/disk/by-label/nixos.
  668. 30.47 s [vm-test-run-nixos-test-read-proxy] server # [ 4.983819] systemd[1]: Mounting /sysroot...
  669. 30.58 s [vm-test-run-nixos-test-read-proxy] server # [ 5.794672] usb 1-1: new full-speed USB device number 2 using uhci_hcd
  670. 30.59 s [vm-test-run-nixos-test-read-proxy] server # [ 5.802243] ata2: found unknown device (class 0)
  671. 30.59 s [vm-test-run-nixos-test-read-proxy] server # [ 5.805552] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100
  672. 30.60 s [vm-test-run-nixos-test-read-proxy] server # [ 5.811032] scsi 1:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5
  673. 30.65 s [vm-test-run-nixos-test-read-proxy] server # [ 5.862614] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray
  674. 30.68 s [vm-test-run-nixos-test-read-proxy] server # [ 5.890152] cdrom: Uniform CD-ROM driver Revision: 3.20
  675. 30.73 s [vm-test-run-nixos-test-read-proxy] server # [ 5.939708] EXT4-fs (vda): mounted filesystem 3b7a8533-f130-4ace-9f7b-f504742e46c2 r/w with ordered data mode. Quota mode: none.
  676. 30.74 s [vm-test-run-nixos-test-read-proxy] server # [ 5.245865] systemd[1]: Mounted /sysroot.
  677. 30.74 s [vm-test-run-nixos-test-read-proxy] server # [ 5.250902] systemd[1]: Reached target Initrd Root File System.
  678. 30.75 s [vm-test-run-nixos-test-read-proxy] server # [ 5.255871] systemd[1]: Starting Mountpoints Configured in the Real Root...
  679. 30.76 s [vm-test-run-nixos-test-read-proxy] server # [ 5.970364] usb 1-1: New USB device found, idVendor=0627, idProduct=0001, bcdDevice= 0.00
  680. 30.76 s [vm-test-run-nixos-test-read-proxy] server # [ 5.975766] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=10
  681. 30.77 s [vm-test-run-nixos-test-read-proxy] server # [ 5.278580] systemd-sysroot-fstab-check[124]: /sysroot should be mounted in the initrd, will request daemon-reload.
  682. 30.78 s [vm-test-run-nixos-test-read-proxy] server # [ 5.988538] usb 1-1: Product: QEMU USB Tablet
  683. 30.78 s [vm-test-run-nixos-test-read-proxy] server # [ 5.990398] usb 1-1: Manufacturer: QEMU
  684. 30.78 s [vm-test-run-nixos-test-read-proxy] server # [ 5.290431] systemd[1]: Reload requested from client PID 124 ('systemd-sysroot') (unit initrd-parse-etc.service)...
  685. 30.80 s [vm-test-run-nixos-test-read-proxy] server # [ 6.000695] usb 1-1: SerialNumber: 28754-0000:00:01.2-1
  686. 30.80 s [vm-test-run-nixos-test-read-proxy] server # [ 5.302851] systemd[1]: Reloading...
  687. 30.84 s [vm-test-run-nixos-test-read-proxy] server # [ 6.051139] hid: raw HID events driver (C) Jiri Kosina
  688. 30.86 s [vm-test-run-nixos-test-read-proxy] server # [ 6.076743] usbcore: registered new interface driver usbhid
  689. 30.96 s [vm-test-run-nixos-test-read-proxy] server # [ 6.084875] usbhid: USB HID core driver
  690. 30.96 s [vm-test-run-nixos-test-read-proxy] server # [ 6.107168] 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
  691. 30.96 s [vm-test-run-nixos-test-read-proxy] server # [ 6.118228] 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
  692. 30.96 s [vm-test-run-nixos-test-read-proxy] server # [ 5.455169] systemd[1]: Reloading finished in 169 ms.
  693. 30.96 s [vm-test-run-nixos-test-read-proxy] server # [ 5.467632] systemd-sysroot-fstab-check[124]: Requesting initrd-fs.target/start/replace...
  694. 30.99 s [vm-test-run-nixos-test-read-proxy] server # [ 5.473450] systemd-sysroot-fstab-check[124]: Requesting swap.target/start/replace...
  695. 30.99 s [vm-test-run-nixos-test-read-proxy] server # [ 5.480882] systemd[1]: Load Kernel Module 9pnet_virtio skipped, unmet condition check ConditionKernelModuleLoaded=!9pnet_virtio
  696. 30.99 s [vm-test-run-nixos-test-read-proxy] server # [ 5.486535] systemd[1]: initrd-parse-etc.service: Deactivated successfully.
  697. 30.99 s [vm-test-run-nixos-test-read-proxy] server # [ 5.489192] systemd[1]: Finished Mountpoints Configured in the Real Root.
  698. 30.99 s [vm-test-run-nixos-test-read-proxy] server # [ 5.491315] systemd[1]: initrd-parse-etc.service: Triggering OnSuccess= dependencies.
  699. 31.36 s [vm-test-run-nixos-test-read-proxy] server # [ 5.869242] systemd[1]: Mounting /sysroot/nix/.ro-store...
  700. 31.36 s [vm-test-run-nixos-test-read-proxy] server # [ 5.872413] systemd[1]: Mounting /sysroot/nix/.rw-store...
  701. 31.37 s [vm-test-run-nixos-test-read-proxy] server # [ 5.880274] systemd[1]: Mounting /sysroot/run...
  702. 31.37 s [vm-test-run-nixos-test-read-proxy] server # [ 5.883489] systemd[1]: Mounting /sysroot/tmp/shared...
  703. 31.38 s [vm-test-run-nixos-test-read-proxy] server # [ 5.895249] systemd[1]: Mounting /sysroot/tmp/xchg...
  704. 31.41 s [vm-test-run-nixos-test-read-proxy] server # [ 6.618143] 9p: Installing v9fs 9p2000 file system support
  705. 31.41 s [vm-test-run-nixos-test-read-proxy] server # [ 5.922449] systemd[1]: Mounted /sysroot/nix/.rw-store.
  706. 31.42 s [vm-test-run-nixos-test-read-proxy] server # [ 5.927648] systemd[1]: Mounted /sysroot/run.
  707. 31.42 s [vm-test-run-nixos-test-read-proxy] server # [ 5.934959] systemd[1]: Mounted /sysroot/nix/.ro-store.
  708. 31.43 s [vm-test-run-nixos-test-read-proxy] server # [ 5.942525] systemd[1]: Mounted /sysroot/tmp/shared.
  709. 31.44 s [vm-test-run-nixos-test-read-proxy] server # [ 5.946385] systemd[1]: Mounted /sysroot/tmp/xchg.
  710. 31.44 s [vm-test-run-nixos-test-read-proxy] server # [ 5.952740] systemd[1]: Starting rw-sysroot-nix-store.service...
  711. 31.46 s [vm-test-run-nixos-test-read-proxy] server # [ 5.967256] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.
  712. 31.46 s [vm-test-run-nixos-test-read-proxy] server # [ 5.970622] systemd[1]: Finished rw-sysroot-nix-store.service.
  713. 32.36 s [vm-test-run-nixos-test-read-proxy] server # [ 6.867945] systemd[1]: Mounting /sysroot/nix/store...
  714. 32.38 s [vm-test-run-nixos-test-read-proxy] server # [ 6.888772] systemd[1]: Mounted /sysroot/nix/store.
  715. 32.38 s [vm-test-run-nixos-test-read-proxy] server # [ 6.893317] systemd[1]: Reached target Initrd File Systems.
  716. 32.39 s [vm-test-run-nixos-test-read-proxy] server # [ 6.897361] systemd[1]: Starting Find NixOS closure...
  717. 32.39 s [vm-test-run-nixos-test-read-proxy] server # [ 6.901333] systemd[1]: Starting Create Volatile Files and Directories in the Real Root...
  718. 32.41 s [vm-test-run-nixos-test-read-proxy] server # [ 6.921572] systemd[1]: Finished Create Volatile Files and Directories in the Real Root.
  719. 32.42 s [vm-test-run-nixos-test-read-proxy] server # [ 6.927489] systemd[1]: sysroot-run-credentials-systemd\x2dtmpfiles\x2dsetup\x2dsysroot.service.mount: Deactivated successfully.
  720. 32.43 s [vm-test-run-nixos-test-read-proxy] server # [ 6.936476] systemd[1]: Finished Find NixOS closure.
  721. 32.43 s [vm-test-run-nixos-test-read-proxy] server # [ 6.939099] systemd[1]: Reached target Initrd Default Target.
  722. 32.43 s [vm-test-run-nixos-test-read-proxy] server # [ 6.942645] systemd[1]: Starting Cleaning Up and Shutting Down Daemons...
  723. 32.45 s [vm-test-run-nixos-test-read-proxy] server # [ 6.958442] systemd[1]: Stopped target Initrd Default Target.
  724. 32.45 s [vm-test-run-nixos-test-read-proxy] server # [ 6.962611] systemd[1]: Stopped target Basic System.
  725. 32.46 s [vm-test-run-nixos-test-read-proxy] server # [ 6.967140] systemd[1]: Stopped target Initrd Root Device.
  726. 32.46 s [vm-test-run-nixos-test-read-proxy] server # [ 6.968870] systemd[1]: Stopped target Path Units.
  727. 32.47 s [vm-test-run-nixos-test-read-proxy] server # [ 6.973310] systemd[1]: systemd-ask-password-console.path: Deactivated successfully.
  728. 32.47 s [vm-test-run-nixos-test-read-proxy] server # [ 6.978940] systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.
  729. 32.47 s [vm-test-run-nixos-test-read-proxy] server # [ 6.984326] systemd[1]: Stopped target Slice Units.
  730. 32.48 s [vm-test-run-nixos-test-read-proxy] server # [ 6.987329] systemd[1]: Stopped target Socket Units.
  731. 32.48 s [vm-test-run-nixos-test-read-proxy] server # [ 6.994481] systemd[1]: Stopped target System Initialization.
  732. 32.49 s [vm-test-run-nixos-test-read-proxy] server # [ 6.998578] systemd[1]: Stopped target Swaps.
  733. 32.49 s [vm-test-run-nixos-test-read-proxy] server # [ 7.002652] systemd[1]: Stopped target Timer Units.
  734. 32.50 s [vm-test-run-nixos-test-read-proxy] server # [ 7.006490] systemd[1]: dbus.socket: Deactivated successfully.
  735. 32.50 s [vm-test-run-nixos-test-read-proxy] server # [ 7.011587] systemd[1]: Closed D-Bus System Message Bus Socket.
  736. 32.51 s [vm-test-run-nixos-test-read-proxy] server # [ 7.015543] systemd[1]: initrd-find-nixos-closure.service: Deactivated successfully.
  737. 32.51 s [vm-test-run-nixos-test-read-proxy] server # [ 7.021344] systemd[1]: Stopped Find NixOS closure.
  738. 32.52 s [vm-test-run-nixos-test-read-proxy] server # [ 7.024307] systemd[1]: Load Kernel Module 9pnet_virtio skipped, unmet condition check ConditionKernelModuleLoaded=!9pnet_virtio
  739. 32.52 s [vm-test-run-nixos-test-read-proxy] server # [ 7.027991] systemd[1]: Starting rw-sysroot-nix-store.service...
  740. 32.52 s [vm-test-run-nixos-test-read-proxy] server # [ 7.032799] systemd[1]: systemd-sysctl.service: Deactivated successfully.
  741. 32.53 s [vm-test-run-nixos-test-read-proxy] server # [ 7.038437] systemd[1]: Stopped Apply Kernel Variables.
  742. 32.53 s [vm-test-run-nixos-test-read-proxy] server # [ 7.042175] systemd[1]: systemd-modules-load.service: Deactivated successfully.
  743. 32.54 s [vm-test-run-nixos-test-read-proxy] server # [ 7.048429] systemd[1]: Stopped Load Kernel Modules.
  744. 32.54 s [vm-test-run-nixos-test-read-proxy] server # [ 7.051639] systemd[1]: systemd-tmpfiles-setup-sysroot.service: Deactivated successfully.
  745. 32.55 s [vm-test-run-nixos-test-read-proxy] server # [ 7.057325] systemd[1]: Stopped Create Volatile Files and Directories in the Real Root.
  746. 32.55 s [vm-test-run-nixos-test-read-proxy] server # [ 7.059980] systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully.
  747. 32.56 s [vm-test-run-nixos-test-read-proxy] server # [ 7.064401] systemd[1]: Stopped Create System Files and Directories.
  748. 32.56 s [vm-test-run-nixos-test-read-proxy] server # [ 7.069669] systemd[1]: Stopped target Local File Systems.
  749. 32.57 s [vm-test-run-nixos-test-read-proxy] server # [ 7.074994] systemd[1]: Stopped target Preparation for Local File Systems.
  750. 32.57 s [vm-test-run-nixos-test-read-proxy] server # [ 7.077880] systemd[1]: systemd-udev-trigger.service: Deactivated successfully.
  751. 32.57 s [vm-test-run-nixos-test-read-proxy] server # [ 7.080775] systemd[1]: Stopped Coldplug All udev Devices.
  752. 32.57 s [vm-test-run-nixos-test-read-proxy] server # [ 7.083193] systemd[1]: Stopping Rule-based Manager for Device Events and Files...
  753. 32.58 s [vm-test-run-nixos-test-read-proxy] server # [ 7.085689] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
  754. 32.58 s [vm-test-run-nixos-test-read-proxy] server # [ 7.087935] systemd[1]: Stopped Virtual Console Setup.
  755. 32.58 s [vm-test-run-nixos-test-read-proxy] server # [ 7.090189] systemd[1]: initrd-cleanup.service: Deactivated successfully.
  756. 32.58 s [vm-test-run-nixos-test-read-proxy] server # [ 7.092823] systemd[1]: Finished Cleaning Up and Shutting Down Daemons.
  757. 32.58 s [vm-test-run-nixos-test-read-proxy] server # [ 7.095159] systemd[1]: systemd-udevd.service: Deactivated successfully.
  758. 32.59 s [vm-test-run-nixos-test-read-proxy] server # [ 7.097713] systemd[1]: Stopped Rule-based Manager for Device Events and Files.
  759. 32.59 s [vm-test-run-nixos-test-read-proxy] server # [ 7.100220] systemd[1]: rw-sysroot-nix-store.service: Deactivated successfully.
  760. 32.59 s [vm-test-run-nixos-test-read-proxy] server # [ 7.102653] systemd[1]: Finished rw-sysroot-nix-store.service.
  761. 32.59 s [vm-test-run-nixos-test-read-proxy] server # [ 7.104654] systemd[1]: systemd-udevd-control.socket: Deactivated successfully.
  762. 32.60 s [vm-test-run-nixos-test-read-proxy] server # [ 7.106994] systemd[1]: Closed udev Control Socket.
  763. 32.60 s [vm-test-run-nixos-test-read-proxy] server # [ 7.108987] systemd[1]: Starting Cleanup udev Database...
  764. 32.60 s [vm-test-run-nixos-test-read-proxy] server # [ 7.111227] systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully.
  765. 32.60 s [vm-test-run-nixos-test-read-proxy] server # [ 7.113663] systemd[1]: Stopped Create Static Device Nodes in /dev.
  766. 32.61 s [vm-test-run-nixos-test-read-proxy] server # [ 7.115870] systemd[1]: systemd-tmpfiles-setup-dev-early.service: Deactivated successfully.
  767. 32.61 s [vm-test-run-nixos-test-read-proxy] server # [ 7.118857] systemd[1]: Stopped Create Static Device Nodes in /dev gracefully.
  768. 32.61 s [vm-test-run-nixos-test-read-proxy] server # [ 7.121394] systemd[1]: kmod-static-nodes.service: Deactivated successfully.
  769. 32.61 s [vm-test-run-nixos-test-read-proxy] server # [ 7.124429] systemd[1]: Stopped Create List of Static Device Nodes.
  770. 32.62 s [vm-test-run-nixos-test-read-proxy] server # [ 7.126856] systemd[1]: initrd-udevadm-cleanup-db.service: Deactivated successfully.
  771. 32.62 s [vm-test-run-nixos-test-read-proxy] server # [ 7.129574] systemd[1]: Finished Cleanup udev Database.
  772. 32.62 s [vm-test-run-nixos-test-read-proxy] server # [ 7.131702] systemd[1]: Reached target Switch Root.
  773. 32.62 s [vm-test-run-nixos-test-read-proxy] server # [ 7.134437] systemd[1]: Starting NixOS Activation...
  774. 32.74 s [vm-test-run-nixos-test-read-proxy] server # [ 7.251352] initrd-nixos-activation-start[177]: booting system configuration /nix/store/n4h28d1k4sk3abz7hk7704rbifdvfpi4-nixos-system-server-test
  775. 32.80 s [vm-test-run-nixos-test-read-proxy] server # [ 7.306093] initrd-nixos-activation-start[177]: running activation script...
  776. 33.17 s [vm-test-run-nixos-test-read-proxy] server # [ 7.677348] initrd-nixos-activation-start[200]: setting up /etc...
  777. 33.40 s [vm-test-run-nixos-test-read-proxy] server # [ 7.908174] systemd[1]: initrd-nixos-activation.service: Deactivated successfully.
  778. 33.40 s [vm-test-run-nixos-test-read-proxy] server # [ 7.912638] systemd[1]: Finished NixOS Activation.
  779. 33.41 s [vm-test-run-nixos-test-read-proxy] server # [ 7.917326] systemd[1]: Starting Switch Root...
  780. 33.42 s [vm-test-run-nixos-test-read-proxy] server # [ 7.930229] systemd[1]: Switching root.
  781. 33.55 s [vm-test-run-nixos-test-read-proxy] server # [ 8.758750] systemd-journald[68]: Received SIGTERM from PID 1 (systemd).
  782. 33.68 s [vm-test-run-nixos-test-read-proxy] server # [ 8.896102] NET: Registered PF_VSOCK protocol family
  783. 34.07 s [vm-test-run-nixos-test-read-proxy] server # [ 9.274150] 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)
  784. 34.07 s [vm-test-run-nixos-test-read-proxy] server # [ 9.284534] systemd[1]: Detected virtualization kvm.
  785. 34.07 s [vm-test-run-nixos-test-read-proxy] server # [ 9.286561] systemd[1]: Detected architecture x86-64.
  786. 34.08 s [vm-test-run-nixos-test-read-proxy] server # [ 9.288563] systemd[1]: Detected first boot.
  787. 34.08 s [vm-test-run-nixos-test-read-proxy] server # [ 9.292848] systemd[1]: Initializing machine ID from random generator.
  788. 34.33 s [vm-test-run-nixos-test-read-proxy] server # [ 9.539385] systemd[1]: bpf-restrict-fs: LSM BPF program attached
  789. 34.45 s [vm-test-run-nixos-test-read-proxy] server # [ 9.665949] systemd[1]: Applying preset policy.
  790. 34.93 s [vm-test-run-nixos-test-read-proxy] server # [ 10.139574] systemd[1]: Populated /etc with preset unit settings.
  791. 35.41 s [vm-test-run-nixos-test-read-proxy] server # [ 10.620911] systemd[1]: initrd-switch-root.service: Deactivated successfully.
  792. 35.42 s [vm-test-run-nixos-test-read-proxy] server # [ 10.628419] systemd[1]: Stopped initrd-switch-root.service.
  793. 35.42 s [vm-test-run-nixos-test-read-proxy] server # [ 10.636585] systemd[1]: systemd-journald.service: Scheduled restart job, restart counter is at 1.
  794. 35.43 s [vm-test-run-nixos-test-read-proxy] server # [ 10.640709] systemd[1]: Created slice Slice /system/getty.
  795. 35.43 s [vm-test-run-nixos-test-read-proxy] server # [ 10.643349] systemd[1]: Created slice User and Session Slice.
  796. 35.43 s [vm-test-run-nixos-test-read-proxy] server # [ 10.645719] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
  797. 35.44 s [vm-test-run-nixos-test-read-proxy] server # [ 10.648707] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
  798. 35.44 s [vm-test-run-nixos-test-read-proxy] server # [ 10.651771] systemd[1]: Expecting device /dev/hvc0...
  799. 35.44 s [vm-test-run-nixos-test-read-proxy] server # [ 10.653656] systemd[1]: Expecting device /dev/ttyS0...
  800. 35.44 s [vm-test-run-nixos-test-read-proxy] server # [ 10.655632] systemd[1]: Reached target Local Encrypted Volumes.
  801. 35.44 s [vm-test-run-nixos-test-read-proxy] server # [ 10.657715] systemd[1]: Stopped target initrd-fs.target.
  802. 35.45 s [vm-test-run-nixos-test-read-proxy] server # [ 10.659692] systemd[1]: Stopped target initrd-root-fs.target.
  803. 35.45 s [vm-test-run-nixos-test-read-proxy] server # [ 10.661799] systemd[1]: Stopped target initrd-switch-root.target.
  804. 35.45 s [vm-test-run-nixos-test-read-proxy] server # [ 10.664036] systemd[1]: Reached target Virtual Machines and Containers.
  805. 35.45 s [vm-test-run-nixos-test-read-proxy] server # [ 10.666653] systemd[1]: Reached target Path Units.
  806. 35.46 s [vm-test-run-nixos-test-read-proxy] server # [ 10.668648] systemd[1]: Reached target Remote File Systems.
  807. 35.46 s [vm-test-run-nixos-test-read-proxy] server # [ 10.670690] systemd[1]: Reached target Slice Units.
  808. 35.46 s [vm-test-run-nixos-test-read-proxy] server # [ 10.672603] systemd[1]: Reached target Swaps.
  809. 35.49 s [vm-test-run-nixos-test-read-proxy] server # [ 10.707080] systemd[1]: Listening on Query the User Interactively for a Password.
  810. 35.50 s [vm-test-run-nixos-test-read-proxy] server # [ 10.716988] systemd[1]: Listening on Process Core Dump Socket.
  811. 35.51 s [vm-test-run-nixos-test-read-proxy] server # [ 10.725854] systemd[1]: Listening on Credential Encryption/Decryption.
  812. 35.52 s [vm-test-run-nixos-test-read-proxy] server # [ 10.734861] systemd[1]: Listening on Factory Reset Management.
  813. 35.52 s [vm-test-run-nixos-test-read-proxy] server # [ 10.737391] systemd[1]: Listening on Hostname Service Socket.
  814. 35.54 s [vm-test-run-nixos-test-read-proxy] server # [ 10.748371] systemd[1]: Starting Journal Log Access Socket...
  815. 35.54 s [vm-test-run-nixos-test-read-proxy] server # [ 10.751446] systemd[1]: Listening on Journal Audit Socket.
  816. 35.54 s [vm-test-run-nixos-test-read-proxy] server # [ 10.756069] systemd[1]: Listening on Console Output Muting Service Socket.
  817. 35.55 s [vm-test-run-nixos-test-read-proxy] server # [ 10.758768] systemd[1]: Listening on Userspace Out-Of-Memory (OOM) Killer Socket.
  818. 35.55 s [vm-test-run-nixos-test-read-proxy] server # [ 10.761770] systemd[1]: TPM PCR Measurements skipped, unmet condition check ConditionSecurity=measured-os
  819. 35.55 s [vm-test-run-nixos-test-read-proxy] server # [ 10.765011] systemd[1]: Make TPM PCR Policy skipped, unmet condition check ConditionSecurity=measured-uki
  820. 35.56 s [vm-test-run-nixos-test-read-proxy] server # [ 10.774829] systemd[1]: Listening on Disk Repartitioning Service Socket.
  821. 35.56 s [vm-test-run-nixos-test-read-proxy] server # [ 10.777443] systemd[1]: Listening on udev Control Socket.
  822. 35.57 s [vm-test-run-nixos-test-read-proxy] server # [ 10.779739] systemd[1]: Listening on udev Varlink Socket.
  823. 35.58 s [vm-test-run-nixos-test-read-proxy] server # [ 10.790925] systemd[1]: Mounting Huge Pages File System...
  824. 35.58 s [vm-test-run-nixos-test-read-proxy] server # [ 10.795634] systemd[1]: Mounting POSIX Message Queue File System...
  825. 35.59 s [vm-test-run-nixos-test-read-proxy] server # [ 10.801612] systemd[1]: Mounting Kernel Debug File System...
  826. 35.60 s [vm-test-run-nixos-test-read-proxy] server # [ 10.813296] systemd[1]: Mounting Kernel Trace File System...
  827. 35.61 s [vm-test-run-nixos-test-read-proxy] server # [ 10.826707] systemd[1]: Starting Create List of Static Device Nodes...
  828. 35.62 s [vm-test-run-nixos-test-read-proxy] server # [ 10.830690] systemd[1]: Load Kernel Module 9pnet_virtio skipped, unmet condition check ConditionKernelModuleLoaded=!9pnet_virtio
  829. 35.65 s [vm-test-run-nixos-test-read-proxy] server # [ 10.860617] systemd[1]: Starting Load Kernel Module configfs...
  830. 35.66 s [vm-test-run-nixos-test-read-proxy] server # [ 10.876046] systemd[1]: Load Kernel Module drm skipped, unmet condition check ConditionKernelModuleLoaded=!drm
  831. 35.68 s [vm-test-run-nixos-test-read-proxy] server # [ 10.893186] systemd[1]: Load Kernel Module efi_pstore skipped, unmet condition check ConditionKernelModuleLoaded=!efi_pstore
  832. 35.69 s [vm-test-run-nixos-test-read-proxy] server # [ 10.898640] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse
  833. 35.70 s [vm-test-run-nixos-test-read-proxy] server # [ 10.913169] systemd[1]: Mounting FUSE Control File System...
  834. 35.71 s [vm-test-run-nixos-test-read-proxy] server # [ 10.915798] systemd[1]: Clear Stale Hibernate Storage Info skipped, unmet condition check ConditionPathExists=/sys/firmware/efi/efivars/HibernateLocation-8cf2644b-4b0b-428f-9387-6d876050dc67
  835. 35.72 s [vm-test-run-nixos-test-read-proxy] server # [ 10.932609] systemd[1]: Starting Journal Service...
  836. 35.73 s [vm-test-run-nixos-test-read-proxy] server # [ 10.941648] systemd[1]: Starting Load Kernel Modules...
  837. 35.75 s [vm-test-run-nixos-test-read-proxy] server # [ 10.960976] systemd[1]: Starting Userspace Out-Of-Memory (OOM) Killer...
  838. 35.77 s [vm-test-run-nixos-test-read-proxy] server # [ 10.985833] systemd[1]: Starting Remount Root and Kernel File Systems...
  839. 35.79 s [vm-test-run-nixos-test-read-proxy] server # [ 10.993813] systemd[1]: Early TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os
  840. 35.80 s [vm-test-run-nixos-test-read-proxy] server # [ 11.009018] systemd-journald[270]: Collecting audit messages is enabled.
  841. 35.82 s [vm-test-run-nixos-test-read-proxy] server # [ 11.027720] systemd[1]: Starting Coldplug All udev Devices...
  842. 35.83 s [vm-test-run-nixos-test-read-proxy] server # [ 11.040992] loop: module loaded
  843. 35.86 s [vm-test-run-nixos-test-read-proxy] server # [ 11.069443] systemd[1]: Listening on Journal Log Access Socket.
  844. 35.87 s [vm-test-run-nixos-test-read-proxy] server # [ 10.374219] systemd[1]: Queued start job for default target Multi-User System.[ 11.084680] systemd[1]: Started Journal Service.
  845. 35.95 s [vm-test-run-nixos-test-read-proxy] server #
  846. 35.95 s [vm-test-run-nixos-test-read-proxy] server # [ 10.385536] systemd[1]: systemd-journald.service: Deactivated successfully.
  847. 35.95 s [vm-test-run-nixos-test-read-proxy] server # [ 10.397755] systemd-modules-load[271]: Inserted module 'loop'
  848. 35.95 s [vm-test-run-nixos-test-read-proxy] server # [ 11.107742] EXT4-fs (vda): re-mounted 3b7a8533-f130-4ace-9f7b-f504742e46c2.
  849. 35.95 s [vm-test-run-nixos-test-read-proxy] server # [ 10.414207] systemd[1]: Mounted Huge Pages File System.
  850. 35.95 s [vm-test-run-nixos-test-read-proxy] server # [ 10.416609] systemd[1]: Mounted POSIX Message Queue File System.
  851. 35.95 s [vm-test-run-nixos-test-read-proxy] server # [ 10.427604] systemd[1]: Mounted Kernel Debug File System.
  852. 35.95 s [vm-test-run-nixos-test-read-proxy] server # [ 10.436439] systemd[1]: Mounted Kernel Trace File System.
  853. 35.95 s [vm-test-run-nixos-test-read-proxy] server # [ 10.446398] systemd[1]: Finished Create List of Static Device Nodes.
  854. 35.95 s [vm-test-run-nixos-test-read-proxy] server # [ 10.458427] systemd[1]: modprobe@configfs.service: Deactivated successfully.
  855. 36.00 s [vm-test-run-nixos-test-read-proxy] server # [ 10.467548] systemd[1]: Finished Load Kernel Module configfs.
  856. 36.00 s [vm-test-run-nixos-test-read-proxy] server # [ 10.476185] systemd[1]: Mounted FUSE Control File System.
  857. 36.00 s [vm-test-run-nixos-test-read-proxy] server # [ 10.479571] systemd[1]: Finished Load Kernel Modules.
  858. 36.00 s [vm-test-run-nixos-test-read-proxy] server # [ 10.484775] systemd[1]: Finished Remount Root and Kernel File Systems.
  859. 36.00 s [vm-test-run-nixos-test-read-proxy] server # [ 10.493557] systemd-oomd[273]: [0;1;38:5:185mNo swap; memory pressure usage will be degraded
  860. 36.00 s [vm-test-run-nixos-test-read-proxy] server # [ 10.504853] systemd[1]: Listening on Disk Image Download Service Socket.
  861. 36.00 s [vm-test-run-nixos-test-read-proxy] server # [ 10.514827] systemd[1]: Mounting Kernel Configuration File System...
  862. 36.01 s [vm-test-run-nixos-test-read-proxy] server # [ 10.523913] systemd[1]: Starting Firewall...
  863. 36.02 s [vm-test-run-nixos-test-read-proxy] server # [ 10.526332] systemd[1]: Starting Flush Journal to Persistent Storage...
  864. 36.02 s [vm-test-run-nixos-test-read-proxy] server # [ 10.531337] systemd[1]: Platform Persistent Storage Archival skipped, unmet condition check ConditionDirectoryNotEmpty=/sys/fs/pstore
  865. 36.03 s [vm-test-run-nixos-test-read-proxy] server # [ 10.544380] systemd[1]: Starting Load/Save OS Random Seed...
  866. 36.04 s [vm-test-run-nixos-test-read-proxy] server # [ 10.547324] systemd[1]: Starting Apply Kernel Variables...
  867. 36.05 s [vm-test-run-nixos-test-read-proxy] server # [ 10.561309] systemd[1]: Starting Create Static Device Nodes in /dev gracefully...
  868. 36.06 s [vm-test-run-nixos-test-read-proxy] server # [ 10.568264] systemd[1]: TPM SRK Setup skipped, unmet condition check ConditionSecurity=measured-os
  869. 36.07 s [vm-test-run-nixos-test-read-proxy] server # [ 10.584160] systemd[1]: Started Userspace Out-Of-Memory (OOM) Killer.
  870. 36.16 s [vm-test-run-nixos-test-read-proxy] server # [ 11.367384] systemd-journald[270]: Received client request to flush runtime journal.
  871. 36.52 s [vm-test-run-nixos-test-read-proxy] server # [ 11.034275] systemd[1]: Mounted Kernel Configuration File System.
  872. 36.53 s [vm-test-run-nixos-test-read-proxy] server # [ 11.042865] systemd[1]: Finished Load/Save OS Random Seed.
  873. 36.54 s [vm-test-run-nixos-test-read-proxy] server # [ 11.051160] systemd[1]: Reached target First Boot Complete.
  874. 36.55 s [vm-test-run-nixos-test-read-proxy] server # [ 11.058228] systemd[1]: Finished Apply Kernel Variables.
  875. 36.55 s [vm-test-run-nixos-test-read-proxy] server # [ 11.062707] systemd[1]: Finished Create Static Device Nodes in /dev gracefully.
  876. 36.56 s [vm-test-run-nixos-test-read-proxy] server # [ 11.070397] systemd[1]: Starting Create Static Device Nodes in /dev...
  877. 36.57 s [vm-test-run-nixos-test-read-proxy] server # [ 11.076268] systemd[1]: Finished Create Static Device Nodes in /dev.
  878. 36.57 s [vm-test-run-nixos-test-read-proxy] server # [ 11.081437] systemd[1]: Reached target Preparation for Local File Systems.
  879. 36.58 s [vm-test-run-nixos-test-read-proxy] server # [ 11.089147] systemd[1]: Mounting /run/wrappers...
  880. 36.58 s [vm-test-run-nixos-test-read-proxy] server # [ 11.091563] systemd[1]: Starting Rule-based Manager for Device Events and Files...
  881. 36.59 s [vm-test-run-nixos-test-read-proxy] server # [ 11.098231] systemd[1]: Finished Coldplug All udev Devices.
  882. 36.59 s [vm-test-run-nixos-test-read-proxy] server # [ 11.103599] systemd[1]: Finished Flush Journal to Persistent Storage.
  883. 36.60 s [vm-test-run-nixos-test-read-proxy] server # [ 11.111302] systemd[1]: Mounted /run/wrappers.
  884. 36.60 s [vm-test-run-nixos-test-read-proxy] server # [ 11.114352] systemd[1]: Reached target Local File Systems.
  885. 36.61 s [vm-test-run-nixos-test-read-proxy] server # [ 11.118550] systemd[1]: Listening on Boot Loader Control Service Socket.
  886. 36.61 s [vm-test-run-nixos-test-read-proxy] server # [ 11.123873] systemd[1]: Starting register-nix-paths.service...
  887. 36.62 s [vm-test-run-nixos-test-read-proxy] server # [ 11.131319] systemd[1]: Starting Create SUID/SGID Wrappers...
  888. 36.63 s [vm-test-run-nixos-test-read-proxy] server # [ 11.137236] systemd[1]: Update Boot Loader Random Seed skipped, no trigger condition checks were met.
  889. 36.64 s [vm-test-run-nixos-test-read-proxy] server # [ 11.145801] systemd[1]: Starting Save Transient machine-id to Disk...
  890. 36.65 s [vm-test-run-nixos-test-read-proxy] server # [ 11.155873] systemd[1]: Starting Create System Files and Directories...
  891. 36.66 s [vm-test-run-nixos-test-read-proxy] server # [ 11.170431] systemd-udevd[305]: Using default interface naming scheme 'v261'.
  892. 36.82 s [vm-test-run-nixos-test-read-proxy] server # [ 11.333613] systemd[1]: etc-machine\x2did.mount: Deactivated successfully.
  893. 36.83 s [vm-test-run-nixos-test-read-proxy] server # [ 11.342483] systemd[1]: Finished Save Transient machine-id to Disk.
  894. 36.84 s [vm-test-run-nixos-test-read-proxy] server # [ 11.350327] systemd[1]: Finished Create System Files and Directories.
  895. 36.86 s [vm-test-run-nixos-test-read-proxy] server # [ 11.366989] systemd[1]: Starting Rebuild Journal Catalog...
  896. 36.86 s [vm-test-run-nixos-test-read-proxy] server # [ 11.374219] systemd[1]: Starting Record System Boot/Shutdown in UTMP...
  897. 36.98 s [vm-test-run-nixos-test-read-proxy] server # [ 11.495361] systemd[1]: Finished Record System Boot/Shutdown in UTMP.
  898. 37.00 s [vm-test-run-nixos-test-read-proxy] server # [ 11.503276] systemd[1]: Started Rule-based Manager for Device Events and Files.
  899. 37.03 s [vm-test-run-nixos-test-read-proxy] server # [ 11.544872] systemd[1]: Finished Rebuild Journal Catalog.
  900. 37.04 s [vm-test-run-nixos-test-read-proxy] server # [ 11.554674] systemd[1]: Starting Update is Completed...
  901. 37.11 s [vm-test-run-nixos-test-read-proxy] server # [ 11.621964] systemd[1]: Finished Update is Completed.
  902. 37.55 s [vm-test-run-nixos-test-read-proxy] server # [ 12.063974] systemd[1]: suid-sgid-wrappers.service: Deactivated successfully.
  903. 37.56 s [vm-test-run-nixos-test-read-proxy] server # [ 12.069706] systemd[1]: Finished Create SUID/SGID Wrappers.
  904. 37.63 s [vm-test-run-nixos-test-read-proxy] server # [ 12.136662] systemd[1]: Load Kernel Module fuse skipped, unmet condition check ConditionKernelModuleLoaded=!fuse
  905. 37.85 s [vm-test-run-nixos-test-read-proxy] server # [ 12.355392] systemd[1]: Condition check resulted in /dev/hvc0 being skipped.
  906. 37.87 s [vm-test-run-nixos-test-read-proxy] server # [ 12.383613] systemd[1]: Condition check resulted in /dev/ttyS0 being skipped.
  907. 37.91 s [vm-test-run-nixos-test-read-proxy] server # [ 12.418634] (udev-worker)[421]: Network interface NamePolicy= disabled on kernel command line.
  908. 37.92 s [vm-test-run-nixos-test-read-proxy] server # [ 12.430898] (udev-worker)[428]: [0;1;38:5:185meth1: Config file /etc/systemd/network/40-eth1.link is applied to device based on potentially unpredictable interface name.
  909. 37.93 s [vm-test-run-nixos-test-read-proxy] server # [ 12.443217] (udev-worker)[428]: Network interface NamePolicy= disabled on kernel command line.
  910. 38.17 s [vm-test-run-nixos-test-read-proxy] server # [ 12.680486] systemd[1]: Finished register-nix-paths.service.
  911. 38.17 s [vm-test-run-nixos-test-read-proxy] server # [ 12.685593] systemd[1]: Reached target System Initialization.
  912. 38.18 s [vm-test-run-nixos-test-read-proxy] server # [ 12.691475] systemd[1]: Started Discard unused filesystem blocks once a week.
  913. 38.19 s [vm-test-run-nixos-test-read-proxy] server # [ 12.698121] systemd[1]: Started niks3 garbage collection timer.
  914. 38.19 s [vm-test-run-nixos-test-read-proxy] server # [ 12.700710] systemd[1]: Started Daily Cleanup of Temporary Directories.
  915. 38.20 s [vm-test-run-nixos-test-read-proxy] server # [ 12.706316] systemd[1]: Reached target Timer Units.
  916. 38.20 s [vm-test-run-nixos-test-read-proxy] server # [ 12.709313] systemd[1]: Listening on D-Bus System Message Bus Socket.
  917. 38.20 s [vm-test-run-nixos-test-read-proxy] server # [ 12.714269] systemd[1]: Listening on niks3 server socket.
  918. 38.21 s [vm-test-run-nixos-test-read-proxy] server # [ 12.717907] systemd[1]: Listening on Nix Daemon Socket.
  919. 38.21 s [vm-test-run-nixos-test-read-proxy] server # [ 12.723798] systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.
  920. 38.22 s [vm-test-run-nixos-test-read-proxy] server # [ 12.731722] systemd[1]: Reached target Socket Units.
  921. 38.23 s [vm-test-run-nixos-test-read-proxy] server # [ 12.738427] systemd[1]: Reached target Basic System.
  922. 38.23 s [vm-test-run-nixos-test-read-proxy] server # [ 12.743304] systemd[1]: Started backdoor.service.
  923. 38.24 s [vm-test-run-nixos-test-read-proxy] server # [ 12.748688] systemd[1]: Starting Import lastlog data into lastlog2 database...
  924. 38.25 s [vm-test-run-nixos-test-read-proxy] server # [ 12.756346] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
  925. 38.25 s [vm-test-run-nixos-test-read-proxy] server # [ 12.765092] systemd[1]: Starting Post-Boot Actions...
  926. 38.27 s [vm-test-run-nixos-test-read-proxy] server # [ 12.785198] systemd[1]: Started Reset console on configuration changes.
  927. 38.30 s [vm-test-run-nixos-test-read-proxy] server # [ 12.809394] systemd[1]: Starting resolvconf update...
  928. 38.31 s [vm-test-run-nixos-test-read-proxy] server # [ 12.825639] systemd[1]: Finished Firewall.
  929. 38.34 s [vm-test-run-nixos-test-read-proxy] server # connecting to host...
  930. 38.36 s [vm-test-run-nixos-test-read-proxy] server # [ 12.866450] systemd[1]: Condition check resulted in Virtio network device being skipped.
  931. 38.38 s [vm-test-run-nixos-test-read-proxy] server # [ 12.887665] systemd[1]: Finished Post-Boot Actions.
  932. 38.40 s [vm-test-run-nixos-test-read-proxy] server: Guest shell says: b'Spawning backdoor root shell...\n'
  933. 38.41 s [vm-test-run-nixos-test-read-proxy] server: connected to guest root shell
  934. 38.41 s [vm-test-run-nixos-test-read-proxy] server: (connecting took 15.41 seconds)
  935. 38.41 s [vm-test-run-nixos-test-read-proxy] server: (finished: waiting for the VM to finish booting, in 15.78 seconds)
  936. 38.42 s [vm-test-run-nixos-test-read-proxy] server # [ 12.931602] systemd[1]: Starting D-Bus System Message Bus...
  937. 38.43 s [vm-test-run-nixos-test-read-proxy] server # [ 12.939501] systemd[1]: Started Name Service Cache Daemon (nsncd).
  938. 38.44 s [vm-test-run-nixos-test-read-proxy] server # [ 12.948512] nsncd[493]: Jul 19 09:28:41.566 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
  939. 38.46 s [vm-test-run-nixos-test-read-proxy] server # [ 12.970796] systemd[1]: Reached target Host and Network Name Lookups.
  940. 38.47 s [vm-test-run-nixos-test-read-proxy] server # [ 12.982322] systemd[1]: Reached target User and Group Name Lookups.
  941. 38.48 s [vm-test-run-nixos-test-read-proxy] server # [ 12.991348] systemd[1]: Starting User Login Management...
  942. 38.49 s [vm-test-run-nixos-test-read-proxy] server # [ 12.998825] systemd[1]: Finished Import lastlog data into lastlog2 database.
  943. 38.66 s [vm-test-run-nixos-test-read-proxy] server # [ 13.870189] mousedev: PS/2 mouse device common for all mice
  944. 38.66 s [vm-test-run-nixos-test-read-proxy] server # [ 13.174399] dbus-broker-launch[518]: Looking up NSS user entry for 'systemd-timesync'...
  945. 38.68 s [vm-test-run-nixos-test-read-proxy] server # [ 13.188430] systemd-logind[521]: New seat seat0.
  946. 38.69 s [vm-test-run-nixos-test-read-proxy] server # [ 13.196278] systemd[1]: Started User Login Management.
  947. 38.69 s [vm-test-run-nixos-test-read-proxy] server # [ 13.202343] systemd[1]: Starting linger-users.service...
  948. 38.70 s [vm-test-run-nixos-test-read-proxy] server # [ 13.910313] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input3
  949. 38.70 s [vm-test-run-nixos-test-read-proxy] server # [ 13.210907] dbus-broker-launch[518]: NSS returned no entry for 'systemd-timesync'
  950. 38.71 s [vm-test-run-nixos-test-read-proxy] server # [ 13.216396] dbus-broker-launch[518]: Invalid user-name in /nix/store/bxhdy57r6hl031izqz6q75p6cqynykp8-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"
  951. 38.73 s [vm-test-run-nixos-test-read-proxy] server # [ 13.238097] systemd[1]: Stopped target Host and Network Name Lookups.
  952. 38.74 s [vm-test-run-nixos-test-read-proxy] server # [ 13.242428] systemd[1]: Stopping Host and Network Name Lookups...[ 13.950259] bochs-drm 0000:00:02.0: vgaarb: deactivate vga console
  953. 38.74 s [vm-test-run-nixos-test-read-proxy] server #
  954. 38.74 s [vm-test-run-nixos-test-read-proxy] server # [ 13.250865] systemd[1]: Stopped target User and Group Name Lookups.
  955. 38.75 s [vm-test-run-nixos-test-read-proxy] server # [ 13.259884] systemd[1]: Stopping User and Group Name Lookups...
  956. 38.76 s [vm-test-run-nixos-test-read-proxy] server # [ 13.274925] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...
  957. 38.78 s [vm-test-run-nixos-test-read-proxy] server # [ 13.292397] systemd[1]: nscd.service: Deactivated successfully.
  958. 38.79 s [vm-test-run-nixos-test-read-proxy] server # [ 13.301362] systemd[1]: Stopped Name Service Cache Daemon (nsncd).
  959. 38.80 s [vm-test-run-nixos-test-read-proxy] server # [ 13.308620] systemd[1]: Started D-Bus System Message Bus.
  960. 38.84 s [vm-test-run-nixos-test-read-proxy] server # [ 13.346270] dbus-broker-launch[518]: Ready
  961. 38.84 s [vm-test-run-nixos-test-read-proxy] server # [ 13.353920] systemd[1]: linger-users.service: Deactivated successfully.
  962. 38.85 s [vm-test-run-nixos-test-read-proxy] server # [ 13.365222] systemd[1]: Finished linger-users.service.
  963. 38.88 s [vm-test-run-nixos-test-read-proxy] server # [ 13.392966] systemd[1]: Starting Name Service Cache Daemon (nsncd)...
  964. 38.91 s [vm-test-run-nixos-test-read-proxy] server # [ 13.421376] systemd[1]: Finished resolvconf update.
  965. 38.91 s [vm-test-run-nixos-test-read-proxy] server # [ 13.425571] systemd[1]: Reached target Preparation for Network.
  966. 38.93 s [vm-test-run-nixos-test-read-proxy] server # [ 13.436169] systemd[1]: Starting DHCP Client...
  967. 38.94 s [vm-test-run-nixos-test-read-proxy] server # [ 13.447962] systemd[1]: Starting Address configuration of eth1...
  968. 38.95 s [vm-test-run-nixos-test-read-proxy] server # [ 13.455537] nsncd[584]: Jul 19 09:28:42.096 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"
  969. 38.96 s [vm-test-run-nixos-test-read-proxy] server # [ 13.471527] systemd[1]: Starting Extra networking commands....
  970. 38.97 s [vm-test-run-nixos-test-read-proxy] server # [ 13.479736] systemd[1]: Started Name Service Cache Daemon (nsncd).
  971. 38.98 s [vm-test-run-nixos-test-read-proxy] server # [ 13.490915] systemd[1]: Reached target Host and Network Name Lookups.
  972. 38.99 s [vm-test-run-nixos-test-read-proxy] server # [ 13.497870] systemd[1]: Reached target User and Group Name Lookups.
  973. 39.03 s [vm-test-run-nixos-test-read-proxy] server # [ 14.022695] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0
  974. 39.08 s [vm-test-run-nixos-test-read-proxy] server # [ 14.022852] i2c i2c-0: Memory type 0x07 not supported yet, not instantiating SPD
  975. 39.08 s [vm-test-run-nixos-test-read-proxy] server # [ 14.031168] ACPI: button: Power Button [PWRF]
  976. 39.08 s [vm-test-run-nixos-test-read-proxy] server # [ 14.191831] rtc_cmos 00:05: RTC can wake from S4
  977. 39.11 s [vm-test-run-nixos-test-read-proxy] server # [ 13.618941] network-addresses-eth1-start[589]: adding address 192.168.1.1/24... done
  978. 39.11 s [vm-test-run-nixos-test-read-proxy] server # [ 14.241643] Console: switching to colour dummy device 80x25
  979. 39.11 s [vm-test-run-nixos-test-read-proxy] server # [ 14.267036] parport_pc 00:03: reported by Plug and Play ACPI
  980. 39.13 s [vm-test-run-nixos-test-read-proxy] server # [ 14.267187] parport0: PC-style at 0x378, irq 7 [PCSPP(,...)]
  981. 39.13 s [vm-test-run-nixos-test-read-proxy] server # [ 14.283378] Floppy drive(s): fd0 is 2.88M AMI BIOS
  982. 39.13 s [vm-test-run-nixos-test-read-proxy] server # [ 13.642206] network-addresses-eth1-start[589]: adding address 2001:db8:1::1/64... done
  983. 39.17 s [vm-test-run-nixos-test-read-proxy] server # [ 14.284099] rtc_cmos 00:05: registered as rtc0
  984. 39.17 s [vm-test-run-nixos-test-read-proxy] server # [ 14.284358] rtc_cmos 00:05: setting system clock to 2026-07-19T09:28:43 UTC (1784453323)
  985. 39.18 s [vm-test-run-nixos-test-read-proxy] server # [ 13.693868] systemd[1]: Finished Address configuration of eth1.
  986. 39.22 s [vm-test-run-nixos-test-read-proxy] server # [ 14.302851] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs
  987. 39.22 s [vm-test-run-nixos-test-read-proxy] server # [ 14.310350] FDC 0 is a S82078B
  988. 39.24 s [vm-test-run-nixos-test-read-proxy] server # [ 13.752450] dhcpcd[608]: dhcpcd-10.3.2 starting
  989. 39.25 s [vm-test-run-nixos-test-read-proxy] server # [ 13.765940] dhcpcd[650]: dev: loaded udev
  990. 39.27 s [vm-test-run-nixos-test-read-proxy] server # [ 14.481328] [drm] Found bochs VGA, ID 0xb0c5.
  991. 39.27 s [vm-test-run-nixos-test-read-proxy] server # [ 14.482297] [drm] Framebuffer size 16384 kB @ 0xfd000000, mmio @ 0xfebd0000.
  992. 39.28 s [vm-test-run-nixos-test-read-proxy] server # [ 14.496680] 8021q: 802.1Q VLAN Support v1.8
  993. 39.29 s [vm-test-run-nixos-test-read-proxy] server # [ 14.499765] 8021q: adding VLAN 0 to HW filter on device eth1
  994. 39.30 s [vm-test-run-nixos-test-read-proxy] server # [ 13.805935] systemd[1]: Finished Extra networking commands..
  995. 39.30 s [vm-test-run-nixos-test-read-proxy] server # [ 13.810986] systemd[1]: Reached target Network.
  996. 39.31 s [vm-test-run-nixos-test-read-proxy] server # [ 14.521932] input: QEMU Virtio Keyboard as /devices/pci0000:00/0000:00:0a.0/virtio7/input/input4
  997. 39.33 s [vm-test-run-nixos-test-read-proxy] server # [ 14.540731] bochs-drm 0000:00:02.0: [drm] Registered 1 planes with drm panic
  998. 39.33 s [vm-test-run-nixos-test-read-proxy] server # [ 14.542301] [drm] Initialized bochs-drm 1.0.0 for 0000:00:02.0 on minor 0
  999. 39.33 s [vm-test-run-nixos-test-read-proxy] server # [ 13.843467] systemd[1]: Starting PostgreSQL Server...
  1000. 39.34 s [vm-test-run-nixos-test-read-proxy] server # [ 14.551123] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input6
  1001. 39.34 s [vm-test-run-nixos-test-read-proxy] server # [ 13.852397] systemd[1]: Started rustfs.service.
  1002. 39.35 s [vm-test-run-nixos-test-read-proxy] server # [ 14.558442] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input5
  1003. 39.37 s [vm-test-run-nixos-test-read-proxy] server # [ 13.878523] systemd[1]: Starting rustfs-setup.service...
  1004. 39.38 s [vm-test-run-nixos-test-read-proxy] server # [ 13.894936] systemd[1]: Starting Permit User Sessions...
  1005. 39.64 s [vm-test-run-nixos-test-read-proxy] server # [ 14.146494] systemd[1]: Finished Permit User Sessions.
  1006. 40.00 s [vm-test-run-nixos-test-read-proxy] server # [ 14.506777] postgresql-pre-start[676]: The files belonging to this database system will be owned by user "postgres".
  1007. 40.01 s [vm-test-run-nixos-test-read-proxy] server # [ 14.524588] postgresql-pre-start[676]: This user must also own the server process.
  1008. 40.04 s [vm-test-run-nixos-test-read-proxy] server # [ 14.540856] postgresql-pre-start[676]: The database cluster will be initialized with locale "en_US.UTF-8".
  1009. 40.05 s [vm-test-run-nixos-test-read-proxy] server # [ 14.557381] postgresql-pre-start[676]: The default database encoding has accordingly been set to "UTF8".
  1010. 40.06 s [vm-test-run-nixos-test-read-proxy] server # [ 14.574589] postgresql-pre-start[676]: The default text search configuration will be set to "english".
  1011. 40.08 s [vm-test-run-nixos-test-read-proxy] server # [ 14.590355] postgresql-pre-start[676]: Data page checksums are enabled.
  1012. 40.09 s [vm-test-run-nixos-test-read-proxy] server # [ 14.600408] postgresql-pre-start[676]: fixing permissions on existing directory /var/lib/postgresql/18 ... ok
  1013. 40.11 s [vm-test-run-nixos-test-read-proxy] server # [ 14.613995] postgresql-pre-start[676]: creating subdirectories ... ok
  1014. 40.11 s [vm-test-run-nixos-test-read-proxy] server # [ 14.621988] postgresql-pre-start[676]: selecting dynamic shared memory implementation ... posix
  1015. 40.15 s [vm-test-run-nixos-test-read-proxy] server # [ 14.660777] dhcpcd[650]: eth0: waiting for carrier
  1016. 40.16 s [vm-test-run-nixos-test-read-proxy] server # [ 14.671187] dhcpcd[650]: libudev: received NULL device
  1017. 40.16 s [vm-test-run-nixos-test-read-proxy] server # [ 14.674272] dhcpcd[650]: libudev: received NULL device
  1018. 40.17 s [vm-test-run-nixos-test-read-proxy] server # [ 14.739051] fbcon: bochs-drmdrmfb (fb0) is primary device
  1019. 40.18 s [vm-test-run-nixos-test-read-proxy] server # [ 14.681836] dhcpcd[650]: eth0: carrier acquired
  1020. 40.18 s [vm-test-run-nixos-test-read-proxy] server # [ 15.020266] cfg80211: Loading compiled-in X.509 certificates for regulatory database
  1021. 40.20 s [vm-test-run-nixos-test-read-proxy] server # [ 15.073861] Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
  1022. 40.22 s [vm-test-run-nixos-test-read-proxy] server # [ 14.726840] dhcpcd[650]: DUID 00:01:00:01:31:ef:55:4c:52:54:00:12:34:56
  1023. 40.23 s [vm-test-run-nixos-test-read-proxy] server # [ 15.073958] Loaded X.509 cert 'wens: 61c038651aabdcf94bd0ac7ff06c7248db18c600'
  1024. 40.23 s [vm-test-run-nixos-test-read-proxy] server # [ 14.737899] dhcpcd[650]: eth0: IAID 00:12:34:56
  1025. 40.23 s [vm-test-run-nixos-test-read-proxy] server # [ 14.739726] dhcpcd[650]: eth0: adding address fe80::5054:ff:fe12:3456
  1026. 40.24 s [vm-test-run-nixos-test-read-proxy] server # [ 15.076244] faux_driver regulatory: Direct firmware load for regulatory.db failed with error -2
  1027. 40.26 s [vm-test-run-nixos-test-read-proxy] server # [ 15.076285] cfg80211: failed to load regulatory.db
  1028. 40.26 s [vm-test-run-nixos-test-read-proxy] server # [ 15.356386] Console: switching to colour frame buffer device 160x50
  1029. 40.27 s [vm-test-run-nixos-test-read-proxy] server # [ 15.362379] 8021q: adding VLAN 0 to HW filter on device eth0
  1030. 40.29 s [vm-test-run-nixos-test-read-proxy] server # [ 15.501060] bochs-drm 0000:00:02.0: [drm] fb0: bochs-drmdrmfb frame buffer device
  1031. 40.30 s [vm-test-run-nixos-test-read-proxy] server # [ 14.810936] systemd[1]: Started Getty on tty1.
  1032. 40.30 s [vm-test-run-nixos-test-read-proxy] server # [ 14.814856] systemd[1]: Reached target Login Prompts.
  1033. 40.44 s [vm-test-run-nixos-test-read-proxy] server # [ 14.951550] systemd[1]: Starting Virtual Console Setup...
  1034. 40.57 s [vm-test-run-nixos-test-read-proxy] server # [ 15.078324] postgresql-pre-start[676]: selecting default "max_connections" ... 100
  1035. 40.58 s [vm-test-run-nixos-test-read-proxy] server # [ 15.796226] kvm_amd: TSC scaling supported
  1036. 40.59 s [vm-test-run-nixos-test-read-proxy] server # [ 15.806899] kvm_amd: Nested Virtualization enabled
  1037. 40.60 s [vm-test-run-nixos-test-read-proxy] server # [ 15.814015] kvm_amd: Nested Paging enabled
  1038. 40.61 s [vm-test-run-nixos-test-read-proxy] server # [ 15.822930] kvm_amd: LBR virtualization supported
  1039. 40.61 s [vm-test-run-nixos-test-read-proxy] server # [ 15.825783] kvm_amd: Virtual VMLOAD VMSAVE supported
  1040. 40.62 s [vm-test-run-nixos-test-read-proxy] server # [ 15.834748] kvm_amd: Virtual GIF supported
  1041. 40.71 s [vm-test-run-nixos-test-read-proxy] server # [ 15.222667] dhcpcd[650]: eth0: soliciting a DHCP lease
  1042. 40.72 s [vm-test-run-nixos-test-read-proxy] server # [ 15.929269] EDAC MC: Ver: 3.0.0
  1043. 40.76 s [vm-test-run-nixos-test-read-proxy] server # [ 15.975831] NET: Registered PF_PACKET protocol family
  1044. 40.78 s [vm-test-run-nixos-test-read-proxy] server # [ 15.290233] dhcpcd[650]: eth0: offered 10.0.2.15 from 10.0.2.2
  1045. 40.78 s [vm-test-run-nixos-test-read-proxy] server # [ 15.295273] dhcpcd[650]: eth0: probing address 10.0.2.15/24
  1046. 40.89 s [vm-test-run-nixos-test-read-proxy] server # [ 15.396509] postgresql-pre-start[676]: selecting default "shared_buffers" ... 128MB
  1047. 41.13 s [vm-test-run-nixos-test-read-proxy] server # [ 15.638877] systemd-logind[521]: Watching system buttons on /dev/input/event0 (AT Translated Set 2 keyboard)
  1048. 41.25 s [vm-test-run-nixos-test-read-proxy] server # [ 15.756607] systemd-vconsole-setup[703]: Configuration of first virtual console was skipped, ignoring remaining ones.
  1049. 41.26 s [vm-test-run-nixos-test-read-proxy] server # [ 15.775201] systemd[1]: Finished Virtual Console Setup.
  1050. 41.32 s [vm-test-run-nixos-test-read-proxy] server # [ 15.826210] systemd-logind[521]: Watching system buttons on /dev/input/event2 (Power Button)
  1051. 41.44 s [vm-test-run-nixos-test-read-proxy] server # [ 15.937755] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
  1052. 41.44 s [vm-test-run-nixos-test-read-proxy] server # [ 15.951834] systemd[1]: Stopped Virtual Console Setup.
  1053. 41.44 s [vm-test-run-nixos-test-read-proxy] server # [ 16.657016] ppdev: user-space parallel port driver
  1054. 41.45 s [vm-test-run-nixos-test-read-proxy] server # [ 15.960244] systemd[1]: Stopping Virtual Console Setup...
  1055. 41.46 s [vm-test-run-nixos-test-read-proxy] server # [ 15.967329] systemd[1]: Starting Virtual Console Setup...
  1056. 41.47 s [vm-test-run-nixos-test-read-proxy] server # [ 15.985102] systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
  1057. 41.57 s [vm-test-run-nixos-test-read-proxy] server # [ 16.080673] systemd-logind[521]: Watching system buttons on /dev/input/event3 (QEMU Virtio Keyboard)
  1058. 41.80 s [vm-test-run-nixos-test-read-proxy] server # [ 16.303545] rustfs[661]: {"timestamp":"2026-07-19T09:28:46.213258528Z","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)"}
  1059. 41.86 s [vm-test-run-nixos-test-read-proxy] server # [ 16.365419] systemd[1]: systemd-vconsole-setup.service: Deactivated successfully.
  1060. 41.87 s [vm-test-run-nixos-test-read-proxy] server # [ 16.375862] systemd[1]: Stopped Virtual Console Setup.
  1061. 41.90 s [vm-test-run-nixos-test-read-proxy] server # [ 16.406328] systemd[1]: Starting Virtual Console Setup...
  1062. 42.30 s [vm-test-run-nixos-test-read-proxy] server # [ 16.812970] systemd-vconsole-setup[744]: Configuration of first virtual console was skipped, ignoring remaining ones.
  1063. 42.31 s [vm-test-run-nixos-test-read-proxy] server # [ 16.821357] systemd[1]: Finished Virtual Console Setup.
  1064. 42.54 s [vm-test-run-nixos-test-read-proxy] server # [ 17.052186] dhcpcd[650]: eth0: soliciting an IPv6 router
  1065. 42.54 s [vm-test-run-nixos-test-read-proxy] server # [ 17.054593] dhcpcd[650]: eth0: Router Advertisement from fe80::2
  1066. 42.55 s [vm-test-run-nixos-test-read-proxy] server # [ 17.060519] dhcpcd[650]: eth0: adding address fec0::5054:ff:fe12:3456/64
  1067. 42.56 s [vm-test-run-nixos-test-read-proxy] server # [ 17.066471] dhcpcd[650]: eth0: adding route to fec0::/64
  1068. 42.56 s [vm-test-run-nixos-test-read-proxy] server # [ 17.071350] dhcpcd[650]: eth0: adding default route via fe80::2
  1069. 43.74 s [vm-test-run-nixos-test-read-proxy] server # [ 18.252884] postgresql-pre-start[676]: selecting default time zone ... UTC
  1070. 43.75 s [vm-test-run-nixos-test-read-proxy] server # [ 18.258110] postgresql-pre-start[676]: creating configuration files ... ok
  1071. 44.40 s [vm-test-run-nixos-test-read-proxy] server # [ 18.906548] postgresql-pre-start[676]: running bootstrap script ... ok
  1072. 45.44 s [vm-test-run-nixos-test-read-proxy] server # [ 19.950492] postgresql-pre-start[676]: performing post-bootstrap initialization ... ok
  1073. 45.73 s [vm-test-run-nixos-test-read-proxy] server # [ 20.240705] postgresql-pre-start[676]: syncing data to disk ... ok
  1074. 45.73 s [vm-test-run-nixos-test-read-proxy] server # [ 20.243819] postgresql-pre-start[676]: initdb: warning: enabling "trust" authentication for local connections
  1075. 45.74 s [vm-test-run-nixos-test-read-proxy] server # [ 20.246455] postgresql-pre-start[676]: 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.
  1076. 45.74 s [vm-test-run-nixos-test-read-proxy] server # [ 20.250813] postgresql-pre-start[676]: Success. You can now start the database server using:
  1077. 45.74 s [vm-test-run-nixos-test-read-proxy] server # [ 20.253267] postgresql-pre-start[676]: pg_ctl -D /var/lib/postgresql/18 -l logfile start
  1078. 45.75 s [vm-test-run-nixos-test-read-proxy] server # [ 20.258647] dhcpcd[650]: eth0: leased 10.0.2.15 for 86400 seconds
  1079. 45.75 s [vm-test-run-nixos-test-read-proxy] server # [ 20.263840] dhcpcd[650]: eth0: adding route to 10.0.2.0/24
  1080. 45.76 s [vm-test-run-nixos-test-read-proxy] server # [ 20.267124] dhcpcd[650]: eth0: adding default route via 10.0.2.2
  1081. 45.88 s [vm-test-run-nixos-test-read-proxy] server # [ 20.391695] systemd[1]: Started DHCP Client.
  1082. 45.95 s [vm-test-run-nixos-test-read-proxy] server # [ 20.457710] postgres[794]: [794] LOG: starting PostgreSQL 18.4 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit
  1083. 45.98 s [vm-test-run-nixos-test-read-proxy] server # [ 20.467464] postgres[794]: [794] LOG: listening on IPv6 address "::1", port 5432
  1084. 45.98 s [vm-test-run-nixos-test-read-proxy] server # [ 20.469766] postgres[794]: [794] LOG: listening on IPv4 address "127.0.0.1", port 5432
  1085. 45.98 s [vm-test-run-nixos-test-read-proxy] server # [ 20.492387] postgres[794]: [794] LOG: listening on Unix socket "/run/postgresql/.s.PGSQL.5432"
  1086. 46.03 s [vm-test-run-nixos-test-read-proxy] server # [ 20.540546] postgres[845]: [845] LOG: database system was shut down at 2026-07-19 09:28:49 GMT
  1087. 46.07 s [vm-test-run-nixos-test-read-proxy] server # [ 20.575836] postgres[794]: [794] LOG: database system is ready to accept connections
  1088. 46.10 s [vm-test-run-nixos-test-read-proxy] server # [ 20.611664] systemd[1]: Started PostgreSQL Server.
  1089. 46.11 s [vm-test-run-nixos-test-read-proxy] server # [ 20.618984] systemd[1]: Starting PostgreSQL Setup Scripts...
  1090. 46.45 s [vm-test-run-nixos-test-read-proxy] server # [ 20.962534] postgresql-setup-start[856]: CREATE DATABASE
  1091. 46.56 s [vm-test-run-nixos-test-read-proxy] server # [ 21.070421] postgresql-setup-start[866]: CREATE ROLE
  1092. 46.59 s [vm-test-run-nixos-test-read-proxy] server # [ 21.104435] postgresql-setup-start[872]: ALTER DATABASE
  1093. 46.60 s [vm-test-run-nixos-test-read-proxy] server # [ 21.110559] systemd[1]: Finished PostgreSQL Setup Scripts.
  1094. 46.60 s [vm-test-run-nixos-test-read-proxy] server # [ 21.114267] systemd[1]: Reached target PostgreSQL.
  1095. 58.20 s [vm-test-run-nixos-test-read-proxy] server # [ 32.709816] rustfs-setup-start[970]: mb s3://niks3-test
  1096. 58.22 s [vm-test-run-nixos-test-read-proxy] server # [ 32.716893] systemd[1]: Finished rustfs-setup.service.
  1097. 58.22 s [vm-test-run-nixos-test-read-proxy] server # [ 32.722548] systemd[1]: Starting niks3 server...
  1098. 58.44 s [vm-test-run-nixos-test-read-proxy] server # [ 32.947215] postgres[987]: [987] ERROR: relation "goose_db_version" does not exist at character 36
  1099. 58.44 s [vm-test-run-nixos-test-read-proxy] server # [ 32.953216] postgres[987]: [987] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1100. 58.54 s [vm-test-run-nixos-test-read-proxy] server # [ 33.046465] niks3-server[977]: 2026/07/19 09:29:02 OK 20241026095416_initial_model.sql (41.79ms)
  1101. 58.56 s [vm-test-run-nixos-test-read-proxy] server # [ 33.066366] niks3-server[977]: 2026/07/19 09:29:02 OK 20251210153512_drop_unused_gin_index.sql (10.56ms)
  1102. 58.57 s [vm-test-run-nixos-test-read-proxy] server # [ 33.075339] niks3-server[977]: 2026/07/19 09:29:02 OK 20251218171726_add_pins.sql (12.46ms)
  1103. 58.58 s [vm-test-run-nixos-test-read-proxy] server # [ 33.085106] niks3-server[977]: 2026/07/19 09:29:03 OK 20260628120000_add_object_size_and_stats.sql (15ms)
  1104. 58.58 s [vm-test-run-nixos-test-read-proxy] server # [ 33.090900] niks3-server[977]: 2026/07/19 09:29:03 goose: successfully migrated database to version: 20260628120000
  1105. 58.59 s [vm-test-run-nixos-test-read-proxy] server # [ 33.104720] niks3-server[977]: 2026/07/19 09:29:03 OK 1_commit_pending_closure.sql (15.5ms)
  1106. 58.60 s [vm-test-run-nixos-test-read-proxy] server # [ 33.113603] niks3-server[977]: 2026/07/19 09:29:03 OK 2_object_stats_trigger.sql (8.84ms)
  1107. 58.61 s [vm-test-run-nixos-test-read-proxy] server # [ 33.120989] niks3-server[977]: 2026/07/19 09:29:03 goose: up to current file version: 2
  1108. 58.63 s [vm-test-run-nixos-test-read-proxy] server # [ 33.136310] niks3-server[977]: 2026/07/19 09:29:03 INFO Loaded signing key name=niks3-test-1 path=/nix/store/ppgsr71bgq33llkbcbnvv6vis04xhnjd-niks3-signing-key
  1109. 58.71 s [vm-test-run-nixos-test-read-proxy] server # [ 33.216830] rustfs[661]: {"timestamp":"2026-07-19T09:29:03.133761271Z","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)"}
  1110. 58.72 s [vm-test-run-nixos-test-read-proxy] server # [ 33.232537] niks3-server[977]: 2026/07/19 09:29:03 INFO Created nix-cache-info in bucket bucket=niks3-test
  1111. 58.73 s [vm-test-run-nixos-test-read-proxy] server # [ 33.238357] niks3-server[977]: 2026/07/19 09:29:03 INFO Read proxy enabled — serving cache objects from S3
  1112. 58.74 s [vm-test-run-nixos-test-read-proxy] server # [ 33.246961] niks3-server[977]: 2026/07/19 09:29:03 INFO Using socket-activated listener address=0.0.0.0:5751
  1113. 58.74 s [vm-test-run-nixos-test-read-proxy] server # [ 33.251169] niks3-server[977]: 2026/07/19 09:29:03 INFO systemd watchdog enabled interval=15s
  1114. 58.74 s [vm-test-run-nixos-test-read-proxy] server # [ 33.253441] niks3-server[977]: 2026/07/19 09:29:03 INFO Starting HTTP server address=0.0.0.0:5751
  1115. 58.75 s [vm-test-run-nixos-test-read-proxy] server # [ 33.256304] systemd[1]: Started niks3 server.
  1116. 58.75 s [vm-test-run-nixos-test-read-proxy] server # [ 33.257951] systemd[1]: Reached target Multi-User System.
  1117. 58.75 s [vm-test-run-nixos-test-read-proxy] server # [ 33.259871] systemd[1]: Startup finished in 2.829s (kernel) + 5.312s (initrd) + 25.108s (userspace) = 33.250s.
  1118. 59.41 s [vm-test-run-nixos-test-read-proxy] server: (finished: waiting for unit niks3.service, in 36.78 seconds)
  1119. 59.41 s [vm-test-run-nixos-test-read-proxy] server: waiting for TCP port 5751 on localhost
  1120. 59.48 s [vm-test-run-nixos-test-read-proxy] server # Connection to localhost (127.0.0.1) 5751 port [tcp/*] succeeded!
  1121. 59.48 s [vm-test-run-nixos-test-read-proxy] server: (finished: waiting for TCP port 5751 on localhost, in 0.07 seconds)
  1122. 59.48 s [vm-test-run-nixos-test-read-proxy] server: must succeed: curl -sf http://localhost:5751/nix-cache-info | grep StoreDir
  1123. 59.60 s [vm-test-run-nixos-test-read-proxy] server: (finished: must succeed: curl -sf http://localhost:5751/nix-cache-info | grep StoreDir, in 0.12 seconds)
  1124. 59.60 s [vm-test-run-nixos-test-read-proxy] server: must succeed: curl -sf http://localhost:5751/health | grep OK
  1125. 59.64 s [vm-test-run-nixos-test-read-proxy] server: (finished: must succeed: curl -sf http://localhost:5751/health | grep OK, in 0.04 seconds)
  1126. 59.64 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
  1127. 59.66 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.02 seconds)
  1128. 59.66 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
  1129. 59.85 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 311 ms (attempt 1/5)
  1130. 60.17 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 619 ms (attempt 2/5)
  1131. 60.79 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 1092 ms (attempt 3/5)
  1132. 61.89 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 2096 ms (attempt 4/5)
  1133. 63.99 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
  1134. 64.03 s [vm-test-run-nixos-test-read-proxy] server # this derivation will be built:
  1135. 64.03 s [vm-test-run-nixos-test-read-proxy] server # /nix/store/hajfq20jdwgnk2z2v3dilxky8964cn2n-proxy-test.drv
  1136. 64.15 s [vm-test-run-nixos-test-read-proxy] server # building '/nix/store/hajfq20jdwgnk2z2v3dilxky8964cn2n-proxy-test.drv'...
  1137. 64.22 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.57 seconds)
  1138. 64.22 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)
  1139. 64.48 s [vm-test-run-nixos-test-read-proxy] server # [ 38.987794] niks3-server[977]: 2026/07/19 09:29:08 INFO Received uploads request method=POST path=/api/pending_closures
  1140. 64.51 s [vm-test-run-nixos-test-read-proxy] server # time=2026-07-19T09:29:08.938Z level=INFO msg="Uploading 1 paths to localhost (0 already cached)"
  1141. 64.51 s [vm-test-run-nixos-test-read-proxy] server # time=2026-07-19T09:29:08.941Z level=INFO msg="Uploading npj0sp4cz1n2d3vd9f879njkf5gvikw4-proxy-test (128B)"
  1142. 64.54 s [vm-test-run-nixos-test-read-proxy] server # [ 39.051667] niks3-server[977]: 2026/07/19 09:29:08 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign
  1143. 64.55 s [vm-test-run-nixos-test-read-proxy] server # time=2026-07-19T09:29:08.976Z level=INFO msg="Uploading 1 narinfos"
  1144. 64.55 s [vm-test-run-nixos-test-read-proxy] server # [ 39.060835] niks3-server[977]: 2026/07/19 09:29:08 INFO Signed narinfos id=1 count=1
  1145. 64.56 s [vm-test-run-nixos-test-read-proxy] server # [ 39.069303] niks3-server[977]: 2026/07/19 09:29:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete
  1146. 64.57 s [vm-test-run-nixos-test-read-proxy] server # time=2026-07-19T09:29:08.999Z level=INFO msg="Upload complete. (187ms)"
  1147. 64.57 s [vm-test-run-nixos-test-read-proxy] server # [ 39.084409] niks3-server[977]: 2026/07/19 09:29:08 INFO Completed upload id=1
  1148. 64.58 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.35 seconds)
  1149. 64.58 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)
  1150. 64.79 s [vm-test-run-nixos-test-read-proxy] server # copying 1 paths...
  1151. 64.80 s [vm-test-run-nixos-test-read-proxy] server # copying path '/nix/store/npj0sp4cz1n2d3vd9f879njkf5gvikw4-proxy-test' from 'http://localhost:5751'...
  1152. 64.86 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.29 seconds)
  1153. 64.86 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
  1154. 64.97 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.10 seconds)
  1155. 64.97 s [vm-test-run-nixos-test-read-proxy] server: must succeed: test $(curl -so /dev/null -w '%{http_code}' http://localhost:5751/nonexistent) = 404
  1156. 65.01 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.04 seconds)
  1157. 65.01 s [vm-test-run-nixos-test-read-proxy] (finished: run the VM test script, in 42.37 seconds)
  1158. 65.08 s [vm-test-run-nixos-test-read-proxy] test script finished in 42.45s
  1159. 65.08 s [vm-test-run-nixos-test-read-proxy] cleanup
  1160. 65.08 s [vm-test-run-nixos-test-read-proxy] kill QemuMachine (pid 45)
  1161. 65.09 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)
  1162. 65.22 s [vm-test-run-nixos-test-read-proxy] (finished: cleanup, in 0.14 seconds)
  1163. 65.37 s [vm-test-run-nixos-test-read-proxy:post-build] Uploading to the NixCI staging cache: /nix/store/lz6qq96n9lyn7drjxhzfikfwfc2cd61v-vm-test-run-nixos-test-read-proxy
  1164. 65.42 s [vm-test-run-nixos-test-read-proxy:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  1165. 65.43 s [vm-test-run-nixos-test-read-proxy:post-build] copying 1 paths...
  1166. 65.43 s [vm-test-run-nixos-test-read-proxy:post-build] copying path '/nix/store/lz6qq96n9lyn7drjxhzfikfwfc2cd61v-vm-test-run-nixos-test-read-proxy' to 'https://cache.staging.nix-ci.com'...
  1167. 65.59 s [vm-test-run-nixos-test-read-proxy:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  1168. 65.91 s [vm-test-run-nixos-test-read-proxy:post-build] copying 1 paths...
  1169. 65.91 s [vm-test-run-nixos-test-read-proxy:post-build] copying path '/nix/store/ms2p1iciz03jp3bhxqbvssr7qz4wvq26-vm-test-run-nixos-test-read-proxy.drv' to 'https://cache.staging.nix-ci.com'...
  1170. 66.10 s Uploaded vm-test-run-nixos-test-read-proxy in 741ms
  1171. 66.10 s Progress: 11 of 12 built
  1172. 66.10 s Built vm-test-run-nixos-test-read-proxy in 44.0s
  1173. 66.10 s Progress: 12 of 12 built
  1174. 66.10 s /nix/store/lz6qq96n9lyn7drjxhzfikfwfc2cd61v-vm-test-run-nixos-test-read-proxy
  1175. 66.21 s Build succeeded.
Tail Raw Logs