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.go-unit-tests --print-build-logs
  2. 1.03 s
  3. 1.80 s Downloading cached postgresql-18.4-doc from https://cache.staging.nix-ci.com
  4. 1.80 s Downloading cached niks3-tests from https://cache.staging.nix-ci.com
  5. 1.80 s Downloading cached brotli-1.2.0-dev from https://cache.staging.nix-ci.com
  6. 1.80 s Downloading cached libpsl-0.21.5-dev from https://cache.staging.nix-ci.com
  7. 1.80 s Downloading cached libssh2-1.11.1-dev from https://cache.staging.nix-ci.com
  8. 1.80 s Downloading cached nghttp3-1.16.0-dev from https://cache.staging.nix-ci.com
  9. 1.80 s Downloading cached ngtcp2-1.23.0-dev from https://cache.staging.nix-ci.com
  10. 1.80 s Downloading cached nix-perl from https://cache.staging.nix-ci.com
  11. 1.80 s Downloading cached numactl-2.0.18-dev from https://cache.staging.nix-ci.com
  12. 1.80 s Downloading cached boehm-gc-8.2.12-dev from https://cache.staging.nix-ci.com
  13. 1.80 s Downloading cached boost-1.89.0-dev from https://cache.staging.nix-ci.com
  14. 1.80 s Downloading cached c-ares from https://cache.staging.nix-ci.com
  15. 1.80 s Downloading cached libidn2-2.3.8-bin from https://cache.staging.nix-ci.com
  16. 1.80 s Downloading cached liburing-2.14-bin from https://cache.staging.nix-ci.com
  17. 1.80 s Downloading cached nix-util-c from https://cache.staging.nix-ci.com
  18. 1.80 s Downloading cached acl-2.3.2-dev from https://cache.staging.nix-ci.com
  19. 1.89 s Downloaded cached libssh2-1.11.1-dev (83 KiB) in 87ms
  20. 1.90 s Progress: 0 of 4 built, 1 of 44 downloaded from cache (15 downloading)
  21. 1.90 s Downloaded cached brotli-1.2.0-dev (57 KiB) in 98ms
  22. 1.90 s Downloading cached attr-2.5.2-dev from https://cache.staging.nix-ci.com
  23. 1.90 s Progress: 0 of 4 built, 2 of 44 downloaded from cache (15 downloading)
  24. 1.90 s Downloading cached libev from https://cache.staging.nix-ci.com
  25. 1.90 s Downloaded cached ngtcp2-1.23.0-dev (302 KiB) in 100ms
  26. 1.90 s Progress: 0 of 4 built, 3 of 44 downloaded from cache (15 downloading)
  27. 1.94 s Downloaded cached libpsl-0.21.5-dev (7800 B) in 140ms
  28. 1.94 s Downloaded cached numactl-2.0.18-dev (19 KiB) in 140ms
  29. 1.94 s Progress: 0 of 4 built, 4 of 44 downloaded from cache (14 downloading)
  30. 1.94 s Progress: 0 of 4 built, 5 of 44 downloaded from cache (13 downloading)
  31. 1.94 s Downloaded cached nix-util-c (106 KiB) in 140ms
  32. 1.94 s Progress: 0 of 4 built, 6 of 44 downloaded from cache (12 downloading)
  33. 1.94 s Downloading cached nix-fetchers-c from https://cache.staging.nix-ci.com
  34. 1.94 s Downloading cached nix-main-c from https://cache.staging.nix-ci.com
  35. 1.94 s Downloading cached nix-store-c from https://cache.staging.nix-ci.com
  36. 2.01 s Downloaded cached libidn2-2.3.8-bin (37 KiB) in 204ms
  37. 2.01 s Progress: 0 of 4 built, 7 of 44 downloaded from cache (14 downloading)
  38. 2.01 s Downloading cached libidn2-2.3.8-dev from https://cache.staging.nix-ci.com
  39. 2.01 s Downloaded cached acl-2.3.2-dev (8624 B) in 204ms
  40. 2.01 s Progress: 0 of 4 built, 8 of 44 downloaded from cache (14 downloading)
  41. 2.03 s Downloaded cached nghttp3-1.16.0-dev (123 KiB) in 228ms
  42. 2.03 s Downloaded cached nix-perl (211 KiB) in 229ms
  43. 2.04 s Progress: 0 of 4 built, 9 of 44 downloaded from cache (13 downloading)
  44. 2.04 s Downloaded cached postgresql-18.4-doc (16.5 MiB) in 241ms
  45. 2.04 s Progress: 0 of 4 built, 10 of 44 downloaded from cache (12 downloading)
  46. 2.04 s Progress: 0 of 4 built, 11 of 44 downloaded from cache (11 downloading)
  47. 2.04 s Downloaded cached boehm-gc-8.2.12-dev (256 KiB) in 240ms
  48. 2.04 s Progress: 0 of 4 built, 12 of 44 downloaded from cache (10 downloading)
  49. 2.04 s Downloaded cached liburing-2.14-bin (640 KiB) in 240ms
  50. 2.04 s Progress: 0 of 4 built, 13 of 44 downloaded from cache (9 downloading)
  51. 2.04 s Downloading cached liburing-2.14-dev from https://cache.staging.nix-ci.com
  52. 2.04 s Downloaded cached attr-2.5.2-dev (13 KiB) in 143ms
  53. 2.04 s Progress: 0 of 4 built, 14 of 44 downloaded from cache (9 downloading)
  54. 2.04 s Downloading cached libarchive-3.8.8-dev from https://cache.staging.nix-ci.com
  55. 2.05 s Downloaded cached nix-fetchers-c (66 KiB) in 103ms
  56. 2.05 s Progress: 0 of 4 built, 15 of 44 downloaded from cache (9 downloading)
  57. 2.05 s Downloaded cached nix-main-c (16 KiB) in 103ms
  58. 2.05 s Progress: 0 of 4 built, 16 of 44 downloaded from cache (8 downloading)
  59. 2.05 s Downloaded cached libev (225 KiB) in 146ms
  60. 2.05 s Progress: 0 of 4 built, 17 of 44 downloaded from cache (7 downloading)
  61. 2.05 s Downloaded cached c-ares (276 KiB) in 245ms
  62. 2.05 s Progress: 0 of 4 built, 18 of 44 downloaded from cache (6 downloading)
  63. 2.05 s Downloading cached nghttp2 from https://cache.staging.nix-ci.com
  64. 2.09 s Downloaded cached libidn2-2.3.8-dev (15 KiB) in 82ms
  65. 2.09 s Progress: 0 of 4 built, 19 of 44 downloaded from cache (6 downloading)
  66. 2.10 s Downloaded cached libarchive-3.8.8-dev (91 KiB) in 52ms
  67. 2.10 s Progress: 0 of 4 built, 20 of 44 downloaded from cache (5 downloading)
  68. 2.10 s Downloaded cached liburing-2.14-dev (95 KiB) in 53ms
  69. 2.10 s Progress: 0 of 4 built, 21 of 44 downloaded from cache (4 downloading)
  70. 2.15 s Downloaded cached nghttp2 (2.6 MiB) in 96ms
  71. 2.15 s Progress: 0 of 4 built, 22 of 44 downloaded from cache (3 downloading)
  72. 2.15 s Downloading cached nghttp2-1.69.0-dev from https://cache.staging.nix-ci.com
  73. 2.21 s Downloaded cached nghttp2-1.69.0-dev (241 KiB) in 66ms
  74. 2.21 s Progress: 0 of 4 built, 23 of 44 downloaded from cache (3 downloading)
  75. 2.21 s Downloading cached curl-8.21.0-dev from https://cache.staging.nix-ci.com
  76. 2.24 s Downloaded cached curl-8.21.0-dev (275 KiB) in 31ms
  77. 2.24 s Progress: 0 of 4 built, 24 of 44 downloaded from cache (3 downloading)
  78. 2.24 s Downloading cached postgresql-18.4-dev from https://cache.staging.nix-ci.com
  79. 2.31 s Downloaded cached nix-store-c (246 KiB) in 365ms
  80. 2.31 s Progress: 0 of 4 built, 25 of 44 downloaded from cache (3 downloading)
  81. 2.32 s Downloading cached nix-expr-c from https://cache.staging.nix-ci.com
  82. 2.49 s Downloaded cached niks3-tests (48.1 MiB) in 684ms
  83. 2.49 s Progress: 0 of 4 built, 26 of 44 downloaded from cache (3 downloading)
  84. 2.67 s Downloaded cached nix-expr-c (402 KiB) in 346ms
  85. 2.67 s Progress: 0 of 3 built, 27 of 44 downloaded from cache (2 downloading)
  86. 2.68 s Downloading cached nix-flake-c from https://cache.staging.nix-ci.com
  87. 2.70 s Downloaded cached nix-flake-c (146 KiB) in 22ms
  88. 2.70 s Progress: 0 of 3 built, 28 of 44 downloaded from cache (2 downloading)
  89. 2.75 s Downloaded cached postgresql-18.4-dev (11.4 MiB) in 504ms
  90. 2.75 s Progress: 0 of 3 built, 29 of 44 downloaded from cache (1 downloading)
  91. 3.08 s Downloaded cached boost-1.89.0-dev (147.1 MiB) in 1.2s
  92. 3.08 s Progress: 0 of 2 built, 30 of 44 downloaded from cache
  93. 3.08 s Downloading cached nix-util-2.34.8-dev from https://cache.staging.nix-ci.com
  94. 3.12 s Downloaded cached nix-util-2.34.8-dev (342 KiB) in 36ms
  95. 3.12 s Progress: 0 of 2 built, 31 of 44 downloaded from cache
  96. 3.12 s Downloading cached nix-store-2.34.8-dev from https://cache.staging.nix-ci.com
  97. 3.12 s Downloading cached nix-util-c-2.34.8-dev from https://cache.staging.nix-ci.com
  98. 3.15 s Downloaded cached nix-store-2.34.8-dev (425 KiB) in 33ms
  99. 3.15 s Progress: 0 of 2 built, 32 of 44 downloaded from cache (1 downloading)
  100. 3.15 s Downloaded cached nix-util-c-2.34.8-dev (15 KiB) in 34ms
  101. 3.15 s Progress: 0 of 2 built, 33 of 44 downloaded from cache (1 downloading)
  102. 3.15 s Downloading cached nix-store-c-2.34.8-dev from https://cache.staging.nix-ci.com
  103. 3.17 s Downloading cached nix-fetchers-2.34.8-dev from https://cache.staging.nix-ci.com
  104. 3.18 s Downloaded cached nix-store-c-2.34.8-dev (17 KiB) in 29ms
  105. 3.18 s Progress: 0 of 2 built, 34 of 44 downloaded from cache (1 downloading)
  106. 3.20 s Downloaded cached nix-fetchers-2.34.8-dev (34 KiB) in 32ms
  107. 3.20 s Progress: 0 of 2 built, 35 of 44 downloaded from cache
  108. 3.20 s Downloading cached nix-expr-2.34.8-dev from https://cache.staging.nix-ci.com
  109. 3.24 s Downloaded cached nix-expr-2.34.8-dev (739 KiB) in 32ms
  110. 3.24 s Progress: 0 of 2 built, 36 of 44 downloaded from cache
  111. 3.24 s Downloading cached nix-expr-c-2.34.8-dev from https://cache.staging.nix-ci.com
  112. 3.24 s Downloading cached nix-main-2.34.8-dev from https://cache.staging.nix-ci.com
  113. 3.25 s Downloading cached nix-flake-2.34.8-dev from https://cache.staging.nix-ci.com
  114. 3.27 s Downloaded cached nix-expr-c-2.34.8-dev (50 KiB) in 29ms
  115. 3.27 s Progress: 0 of 2 built, 37 of 44 downloaded from cache (2 downloading)
  116. 3.27 s Downloading cached nix-fetchers-c-2.34.8-dev from https://cache.staging.nix-ci.com
  117. 3.27 s Downloaded cached nix-main-2.34.8-dev (10 KiB) in 31ms
  118. 3.27 s Progress: 0 of 2 built, 38 of 44 downloaded from cache (2 downloading)
  119. 3.27 s Downloading cached nix-main-c-2.34.8-dev from https://cache.staging.nix-ci.com
  120. 3.29 s Downloaded cached nix-flake-2.34.8-dev (19 KiB) in 39ms
  121. 3.29 s Progress: 0 of 2 built, 39 of 44 downloaded from cache (2 downloading)
  122. 3.29 s Downloading cached nix-cmd-2.34.8-dev from https://cache.staging.nix-ci.com
  123. 3.29 s Downloaded cached nix-fetchers-c-2.34.8-dev (3264 B) in 27ms
  124. 3.29 s Progress: 0 of 2 built, 40 of 44 downloaded from cache (2 downloading)
  125. 3.29 s Downloading cached nix-flake-c-2.34.8-dev from https://cache.staging.nix-ci.com
  126. 3.32 s Downloaded cached nix-cmd-2.34.8-dev (44 KiB) in 29ms
  127. 3.32 s Progress: 0 of 2 built, 41 of 44 downloaded from cache (2 downloading)
  128. 3.33 s Downloaded cached nix-flake-c-2.34.8-dev (11 KiB) in 32ms
  129. 3.33 s Progress: 0 of 2 built, 42 of 44 downloaded from cache (1 downloading)
  130. 3.39 s Downloaded cached nix-main-c-2.34.8-dev (3136 B) in 117ms
  131. 3.39 s Progress: 0 of 2 built, 43 of 44 downloaded from cache
  132. 3.39 s Downloading cached nix-2.34.8-dev from https://cache.staging.nix-ci.com
  133. 3.43 s Downloaded cached nix-2.34.8-dev (91 KiB) in 39ms
  134. 3.43 s Progress: 0 of 2 built, 44 of 44 downloaded from cache
  135. 3.53 s Building /nix/store/jp6kjx0b861i6k6x72m47d2sbq7x6jh3-niks3-go-unit-tests.drv
  136. 3.63 s [niks3-go-unit-tests] Running client tests...
  137. 3.63 s [niks3-go-unit-tests] === RUN TestDoServerRequestAttachesToken
  138. 3.63 s [niks3-go-unit-tests] === PAUSE TestDoServerRequestAttachesToken
  139. 3.63 s [niks3-go-unit-tests] === RUN TestCaseHackSuffix
  140. 3.63 s [niks3-go-unit-tests] === PAUSE TestCaseHackSuffix
  141. 3.63 s [niks3-go-unit-tests] === RUN TestPartSizeForNAR
  142. 3.63 s [niks3-go-unit-tests] === PAUSE TestPartSizeForNAR
  143. 3.63 s [niks3-go-unit-tests] === RUN TestUploadMultipart_SupersededByPeer
  144. 3.63 s [niks3-go-unit-tests] === PAUSE TestUploadMultipart_SupersededByPeer
  145. 3.63 s [niks3-go-unit-tests] === RUN TestDumpPathMatchesNix
  146. 3.63 s [niks3-go-unit-tests] === PAUSE TestDumpPathMatchesNix
  147. 3.63 s [niks3-go-unit-tests] === RUN TestDumpPathSingleFile
  148. 3.63 s [niks3-go-unit-tests] === PAUSE TestDumpPathSingleFile
  149. 3.63 s [niks3-go-unit-tests] === RUN TestDumpPathWriterError
  150. 3.63 s [niks3-go-unit-tests] === PAUSE TestDumpPathWriterError
  151. 3.63 s [niks3-go-unit-tests] === RUN TestEncodeNixBase32
  152. 3.63 s [niks3-go-unit-tests] === PAUSE TestEncodeNixBase32
  153. 3.63 s [niks3-go-unit-tests] === RUN TestEncodeNixBase32WithRealHash
  154. 3.63 s [niks3-go-unit-tests] === PAUSE TestEncodeNixBase32WithRealHash
  155. 3.63 s [niks3-go-unit-tests] === RUN TestConvertHashToNix32
  156. 3.63 s [niks3-go-unit-tests] === PAUSE TestConvertHashToNix32
  157. 3.63 s [niks3-go-unit-tests] === RUN TestGetStorePathHash
  158. 3.63 s [niks3-go-unit-tests] === PAUSE TestGetStorePathHash
  159. 3.63 s [niks3-go-unit-tests] === RUN TestPathInfoHashCompatibility
  160. 3.63 s [niks3-go-unit-tests] === PAUSE TestPathInfoHashCompatibility
  161. 3.63 s [niks3-go-unit-tests] === RUN TestParsePathInfoJSON
  162. 3.63 s [niks3-go-unit-tests] === PAUSE TestParsePathInfoJSON
  163. 3.63 s [niks3-go-unit-tests] === RUN TestParsePathInfoJSONMultiplePaths
  164. 3.63 s [niks3-go-unit-tests] === PAUSE TestParsePathInfoJSONMultiplePaths
  165. 3.63 s [niks3-go-unit-tests] === RUN TestPathInfoCACompatibility
  166. 3.64 s [niks3-go-unit-tests] === PAUSE TestPathInfoCACompatibility
  167. 3.64 s [niks3-go-unit-tests] === RUN TestRateLimiterFeedback
  168. 3.64 s [niks3-go-unit-tests] === PAUSE TestRateLimiterFeedback
  169. 3.64 s [niks3-go-unit-tests] === RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess
  170. 3.64 s [niks3-go-unit-tests] === PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess
  171. 3.64 s [niks3-go-unit-tests] === RUN TestResolveStorePath
  172. 3.64 s [niks3-go-unit-tests] === PAUSE TestResolveStorePath
  173. 3.64 s [niks3-go-unit-tests] === RUN TestDoWithRetry_BodyReplayedViaGetBody
  174. 3.64 s [niks3-go-unit-tests] === PAUSE TestDoWithRetry_BodyReplayedViaGetBody
  175. 3.64 s [niks3-go-unit-tests] === RUN TestShellSplit
  176. 3.64 s [niks3-go-unit-tests] === PAUSE TestShellSplit
  177. 3.64 s [niks3-go-unit-tests] === RUN TestShellSplitErrors
  178. 3.64 s [niks3-go-unit-tests] === PAUSE TestShellSplitErrors
  179. 3.64 s [niks3-go-unit-tests] === RUN TestSetClientTLS
  180. 3.64 s [niks3-go-unit-tests] === PAUSE TestSetClientTLS
  181. 3.64 s [niks3-go-unit-tests] === RUN TestSetClientTLSDoesNotMutateDefaultTransport
  182. 3.64 s [niks3-go-unit-tests] === PAUSE TestSetClientTLSDoesNotMutateDefaultTransport
  183. 3.64 s [niks3-go-unit-tests] === RUN TestSetClientTLSErrors
  184. 3.64 s [niks3-go-unit-tests] === PAUSE TestSetClientTLSErrors
  185. 3.64 s [niks3-go-unit-tests] === RUN TestStaticToken
  186. 3.64 s [niks3-go-unit-tests] === PAUSE TestStaticToken
  187. 3.64 s [niks3-go-unit-tests] === RUN TestFileTokenReadsAndCaches
  188. 3.64 s [niks3-go-unit-tests] === PAUSE TestFileTokenReadsAndCaches
  189. 3.64 s [niks3-go-unit-tests] === RUN TestFileTokenMissing
  190. 3.64 s [niks3-go-unit-tests] === PAUSE TestFileTokenMissing
  191. 3.64 s [niks3-go-unit-tests] === RUN TestFileTokenEmpty
  192. 3.64 s [niks3-go-unit-tests] === PAUSE TestFileTokenEmpty
  193. 3.64 s [niks3-go-unit-tests] === RUN TestScriptTokenNoExpiryRerunsEveryCall
  194. 3.64 s [niks3-go-unit-tests] === PAUSE TestScriptTokenNoExpiryRerunsEveryCall
  195. 3.64 s [niks3-go-unit-tests] === RUN TestScriptTokenCachesUntilRefresh
  196. 3.64 s [niks3-go-unit-tests] === PAUSE TestScriptTokenCachesUntilRefresh
  197. 3.64 s [niks3-go-unit-tests] === RUN TestScriptTokenEmptyToken
  198. 3.64 s [niks3-go-unit-tests] === PAUSE TestScriptTokenEmptyToken
  199. 3.64 s [niks3-go-unit-tests] === RUN TestScriptTokenBadJSON
  200. 3.64 s [niks3-go-unit-tests] === PAUSE TestScriptTokenBadJSON
  201. 3.64 s [niks3-go-unit-tests] === RUN TestScriptTokenScriptFails
  202. 3.64 s [niks3-go-unit-tests] === PAUSE TestScriptTokenScriptFails
  203. 3.64 s [niks3-go-unit-tests] === RUN TestScriptTokenEmptyCommand
  204. 3.64 s [niks3-go-unit-tests] === PAUSE TestScriptTokenEmptyCommand
  205. 3.64 s [niks3-go-unit-tests] === CONT TestDoServerRequestAttachesToken
  206. 3.64 s [niks3-go-unit-tests] === CONT TestConvertHashToNix32
  207. 3.64 s [niks3-go-unit-tests] === CONT TestResolveStorePath
  208. 3.64 s [niks3-go-unit-tests] === RUN TestConvertHashToNix32/SRI_format_to_Nix32
  209. 3.64 s [niks3-go-unit-tests] === PAUSE TestConvertHashToNix32/SRI_format_to_Nix32
  210. 3.64 s [niks3-go-unit-tests] === RUN TestConvertHashToNix32/already_Nix32_format
  211. 3.64 s [niks3-go-unit-tests] === PAUSE TestConvertHashToNix32/already_Nix32_format
  212. 3.64 s [niks3-go-unit-tests] === CONT TestParsePathInfoJSON
  213. 3.64 s [niks3-go-unit-tests] === RUN TestParsePathInfoJSON/Nix_format
  214. 3.64 s [niks3-go-unit-tests] === PAUSE TestParsePathInfoJSON/Nix_format
  215. 3.64 s [niks3-go-unit-tests] === RUN TestParsePathInfoJSON/Lix_format
  216. 3.64 s [niks3-go-unit-tests] === PAUSE TestParsePathInfoJSON/Lix_format
  217. 3.64 s [niks3-go-unit-tests] === RUN TestParsePathInfoJSON/empty_input
  218. 3.64 s [niks3-go-unit-tests] === PAUSE TestParsePathInfoJSON/empty_input
  219. 3.64 s [niks3-go-unit-tests] === CONT TestPathInfoHashCompatibility
  220. 3.64 s [niks3-go-unit-tests] === RUN TestParsePathInfoJSON/whitespace_only
  221. 3.64 s [niks3-go-unit-tests] === RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)
  222. 3.64 s [niks3-go-unit-tests] === PAUSE TestParsePathInfoJSON/whitespace_only
  223. 3.64 s [niks3-go-unit-tests] === RUN TestParsePathInfoJSON/invalid_JSON
  224. 3.64 s [niks3-go-unit-tests] === PAUSE TestParsePathInfoJSON/invalid_JSON
  225. 3.64 s [niks3-go-unit-tests] === PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)
  226. 3.64 s [niks3-go-unit-tests] === RUN TestPathInfoHashCompatibility/old_string_format_with_colon
  227. 3.64 s [niks3-go-unit-tests] === CONT TestDumpPathSingleFile
  228. 3.64 s [niks3-go-unit-tests] === PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon
  229. 3.64 s [niks3-go-unit-tests] === RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI
  230. 3.64 s [niks3-go-unit-tests] === PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI
  231. 3.64 s [niks3-go-unit-tests] === RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512
  232. 3.64 s [niks3-go-unit-tests] === PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512
  233. 3.64 s [niks3-go-unit-tests] === CONT TestScriptTokenEmptyCommand
  234. 3.64 s [niks3-go-unit-tests] === CONT TestEncodeNixBase32
  235. 3.64 s [niks3-go-unit-tests] === RUN TestEncodeNixBase32/test_string_hash
  236. 3.64 s [niks3-go-unit-tests] === CONT TestDumpPathWriterError
  237. 3.64 s [niks3-go-unit-tests] === PAUSE TestEncodeNixBase32/test_string_hash
  238. 3.64 s [niks3-go-unit-tests] === RUN TestEncodeNixBase32/empty_input
  239. 3.64 s [niks3-go-unit-tests] === PAUSE TestEncodeNixBase32/empty_input
  240. 3.64 s [niks3-go-unit-tests] === CONT TestScriptTokenBadJSON
  241. 3.64 s [niks3-go-unit-tests] === CONT TestScriptTokenEmptyToken
  242. 3.64 s [niks3-go-unit-tests] === CONT TestScriptTokenCachesUntilRefresh
  243. 3.64 s [niks3-go-unit-tests] === CONT TestScriptTokenNoExpiryRerunsEveryCall
  244. 3.64 s [niks3-go-unit-tests] === CONT TestDumpPathMatchesNix
  245. 3.64 s [niks3-go-unit-tests] === CONT TestFileTokenEmpty
  246. 3.64 s [niks3-go-unit-tests] === CONT TestPartSizeForNAR
  247. 3.64 s [niks3-go-unit-tests] === RUN TestConvertHashToNix32/invalid_format
  248. 3.64 s [niks3-go-unit-tests] === PAUSE TestConvertHashToNix32/invalid_format
  249. 3.64 s [niks3-go-unit-tests] === CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess
  250. 3.64 s [niks3-go-unit-tests] === CONT TestCaseHackSuffix
  251. 3.64 s [niks3-go-unit-tests] 2026/07/19 09:28:41 WARN Rate limiter enabled after throttle name=server-test rate=5
  252. 3.64 s [niks3-go-unit-tests] === CONT TestRateLimiterFeedback
  253. 3.64 s [niks3-go-unit-tests] === RUN TestRateLimiterFeedback/429_enables_limiter
  254. 3.64 s [niks3-go-unit-tests] === PAUSE TestRateLimiterFeedback/429_enables_limiter
  255. 3.64 s [niks3-go-unit-tests] === RUN TestRateLimiterFeedback/503_enables_limiter
  256. 3.64 s [niks3-go-unit-tests] === PAUSE TestRateLimiterFeedback/503_enables_limiter
  257. 3.64 s [niks3-go-unit-tests] === RUN TestRateLimiterFeedback/200_does_not_enable_limiter
  258. 3.64 s [niks3-go-unit-tests] === PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter
  259. 3.64 s [niks3-go-unit-tests] === RUN TestRateLimiterFeedback/400_does_not_enable_limiter
  260. 3.64 s [niks3-go-unit-tests] === PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter
  261. 3.64 s [niks3-go-unit-tests] === CONT TestGetStorePathHash
  262. 3.64 s [niks3-go-unit-tests] === RUN TestGetStorePathHash/valid_store_path
  263. 3.64 s [niks3-go-unit-tests] === CONT TestFileTokenMissing
  264. 3.64 s [niks3-go-unit-tests] --- PASS: TestResolveStorePath (0.00s)
  265. 3.64 s [niks3-go-unit-tests] --- PASS: TestScriptTokenEmptyCommand (0.00s)
  266. 3.64 s [niks3-go-unit-tests] --- PASS: TestDoServerRequestAttachesToken (0.00s)
  267. 3.64 s [niks3-go-unit-tests] --- PASS: TestFileTokenEmpty (0.00s)
  268. 3.64 s [niks3-go-unit-tests] === CONT TestEncodeNixBase32WithRealHash
  269. 3.64 s [niks3-go-unit-tests] === CONT TestSetClientTLSDoesNotMutateDefaultTransport
  270. 3.64 s [niks3-go-unit-tests] === CONT TestScriptTokenScriptFails
  271. 3.64 s [niks3-go-unit-tests] === CONT TestFileTokenReadsAndCaches
  272. 3.65 s [niks3-go-unit-tests] === CONT TestUploadMultipart_SupersededByPeer
  273. 3.65 s [niks3-go-unit-tests] === RUN TestUploadMultipart_SupersededByPeer/exists
  274. 3.65 s [niks3-go-unit-tests] === PAUSE TestUploadMultipart_SupersededByPeer/exists
  275. 3.65 s [niks3-go-unit-tests] === RUN TestPartSizeForNAR/zero_stays_at_minimum
  276. 3.65 s [niks3-go-unit-tests] === CONT TestPathInfoCACompatibility
  277. 3.65 s [niks3-go-unit-tests] === PAUSE TestGetStorePathHash/valid_store_path
  278. 3.65 s [niks3-go-unit-tests] --- PASS: TestScriptTokenBadJSON (0.00s)
  279. 3.65 s [niks3-go-unit-tests] --- PASS: TestScriptTokenEmptyToken (0.00s)
  280. 3.65 s [niks3-go-unit-tests] --- PASS: TestEncodeNixBase32WithRealHash (0.00s)
  281. 3.65 s [niks3-go-unit-tests] --- PASS: TestScriptTokenCachesUntilRefresh (0.01s)
  282. 3.65 s [niks3-go-unit-tests] === RUN TestUploadMultipart_SupersededByPeer/missing
  283. 3.65 s [niks3-go-unit-tests] --- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)
  284. 3.65 s [niks3-go-unit-tests] --- PASS: TestFileTokenReadsAndCaches (0.00s)
  285. 3.65 s [niks3-go-unit-tests] --- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)
  286. 3.65 s [niks3-go-unit-tests] === CONT TestShellSplitErrors
  287. 3.65 s [niks3-go-unit-tests] --- PASS: TestShellSplitErrors (0.00s)
  288. 3.65 s [niks3-go-unit-tests] === PAUSE TestUploadMultipart_SupersededByPeer/missing
  289. 3.65 s [niks3-go-unit-tests] === PAUSE TestPartSizeForNAR/zero_stays_at_minimum
  290. 3.65 s [niks3-go-unit-tests] --- PASS: TestFileTokenMissing (0.00s)
  291. 3.65 s [niks3-go-unit-tests] === RUN TestPartSizeForNAR/small_stays_at_minimum
  292. 3.65 s [niks3-go-unit-tests] === CONT TestShellSplit
  293. 3.65 s [niks3-go-unit-tests] === PAUSE TestPartSizeForNAR/small_stays_at_minimum
  294. 3.65 s [niks3-go-unit-tests] === RUN TestGetStorePathHash/basename_without_hyphen_should_error
  295. 3.65 s [niks3-go-unit-tests] === CONT TestDoWithRetry_BodyReplayedViaGetBody
  296. 3.65 s [niks3-go-unit-tests] === PAUSE TestGetStorePathHash/basename_without_hyphen_should_error
  297. 3.65 s [niks3-go-unit-tests] === RUN TestGetStorePathHash/hash_with_invalid_characters_should_error
  298. 3.65 s [niks3-go-unit-tests] === PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error
  299. 3.65 s [niks3-go-unit-tests] === RUN TestGetStorePathHash/hash_with_wrong_length_should_error
  300. 3.65 s [niks3-go-unit-tests] === PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error
  301. 3.65 s [niks3-go-unit-tests] === CONT TestParsePathInfoJSON/Nix_format
  302. 3.65 s [niks3-go-unit-tests] === RUN TestPathInfoCACompatibility/null_ca_field
  303. 3.65 s [niks3-go-unit-tests] === PAUSE TestPathInfoCACompatibility/null_ca_field
  304. 3.65 s [niks3-go-unit-tests] === RUN TestPathInfoCACompatibility/old_string_format_-_text
  305. 3.65 s [niks3-go-unit-tests] === PAUSE TestPathInfoCACompatibility/old_string_format_-_text
  306. 3.65 s [niks3-go-unit-tests] === RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive
  307. 3.65 s [niks3-go-unit-tests] === PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive
  308. 3.65 s [niks3-go-unit-tests] === CONT TestSetClientTLSErrors
  309. 3.65 s [niks3-go-unit-tests] === CONT TestSetClientTLS
  310. 3.65 s [niks3-go-unit-tests] === CONT TestParsePathInfoJSON/whitespace_only
  311. 3.65 s [niks3-go-unit-tests] === CONT TestStaticToken
  312. 3.65 s [niks3-go-unit-tests] === CONT TestParsePathInfoJSON/empty_input
  313. 3.65 s [niks3-go-unit-tests] === CONT TestParsePathInfoJSON/Lix_format
  314. 3.65 s [niks3-go-unit-tests] === CONT TestParsePathInfoJSON/invalid_JSON
  315. 3.65 s [niks3-go-unit-tests] === CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)
  316. 3.65 s [niks3-go-unit-tests] === CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512
  317. 3.65 s [niks3-go-unit-tests] === CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI
  318. 3.65 s [niks3-go-unit-tests] === CONT TestPathInfoHashCompatibility/old_string_format_with_colon
  319. 3.65 s [niks3-go-unit-tests] === CONT TestEncodeNixBase32/test_string_hash
  320. 3.65 s [niks3-go-unit-tests] === CONT TestConvertHashToNix32/SRI_format_to_Nix32
  321. 3.65 s [niks3-go-unit-tests] === RUN TestPartSizeForNAR/80_GiB_fits_at_minimum
  322. 3.65 s [niks3-go-unit-tests] === PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum
  323. 3.65 s [niks3-go-unit-tests] === CONT TestRateLimiterFeedback/429_enables_limiter
  324. 3.65 s [niks3-go-unit-tests] === RUN TestPartSizeForNAR/115_GiB_needs_larger_parts
  325. 3.65 s [niks3-go-unit-tests] === PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts
  326. 3.65 s [niks3-go-unit-tests] === RUN TestPartSizeForNAR/1_TiB
  327. 3.65 s [niks3-go-unit-tests] === PAUSE TestPartSizeForNAR/1_TiB
  328. 3.65 s [niks3-go-unit-tests] === RUN TestPartSizeForNAR/5_TiB_S3_max_object
  329. 3.65 s [niks3-go-unit-tests] === PAUSE TestPartSizeForNAR/5_TiB_S3_max_object
  330. 3.65 s [niks3-go-unit-tests] === RUN TestPartSizeForNAR/capped_at_5_GiB
  331. 3.65 s [niks3-go-unit-tests] === PAUSE TestPartSizeForNAR/capped_at_5_GiB
  332. 3.65 s [niks3-go-unit-tests] === RUN TestPathInfoCACompatibility/new_structured_format_-_text
  333. 3.65 s [niks3-go-unit-tests] === PAUSE TestPathInfoCACompatibility/new_structured_format_-_text
  334. 3.65 s [niks3-go-unit-tests] === RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method
  335. 3.65 s [niks3-go-unit-tests] === PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method
  336. 3.65 s [niks3-go-unit-tests] --- PASS: TestShellSplit (0.00s)
  337. 3.65 s [niks3-go-unit-tests] === CONT TestEncodeNixBase32/empty_input
  338. 3.65 s [niks3-go-unit-tests] === CONT TestRateLimiterFeedback/400_does_not_enable_limiter
  339. 3.65 s [niks3-go-unit-tests] === RUN TestSetClientTLSErrors/missing_cert_file
  340. 3.65 s [niks3-go-unit-tests] === PAUSE TestSetClientTLSErrors/missing_cert_file
  341. 3.65 s [niks3-go-unit-tests] === RUN TestSetClientTLSErrors/missing_key_file
  342. 3.65 s [niks3-go-unit-tests] === PAUSE TestSetClientTLSErrors/missing_key_file
  343. 3.65 s [niks3-go-unit-tests] === RUN TestSetClientTLSErrors/missing_ca_file
  344. 3.65 s [niks3-go-unit-tests] === PAUSE TestSetClientTLSErrors/missing_ca_file
  345. 3.65 s [niks3-go-unit-tests] --- PASS: TestStaticToken (0.00s)
  346. 3.65 s [niks3-go-unit-tests] --- PASS: TestParsePathInfoJSON (0.00s)
  347. 3.65 s [niks3-go-unit-tests] --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)
  348. 3.65 s [niks3-go-unit-tests] --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)
  349. 3.65 s [niks3-go-unit-tests] --- PASS: TestParsePathInfoJSON/empty_input (0.00s)
  350. 3.65 s [niks3-go-unit-tests] --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)
  351. 3.65 s [niks3-go-unit-tests] --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)
  352. 3.65 s [niks3-go-unit-tests] === CONT TestConvertHashToNix32/invalid_format
  353. 3.65 s [niks3-go-unit-tests] === CONT TestRateLimiterFeedback/503_enables_limiter
  354. 3.65 s [niks3-go-unit-tests] === RUN TestSetClientTLSErrors/invalid_ca_file
  355. 3.65 s [niks3-go-unit-tests] === PAUSE TestSetClientTLSErrors/invalid_ca_file
  356. 3.65 s [niks3-go-unit-tests] --- PASS: TestPathInfoHashCompatibility (0.00s)
  357. 3.65 s [niks3-go-unit-tests] --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)
  358. 3.65 s [niks3-go-unit-tests] --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)
  359. 3.65 s [niks3-go-unit-tests] --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)
  360. 3.65 s [niks3-go-unit-tests] --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)
  361. 3.65 s [niks3-go-unit-tests] === CONT TestRateLimiterFeedback/200_does_not_enable_limiter
  362. 3.65 s [niks3-go-unit-tests] === CONT TestParsePathInfoJSONMultiplePaths
  363. 3.65 s [niks3-go-unit-tests] === RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths
  364. 3.65 s [niks3-go-unit-tests] === CONT TestUploadMultipart_SupersededByPeer/exists
  365. 3.65 s [niks3-go-unit-tests] === PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths
  366. 3.65 s [niks3-go-unit-tests] --- PASS: TestEncodeNixBase32 (0.00s)
  367. 3.65 s [niks3-go-unit-tests] --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)
  368. 3.65 s [niks3-go-unit-tests] --- PASS: TestEncodeNixBase32/empty_input (0.00s)
  369. 3.65 s [niks3-go-unit-tests] === CONT TestConvertHashToNix32/already_Nix32_format
  370. 3.65 s [niks3-go-unit-tests] --- PASS: TestScriptTokenScriptFails (0.01s)
  371. 3.65 s [niks3-go-unit-tests] === RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths
  372. 3.65 s [niks3-go-unit-tests] --- PASS: TestConvertHashToNix32 (0.00s)
  373. 3.65 s [niks3-go-unit-tests] --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)
  374. 3.65 s [niks3-go-unit-tests] --- PASS: TestConvertHashToNix32/invalid_format (0.00s)
  375. 3.65 s [niks3-go-unit-tests] --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)
  376. 3.65 s [niks3-go-unit-tests] 2026/07/19 09:28:41 WARN Rate limiter enabled after throttle name=server-test rate=5
  377. 3.65 s [niks3-go-unit-tests] 2026/07/19 09:28:41 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:36553
  378. 3.65 s [niks3-go-unit-tests] === RUN TestSetClientTLS/rejects_connection_without_client_cert
  379. 3.65 s [niks3-go-unit-tests] === CONT TestGetStorePathHash/valid_store_path
  380. 3.65 s [niks3-go-unit-tests] === CONT TestGetStorePathHash/hash_with_invalid_characters_should_error
  381. 3.65 s [niks3-go-unit-tests] === CONT TestGetStorePathHash/hash_with_wrong_length_should_error
  382. 3.65 s [niks3-go-unit-tests] === CONT TestUploadMultipart_SupersededByPeer/missing
  383. 3.65 s [niks3-go-unit-tests] 2026/07/19 09:28:41 WARN Rate limiter enabled after throttle name=server-test rate=5
  384. 3.65 s [niks3-go-unit-tests] 2026/07/19 09:28:41 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35917
  385. 3.65 s [niks3-go-unit-tests] 2026/07/19 09:28:41 WARN Rate limiter backed off name=server-test rate=5
  386. 3.65 s [niks3-go-unit-tests] 2026/07/19 09:28:41 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:35917
  387. 3.65 s [niks3-go-unit-tests] === PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths
  388. 3.65 s [niks3-go-unit-tests] === CONT TestPathInfoCACompatibility/null_ca_field
  389. 3.65 s [niks3-go-unit-tests] === CONT TestGetStorePathHash/basename_without_hyphen_should_error
  390. 3.65 s [niks3-go-unit-tests] --- PASS: TestGetStorePathHash (0.01s)
  391. 3.65 s [niks3-go-unit-tests] --- PASS: TestGetStorePathHash/valid_store_path (0.00s)
  392. 3.65 s [niks3-go-unit-tests] --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)
  393. 3.65 s [niks3-go-unit-tests] --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)
  394. 3.65 s [niks3-go-unit-tests] --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)
  395. 3.65 s [niks3-go-unit-tests] --- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)
  396. 3.65 s [niks3-go-unit-tests] === CONT TestPartSizeForNAR/capped_at_5_GiB
  397. 3.65 s [niks3-go-unit-tests] === CONT TestPartSizeForNAR/115_GiB_needs_larger_parts
  398. 3.65 s [niks3-go-unit-tests] === CONT TestPartSizeForNAR/80_GiB_fits_at_minimum
  399. 3.65 s [niks3-go-unit-tests] === CONT TestPartSizeForNAR/small_stays_at_minimum
  400. 3.65 s [niks3-go-unit-tests] === CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method
  401. 3.65 s [niks3-go-unit-tests] === CONT TestPathInfoCACompatibility/new_structured_format_-_text
  402. 3.65 s [niks3-go-unit-tests] === CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive
  403. 3.65 s [niks3-go-unit-tests] === CONT TestPathInfoCACompatibility/old_string_format_-_text
  404. 3.65 s [niks3-go-unit-tests] === PAUSE TestSetClientTLS/rejects_connection_without_client_cert
  405. 3.65 s [niks3-go-unit-tests] --- PASS: TestPathInfoCACompatibility (0.00s)
  406. 3.65 s [niks3-go-unit-tests] --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)
  407. 3.65 s [niks3-go-unit-tests] --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)
  408. 3.65 s [niks3-go-unit-tests] --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)
  409. 3.65 s [niks3-go-unit-tests] --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)
  410. 3.65 s [niks3-go-unit-tests] --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)
  411. 3.65 s [niks3-go-unit-tests] 2026/07/19 09:28:41 WARN Rate limiter backed off name=server-test rate=5
  412. 3.65 s [niks3-go-unit-tests] === CONT TestPartSizeForNAR/1_TiB
  413. 3.65 s [niks3-go-unit-tests] === CONT TestSetClientTLSErrors/invalid_ca_file
  414. 3.65 s [niks3-go-unit-tests] 2026/07/19 09:28:41 WARN Rate limiter enabled after throttle name=server-test rate=5
  415. 3.65 s [niks3-go-unit-tests] 2026/07/19 09:28:41 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:33717
  416. 3.65 s [niks3-go-unit-tests] === CONT TestPartSizeForNAR/5_TiB_S3_max_object
  417. 3.65 s [niks3-go-unit-tests] --- PASS: TestUploadMultipart_SupersededByPeer (0.00s)
  418. 3.65 s [niks3-go-unit-tests] --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)
  419. 3.65 s [niks3-go-unit-tests] --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)
  420. 3.65 s [niks3-go-unit-tests] === CONT TestPartSizeForNAR/zero_stays_at_minimum
  421. 3.65 s [niks3-go-unit-tests] === CONT TestSetClientTLSErrors/missing_ca_file
  422. 3.65 s [niks3-go-unit-tests] 2026/07/19 09:28:41 WARN Rate limiter backed off name=server-test rate=5
  423. 3.65 s [niks3-go-unit-tests] --- PASS: TestPartSizeForNAR (0.01s)
  424. 3.65 s [niks3-go-unit-tests] --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)
  425. 3.65 s [niks3-go-unit-tests] --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)
  426. 3.65 s [niks3-go-unit-tests] --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)
  427. 3.65 s [niks3-go-unit-tests] --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)
  428. 3.65 s [niks3-go-unit-tests] --- PASS: TestPartSizeForNAR/1_TiB (0.00s)
  429. 3.65 s [niks3-go-unit-tests] --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)
  430. 3.65 s [niks3-go-unit-tests] --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)
  431. 3.65 s [niks3-go-unit-tests] === CONT TestSetClientTLSErrors/missing_key_file
  432. 3.65 s [niks3-go-unit-tests] --- PASS: TestRateLimiterFeedback (0.00s)
  433. 3.65 s [niks3-go-unit-tests] --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)
  434. 3.65 s [niks3-go-unit-tests] --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)
  435. 3.65 s [niks3-go-unit-tests] --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)
  436. 3.65 s [niks3-go-unit-tests] --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)
  437. 3.65 s [niks3-go-unit-tests] === CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths
  438. 3.65 s [niks3-go-unit-tests] === RUN TestSetClientTLS/succeeds_with_client_cert_and_CA
  439. 3.65 s [niks3-go-unit-tests] === PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA
  440. 3.65 s [niks3-go-unit-tests] === RUN TestSetClientTLS/preserves_debug_logging_transport
  441. 3.65 s [niks3-go-unit-tests] === PAUSE TestSetClientTLS/preserves_debug_logging_transport
  442. 3.65 s [niks3-go-unit-tests] === CONT TestSetClientTLS/rejects_connection_without_client_cert
  443. 3.65 s [niks3-go-unit-tests] === CONT TestSetClientTLS/preserves_debug_logging_transport
  444. 3.66 s [niks3-go-unit-tests] === CONT TestSetClientTLS/succeeds_with_client_cert_and_CA
  445. 3.66 s [niks3-go-unit-tests] === CONT TestSetClientTLSErrors/missing_cert_file
  446. 3.66 s [niks3-go-unit-tests] === CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths
  447. 3.66 s [niks3-go-unit-tests] --- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)
  448. 3.66 s [niks3-go-unit-tests] --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)
  449. 3.66 s [niks3-go-unit-tests] --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)
  450. 3.66 s [niks3-go-unit-tests] --- PASS: TestSetClientTLSErrors (0.00s)
  451. 3.66 s [niks3-go-unit-tests] --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)
  452. 3.66 s [niks3-go-unit-tests] --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)
  453. 3.66 s [niks3-go-unit-tests] --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)
  454. 3.66 s [niks3-go-unit-tests] --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)
  455. 3.66 s [niks3-go-unit-tests] 2026/07/19 09:28:41 http: TLS handshake error from 127.0.0.1:48354: remote error: tls: bad certificate
  456. 3.66 s [niks3-go-unit-tests] --- PASS: TestSetClientTLS (0.01s)
  457. 3.66 s [niks3-go-unit-tests] --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.00s)
  458. 3.66 s [niks3-go-unit-tests] --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)
  459. 3.66 s [niks3-go-unit-tests] --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)
  460. 3.66 s [niks3-go-unit-tests] --- PASS: TestDumpPathSingleFile (0.02s)
  461. 3.66 s [niks3-go-unit-tests] --- PASS: TestCaseHackSuffix (0.02s)
  462. 3.66 s [niks3-go-unit-tests] --- PASS: TestDumpPathWriterError (0.02s)
  463. 3.68 s [niks3-go-unit-tests] --- PASS: TestDumpPathMatchesNix (0.04s)
  464. 4.64 s [niks3-go-unit-tests] --- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)
  465. 4.64 s [niks3-go-unit-tests] PASS
  466. 4.64 s [niks3-go-unit-tests] Running server tests...
  467. 4.65 s [niks3-go-unit-tests] The files belonging to this database system will be owned by user "nixbld".
  468. 4.65 s [niks3-go-unit-tests] This user must also own the server process.
  469. 4.65 s [niks3-go-unit-tests]
  470. 4.65 s [niks3-go-unit-tests] The database cluster will be initialized with locale "C".
  471. 4.66 s [niks3-go-unit-tests] The default database encoding has accordingly been set to "SQL_ASCII".
  472. 4.66 s [niks3-go-unit-tests] The default text search configuration will be set to "english".
  473. 4.66 s [niks3-go-unit-tests]
  474. 4.66 s [niks3-go-unit-tests] Data page checksums are enabled.
  475. 4.66 s [niks3-go-unit-tests]
  476. 4.66 s [niks3-go-unit-tests] creating directory /build/postgres3575714155/data ... ok
  477. 4.66 s [niks3-go-unit-tests] creating subdirectories ... ok
  478. 4.66 s [niks3-go-unit-tests] selecting dynamic shared memory implementation ... posix
  479. 4.67 s [niks3-go-unit-tests] selecting default "max_connections" ... 100
  480. 4.68 s [niks3-go-unit-tests] selecting default "shared_buffers" ... 128MB
  481. 4.68 s [niks3-go-unit-tests] selecting default time zone ... UTC
  482. 4.68 s [niks3-go-unit-tests] creating configuration files ... ok
  483. 4.77 s [niks3-go-unit-tests] running bootstrap script ... ok
  484. 5.00 s [niks3-go-unit-tests] performing post-bootstrap initialization ... ok
  485. 5.14 s [niks3-go-unit-tests] syncing data to disk ... ok
  486. 5.25 s [niks3-go-unit-tests]
  487. 5.25 s [niks3-go-unit-tests] initdb: warning: enabling "trust" authentication for local connections
  488. 5.25 s [niks3-go-unit-tests] 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.
  489. 5.25 s [niks3-go-unit-tests]
  490. 5.25 s [niks3-go-unit-tests] Success. You can now start the database server using:
  491. 5.25 s [niks3-go-unit-tests]
  492. 5.25 s [niks3-go-unit-tests] pg_ctl -D /build/postgres3575714155/data -l logfile start
  493. 5.25 s [niks3-go-unit-tests]
  494. 5.25 s [niks3-go-unit-tests] /build/postgres3575714155:5432 - no response
  495. 5.25 s [niks3-go-unit-tests] 2026-07-19 09:28:43.305 UTC [95] LOG: starting PostgreSQL 18.4 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit
  496. 5.25 s [niks3-go-unit-tests] 2026-07-19 09:28:43.312 UTC [95] LOG: listening on Unix socket "/build/postgres3575714155/.s.PGSQL.5432"
  497. 5.25 s [niks3-go-unit-tests] 2026-07-19 09:28:43.342 UTC [102] LOG: database system was shut down at 2026-07-19 09:28:43 UTC
  498. 5.25 s [niks3-go-unit-tests] 2026-07-19 09:28:43.352 UTC [95] LOG: database system is ready to accept connections
  499. 5.25 s [niks3-go-unit-tests] /build/postgres3575714155:5432 - accepting connections
  500. 5.31 s [niks3-go-unit-tests] {"timestamp":"2026-07-19T09:28:43.441718335Z","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(16)"}
  501. 5.31 s [niks3-go-unit-tests]
  502. 5.31 s [niks3-go-unit-tests] thread 'rustfs-worker' (139) panicked at /build/rustfs-1.0.0-beta.7-vendor/source-registry-0/reqwest-0.13.4/src/async_impl/client.rs:2507:38:
  503. 5.31 s [niks3-go-unit-tests] Client::new(): reqwest::Error { kind: Builder, source: General("No CA certificates were loaded from the system") }
  504. 5.31 s [niks3-go-unit-tests] note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
  505. 5.35 s [niks3-go-unit-tests] === RUN TestService_AuthMiddleware
  506. 5.35 s [niks3-go-unit-tests] === PAUSE TestService_AuthMiddleware
  507. 5.35 s [niks3-go-unit-tests] === RUN TestService_AuthMiddleware_MTLSProxyHeader
  508. 5.35 s [niks3-go-unit-tests] === PAUSE TestService_AuthMiddleware_MTLSProxyHeader
  509. 5.35 s [niks3-go-unit-tests] === RUN TestService_AuthMiddleware_MTLSBoundSubjects
  510. 5.35 s [niks3-go-unit-tests] === PAUSE TestService_AuthMiddleware_MTLSBoundSubjects
  511. 5.35 s [niks3-go-unit-tests] === RUN TestService_ReadAuthMiddleware
  512. 5.35 s [niks3-go-unit-tests] === PAUSE TestService_ReadAuthMiddleware
  513. 5.35 s [niks3-go-unit-tests] === RUN TestService_AuthMiddleware_OIDC
  514. 5.35 s [niks3-go-unit-tests] === PAUSE TestService_AuthMiddleware_OIDC
  515. 5.36 s [niks3-go-unit-tests] === RUN TestCacheConfigHandler
  516. 5.36 s [niks3-go-unit-tests] === PAUSE TestCacheConfigHandler
  517. 5.36 s [niks3-go-unit-tests] === RUN TestCacheStatsHandler
  518. 5.36 s [niks3-go-unit-tests] === PAUSE TestCacheStatsHandler
  519. 5.36 s [niks3-go-unit-tests] === RUN TestClientCADerivations
  520. 5.36 s [niks3-go-unit-tests] === PAUSE TestClientCADerivations
  521. 5.36 s [niks3-go-unit-tests] === RUN TestClientErrorHandling
  522. 5.36 s [niks3-go-unit-tests] === PAUSE TestClientErrorHandling
  523. 5.36 s [niks3-go-unit-tests] === RUN TestClientIntegration
  524. 5.36 s [niks3-go-unit-tests] === PAUSE TestClientIntegration
  525. 5.36 s [niks3-go-unit-tests] === RUN TestClientMultipleUploads
  526. 5.36 s [niks3-go-unit-tests] === PAUSE TestClientMultipleUploads
  527. 5.36 s [niks3-go-unit-tests] === RUN TestClientWithDependencies
  528. 5.36 s [niks3-go-unit-tests] === PAUSE TestClientWithDependencies
  529. 5.36 s [niks3-go-unit-tests] === RUN TestPinProtectsFromGC
  530. 5.36 s [niks3-go-unit-tests] === PAUSE TestPinProtectsFromGC
  531. 5.36 s [niks3-go-unit-tests] === RUN TestGCAdvisoryLockBlocksConcurrentRun
  532. 5.44 s [niks3-go-unit-tests] 2026-07-19 09:28:43.565 UTC [154] ERROR: relation "goose_db_version" does not exist at character 36
  533. 5.44 s [niks3-go-unit-tests] 2026-07-19 09:28:43.565 UTC [154] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  534. 5.45 s [niks3-go-unit-tests] 2026/07/19 09:28:43 OK 20241026095416_initial_model.sql (9.55ms)
  535. 5.46 s [niks3-go-unit-tests] 2026/07/19 09:28:43 OK 20251210153512_drop_unused_gin_index.sql (4.67ms)
  536. 5.46 s [niks3-go-unit-tests] 2026/07/19 09:28:43 OK 20251218171726_add_pins.sql (5.13ms)
  537. 5.47 s [niks3-go-unit-tests] 2026/07/19 09:28:43 OK 20260628120000_add_object_size_and_stats.sql (4.66ms)
  538. 5.47 s [niks3-go-unit-tests] 2026/07/19 09:28:43 goose: successfully migrated database to version: 20260628120000
  539. 5.47 s [niks3-go-unit-tests] 2026/07/19 09:28:43 OK 1_commit_pending_closure.sql (4.7ms)
  540. 5.48 s [niks3-go-unit-tests] 2026/07/19 09:28:43 OK 2_object_stats_trigger.sql (4.66ms)
  541. 5.48 s [niks3-go-unit-tests] 2026/07/19 09:28:43 goose: up to current file version: 2
  542. 5.48 s [niks3-go-unit-tests] --- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.13s)
  543. 5.48 s [niks3-go-unit-tests] === RUN TestGCBugBareHashReferences
  544. 5.48 s [niks3-go-unit-tests] === PAUSE TestGCBugBareHashReferences
  545. 5.48 s [niks3-go-unit-tests] === RUN TestGCMetrics
  546. 5.48 s [niks3-go-unit-tests] === PAUSE TestGCMetrics
  547. 5.48 s [niks3-go-unit-tests] === RUN TestGCTaskStore_StartNew
  548. 5.48 s [niks3-go-unit-tests] === PAUSE TestGCTaskStore_StartNew
  549. 5.48 s [niks3-go-unit-tests] === RUN TestGCTaskStore_DeduplicateSameParams
  550. 5.48 s [niks3-go-unit-tests] === PAUSE TestGCTaskStore_DeduplicateSameParams
  551. 5.48 s [niks3-go-unit-tests] === RUN TestGCTaskStore_ConflictDifferentParams
  552. 5.48 s [niks3-go-unit-tests] === PAUSE TestGCTaskStore_ConflictDifferentParams
  553. 5.48 s [niks3-go-unit-tests] === RUN TestGCTaskStore_GetEmpty
  554. 5.48 s [niks3-go-unit-tests] === PAUSE TestGCTaskStore_GetEmpty
  555. 5.48 s [niks3-go-unit-tests] === RUN TestGCTaskStore_GetReturnsLatest
  556. 5.48 s [niks3-go-unit-tests] === PAUSE TestGCTaskStore_GetReturnsLatest
  557. 5.48 s [niks3-go-unit-tests] === RUN TestGCTaskStore_CompletedAllowsNewTask
  558. 5.48 s [niks3-go-unit-tests] === PAUSE TestGCTaskStore_CompletedAllowsNewTask
  559. 5.48 s [niks3-go-unit-tests] === RUN TestGCTaskStore_PhaseUpdates
  560. 5.48 s [niks3-go-unit-tests] === PAUSE TestGCTaskStore_PhaseUpdates
  561. 5.48 s [niks3-go-unit-tests] === RUN TestGCTaskStore_Fail
  562. 5.48 s [niks3-go-unit-tests] === PAUSE TestGCTaskStore_Fail
  563. 5.48 s [niks3-go-unit-tests] === RUN TestGracefulShutdownDrainsInflight
  564. 5.48 s [niks3-go-unit-tests] === PAUSE TestGracefulShutdownDrainsInflight
  565. 5.48 s [niks3-go-unit-tests] === RUN TestService_healthCheckHandler
  566. 5.48 s [niks3-go-unit-tests] === PAUSE TestService_healthCheckHandler
  567. 5.48 s [niks3-go-unit-tests] === RUN TestGenerateLandingPage
  568. 5.48 s [niks3-go-unit-tests] === PAUSE TestGenerateLandingPage
  569. 5.48 s [niks3-go-unit-tests] === RUN TestNARDeduplicationMetadataUploadBug
  570. 5.48 s [niks3-go-unit-tests] === PAUSE TestNARDeduplicationMetadataUploadBug
  571. 5.48 s [niks3-go-unit-tests] === RUN TestMetricsInventory
  572. 5.48 s [niks3-go-unit-tests] === PAUSE TestMetricsInventory
  573. 5.48 s [niks3-go-unit-tests] === RUN TestService_NativeMTLS
  574. 5.48 s [niks3-go-unit-tests] === PAUSE TestService_NativeMTLS
  575. 5.48 s [niks3-go-unit-tests] === RUN TestServerTLSConfig
  576. 5.48 s [niks3-go-unit-tests] === PAUSE TestServerTLSConfig
  577. 5.48 s [niks3-go-unit-tests] === RUN TestMultipartCleanup
  578. 5.48 s [niks3-go-unit-tests] === PAUSE TestMultipartCleanup
  579. 5.48 s [niks3-go-unit-tests] === RUN TestObjectStatsTrigger
  580. 5.48 s [niks3-go-unit-tests] === PAUSE TestObjectStatsTrigger
  581. 5.48 s [niks3-go-unit-tests] === RUN TestOrphanedObjectsGC
  582. 5.48 s [niks3-go-unit-tests] === PAUSE TestOrphanedObjectsGC
  583. 5.48 s [niks3-go-unit-tests] === RUN TestOrphanedObjectsGCStressTest
  584. 5.48 s [niks3-go-unit-tests] === PAUSE TestOrphanedObjectsGCStressTest
  585. 5.48 s [niks3-go-unit-tests] === RUN TestResurrectedObjectNotDeleted
  586. 5.48 s [niks3-go-unit-tests] === PAUSE TestResurrectedObjectNotDeleted
  587. 5.48 s [niks3-go-unit-tests] === RUN TestParseSingleRange
  588. 5.48 s [niks3-go-unit-tests] === PAUSE TestParseSingleRange
  589. 5.48 s [niks3-go-unit-tests] === RUN TestIsValidCachePath
  590. 5.48 s [niks3-go-unit-tests] === PAUSE TestIsValidCachePath
  591. 5.48 s [niks3-go-unit-tests] === RUN TestReadProxyNarinfo
  592. 5.48 s [niks3-go-unit-tests] === PAUSE TestReadProxyNarinfo
  593. 5.48 s [niks3-go-unit-tests] === RUN TestReadProxyNarinfoAlreadyDecompressed
  594. 5.48 s [niks3-go-unit-tests] === PAUSE TestReadProxyNarinfoAlreadyDecompressed
  595. 5.48 s [niks3-go-unit-tests] === RUN TestReadProxyNarStreaming
  596. 5.48 s [niks3-go-unit-tests] === PAUSE TestReadProxyNarStreaming
  597. 5.48 s [niks3-go-unit-tests] === RUN TestReadProxy404
  598. 5.48 s [niks3-go-unit-tests] === PAUSE TestReadProxy404
  599. 5.48 s [niks3-go-unit-tests] === RUN TestReadProxyInvalidPath
  600. 5.48 s [niks3-go-unit-tests] === PAUSE TestReadProxyInvalidPath
  601. 5.48 s [niks3-go-unit-tests] === RUN TestReadProxyHead
  602. 5.48 s [niks3-go-unit-tests] === PAUSE TestReadProxyHead
  603. 5.48 s [niks3-go-unit-tests] === RUN TestReadProxyConditionalGet
  604. 5.48 s [niks3-go-unit-tests] === PAUSE TestReadProxyConditionalGet
  605. 5.48 s [niks3-go-unit-tests] === RUN TestReadProxyRootRedirectsToIndexHTML
  606. 5.48 s [niks3-go-unit-tests] === PAUSE TestReadProxyRootRedirectsToIndexHTML
  607. 5.48 s [niks3-go-unit-tests] === RUN TestReadProxyDisabled
  608. 5.48 s [niks3-go-unit-tests] === PAUSE TestReadProxyDisabled
  609. 5.48 s [niks3-go-unit-tests] === RUN TestReadProxyRangeRequest
  610. 5.48 s [niks3-go-unit-tests] === PAUSE TestReadProxyRangeRequest
  611. 5.48 s [niks3-go-unit-tests] === RUN TestRedundantMultipartUpload
  612. 5.48 s [niks3-go-unit-tests] === PAUSE TestRedundantMultipartUpload
  613. 5.48 s [niks3-go-unit-tests] === RUN TestCompleteMultipartUpload_ErrorButObjectExists
  614. 5.48 s [niks3-go-unit-tests] === PAUSE TestCompleteMultipartUpload_ErrorButObjectExists
  615. 5.48 s [niks3-go-unit-tests] === RUN TestCompletedNarNotReofferedAcrossClosures
  616. 5.48 s [niks3-go-unit-tests] === PAUSE TestCompletedNarNotReofferedAcrossClosures
  617. 5.48 s [niks3-go-unit-tests] === RUN TestService_Rustfstest
  618. 5.48 s [niks3-go-unit-tests] === PAUSE TestService_Rustfstest
  619. 5.48 s [niks3-go-unit-tests] === RUN TestSystemdListenerNotActivated
  620. 5.48 s [niks3-go-unit-tests] --- PASS: TestSystemdListenerNotActivated (0.00s)
  621. 5.48 s [niks3-go-unit-tests] === RUN TestWatchdogBeatsWhenHealthy
  622. 5.50 s [niks3-go-unit-tests] --- PASS: TestWatchdogBeatsWhenHealthy (0.02s)
  623. 5.50 s [niks3-go-unit-tests] === RUN TestWatchdogSkipsWhenUnhealthy
  624. 5.52 s [niks3-go-unit-tests] 2026/07/19 09:28:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"
  625. 5.54 s [niks3-go-unit-tests] 2026/07/19 09:28:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"
  626. 5.56 s [niks3-go-unit-tests] 2026/07/19 09:28:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"
  627. 5.58 s [niks3-go-unit-tests] 2026/07/19 09:28:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"
  628. 5.60 s [niks3-go-unit-tests] 2026/07/19 09:28:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"
  629. 5.62 s [niks3-go-unit-tests] 2026/07/19 09:28:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"
  630. 5.64 s [niks3-go-unit-tests] 2026/07/19 09:28:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"
  631. 5.66 s [niks3-go-unit-tests] 2026/07/19 09:28:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"
  632. 5.68 s [niks3-go-unit-tests] 2026/07/19 09:28:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"
  633. 5.70 s [niks3-go-unit-tests] 2026/07/19 09:28:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"
  634. 5.70 s [niks3-go-unit-tests] --- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)
  635. 5.70 s [niks3-go-unit-tests] === RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle
  636. 5.70 s [niks3-go-unit-tests] === PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle
  637. 5.70 s [niks3-go-unit-tests] === RUN TestProxyWriteTimeout
  638. 5.70 s [niks3-go-unit-tests] === PAUSE TestProxyWriteTimeout
  639. 5.71 s [niks3-go-unit-tests] === RUN TestIsValidUploadKey
  640. 5.71 s [niks3-go-unit-tests] === PAUSE TestIsValidUploadKey
  641. 5.71 s [niks3-go-unit-tests] === RUN TestUploadHandlersRejectInvalidKeys
  642. 5.71 s [niks3-go-unit-tests] === PAUSE TestUploadHandlersRejectInvalidKeys
  643. 5.71 s [niks3-go-unit-tests] === RUN TestUploadHandlersRejectOversizedBody
  644. 5.71 s [niks3-go-unit-tests] === PAUSE TestUploadHandlersRejectOversizedBody
  645. 5.71 s [niks3-go-unit-tests] === RUN TestService_cleanupPendingClosuresHandler
  646. 5.71 s [niks3-go-unit-tests] === PAUSE TestService_cleanupPendingClosuresHandler
  647. 5.71 s [niks3-go-unit-tests] === RUN TestService_createPendingClosureHandler
  648. 5.71 s [niks3-go-unit-tests] === PAUSE TestService_createPendingClosureHandler
  649. 5.71 s [niks3-go-unit-tests] === RUN TestService_verifyS3Integrity
  650. 5.71 s [niks3-go-unit-tests] === PAUSE TestService_verifyS3Integrity
  651. 5.71 s [niks3-go-unit-tests] === RUN TestCompleteMultipartUnregistered
  652. 5.71 s [niks3-go-unit-tests] === PAUSE TestCompleteMultipartUnregistered
  653. 5.71 s [niks3-go-unit-tests] === RUN TestCreatePendingClosure_SmallNARUsesSimplePUT
  654. 5.71 s [niks3-go-unit-tests] === PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT
  655. 5.71 s [niks3-go-unit-tests] === CONT TestService_AuthMiddleware
  656. 5.71 s [niks3-go-unit-tests] === CONT TestObjectStatsTrigger
  657. 5.71 s [niks3-go-unit-tests] === CONT TestReadProxyRangeRequest
  658. 5.71 s [niks3-go-unit-tests] === CONT TestReadProxyNarStreaming
  659. 5.71 s [niks3-go-unit-tests] === CONT TestParseSingleRange
  660. 5.71 s [niks3-go-unit-tests] === CONT TestReadProxyNarinfo
  661. 5.71 s [niks3-go-unit-tests] === CONT TestResurrectedObjectNotDeleted
  662. 5.71 s [niks3-go-unit-tests] === CONT TestClientErrorHandling
  663. 5.71 s [niks3-go-unit-tests] === RUN TestClientErrorHandling/InvalidStorePath
  664. 5.71 s [niks3-go-unit-tests] === CONT TestIsValidCachePath
  665. 5.71 s [niks3-go-unit-tests] === RUN TestParseSingleRange/none
  666. 5.71 s [niks3-go-unit-tests] === PAUSE TestParseSingleRange/none
  667. 5.71 s [niks3-go-unit-tests] === RUN TestIsValidCachePath/narinfo
  668. 5.71 s [niks3-go-unit-tests] === CONT TestOrphanedObjectsGCStressTest
  669. 5.71 s [niks3-go-unit-tests] === PAUSE TestIsValidCachePath/narinfo
  670. 5.71 s [niks3-go-unit-tests] === RUN TestIsValidCachePath/narinfo_all_nix_base32_chars
  671. 5.71 s [niks3-go-unit-tests] === PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars
  672. 5.71 s [niks3-go-unit-tests] === RUN TestIsValidCachePath/nar_zst
  673. 5.71 s [niks3-go-unit-tests] === PAUSE TestIsValidCachePath/nar_zst
  674. 5.71 s [niks3-go-unit-tests] === RUN TestIsValidCachePath/nar_xz
  675. 5.71 s [niks3-go-unit-tests] === PAUSE TestIsValidCachePath/nar_xz
  676. 5.71 s [niks3-go-unit-tests] === RUN TestIsValidCachePath/nar_bz2
  677. 5.71 s [niks3-go-unit-tests] === RUN TestParseSingleRange/unknown_unit
  678. 5.71 s [niks3-go-unit-tests] === PAUSE TestIsValidCachePath/nar_bz2
  679. 5.71 s [niks3-go-unit-tests] === CONT TestGCTaskStore_StartNew
  680. 5.71 s [niks3-go-unit-tests] --- PASS: TestGCTaskStore_StartNew (0.00s)
  681. 5.71 s [niks3-go-unit-tests] === CONT TestGCBugBareHashReferences
  682. 5.71 s [niks3-go-unit-tests] === CONT TestPinProtectsFromGC
  683. 5.71 s [niks3-go-unit-tests] === PAUSE TestParseSingleRange/unknown_unit
  684. 5.71 s [niks3-go-unit-tests] === RUN TestParseSingleRange/multi-range_ignored
  685. 5.71 s [niks3-go-unit-tests] === PAUSE TestParseSingleRange/multi-range_ignored
  686. 5.71 s [niks3-go-unit-tests] === RUN TestParseSingleRange/malformed_no_dash
  687. 5.71 s [niks3-go-unit-tests] === PAUSE TestParseSingleRange/malformed_no_dash
  688. 5.71 s [niks3-go-unit-tests] === RUN TestParseSingleRange/malformed_both_empty
  689. 5.71 s [niks3-go-unit-tests] === PAUSE TestParseSingleRange/malformed_both_empty
  690. 5.71 s [niks3-go-unit-tests] === RUN TestParseSingleRange/malformed_end_before_start
  691. 5.71 s [niks3-go-unit-tests] === PAUSE TestParseSingleRange/malformed_end_before_start
  692. 5.71 s [niks3-go-unit-tests] === RUN TestParseSingleRange/closed
  693. 5.71 s [niks3-go-unit-tests] === PAUSE TestParseSingleRange/closed
  694. 5.71 s [niks3-go-unit-tests] === RUN TestParseSingleRange/open-ended
  695. 5.71 s [niks3-go-unit-tests] === PAUSE TestParseSingleRange/open-ended
  696. 5.71 s [niks3-go-unit-tests] === RUN TestIsValidCachePath/nar_uncompressed
  697. 5.71 s [niks3-go-unit-tests] === PAUSE TestClientErrorHandling/InvalidStorePath
  698. 5.71 s [niks3-go-unit-tests] === RUN TestClientErrorHandling/InvalidAuthToken
  699. 5.71 s [niks3-go-unit-tests] === PAUSE TestClientErrorHandling/InvalidAuthToken
  700. 5.71 s [niks3-go-unit-tests] === RUN TestClientErrorHandling/ServerNotAvailable
  701. 5.71 s [niks3-go-unit-tests] === PAUSE TestClientErrorHandling/ServerNotAvailable
  702. 5.71 s [niks3-go-unit-tests] === CONT TestReadProxyNarinfoAlreadyDecompressed
  703. 5.71 s [niks3-go-unit-tests] === CONT TestClientWithDependencies
  704. 5.71 s [niks3-go-unit-tests] === CONT TestGCMetrics
  705. 5.71 s [niks3-go-unit-tests] === RUN TestParseSingleRange/end_clamped_to_size
  706. 5.71 s [niks3-go-unit-tests] === PAUSE TestParseSingleRange/end_clamped_to_size
  707. 5.71 s [niks3-go-unit-tests] === RUN TestParseSingleRange/suffix
  708. 5.71 s [niks3-go-unit-tests] === PAUSE TestParseSingleRange/suffix
  709. 5.71 s [niks3-go-unit-tests] === RUN TestParseSingleRange/suffix_exceeds_size
  710. 5.71 s [niks3-go-unit-tests] === PAUSE TestParseSingleRange/suffix_exceeds_size
  711. 5.71 s [niks3-go-unit-tests] === RUN TestParseSingleRange/single_byte
  712. 5.71 s [niks3-go-unit-tests] === PAUSE TestParseSingleRange/single_byte
  713. 5.71 s [niks3-go-unit-tests] === RUN TestParseSingleRange/start_past_EOF
  714. 5.71 s [niks3-go-unit-tests] === PAUSE TestParseSingleRange/start_past_EOF
  715. 5.71 s [niks3-go-unit-tests] === RUN TestParseSingleRange/start_far_past_EOF
  716. 5.71 s [niks3-go-unit-tests] === PAUSE TestParseSingleRange/start_far_past_EOF
  717. 5.71 s [niks3-go-unit-tests] === PAUSE TestIsValidCachePath/nar_uncompressed
  718. 5.71 s [niks3-go-unit-tests] === RUN TestIsValidCachePath/ls
  719. 5.71 s [niks3-go-unit-tests] === PAUSE TestIsValidCachePath/ls
  720. 5.71 s [niks3-go-unit-tests] === RUN TestIsValidCachePath/log
  721. 5.71 s [niks3-go-unit-tests] === PAUSE TestIsValidCachePath/log
  722. 5.71 s [niks3-go-unit-tests] === RUN TestIsValidCachePath/realisation
  723. 5.71 s [niks3-go-unit-tests] === PAUSE TestIsValidCachePath/realisation
  724. 5.71 s [niks3-go-unit-tests] === RUN TestIsValidCachePath/nix-cache-info
  725. 5.71 s [niks3-go-unit-tests] === PAUSE TestIsValidCachePath/nix-cache-info
  726. 5.71 s [niks3-go-unit-tests] === RUN TestIsValidCachePath/index.html
  727. 5.71 s [niks3-go-unit-tests] === PAUSE TestIsValidCachePath/index.html
  728. 5.71 s [niks3-go-unit-tests] === RUN TestIsValidCachePath/traversal_parent
  729. 5.71 s [niks3-go-unit-tests] === PAUSE TestIsValidCachePath/traversal_parent
  730. 5.71 s [niks3-go-unit-tests] === RUN TestIsValidCachePath/traversal_in_middle
  731. 5.71 s [niks3-go-unit-tests] === PAUSE TestIsValidCachePath/traversal_in_middle
  732. 5.71 s [niks3-go-unit-tests] === RUN TestIsValidCachePath/invalid_char_e
  733. 5.71 s [niks3-go-unit-tests] === PAUSE TestIsValidCachePath/invalid_char_e
  734. 5.71 s [niks3-go-unit-tests] === RUN TestIsValidCachePath/invalid_char_u
  735. 5.71 s [niks3-go-unit-tests] === PAUSE TestIsValidCachePath/invalid_char_u
  736. 5.71 s [niks3-go-unit-tests] === RUN TestIsValidCachePath/random_path
  737. 5.71 s [niks3-go-unit-tests] === PAUSE TestIsValidCachePath/random_path
  738. 5.71 s [niks3-go-unit-tests] === RUN TestIsValidCachePath/empty
  739. 5.71 s [niks3-go-unit-tests] === CONT TestClientMultipleUploads
  740. 5.71 s [niks3-go-unit-tests] === PAUSE TestIsValidCachePath/empty
  741. 5.71 s [niks3-go-unit-tests] === RUN TestIsValidCachePath/leading_slash
  742. 5.71 s [niks3-go-unit-tests] === PAUSE TestIsValidCachePath/leading_slash
  743. 5.71 s [niks3-go-unit-tests] === RUN TestIsValidCachePath/wrong_extension
  744. 5.71 s [niks3-go-unit-tests] === PAUSE TestIsValidCachePath/wrong_extension
  745. 5.71 s [niks3-go-unit-tests] === RUN TestIsValidCachePath/short_hash
  746. 5.71 s [niks3-go-unit-tests] === PAUSE TestIsValidCachePath/short_hash
  747. 5.71 s [niks3-go-unit-tests] === CONT TestClientIntegration
  748. 6.26 s [niks3-go-unit-tests] 2026-07-19 09:28:44.391 UTC [205] ERROR: relation "goose_db_version" does not exist at character 36
  749. 6.26 s [niks3-go-unit-tests] 2026-07-19 09:28:44.391 UTC [205] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  750. 6.26 s [niks3-go-unit-tests] 2026-07-19 09:28:44.391 UTC [204] ERROR: relation "goose_db_version" does not exist at character 36
  751. 6.26 s [niks3-go-unit-tests] 2026-07-19 09:28:44.391 UTC [204] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  752. 6.26 s [niks3-go-unit-tests] 2026-07-19 09:28:44.392 UTC [197] ERROR: relation "goose_db_version" does not exist at character 36
  753. 6.26 s [niks3-go-unit-tests] 2026-07-19 09:28:44.392 UTC [197] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  754. 6.26 s [niks3-go-unit-tests] 2026-07-19 09:28:44.392 UTC [200] ERROR: relation "goose_db_version" does not exist at character 36
  755. 6.26 s [niks3-go-unit-tests] 2026-07-19 09:28:44.392 UTC [200] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  756. 6.26 s [niks3-go-unit-tests] 2026-07-19 09:28:44.392 UTC [202] ERROR: relation "goose_db_version" does not exist at character 36
  757. 6.26 s [niks3-go-unit-tests] 2026-07-19 09:28:44.392 UTC [202] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  758. 6.26 s [niks3-go-unit-tests] 2026-07-19 09:28:44.392 UTC [199] ERROR: relation "goose_db_version" does not exist at character 36
  759. 6.26 s [niks3-go-unit-tests] 2026-07-19 09:28:44.392 UTC [199] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  760. 6.26 s [niks3-go-unit-tests] 2026-07-19 09:28:44.392 UTC [203] ERROR: relation "goose_db_version" does not exist at character 36
  761. 6.26 s [niks3-go-unit-tests] 2026-07-19 09:28:44.392 UTC [203] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  762. 6.27 s [niks3-go-unit-tests] 2026-07-19 09:28:44.394 UTC [198] ERROR: relation "goose_db_version" does not exist at character 36
  763. 6.27 s [niks3-go-unit-tests] 2026-07-19 09:28:44.394 UTC [198] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  764. 6.27 s [niks3-go-unit-tests] 2026-07-19 09:28:44.394 UTC [201] ERROR: relation "goose_db_version" does not exist at character 36
  765. 6.27 s [niks3-go-unit-tests] 2026-07-19 09:28:44.394 UTC [201] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  766. 6.32 s [niks3-go-unit-tests] 2026-07-19 09:28:44.445 UTC [206] ERROR: relation "goose_db_version" does not exist at character 36
  767. 6.32 s [niks3-go-unit-tests] 2026-07-19 09:28:44.445 UTC [206] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  768. 6.33 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20241026095416_initial_model.sql (11.74ms)
  769. 6.33 s [niks3-go-unit-tests] 2026-07-19 09:28:44.460 UTC [207] ERROR: relation "goose_db_version" does not exist at character 36
  770. 6.33 s [niks3-go-unit-tests] 2026-07-19 09:28:44.460 UTC [207] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  771. 6.33 s [niks3-go-unit-tests] 2026-07-19 09:28:44.460 UTC [208] ERROR: relation "goose_db_version" does not exist at character 36
  772. 6.33 s [niks3-go-unit-tests] 2026-07-19 09:28:44.460 UTC [208] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  773. 6.33 s [niks3-go-unit-tests] 2026-07-19 09:28:44.461 UTC [209] ERROR: relation "goose_db_version" does not exist at character 36
  774. 6.33 s [niks3-go-unit-tests] 2026-07-19 09:28:44.461 UTC [209] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  775. 6.34 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251210153512_drop_unused_gin_index.sql (6.91ms)
  776. 6.34 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20241026095416_initial_model.sql (17.71ms)
  777. 6.34 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20241026095416_initial_model.sql (16.89ms)
  778. 6.34 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20241026095416_initial_model.sql (18.18ms)
  779. 6.34 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20241026095416_initial_model.sql (17.81ms)
  780. 6.34 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20241026095416_initial_model.sql (11.98ms)
  781. 6.34 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20241026095416_initial_model.sql (14.81ms)
  782. 6.34 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20241026095416_initial_model.sql (17.16ms)
  783. 6.34 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20241026095416_initial_model.sql (18.2ms)
  784. 6.35 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251218171726_add_pins.sql (8.29ms)
  785. 6.35 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20241026095416_initial_model.sql (15.05ms)
  786. 6.35 s [niks3-go-unit-tests] 2026-07-19 09:28:44.477 UTC [210] ERROR: relation "goose_db_version" does not exist at character 36
  787. 6.35 s [niks3-go-unit-tests] 2026-07-19 09:28:44.477 UTC [210] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  788. 6.35 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251210153512_drop_unused_gin_index.sql (8.43ms)
  789. 6.35 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251210153512_drop_unused_gin_index.sql (8.38ms)
  790. 6.35 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251210153512_drop_unused_gin_index.sql (8.7ms)
  791. 6.35 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251210153512_drop_unused_gin_index.sql (7.94ms)
  792. 6.35 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251210153512_drop_unused_gin_index.sql (7.93ms)
  793. 6.35 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251210153512_drop_unused_gin_index.sql (8.77ms)
  794. 6.35 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251210153512_drop_unused_gin_index.sql (8.55ms)
  795. 6.35 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251210153512_drop_unused_gin_index.sql (8.72ms)
  796. 6.36 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20260628120000_add_object_size_and_stats.sql (10.37ms)
  797. 6.36 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: successfully migrated database to version: 20260628120000
  798. 6.36 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20241026095416_initial_model.sql (13.41ms)
  799. 6.36 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251210153512_drop_unused_gin_index.sql (10.48ms)
  800. 6.36 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20241026095416_initial_model.sql (13.44ms)
  801. 6.36 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20241026095416_initial_model.sql (13.33ms)
  802. 6.36 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251218171726_add_pins.sql (9.92ms)
  803. 6.36 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251218171726_add_pins.sql (10.14ms)
  804. 6.36 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251218171726_add_pins.sql (10.16ms)
  805. 6.36 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251218171726_add_pins.sql (10.05ms)
  806. 6.36 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251218171726_add_pins.sql (8.42ms)
  807. 6.36 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251218171726_add_pins.sql (10.03ms)
  808. 6.36 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251218171726_add_pins.sql (10.14ms)
  809. 6.36 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251218171726_add_pins.sql (10.14ms)
  810. 6.37 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 1_commit_pending_closure.sql (8.76ms)
  811. 6.37 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251218171726_add_pins.sql (8.71ms)
  812. 6.37 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251210153512_drop_unused_gin_index.sql (6.81ms)
  813. 6.37 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251210153512_drop_unused_gin_index.sql (6.49ms)
  814. 6.37 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251210153512_drop_unused_gin_index.sql (6.87ms)
  815. 6.37 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20260628120000_add_object_size_and_stats.sql (8.31ms)
  816. 6.37 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20260628120000_add_object_size_and_stats.sql (8.4ms)
  817. 6.37 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: successfully migrated database to version: 20260628120000
  818. 6.37 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20260628120000_add_object_size_and_stats.sql (8.33ms)
  819. 6.37 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: successfully migrated database to version: 20260628120000
  820. 6.37 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20260628120000_add_object_size_and_stats.sql (8.35ms)
  821. 6.37 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20241026095416_initial_model.sql (12.33ms)
  822. 6.37 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20260628120000_add_object_size_and_stats.sql (8.37ms)
  823. 6.37 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20260628120000_add_object_size_and_stats.sql (8.37ms)
  824. 6.37 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: successfully migrated database to version: 20260628120000
  825. 6.37 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: successfully migrated database to version: 20260628120000
  826. 6.37 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: successfully migrated database to version: 20260628120000
  827. 6.37 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20260628120000_add_object_size_and_stats.sql (8.33ms)
  828. 6.37 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: successfully migrated database to version: 20260628120000
  829. 6.37 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: successfully migrated database to version: 20260628120000
  830. 6.37 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20260628120000_add_object_size_and_stats.sql (8.26ms)
  831. 6.37 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: successfully migrated database to version: 20260628120000
  832. 6.38 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251218171726_add_pins.sql (8.58ms)
  833. 6.38 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 2_object_stats_trigger.sql (8.8ms)
  834. 6.38 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: up to current file version: 2
  835. 6.38 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20260628120000_add_object_size_and_stats.sql (8.86ms)
  836. 6.38 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: successfully migrated database to version: 20260628120000
  837. 6.38 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251218171726_add_pins.sql (8.68ms)
  838. 6.38 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251218171726_add_pins.sql (10.78ms)
  839. 6.38 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 1_commit_pending_closure.sql (10.37ms)
  840. 6.38 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 1_commit_pending_closure.sql (10.49ms)
  841. 6.38 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 1_commit_pending_closure.sql (10.39ms)
  842. 6.38 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 1_commit_pending_closure.sql (10.26ms)
  843. 6.38 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 1_commit_pending_closure.sql (10.47ms)
  844. 6.38 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 1_commit_pending_closure.sql (10.37ms)
  845. 6.38 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 1_commit_pending_closure.sql (10.48ms)
  846. 6.38 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 1_commit_pending_closure.sql (10.44ms)
  847. 6.38 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251210153512_drop_unused_gin_index.sql (10.65ms)
  848. 6.38 s [niks3-go-unit-tests] {"timestamp":"2026-07-19T09:28:44.510068354Z","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(28)"}
  849. 6.38 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 1_commit_pending_closure.sql (9.57ms)
  850. 6.38 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20260628120000_add_object_size_and_stats.sql (9.52ms)
  851. 6.38 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20260628120000_add_object_size_and_stats.sql (9.67ms)
  852. 6.38 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20260628120000_add_object_size_and_stats.sql (7.5ms)
  853. 6.38 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: successfully migrated database to version: 20260628120000
  854. 6.38 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: successfully migrated database to version: 20260628120000
  855. 6.38 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: successfully migrated database to version: 20260628120000
  856. 6.39 s [niks3-go-unit-tests] --- PASS: TestReadProxyRangeRequest (0.68s)
  857. 6.39 s [niks3-go-unit-tests] === CONT TestOrphanedObjectsGC
  858. 6.39 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 2_object_stats_trigger.sql (8.4ms)
  859. 6.39 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: up to current file version: 2
  860. 6.39 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 2_object_stats_trigger.sql (8.62ms)
  861. 6.39 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: up to current file version: 2
  862. 6.39 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251218171726_add_pins.sql (8.54ms)
  863. 6.39 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 2_object_stats_trigger.sql (8.67ms)
  864. 6.39 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: up to current file version: 2
  865. 6.39 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 2_object_stats_trigger.sql (8.68ms)
  866. 6.39 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 2_object_stats_trigger.sql (8.67ms)
  867. 6.39 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: up to current file version: 2
  868. 6.39 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: up to current file version: 2
  869. 6.39 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 2_object_stats_trigger.sql (8.73ms)
  870. 6.39 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: up to current file version: 2
  871. 6.39 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 2_object_stats_trigger.sql (8.67ms)
  872. 6.39 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: up to current file version: 2
  873. 6.39 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 2_object_stats_trigger.sql (8.59ms)
  874. 6.39 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: up to current file version: 2
  875. 6.39 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 1_commit_pending_closure.sql (9.54ms)
  876. 6.39 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 1_commit_pending_closure.sql (9.67ms)
  877. 6.39 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 1_commit_pending_closure.sql (9.61ms)
  878. 6.39 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 2_object_stats_trigger.sql (9.78ms)
  879. 6.39 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: up to current file version: 2
  880. 6.40 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20260628120000_add_object_size_and_stats.sql (13.24ms)
  881. 6.40 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: successfully migrated database to version: 20260628120000
  882. 6.41 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 2_object_stats_trigger.sql (15.73ms)
  883. 6.41 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: up to current file version: 2
  884. 6.41 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 2_object_stats_trigger.sql (15.8ms)
  885. 6.41 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: up to current file version: 2
  886. 6.41 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 2_object_stats_trigger.sql (15.88ms)
  887. 6.41 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: up to current file version: 2
  888. 6.42 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 1_commit_pending_closure.sql (16.19ms)
  889. 6.43 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 2_object_stats_trigger.sql (8.94ms)
  890. 6.43 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: up to current file version: 2
  891. 6.47 s [niks3-go-unit-tests] 2026/07/19 09:28:44 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"
  892. 6.47 s [niks3-go-unit-tests] --- PASS: TestService_AuthMiddleware (0.77s)
  893. 6.47 s [niks3-go-unit-tests] === CONT TestService_AuthMiddleware_OIDC
  894. 6.47 s [niks3-go-unit-tests] 2026/07/19 09:28:44 INFO OIDC provider initialized name=test
  895. 6.47 s [niks3-go-unit-tests] 2026/07/19 09:28:44 INFO Created nix-cache-info in bucket bucket=bucket10
  896. 6.47 s [niks3-go-unit-tests] --- PASS: TestReadProxyNarinfo (0.77s)
  897. 6.47 s [niks3-go-unit-tests] === CONT TestClientCADerivations
  898. 6.47 s [niks3-go-unit-tests] --- PASS: TestReadProxyNarStreaming (0.77s)
  899. 6.47 s [niks3-go-unit-tests] === CONT TestCacheStatsHandler
  900. 6.48 s [niks3-go-unit-tests] 2026/07/19 09:28:44 INFO Aborted multipart uploads count=0
  901. 6.48 s [niks3-go-unit-tests] 2026/07/19 09:28:44 WARN Force mode enabled - objects will be deleted immediately without grace period
  902. 6.48 s [niks3-go-unit-tests] 2026/07/19 09:28:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=0
  903. 6.48 s [niks3-go-unit-tests] 2026/07/19 09:28:44 INFO Vacuumed table table=pending_closures
  904. 6.48 s [niks3-go-unit-tests] 2026/07/19 09:28:44 INFO Vacuumed table table=pending_objects
  905. 6.48 s [niks3-go-unit-tests] 2026/07/19 09:28:44 INFO Vacuumed table table=multipart_uploads
  906. 6.48 s [niks3-go-unit-tests] 2026/07/19 09:28:44 INFO Vacuumed table table=closures
  907. 6.48 s [niks3-go-unit-tests] 2026/07/19 09:28:44 INFO Vacuumed table table=objects
  908. 6.48 s [niks3-go-unit-tests] --- PASS: TestGCMetrics (0.78s)
  909. 6.48 s [niks3-go-unit-tests] === CONT TestCacheConfigHandler
  910. 6.48 s [niks3-go-unit-tests] === RUN TestCacheConfigHandler/full_config,_no_issuer
  911. 6.48 s [niks3-go-unit-tests] === PAUSE TestCacheConfigHandler/full_config,_no_issuer
  912. 6.48 s [niks3-go-unit-tests] === RUN TestCacheConfigHandler/no_cache_url_configured
  913. 6.48 s [niks3-go-unit-tests] === PAUSE TestCacheConfigHandler/no_cache_url_configured
  914. 6.48 s [niks3-go-unit-tests] === RUN TestCacheConfigHandler/no_signing_keys
  915. 6.48 s [niks3-go-unit-tests] === PAUSE TestCacheConfigHandler/no_signing_keys
  916. 6.48 s [niks3-go-unit-tests] === RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator
  917. 6.48 s [niks3-go-unit-tests] === PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator
  918. 6.48 s [niks3-go-unit-tests] === CONT TestService_AuthMiddleware_MTLSBoundSubjects
  919. 6.49 s [niks3-go-unit-tests] 2026-07-19 09:28:44.616 UTC [241] ERROR: relation "goose_db_version" does not exist at character 36
  920. 6.49 s [niks3-go-unit-tests] 2026-07-19 09:28:44.616 UTC [241] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  921. 6.52 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20241026095416_initial_model.sql (16.56ms)
  922. 6.54 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251210153512_drop_unused_gin_index.sql (16.64ms)
  923. 6.56 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20251218171726_add_pins.sql (17.58ms)
  924. 6.57 s [niks3-go-unit-tests] --- PASS: TestObjectStatsTrigger (0.86s)
  925. 6.57 s [niks3-go-unit-tests] === CONT TestService_ReadAuthMiddleware
  926. 6.57 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 20260628120000_add_object_size_and_stats.sql (16.09ms)
  927. 6.57 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: successfully migrated database to version: 20260628120000
  928. 6.58 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 1_commit_pending_closure.sql (8.77ms)
  929. 6.60 s [niks3-go-unit-tests] 2026/07/19 09:28:44 OK 2_object_stats_trigger.sql (18.02ms)
  930. 6.60 s [niks3-go-unit-tests] 2026/07/19 09:28:44 goose: up to current file version: 2
  931. 6.70 s [niks3-go-unit-tests] === NAME TestClientWithDependencies
  932. 6.70 s [niks3-go-unit-tests] client_integration_test.go:593: Built derivation: /build/TestClientWithDependencies908467413/001/store/743saqd5nfr52pfv28aq2kr0rw6dy25w-test-script
  933. 6.72 s [niks3-go-unit-tests] client_integration_test.go:595: Found 1 dependencies (including self)
  934. 6.81 s [niks3-go-unit-tests] --- PASS: TestGCBugBareHashReferences (1.10s)
  935. 6.81 s [niks3-go-unit-tests] === CONT TestService_AuthMiddleware_MTLSProxyHeader
  936. 6.86 s [niks3-go-unit-tests] 2026-07-19 09:28:44.987 UTC [308] ERROR: relation "goose_db_version" does not exist at character 36
  937. 6.86 s [niks3-go-unit-tests] 2026-07-19 09:28:44.987 UTC [308] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  938. 6.86 s [niks3-go-unit-tests] 2026-07-19 09:28:44.990 UTC [311] ERROR: relation "goose_db_version" does not exist at character 36
  939. 6.86 s [niks3-go-unit-tests] 2026-07-19 09:28:44.990 UTC [311] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  940. 6.86 s [niks3-go-unit-tests] 2026-07-19 09:28:44.990 UTC [309] ERROR: relation "goose_db_version" does not exist at character 36
  941. 6.86 s [niks3-go-unit-tests] 2026-07-19 09:28:44.990 UTC [309] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  942. 6.86 s [niks3-go-unit-tests] 2026-07-19 09:28:44.990 UTC [310] ERROR: relation "goose_db_version" does not exist at character 36
  943. 6.86 s [niks3-go-unit-tests] 2026-07-19 09:28:44.990 UTC [310] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  944. 6.96 s [niks3-go-unit-tests] 2026/07/19 09:28:45 INFO Received uploads request method=POST path=/api/pending_closures
  945. 6.96 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20241026095416_initial_model.sql (86.09ms)
  946. 6.97 s [niks3-go-unit-tests] 2026/07/19 09:28:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)
  947. 6.97 s [niks3-go-unit-tests] 2026/07/19 09:28:45 INFO Uploading 743saqd5nfr52pfv28aq2kr0rw6dy25w-test-script (136B)
  948. 6.98 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20241026095416_initial_model.sql (22.04ms)
  949. 6.98 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20241026095416_initial_model.sql (22.17ms)
  950. 6.98 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20241026095416_initial_model.sql (22.11ms)
  951. 6.98 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20251210153512_drop_unused_gin_index.sql (15.52ms)
  952. 6.98 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20251218171726_add_pins.sql (7.29ms)
  953. 6.99 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20251210153512_drop_unused_gin_index.sql (14.73ms)
  954. 6.99 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20251210153512_drop_unused_gin_index.sql (14.89ms)
  955. 6.99 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20251210153512_drop_unused_gin_index.sql (14.62ms)
  956. 7.00 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20260628120000_add_object_size_and_stats.sql (18.12ms)
  957. 7.00 s [niks3-go-unit-tests] 2026/07/19 09:28:45 goose: successfully migrated database to version: 20260628120000
  958. 7.01 s [niks3-go-unit-tests] 2026-07-19 09:28:45.138 UTC [328] ERROR: relation "goose_db_version" does not exist at character 36
  959. 7.01 s [niks3-go-unit-tests] 2026-07-19 09:28:45.138 UTC [328] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  960. 7.01 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20251218171726_add_pins.sql (18.16ms)
  961. 7.01 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20251218171726_add_pins.sql (18.23ms)
  962. 7.01 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20251218171726_add_pins.sql (18.17ms)
  963. 7.02 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 1_commit_pending_closure.sql (13.86ms)
  964. 7.02 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20260628120000_add_object_size_and_stats.sql (10.43ms)
  965. 7.02 s [niks3-go-unit-tests] 2026/07/19 09:28:45 goose: successfully migrated database to version: 20260628120000
  966. 7.02 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20260628120000_add_object_size_and_stats.sql (10.49ms)
  967. 7.02 s [niks3-go-unit-tests] 2026/07/19 09:28:45 goose: successfully migrated database to version: 20260628120000
  968. 7.02 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20260628120000_add_object_size_and_stats.sql (10.45ms)
  969. 7.02 s [niks3-go-unit-tests] 2026/07/19 09:28:45 goose: successfully migrated database to version: 20260628120000
  970. 7.03 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 2_object_stats_trigger.sql (10.95ms)
  971. 7.03 s [niks3-go-unit-tests] 2026/07/19 09:28:45 goose: up to current file version: 2
  972. 7.03 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 1_commit_pending_closure.sql (10.3ms)
  973. 7.03 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 1_commit_pending_closure.sql (10.29ms)
  974. 7.03 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 1_commit_pending_closure.sql (10.39ms)
  975. 7.04 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20241026095416_initial_model.sql (14.75ms)
  976. 7.04 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 2_object_stats_trigger.sql (9.44ms)
  977. 7.04 s [niks3-go-unit-tests] 2026/07/19 09:28:45 goose: up to current file version: 2
  978. 7.04 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 2_object_stats_trigger.sql (9.43ms)
  979. 7.04 s [niks3-go-unit-tests] 2026/07/19 09:28:45 goose: up to current file version: 2
  980. 7.04 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 2_object_stats_trigger.sql (9.46ms)
  981. 7.04 s [niks3-go-unit-tests] 2026/07/19 09:28:45 goose: up to current file version: 2
  982. 7.04 s [niks3-go-unit-tests] 2026-07-19 09:28:45.171 UTC [329] ERROR: relation "goose_db_version" does not exist at character 36
  983. 7.04 s [niks3-go-unit-tests] 2026-07-19 09:28:45.171 UTC [329] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  984. 7.05 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20251210153512_drop_unused_gin_index.sql (9.38ms)
  985. 7.05 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20251218171726_add_pins.sql (9.09ms)
  986. 7.06 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20241026095416_initial_model.sql (11.47ms)
  987. 7.07 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20260628120000_add_object_size_and_stats.sql (11.52ms)
  988. 7.07 s [niks3-go-unit-tests] 2026/07/19 09:28:45 goose: successfully migrated database to version: 20260628120000
  989. 7.07 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20251210153512_drop_unused_gin_index.sql (8.79ms)
  990. 7.08 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 1_commit_pending_closure.sql (8.93ms)
  991. 7.08 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20251218171726_add_pins.sql (8.89ms)
  992. 7.08 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 2_object_stats_trigger.sql (9.08ms)
  993. 7.08 s [niks3-go-unit-tests] 2026/07/19 09:28:45 goose: up to current file version: 2
  994. 7.09 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 20260628120000_add_object_size_and_stats.sql (9.08ms)
  995. 7.09 s [niks3-go-unit-tests] 2026/07/19 09:28:45 goose: successfully migrated database to version: 20260628120000
  996. 7.09 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 1_commit_pending_closure.sql (4.61ms)
  997. 7.10 s [niks3-go-unit-tests] 2026/07/19 09:28:45 OK 2_object_stats_trigger.sql (3.92ms)
  998. 7.10 s [niks3-go-unit-tests] 2026/07/19 09:28:45 goose: up to current file version: 2
  999. 7.70 s [niks3-go-unit-tests] 2026/07/19 09:28:45 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"
  1000. 7.71 s [niks3-go-unit-tests] 2026/07/19 09:28:45 WARN mTLS auth: bound subjects configured but subject DN unavailable
  1001. 7.71 s [niks3-go-unit-tests] 2026/07/19 09:28:45 INFO Created nix-cache-info in bucket bucket=bucket7
  1002. 7.71 s [niks3-go-unit-tests] 2026/07/19 09:28:45 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"
  1003. 7.71 s [niks3-go-unit-tests] --- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.22s)
  1004. 7.71 s [niks3-go-unit-tests] === CONT TestUploadHandlersRejectInvalidKeys
  1005. 7.71 s [niks3-go-unit-tests] === RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info
  1006. 7.71 s [niks3-go-unit-tests] === PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info
  1007. 7.71 s [niks3-go-unit-tests] === RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal
  1008. 7.71 s [niks3-go-unit-tests] === PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal
  1009. 7.71 s [niks3-go-unit-tests] === RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key
  1010. 7.71 s [niks3-go-unit-tests] === PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key
  1011. 7.71 s [niks3-go-unit-tests] === RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key
  1012. 7.71 s [niks3-go-unit-tests] === PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key
  1013. 7.71 s [niks3-go-unit-tests] === CONT TestCreatePendingClosure_SmallNARUsesSimplePUT
  1014. 7.71 s [niks3-go-unit-tests] 2026/07/19 09:28:45 WARN mTLS auth: subject not in bound subjects subject="CN=writer"
  1015. 7.71 s [niks3-go-unit-tests] --- PASS: TestService_ReadAuthMiddleware (1.14s)
  1016. 7.71 s [niks3-go-unit-tests] === CONT TestCompleteMultipartUnregistered
  1017. 7.71 s [niks3-go-unit-tests] === RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token
  1018. 7.71 s [niks3-go-unit-tests] === PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token
  1019. 7.71 s [niks3-go-unit-tests] === RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected
  1020. 7.71 s [niks3-go-unit-tests] === PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected
  1021. 7.71 s [niks3-go-unit-tests] === RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected
  1022. 7.71 s [niks3-go-unit-tests] === PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected
  1023. 7.71 s [niks3-go-unit-tests] === RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured
  1024. 7.71 s [niks3-go-unit-tests] === PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured
  1025. 7.71 s [niks3-go-unit-tests] === CONT TestService_verifyS3Integrity
  1026. 7.71 s [niks3-go-unit-tests] --- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.90s)
  1027. 7.71 s [niks3-go-unit-tests] === CONT TestService_createPendingClosureHandler
  1028. 7.71 s [niks3-go-unit-tests] 2026/07/19 09:28:45 INFO Created nix-cache-info in bucket bucket=bucket14
  1029. 7.71 s [niks3-go-unit-tests] 2026/07/19 09:28:45 INFO Created nix-cache-info in bucket bucket=bucket13
  1030. 7.71 s [niks3-go-unit-tests] 2026/07/19 09:28:45 INFO Created nix-cache-info in bucket bucket=bucket18
  1031. 7.71 s [niks3-go-unit-tests] --- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.00s)
  1032. 7.71 s [niks3-go-unit-tests] === CONT TestService_cleanupPendingClosuresHandler
  1033. 7.71 s [niks3-go-unit-tests] 2026/07/19 09:28:45 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign
  1034. 7.71 s [niks3-go-unit-tests] 2026/07/19 09:28:45 INFO Signed narinfos id=1 count=1
  1035. 7.71 s [niks3-go-unit-tests] 2026/07/19 09:28:45 INFO Uploading 1 narinfos
  1036. 7.71 s [niks3-go-unit-tests] 2026/07/19 09:28:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete
  1037. 7.73 s [niks3-go-unit-tests] 2026/07/19 09:28:45 INFO Completed upload id=1
  1038. 7.73 s [niks3-go-unit-tests] 2026/07/19 09:28:45 INFO Upload complete. (801ms)
  1039. 7.73 s [niks3-go-unit-tests] === NAME TestClientWithDependencies
  1040. 7.73 s [niks3-go-unit-tests] client_integration_test.go:597: Skipping nix copy test - isolated store (/build/TestClientWithDependencies908467413/001/store) requires matching store prefix
  1041. 7.73 s [niks3-go-unit-tests] --- PASS: TestClientWithDependencies (2.03s)
  1042. 7.73 s [niks3-go-unit-tests] === CONT TestUploadHandlersRejectOversizedBody
  1043. 7.82 s [niks3-go-unit-tests] --- PASS: TestResurrectedObjectNotDeleted (2.12s)
  1044. 7.82 s [niks3-go-unit-tests] === CONT TestReadProxyConditionalGet
  1045. 7.82 s [niks3-go-unit-tests] --- PASS: TestCacheStatsHandler (1.35s)
  1046. 7.83 s [niks3-go-unit-tests] === CONT TestReadProxyDisabled
  1047. 7.95 s [niks3-go-unit-tests] === NAME TestClientMultipleUploads
  1048. 7.95 s [niks3-go-unit-tests] client_integration_test.go:338: Created store path 0: /build/TestClientMultipleUploads2768985259/001/store/s7iy7ap2nhfksivdmph8528z35qf3wsc-test-file-0.txt
  1049. 7.95 s [niks3-go-unit-tests] === NAME TestClientCADerivations
  1050. 7.95 s [niks3-go-unit-tests] client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations4084360560/001/store/620h9k381hy5dz3hiqlqqi2f85fw6cm5-ca-test
  1051. 7.95 s [niks3-go-unit-tests] === NAME TestClientIntegration
  1052. 7.95 s [niks3-go-unit-tests] client_integration_test.go:276: Created store path: /build/TestClientIntegration180693984/002/store/wnz7dv6hyl9d3yxpvzqkc35gba22q5zq-test-file.txt
  1053. 7.97 s [niks3-go-unit-tests] === NAME TestClientCADerivations
  1054. 7.97 s [niks3-go-unit-tests] client_ca_test.go:139: Found 1 dependencies (including self)
  1055. 8.00 s [niks3-go-unit-tests] 2026-07-19 09:28:46.126 UTC [513] ERROR: relation "goose_db_version" does not exist at character 36
  1056. 8.00 s [niks3-go-unit-tests] 2026-07-19 09:28:46.126 UTC [513] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1057. 8.02 s [niks3-go-unit-tests] === RUN TestUploadHandlersRejectOversizedBody/create_pending_closure
  1058. 8.02 s [niks3-go-unit-tests] === PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure
  1059. 8.02 s [niks3-go-unit-tests] === RUN TestUploadHandlersRejectOversizedBody/complete_multipart
  1060. 8.02 s [niks3-go-unit-tests] === PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart
  1061. 8.02 s [niks3-go-unit-tests] === RUN TestUploadHandlersRejectOversizedBody/request_more_parts
  1062. 8.02 s [niks3-go-unit-tests] === PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts
  1063. 8.02 s [niks3-go-unit-tests] === CONT TestReadProxyRootRedirectsToIndexHTML
  1064. 8.02 s [niks3-go-unit-tests] 2026-07-19 09:28:46.147 UTC [518] ERROR: relation "goose_db_version" does not exist at character 36
  1065. 8.02 s [niks3-go-unit-tests] 2026-07-19 09:28:46.147 UTC [518] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1066. 8.03 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20241026095416_initial_model.sql (19.09ms)
  1067. 8.05 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received uploads request method=POST path=/api/pending_closures
  1068. 8.05 s [niks3-go-unit-tests] === NAME TestClientMultipleUploads
  1069. 8.05 s [niks3-go-unit-tests] client_integration_test.go:338: Created store path 1: /build/TestClientMultipleUploads2768985259/001/store/d1lay1jikgc1rzghcmpwyza5qbvsy6q1-test-file-1.txt
  1070. 8.05 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20251210153512_drop_unused_gin_index.sql (18.78ms)
  1071. 8.05 s [niks3-go-unit-tests] === NAME TestPinProtectsFromGC
  1072. 8.05 s [niks3-go-unit-tests] client_integration_test.go:646: Pinned store path: /build/TestPinProtectsFromGC2941841318/001/store/c21ld1yp3gmj7aw6q7lifwi6iq5kj8cm-pinned-file.txt
  1073. 8.05 s [niks3-go-unit-tests] client_integration_test.go:647: Unpinned store path: /build/TestPinProtectsFromGC2941841318/001/store/biffan3mgjhxs08hdji13zcs9na5kang-unpinned-file.txt
  1074. 8.06 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20241026095416_initial_model.sql (15.91ms)
  1075. 8.06 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)
  1076. 8.06 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Uploading 620h9k381hy5dz3hiqlqqi2f85fw6cm5-ca-test (144B)
  1077. 8.06 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign
  1078. 8.06 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Signed narinfos id=1 count=1
  1079. 8.06 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Uploading 1 narinfos
  1080. 8.06 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete
  1081. 8.07 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20251218171726_add_pins.sql (16.04ms)
  1082. 8.07 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20251210153512_drop_unused_gin_index.sql (14.48ms)
  1083. 8.08 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20260628120000_add_object_size_and_stats.sql (16.31ms)
  1084. 8.08 s [niks3-go-unit-tests] 2026/07/19 09:28:46 goose: successfully migrated database to version: 20260628120000
  1085. 8.08 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Completed upload id=1
  1086. 8.08 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Upload complete. (85ms)
  1087. 8.08 s [niks3-go-unit-tests] === NAME TestClientCADerivations
  1088. 8.08 s [niks3-go-unit-tests] client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations4084360560/001/store/620h9k381hy5dz3hiqlqqi2f85fw6cm5-ca-test
  1089. 8.08 s [niks3-go-unit-tests] URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst
  1090. 8.08 s [niks3-go-unit-tests] Compression: zstd
  1091. 8.08 s [niks3-go-unit-tests] NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n
  1092. 8.09 s [niks3-go-unit-tests] NarSize: 144
  1093. 8.09 s [niks3-go-unit-tests] References:
  1094. 8.09 s [niks3-go-unit-tests] Deriver: /build/TestClientCADerivations4084360560/001/store/h3kgm6409yx69mfkxmqiwgir0qzg908v-ca-test.drv
  1095. 8.09 s [niks3-go-unit-tests] CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n
  1096. 8.09 s [niks3-go-unit-tests] client_ca_test.go:185: Checking for realisation files in S3...
  1097. 8.09 s [niks3-go-unit-tests] client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations
  1098. 8.09 s [niks3-go-unit-tests] client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache
  1099. 8.09 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20251218171726_add_pins.sql (13.42ms)
  1100. 8.10 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 1_commit_pending_closure.sql (11.21ms)
  1101. 8.10 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20260628120000_add_object_size_and_stats.sql (13.91ms)
  1102. 8.10 s [niks3-go-unit-tests] 2026/07/19 09:28:46 goose: successfully migrated database to version: 20260628120000
  1103. 8.11 s [niks3-go-unit-tests] client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features
  1104. 8.11 s [niks3-go-unit-tests] warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable
  1105. 8.11 s [niks3-go-unit-tests] error: binary cache 's3://bucket18?endpoint=http://localhost:33129&region=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations4084360560/001/store'
  1106. 8.11 s [niks3-go-unit-tests] client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 1
  1107. 8.11 s [niks3-go-unit-tests] --- PASS: TestClientCADerivations (1.64s)
  1108. 8.11 s [niks3-go-unit-tests] === CONT TestReadProxyInvalidPath
  1109. 8.11 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 2_object_stats_trigger.sql (16.46ms)
  1110. 8.11 s [niks3-go-unit-tests] 2026/07/19 09:28:46 goose: up to current file version: 2
  1111. 8.11 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received uploads request method=POST path=/api/pending_closures
  1112. 8.12 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 1_commit_pending_closure.sql (17.48ms)
  1113. 8.14 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 2_object_stats_trigger.sql (15.82ms)
  1114. 8.14 s [niks3-go-unit-tests] 2026/07/19 09:28:46 goose: up to current file version: 2
  1115. 8.14 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received uploads request method=POST path=/api/pending_closures
  1116. 8.14 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received uploads request method=POST path=/api/pending_closures
  1117. 8.14 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received uploads request method=POST path=/api/pending_closures
  1118. 8.15 s [niks3-go-unit-tests] === NAME TestClientMultipleUploads
  1119. 8.15 s [niks3-go-unit-tests] client_integration_test.go:338: Created store path 2: /build/TestClientMultipleUploads2768985259/001/store/zgn39v4pzxbjrsdlb274nxsdcmfzfcyd-test-file-2.txt
  1120. 8.15 s [niks3-go-unit-tests] --- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.45s)
  1121. 8.15 s [niks3-go-unit-tests] === CONT TestReadProxyHead
  1122. 8.15 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received uploads request method=POST path=/api/pending_closures
  1123. 8.16 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)
  1124. 8.16 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Uploading wnz7dv6hyl9d3yxpvzqkc35gba22q5zq-test-file.txt (152B)
  1125. 8.16 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign
  1126. 8.16 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Signed narinfos id=1 count=1
  1127. 8.16 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Uploading 1 narinfos
  1128. 8.16 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete
  1129. 8.18 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Completed upload id=1
  1130. 8.18 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Upload complete. (200ms)
  1131. 8.18 s [niks3-go-unit-tests] === NAME TestClientIntegration
  1132. 8.18 s [niks3-go-unit-tests] client_integration_test.go:292: Retrieved narinfo from S3:
  1133. 8.18 s [niks3-go-unit-tests] StorePath: /build/TestClientIntegration180693984/002/store/wnz7dv6hyl9d3yxpvzqkc35gba22q5zq-test-file.txt
  1134. 8.18 s [niks3-go-unit-tests] URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst
  1135. 8.18 s [niks3-go-unit-tests] Compression: zstd
  1136. 8.18 s [niks3-go-unit-tests] NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1
  1137. 8.18 s [niks3-go-unit-tests] NarSize: 152
  1138. 8.18 s [niks3-go-unit-tests] References:
  1139. 8.18 s [niks3-go-unit-tests] CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1
  1140. 8.18 s [niks3-go-unit-tests] client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)
  1141. 8.18 s [niks3-go-unit-tests] client_integration_test.go:293: Decompressed .ls content (64 bytes):
  1142. 8.18 s [niks3-go-unit-tests] {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}
  1143. 8.18 s [niks3-go-unit-tests] client_integration_test.go:296: Testing garbage collection...
  1144. 8.20 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Starting cleanup of old closures method=DELETE path=/api/closures
  1145. 8.20 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Garbage collection started
  1146. 8.21 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received uploads request method=POST path=/api/pending_closures
  1147. 8.23 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)
  1148. 8.23 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Uploading c21ld1yp3gmj7aw6q7lifwi6iq5kj8cm-pinned-file.txt (128B)
  1149. 8.23 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign
  1150. 8.23 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Signed narinfos id=1 count=1
  1151. 8.23 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Uploading 1 narinfos
  1152. 8.23 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete
  1153. 8.24 s [niks3-go-unit-tests] 2026-07-19 09:28:46.371 UTC [570] ERROR: relation "goose_db_version" does not exist at character 36
  1154. 8.24 s [niks3-go-unit-tests] 2026-07-19 09:28:46.371 UTC [570] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1155. 8.24 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Completed upload id=1
  1156. 8.24 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Upload complete. (163ms)
  1157. 8.28 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20241026095416_initial_model.sql (15.26ms)
  1158. 8.30 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete
  1159. 8.32 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received uploads request method=POST path=/api/pending_closures
  1160. 8.32 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received uploads request method=POST path=/api/pending_closures
  1161. 8.32 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Aborted multipart uploads count=0
  1162. 8.35 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20251210153512_drop_unused_gin_index.sql (66.36ms)
  1163. 8.35 s [niks3-go-unit-tests] 2026-07-19 09:28:46.475 UTC [569] ERROR: relation "goose_db_version" does not exist at character 36
  1164. 8.35 s [niks3-go-unit-tests] 2026-07-19 09:28:46.475 UTC [569] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1165. 8.36 s [niks3-go-unit-tests] 2026/07/19 09:28:46 WARN Force mode enabled - objects will be deleted immediately without grace period
  1166. 8.36 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)
  1167. 8.36 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Uploading biffan3mgjhxs08hdji13zcs9na5kang-unpinned-file.txt (128B)
  1168. 8.36 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign
  1169. 8.37 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Signed narinfos id=2 count=1
  1170. 8.37 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Uploading 1 narinfos
  1171. 8.37 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete
  1172. 8.37 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20251218171726_add_pins.sql (23.78ms)
  1173. 8.37 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received uploads request method=POST path=/api/pending_closures
  1174. 8.37 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=OGE3NmQ0N2YtMzQ4MC00YzA2LWJiMDUtN2YyODU2MjFjODA2Ljg5OWYzYzU1LTMwMjQtNDFkNC1hYWEzLTBiMDIwNzg0YzA3MngxNzg0NDUzMzI2Mjg0NDI2OTk3 parts=10
  1175. 8.37 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete
  1176. 8.38 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Completed upload id=2
  1177. 8.38 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Upload complete. (108ms)
  1178. 8.39 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20260628120000_add_object_size_and_stats.sql (16.88ms)
  1179. 8.39 s [niks3-go-unit-tests] 2026/07/19 09:28:46 goose: successfully migrated database to version: 20260628120000
  1180. 8.39 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Completed upload id=1
  1181. 8.39 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000
  1182. 8.39 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received uploads request method=POST path=/api/pending_closures
  1183. 8.39 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received uploads request method=POST path=/api/pending_closures
  1184. 8.40 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20241026095416_initial_model.sql (17.54ms)
  1185. 8.40 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 1_commit_pending_closure.sql (15.96ms)
  1186. 8.40 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Starting cleanup of old closures method=DELETE path=/api/closures
  1187. 8.40 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)
  1188. 8.40 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Uploading d1lay1jikgc1rzghcmpwyza5qbvsy6q1-test-file-1.txt (160B)
  1189. 8.40 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Uploading zgn39v4pzxbjrsdlb274nxsdcmfzfcyd-test-file-2.txt (160B)
  1190. 8.40 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Uploading s7iy7ap2nhfksivdmph8528z35qf3wsc-test-file-0.txt (160B)
  1191. 8.40 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received create pin request method=POST path=/api/pins/myapp
  1192. 8.41 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign
  1193. 8.41 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Signed narinfos id=1 count=1
  1194. 8.41 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign
  1195. 8.41 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Signed narinfos id=2 count=1
  1196. 8.41 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign
  1197. 8.41 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Signed narinfos id=3 count=1
  1198. 8.41 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Uploading 3 narinfos
  1199. 8.41 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete
  1200. 8.41 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20251210153512_drop_unused_gin_index.sql (15.37ms)
  1201. 8.42 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 2_object_stats_trigger.sql (16.91ms)
  1202. 8.42 s [niks3-go-unit-tests] 2026/07/19 09:28:46 goose: up to current file version: 2
  1203. 8.42 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2941841318/001/store/c21ld1yp3gmj7aw6q7lifwi6iq5kj8cm-pinned-file.txt narinfo_key=c21ld1yp3gmj7aw6q7lifwi6iq5kj8cm.narinfo
  1204. 8.42 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Starting cleanup of old closures method=DELETE path=/api/closures
  1205. 8.42 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Garbage collection started
  1206. 8.42 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete
  1207. 8.42 s [niks3-go-unit-tests] 2026/07/19 09:28:46 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst
  1208. 8.42 s [niks3-go-unit-tests] --- PASS: TestCompleteMultipartUnregistered (0.72s)
  1209. 8.42 s [niks3-go-unit-tests] === CONT TestService_Rustfstest
  1210. 8.43 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20251218171726_add_pins.sql (15.59ms)
  1211. 8.43 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Completed upload id=1
  1212. 8.43 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete
  1213. 8.44 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Completed upload id=2
  1214. 8.44 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20260628120000_add_object_size_and_stats.sql (8.84ms)
  1215. 8.44 s [niks3-go-unit-tests] 2026/07/19 09:28:46 goose: successfully migrated database to version: 20260628120000
  1216. 8.44 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete
  1217. 8.45 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Completed upload id=3
  1218. 8.45 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 1_commit_pending_closure.sql (17.75ms)
  1219. 8.45 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Upload complete. (287ms)
  1220. 8.45 s [niks3-go-unit-tests] === NAME TestClientMultipleUploads
  1221. 8.45 s [niks3-go-unit-tests] client_integration_test.go:349: Uploaded 3 paths in 308.712122ms
  1222. 8.46 s [niks3-go-unit-tests] --- PASS: TestClientMultipleUploads (2.75s)
  1223. 8.46 s [niks3-go-unit-tests] === CONT TestIsValidUploadKey
  1224. 8.46 s [niks3-go-unit-tests] === RUN TestIsValidUploadKey/narinfo
  1225. 8.46 s [niks3-go-unit-tests] === PAUSE TestIsValidUploadKey/narinfo
  1226. 8.46 s [niks3-go-unit-tests] === RUN TestIsValidUploadKey/nar_zst
  1227. 8.46 s [niks3-go-unit-tests] === PAUSE TestIsValidUploadKey/nar_zst
  1228. 8.46 s [niks3-go-unit-tests] === RUN TestIsValidUploadKey/nar_xz
  1229. 8.46 s [niks3-go-unit-tests] === PAUSE TestIsValidUploadKey/nar_xz
  1230. 8.46 s [niks3-go-unit-tests] === RUN TestIsValidUploadKey/nar_plain
  1231. 8.46 s [niks3-go-unit-tests] === PAUSE TestIsValidUploadKey/nar_plain
  1232. 8.46 s [niks3-go-unit-tests] === RUN TestIsValidUploadKey/listing
  1233. 8.46 s [niks3-go-unit-tests] === PAUSE TestIsValidUploadKey/listing
  1234. 8.46 s [niks3-go-unit-tests] === RUN TestIsValidUploadKey/build_log
  1235. 8.46 s [niks3-go-unit-tests] === PAUSE TestIsValidUploadKey/build_log
  1236. 8.46 s [niks3-go-unit-tests] === RUN TestIsValidUploadKey/build_log_home-manager_file
  1237. 8.46 s [niks3-go-unit-tests] === PAUSE TestIsValidUploadKey/build_log_home-manager_file
  1238. 8.46 s [niks3-go-unit-tests] === RUN TestIsValidUploadKey/build_log_plus_in_name
  1239. 8.46 s [niks3-go-unit-tests] === PAUSE TestIsValidUploadKey/build_log_plus_in_name
  1240. 8.46 s [niks3-go-unit-tests] === RUN TestIsValidUploadKey/build_log_question_mark
  1241. 8.46 s [niks3-go-unit-tests] === PAUSE TestIsValidUploadKey/build_log_question_mark
  1242. 8.46 s [niks3-go-unit-tests] === RUN TestIsValidUploadKey/build_log_equals
  1243. 8.46 s [niks3-go-unit-tests] === PAUSE TestIsValidUploadKey/build_log_equals
  1244. 8.46 s [niks3-go-unit-tests] === RUN TestIsValidUploadKey/realisation
  1245. 8.46 s [niks3-go-unit-tests] === PAUSE TestIsValidUploadKey/realisation
  1246. 8.46 s [niks3-go-unit-tests] === RUN TestIsValidUploadKey/realisation_plus_in_output
  1247. 8.46 s [niks3-go-unit-tests] === PAUSE TestIsValidUploadKey/realisation_plus_in_output
  1248. 8.46 s [niks3-go-unit-tests] === RUN TestIsValidUploadKey/nix-cache-info
  1249. 8.46 s [niks3-go-unit-tests] === PAUSE TestIsValidUploadKey/nix-cache-info
  1250. 8.46 s [niks3-go-unit-tests] === RUN TestIsValidUploadKey/index.html
  1251. 8.46 s [niks3-go-unit-tests] === PAUSE TestIsValidUploadKey/index.html
  1252. 8.46 s [niks3-go-unit-tests] === RUN TestIsValidUploadKey/narinfo_key,_nar_type
  1253. 8.46 s [niks3-go-unit-tests] === PAUSE TestIsValidUploadKey/narinfo_key,_nar_type
  1254. 8.46 s [niks3-go-unit-tests] === RUN TestIsValidUploadKey/nar_key,_narinfo_type
  1255. 8.46 s [niks3-go-unit-tests] === PAUSE TestIsValidUploadKey/nar_key,_narinfo_type
  1256. 8.46 s [niks3-go-unit-tests] === RUN TestIsValidUploadKey/listing_key,_narinfo_type
  1257. 8.46 s [niks3-go-unit-tests] === PAUSE TestIsValidUploadKey/listing_key,_narinfo_type
  1258. 8.46 s [niks3-go-unit-tests] === RUN TestIsValidUploadKey/traversal
  1259. 8.46 s [niks3-go-unit-tests] === PAUSE TestIsValidUploadKey/traversal
  1260. 8.46 s [niks3-go-unit-tests] === RUN TestIsValidUploadKey/traversal_nar
  1261. 8.46 s [niks3-go-unit-tests] === PAUSE TestIsValidUploadKey/traversal_nar
  1262. 8.46 s [niks3-go-unit-tests] === RUN TestIsValidUploadKey/absolute
  1263. 8.46 s [niks3-go-unit-tests] === PAUSE TestIsValidUploadKey/absolute
  1264. 8.46 s [niks3-go-unit-tests] === RUN TestIsValidUploadKey/empty_key
  1265. 8.46 s [niks3-go-unit-tests] === PAUSE TestIsValidUploadKey/empty_key
  1266. 8.46 s [niks3-go-unit-tests] === RUN TestIsValidUploadKey/unknown_type
  1267. 8.46 s [niks3-go-unit-tests] === PAUSE TestIsValidUploadKey/unknown_type
  1268. 8.46 s [niks3-go-unit-tests] === CONT TestProxyWriteTimeout
  1269. 8.46 s [niks3-go-unit-tests] === RUN TestProxyWriteTimeout/narinfo
  1270. 8.46 s [niks3-go-unit-tests] === PAUSE TestProxyWriteTimeout/narinfo
  1271. 8.46 s [niks3-go-unit-tests] === RUN TestProxyWriteTimeout/1_GiB_nar
  1272. 8.46 s [niks3-go-unit-tests] === PAUSE TestProxyWriteTimeout/1_GiB_nar
  1273. 8.46 s [niks3-go-unit-tests] === RUN TestProxyWriteTimeout/10_GiB_nar
  1274. 8.46 s [niks3-go-unit-tests] === PAUSE TestProxyWriteTimeout/10_GiB_nar
  1275. 8.46 s [niks3-go-unit-tests] === RUN TestProxyWriteTimeout/unknown_size
  1276. 8.46 s [niks3-go-unit-tests] === PAUSE TestProxyWriteTimeout/unknown_size
  1277. 8.46 s [niks3-go-unit-tests] === CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle
  1278. 8.47 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 2_object_stats_trigger.sql (14.82ms)
  1279. 8.47 s [niks3-go-unit-tests] 2026/07/19 09:28:46 goose: up to current file version: 2
  1280. 8.47 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received uploads request method=POST path=/api/pending_closures
  1281. 8.49 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Aborted multipart uploads count=0
  1282. 8.49 s [niks3-go-unit-tests] 2026-07-19 09:28:46.615 UTC [782] ERROR: relation "goose_db_version" does not exist at character 36
  1283. 8.49 s [niks3-go-unit-tests] 2026-07-19 09:28:46.615 UTC [782] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1284. 8.49 s [niks3-go-unit-tests] 2026-07-19 09:28:46.615 UTC [784] ERROR: relation "goose_db_version" does not exist at character 36
  1285. 8.49 s [niks3-go-unit-tests] 2026-07-19 09:28:46.615 UTC [784] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1286. 8.49 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Aborted multipart uploads count=0
  1287. 8.49 s [niks3-go-unit-tests] 2026-07-19 09:28:46.616 UTC [780] ERROR: relation "goose_db_version" does not exist at character 36
  1288. 8.49 s [niks3-go-unit-tests] 2026-07-19 09:28:46.616 UTC [780] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1289. 8.50 s [niks3-go-unit-tests] 2026/07/19 09:28:46 WARN Force mode enabled - objects will be deleted immediately without grace period
  1290. 8.50 s [niks3-go-unit-tests] 2026-07-19 09:28:46.630 UTC [805] ERROR: relation "goose_db_version" does not exist at character 36
  1291. 8.50 s [niks3-go-unit-tests] 2026-07-19 09:28:46.630 UTC [805] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1292. 8.57 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20241026095416_initial_model.sql (63.83ms)
  1293. 8.57 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20241026095416_initial_model.sql (63.99ms)
  1294. 8.57 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=0
  1295. 8.58 s [niks3-go-unit-tests] === NAME TestOrphanedObjectsGC
  1296. 8.58 s [niks3-go-unit-tests] orphaned_objects_gc_test.go:290: GC Test Summary:
  1297. 8.58 s [niks3-go-unit-tests] orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A
  1298. 8.58 s [niks3-go-unit-tests] orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B
  1299. 8.58 s [niks3-go-unit-tests] orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)
  1300. 8.58 s [niks3-go-unit-tests] orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)
  1301. 8.58 s [niks3-go-unit-tests] orphaned_objects_gc_test.go:295: - Total deleted: 10 objects
  1302. 8.58 s [niks3-go-unit-tests] --- PASS: TestOrphanedObjectsGC (2.19s)
  1303. 8.58 s [niks3-go-unit-tests] === CONT TestReadProxy404
  1304. 8.59 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20251210153512_drop_unused_gin_index.sql (18.09ms)
  1305. 8.59 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Vacuumed table table=pending_closures
  1306. 8.59 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20241026095416_initial_model.sql (84.61ms)
  1307. 8.59 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20251210153512_drop_unused_gin_index.sql (20.35ms)
  1308. 8.60 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20241026095416_initial_model.sql (17.1ms)
  1309. 8.61 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20251218171726_add_pins.sql (14.98ms)
  1310. 8.61 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Vacuumed table table=pending_objects
  1311. 8.61 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20251218171726_add_pins.sql (15.14ms)
  1312. 8.61 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20251210153512_drop_unused_gin_index.sql (15.15ms)
  1313. 8.61 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20251210153512_drop_unused_gin_index.sql (16.21ms)
  1314. 8.62 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20260628120000_add_object_size_and_stats.sql (16.61ms)
  1315. 8.62 s [niks3-go-unit-tests] 2026/07/19 09:28:46 goose: successfully migrated database to version: 20260628120000
  1316. 8.62 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20251218171726_add_pins.sql (16.59ms)
  1317. 8.62 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20260628120000_add_object_size_and_stats.sql (16.66ms)
  1318. 8.62 s [niks3-go-unit-tests] 2026/07/19 09:28:46 goose: successfully migrated database to version: 20260628120000
  1319. 8.63 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20251218171726_add_pins.sql (12.52ms)
  1320. 8.63 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete
  1321. 8.63 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 1_commit_pending_closure.sql (7.44ms)
  1322. 8.63 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20260628120000_add_object_size_and_stats.sql (7.39ms)
  1323. 8.63 s [niks3-go-unit-tests] 2026/07/19 09:28:46 goose: successfully migrated database to version: 20260628120000
  1324. 8.63 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 1_commit_pending_closure.sql (7.34ms)
  1325. 8.63 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Vacuumed table table=multipart_uploads
  1326. 8.64 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20260628120000_add_object_size_and_stats.sql (12.4ms)
  1327. 8.64 s [niks3-go-unit-tests] 2026/07/19 09:28:46 goose: successfully migrated database to version: 20260628120000
  1328. 8.65 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 2_object_stats_trigger.sql (15.81ms)
  1329. 8.65 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 2_object_stats_trigger.sql (15.86ms)
  1330. 8.65 s [niks3-go-unit-tests] 2026/07/19 09:28:46 goose: up to current file version: 2
  1331. 8.65 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 1_commit_pending_closure.sql (15.84ms)
  1332. 8.65 s [niks3-go-unit-tests] 2026/07/19 09:28:46 goose: up to current file version: 2
  1333. 8.65 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received cleanup request method=DELETE path=/api/pending_closures
  1334. 8.65 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Aborted multipart uploads count=0
  1335. 8.65 s [niks3-go-unit-tests] --- PASS: TestReadProxyRootRedirectsToIndexHTML (0.63s)
  1336. 8.65 s [niks3-go-unit-tests] === CONT TestService_healthCheckHandler
  1337. 8.65 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received uploads request method=POST path=/api/pending_closures
  1338. 8.65 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 1_commit_pending_closure.sql (14.44ms)
  1339. 8.66 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 2_object_stats_trigger.sql (18.2ms)
  1340. 8.66 s [niks3-go-unit-tests] 2026/07/19 09:28:46 goose: up to current file version: 2
  1341. 8.66 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Vacuumed table table=closures
  1342. 8.66 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=OGE3NmQ0N2YtMzQ4MC00YzA2LWJiMDUtN2YyODU2MjFjODA2LjYzNDgzNWQ2LTU3OTktNGNjMS1iMzIyLTllMjY5N2IzZGY3ZHgxNzg0NDUzMzI2NjE3MjI2MzUy parts=10
  1343. 8.66 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete
  1344. 8.67 s [niks3-go-unit-tests] --- PASS: TestReadProxyDisabled (0.84s)
  1345. 8.67 s [niks3-go-unit-tests] === CONT TestMultipartCleanup
  1346. 8.67 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 2_object_stats_trigger.sql (17.82ms)
  1347. 8.67 s [niks3-go-unit-tests] 2026/07/19 09:28:46 goose: up to current file version: 2
  1348. 8.68 s [niks3-go-unit-tests] 2026-07-19 09:28:46.807 UTC [809] ERROR: relation "goose_db_version" does not exist at character 36
  1349. 8.68 s [niks3-go-unit-tests] 2026-07-19 09:28:46.807 UTC [809] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1350. 8.68 s [niks3-go-unit-tests] 2026-07-19 09:28:46.808 UTC [808] ERROR: relation "goose_db_version" does not exist at character 36
  1351. 8.68 s [niks3-go-unit-tests] 2026-07-19 09:28:46.808 UTC [808] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1352. 8.68 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Completed upload id=1
  1353. 8.68 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Vacuumed table table=objects
  1354. 8.68 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received cleanup request method=DELETE path=/api/pending_closures
  1355. 8.68 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received uploads request method=POST path=/api/pending_closures
  1356. 8.68 s [niks3-go-unit-tests] --- PASS: TestReadProxyConditionalGet (0.86s)
  1357. 8.68 s [niks3-go-unit-tests] === CONT TestServerTLSConfig
  1358. 8.68 s [niks3-go-unit-tests] === RUN TestServerTLSConfig/no_client_CA
  1359. 8.68 s [niks3-go-unit-tests] === PAUSE TestServerTLSConfig/no_client_CA
  1360. 8.68 s [niks3-go-unit-tests] === RUN TestServerTLSConfig/missing_CA_file
  1361. 8.68 s [niks3-go-unit-tests] === PAUSE TestServerTLSConfig/missing_CA_file
  1362. 8.68 s [niks3-go-unit-tests] === RUN TestServerTLSConfig/not_a_PEM_file
  1363. 8.68 s [niks3-go-unit-tests] === PAUSE TestServerTLSConfig/not_a_PEM_file
  1364. 8.68 s [niks3-go-unit-tests] === CONT TestService_NativeMTLS
  1365. 8.68 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Aborted multipart uploads count=1
  1366. 8.70 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received uploads request method=POST path=/api/pending_closures
  1367. 8.70 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete
  1368. 8.70 s [niks3-go-unit-tests] 2026-07-19 09:28:46.827 UTC [780] ERROR: Closure does not exist: id=1
  1369. 8.70 s [niks3-go-unit-tests] 2026-07-19 09:28:46.827 UTC [780] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE
  1370. 8.70 s [niks3-go-unit-tests] 2026-07-19 09:28:46.827 UTC [780] STATEMENT: -- name: CommitPendingClosure :exec
  1371. 8.70 s [niks3-go-unit-tests] SELECT commit_pending_closure($1::bigint)
  1372. 8.70 s [niks3-go-unit-tests]
  1373. 8.70 s [niks3-go-unit-tests] --- PASS: TestService_cleanupPendingClosuresHandler (0.99s)
  1374. 8.70 s [niks3-go-unit-tests] === CONT TestMetricsInventory
  1375. 8.70 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo
  1376. 8.70 s [niks3-go-unit-tests] 2026/07/19 09:28:46 WARN Found objects in DB but missing from S3, will re-upload count=1
  1377. 8.70 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000
  1378. 8.70 s [niks3-go-unit-tests] --- PASS: TestService_createPendingClosureHandler (1.00s)
  1379. 8.70 s [niks3-go-unit-tests] === CONT TestNARDeduplicationMetadataUploadBug
  1380. 8.71 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20241026095416_initial_model.sql (14.42ms)
  1381. 8.71 s [niks3-go-unit-tests] --- PASS: TestService_verifyS3Integrity (1.01s)
  1382. 8.71 s [niks3-go-unit-tests] === CONT TestGenerateLandingPage
  1383. 8.71 s [niks3-go-unit-tests] --- PASS: TestGenerateLandingPage (0.00s)
  1384. 8.71 s [niks3-go-unit-tests] === CONT TestCompleteMultipartUpload_ErrorButObjectExists
  1385. 8.72 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20241026095416_initial_model.sql (23.48ms)
  1386. 8.73 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20251210153512_drop_unused_gin_index.sql (17.94ms)
  1387. 8.74 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20251210153512_drop_unused_gin_index.sql (16.07ms)
  1388. 8.74 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20251218171726_add_pins.sql (14.48ms)
  1389. 8.75 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20251218171726_add_pins.sql (16.16ms)
  1390. 8.76 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20260628120000_add_object_size_and_stats.sql (13.29ms)
  1391. 8.76 s [niks3-go-unit-tests] 2026/07/19 09:28:46 goose: successfully migrated database to version: 20260628120000
  1392. 8.76 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 20260628120000_add_object_size_and_stats.sql (9.02ms)
  1393. 8.76 s [niks3-go-unit-tests] 2026/07/19 09:28:46 goose: successfully migrated database to version: 20260628120000
  1394. 8.77 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 1_commit_pending_closure.sql (8.85ms)
  1395. 8.77 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 1_commit_pending_closure.sql (8.7ms)
  1396. 8.77 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=0
  1397. 8.78 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 2_object_stats_trigger.sql (11.55ms)
  1398. 8.78 s [niks3-go-unit-tests] 2026/07/19 09:28:46 goose: up to current file version: 2
  1399. 8.78 s [niks3-go-unit-tests] 2026/07/19 09:28:46 OK 2_object_stats_trigger.sql (11.43ms)
  1400. 8.78 s [niks3-go-unit-tests] 2026/07/19 09:28:46 goose: up to current file version: 2
  1401. 8.78 s [niks3-go-unit-tests] --- PASS: TestReadProxyHead (0.63s)
  1402. 8.78 s [niks3-go-unit-tests] === CONT TestCompletedNarNotReofferedAcrossClosures
  1403. 8.78 s [niks3-go-unit-tests] --- PASS: TestReadProxyInvalidPath (0.68s)
  1404. 8.78 s [niks3-go-unit-tests] === CONT TestRedundantMultipartUpload
  1405. 8.80 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Vacuumed table table=pending_closures
  1406. 8.83 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Vacuumed table table=pending_objects
  1407. 8.83 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Vacuumed table table=multipart_uploads
  1408. 8.85 s [niks3-go-unit-tests] 2026/07/19 09:28:46 INFO Vacuumed table table=closures
  1409. 8.89 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Vacuumed table table=objects
  1410. 8.90 s [niks3-go-unit-tests] 2026-07-19 09:28:47.025 UTC [823] ERROR: relation "goose_db_version" does not exist at character 36
  1411. 8.90 s [niks3-go-unit-tests] 2026-07-19 09:28:47.025 UTC [823] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1412. 8.90 s [niks3-go-unit-tests] 2026-07-19 09:28:47.025 UTC [824] ERROR: relation "goose_db_version" does not exist at character 36
  1413. 8.90 s [niks3-go-unit-tests] 2026-07-19 09:28:47.025 UTC [824] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1414. 8.98 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=0
  1415. 8.98 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20241026095416_initial_model.sql (18.26ms)
  1416. 8.98 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20241026095416_initial_model.sql (18.24ms)
  1417. 9.00 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251210153512_drop_unused_gin_index.sql (16.67ms)
  1418. 9.00 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251210153512_drop_unused_gin_index.sql (16.56ms)
  1419. 9.03 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Vacuumed table table=pending_closures
  1420. 9.04 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251218171726_add_pins.sql (34.88ms)
  1421. 9.04 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251218171726_add_pins.sql (34.97ms)
  1422. 9.05 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20260628120000_add_object_size_and_stats.sql (15.23ms)
  1423. 9.05 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: successfully migrated database to version: 20260628120000
  1424. 9.05 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20260628120000_add_object_size_and_stats.sql (15.36ms)
  1425. 9.05 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: successfully migrated database to version: 20260628120000
  1426. 9.11 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 1_commit_pending_closure.sql (60.07ms)
  1427. 9.11 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 1_commit_pending_closure.sql (60.2ms)
  1428. 9.11 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Vacuumed table table=pending_objects
  1429. 9.11 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Vacuumed table table=multipart_uploads
  1430. 9.12 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 2_object_stats_trigger.sql (8.98ms)
  1431. 9.12 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Vacuumed table table=closures
  1432. 9.12 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 2_object_stats_trigger.sql (9.06ms)
  1433. 9.12 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: up to current file version: 2
  1434. 9.12 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: up to current file version: 2
  1435. 9.12 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Received uploads request method=POST path=/api/pending_closures
  1436. 9.12 s [niks3-go-unit-tests] --- PASS: TestService_Rustfstest (0.70s)
  1437. 9.12 s [niks3-go-unit-tests] === CONT TestGCTaskStore_CompletedAllowsNewTask
  1438. 9.12 s [niks3-go-unit-tests] --- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)
  1439. 9.12 s [niks3-go-unit-tests] === CONT TestGracefulShutdownDrainsInflight
  1440. 9.12 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Starting HTTP server address=127.0.0.1:35299
  1441. 9.12 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Shutdown signal received, draining in-flight requests timeout=10s
  1442. 9.13 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Vacuumed table table=objects
  1443. 9.18 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete
  1444. 9.19 s [niks3-go-unit-tests] --- PASS: TestGracefulShutdownDrainsInflight (0.07s)
  1445. 9.19 s [niks3-go-unit-tests] === CONT TestGCTaskStore_Fail
  1446. 9.19 s [niks3-go-unit-tests] --- PASS: TestGCTaskStore_Fail (0.00s)
  1447. 9.19 s [niks3-go-unit-tests] === CONT TestGCTaskStore_PhaseUpdates
  1448. 9.19 s [niks3-go-unit-tests] --- PASS: TestGCTaskStore_PhaseUpdates (0.00s)
  1449. 9.19 s [niks3-go-unit-tests] === CONT TestGCTaskStore_GetEmpty
  1450. 9.19 s [niks3-go-unit-tests] --- PASS: TestGCTaskStore_GetEmpty (0.00s)
  1451. 9.19 s [niks3-go-unit-tests] === CONT TestGCTaskStore_GetReturnsLatest
  1452. 9.19 s [niks3-go-unit-tests] --- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)
  1453. 9.19 s [niks3-go-unit-tests] === CONT TestGCTaskStore_ConflictDifferentParams
  1454. 9.19 s [niks3-go-unit-tests] --- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)
  1455. 9.19 s [niks3-go-unit-tests] === CONT TestGCTaskStore_DeduplicateSameParams
  1456. 9.19 s [niks3-go-unit-tests] --- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)
  1457. 9.19 s [niks3-go-unit-tests] === CONT TestClientErrorHandling/InvalidStorePath
  1458. 9.27 s [niks3-go-unit-tests] 2026-07-19 09:28:47.401 UTC [830] ERROR: relation "goose_db_version" does not exist at character 36
  1459. 9.27 s [niks3-go-unit-tests] 2026-07-19 09:28:47.401 UTC [830] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1460. 9.27 s [niks3-go-unit-tests] 2026-07-19 09:28:47.401 UTC [834] ERROR: relation "goose_db_version" does not exist at character 36
  1461. 9.27 s [niks3-go-unit-tests] 2026-07-19 09:28:47.401 UTC [834] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1462. 9.27 s [niks3-go-unit-tests] 2026-07-19 09:28:47.401 UTC [832] ERROR: relation "goose_db_version" does not exist at character 36
  1463. 9.27 s [niks3-go-unit-tests] 2026-07-19 09:28:47.401 UTC [832] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1464. 9.27 s [niks3-go-unit-tests] 2026-07-19 09:28:47.402 UTC [831] ERROR: relation "goose_db_version" does not exist at character 36
  1465. 9.27 s [niks3-go-unit-tests] 2026-07-19 09:28:47.402 UTC [831] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1466. 9.27 s [niks3-go-unit-tests] 2026-07-19 09:28:47.402 UTC [833] ERROR: relation "goose_db_version" does not exist at character 36
  1467. 9.27 s [niks3-go-unit-tests] 2026-07-19 09:28:47.402 UTC [833] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1468. 9.31 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20241026095416_initial_model.sql (17.8ms)
  1469. 9.32 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20241026095416_initial_model.sql (23.59ms)
  1470. 9.32 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20241026095416_initial_model.sql (23.52ms)
  1471. 9.32 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20241026095416_initial_model.sql (23.62ms)
  1472. 9.32 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20241026095416_initial_model.sql (23.39ms)
  1473. 9.33 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251210153512_drop_unused_gin_index.sql (12.84ms)
  1474. 9.33 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251210153512_drop_unused_gin_index.sql (12.9ms)
  1475. 9.33 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251210153512_drop_unused_gin_index.sql (12.88ms)
  1476. 9.33 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251210153512_drop_unused_gin_index.sql (12.91ms)
  1477. 9.33 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251210153512_drop_unused_gin_index.sql (18.71ms)
  1478. 9.38 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251218171726_add_pins.sql (56.19ms)
  1479. 9.38 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251218171726_add_pins.sql (56.2ms)
  1480. 9.38 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251218171726_add_pins.sql (56.19ms)
  1481. 9.38 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251218171726_add_pins.sql (56.16ms)
  1482. 9.39 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251218171726_add_pins.sql (56.15ms)
  1483. 9.39 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20260628120000_add_object_size_and_stats.sql (9.58ms)
  1484. 9.39 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: successfully migrated database to version: 20260628120000
  1485. 9.39 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20260628120000_add_object_size_and_stats.sql (9.57ms)
  1486. 9.39 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: successfully migrated database to version: 20260628120000
  1487. 9.39 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20260628120000_add_object_size_and_stats.sql (9.61ms)
  1488. 9.39 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: successfully migrated database to version: 20260628120000
  1489. 9.39 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20260628120000_add_object_size_and_stats.sql (9.62ms)
  1490. 9.39 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: successfully migrated database to version: 20260628120000
  1491. 9.39 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20260628120000_add_object_size_and_stats.sql (9.57ms)
  1492. 9.39 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: successfully migrated database to version: 20260628120000
  1493. 9.40 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 1_commit_pending_closure.sql (9.81ms)
  1494. 9.40 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 1_commit_pending_closure.sql (9.94ms)
  1495. 9.40 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 1_commit_pending_closure.sql (9.84ms)
  1496. 9.40 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 1_commit_pending_closure.sql (9.89ms)
  1497. 9.40 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 1_commit_pending_closure.sql (9.78ms)
  1498. 9.40 s [niks3-go-unit-tests] 2026-07-19 09:28:47.533 UTC [838] ERROR: relation "goose_db_version" does not exist at character 36
  1499. 9.40 s [niks3-go-unit-tests] 2026-07-19 09:28:47.533 UTC [838] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1500. 9.40 s [niks3-go-unit-tests] 2026-07-19 09:28:47.534 UTC [837] ERROR: relation "goose_db_version" does not exist at character 36
  1501. 9.41 s [niks3-go-unit-tests] 2026-07-19 09:28:47.534 UTC [837] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1502. 9.41 s [niks3-go-unit-tests] 2026-07-19 09:28:47.534 UTC [840] ERROR: relation "goose_db_version" does not exist at character 36
  1503. 9.41 s [niks3-go-unit-tests] 2026-07-19 09:28:47.534 UTC [840] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1504. 9.41 s [niks3-go-unit-tests] 2026-07-19 09:28:47.534 UTC [839] ERROR: relation "goose_db_version" does not exist at character 36
  1505. 9.41 s [niks3-go-unit-tests] 2026-07-19 09:28:47.534 UTC [839] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1506. 9.41 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 2_object_stats_trigger.sql (9.21ms)
  1507. 9.41 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 2_object_stats_trigger.sql (9.24ms)
  1508. 9.41 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 2_object_stats_trigger.sql (9.1ms)
  1509. 9.41 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 2_object_stats_trigger.sql (9.23ms)
  1510. 9.41 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 2_object_stats_trigger.sql (9.15ms)
  1511. 9.41 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: up to current file version: 2
  1512. 9.41 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: up to current file version: 2
  1513. 9.41 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: up to current file version: 2
  1514. 9.41 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: up to current file version: 2
  1515. 9.41 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: up to current file version: 2
  1516. 9.42 s [niks3-go-unit-tests] --- PASS: TestService_healthCheckHandler (0.77s)
  1517. 9.42 s [niks3-go-unit-tests] === CONT TestClientErrorHandling/ServerNotAvailable
  1518. 9.42 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Received uploads request method=POST path=/api/pending_closures
  1519. 9.42 s [niks3-go-unit-tests] 2026/07/19 09:28:47 WARN mTLS auth: subject not in bound subjects subject="CN=reader"
  1520. 9.42 s [niks3-go-unit-tests] 2026/07/19 09:28:47 WARN mTLS auth: subject not in bound subjects subject="CN=writer"
  1521. 9.42 s [niks3-go-unit-tests] --- PASS: TestService_NativeMTLS (0.73s)
  1522. 9.42 s [niks3-go-unit-tests] === CONT TestClientErrorHandling/InvalidAuthToken
  1523. 9.42 s [niks3-go-unit-tests] --- PASS: TestReadProxy404 (0.84s)
  1524. 9.42 s [niks3-go-unit-tests] === CONT TestParseSingleRange/none
  1525. 9.42 s [niks3-go-unit-tests] === CONT TestParseSingleRange/end_clamped_to_size
  1526. 9.42 s [niks3-go-unit-tests] === CONT TestParseSingleRange/start_far_past_EOF
  1527. 9.42 s [niks3-go-unit-tests] === CONT TestParseSingleRange/start_past_EOF
  1528. 9.42 s [niks3-go-unit-tests] === CONT TestParseSingleRange/single_byte
  1529. 9.42 s [niks3-go-unit-tests] === CONT TestParseSingleRange/suffix_exceeds_size
  1530. 9.42 s [niks3-go-unit-tests] === CONT TestParseSingleRange/suffix
  1531. 9.42 s [niks3-go-unit-tests] === CONT TestParseSingleRange/malformed_both_empty
  1532. 9.42 s [niks3-go-unit-tests] === CONT TestParseSingleRange/open-ended
  1533. 9.42 s [niks3-go-unit-tests] === CONT TestParseSingleRange/closed
  1534. 9.42 s [niks3-go-unit-tests] === CONT TestParseSingleRange/malformed_end_before_start
  1535. 9.42 s [niks3-go-unit-tests] === CONT TestParseSingleRange/multi-range_ignored
  1536. 9.42 s [niks3-go-unit-tests] === CONT TestParseSingleRange/malformed_no_dash
  1537. 9.42 s [niks3-go-unit-tests] === CONT TestParseSingleRange/unknown_unit
  1538. 9.42 s [niks3-go-unit-tests] --- PASS: TestParseSingleRange (0.00s)
  1539. 9.42 s [niks3-go-unit-tests] --- PASS: TestParseSingleRange/none (0.00s)
  1540. 9.42 s [niks3-go-unit-tests] --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)
  1541. 9.42 s [niks3-go-unit-tests] --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)
  1542. 9.42 s [niks3-go-unit-tests] --- PASS: TestParseSingleRange/start_past_EOF (0.00s)
  1543. 9.42 s [niks3-go-unit-tests] --- PASS: TestParseSingleRange/single_byte (0.00s)
  1544. 9.42 s [niks3-go-unit-tests] --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)
  1545. 9.42 s [niks3-go-unit-tests] --- PASS: TestParseSingleRange/suffix (0.00s)
  1546. 9.42 s [niks3-go-unit-tests] --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)
  1547. 9.42 s [niks3-go-unit-tests] --- PASS: TestParseSingleRange/open-ended (0.00s)
  1548. 9.42 s [niks3-go-unit-tests] --- PASS: TestParseSingleRange/closed (0.00s)
  1549. 9.42 s [niks3-go-unit-tests] --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)
  1550. 9.42 s [niks3-go-unit-tests] --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)
  1551. 9.42 s [niks3-go-unit-tests] --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)
  1552. 9.42 s [niks3-go-unit-tests] --- PASS: TestParseSingleRange/unknown_unit (0.00s)
  1553. 9.42 s [niks3-go-unit-tests] === CONT TestIsValidCachePath/narinfo
  1554. 9.42 s [niks3-go-unit-tests] === CONT TestIsValidCachePath/index.html
  1555. 9.42 s [niks3-go-unit-tests] === CONT TestIsValidCachePath/short_hash
  1556. 9.42 s [niks3-go-unit-tests] === CONT TestIsValidCachePath/wrong_extension
  1557. 9.42 s [niks3-go-unit-tests] === CONT TestIsValidCachePath/leading_slash
  1558. 9.42 s [niks3-go-unit-tests] === CONT TestIsValidCachePath/empty
  1559. 9.42 s [niks3-go-unit-tests] === CONT TestIsValidCachePath/random_path
  1560. 9.42 s [niks3-go-unit-tests] === CONT TestIsValidCachePath/invalid_char_u
  1561. 9.42 s [niks3-go-unit-tests] === CONT TestIsValidCachePath/invalid_char_e
  1562. 9.42 s [niks3-go-unit-tests] === CONT TestIsValidCachePath/traversal_in_middle
  1563. 9.42 s [niks3-go-unit-tests] === CONT TestIsValidCachePath/traversal_parent
  1564. 9.42 s [niks3-go-unit-tests] === CONT TestIsValidCachePath/nar_uncompressed
  1565. 9.42 s [niks3-go-unit-tests] === CONT TestIsValidCachePath/nix-cache-info
  1566. 9.42 s [niks3-go-unit-tests] === CONT TestIsValidCachePath/realisation
  1567. 9.42 s [niks3-go-unit-tests] === CONT TestIsValidCachePath/log
  1568. 9.42 s [niks3-go-unit-tests] === CONT TestIsValidCachePath/ls
  1569. 9.42 s [niks3-go-unit-tests] === CONT TestIsValidCachePath/nar_xz
  1570. 9.42 s [niks3-go-unit-tests] === CONT TestIsValidCachePath/nar_bz2
  1571. 9.42 s [niks3-go-unit-tests] === CONT TestIsValidCachePath/nar_zst
  1572. 9.42 s [niks3-go-unit-tests] === CONT TestIsValidCachePath/narinfo_all_nix_base32_chars
  1573. 9.42 s [niks3-go-unit-tests] --- PASS: TestIsValidCachePath (0.00s)
  1574. 9.42 s [niks3-go-unit-tests] --- PASS: TestIsValidCachePath/narinfo (0.00s)
  1575. 9.42 s [niks3-go-unit-tests] --- PASS: TestIsValidCachePath/index.html (0.00s)
  1576. 9.42 s [niks3-go-unit-tests] --- PASS: TestIsValidCachePath/short_hash (0.00s)
  1577. 9.42 s [niks3-go-unit-tests] --- PASS: TestIsValidCachePath/wrong_extension (0.00s)
  1578. 9.42 s [niks3-go-unit-tests] --- PASS: TestIsValidCachePath/leading_slash (0.00s)
  1579. 9.42 s [niks3-go-unit-tests] --- PASS: TestIsValidCachePath/empty (0.00s)
  1580. 9.42 s [niks3-go-unit-tests] --- PASS: TestIsValidCachePath/random_path (0.00s)
  1581. 9.42 s [niks3-go-unit-tests] --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)
  1582. 9.42 s [niks3-go-unit-tests] --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)
  1583. 9.42 s [niks3-go-unit-tests] --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)
  1584. 9.42 s [niks3-go-unit-tests] --- PASS: TestIsValidCachePath/traversal_parent (0.00s)
  1585. 9.42 s [niks3-go-unit-tests] --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)
  1586. 9.42 s [niks3-go-unit-tests] --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)
  1587. 9.42 s [niks3-go-unit-tests] --- PASS: TestIsValidCachePath/realisation (0.00s)
  1588. 9.42 s [niks3-go-unit-tests] --- PASS: TestIsValidCachePath/log (0.00s)
  1589. 9.42 s [niks3-go-unit-tests] --- PASS: TestIsValidCachePath/ls (0.00s)
  1590. 9.42 s [niks3-go-unit-tests] --- PASS: TestIsValidCachePath/nar_xz (0.00s)
  1591. 9.42 s [niks3-go-unit-tests] --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)
  1592. 9.42 s [niks3-go-unit-tests] --- PASS: TestIsValidCachePath/nar_zst (0.00s)
  1593. 9.42 s [niks3-go-unit-tests] --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)
  1594. 9.42 s [niks3-go-unit-tests] === CONT TestCacheConfigHandler/full_config,_no_issuer
  1595. 9.42 s [niks3-go-unit-tests] === CONT TestCacheConfigHandler/no_signing_keys
  1596. 9.42 s [niks3-go-unit-tests] === CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator
  1597. 9.42 s [niks3-go-unit-tests] === CONT TestCacheConfigHandler/no_cache_url_configured
  1598. 9.42 s [niks3-go-unit-tests] --- PASS: TestCacheConfigHandler (0.00s)
  1599. 9.42 s [niks3-go-unit-tests] --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)
  1600. 9.42 s [niks3-go-unit-tests] --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)
  1601. 9.42 s [niks3-go-unit-tests] --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)
  1602. 9.42 s [niks3-go-unit-tests] --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)
  1603. 9.42 s [niks3-go-unit-tests] === CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info
  1604. 9.42 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Received uploads request method=POST path=/
  1605. 9.42 s [niks3-go-unit-tests] === CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token
  1606. 9.42 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO OIDC auth successful provider=test
  1607. 9.42 s [niks3-go-unit-tests] === CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected
  1608. 9.42 s [niks3-go-unit-tests] 2026/07/19 09:28:47 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]
  1609. 9.42 s [niks3-go-unit-tests] === CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured
  1610. 9.42 s [niks3-go-unit-tests] === CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key
  1611. 9.42 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Received complete multipart upload request method=POST path=/
  1612. 9.42 s [niks3-go-unit-tests] === CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key
  1613. 9.42 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Received request for more parts method=POST path=/
  1614. 9.42 s [niks3-go-unit-tests] === CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected
  1615. 9.42 s [niks3-go-unit-tests] 2026/07/19 09:28:47 WARN Authentication failed token_preview=eyJhbGciOi...HfX3eh0EcA token_length=702 oidc_error="bound claims validation failed: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]
  1616. 9.42 s [niks3-go-unit-tests] === CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal
  1617. 9.42 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Received uploads request method=POST path=/
  1618. 9.42 s [niks3-go-unit-tests] --- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)
  1619. 9.42 s [niks3-go-unit-tests] --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)
  1620. 9.42 s [niks3-go-unit-tests] --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)
  1621. 9.42 s [niks3-go-unit-tests] --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)
  1622. 9.42 s [niks3-go-unit-tests] --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)
  1623. 9.42 s [niks3-go-unit-tests] === CONT TestUploadHandlersRejectOversizedBody/create_pending_closure
  1624. 9.42 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Received uploads request method=POST path=/
  1625. 9.42 s [niks3-go-unit-tests] --- PASS: TestService_AuthMiddleware_OIDC (1.23s)
  1626. 9.42 s [niks3-go-unit-tests] --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)
  1627. 9.42 s [niks3-go-unit-tests] --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)
  1628. 9.42 s [niks3-go-unit-tests] --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)
  1629. 9.42 s [niks3-go-unit-tests] --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)
  1630. 9.43 s [niks3-go-unit-tests] 2026-07-19 09:28:47.557 UTC [844] ERROR: relation "goose_db_version" does not exist at character 36
  1631. 9.43 s [niks3-go-unit-tests] 2026-07-19 09:28:47.557 UTC [844] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1632. 9.43 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20241026095416_initial_model.sql (18.29ms)
  1633. 9.43 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20241026095416_initial_model.sql (18.28ms)
  1634. 9.43 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20241026095416_initial_model.sql (18.37ms)
  1635. 9.44 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20241026095416_initial_model.sql (20.23ms)
  1636. 9.45 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251210153512_drop_unused_gin_index.sql (15.13ms)
  1637. 9.45 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251210153512_drop_unused_gin_index.sql (15.3ms)
  1638. 9.45 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251210153512_drop_unused_gin_index.sql (15.38ms)
  1639. 9.46 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20241026095416_initial_model.sql (15.14ms)
  1640. 9.46 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251210153512_drop_unused_gin_index.sql (15.67ms)
  1641. 9.46 s [niks3-go-unit-tests] --- PASS: TestMetricsInventory (0.76s)
  1642. 9.46 s [niks3-go-unit-tests] === CONT TestUploadHandlersRejectOversizedBody/request_more_parts
  1643. 9.46 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Received request for more parts method=POST path=/
  1644. 9.46 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251218171726_add_pins.sql (14.79ms)
  1645. 9.46 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251218171726_add_pins.sql (14.72ms)
  1646. 9.46 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251218171726_add_pins.sql (14.69ms)
  1647. 9.47 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251218171726_add_pins.sql (15.3ms)
  1648. 9.47 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251210153512_drop_unused_gin_index.sql (15.6ms)
  1649. 9.48 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20260628120000_add_object_size_and_stats.sql (17.12ms)
  1650. 9.48 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20260628120000_add_object_size_and_stats.sql (17.11ms)
  1651. 9.48 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: successfully migrated database to version: 20260628120000
  1652. 9.48 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20260628120000_add_object_size_and_stats.sql (17.1ms)
  1653. 9.48 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: successfully migrated database to version: 20260628120000
  1654. 9.48 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: successfully migrated database to version: 20260628120000
  1655. 9.49 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20260628120000_add_object_size_and_stats.sql (18.08ms)
  1656. 9.49 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: successfully migrated database to version: 20260628120000
  1657. 9.49 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251218171726_add_pins.sql (17.67ms)
  1658. 9.49 s [niks3-go-unit-tests] === CONT TestUploadHandlersRejectOversizedBody/complete_multipart
  1659. 9.49 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Received complete multipart upload request method=POST path=/
  1660. 9.50 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 1_commit_pending_closure.sql (15.84ms)
  1661. 9.50 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 1_commit_pending_closure.sql (15.89ms)
  1662. 9.50 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 1_commit_pending_closure.sql (15.89ms)
  1663. 9.51 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 1_commit_pending_closure.sql (16.35ms)
  1664. 9.51 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20260628120000_add_object_size_and_stats.sql (16.39ms)
  1665. 9.51 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: successfully migrated database to version: 20260628120000
  1666. 9.51 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 2_object_stats_trigger.sql (18.24ms)
  1667. 9.51 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: up to current file version: 2
  1668. 9.51 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 2_object_stats_trigger.sql (18.27ms)
  1669. 9.51 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 2_object_stats_trigger.sql (18.24ms)
  1670. 9.51 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: up to current file version: 2
  1671. 9.51 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: up to current file version: 2
  1672. 9.52 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Received uploads request method=POST path=/api/pending_closures
  1673. 9.52 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Received uploads request method=POST path=/api/pending_closures
  1674. 9.52 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Created nix-cache-info in bucket bucket=bucket40
  1675. 9.52 s [niks3-go-unit-tests] === CONT TestIsValidUploadKey/narinfo
  1676. 9.52 s [niks3-go-unit-tests] === CONT TestIsValidUploadKey/realisation_plus_in_output
  1677. 9.52 s [niks3-go-unit-tests] === CONT TestIsValidUploadKey/unknown_type
  1678. 9.52 s [niks3-go-unit-tests] === CONT TestIsValidUploadKey/empty_key
  1679. 9.52 s [niks3-go-unit-tests] === CONT TestIsValidUploadKey/absolute
  1680. 9.52 s [niks3-go-unit-tests] === CONT TestIsValidUploadKey/traversal_nar
  1681. 9.52 s [niks3-go-unit-tests] === CONT TestIsValidUploadKey/traversal
  1682. 9.52 s [niks3-go-unit-tests] === CONT TestIsValidUploadKey/listing_key,_narinfo_type
  1683. 9.52 s [niks3-go-unit-tests] === CONT TestIsValidUploadKey/index.html
  1684. 9.52 s [niks3-go-unit-tests] === CONT TestIsValidUploadKey/nix-cache-info
  1685. 9.52 s [niks3-go-unit-tests] === CONT TestIsValidUploadKey/nar_key,_narinfo_type
  1686. 9.52 s [niks3-go-unit-tests] === CONT TestIsValidUploadKey/build_log_home-manager_file
  1687. 9.52 s [niks3-go-unit-tests] === CONT TestIsValidUploadKey/realisation
  1688. 9.52 s [niks3-go-unit-tests] === CONT TestIsValidUploadKey/build_log_equals
  1689. 9.52 s [niks3-go-unit-tests] === CONT TestIsValidUploadKey/build_log_question_mark
  1690. 9.52 s [niks3-go-unit-tests] === CONT TestIsValidUploadKey/build_log_plus_in_name
  1691. 9.52 s [niks3-go-unit-tests] === CONT TestIsValidUploadKey/narinfo_key,_nar_type
  1692. 9.52 s [niks3-go-unit-tests] === CONT TestIsValidUploadKey/nar_plain
  1693. 9.52 s [niks3-go-unit-tests] === CONT TestIsValidUploadKey/build_log
  1694. 9.52 s [niks3-go-unit-tests] === CONT TestIsValidUploadKey/nar_xz
  1695. 9.52 s [niks3-go-unit-tests] === CONT TestIsValidUploadKey/listing
  1696. 9.52 s [niks3-go-unit-tests] === CONT TestIsValidUploadKey/nar_zst
  1697. 9.52 s [niks3-go-unit-tests] --- PASS: TestIsValidUploadKey (0.00s)
  1698. 9.52 s [niks3-go-unit-tests] --- PASS: TestIsValidUploadKey/narinfo (0.00s)
  1699. 9.52 s [niks3-go-unit-tests] --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)
  1700. 9.52 s [niks3-go-unit-tests] --- PASS: TestIsValidUploadKey/unknown_type (0.00s)
  1701. 9.52 s [niks3-go-unit-tests] --- PASS: TestIsValidUploadKey/empty_key (0.00s)
  1702. 9.52 s [niks3-go-unit-tests] --- PASS: TestIsValidUploadKey/absolute (0.00s)
  1703. 9.52 s [niks3-go-unit-tests] --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)
  1704. 9.52 s [niks3-go-unit-tests] --- PASS: TestIsValidUploadKey/traversal (0.00s)
  1705. 9.52 s [niks3-go-unit-tests] --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)
  1706. 9.52 s [niks3-go-unit-tests] --- PASS: TestIsValidUploadKey/index.html (0.00s)
  1707. 9.52 s [niks3-go-unit-tests] --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)
  1708. 9.52 s [niks3-go-unit-tests] --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)
  1709. 9.52 s [niks3-go-unit-tests] --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)
  1710. 9.52 s [niks3-go-unit-tests] --- PASS: TestIsValidUploadKey/realisation (0.00s)
  1711. 9.52 s [niks3-go-unit-tests] --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)
  1712. 9.52 s [niks3-go-unit-tests] --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)
  1713. 9.52 s [niks3-go-unit-tests] --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)
  1714. 9.52 s [niks3-go-unit-tests] --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)
  1715. 9.52 s [niks3-go-unit-tests] --- PASS: TestIsValidUploadKey/nar_plain (0.00s)
  1716. 9.52 s [niks3-go-unit-tests] --- PASS: TestIsValidUploadKey/build_log (0.00s)
  1717. 9.52 s [niks3-go-unit-tests] --- PASS: TestIsValidUploadKey/nar_xz (0.00s)
  1718. 9.52 s [niks3-go-unit-tests] --- PASS: TestIsValidUploadKey/listing (0.00s)
  1719. 9.52 s [niks3-go-unit-tests] --- PASS: TestIsValidUploadKey/nar_zst (0.00s)
  1720. 9.52 s [niks3-go-unit-tests] === CONT TestProxyWriteTimeout/narinfo
  1721. 9.52 s [niks3-go-unit-tests] === CONT TestProxyWriteTimeout/1_GiB_nar
  1722. 9.52 s [niks3-go-unit-tests] === CONT TestProxyWriteTimeout/10_GiB_nar
  1723. 9.52 s [niks3-go-unit-tests] === CONT TestProxyWriteTimeout/unknown_size
  1724. 9.52 s [niks3-go-unit-tests] --- PASS: TestProxyWriteTimeout (0.00s)
  1725. 9.52 s [niks3-go-unit-tests] --- PASS: TestProxyWriteTimeout/narinfo (0.00s)
  1726. 9.52 s [niks3-go-unit-tests] --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)
  1727. 9.52 s [niks3-go-unit-tests] --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)
  1728. 9.52 s [niks3-go-unit-tests] --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)
  1729. 9.52 s [niks3-go-unit-tests] === CONT TestServerTLSConfig/no_client_CA
  1730. 9.52 s [niks3-go-unit-tests] === CONT TestServerTLSConfig/not_a_PEM_file
  1731. 9.52 s [niks3-go-unit-tests] === CONT TestServerTLSConfig/missing_CA_file
  1732. 9.52 s [niks3-go-unit-tests] --- PASS: TestServerTLSConfig (0.00s)
  1733. 9.52 s [niks3-go-unit-tests] --- PASS: TestServerTLSConfig/no_client_CA (0.00s)
  1734. 9.52 s [niks3-go-unit-tests] --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)
  1735. 9.52 s [niks3-go-unit-tests] --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)
  1736. 9.52 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 1_commit_pending_closure.sql (17.64ms)
  1737. 9.52 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 2_object_stats_trigger.sql (17.75ms)
  1738. 9.52 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: up to current file version: 2
  1739. 9.53 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Received uploads request method=POST path=/api/pending_closures
  1740. 9.54 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 2_object_stats_trigger.sql (16.39ms)
  1741. 9.54 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: up to current file version: 2
  1742. 9.54 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Received cleanup request method=DELETE path=/api/pending_closures
  1743. 9.54 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Aborted multipart uploads count=1
  1744. 9.55 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete
  1745. 9.56 s [niks3-go-unit-tests] {"timestamp":"2026-07-19T09:28:47.68541354Z","level":"ERROR","fields":{"message":"complete_multipart_upload part error: \"part.1 not found\""},"target":"rustfs_ecstore::set_disk","filename":"crates/ecstore/src/set_disk.rs","line_number":3463,"threadName":"rustfs-worker","threadId":"ThreadId(27)"}
  1746. 9.56 s [niks3-go-unit-tests] {"timestamp":"2026-07-19T09:28:47.68544279Z","level":"ERROR","fields":{"message":"complete_multipart_upload etag err client=Some(\"deadbeef\"), stored=\"\", part_id=1, bucket=bucket41, object=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst"},"target":"rustfs_ecstore::set_disk","filename":"crates/ecstore/src/set_disk.rs","line_number":3534,"threadName":"rustfs-worker","threadId":"ThreadId(27)"}
  1747. 9.56 s [niks3-go-unit-tests] --- PASS: TestMultipartCleanup (0.89s)
  1748. 9.56 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Received uploads request method=POST path=/api/pending_closures
  1749. 9.56 s [niks3-go-unit-tests] 2026/07/19 09:28:47 WARN CompleteMultipartUpload errored but object exists; treating as success error="One or more of the specified parts could not be found. The part may not have been uploaded, or the specified entity tag may not match the part's entity tag." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OGE3NmQ0N2YtMzQ4MC00YzA2LWJiMDUtN2YyODU2MjFjODA2LjJlOGUxYjAzLTIzYTItNGExYi04M2U1LTFkNWMzNDg5NzkzYngxNzg0NDUzMzI3NjYyMTI4Nzc3
  1750. 9.56 s [niks3-go-unit-tests] 2026-07-19 09:28:47.691 UTC [875] ERROR: relation "goose_db_version" does not exist at character 36
  1751. 9.56 s [niks3-go-unit-tests] 2026-07-19 09:28:47.691 UTC [875] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC
  1752. 9.59 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OGE3NmQ0N2YtMzQ4MC00YzA2LWJiMDUtN2YyODU2MjFjODA2LjJlOGUxYjAzLTIzYTItNGExYi04M2U1LTFkNWMzNDg5NzkzYngxNzg0NDUzMzI3NjYyMTI4Nzc3 parts=1
  1753. 9.59 s [niks3-go-unit-tests] --- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.88s)
  1754. 9.60 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20241026095416_initial_model.sql (16.69ms)
  1755. 9.61 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251210153512_drop_unused_gin_index.sql (7.38ms)
  1756. 9.73 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20251218171726_add_pins.sql (124.06ms)
  1757. 9.74 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 20260628120000_add_object_size_and_stats.sql (12.93ms)
  1758. 9.74 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: successfully migrated database to version: 20260628120000
  1759. 9.76 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 1_commit_pending_closure.sql (15.11ms)
  1760. 9.77 s [niks3-go-unit-tests] 2026/07/19 09:28:47 OK 2_object_stats_trigger.sql (15.32ms)
  1761. 9.77 s [niks3-go-unit-tests] 2026/07/19 09:28:47 goose: up to current file version: 2
  1762. 9.80 s [niks3-go-unit-tests] === NAME TestNARDeduplicationMetadataUploadBug
  1763. 9.80 s [niks3-go-unit-tests] metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3728107378/001/store/j1prn95gkdivms0wcxjvik00cqj5s6s9-file1.txt
  1764. 9.82 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete
  1765. 9.86 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=OGE3NmQ0N2YtMzQ4MC00YzA2LWJiMDUtN2YyODU2MjFjODA2LmIyZjBhYTlkLWY2NzQtNDBhZi1iNmExLThjNjMxZGUxODVlZXgxNzg0NDUzMzI3NjYyMTU1OTQ3 parts=12
  1766. 9.86 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Received uploads request method=POST path=/api/pending_closures
  1767. 9.86 s [niks3-go-unit-tests] 2026/07/19 09:28:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete
  1768. 9.88 s [niks3-go-unit-tests] --- PASS: TestCompletedNarNotReofferedAcrossClosures (1.09s)
  1769. 9.91 s [niks3-go-unit-tests] 2026/07/19 09:28:48 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=OGE3NmQ0N2YtMzQ4MC00YzA2LWJiMDUtN2YyODU2MjFjODA2LmI2ZmE5NjJmLTU4OGUtNDEwNS05N2FmLTg5MTM5MGI1NGZlMHgxNzg0NDUzMzI3NjY5OTQ3MDUx parts=12
  1770. 9.91 s [niks3-go-unit-tests] --- PASS: TestRedundantMultipartUpload (1.12s)
  1771. 9.91 s [niks3-go-unit-tests] 2026/07/19 09:28:48 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures
  1772. 9.99 s [niks3-go-unit-tests] 2026/07/19 09:28:48 INFO Received uploads request method=POST path=/api/pending_closures
  1773. 10.01 s [niks3-go-unit-tests] 2026/07/19 09:28:48 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)
  1774. 10.01 s [niks3-go-unit-tests] 2026/07/19 09:28:48 INFO Uploading j1prn95gkdivms0wcxjvik00cqj5s6s9-file1.txt (160B)
  1775. 10.01 s [niks3-go-unit-tests] 2026/07/19 09:28:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign
  1776. 10.01 s [niks3-go-unit-tests] 2026/07/19 09:28:48 INFO Signed narinfos id=1 count=1
  1777. 10.01 s [niks3-go-unit-tests] 2026/07/19 09:28:48 INFO Uploading 1 narinfos
  1778. 10.01 s [niks3-go-unit-tests] 2026/07/19 09:28:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete
  1779. 10.01 s [niks3-go-unit-tests] 2026/07/19 09:28:48 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=196.340405ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures
  1780. 10.02 s [niks3-go-unit-tests] 2026/07/19 09:28:48 INFO Completed upload id=1
  1781. 10.02 s [niks3-go-unit-tests] 2026/07/19 09:28:48 INFO Upload complete. (186ms)
  1782. 10.02 s [niks3-go-unit-tests] === NAME TestNARDeduplicationMetadataUploadBug
  1783. 10.02 s [niks3-go-unit-tests] metadata_upload_test.go:54: Retrieved narinfo from S3:
  1784. 10.02 s [niks3-go-unit-tests] StorePath: /build/TestNARDeduplicationMetadataUploadBug3728107378/001/store/j1prn95gkdivms0wcxjvik00cqj5s6s9-file1.txt
  1785. 10.02 s [niks3-go-unit-tests] URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst
  1786. 10.02 s [niks3-go-unit-tests] Compression: zstd
  1787. 10.02 s [niks3-go-unit-tests] NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf
  1788. 10.02 s [niks3-go-unit-tests] NarSize: 160
  1789. 10.02 s [niks3-go-unit-tests] References:
  1790. 10.02 s [niks3-go-unit-tests] CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf
  1791. 10.02 s [niks3-go-unit-tests] metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)
  1792. 10.02 s [niks3-go-unit-tests] metadata_upload_test.go:55: Decompressed .ls content (64 bytes):
  1793. 10.02 s [niks3-go-unit-tests] {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}
  1794. 10.05 s [niks3-go-unit-tests] --- PASS: TestUploadHandlersRejectOversizedBody (0.28s)
  1795. 10.05 s [niks3-go-unit-tests] --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)
  1796. 10.05 s [niks3-go-unit-tests] --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)
  1797. 10.05 s [niks3-go-unit-tests] --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.63s)
  1798. 10.10 s [niks3-go-unit-tests] === NAME TestNARDeduplicationMetadataUploadBug
  1799. 10.10 s [niks3-go-unit-tests] metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3728107378/001/store/13r74in1imk2ffqq6hj3jx9811wzwdkq-file2.txt
  1800. 10.16 s [niks3-go-unit-tests] 2026/07/19 09:28:48 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"
  1801. 10.51 s [niks3-go-unit-tests] 2026/07/19 09:28:48 INFO Received uploads request method=POST path=/api/pending_closures
  1802. 10.51 s [niks3-go-unit-tests] 2026/07/19 09:28:48 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)
  1803. 10.51 s [niks3-go-unit-tests] 2026/07/19 09:28:48 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign
  1804. 10.51 s [niks3-go-unit-tests] 2026/07/19 09:28:48 INFO Signed narinfos id=2 count=1
  1805. 10.51 s [niks3-go-unit-tests] 2026/07/19 09:28:48 INFO Uploading 1 narinfos
  1806. 10.51 s [niks3-go-unit-tests] 2026/07/19 09:28:48 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete
  1807. 10.51 s [niks3-go-unit-tests] 2026/07/19 09:28:48 INFO Completed upload id=2
  1808. 10.51 s [niks3-go-unit-tests] 2026/07/19 09:28:48 INFO Upload complete. (56ms)
  1809. 10.51 s [niks3-go-unit-tests] metadata_upload_test.go:76: Retrieved narinfo from S3:
  1810. 10.51 s [niks3-go-unit-tests] StorePath: /build/TestNARDeduplicationMetadataUploadBug3728107378/001/store/13r74in1imk2ffqq6hj3jx9811wzwdkq-file2.txt
  1811. 10.51 s [niks3-go-unit-tests] URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst
  1812. 10.51 s [niks3-go-unit-tests] Compression: zstd
  1813. 10.51 s [niks3-go-unit-tests] NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf
  1814. 10.51 s [niks3-go-unit-tests] NarSize: 160
  1815. 10.51 s [niks3-go-unit-tests] References:
  1816. 10.51 s [niks3-go-unit-tests] CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf
  1817. 10.51 s [niks3-go-unit-tests] metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)
  1818. 10.51 s [niks3-go-unit-tests] metadata_upload_test.go:77: Decompressed .ls content (49 bytes):
  1819. 10.51 s [niks3-go-unit-tests] {"version":1,"root":{"type":"regular","size":44}}
  1820. 10.51 s [niks3-go-unit-tests] --- PASS: TestNARDeduplicationMetadataUploadBug (1.48s)
  1821. 10.51 s [niks3-go-unit-tests] 2026/07/19 09:28:48 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=0
  1822. 10.51 s [niks3-go-unit-tests] === NAME TestClientIntegration
  1823. 10.51 s [niks3-go-unit-tests] client_integration_test.go:303: Objects in database after GC:
  1824. 10.51 s [niks3-go-unit-tests] client_integration_test.go:303: Successfully deleted all objects with GC --force
  1825. 10.51 s [niks3-go-unit-tests] --- PASS: TestClientIntegration (4.50s)
  1826. 10.51 s [niks3-go-unit-tests] 2026/07/19 09:28:48 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=374.53415ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures
  1827. 10.51 s [niks3-go-unit-tests] 2026/07/19 09:28:48 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=0
  1828. 10.51 s [niks3-go-unit-tests] === NAME TestPinProtectsFromGC
  1829. 10.51 s [niks3-go-unit-tests] client_integration_test.go:709: Pin successfully protected closure from garbage collection
  1830. 10.51 s [niks3-go-unit-tests] --- PASS: TestPinProtectsFromGC (4.72s)
  1831. 10.58 s [niks3-go-unit-tests] 2026/07/19 09:28:48 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=809.439901ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures
  1832. 10.73 s [niks3-go-unit-tests] === NAME TestOrphanedObjectsGCStressTest
  1833. 10.73 s [niks3-go-unit-tests] orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains
  1834. 10.74 s [niks3-go-unit-tests] orphaned_objects_gc_test.go:446: Marked 210 objects for deletion
  1835. 10.84 s [niks3-go-unit-tests] orphaned_objects_gc_test.go:509: Stress test completed successfully:
  1836. 10.84 s [niks3-go-unit-tests] orphaned_objects_gc_test.go:510: - Active objects preserved: 20
  1837. 10.84 s [niks3-go-unit-tests] orphaned_objects_gc_test.go:511: - Objects deleted: 210
  1838. 10.84 s [niks3-go-unit-tests] orphaned_objects_gc_test.go:512: - Total GC'd: 210
  1839. 10.84 s [niks3-go-unit-tests] --- PASS: TestOrphanedObjectsGCStressTest (5.13s)
  1840. 11.39 s [niks3-go-unit-tests] 2026/07/19 09:28:49 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.56095288s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures
  1841. 12.96 s [niks3-go-unit-tests] --- PASS: TestClientErrorHandling (0.00s)
  1842. 12.96 s [niks3-go-unit-tests] --- PASS: TestClientErrorHandling/InvalidStorePath (0.37s)
  1843. 12.96 s [niks3-go-unit-tests] --- PASS: TestClientErrorHandling/InvalidAuthToken (0.75s)
  1844. 12.96 s [niks3-go-unit-tests] --- PASS: TestClientErrorHandling/ServerNotAvailable (3.54s)
  1845. 13.37 s [niks3-go-unit-tests] 2026/07/19 09:28:51 WARN Rate limiter enabled after throttle name=s3-test rate=5
  1846. 13.37 s [niks3-go-unit-tests] 2026/07/19 09:28:51 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."
  1847. 13.37 s [niks3-go-unit-tests] === NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle
  1848. 13.37 s [niks3-go-unit-tests] throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=10
  1849. 13.37 s [niks3-go-unit-tests] throttle_test.go:215: Rate limiter: enabled=true, rate=5.00
  1850. 13.37 s [niks3-go-unit-tests] --- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.91s)
  1851. 13.37 s [niks3-go-unit-tests] PASS
  1852. 13.88 s [niks3-go-unit-tests] {"timestamp":"2026-07-19T09:28:52.00452704Z","level":"ERROR","fields":{"message":"Unknown connection IO error:Cancelled","peer_addr":"127.0.0.1:34962"},"target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":973,"threadName":"rustfs-worker","threadId":"ThreadId(24)"}
  1853. 13.92 s [niks3-go-unit-tests] 2026-07-19 09:28:52.048 UTC [95] LOG: received smart shutdown request
  1854. 13.93 s [niks3-go-unit-tests] 2026-07-19 09:28:52.061 UTC [95] LOG: background worker "logical replication launcher" (PID 105) exited with exit code 1
  1855. 13.94 s [niks3-go-unit-tests] 2026-07-19 09:28:52.065 UTC [100] LOG: shutting down
  1856. 13.94 s [niks3-go-unit-tests] 2026-07-19 09:28:52.074 UTC [100] LOG: checkpoint starting: shutdown immediate
  1857. 23.38 s [niks3-go-unit-tests] 2026/07/19 09:29:01 ERROR failed to kill rustfs error="no such process"
  1858. 23.92 s [niks3-go-unit-tests] 2026/07/19 09:29:02 INFO killed rustfs
  1859. 23.92 s [niks3-go-unit-tests] 2026/07/19 09:29:02 ERROR failed to wait for rustfs error="signal: killed"
  1860. 23.95 s [niks3-go-unit-tests] 2026-07-19 09:29:02.082 UTC [100] PANIC: could not fsync file "base/18760/4145": No such file or directory
  1861. 24.26 s [niks3-go-unit-tests] Running OIDC tests...
  1862. 24.27 s [niks3-go-unit-tests] === RUN TestGlobMatch
  1863. 24.27 s [niks3-go-unit-tests] === PAUSE TestGlobMatch
  1864. 24.27 s [niks3-go-unit-tests] === RUN TestAudienceForIssuer
  1865. 24.27 s [niks3-go-unit-tests] === PAUSE TestAudienceForIssuer
  1866. 24.27 s [niks3-go-unit-tests] === RUN TestValidateToken_ValidToken
  1867. 24.27 s [niks3-go-unit-tests] === PAUSE TestValidateToken_ValidToken
  1868. 24.27 s [niks3-go-unit-tests] === RUN TestValidateToken_WrongAudience
  1869. 24.27 s [niks3-go-unit-tests] === PAUSE TestValidateToken_WrongAudience
  1870. 24.27 s [niks3-go-unit-tests] === RUN TestValidateToken_Expired
  1871. 24.27 s [niks3-go-unit-tests] === PAUSE TestValidateToken_Expired
  1872. 24.27 s [niks3-go-unit-tests] === RUN TestValidateToken_BoundClaimsMismatch
  1873. 24.27 s [niks3-go-unit-tests] === PAUSE TestValidateToken_BoundClaimsMismatch
  1874. 24.27 s [niks3-go-unit-tests] === RUN TestValidateToken_BoundSubjectMismatch
  1875. 24.27 s [niks3-go-unit-tests] === PAUSE TestValidateToken_BoundSubjectMismatch
  1876. 24.27 s [niks3-go-unit-tests] === RUN TestValidateToken_MultipleProviders
  1877. 24.27 s [niks3-go-unit-tests] === PAUSE TestValidateToken_MultipleProviders
  1878. 24.27 s [niks3-go-unit-tests] === RUN TestValidateToken_NoMatchingProvider
  1879. 24.27 s [niks3-go-unit-tests] === PAUSE TestValidateToken_NoMatchingProvider
  1880. 24.27 s [niks3-go-unit-tests] === CONT TestGlobMatch
  1881. 24.27 s [niks3-go-unit-tests] === RUN TestGlobMatch/foo_foo
  1882. 24.27 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/foo_foo
  1883. 24.27 s [niks3-go-unit-tests] === RUN TestGlobMatch/foo_bar
  1884. 24.27 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/foo_bar
  1885. 24.27 s [niks3-go-unit-tests] === RUN TestGlobMatch/*_
  1886. 24.27 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/*_
  1887. 24.27 s [niks3-go-unit-tests] === CONT TestValidateToken_BoundClaimsMismatch
  1888. 24.27 s [niks3-go-unit-tests] === RUN TestGlobMatch/*_anything
  1889. 24.27 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/*_anything
  1890. 24.27 s [niks3-go-unit-tests] === RUN TestGlobMatch/foo*_foo
  1891. 24.27 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/foo*_foo
  1892. 24.27 s [niks3-go-unit-tests] === RUN TestGlobMatch/foo*_foobar
  1893. 24.27 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/foo*_foobar
  1894. 24.27 s [niks3-go-unit-tests] === CONT TestValidateToken_Expired
  1895. 24.27 s [niks3-go-unit-tests] === CONT TestValidateToken_WrongAudience
  1896. 24.27 s [niks3-go-unit-tests] === CONT TestValidateToken_ValidToken
  1897. 24.27 s [niks3-go-unit-tests] === CONT TestAudienceForIssuer
  1898. 24.27 s [niks3-go-unit-tests] --- PASS: TestAudienceForIssuer (0.00s)
  1899. 24.27 s [niks3-go-unit-tests] === CONT TestValidateToken_MultipleProviders
  1900. 24.27 s [niks3-go-unit-tests] === CONT TestValidateToken_NoMatchingProvider
  1901. 24.27 s [niks3-go-unit-tests] === CONT TestValidateToken_BoundSubjectMismatch
  1902. 24.27 s [niks3-go-unit-tests] === RUN TestGlobMatch/foo*_bar
  1903. 24.27 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/foo*_bar
  1904. 24.27 s [niks3-go-unit-tests] === RUN TestGlobMatch/*bar_bar
  1905. 24.27 s [niks3-go-unit-tests] 2026/07/19 09:29:02 INFO OIDC provider initialized name=test
  1906. 24.27 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/*bar_bar
  1907. 24.27 s [niks3-go-unit-tests] === RUN TestGlobMatch/*bar_foobar
  1908. 24.27 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/*bar_foobar
  1909. 24.27 s [niks3-go-unit-tests] 2026/07/19 09:29:02 INFO OIDC provider initialized name=test
  1910. 24.27 s [niks3-go-unit-tests] === RUN TestGlobMatch/*bar_foo
  1911. 24.27 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/*bar_foo
  1912. 24.27 s [niks3-go-unit-tests] === RUN TestGlobMatch/foo*bar_foobar
  1913. 24.27 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/foo*bar_foobar
  1914. 24.27 s [niks3-go-unit-tests] === RUN TestGlobMatch/foo*bar_foo123bar
  1915. 24.27 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/foo*bar_foo123bar
  1916. 24.27 s [niks3-go-unit-tests] === RUN TestGlobMatch/foo*bar_foobarbaz
  1917. 24.27 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/foo*bar_foobarbaz
  1918. 24.50 s [niks3-go-unit-tests] 2026/07/19 09:29:02 INFO OIDC provider initialized name=test
  1919. 24.50 s [niks3-go-unit-tests] === RUN TestGlobMatch/*/*_foo/bar
  1920. 24.50 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/*/*_foo/bar
  1921. 24.50 s [niks3-go-unit-tests] 2026/07/19 09:29:02 INFO OIDC provider initialized name=test
  1922. 24.50 s [niks3-go-unit-tests] === RUN TestGlobMatch/*/*_foo
  1923. 24.52 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/*/*_foo
  1924. 24.52 s [niks3-go-unit-tests] === RUN TestGlobMatch/refs/heads/*_refs/heads/main
  1925. 24.52 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/refs/heads/*_refs/heads/main
  1926. 24.52 s [niks3-go-unit-tests] === RUN TestGlobMatch/refs/heads/*_refs/tags/v1.0
  1927. 24.52 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.0
  1928. 24.52 s [niks3-go-unit-tests] === RUN TestGlobMatch/refs/*/main_refs/heads/main
  1929. 24.52 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/refs/*/main_refs/heads/main
  1930. 24.52 s [niks3-go-unit-tests] === RUN TestGlobMatch/fo?_foo
  1931. 24.52 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/fo?_foo
  1932. 24.52 s [niks3-go-unit-tests] === RUN TestGlobMatch/fo?_fo
  1933. 24.52 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/fo?_fo
  1934. 24.52 s [niks3-go-unit-tests] === RUN TestGlobMatch/fo?_fooo
  1935. 24.52 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/fo?_fooo
  1936. 24.52 s [niks3-go-unit-tests] === RUN TestGlobMatch/?oo_foo
  1937. 24.52 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/?oo_foo
  1938. 24.52 s [niks3-go-unit-tests] === RUN TestGlobMatch/?oo_boo
  1939. 24.52 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/?oo_boo
  1940. 24.52 s [niks3-go-unit-tests] === RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main
  1941. 24.52 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main
  1942. 24.52 s [niks3-go-unit-tests] === RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main
  1943. 24.52 s [niks3-go-unit-tests] === PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main
  1944. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/foo_foo
  1945. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main
  1946. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main
  1947. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/?oo_boo
  1948. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/?oo_foo
  1949. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/fo?_fooo
  1950. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/fo?_fo
  1951. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/foo*bar_foobar
  1952. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/*bar_foo
  1953. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/*_anything
  1954. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/*_
  1955. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/refs/heads/*_refs/heads/main
  1956. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/fo?_foo
  1957. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/refs/*/main_refs/heads/main
  1958. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/refs/heads/*_refs/tags/v1.0
  1959. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/*/*_foo/bar
  1960. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/*/*_foo
  1961. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/foo*bar_foo123bar
  1962. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/foo*bar_foobarbaz
  1963. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/foo_bar
  1964. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/*bar_bar
  1965. 24.52 s [niks3-go-unit-tests] 2026/07/19 09:29:02 INFO OIDC provider initialized name=provider1
  1966. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/foo*_bar
  1967. 24.52 s [niks3-go-unit-tests] 2026/07/19 09:29:02 INFO OIDC provider initialized name=test
  1968. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/foo*_foobar
  1969. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/foo*_foo
  1970. 24.52 s [niks3-go-unit-tests] === CONT TestGlobMatch/*bar_foobar
  1971. 24.52 s [niks3-go-unit-tests] 2026/07/19 09:29:02 INFO OIDC provider initialized name=provider1
  1972. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch (0.25s)
  1973. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/foo_foo (0.00s)
  1974. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)
  1975. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)
  1976. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/?oo_boo (0.00s)
  1977. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/?oo_foo (0.00s)
  1978. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/fo?_fooo (0.00s)
  1979. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/fo?_fo (0.00s)
  1980. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)
  1981. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/*bar_foo (0.00s)
  1982. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/*_anything (0.00s)
  1983. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/*_ (0.00s)
  1984. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)
  1985. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/fo?_foo (0.00s)
  1986. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)
  1987. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)
  1988. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)
  1989. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/*/*_foo (0.00s)
  1990. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)
  1991. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)
  1992. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/foo_bar (0.00s)
  1993. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/*bar_bar (0.00s)
  1994. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/foo*_bar (0.00s)
  1995. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/foo*_foobar (0.00s)
  1996. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/foo*_foo (0.00s)
  1997. 24.52 s [niks3-go-unit-tests] --- PASS: TestGlobMatch/*bar_foobar (0.00s)
  1998. 24.63 s [niks3-go-unit-tests] 2026/07/19 09:29:02 INFO OIDC provider initialized name=provider2
  1999. 24.84 s [niks3-go-unit-tests] --- PASS: TestValidateToken_Expired (0.57s)
  2000. 24.84 s [niks3-go-unit-tests] --- PASS: TestValidateToken_BoundSubjectMismatch (0.57s)
  2001. 24.84 s [niks3-go-unit-tests] --- PASS: TestValidateToken_ValidToken (0.57s)
  2002. 24.84 s [niks3-go-unit-tests] --- PASS: TestValidateToken_BoundClaimsMismatch (0.57s)
  2003. 24.84 s [niks3-go-unit-tests] --- PASS: TestValidateToken_NoMatchingProvider (0.57s)
  2004. 24.84 s [niks3-go-unit-tests] --- PASS: TestValidateToken_WrongAudience (0.58s)
  2005. 24.84 s [niks3-go-unit-tests] --- PASS: TestValidateToken_MultipleProviders (0.57s)
  2006. 24.84 s [niks3-go-unit-tests] PASS
  2007. 24.87 s [niks3-go-unit-tests] Running hook tests...
  2008. 24.88 s [niks3-go-unit-tests] === RUN TestSendPathsEmpty
  2009. 24.88 s [niks3-go-unit-tests] === PAUSE TestSendPathsEmpty
  2010. 24.88 s [niks3-go-unit-tests] === RUN TestQueueEnqueueAndFetch
  2011. 24.88 s [niks3-go-unit-tests] === PAUSE TestQueueEnqueueAndFetch
  2012. 24.88 s [niks3-go-unit-tests] === RUN TestQueueDeduplication
  2013. 24.88 s [niks3-go-unit-tests] === PAUSE TestQueueDeduplication
  2014. 24.88 s [niks3-go-unit-tests] === RUN TestQueueRemove
  2015. 24.88 s [niks3-go-unit-tests] === PAUSE TestQueueRemove
  2016. 24.88 s [niks3-go-unit-tests] === RUN TestQueueFetchBatchLimit
  2017. 24.88 s [niks3-go-unit-tests] === PAUSE TestQueueFetchBatchLimit
  2018. 24.88 s [niks3-go-unit-tests] === RUN TestQueueFetchRemoveLifecycle
  2019. 24.88 s [niks3-go-unit-tests] === PAUSE TestQueueFetchRemoveLifecycle
  2020. 24.88 s [niks3-go-unit-tests] === RUN TestQueueConcurrentWriters
  2021. 24.88 s [niks3-go-unit-tests] === PAUSE TestQueueConcurrentWriters
  2022. 24.88 s [niks3-go-unit-tests] === RUN TestServerClientIntegration
  2023. 24.88 s [niks3-go-unit-tests] === PAUSE TestServerClientIntegration
  2024. 24.88 s [niks3-go-unit-tests] === RUN TestServerQueueError
  2025. 24.88 s [niks3-go-unit-tests] === PAUSE TestServerQueueError
  2026. 24.88 s [niks3-go-unit-tests] === RUN TestGetListenerSocketActivation
  2027. 24.89 s [niks3-go-unit-tests] server_test.go:210: === RUN TestGetListenerSocketActivation
  2028. 24.89 s [niks3-go-unit-tests] --- PASS: TestGetListenerSocketActivation (0.00s)
  2029. 24.89 s [niks3-go-unit-tests] PASS
  2030. 24.89 s [niks3-go-unit-tests]
  2031. 24.89 s [niks3-go-unit-tests] --- PASS: TestGetListenerSocketActivation (0.00s)
  2032. 24.89 s [niks3-go-unit-tests] === RUN TestWorkerUploadsAndRemoves
  2033. 24.89 s [niks3-go-unit-tests] === PAUSE TestWorkerUploadsAndRemoves
  2034. 24.99 s [niks3-go-unit-tests] === RUN TestWorkerSkipsGCdPaths
  2035. 24.99 s [niks3-go-unit-tests] === PAUSE TestWorkerSkipsGCdPaths
  2036. 24.99 s [niks3-go-unit-tests] === RUN TestWorkerPrunesClosureDeps
  2037. 24.99 s [niks3-go-unit-tests] === PAUSE TestWorkerPrunesClosureDeps
  2038. 24.99 s [niks3-go-unit-tests] === CONT TestSendPathsEmpty
  2039. 24.99 s [niks3-go-unit-tests] --- PASS: TestSendPathsEmpty (0.00s)
  2040. 24.99 s [niks3-go-unit-tests] === CONT TestWorkerPrunesClosureDeps
  2041. 24.99 s [niks3-go-unit-tests] === CONT TestQueueConcurrentWriters
  2042. 24.99 s [niks3-go-unit-tests] === CONT TestServerQueueError
  2043. 24.99 s [niks3-go-unit-tests] === CONT TestQueueRemove
  2044. 24.99 s [niks3-go-unit-tests] === CONT TestQueueEnqueueAndFetch
  2045. 24.99 s [niks3-go-unit-tests] === CONT TestServerClientIntegration
  2046. 24.99 s [niks3-go-unit-tests] === CONT TestQueueDeduplication
  2047. 24.99 s [niks3-go-unit-tests] === CONT TestWorkerUploadsAndRemoves
  2048. 24.99 s [niks3-go-unit-tests] 2026/07/19 09:29:03 ERROR Failed to queue paths error="permission denied" count=1
  2049. 24.99 s [niks3-go-unit-tests] === CONT TestWorkerSkipsGCdPaths
  2050. 24.99 s [niks3-go-unit-tests] === CONT TestQueueFetchRemoveLifecycle
  2051. 24.99 s [niks3-go-unit-tests] --- PASS: TestServerQueueError (0.00s)
  2052. 24.99 s [niks3-go-unit-tests] === CONT TestQueueFetchBatchLimit
  2053. 24.99 s [niks3-go-unit-tests] --- PASS: TestServerClientIntegration (0.00s)
  2054. 24.99 s [niks3-go-unit-tests] 2026/07/19 09:29:03 INFO Upload queue status pending=2
  2055. 24.99 s [niks3-go-unit-tests] 2026/07/19 09:29:03 INFO Uploading batch count=1
  2056. 24.99 s [niks3-go-unit-tests] 2026/07/19 09:29:03 INFO Upload queue status pending=2
  2057. 24.99 s [niks3-go-unit-tests] 2026/07/19 09:29:03 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths4243524700/002/nonexistent
  2058. 25.09 s [niks3-go-unit-tests] --- PASS: TestQueueFetchBatchLimit (0.20s)
  2059. 25.09 s [niks3-go-unit-tests] 2026/07/19 09:29:03 INFO Uploading batch count=1
  2060. 25.09 s [niks3-go-unit-tests] --- PASS: TestQueueEnqueueAndFetch (0.20s)
  2061. 25.11 s [niks3-go-unit-tests] --- PASS: TestQueueDeduplication (0.22s)
  2062. 25.11 s [niks3-go-unit-tests] --- PASS: TestQueueFetchRemoveLifecycle (0.22s)
  2063. 25.11 s [niks3-go-unit-tests] 2026/07/19 09:29:03 INFO Upload queue status pending=2
  2064. 25.11 s [niks3-go-unit-tests] 2026/07/19 09:29:03 INFO Uploading batch count=2
  2065. 25.12 s [niks3-go-unit-tests] --- PASS: TestQueueRemove (0.23s)
  2066. 25.12 s [niks3-go-unit-tests] --- PASS: TestWorkerPrunesClosureDeps (0.23s)
  2067. 25.15 s [niks3-go-unit-tests] --- PASS: TestWorkerSkipsGCdPaths (0.27s)
  2068. 25.17 s [niks3-go-unit-tests] --- PASS: TestWorkerUploadsAndRemoves (0.29s)
  2069. 28.27 s [niks3-go-unit-tests] --- PASS: TestQueueConcurrentWriters (3.38s)
  2070. 28.27 s [niks3-go-unit-tests] PASS
  2071. 28.30 s [niks3-go-unit-tests:post-build] Uploading to the NixCI staging cache: /nix/store/5zvjmz49qmzn4nvxz0dqf4bmgb9ch0d9-niks3-go-unit-tests
  2072. 28.35 s [niks3-go-unit-tests:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  2073. 28.36 s [niks3-go-unit-tests:post-build] copying 1 paths...
  2074. 28.36 s [niks3-go-unit-tests:post-build] copying path '/nix/store/5zvjmz49qmzn4nvxz0dqf4bmgb9ch0d9-niks3-go-unit-tests' to 'https://cache.staging.nix-ci.com'...
  2075. 28.47 s [niks3-go-unit-tests:post-build] warning: 'warn-short-path-literals' is deprecated, use 'lint-short-path-literals = ignore' instead
  2076. 28.68 s [niks3-go-unit-tests:post-build] copying 1 paths...
  2077. 28.68 s [niks3-go-unit-tests:post-build] copying path '/nix/store/jp6kjx0b861i6k6x72m47d2sbq7x6jh3-niks3-go-unit-tests.drv' to 'https://cache.staging.nix-ci.com'...
  2078. 28.86 s Uploaded niks3-go-unit-tests in 566ms
  2079. 28.86 s Progress: 1 of 2 built, 44 of 44 downloaded from cache
  2080. 28.86 s Built niks3-go-unit-tests in 25.3s
  2081. 28.86 s Progress: 2 of 2 built, 44 of 44 downloaded from cache
  2082. 28.86 s /nix/store/5zvjmz49qmzn4nvxz0dqf4bmgb9ch0d9-niks3-go-unit-tests
  2083. 28.91 s Build succeeded.