niks3-go-unit-tests
default.checks.aarch64-darwin.go-unit-tests
· build #133
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestCaseHackSuffix5=== PAUSE TestCaseHackSuffix6=== RUN TestFilterOversizedClosures7=== PAUSE TestFilterOversizedClosures8=== RUN TestPartSizeForNAR9=== PAUSE TestPartSizeForNAR10=== RUN TestUploadMultipart_SupersededByPeer11=== PAUSE TestUploadMultipart_SupersededByPeer12=== RUN TestDumpPathMatchesNix13=== PAUSE TestDumpPathMatchesNix14=== RUN TestDumpPathSingleFile15=== PAUSE TestDumpPathSingleFile16=== RUN TestDumpPathWriterError17=== PAUSE TestDumpPathWriterError18=== RUN TestEncodeNixBase3219=== PAUSE TestEncodeNixBase3220=== RUN TestEncodeNixBase32WithRealHash21=== PAUSE TestEncodeNixBase32WithRealHash22=== RUN TestConvertHashToNix3223=== PAUSE TestConvertHashToNix3224=== RUN TestGetStorePathHash25=== PAUSE TestGetStorePathHash26=== RUN TestPathInfoHashCompatibility27=== PAUSE TestPathInfoHashCompatibility28=== RUN TestParsePathInfoJSON29=== PAUSE TestParsePathInfoJSON30=== RUN TestParsePathInfoJSONMultiplePaths31=== PAUSE TestParsePathInfoJSONMultiplePaths32=== RUN TestPathInfoCACompatibility33=== PAUSE TestPathInfoCACompatibility34=== RUN TestRateLimiterFeedback35=== PAUSE TestRateLimiterFeedback36=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess37=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess38=== RUN TestResolveStorePath39=== PAUSE TestResolveStorePath40=== RUN TestDoWithRetry_BodyReplayedViaGetBody41=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody42=== RUN TestShellSplit43=== PAUSE TestShellSplit44=== RUN TestShellSplitErrors45=== PAUSE TestShellSplitErrors46=== RUN TestSetClientTLS47=== PAUSE TestSetClientTLS48=== RUN TestSetClientTLSDoesNotMutateDefaultTransport49=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport50=== RUN TestSetClientTLSErrors51=== PAUSE TestSetClientTLSErrors52=== RUN TestStaticToken53=== PAUSE TestStaticToken54=== RUN TestFileTokenReadsAndCaches55=== PAUSE TestFileTokenReadsAndCaches56=== RUN TestFileTokenMissing57=== PAUSE TestFileTokenMissing58=== RUN TestFileTokenEmpty59=== PAUSE TestFileTokenEmpty60=== RUN TestScriptTokenNoExpiryRerunsEveryCall61=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall62=== RUN TestScriptTokenCachesUntilRefresh63=== PAUSE TestScriptTokenCachesUntilRefresh64=== RUN TestScriptTokenEmptyToken65=== PAUSE TestScriptTokenEmptyToken66=== RUN TestScriptTokenBadJSON67=== PAUSE TestScriptTokenBadJSON68=== RUN TestScriptTokenScriptFails69=== PAUSE TestScriptTokenScriptFails70=== RUN TestScriptTokenEmptyCommand71=== PAUSE TestScriptTokenEmptyCommand72=== RUN TestFilterUpstreamClosure73=== PAUSE TestFilterUpstreamClosure74=== CONT TestDoServerRequestAttachesToken75=== CONT TestFileTokenMissing76=== CONT TestResolveStorePath77=== CONT TestFileTokenReadsAndCaches78=== CONT TestStaticToken79--- PASS: TestStaticToken (0.00s)80=== CONT TestDoWithRetry_BodyReplayedViaGetBody81--- PASS: TestFileTokenMissing (0.00s)82=== CONT TestParsePathInfoJSONMultiplePaths83=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths84=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths85=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths86=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths87=== CONT TestSetClientTLSErrors88=== CONT TestSetClientTLSDoesNotMutateDefaultTransport89=== CONT TestSetClientTLS90=== CONT TestShellSplitErrors91--- PASS: TestShellSplitErrors (0.00s)92=== CONT TestRateLimiterFeedback93=== RUN TestRateLimiterFeedback/429_enables_limiter94=== PAUSE TestRateLimiterFeedback/429_enables_limiter95=== CONT TestShellSplit96=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess97=== RUN TestRateLimiterFeedback/503_enables_limiter98=== PAUSE TestRateLimiterFeedback/503_enables_limiter99=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter100=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter101=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter102=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter103--- PASS: TestFileTokenReadsAndCaches (0.00s)104=== CONT TestDumpPathMatchesNix105=== CONT TestPathInfoCACompatibility106=== RUN TestPathInfoCACompatibility/null_ca_field107=== PAUSE TestPathInfoCACompatibility/null_ca_field108=== RUN TestPathInfoCACompatibility/old_string_format_-_text109=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text110=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive111=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive112=== RUN TestPathInfoCACompatibility/new_structured_format_-_text1132026/08/16 15:40:04 WARN Rate limiter enabled after throttle name=server-test rate=5114=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text115=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method116=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method117=== CONT TestEncodeNixBase32118=== RUN TestEncodeNixBase32/test_string_hash119=== PAUSE TestEncodeNixBase32/test_string_hash120=== RUN TestEncodeNixBase32/empty_input121=== PAUSE TestEncodeNixBase32/empty_input122=== CONT TestDumpPathWriterError123--- PASS: TestShellSplit (0.00s)124=== CONT TestDumpPathSingleFile125--- PASS: TestResolveStorePath (0.00s)126=== CONT TestPathInfoHashCompatibility127=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)128=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)129=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon130=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon131=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI132=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI133=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512134=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512135=== CONT TestParsePathInfoJSON136=== RUN TestParsePathInfoJSON/Nix_format137=== PAUSE TestParsePathInfoJSON/Nix_format138=== RUN TestParsePathInfoJSON/Lix_format139=== PAUSE TestParsePathInfoJSON/Lix_format140=== RUN TestParsePathInfoJSON/empty_input141=== PAUSE TestParsePathInfoJSON/empty_input142=== RUN TestParsePathInfoJSON/whitespace_only143=== PAUSE TestParsePathInfoJSON/whitespace_only144=== RUN TestParsePathInfoJSON/invalid_JSON145=== PAUSE TestParsePathInfoJSON/invalid_JSON146=== CONT TestGetStorePathHash147=== RUN TestGetStorePathHash/valid_store_path148=== PAUSE TestGetStorePathHash/valid_store_path149=== RUN TestGetStorePathHash/basename_without_hyphen_should_error150=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error151=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error152=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error153=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error154=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error155=== CONT TestPartSizeForNAR156=== RUN TestPartSizeForNAR/zero_stays_at_minimum157=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum158=== RUN TestPartSizeForNAR/small_stays_at_minimum159=== PAUSE TestPartSizeForNAR/small_stays_at_minimum160=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum161=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum162=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts163=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts164=== RUN TestPartSizeForNAR/1_TiB165=== PAUSE TestPartSizeForNAR/1_TiB166=== RUN TestPartSizeForNAR/5_TiB_S3_max_object167=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object168=== RUN TestPartSizeForNAR/capped_at_5_GiB169=== PAUSE TestPartSizeForNAR/capped_at_5_GiB170=== CONT TestUploadMultipart_SupersededByPeer171=== RUN TestUploadMultipart_SupersededByPeer/exists172=== PAUSE TestUploadMultipart_SupersededByPeer/exists173=== RUN TestUploadMultipart_SupersededByPeer/missing174=== PAUSE TestUploadMultipart_SupersededByPeer/missing175=== CONT TestFilterOversizedClosures176=== RUN TestFilterOversizedClosures/no_limit_keeps_everything177=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything178=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped179=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped1802026/08/16 15:40:04 WARN Rate limiter enabled after throttle name=server-test rate=5181=== RUN TestFilterOversizedClosures/all_closures_skipped182=== PAUSE TestFilterOversizedClosures/all_closures_skipped183=== CONT TestCaseHackSuffix1842026/08/16 15:40:04 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:55973185--- PASS: TestDoServerRequestAttachesToken (0.00s)186=== CONT TestConvertHashToNix32187=== RUN TestConvertHashToNix32/SRI_format_to_Nix32188=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32189=== RUN TestConvertHashToNix32/already_Nix32_format1902026/08/16 15:40:04 WARN Rate limiter backed off name=server-test rate=5191=== PAUSE TestConvertHashToNix32/already_Nix32_format1922026/08/16 15:40:04 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:55973193=== RUN TestConvertHashToNix32/invalid_format194=== PAUSE TestConvertHashToNix32/invalid_format195=== CONT TestScriptTokenBadJSON196--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)197=== CONT TestFilterUpstreamClosure198=== RUN TestFilterUpstreamClosure/empty_configuration_disables_filtering199=== PAUSE TestFilterUpstreamClosure/empty_configuration_disables_filtering200=== RUN TestFilterUpstreamClosure/signed_path_cuts_its_dependency_subtree201=== PAUSE TestFilterUpstreamClosure/signed_path_cuts_its_dependency_subtree202=== RUN TestFilterUpstreamClosure/separate_root_keeps_a_path_below_an_upstream_boundary203=== PAUSE TestFilterUpstreamClosure/separate_root_keeps_a_path_below_an_upstream_boundary204=== RUN TestFilterUpstreamClosure/signed_root_removes_its_whole_closure205=== RUN TestSetClientTLSErrors/missing_cert_file206=== PAUSE TestFilterUpstreamClosure/signed_root_removes_its_whole_closure207=== RUN TestFilterUpstreamClosure/key_names_match_exactly208=== PAUSE TestFilterUpstreamClosure/key_names_match_exactly209=== RUN TestFilterUpstreamClosure/any_configured_key_can_match210=== PAUSE TestFilterUpstreamClosure/any_configured_key_can_match211--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)212=== CONT TestScriptTokenScriptFails213=== PAUSE TestSetClientTLSErrors/missing_cert_file214=== RUN TestSetClientTLSErrors/missing_key_file215=== PAUSE TestSetClientTLSErrors/missing_key_file216=== RUN TestSetClientTLSErrors/missing_ca_file217=== PAUSE TestSetClientTLSErrors/missing_ca_file218=== RUN TestSetClientTLSErrors/invalid_ca_file219=== PAUSE TestSetClientTLSErrors/invalid_ca_file220=== CONT TestScriptTokenEmptyCommand221--- PASS: TestScriptTokenEmptyCommand (0.00s)222=== CONT TestScriptTokenEmptyToken223=== CONT TestScriptTokenCachesUntilRefresh224=== RUN TestSetClientTLS/rejects_connection_without_client_cert225=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert226=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA227=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA228=== RUN TestSetClientTLS/preserves_debug_logging_transport229=== PAUSE TestSetClientTLS/preserves_debug_logging_transport230=== CONT TestScriptTokenNoExpiryRerunsEveryCall231--- PASS: TestScriptTokenScriptFails (0.01s)232=== CONT TestFileTokenEmpty233--- PASS: TestFileTokenEmpty (0.00s)234=== CONT TestEncodeNixBase32WithRealHash235--- PASS: TestEncodeNixBase32WithRealHash (0.00s)236=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths237=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths238--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)239 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)240 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)241=== CONT TestRateLimiterFeedback/429_enables_limiter2422026/08/16 15:40:04 WARN Rate limiter enabled after throttle name=server-test rate=52432026/08/16 15:40:04 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:559792442026/08/16 15:40:04 WARN Rate limiter backed off name=server-test rate=5245=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter246=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter247=== CONT TestRateLimiterFeedback/503_enables_limiter2482026/08/16 15:40:04 WARN Rate limiter enabled after throttle name=server-test rate=52492026/08/16 15:40:04 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:559852502026/08/16 15:40:04 WARN Rate limiter backed off name=server-test rate=5251--- PASS: TestRateLimiterFeedback (0.00s)252 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)253 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)254 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)255 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)256=== CONT TestPathInfoCACompatibility/null_ca_field257=== CONT TestEncodeNixBase32/test_string_hash258=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method259=== CONT TestPathInfoCACompatibility/new_structured_format_-_text260=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive261=== CONT TestPathInfoCACompatibility/old_string_format_-_text262--- PASS: TestPathInfoCACompatibility (0.00s)263 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)264 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)265 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)266 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)267 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)268=== CONT TestEncodeNixBase32/empty_input269--- PASS: TestEncodeNixBase32 (0.00s)270 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)271 --- PASS: TestEncodeNixBase32/empty_input (0.00s)272=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)273=== CONT TestParsePathInfoJSON/Nix_format274=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512275=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI276=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon277--- PASS: TestPathInfoHashCompatibility (0.00s)278 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)279 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)280 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)281 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)282=== CONT TestParsePathInfoJSON/whitespace_only283=== CONT TestParsePathInfoJSON/invalid_JSON284=== CONT TestParsePathInfoJSON/empty_input285=== CONT TestParsePathInfoJSON/Lix_format286--- PASS: TestParsePathInfoJSON (0.00s)287 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)288 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)289 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)290 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)291 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)292=== CONT TestGetStorePathHash/valid_store_path293=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error294=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error295=== CONT TestGetStorePathHash/basename_without_hyphen_should_error296--- PASS: TestGetStorePathHash (0.00s)297 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)298 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)299 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)300 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)301=== CONT TestPartSizeForNAR/zero_stays_at_minimum302=== CONT TestUploadMultipart_SupersededByPeer/exists303--- PASS: TestScriptTokenBadJSON (0.01s)304=== CONT TestPartSizeForNAR/capped_at_5_GiB305=== CONT TestPartSizeForNAR/5_TiB_S3_max_object306=== CONT TestPartSizeForNAR/1_TiB307=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts308=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum309=== CONT TestPartSizeForNAR/small_stays_at_minimum310=== CONT TestFilterOversizedClosures/no_limit_keeps_everything311=== CONT TestUploadMultipart_SupersededByPeer/missing312--- PASS: TestPartSizeForNAR (0.00s)313 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)314 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)315 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)316 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)317 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)318 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)319 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)320=== CONT TestFilterOversizedClosures/all_closures_skipped3212026/08/16 15:40:04 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=50322=== CONT TestConvertHashToNix32/SRI_format_to_Nix32323=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3242026/08/16 15:40:04 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000325--- PASS: TestFilterOversizedClosures (0.00s)326 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)327 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)328 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)329=== CONT TestConvertHashToNix32/invalid_format330=== CONT TestConvertHashToNix32/already_Nix32_format331--- PASS: TestConvertHashToNix32 (0.00s)332 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)333 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)334 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)335=== CONT TestFilterUpstreamClosure/empty_configuration_disables_filtering336=== CONT TestFilterUpstreamClosure/key_names_match_exactly337=== CONT TestFilterUpstreamClosure/separate_root_keeps_a_path_below_an_upstream_boundary338=== CONT TestFilterUpstreamClosure/signed_root_removes_its_whole_closure339=== CONT TestFilterUpstreamClosure/any_configured_key_can_match340=== CONT TestFilterUpstreamClosure/signed_path_cuts_its_dependency_subtree341--- PASS: TestFilterUpstreamClosure (0.00s)342 --- PASS: TestFilterUpstreamClosure/empty_configuration_disables_filtering (0.00s)343 --- PASS: TestFilterUpstreamClosure/key_names_match_exactly (0.00s)344 --- PASS: TestFilterUpstreamClosure/separate_root_keeps_a_path_below_an_upstream_boundary (0.00s)345 --- PASS: TestFilterUpstreamClosure/signed_root_removes_its_whole_closure (0.00s)346 --- PASS: TestFilterUpstreamClosure/any_configured_key_can_match (0.00s)347 --- PASS: TestFilterUpstreamClosure/signed_path_cuts_its_dependency_subtree (0.00s)348=== CONT TestSetClientTLSErrors/missing_cert_file349=== CONT TestSetClientTLSErrors/invalid_ca_file350--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)351 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)352 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)353=== CONT TestSetClientTLSErrors/missing_ca_file354=== CONT TestSetClientTLSErrors/missing_key_file355=== CONT TestSetClientTLS/rejects_connection_without_client_cert356=== CONT TestSetClientTLS/preserves_debug_logging_transport357--- PASS: TestSetClientTLSErrors (0.01s)358 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)359 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)360 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)361 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)362--- PASS: TestScriptTokenEmptyToken (0.01s)363=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3642026/08/16 15:40:04 http: TLS handshake error from 127.0.0.1:55992: remote error: tls: bad certificate365--- PASS: TestSetClientTLS (0.01s)366 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)367 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)368 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)369--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)370--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)371--- PASS: TestDumpPathWriterError (0.04s)372--- PASS: TestDumpPathSingleFile (0.05s)373--- PASS: TestCaseHackSuffix (0.05s)374--- PASS: TestDumpPathMatchesNix (0.07s)375--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)376PASS377Running server tests...378The files belonging to this database system will be owned by user "_nixbld1".379This user must also own the server process.380381The database cluster will be initialized with locale "C".382The default database encoding has accordingly been set to "SQL_ASCII".383The default text search configuration will be set to "english".384385Data page checksums are enabled.386387creating directory /nix/var/nix/builds/nix-4114-2679204974/postgres4173643391/data ... ok388creating subdirectories ... ok389selecting dynamic shared memory implementation ... posix390selecting default "max_connections" ... 100391selecting default "shared_buffers" ... 128MB392selecting default time zone ... UTC393creating configuration files ... ok394running bootstrap script ... ok395performing post-bootstrap initialization ... ok396syncing data to disk ... ok397398initdb: warning: enabling "trust" authentication for local connections399initdb: 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.400401Success. You can now start the database server using:402403 pg_ctl -D /nix/var/nix/builds/nix-4114-2679204974/postgres4173643391/data -l logfile start404405/nix/var/nix/builds/nix-4114-2679204974/postgres4173643391:5432 - no response4062026-08-16 15:40:05.794 UTC [4178] LOG: starting PostgreSQL 18.4 on aarch64-apple-darwin25.5.0, compiled by clang version 21.1.8, 64-bit4072026-08-16 15:40:05.794 UTC [4178] LOG: listening on Unix socket "/nix/var/nix/builds/nix-4114-2679204974/postgres4173643391/.s.PGSQL.5432"4082026-08-16 15:40:05.796 UTC [4185] LOG: database system was shut down at 2026-08-16 15:40:05 UTC4092026-08-16 15:40:05.797 UTC [4178] LOG: database system is ready to accept connections410/nix/var/nix/builds/nix-4114-2679204974/postgres4173643391:5432 - accepting connections411=== RUN TestService_AuthMiddleware412=== PAUSE TestService_AuthMiddleware413=== RUN TestService_AuthMiddleware_MTLSProxyHeader414=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader415=== RUN TestService_AuthMiddleware_MTLSBoundSubjects416=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects417=== RUN TestService_ReadAuthMiddleware418=== PAUSE TestService_ReadAuthMiddleware419=== RUN TestService_AuthMiddleware_OIDC420=== PAUSE TestService_AuthMiddleware_OIDC421=== RUN TestCacheConfigHandler422=== PAUSE TestCacheConfigHandler423=== RUN TestCacheStatsHandler424=== PAUSE TestCacheStatsHandler425=== RUN TestClientCADerivations426=== PAUSE TestClientCADerivations427=== RUN TestClientErrorHandling428=== PAUSE TestClientErrorHandling429=== RUN TestClientIntegration430=== PAUSE TestClientIntegration431=== RUN TestClientMultipleUploads432=== PAUSE TestClientMultipleUploads433=== RUN TestClientWithDependencies434=== PAUSE TestClientWithDependencies435=== RUN TestPinProtectsFromGC436=== PAUSE TestPinProtectsFromGC437=== RUN TestGCAdvisoryLockBlocksConcurrentRun4382026-08-16 15:40:06.181 UTC [4262] ERROR: relation "goose_db_version" does not exist at character 364392026-08-16 15:40:06.181 UTC [4262] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4402026/08/16 15:40:06 OK 20241026095416_initial_model.sql (3.37ms)4412026/08/16 15:40:06 OK 20251210153512_drop_unused_gin_index.sql (384.79µs)4422026/08/16 15:40:06 OK 20251218171726_add_pins.sql (763.08µs)4432026/08/16 15:40:06 OK 20260628120000_add_object_size_and_stats.sql (859.54µs)4442026/08/16 15:40:06 goose: successfully migrated database to version: 202606281200004452026/08/16 15:40:06 OK 1_commit_pending_closure.sql (880.83µs)4462026/08/16 15:40:06 OK 2_object_stats_trigger.sql (203.83µs)4472026/08/16 15:40:06 goose: up to current file version: 2448--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.22s)449=== RUN TestGCBugBareHashReferences450=== PAUSE TestGCBugBareHashReferences451=== RUN TestGCMetrics452=== PAUSE TestGCMetrics453=== RUN TestGCTaskStore_StartNew454=== PAUSE TestGCTaskStore_StartNew455=== RUN TestGCTaskStore_DeduplicateSameParams456=== PAUSE TestGCTaskStore_DeduplicateSameParams457=== RUN TestGCTaskStore_ConflictDifferentParams458=== PAUSE TestGCTaskStore_ConflictDifferentParams459=== RUN TestGCTaskStore_GetEmpty460=== PAUSE TestGCTaskStore_GetEmpty461=== RUN TestGCTaskStore_GetReturnsLatest462=== PAUSE TestGCTaskStore_GetReturnsLatest463=== RUN TestGCTaskStore_CompletedAllowsNewTask464=== PAUSE TestGCTaskStore_CompletedAllowsNewTask465=== RUN TestGCTaskStore_PhaseUpdates466=== PAUSE TestGCTaskStore_PhaseUpdates467=== RUN TestGCTaskStore_Fail468=== PAUSE TestGCTaskStore_Fail469=== RUN TestGracefulShutdownDrainsInflight470=== PAUSE TestGracefulShutdownDrainsInflight471=== RUN TestService_healthCheckHandler472=== PAUSE TestService_healthCheckHandler473=== RUN TestGenerateLandingPage474=== PAUSE TestGenerateLandingPage475=== RUN TestCacheConfigHandlerMaxNarSize476=== PAUSE TestCacheConfigHandlerMaxNarSize477=== RUN TestCreatePendingClosureRejectsOversizedNAR478=== PAUSE TestCreatePendingClosureRejectsOversizedNAR479=== RUN TestNARDeduplicationMetadataUploadBug480=== PAUSE TestNARDeduplicationMetadataUploadBug481=== RUN TestMetricsInventory482=== PAUSE TestMetricsInventory483=== RUN TestService_NativeMTLS484=== PAUSE TestService_NativeMTLS485=== RUN TestServerTLSConfig486=== PAUSE TestServerTLSConfig487=== RUN TestMultipartCleanup488=== PAUSE TestMultipartCleanup489=== RUN TestObjectStatsTrigger490=== PAUSE TestObjectStatsTrigger491=== RUN TestOrphanedObjectsGC492=== PAUSE TestOrphanedObjectsGC493=== RUN TestOrphanedObjectsGCStressTest494=== PAUSE TestOrphanedObjectsGCStressTest495=== RUN TestResurrectedObjectNotDeleted496=== PAUSE TestResurrectedObjectNotDeleted497=== RUN TestParseSingleRange498=== PAUSE TestParseSingleRange499=== RUN TestIsValidCachePath500=== PAUSE TestIsValidCachePath501=== RUN TestReadProxyNarinfo502=== PAUSE TestReadProxyNarinfo503=== RUN TestReadProxyNarinfoAlreadyDecompressed504=== PAUSE TestReadProxyNarinfoAlreadyDecompressed505=== RUN TestReadProxyNarStreaming506=== PAUSE TestReadProxyNarStreaming507=== RUN TestReadProxy404508=== PAUSE TestReadProxy404509=== RUN TestReadProxyInvalidPath510=== PAUSE TestReadProxyInvalidPath511=== RUN TestReadProxyHead512=== PAUSE TestReadProxyHead513=== RUN TestReadProxyConditionalGet514=== PAUSE TestReadProxyConditionalGet515=== RUN TestReadProxyRootRedirectsToIndexHTML516=== PAUSE TestReadProxyRootRedirectsToIndexHTML517=== RUN TestReadProxyDisabled518=== PAUSE TestReadProxyDisabled519=== RUN TestReadProxyRangeRequest520=== PAUSE TestReadProxyRangeRequest521=== RUN TestRedundantMultipartUpload522=== PAUSE TestRedundantMultipartUpload523=== RUN TestCompleteMultipartUpload_ErrorButObjectExists524=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists525=== RUN TestCompletedNarNotReofferedAcrossClosures526=== PAUSE TestCompletedNarNotReofferedAcrossClosures527=== RUN TestPresignedUploadRegisteredBeforeCommit528=== PAUSE TestPresignedUploadRegisteredBeforeCommit529=== RUN TestService_Rustfstest530=== PAUSE TestService_Rustfstest531=== RUN TestParseSize532=== PAUSE TestParseSize533=== RUN TestSkippedUploadsHandler534=== PAUSE TestSkippedUploadsHandler535=== RUN TestSystemdListenerNotActivated536--- PASS: TestSystemdListenerNotActivated (0.00s)537=== RUN TestWatchdogBeatsWhenHealthy538--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)539=== RUN TestWatchdogSkipsWhenUnhealthy5402026/08/16 15:40:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5412026/08/16 15:40:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5422026/08/16 15:40:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5432026/08/16 15:40:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5442026/08/16 15:40:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5452026/08/16 15:40:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5462026/08/16 15:40:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5472026/08/16 15:40:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5482026/08/16 15:40:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5492026/08/16 15:40:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"550--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)551=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle552=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle553=== RUN TestProxyWriteTimeout554=== PAUSE TestProxyWriteTimeout555=== RUN TestIsValidUploadKey556=== PAUSE TestIsValidUploadKey557=== RUN TestUploadHandlersRejectInvalidKeys558=== PAUSE TestUploadHandlersRejectInvalidKeys559=== RUN TestUploadHandlersRejectOversizedBody560=== PAUSE TestUploadHandlersRejectOversizedBody561=== RUN TestService_cleanupPendingClosuresHandler562=== PAUSE TestService_cleanupPendingClosuresHandler563=== RUN TestService_createPendingClosureHandler564=== PAUSE TestService_createPendingClosureHandler565=== RUN TestService_verifyS3Integrity566=== PAUSE TestService_verifyS3Integrity567=== RUN TestCompleteMultipartUnregistered568=== PAUSE TestCompleteMultipartUnregistered569=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT570=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT571=== RUN TestGCMissingUpstreamReference572=== PAUSE TestGCMissingUpstreamReference573=== CONT TestService_AuthMiddleware574=== CONT TestOrphanedObjectsGC575=== CONT TestCompletedNarNotReofferedAcrossClosures576=== CONT TestReadProxyInvalidPath577=== CONT TestReadProxy404578=== CONT TestParseSize579--- PASS: TestParseSize (0.00s)580=== CONT TestService_Rustfstest581=== CONT TestReadProxyNarStreaming582=== CONT TestGCTaskStore_ConflictDifferentParams583=== CONT TestUploadHandlersRejectInvalidKeys584=== CONT TestPresignedUploadRegisteredBeforeCommit585--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)586=== CONT TestObjectStatsTrigger587=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info588=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info589=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal590=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal591=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key592=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key593=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key594=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key595=== CONT TestMultipartCleanup5962026-08-16 15:40:06.789 UTC [4291] ERROR: relation "goose_db_version" does not exist at character 365972026-08-16 15:40:06.789 UTC [4291] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5982026-08-16 15:40:06.791 UTC [4292] ERROR: relation "goose_db_version" does not exist at character 365992026-08-16 15:40:06.791 UTC [4292] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6002026-08-16 15:40:06.792 UTC [4293] ERROR: relation "goose_db_version" does not exist at character 366012026-08-16 15:40:06.792 UTC [4293] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6022026-08-16 15:40:06.793 UTC [4294] ERROR: relation "goose_db_version" does not exist at character 366032026-08-16 15:40:06.793 UTC [4294] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6042026-08-16 15:40:06.793 UTC [4296] ERROR: relation "goose_db_version" does not exist at character 366052026-08-16 15:40:06.793 UTC [4296] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6062026-08-16 15:40:06.794 UTC [4295] ERROR: relation "goose_db_version" does not exist at character 366072026-08-16 15:40:06.794 UTC [4295] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6082026-08-16 15:40:06.795 UTC [4297] ERROR: relation "goose_db_version" does not exist at character 366092026-08-16 15:40:06.795 UTC [4297] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6102026-08-16 15:40:06.795 UTC [4299] ERROR: relation "goose_db_version" does not exist at character 366112026-08-16 15:40:06.795 UTC [4299] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6122026-08-16 15:40:06.795 UTC [4298] ERROR: relation "goose_db_version" does not exist at character 366132026-08-16 15:40:06.795 UTC [4298] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6142026-08-16 15:40:06.796 UTC [4300] ERROR: relation "goose_db_version" does not exist at character 366152026-08-16 15:40:06.796 UTC [4300] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6162026/08/16 15:40:06 OK 20241026095416_initial_model.sql (7.09ms)6172026/08/16 15:40:06 OK 20241026095416_initial_model.sql (8.72ms)6182026/08/16 15:40:06 OK 20241026095416_initial_model.sql (7.47ms)6192026/08/16 15:40:06 OK 20251210153512_drop_unused_gin_index.sql (1.08ms)6202026/08/16 15:40:06 OK 20251210153512_drop_unused_gin_index.sql (870.5µs)6212026/08/16 15:40:06 OK 20241026095416_initial_model.sql (5.93ms)6222026/08/16 15:40:06 OK 20251210153512_drop_unused_gin_index.sql (900.13µs)6232026/08/16 15:40:06 OK 20241026095416_initial_model.sql (9.38ms)6242026/08/16 15:40:06 OK 20251210153512_drop_unused_gin_index.sql (1.03ms)6252026/08/16 15:40:06 OK 20251218171726_add_pins.sql (1.82ms)6262026/08/16 15:40:06 OK 20251218171726_add_pins.sql (2ms)6272026/08/16 15:40:06 OK 20251210153512_drop_unused_gin_index.sql (799.92µs)6282026/08/16 15:40:06 OK 20241026095416_initial_model.sql (7.37ms)6292026/08/16 15:40:06 OK 20251218171726_add_pins.sql (1.69ms)6302026/08/16 15:40:06 OK 20241026095416_initial_model.sql (8.12ms)6312026/08/16 15:40:06 OK 20241026095416_initial_model.sql (10.23ms)6322026/08/16 15:40:06 OK 20251210153512_drop_unused_gin_index.sql (871.83µs)6332026/08/16 15:40:06 OK 20251218171726_add_pins.sql (1.82ms)6342026/08/16 15:40:06 OK 20260628120000_add_object_size_and_stats.sql (1.97ms)6352026/08/16 15:40:06 goose: successfully migrated database to version: 202606281200006362026/08/16 15:40:06 OK 20241026095416_initial_model.sql (7.9ms)6372026/08/16 15:40:06 OK 20251210153512_drop_unused_gin_index.sql (1.04ms)6382026/08/16 15:40:06 OK 20260628120000_add_object_size_and_stats.sql (2.01ms)6392026/08/16 15:40:06 goose: successfully migrated database to version: 202606281200006402026/08/16 15:40:06 OK 20260628120000_add_object_size_and_stats.sql (1.63ms)6412026/08/16 15:40:06 goose: successfully migrated database to version: 202606281200006422026/08/16 15:40:06 OK 20251210153512_drop_unused_gin_index.sql (1.12ms)6432026/08/16 15:40:06 OK 20251218171726_add_pins.sql (1.8ms)6442026/08/16 15:40:06 OK 20241026095416_initial_model.sql (9.14ms)6452026/08/16 15:40:06 OK 20251210153512_drop_unused_gin_index.sql (902µs)6462026/08/16 15:40:06 OK 1_commit_pending_closure.sql (1.15ms)6472026/08/16 15:40:06 OK 20251218171726_add_pins.sql (1.26ms)6482026/08/16 15:40:06 OK 20251218171726_add_pins.sql (2ms)6492026/08/16 15:40:06 OK 1_commit_pending_closure.sql (1.48ms)6502026/08/16 15:40:06 OK 20260628120000_add_object_size_and_stats.sql (1.87ms)6512026/08/16 15:40:06 goose: successfully migrated database to version: 202606281200006522026/08/16 15:40:06 OK 20251210153512_drop_unused_gin_index.sql (909.71µs)6532026/08/16 15:40:06 OK 1_commit_pending_closure.sql (1.55ms)6542026/08/16 15:40:06 OK 2_object_stats_trigger.sql (542.67µs)6552026/08/16 15:40:06 goose: up to current file version: 26562026/08/16 15:40:06 OK 20260628120000_add_object_size_and_stats.sql (1.8ms)6572026/08/16 15:40:06 goose: successfully migrated database to version: 202606281200006582026/08/16 15:40:06 OK 20251218171726_add_pins.sql (1.26ms)6592026/08/16 15:40:06 OK 2_object_stats_trigger.sql (749.38µs)6602026/08/16 15:40:06 goose: up to current file version: 26612026/08/16 15:40:06 OK 20251218171726_add_pins.sql (2.03ms)6622026/08/16 15:40:06 OK 2_object_stats_trigger.sql (655.96µs)6632026/08/16 15:40:06 goose: up to current file version: 26642026/08/16 15:40:06 OK 1_commit_pending_closure.sql (1ms)6652026/08/16 15:40:06 OK 20260628120000_add_object_size_and_stats.sql (1.32ms)6662026/08/16 15:40:06 goose: successfully migrated database to version: 202606281200006672026/08/16 15:40:06 OK 2_object_stats_trigger.sql (605.96µs)6682026/08/16 15:40:06 goose: up to current file version: 26692026/08/16 15:40:06 OK 20260628120000_add_object_size_and_stats.sql (1.91ms)6702026/08/16 15:40:06 goose: successfully migrated database to version: 202606281200006712026/08/16 15:40:06 OK 20251218171726_add_pins.sql (1.64ms)6722026/08/16 15:40:06 OK 20260628120000_add_object_size_and_stats.sql (1.25ms)6732026/08/16 15:40:06 goose: successfully migrated database to version: 202606281200006742026/08/16 15:40:06 OK 1_commit_pending_closure.sql (1.63ms)6752026/08/16 15:40:06 OK 20260628120000_add_object_size_and_stats.sql (1.67ms)6762026/08/16 15:40:06 goose: successfully migrated database to version: 202606281200006772026/08/16 15:40:06 OK 1_commit_pending_closure.sql (1.14ms)6782026/08/16 15:40:06 OK 2_object_stats_trigger.sql (279.17µs)6792026/08/16 15:40:06 goose: up to current file version: 26802026/08/16 15:40:06 OK 2_object_stats_trigger.sql (517.13µs)6812026/08/16 15:40:06 goose: up to current file version: 26822026/08/16 15:40:06 OK 1_commit_pending_closure.sql (1.05ms)6832026/08/16 15:40:06 OK 1_commit_pending_closure.sql (1.47ms)6842026/08/16 15:40:06 OK 1_commit_pending_closure.sql (1.13ms)6852026/08/16 15:40:06 OK 2_object_stats_trigger.sql (297.46µs)6862026/08/16 15:40:06 goose: up to current file version: 26872026/08/16 15:40:06 OK 2_object_stats_trigger.sql (405.5µs)6882026/08/16 15:40:06 goose: up to current file version: 26892026/08/16 15:40:06 OK 2_object_stats_trigger.sql (180.79µs)6902026/08/16 15:40:06 goose: up to current file version: 2691{"timestamp":"2026-08-16T15:40:06.813877Z","level":"ERROR","duration":"92.542µs","resp":"Response { status: 503, version: HTTP/1.1, headers: {\"content-type\": \"application/xml\"}, body: Body { once: b\"<?xml version=\\\"1.0\\\" encoding=\\\"UTF-8\\\"?><Error><Code>SlowDown</Code><Message>bucket creation concurrency limit reached; retry later</Message></Error>\" } }","target":"s3s::service","filename":"/nix/var/nix/builds/nix-57705-2947227838/rustfs-1.0.0-beta.12-vendor/source-git-1/s3s-0.14.1/src/service.rs","line_number":640,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}692{"timestamp":"2026-08-16T15:40:06.813974Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"1abeda2a-e878-45ea-a38a-16aef0fa41bb","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket10/","status_code":503,"duration_ms":0,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}6932026/08/16 15:40:06 OK 20260628120000_add_object_size_and_stats.sql (4.68ms)6942026/08/16 15:40:06 goose: successfully migrated database to version: 202606281200006952026/08/16 15:40:06 OK 1_commit_pending_closure.sql (765.58µs)6962026/08/16 15:40:06 OK 2_object_stats_trigger.sql (208.13µs)6972026/08/16 15:40:06 goose: up to current file version: 2698{"timestamp":"2026-08-16T15:40:06.817832Z","level":"ERROR","duration":"58.708µs","resp":"Response { status: 503, version: HTTP/1.1, headers: {\"content-type\": \"application/xml\"}, body: Body { once: b\"<?xml version=\\\"1.0\\\" encoding=\\\"UTF-8\\\"?><Error><Code>SlowDown</Code><Message>bucket creation concurrency limit reached; retry later</Message></Error>\" } }","target":"s3s::service","filename":"/nix/var/nix/builds/nix-57705-2947227838/rustfs-1.0.0-beta.12-vendor/source-git-1/s3s-0.14.1/src/service.rs","line_number":640,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}699{"timestamp":"2026-08-16T15:40:06.817844Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"3754677b-cf10-4bc7-8737-5a936fdfe778","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket11/","status_code":503,"duration_ms":0,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}700{"timestamp":"2026-08-16T15:40:06.823534Z","level":"ERROR","duration":"17.458µs","resp":"Response { status: 503, version: HTTP/1.1, headers: {\"content-type\": \"application/xml\"}, body: Body { once: b\"<?xml version=\\\"1.0\\\" encoding=\\\"UTF-8\\\"?><Error><Code>SlowDown</Code><Message>bucket creation concurrency limit reached; retry later</Message></Error>\" } }","target":"s3s::service","filename":"/nix/var/nix/builds/nix-57705-2947227838/rustfs-1.0.0-beta.12-vendor/source-git-1/s3s-0.14.1/src/service.rs","line_number":640,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}701{"timestamp":"2026-08-16T15:40:06.82354Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"dc8b831e-050f-478d-9295-d41dfdb8d9e9","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"PUT","uri":"/bucket11/","status_code":503,"duration_ms":0,"result":"server_error","target":"rustfs::server::layer","filename":"rustfs/src/server/layer.rs","line_number":392,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}702--- PASS: TestReadProxyInvalidPath (0.43s)703=== CONT TestServerTLSConfig704=== RUN TestServerTLSConfig/no_client_CA705=== PAUSE TestServerTLSConfig/no_client_CA706=== RUN TestServerTLSConfig/missing_CA_file707=== PAUSE TestServerTLSConfig/missing_CA_file708=== RUN TestServerTLSConfig/not_a_PEM_file709=== PAUSE TestServerTLSConfig/not_a_PEM_file710=== CONT TestService_NativeMTLS7112026/08/16 15:40:06 INFO Received uploads request method=POST path=/api/pending_closures712--- PASS: TestReadProxy404 (0.56s)713=== CONT TestMetricsInventory714--- PASS: TestReadProxyNarStreaming (0.63s)715=== CONT TestNARDeduplicationMetadataUploadBug7162026/08/16 15:40:07 INFO Received cleanup request method=DELETE path=/api/pending_closures7172026/08/16 15:40:07 INFO Aborted multipart uploads count=1718--- PASS: TestMultipartCleanup (0.67s)719=== CONT TestCreatePendingClosureRejectsOversizedNAR7202026/08/16 15:40:07 INFO Received uploads request method=POST path=/api/pending_closures721--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)722=== CONT TestCacheConfigHandlerMaxNarSize723--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)724=== CONT TestGenerateLandingPage725--- PASS: TestGenerateLandingPage (0.00s)726=== CONT TestService_healthCheckHandler7272026/08/16 15:40:07 INFO Received uploads request method=POST path=/api/pending_closures728--- PASS: TestService_Rustfstest (0.73s)729=== CONT TestGracefulShutdownDrainsInflight7302026/08/16 15:40:07 INFO Starting HTTP server address=127.0.0.1:560227312026/08/16 15:40:07 INFO Shutdown signal received, draining in-flight requests timeout=10s732--- PASS: TestGracefulShutdownDrainsInflight (0.07s)733=== CONT TestGCTaskStore_Fail734--- PASS: TestGCTaskStore_Fail (0.00s)735=== CONT TestGCTaskStore_PhaseUpdates736--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)737=== CONT TestGCTaskStore_CompletedAllowsNewTask738--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)739=== CONT TestGCTaskStore_GetReturnsLatest740--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)741=== CONT TestGCTaskStore_GetEmpty742--- PASS: TestGCTaskStore_GetEmpty (0.00s)743=== CONT TestReadProxyDisabled744--- PASS: TestObjectStatsTrigger (0.80s)745=== CONT TestCompleteMultipartUpload_ErrorButObjectExists7462026/08/16 15:40:07 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"747--- PASS: TestService_AuthMiddleware (0.85s)748=== CONT TestRedundantMultipartUpload7492026/08/16 15:40:07 INFO Received uploads request method=POST path=/api/pending_closures7502026/08/16 15:40:07 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7512026/08/16 15:40:07 INFO Received uploads request method=POST path=/api/pending_closures752--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.12s)753=== CONT TestReadProxyRangeRequest754=== NAME TestOrphanedObjectsGC755 orphaned_objects_gc_test.go:290: GC Test Summary:756 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A757 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B758 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)759 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)760 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects761--- PASS: TestOrphanedObjectsGC (1.81s)762=== CONT TestReadProxyConditionalGet7632026-08-16 15:40:08.324 UTC [4320] ERROR: relation "goose_db_version" does not exist at character 367642026-08-16 15:40:08.324 UTC [4320] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7652026/08/16 15:40:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7662026-08-16 15:40:08.506 UTC [4324] ERROR: relation "goose_db_version" does not exist at character 367672026-08-16 15:40:08.506 UTC [4324] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7682026/08/16 15:40:08 OK 20241026095416_initial_model.sql (147.2ms)7692026/08/16 15:40:08 OK 20251210153512_drop_unused_gin_index.sql (605.92µs)7702026/08/16 15:40:08 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MzYwMTU3ZjYtNzA4OS00MTBjLWJmNDctYjJkMDg0ZjVmMjRkLjJlMzUwMmI5LTUxNjktNGNiZi1hM2IwLWZmOTQ5ZmFiZWFlNngxNzg2ODk0ODA3MTU0NTkxMDAw parts=127712026/08/16 15:40:08 INFO Received uploads request method=POST path=/api/pending_closures7722026/08/16 15:40:08 OK 20251218171726_add_pins.sql (1.61ms)773--- PASS: TestCompletedNarNotReofferedAcrossClosures (2.05s)774=== CONT TestReadProxyRootRedirectsToIndexHTML7752026-08-16 15:40:08.518 UTC [4327] ERROR: relation "goose_db_version" does not exist at character 367762026-08-16 15:40:08.518 UTC [4327] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7772026-08-16 15:40:08.518 UTC [4326] ERROR: relation "goose_db_version" does not exist at character 367782026-08-16 15:40:08.518 UTC [4326] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC7792026/08/16 15:40:08 OK 20260628120000_add_object_size_and_stats.sql (11.83ms)7802026/08/16 15:40:08 goose: successfully migrated database to version: 202606281200007812026/08/16 15:40:08 OK 1_commit_pending_closure.sql (1.16ms)7822026/08/16 15:40:08 OK 2_object_stats_trigger.sql (221.71µs)7832026/08/16 15:40:08 goose: up to current file version: 27842026/08/16 15:40:08 WARN mTLS auth: subject not in bound subjects subject="CN=reader"7852026/08/16 15:40:08 WARN mTLS auth: subject not in bound subjects subject="CN=writer"786--- PASS: TestService_NativeMTLS (1.78s)787=== CONT TestProxyWriteTimeout788=== RUN TestProxyWriteTimeout/narinfo789=== PAUSE TestProxyWriteTimeout/narinfo790=== RUN TestProxyWriteTimeout/1_GiB_nar791=== PAUSE TestProxyWriteTimeout/1_GiB_nar792=== RUN TestProxyWriteTimeout/10_GiB_nar793=== PAUSE TestProxyWriteTimeout/10_GiB_nar794=== RUN TestProxyWriteTimeout/unknown_size795=== PAUSE TestProxyWriteTimeout/unknown_size796=== CONT TestIsValidUploadKey797=== RUN TestIsValidUploadKey/narinfo798=== PAUSE TestIsValidUploadKey/narinfo799=== RUN TestIsValidUploadKey/nar_zst800=== PAUSE TestIsValidUploadKey/nar_zst801=== RUN TestIsValidUploadKey/nar_xz802=== PAUSE TestIsValidUploadKey/nar_xz803=== RUN TestIsValidUploadKey/nar_plain804=== PAUSE TestIsValidUploadKey/nar_plain805=== RUN TestIsValidUploadKey/listing806=== PAUSE TestIsValidUploadKey/listing807=== RUN TestIsValidUploadKey/build_log808=== PAUSE TestIsValidUploadKey/build_log809=== RUN TestIsValidUploadKey/build_log_home-manager_file810=== PAUSE TestIsValidUploadKey/build_log_home-manager_file811=== RUN TestIsValidUploadKey/build_log_plus_in_name812=== PAUSE TestIsValidUploadKey/build_log_plus_in_name813=== RUN TestIsValidUploadKey/build_log_question_mark814=== PAUSE TestIsValidUploadKey/build_log_question_mark815=== RUN TestIsValidUploadKey/build_log_equals816=== PAUSE TestIsValidUploadKey/build_log_equals817=== RUN TestIsValidUploadKey/realisation818=== PAUSE TestIsValidUploadKey/realisation819=== RUN TestIsValidUploadKey/realisation_plus_in_output820=== PAUSE TestIsValidUploadKey/realisation_plus_in_output821=== RUN TestIsValidUploadKey/nix-cache-info822=== PAUSE TestIsValidUploadKey/nix-cache-info823=== RUN TestIsValidUploadKey/index.html824=== PAUSE TestIsValidUploadKey/index.html825=== RUN TestIsValidUploadKey/narinfo_key,_nar_type826=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type827=== RUN TestIsValidUploadKey/nar_key,_narinfo_type828=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type829=== RUN TestIsValidUploadKey/listing_key,_narinfo_type830=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type831=== RUN TestIsValidUploadKey/traversal832=== PAUSE TestIsValidUploadKey/traversal833=== RUN TestIsValidUploadKey/traversal_nar834=== PAUSE TestIsValidUploadKey/traversal_nar835=== RUN TestIsValidUploadKey/absolute836=== PAUSE TestIsValidUploadKey/absolute837=== RUN TestIsValidUploadKey/empty_key838=== PAUSE TestIsValidUploadKey/empty_key839=== RUN TestIsValidUploadKey/unknown_type840=== PAUSE TestIsValidUploadKey/unknown_type841=== CONT TestIsValidCachePath842=== RUN TestIsValidCachePath/narinfo843=== PAUSE TestIsValidCachePath/narinfo844=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars845=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars846=== RUN TestIsValidCachePath/nar_zst847=== PAUSE TestIsValidCachePath/nar_zst848=== RUN TestIsValidCachePath/nar_xz849=== PAUSE TestIsValidCachePath/nar_xz850=== RUN TestIsValidCachePath/nar_bz2851=== PAUSE TestIsValidCachePath/nar_bz2852=== RUN TestIsValidCachePath/nar_uncompressed853=== PAUSE TestIsValidCachePath/nar_uncompressed854=== RUN TestIsValidCachePath/ls855=== PAUSE TestIsValidCachePath/ls856=== RUN TestIsValidCachePath/log857=== PAUSE TestIsValidCachePath/log858=== RUN TestIsValidCachePath/realisation859=== PAUSE TestIsValidCachePath/realisation860=== RUN TestIsValidCachePath/nix-cache-info861=== PAUSE TestIsValidCachePath/nix-cache-info862=== RUN TestIsValidCachePath/index.html863=== PAUSE TestIsValidCachePath/index.html864=== RUN TestIsValidCachePath/traversal_parent865=== PAUSE TestIsValidCachePath/traversal_parent866=== RUN TestIsValidCachePath/traversal_in_middle867=== PAUSE TestIsValidCachePath/traversal_in_middle868=== RUN TestIsValidCachePath/invalid_char_e869=== PAUSE TestIsValidCachePath/invalid_char_e870=== RUN TestIsValidCachePath/invalid_char_u871=== PAUSE TestIsValidCachePath/invalid_char_u872=== RUN TestIsValidCachePath/random_path873=== PAUSE TestIsValidCachePath/random_path874=== RUN TestIsValidCachePath/empty875=== PAUSE TestIsValidCachePath/empty876=== RUN TestIsValidCachePath/leading_slash877=== PAUSE TestIsValidCachePath/leading_slash878=== RUN TestIsValidCachePath/wrong_extension879=== PAUSE TestIsValidCachePath/wrong_extension880=== RUN TestIsValidCachePath/short_hash881=== PAUSE TestIsValidCachePath/short_hash882=== CONT TestReadProxyNarinfoAlreadyDecompressed8832026/08/16 15:40:08 OK 20241026095416_initial_model.sql (130.7ms)8842026/08/16 15:40:08 OK 20241026095416_initial_model.sql (122.82ms)8852026/08/16 15:40:08 OK 20241026095416_initial_model.sql (118.14ms)8862026/08/16 15:40:08 OK 20251210153512_drop_unused_gin_index.sql (1.32ms)8872026/08/16 15:40:08 OK 20251210153512_drop_unused_gin_index.sql (1.31ms)8882026/08/16 15:40:08 OK 20251210153512_drop_unused_gin_index.sql (1.34ms)8892026/08/16 15:40:08 OK 20251218171726_add_pins.sql (2.81ms)8902026/08/16 15:40:08 OK 20251218171726_add_pins.sql (3.07ms)8912026/08/16 15:40:08 OK 20251218171726_add_pins.sql (3.29ms)8922026-08-16 15:40:08.713 UTC [4333] ERROR: relation "goose_db_version" does not exist at character 368932026-08-16 15:40:08.713 UTC [4333] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8942026-08-16 15:40:08.716 UTC [4334] ERROR: relation "goose_db_version" does not exist at character 368952026-08-16 15:40:08.716 UTC [4334] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8962026-08-16 15:40:08.718 UTC [4335] ERROR: relation "goose_db_version" does not exist at character 368972026-08-16 15:40:08.718 UTC [4335] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8982026/08/16 15:40:08 OK 20260628120000_add_object_size_and_stats.sql (13.06ms)8992026/08/16 15:40:08 goose: successfully migrated database to version: 202606281200009002026/08/16 15:40:08 OK 20260628120000_add_object_size_and_stats.sql (13.87ms)9012026/08/16 15:40:08 goose: successfully migrated database to version: 202606281200009022026/08/16 15:40:08 OK 20260628120000_add_object_size_and_stats.sql (13.72ms)9032026/08/16 15:40:08 goose: successfully migrated database to version: 202606281200009042026/08/16 15:40:08 OK 1_commit_pending_closure.sql (1.91ms)9052026/08/16 15:40:08 OK 1_commit_pending_closure.sql (2.52ms)9062026/08/16 15:40:08 OK 1_commit_pending_closure.sql (1.92ms)9072026/08/16 15:40:08 OK 2_object_stats_trigger.sql (485µs)9082026/08/16 15:40:08 goose: up to current file version: 29092026/08/16 15:40:08 OK 2_object_stats_trigger.sql (588.46µs)9102026/08/16 15:40:08 goose: up to current file version: 29112026/08/16 15:40:08 OK 2_object_stats_trigger.sql (612.5µs)9122026/08/16 15:40:08 goose: up to current file version: 29132026/08/16 15:40:08 OK 20241026095416_initial_model.sql (81.35ms)9142026/08/16 15:40:08 OK 20241026095416_initial_model.sql (76ms)9152026/08/16 15:40:08 OK 20241026095416_initial_model.sql (76.39ms)9162026/08/16 15:40:08 OK 20251210153512_drop_unused_gin_index.sql (12.78ms)9172026/08/16 15:40:08 OK 20251210153512_drop_unused_gin_index.sql (12.88ms)9182026/08/16 15:40:08 OK 20251210153512_drop_unused_gin_index.sql (13.34ms)9192026/08/16 15:40:08 OK 20251218171726_add_pins.sql (26.39ms)9202026/08/16 15:40:08 OK 20251218171726_add_pins.sql (26.46ms)9212026/08/16 15:40:08 OK 20251218171726_add_pins.sql (41.44ms)9222026/08/16 15:40:08 INFO Created nix-cache-info in bucket bucket=bucket159232026/08/16 15:40:08 OK 20260628120000_add_object_size_and_stats.sql (31.34ms)9242026/08/16 15:40:08 goose: successfully migrated database to version: 202606281200009252026/08/16 15:40:08 OK 20260628120000_add_object_size_and_stats.sql (23.06ms)9262026/08/16 15:40:08 goose: successfully migrated database to version: 202606281200009272026/08/16 15:40:08 OK 20260628120000_add_object_size_and_stats.sql (38.7ms)9282026/08/16 15:40:08 goose: successfully migrated database to version: 202606281200009292026/08/16 15:40:08 OK 1_commit_pending_closure.sql (8.1ms)9302026/08/16 15:40:08 OK 1_commit_pending_closure.sql (8.08ms)9312026/08/16 15:40:08 OK 1_commit_pending_closure.sql (15.35ms)9322026/08/16 15:40:08 OK 2_object_stats_trigger.sql (850.67µs)9332026/08/16 15:40:08 goose: up to current file version: 29342026/08/16 15:40:08 OK 2_object_stats_trigger.sql (1.08ms)9352026/08/16 15:40:08 goose: up to current file version: 29362026/08/16 15:40:08 OK 2_object_stats_trigger.sql (1.04ms)9372026/08/16 15:40:08 goose: up to current file version: 2938--- PASS: TestService_healthCheckHandler (1.78s)939=== CONT TestReadProxyNarinfo940--- PASS: TestMetricsInventory (2.01s)941=== CONT TestReadProxyHead942--- PASS: TestReadProxyDisabled (1.83s)943=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle9442026/08/16 15:40:09 INFO Received uploads request method=POST path=/api/pending_closures945=== NAME TestNARDeduplicationMetadataUploadBug946 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-4114-2679204974/TestNARDeduplicationMetadataUploadBug2770458563/001/store/5vkxb803hjcj43jk8z4n4zxc44bilq0y-file1.txt9472026/08/16 15:40:09 INFO Received uploads request method=POST path=/api/pending_closures9482026/08/16 15:40:09 INFO Received uploads request method=POST path=/api/pending_closures9492026/08/16 15:40:09 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"9502026-08-16 15:40:09.310 UTC [4348] ERROR: relation "goose_db_version" does not exist at character 369512026-08-16 15:40:09.310 UTC [4348] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9522026/08/16 15:40:09 INFO Received uploads request method=POST path=/api/pending_closures9532026/08/16 15:40:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached, 0 in upstream)9542026/08/16 15:40:09 INFO Uploading 5vkxb803hjcj43jk8z4n4zxc44bilq0y-file1.txt (160B)9552026/08/16 15:40:09 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"9562026/08/16 15:40:09 WARN Failed to register uploaded object key=5vkxb803hjcj43jk8z4n4zxc44bilq0y.ls error="server returned 404: 404 page not found\n"9572026/08/16 15:40:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9582026/08/16 15:40:09 INFO Signed narinfos id=1 count=19592026/08/16 15:40:09 INFO Uploading 1 narinfos9602026/08/16 15:40:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9612026/08/16 15:40:09 WARN Failed to register uploaded object key=5vkxb803hjcj43jk8z4n4zxc44bilq0y.narinfo error="server returned 404: 404 page not found\n"9622026/08/16 15:40:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9632026/08/16 15:40:09 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MzYwMTU3ZjYtNzA4OS00MTBjLWJmNDctYjJkMDg0ZjVmMjRkLmJiZjJhMTYwLWExODQtNDE0My1iNmE0LTAxMmRiY2Q1NTdiMXgxNzg2ODk0ODA5MjM3MDkxMDAw9642026/08/16 15:40:09 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MzYwMTU3ZjYtNzA4OS00MTBjLWJmNDctYjJkMDg0ZjVmMjRkLmJiZjJhMTYwLWExODQtNDE0My1iNmE0LTAxMmRiY2Q1NTdiMXgxNzg2ODk0ODA5MjM3MDkxMDAw parts=1965--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.19s)966=== CONT TestClientIntegration9672026/08/16 15:40:09 INFO Completed upload id=19682026/08/16 15:40:09 INFO Upload complete. (252ms)969=== NAME TestNARDeduplicationMetadataUploadBug970 metadata_upload_test.go:54: Retrieved narinfo from S3:971 StorePath: /nix/var/nix/builds/nix-4114-2679204974/TestNARDeduplicationMetadataUploadBug2770458563/001/store/5vkxb803hjcj43jk8z4n4zxc44bilq0y-file1.txt972 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst973 Compression: zstd974 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf975 NarSize: 160976 References: 977 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf978 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)979 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):980 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}9812026/08/16 15:40:09 OK 20241026095416_initial_model.sql (94.57ms)9822026/08/16 15:40:09 OK 20251210153512_drop_unused_gin_index.sql (8.09ms)9832026/08/16 15:40:09 OK 20251218171726_add_pins.sql (26.55ms)9842026/08/16 15:40:09 OK 20260628120000_add_object_size_and_stats.sql (30.38ms)9852026/08/16 15:40:09 goose: successfully migrated database to version: 202606281200009862026/08/16 15:40:09 OK 1_commit_pending_closure.sql (8.35ms)9872026/08/16 15:40:09 OK 2_object_stats_trigger.sql (553µs)9882026/08/16 15:40:09 goose: up to current file version: 2989 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-4114-2679204974/TestNARDeduplicationMetadataUploadBug2770458563/001/store/10cmmdgyk5scfqr6ksy5p8ywq9y6rr6s-file2.txt9902026/08/16 15:40:09 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"9912026/08/16 15:40:09 INFO Received uploads request method=POST path=/api/pending_closures9922026/08/16 15:40:09 INFO Uploading 0 paths to 127.0.0.1 (1 already cached, 0 in upstream)993--- PASS: TestReadProxyRangeRequest (2.13s)994=== CONT TestGCTaskStore_DeduplicateSameParams995--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)996=== CONT TestGCTaskStore_StartNew997--- PASS: TestGCTaskStore_StartNew (0.00s)998=== CONT TestGCMetrics9992026/08/16 15:40:09 WARN Failed to register uploaded object key=10cmmdgyk5scfqr6ksy5p8ywq9y6rr6s.ls error="server returned 404: 404 page not found\n"10002026/08/16 15:40:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10012026/08/16 15:40:09 INFO Signed narinfos id=2 count=110022026/08/16 15:40:09 INFO Uploading 1 narinfos10032026/08/16 15:40:09 WARN Failed to register uploaded object key=10cmmdgyk5scfqr6ksy5p8ywq9y6rr6s.narinfo error="server returned 404: 404 page not found\n"10042026/08/16 15:40:09 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10052026/08/16 15:40:09 INFO Completed upload id=210062026/08/16 15:40:09 INFO Upload complete. (204ms)1007=== NAME TestNARDeduplicationMetadataUploadBug1008 metadata_upload_test.go:76: Retrieved narinfo from S3:1009 StorePath: /nix/var/nix/builds/nix-4114-2679204974/TestNARDeduplicationMetadataUploadBug2770458563/001/store/10cmmdgyk5scfqr6ksy5p8ywq9y6rr6s-file2.txt1010 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1011 Compression: zstd1012 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1013 NarSize: 1601014 References: 1015 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1016 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1017 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1018 {"version":1,"root":{"type":"regular","size":44}}1019--- PASS: TestNARDeduplicationMetadataUploadBug (2.78s)1020=== CONT TestGCBugBareHashReferences10212026-08-16 15:40:09.947 UTC [4365] ERROR: relation "goose_db_version" does not exist at character 3610222026-08-16 15:40:09.947 UTC [4365] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10232026-08-16 15:40:10.001 UTC [4366] ERROR: relation "goose_db_version" does not exist at character 3610242026-08-16 15:40:10.001 UTC [4366] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10252026/08/16 15:40:10 OK 20241026095416_initial_model.sql (59.35ms)10262026/08/16 15:40:10 OK 20251210153512_drop_unused_gin_index.sql (741.42µs)10272026/08/16 15:40:10 OK 20251218171726_add_pins.sql (1.22ms)10282026-08-16 15:40:10.062 UTC [4367] ERROR: relation "goose_db_version" does not exist at character 3610292026-08-16 15:40:10.062 UTC [4367] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10302026/08/16 15:40:10 OK 20241026095416_initial_model.sql (27.38ms)10312026/08/16 15:40:10 OK 20251210153512_drop_unused_gin_index.sql (4.31ms)10322026/08/16 15:40:10 OK 20260628120000_add_object_size_and_stats.sql (24.29ms)10332026/08/16 15:40:10 goose: successfully migrated database to version: 2026062812000010342026/08/16 15:40:10 OK 1_commit_pending_closure.sql (5.37ms)10352026/08/16 15:40:10 OK 2_object_stats_trigger.sql (307.21µs)10362026/08/16 15:40:10 goose: up to current file version: 210372026/08/16 15:40:10 OK 20251218171726_add_pins.sql (28.33ms)10382026/08/16 15:40:10 OK 20260628120000_add_object_size_and_stats.sql (44.66ms)10392026/08/16 15:40:10 goose: successfully migrated database to version: 2026062812000010402026/08/16 15:40:10 OK 1_commit_pending_closure.sql (6.24ms)10412026/08/16 15:40:10 OK 2_object_stats_trigger.sql (383.5µs)10422026/08/16 15:40:10 goose: up to current file version: 21043--- PASS: TestReadProxyConditionalGet (2.02s)1044=== CONT TestPinProtectsFromGC10452026/08/16 15:40:10 OK 20241026095416_initial_model.sql (189.93ms)10462026/08/16 15:40:10 OK 20251210153512_drop_unused_gin_index.sql (14.59ms)10472026/08/16 15:40:10 OK 20251218171726_add_pins.sql (27.32ms)10482026/08/16 15:40:10 OK 20260628120000_add_object_size_and_stats.sql (42.29ms)10492026/08/16 15:40:10 goose: successfully migrated database to version: 2026062812000010502026/08/16 15:40:10 OK 1_commit_pending_closure.sql (9.92ms)10512026/08/16 15:40:10 OK 2_object_stats_trigger.sql (759.46µs)10522026/08/16 15:40:10 goose: up to current file version: 21053--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.92s)1054=== CONT TestClientWithDependencies10552026/08/16 15:40:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1056--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.95s)1057=== CONT TestClientMultipleUploads10582026/08/16 15:40:10 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MzYwMTU3ZjYtNzA4OS00MTBjLWJmNDctYjJkMDg0ZjVmMjRkLjExYzM4NTMyLTZlYTMtNDdkYS05MTA0LWJiYWJiY2NmYTBlNXgxNzg2ODk0ODA5MTc3MTAzMDAw parts=121059--- PASS: TestRedundantMultipartUpload (3.41s)1060=== CONT TestResurrectedObjectNotDeleted10612026-08-16 15:40:10.800 UTC [4376] ERROR: relation "goose_db_version" does not exist at character 3610622026-08-16 15:40:10.800 UTC [4376] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10632026-08-16 15:40:10.842 UTC [4378] ERROR: relation "goose_db_version" does not exist at character 3610642026-08-16 15:40:10.842 UTC [4378] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10652026-08-16 15:40:10.842 UTC [4377] ERROR: relation "goose_db_version" does not exist at character 3610662026-08-16 15:40:10.842 UTC [4377] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10672026/08/16 15:40:10 OK 20241026095416_initial_model.sql (70.42ms)10682026/08/16 15:40:10 OK 20251210153512_drop_unused_gin_index.sql (4.04ms)10692026/08/16 15:40:10 OK 20251218171726_add_pins.sql (34.05ms)10702026/08/16 15:40:10 OK 20241026095416_initial_model.sql (75.93ms)10712026/08/16 15:40:10 OK 20241026095416_initial_model.sql (75.91ms)10722026/08/16 15:40:10 OK 20251210153512_drop_unused_gin_index.sql (2.54ms)10732026/08/16 15:40:10 OK 20251210153512_drop_unused_gin_index.sql (3.25ms)10742026/08/16 15:40:10 OK 20260628120000_add_object_size_and_stats.sql (17.68ms)10752026/08/16 15:40:10 goose: successfully migrated database to version: 2026062812000010762026/08/16 15:40:10 OK 1_commit_pending_closure.sql (4.19ms)10772026/08/16 15:40:10 OK 2_object_stats_trigger.sql (683.5µs)10782026/08/16 15:40:10 goose: up to current file version: 210792026/08/16 15:40:10 OK 20251218171726_add_pins.sql (28.92ms)10802026/08/16 15:40:10 OK 20251218171726_add_pins.sql (29.2ms)10812026/08/16 15:40:11 OK 20260628120000_add_object_size_and_stats.sql (49.21ms)10822026/08/16 15:40:11 goose: successfully migrated database to version: 2026062812000010832026/08/16 15:40:11 OK 20260628120000_add_object_size_and_stats.sql (50.5ms)10842026/08/16 15:40:11 goose: successfully migrated database to version: 2026062812000010852026/08/16 15:40:11 OK 1_commit_pending_closure.sql (12.69ms)10862026/08/16 15:40:11 OK 1_commit_pending_closure.sql (13.27ms)10872026/08/16 15:40:11 OK 2_object_stats_trigger.sql (1.14ms)10882026/08/16 15:40:11 goose: up to current file version: 210892026/08/16 15:40:11 OK 2_object_stats_trigger.sql (1.47ms)10902026/08/16 15:40:11 goose: up to current file version: 21091--- PASS: TestReadProxyNarinfo (2.32s)1092=== CONT TestParseSingleRange1093=== RUN TestParseSingleRange/none1094=== PAUSE TestParseSingleRange/none1095=== RUN TestParseSingleRange/unknown_unit1096=== PAUSE TestParseSingleRange/unknown_unit1097=== RUN TestParseSingleRange/multi-range_ignored1098=== PAUSE TestParseSingleRange/multi-range_ignored1099=== RUN TestParseSingleRange/malformed_no_dash1100=== PAUSE TestParseSingleRange/malformed_no_dash1101=== RUN TestParseSingleRange/malformed_both_empty1102=== PAUSE TestParseSingleRange/malformed_both_empty1103=== RUN TestParseSingleRange/malformed_end_before_start1104=== PAUSE TestParseSingleRange/malformed_end_before_start1105=== RUN TestParseSingleRange/closed1106=== PAUSE TestParseSingleRange/closed1107=== RUN TestParseSingleRange/open-ended1108=== PAUSE TestParseSingleRange/open-ended1109=== RUN TestParseSingleRange/end_clamped_to_size1110=== PAUSE TestParseSingleRange/end_clamped_to_size1111=== RUN TestParseSingleRange/suffix1112=== PAUSE TestParseSingleRange/suffix1113=== RUN TestParseSingleRange/suffix_exceeds_size1114=== PAUSE TestParseSingleRange/suffix_exceeds_size1115=== RUN TestParseSingleRange/single_byte1116=== PAUSE TestParseSingleRange/single_byte1117=== RUN TestParseSingleRange/start_past_EOF1118=== PAUSE TestParseSingleRange/start_past_EOF1119=== RUN TestParseSingleRange/start_far_past_EOF1120=== PAUSE TestParseSingleRange/start_far_past_EOF1121=== CONT TestService_verifyS3Integrity11222026-08-16 15:40:11.230 UTC [4379] ERROR: relation "goose_db_version" does not exist at character 3611232026-08-16 15:40:11.230 UTC [4379] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11242026/08/16 15:40:11 INFO Received uploads request method=POST path=/api/pending_closures1125--- PASS: TestReadProxyHead (2.38s)1126=== CONT TestGCMissingUpstreamReference11272026/08/16 15:40:11 OK 20241026095416_initial_model.sql (186.34ms)11282026/08/16 15:40:11 OK 20251210153512_drop_unused_gin_index.sql (8.23ms)11292026/08/16 15:40:11 OK 20251218171726_add_pins.sql (28.26ms)11302026/08/16 15:40:11 OK 20260628120000_add_object_size_and_stats.sql (25.34ms)11312026/08/16 15:40:11 goose: successfully migrated database to version: 2026062812000011322026/08/16 15:40:11 OK 1_commit_pending_closure.sql (9.95ms)11332026/08/16 15:40:11 OK 2_object_stats_trigger.sql (1.61ms)11342026/08/16 15:40:11 goose: up to current file version: 211352026/08/16 15:40:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11362026-08-16 15:40:11.700 UTC [4384] ERROR: relation "goose_db_version" does not exist at character 3611372026-08-16 15:40:11.700 UTC [4384] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11382026/08/16 15:40:11 INFO Created nix-cache-info in bucket bucket=bucket2611392026-08-16 15:40:11.803 UTC [4386] ERROR: relation "goose_db_version" does not exist at character 3611402026-08-16 15:40:11.803 UTC [4386] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11412026/08/16 15:40:11 OK 20241026095416_initial_model.sql (44.88ms)11422026/08/16 15:40:11 OK 20251210153512_drop_unused_gin_index.sql (642.71µs)11432026/08/16 15:40:11 OK 20251218171726_add_pins.sql (1.28ms)11442026/08/16 15:40:11 OK 20241026095416_initial_model.sql (10.51ms)11452026/08/16 15:40:11 OK 20251210153512_drop_unused_gin_index.sql (990.92µs)11462026/08/16 15:40:11 OK 20260628120000_add_object_size_and_stats.sql (18.69ms)11472026/08/16 15:40:11 goose: successfully migrated database to version: 2026062812000011482026/08/16 15:40:11 OK 20251218171726_add_pins.sql (8.08ms)11492026/08/16 15:40:11 OK 1_commit_pending_closure.sql (1.61ms)11502026/08/16 15:40:11 OK 2_object_stats_trigger.sql (399.83µs)11512026/08/16 15:40:11 goose: up to current file version: 211522026-08-16 15:40:11.833 UTC [4387] ERROR: relation "goose_db_version" does not exist at character 3611532026-08-16 15:40:11.833 UTC [4387] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11542026/08/16 15:40:11 OK 20260628120000_add_object_size_and_stats.sql (50.47ms)11552026/08/16 15:40:11 goose: successfully migrated database to version: 2026062812000011562026/08/16 15:40:11 OK 1_commit_pending_closure.sql (6.75ms)11572026/08/16 15:40:11 OK 2_object_stats_trigger.sql (338.83µs)11582026/08/16 15:40:11 goose: up to current file version: 21159=== NAME TestClientIntegration1160 client_integration_test.go:276: Created store path: /nix/var/nix/builds/nix-4114-2679204974/TestClientIntegration2230914588/002/store/q4hfjf2387vh7dkdv9k7k037p0c7jl0l-test-file.txt11612026/08/16 15:40:11 INFO Aborted multipart uploads count=011622026/08/16 15:40:11 WARN Force mode enabled - objects will be deleted immediately without grace period11632026/08/16 15:40:11 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=011642026/08/16 15:40:11 INFO Vacuumed table table=pending_closures11652026/08/16 15:40:11 INFO Vacuumed table table=pending_objects11662026/08/16 15:40:11 INFO Vacuumed table table=multipart_uploads11672026/08/16 15:40:11 INFO Vacuumed table table=closures11682026/08/16 15:40:12 INFO Vacuumed table table=objects1169--- PASS: TestGCMetrics (2.29s)1170=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT11712026/08/16 15:40:12 OK 20241026095416_initial_model.sql (159.49ms)11722026/08/16 15:40:12 OK 20251210153512_drop_unused_gin_index.sql (7.65ms)11732026-08-16 15:40:12.076 UTC [4395] ERROR: relation "goose_db_version" does not exist at character 3611742026-08-16 15:40:12.076 UTC [4395] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11752026/08/16 15:40:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"11762026/08/16 15:40:12 OK 20251218171726_add_pins.sql (30.35ms)11772026/08/16 15:40:12 OK 20260628120000_add_object_size_and_stats.sql (27.85ms)11782026/08/16 15:40:12 goose: successfully migrated database to version: 2026062812000011792026/08/16 15:40:12 OK 1_commit_pending_closure.sql (5.24ms)11802026/08/16 15:40:12 OK 2_object_stats_trigger.sql (249.42µs)11812026/08/16 15:40:12 goose: up to current file version: 211822026/08/16 15:40:12 INFO Received uploads request method=POST path=/api/pending_closures11832026/08/16 15:40:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached, 0 in upstream)11842026/08/16 15:40:12 INFO Uploading q4hfjf2387vh7dkdv9k7k037p0c7jl0l-test-file.txt (152B)11852026/08/16 15:40:12 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"11862026/08/16 15:40:12 WARN Failed to register uploaded object key=q4hfjf2387vh7dkdv9k7k037p0c7jl0l.ls error="server returned 404: 404 page not found\n"11872026/08/16 15:40:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11882026/08/16 15:40:12 INFO Signed narinfos id=1 count=111892026/08/16 15:40:12 INFO Uploading 1 narinfos11902026/08/16 15:40:12 WARN Failed to register uploaded object key=q4hfjf2387vh7dkdv9k7k037p0c7jl0l.narinfo error="server returned 404: 404 page not found\n"11912026/08/16 15:40:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11922026/08/16 15:40:12 OK 20241026095416_initial_model.sql (138.15ms)11932026/08/16 15:40:12 INFO Completed upload id=111942026/08/16 15:40:12 INFO Upload complete. (248ms)1195=== NAME TestClientIntegration1196 client_integration_test.go:292: Retrieved narinfo from S3:1197 StorePath: /nix/var/nix/builds/nix-4114-2679204974/TestClientIntegration2230914588/002/store/q4hfjf2387vh7dkdv9k7k037p0c7jl0l-test-file.txt1198 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1199 Compression: zstd1200 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11201 NarSize: 1521202 References: 1203 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11204 client_integration_test.go:293: Retrieved .ls file from S3 (compressed size: 77 bytes)1205 client_integration_test.go:293: Decompressed .ls content (64 bytes):1206 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1207 client_integration_test.go:296: Testing garbage collection...12082026/08/16 15:40:12 OK 20251210153512_drop_unused_gin_index.sql (7.4ms)12092026/08/16 15:40:12 INFO Created nix-cache-info in bucket bucket=bucket2912102026/08/16 15:40:12 OK 20251218171726_add_pins.sql (28.66ms)12112026/08/16 15:40:12 OK 20260628120000_add_object_size_and_stats.sql (4.91ms)12122026/08/16 15:40:12 goose: successfully migrated database to version: 2026062812000012132026/08/16 15:40:12 INFO Starting cleanup of old closures method=DELETE path=/api/closures12142026/08/16 15:40:12 INFO Garbage collection started12152026/08/16 15:40:12 INFO Aborted multipart uploads count=012162026/08/16 15:40:12 OK 1_commit_pending_closure.sql (8.41ms)12172026/08/16 15:40:12 OK 2_object_stats_trigger.sql (260µs)12182026/08/16 15:40:12 goose: up to current file version: 212192026/08/16 15:40:12 WARN Force mode enabled - objects will be deleted immediately without grace period12202026-08-16 15:40:12.387 UTC [4404] ERROR: relation "goose_db_version" does not exist at character 3612212026-08-16 15:40:12.387 UTC [4404] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1222--- PASS: TestGCBugBareHashReferences (2.53s)1223=== CONT TestCompleteMultipartUnregistered12242026-08-16 15:40:12.437 UTC [4407] ERROR: relation "goose_db_version" does not exist at character 3612252026-08-16 15:40:12.437 UTC [4407] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12262026/08/16 15:40:12 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=012272026/08/16 15:40:12 INFO Vacuumed table table=pending_closures12282026/08/16 15:40:12 INFO Vacuumed table table=pending_objects12292026/08/16 15:40:12 INFO Vacuumed table table=multipart_uploads12302026/08/16 15:40:12 INFO Created nix-cache-info in bucket bucket=bucket3012312026/08/16 15:40:12 INFO Vacuumed table table=closures1232=== NAME TestPinProtectsFromGC1233 client_integration_test.go:646: Pinned store path: /nix/var/nix/builds/nix-4114-2679204974/TestPinProtectsFromGC1582277594/001/store/8db3dhf05rv0p98pyrw0bdzbrjshz2l1-pinned-file.txt1234 client_integration_test.go:647: Unpinned store path: /nix/var/nix/builds/nix-4114-2679204974/TestPinProtectsFromGC1582277594/001/store/5gl2alcc8483z9ccl75bmvdsgnp9hq90-unpinned-file.txt12352026/08/16 15:40:12 INFO Vacuumed table table=objects12362026/08/16 15:40:12 OK 20241026095416_initial_model.sql (74.73ms)12372026/08/16 15:40:12 OK 20251210153512_drop_unused_gin_index.sql (6.97ms)12382026/08/16 15:40:12 OK 20251218171726_add_pins.sql (13.51ms)12392026/08/16 15:40:12 OK 20241026095416_initial_model.sql (59.78ms)12402026/08/16 15:40:12 OK 20251210153512_drop_unused_gin_index.sql (7.54ms)12412026/08/16 15:40:12 OK 20260628120000_add_object_size_and_stats.sql (28.23ms)12422026/08/16 15:40:12 goose: successfully migrated database to version: 2026062812000012432026/08/16 15:40:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12442026/08/16 15:40:12 OK 1_commit_pending_closure.sql (1.18ms)12452026/08/16 15:40:12 OK 2_object_stats_trigger.sql (406.46µs)12462026/08/16 15:40:12 goose: up to current file version: 212472026/08/16 15:40:12 OK 20251218171726_add_pins.sql (21.41ms)12482026/08/16 15:40:12 OK 20260628120000_add_object_size_and_stats.sql (26.46ms)12492026/08/16 15:40:12 goose: successfully migrated database to version: 2026062812000012502026-08-16 15:40:12.595 UTC [4418] ERROR: relation "goose_db_version" does not exist at character 3612512026-08-16 15:40:12.595 UTC [4418] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12522026/08/16 15:40:12 OK 1_commit_pending_closure.sql (5.72ms)12532026/08/16 15:40:12 OK 2_object_stats_trigger.sql (243.92µs)12542026/08/16 15:40:12 goose: up to current file version: 212552026/08/16 15:40:12 INFO Received uploads request method=POST path=/api/pending_closures12562026/08/16 15:40:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached, 0 in upstream)12572026/08/16 15:40:12 INFO Uploading 8db3dhf05rv0p98pyrw0bdzbrjshz2l1-pinned-file.txt (128B)12582026/08/16 15:40:12 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"12592026/08/16 15:40:12 WARN Failed to register uploaded object key=8db3dhf05rv0p98pyrw0bdzbrjshz2l1.ls error="server returned 404: 404 page not found\n"12602026/08/16 15:40:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12612026/08/16 15:40:12 INFO Signed narinfos id=1 count=112622026/08/16 15:40:12 INFO Uploading 1 narinfos12632026/08/16 15:40:12 INFO Created nix-cache-info in bucket bucket=bucket3112642026/08/16 15:40:12 WARN Failed to register uploaded object key=8db3dhf05rv0p98pyrw0bdzbrjshz2l1.narinfo error="server returned 404: 404 page not found\n"12652026/08/16 15:40:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12662026/08/16 15:40:12 INFO Completed upload id=112672026/08/16 15:40:12 INFO Upload complete. (230ms)12682026/08/16 15:40:12 OK 20241026095416_initial_model.sql (121.07ms)12692026/08/16 15:40:12 OK 20251210153512_drop_unused_gin_index.sql (5.18ms)1270=== NAME TestClientWithDependencies1271 client_integration_test.go:593: Built derivation: /nix/var/nix/builds/nix-4114-2679204974/TestClientWithDependencies243561444/001/store/s7c5xdpjq2bdnphrnh3jrb8m45xbqvd0-test-script12722026/08/16 15:40:12 OK 20251218171726_add_pins.sql (1.69ms)12732026/08/16 15:40:12 OK 20260628120000_add_object_size_and_stats.sql (8.28ms)12742026/08/16 15:40:12 goose: successfully migrated database to version: 2026062812000012752026/08/16 15:40:12 OK 1_commit_pending_closure.sql (6.89ms)12762026/08/16 15:40:12 OK 2_object_stats_trigger.sql (244.63µs)12772026/08/16 15:40:12 goose: up to current file version: 212782026-08-16 15:40:12.791 UTC [4426] ERROR: relation "goose_db_version" does not exist at character 3612792026-08-16 15:40:12.791 UTC [4426] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1280 client_integration_test.go:595: Found 1 dependencies (including self)12812026/08/16 15:40:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1282--- PASS: TestResurrectedObjectNotDeleted (2.14s)1283=== CONT TestService_cleanupPendingClosuresHandler12842026/08/16 15:40:12 INFO Received uploads request method=POST path=/api/pending_closures12852026/08/16 15:40:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached, 0 in upstream)12862026/08/16 15:40:12 INFO Uploading 5gl2alcc8483z9ccl75bmvdsgnp9hq90-unpinned-file.txt (128B)1287=== NAME TestClientMultipleUploads1288 client_integration_test.go:338: Created store path 0: /nix/var/nix/builds/nix-4114-2679204974/TestClientMultipleUploads1083614410/001/store/g18sj555nls4iklxd5hp9y06sff73f6p-test-file-0.txt12892026/08/16 15:40:12 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"12902026/08/16 15:40:12 INFO Received uploads request method=POST path=/api/pending_closures12912026/08/16 15:40:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached, 0 in upstream)12922026/08/16 15:40:12 INFO Uploading s7c5xdpjq2bdnphrnh3jrb8m45xbqvd0-test-script (136B)12932026/08/16 15:40:12 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"12942026/08/16 15:40:12 INFO Received uploads request method=POST path=/api/pending_closures12952026/08/16 15:40:12 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"12962026/08/16 15:40:12 WARN Failed to register uploaded object key=5gl2alcc8483z9ccl75bmvdsgnp9hq90.ls error="server returned 404: 404 page not found\n"12972026/08/16 15:40:12 WARN Failed to register uploaded object key=log/zqz576wixfs5vp4k1sdjq1l2357nd9cp-test-script.drv error="server returned 404: 404 page not found\n"12982026/08/16 15:40:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12992026/08/16 15:40:12 INFO Signed narinfos id=2 count=113002026/08/16 15:40:12 INFO Uploading 1 narinfos1301 client_integration_test.go:338: Created store path 1: /nix/var/nix/builds/nix-4114-2679204974/TestClientMultipleUploads1083614410/001/store/wn6kirpk3gznf2irhiqaiqkhkblj7nq3-test-file-1.txt13022026/08/16 15:40:12 WARN Failed to register uploaded object key=s7c5xdpjq2bdnphrnh3jrb8m45xbqvd0.ls error="server returned 404: 404 page not found\n"13032026/08/16 15:40:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13042026/08/16 15:40:12 INFO Signed narinfos id=1 count=113052026/08/16 15:40:12 INFO Uploading 1 narinfos13062026/08/16 15:40:13 WARN Failed to register uploaded object key=5gl2alcc8483z9ccl75bmvdsgnp9hq90.narinfo error="server returned 404: 404 page not found\n"13072026/08/16 15:40:13 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13082026/08/16 15:40:13 INFO Completed upload id=213092026/08/16 15:40:13 INFO Upload complete. (223ms)13102026/08/16 15:40:13 OK 20241026095416_initial_model.sql (168.15ms)13112026/08/16 15:40:13 WARN Failed to register uploaded object key=s7c5xdpjq2bdnphrnh3jrb8m45xbqvd0.narinfo error="server returned 404: 404 page not found\n"13122026/08/16 15:40:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13132026/08/16 15:40:13 OK 20251210153512_drop_unused_gin_index.sql (10.67ms)13142026/08/16 15:40:13 INFO Received create pin request method=POST path=/api/pins/myapp13152026/08/16 15:40:13 INFO Completed upload id=113162026/08/16 15:40:13 INFO Upload complete. (201ms)1317=== NAME TestClientWithDependencies1318 client_integration_test.go:597: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-4114-2679204974/TestClientWithDependencies243561444/001/store) requires matching store prefix13192026/08/16 15:40:13 OK 20251218171726_add_pins.sql (18.87ms)13202026/08/16 15:40:13 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-4114-2679204974/TestPinProtectsFromGC1582277594/001/store/8db3dhf05rv0p98pyrw0bdzbrjshz2l1-pinned-file.txt narinfo_key=8db3dhf05rv0p98pyrw0bdzbrjshz2l1.narinfo13212026/08/16 15:40:13 INFO Starting cleanup of old closures method=DELETE path=/api/closures13222026/08/16 15:40:13 INFO Garbage collection started13232026/08/16 15:40:13 INFO Aborted multipart uploads count=013242026/08/16 15:40:13 WARN Force mode enabled - objects will be deleted immediately without grace period13252026/08/16 15:40:13 OK 20260628120000_add_object_size_and_stats.sql (42.71ms)13262026/08/16 15:40:13 goose: successfully migrated database to version: 2026062812000013272026/08/16 15:40:13 OK 1_commit_pending_closure.sql (1.15ms)1328=== NAME TestClientMultipleUploads1329 client_integration_test.go:338: Created store path 2: /nix/var/nix/builds/nix-4114-2679204974/TestClientMultipleUploads1083614410/001/store/ig3y2d2pvj7bidphzhnbr1ld4hp954d5-test-file-2.txt13302026/08/16 15:40:13 OK 2_object_stats_trigger.sql (620.04µs)13312026/08/16 15:40:13 goose: up to current file version: 21332--- PASS: TestClientWithDependencies (2.69s)1333=== CONT TestService_createPendingClosureHandler13342026/08/16 15:40:13 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"13352026/08/16 15:40:13 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=013362026/08/16 15:40:13 INFO Vacuumed table table=pending_closures13372026/08/16 15:40:13 INFO Vacuumed table table=pending_objects13382026/08/16 15:40:13 INFO Vacuumed table table=multipart_uploads13392026/08/16 15:40:13 INFO Received uploads request method=POST path=/api/pending_closures13402026/08/16 15:40:13 INFO Vacuumed table table=closures13412026/08/16 15:40:13 INFO Received uploads request method=POST path=/api/pending_closures13422026/08/16 15:40:13 INFO Received uploads request method=POST path=/api/pending_closures13432026/08/16 15:40:13 INFO Uploading 3 paths to 127.0.0.1 (0 already cached, 0 in upstream)13442026/08/16 15:40:13 INFO Uploading ig3y2d2pvj7bidphzhnbr1ld4hp954d5-test-file-2.txt (160B)13452026/08/16 15:40:13 INFO Uploading wn6kirpk3gznf2irhiqaiqkhkblj7nq3-test-file-1.txt (160B)13462026/08/16 15:40:13 INFO Uploading g18sj555nls4iklxd5hp9y06sff73f6p-test-file-0.txt (160B)13472026-08-16 15:40:13.306 UTC [4456] ERROR: relation "goose_db_version" does not exist at character 3613482026-08-16 15:40:13.306 UTC [4456] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1349--- PASS: TestGCMissingUpstreamReference (1.90s)1350=== CONT TestOrphanedObjectsGCStressTest13512026/08/16 15:40:13 INFO Vacuumed table table=objects13522026/08/16 15:40:13 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"13532026/08/16 15:40:13 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"13542026/08/16 15:40:13 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"13552026/08/16 15:40:13 WARN Failed to register uploaded object key=g18sj555nls4iklxd5hp9y06sff73f6p.ls error="server returned 404: 404 page not found\n"13562026/08/16 15:40:13 WARN Failed to register uploaded object key=wn6kirpk3gznf2irhiqaiqkhkblj7nq3.ls error="server returned 404: 404 page not found\n"13572026/08/16 15:40:13 WARN Failed to register uploaded object key=ig3y2d2pvj7bidphzhnbr1ld4hp954d5.ls error="server returned 404: 404 page not found\n"13582026/08/16 15:40:13 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13592026/08/16 15:40:13 INFO Signed narinfos id=1 count=113602026/08/16 15:40:13 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13612026/08/16 15:40:13 INFO Signed narinfos id=2 count=113622026/08/16 15:40:13 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign13632026/08/16 15:40:13 INFO Signed narinfos id=3 count=113642026/08/16 15:40:13 INFO Uploading 3 narinfos13652026/08/16 15:40:13 WARN Failed to register uploaded object key=ig3y2d2pvj7bidphzhnbr1ld4hp954d5.narinfo error="server returned 404: 404 page not found\n"13662026/08/16 15:40:13 WARN Failed to register uploaded object key=g18sj555nls4iklxd5hp9y06sff73f6p.narinfo error="server returned 404: 404 page not found\n"13672026/08/16 15:40:13 WARN Failed to register uploaded object key=wn6kirpk3gznf2irhiqaiqkhkblj7nq3.narinfo error="server returned 404: 404 page not found\n"13682026/08/16 15:40:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13692026/08/16 15:40:13 INFO Completed upload id=113702026/08/16 15:40:13 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13712026/08/16 15:40:13 INFO Completed upload id=213722026/08/16 15:40:13 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete13732026/08/16 15:40:13 INFO Completed upload id=313742026/08/16 15:40:13 INFO Upload complete. (343ms)1375=== NAME TestClientMultipleUploads1376 client_integration_test.go:349: Uploaded 3 paths in 378.615667ms1377--- PASS: TestClientMultipleUploads (2.87s)1378=== CONT TestUploadHandlersRejectOversizedBody13792026/08/16 15:40:13 OK 20241026095416_initial_model.sql (126.05ms)13802026/08/16 15:40:13 OK 20251210153512_drop_unused_gin_index.sql (1.19ms)1381=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1382=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1383=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1384=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1385=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1386=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1387=== CONT TestCacheConfigHandler1388=== RUN TestCacheConfigHandler/full_config,_no_issuer1389=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1390=== RUN TestCacheConfigHandler/no_cache_url_configured1391=== PAUSE TestCacheConfigHandler/no_cache_url_configured1392=== RUN TestCacheConfigHandler/no_signing_keys1393=== PAUSE TestCacheConfigHandler/no_signing_keys1394=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1395=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1396=== CONT TestClientErrorHandling1397=== RUN TestClientErrorHandling/InvalidStorePath1398=== PAUSE TestClientErrorHandling/InvalidStorePath1399=== RUN TestClientErrorHandling/InvalidAuthToken1400=== PAUSE TestClientErrorHandling/InvalidAuthToken1401=== RUN TestClientErrorHandling/ServerNotAvailable1402=== PAUSE TestClientErrorHandling/ServerNotAvailable1403=== CONT TestClientCADerivations14042026/08/16 15:40:13 OK 20251218171726_add_pins.sql (34.7ms)14052026/08/16 15:40:13 OK 20260628120000_add_object_size_and_stats.sql (17.96ms)14062026/08/16 15:40:13 goose: successfully migrated database to version: 2026062812000014072026/08/16 15:40:13 OK 1_commit_pending_closure.sql (1.58ms)14082026/08/16 15:40:13 OK 2_object_stats_trigger.sql (276.75µs)14092026/08/16 15:40:13 goose: up to current file version: 214102026/08/16 15:40:13 INFO Received uploads request method=POST path=/api/pending_closures1411--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.87s)1412=== CONT TestCacheStatsHandler14132026-08-16 15:40:13.891 UTC [4462] ERROR: relation "goose_db_version" does not exist at character 3614142026-08-16 15:40:13.891 UTC [4462] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14152026/08/16 15:40:14 OK 20241026095416_initial_model.sql (74.26ms)14162026/08/16 15:40:14 OK 20251210153512_drop_unused_gin_index.sql (6.81ms)14172026/08/16 15:40:14 OK 20251218171726_add_pins.sql (11ms)14182026/08/16 15:40:14 OK 20260628120000_add_object_size_and_stats.sql (31.41ms)14192026/08/16 15:40:14 goose: successfully migrated database to version: 2026062812000014202026/08/16 15:40:14 OK 1_commit_pending_closure.sql (2.47ms)14212026/08/16 15:40:14 OK 2_object_stats_trigger.sql (491.13µs)14222026/08/16 15:40:14 goose: up to current file version: 214232026/08/16 15:40:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14242026/08/16 15:40:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14252026/08/16 15:40:14 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1426--- PASS: TestCompleteMultipartUnregistered (1.84s)1427=== CONT TestService_ReadAuthMiddleware14282026/08/16 15:40:14 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MzYwMTU3ZjYtNzA4OS00MTBjLWJmNDctYjJkMDg0ZjVmMjRkLjI4YzI2N2EyLTQzZGEtNGE1OC1iMTgwLWQ3MzkwODM5MWZmYXgxNzg2ODk0ODEyOTYyNDU4MDAw parts=1014292026/08/16 15:40:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14302026/08/16 15:40:14 INFO Completed upload id=114312026/08/16 15:40:14 INFO Received uploads request method=POST path=/api/pending_closures14322026/08/16 15:40:14 INFO Received uploads request method=POST path=/api/pending_closures14332026/08/16 15:40:14 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo14342026/08/16 15:40:14 WARN Found objects in DB but missing from S3, will re-upload count=11435--- PASS: TestService_verifyS3Integrity (3.06s)1436=== CONT TestService_AuthMiddleware_OIDC14372026/08/16 15:40:14 INFO OIDC provider initialized name=test14382026/08/16 15:40:14 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01439=== NAME TestClientIntegration1440 client_integration_test.go:303: Objects in database after GC:1441 client_integration_test.go:303: Successfully deleted all objects with GC --force14422026-08-16 15:40:14.334 UTC [4467] ERROR: relation "goose_db_version" does not exist at character 3614432026-08-16 15:40:14.334 UTC [4467] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1444--- PASS: TestClientIntegration (4.89s)1445=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14462026-08-16 15:40:14.393 UTC [4471] ERROR: relation "goose_db_version" does not exist at character 3614472026-08-16 15:40:14.393 UTC [4471] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14482026/08/16 15:40:14 OK 20241026095416_initial_model.sql (50.09ms)14492026/08/16 15:40:14 OK 20251210153512_drop_unused_gin_index.sql (2.47ms)14502026/08/16 15:40:14 OK 20251218171726_add_pins.sql (21.72ms)14512026/08/16 15:40:14 OK 20260628120000_add_object_size_and_stats.sql (11.54ms)14522026/08/16 15:40:14 goose: successfully migrated database to version: 2026062812000014532026/08/16 15:40:14 OK 1_commit_pending_closure.sql (1.73ms)14542026/08/16 15:40:14 OK 2_object_stats_trigger.sql (367.17µs)14552026/08/16 15:40:14 goose: up to current file version: 214562026-08-16 15:40:14.496 UTC [4472] ERROR: relation "goose_db_version" does not exist at character 3614572026-08-16 15:40:14.496 UTC [4472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14582026/08/16 15:40:14 OK 20241026095416_initial_model.sql (133.71ms)14592026/08/16 15:40:14 OK 20251210153512_drop_unused_gin_index.sql (12.19ms)14602026/08/16 15:40:14 INFO Received cleanup request method=DELETE path=/api/pending_closures14612026/08/16 15:40:14 INFO Aborted multipart uploads count=014622026/08/16 15:40:14 OK 20251218171726_add_pins.sql (21.7ms)14632026/08/16 15:40:14 INFO Received uploads request method=POST path=/api/pending_closures14642026/08/16 15:40:14 OK 20260628120000_add_object_size_and_stats.sql (20.15ms)14652026/08/16 15:40:14 goose: successfully migrated database to version: 2026062812000014662026/08/16 15:40:14 OK 1_commit_pending_closure.sql (9.58ms)14672026/08/16 15:40:14 OK 2_object_stats_trigger.sql (1.3ms)14682026/08/16 15:40:14 goose: up to current file version: 214692026/08/16 15:40:14 INFO Received cleanup request method=DELETE path=/api/pending_closures14702026/08/16 15:40:14 INFO Aborted multipart uploads count=114712026/08/16 15:40:14 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14722026-08-16 15:40:14.655 UTC [4467] ERROR: Closure does not exist: id=114732026-08-16 15:40:14.655 UTC [4467] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE14742026-08-16 15:40:14.655 UTC [4467] STATEMENT: -- name: CommitPendingClosure :exec1475 SELECT commit_pending_closure($1::bigint)1476 1477--- PASS: TestService_cleanupPendingClosuresHandler (1.80s)1478=== CONT TestService_AuthMiddleware_MTLSProxyHeader14792026/08/16 15:40:14 OK 20241026095416_initial_model.sql (105.31ms)14802026/08/16 15:40:14 OK 20251210153512_drop_unused_gin_index.sql (9.67ms)14812026/08/16 15:40:14 OK 20251218171726_add_pins.sql (17.71ms)14822026/08/16 15:40:14 OK 20260628120000_add_object_size_and_stats.sql (27.6ms)14832026/08/16 15:40:14 goose: successfully migrated database to version: 2026062812000014842026/08/16 15:40:14 OK 1_commit_pending_closure.sql (8.37ms)14852026/08/16 15:40:14 OK 2_object_stats_trigger.sql (655.67µs)14862026/08/16 15:40:14 goose: up to current file version: 214872026/08/16 15:40:14 INFO Received uploads request method=POST path=/api/pending_closures14882026/08/16 15:40:14 INFO Received uploads request method=POST path=/api/pending_closures14892026/08/16 15:40:14 INFO Received uploads request method=POST path=/api/pending_closures14902026/08/16 15:40:15 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01491=== NAME TestPinProtectsFromGC1492 client_integration_test.go:709: Pin successfully protected closure from garbage collection1493--- PASS: TestPinProtectsFromGC (4.87s)1494=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info14952026/08/16 15:40:15 INFO Received uploads request method=POST path=/1496=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key14972026/08/16 15:40:15 INFO Received request for more parts method=POST path=/1498=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key14992026/08/16 15:40:15 INFO Received complete multipart upload request method=POST path=/1500=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15012026/08/16 15:40:15 INFO Received uploads request method=POST path=/1502--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1503 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1504 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1505 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1506 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1507=== CONT TestSkippedUploadsHandler15082026/08/16 15:40:15 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001509--- PASS: TestSkippedUploadsHandler (0.00s)1510=== CONT TestServerTLSConfig/no_client_CA1511=== CONT TestServerTLSConfig/missing_CA_file1512=== CONT TestServerTLSConfig/not_a_PEM_file1513--- PASS: TestServerTLSConfig (0.00s)1514 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1515 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1516 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.03s)1517=== CONT TestProxyWriteTimeout/narinfo1518=== CONT TestProxyWriteTimeout/10_GiB_nar1519=== CONT TestProxyWriteTimeout/unknown_size1520=== CONT TestProxyWriteTimeout/1_GiB_nar1521--- PASS: TestProxyWriteTimeout (0.00s)1522 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1523 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1524 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1525 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1526=== CONT TestIsValidUploadKey/narinfo1527=== CONT TestIsValidUploadKey/realisation_plus_in_output1528=== CONT TestIsValidUploadKey/unknown_type1529=== CONT TestIsValidUploadKey/empty_key1530=== CONT TestIsValidUploadKey/absolute1531=== CONT TestIsValidUploadKey/traversal_nar1532=== CONT TestIsValidUploadKey/traversal1533=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1534=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1535=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1536=== CONT TestIsValidUploadKey/index.html1537=== CONT TestIsValidUploadKey/nix-cache-info1538=== CONT TestIsValidUploadKey/build_log_home-manager_file1539=== CONT TestIsValidUploadKey/realisation1540=== CONT TestIsValidUploadKey/build_log_equals1541=== CONT TestIsValidUploadKey/build_log_question_mark1542=== CONT TestIsValidUploadKey/build_log_plus_in_name1543=== CONT TestIsValidUploadKey/nar_plain1544=== CONT TestIsValidUploadKey/build_log1545=== CONT TestIsValidUploadKey/listing1546=== CONT TestIsValidUploadKey/nar_xz1547=== CONT TestIsValidUploadKey/nar_zst1548--- PASS: TestIsValidUploadKey (0.00s)1549 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1550 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1551 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1552 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1553 --- PASS: TestIsValidUploadKey/absolute (0.00s)1554 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1555 --- PASS: TestIsValidUploadKey/traversal (0.00s)1556 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1557 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1558 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1559 --- PASS: TestIsValidUploadKey/index.html (0.00s)1560 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1561 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1562 --- PASS: TestIsValidUploadKey/realisation (0.00s)1563 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1564 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1565 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1566 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1567 --- PASS: TestIsValidUploadKey/build_log (0.00s)1568 --- PASS: TestIsValidUploadKey/listing (0.00s)1569 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1570 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1571=== CONT TestIsValidCachePath/narinfo1572=== CONT TestIsValidCachePath/index.html1573=== CONT TestIsValidCachePath/short_hash1574=== CONT TestIsValidCachePath/wrong_extension1575=== CONT TestIsValidCachePath/leading_slash1576=== CONT TestIsValidCachePath/empty1577=== CONT TestIsValidCachePath/random_path1578=== CONT TestIsValidCachePath/invalid_char_u1579=== CONT TestIsValidCachePath/invalid_char_e1580=== CONT TestIsValidCachePath/traversal_in_middle1581=== CONT TestIsValidCachePath/traversal_parent1582=== CONT TestIsValidCachePath/nar_uncompressed1583=== CONT TestIsValidCachePath/nix-cache-info1584=== CONT TestIsValidCachePath/realisation1585=== CONT TestIsValidCachePath/log1586=== CONT TestIsValidCachePath/ls1587=== CONT TestIsValidCachePath/nar_xz1588=== CONT TestIsValidCachePath/nar_bz21589=== CONT TestIsValidCachePath/nar_zst1590=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1591--- PASS: TestIsValidCachePath (0.00s)1592 --- PASS: TestIsValidCachePath/narinfo (0.00s)1593 --- PASS: TestIsValidCachePath/index.html (0.00s)1594 --- PASS: TestIsValidCachePath/short_hash (0.00s)1595 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1596 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1597 --- PASS: TestIsValidCachePath/empty (0.00s)1598 --- PASS: TestIsValidCachePath/random_path (0.00s)1599 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1600 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1601 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1602 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1603 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1604 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1605 --- PASS: TestIsValidCachePath/realisation (0.00s)1606 --- PASS: TestIsValidCachePath/log (0.00s)1607 --- PASS: TestIsValidCachePath/ls (0.00s)1608 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1609 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1610 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1611 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1612=== CONT TestParseSingleRange/none1613=== CONT TestParseSingleRange/open-ended1614=== CONT TestParseSingleRange/start_far_past_EOF1615=== CONT TestParseSingleRange/start_past_EOF1616=== CONT TestParseSingleRange/single_byte1617=== CONT TestParseSingleRange/suffix_exceeds_size1618=== CONT TestParseSingleRange/suffix1619=== CONT TestParseSingleRange/end_clamped_to_size1620=== CONT TestParseSingleRange/malformed_both_empty1621=== CONT TestParseSingleRange/closed1622=== CONT TestParseSingleRange/malformed_end_before_start1623=== CONT TestParseSingleRange/multi-range_ignored1624=== CONT TestParseSingleRange/malformed_no_dash1625=== CONT TestParseSingleRange/unknown_unit1626--- PASS: TestParseSingleRange (0.00s)1627 --- PASS: TestParseSingleRange/none (0.00s)1628 --- PASS: TestParseSingleRange/open-ended (0.00s)1629 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1630 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1631 --- PASS: TestParseSingleRange/single_byte (0.00s)1632 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1633 --- PASS: TestParseSingleRange/suffix (0.00s)1634 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1635 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1636 --- PASS: TestParseSingleRange/closed (0.00s)1637 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1638 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1639 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1640 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1641=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart16422026/08/16 15:40:15 INFO Received complete multipart upload request method=POST path=/16432026-08-16 15:40:15.212 UTC [4475] ERROR: relation "goose_db_version" does not exist at character 3616442026-08-16 15:40:15.212 UTC [4475] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1645=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure16462026/08/16 15:40:15 INFO Received uploads request method=POST path=/16472026-08-16 15:40:15.364 UTC [4476] ERROR: relation "goose_db_version" does not exist at character 3616482026-08-16 15:40:15.364 UTC [4476] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16492026/08/16 15:40:15 OK 20241026095416_initial_model.sql (106.67ms)16502026/08/16 15:40:15 OK 20251210153512_drop_unused_gin_index.sql (10.29ms)16512026/08/16 15:40:15 OK 20251218171726_add_pins.sql (15.51ms)16522026/08/16 15:40:15 OK 20260628120000_add_object_size_and_stats.sql (1.64ms)16532026/08/16 15:40:15 goose: successfully migrated database to version: 2026062812000016542026/08/16 15:40:15 OK 1_commit_pending_closure.sql (934.58µs)16552026/08/16 15:40:15 OK 2_object_stats_trigger.sql (210.75µs)16562026/08/16 15:40:15 goose: up to current file version: 21657=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts16582026/08/16 15:40:15 INFO Received request for more parts method=POST path=/16592026/08/16 15:40:15 OK 20241026095416_initial_model.sql (116.58ms)1660--- PASS: TestUploadHandlersRejectOversizedBody (0.03s)1661 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)1662 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.28s)1663 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1664=== CONT TestCacheConfigHandler/full_config,_no_issuer1665=== CONT TestCacheConfigHandler/no_signing_keys1666=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1667=== CONT TestCacheConfigHandler/no_cache_url_configured1668--- PASS: TestCacheConfigHandler (0.00s)1669 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1670 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1671 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1672 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1673=== CONT TestClientErrorHandling/InvalidStorePath16742026/08/16 15:40:15 OK 20251210153512_drop_unused_gin_index.sql (21.09ms)16752026/08/16 15:40:15 OK 20251218171726_add_pins.sql (25.31ms)16762026/08/16 15:40:15 OK 20260628120000_add_object_size_and_stats.sql (31.83ms)16772026/08/16 15:40:15 goose: successfully migrated database to version: 2026062812000016782026/08/16 15:40:15 INFO Created nix-cache-info in bucket bucket=bucket4016792026/08/16 15:40:15 OK 1_commit_pending_closure.sql (1.56ms)16802026/08/16 15:40:15 OK 2_object_stats_trigger.sql (224µs)16812026/08/16 15:40:15 goose: up to current file version: 21682--- PASS: TestCacheStatsHandler (1.96s)1683=== CONT TestClientErrorHandling/ServerNotAvailable16842026/08/16 15:40:15 WARN Rate limiter enabled after throttle name=s3-test rate=516852026/08/16 15:40:15 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1686=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1687 throttle_test.go:213: Proxy stats: total=15, throttled=10, completeMultipart=101688 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001689--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.81s)1690=== CONT TestClientErrorHandling/InvalidAuthToken1691=== NAME TestClientCADerivations1692 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-4114-2679204974/TestClientCADerivations3765270438/001/store/pxprqmdx5fiqprpc2in631kq3rjqygcc-ca-test16932026/08/16 15:40:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16942026-08-16 15:40:16.108 UTC [4490] ERROR: relation "goose_db_version" does not exist at character 3616952026-08-16 15:40:16.108 UTC [4490] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16962026-08-16 15:40:16.108 UTC [4493] ERROR: relation "goose_db_version" does not exist at character 3616972026-08-16 15:40:16.108 UTC [4493] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16982026/08/16 15:40:16 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1699 client_ca_test.go:139: Found 1 dependencies (including self)17002026/08/16 15:40:16 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17012026/08/16 15:40:16 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MzYwMTU3ZjYtNzA4OS00MTBjLWJmNDctYjJkMDg0ZjVmMjRkLjRiMDZmMWJlLTYwNTYtNGQ5Yi1hNmQwLTUyOGY3ZGJmNDUzNXgxNzg2ODk0ODE0NzYzMzM1MDAw parts=1017022026/08/16 15:40:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17032026/08/16 15:40:16 INFO Completed upload id=117042026/08/16 15:40:16 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000017052026/08/16 15:40:16 INFO Received uploads request method=POST path=/api/pending_closures17062026/08/16 15:40:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures17072026/08/16 15:40:16 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=212.021411ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17082026/08/16 15:40:16 INFO Aborted multipart uploads count=017092026/08/16 15:40:16 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=017102026-08-16 15:40:16.235 UTC [4503] ERROR: relation "goose_db_version" does not exist at character 3617112026-08-16 15:40:16.235 UTC [4503] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17122026/08/16 15:40:16 INFO Received uploads request method=POST path=/api/pending_closures17132026/08/16 15:40:16 INFO Vacuumed table table=pending_closures17142026/08/16 15:40:16 INFO Vacuumed table table=pending_objects17152026/08/16 15:40:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached, 0 in upstream)17162026/08/16 15:40:16 INFO Uploading pxprqmdx5fiqprpc2in631kq3rjqygcc-ca-test (144B)17172026/08/16 15:40:16 INFO Vacuumed table table=multipart_uploads17182026/08/16 15:40:16 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"17192026/08/16 15:40:16 INFO Vacuumed table table=closures17202026/08/16 15:40:16 WARN Failed to register uploaded object key=log/60gp8z2sq0fvc6zbl8zxdc7gwkrghqqw-ca-test.drv error="server returned 404: 404 page not found\n"17212026/08/16 15:40:16 OK 20241026095416_initial_model.sql (157.65ms)17222026/08/16 15:40:16 OK 20241026095416_initial_model.sql (161.3ms)17232026/08/16 15:40:16 OK 20251210153512_drop_unused_gin_index.sql (18.31ms)17242026/08/16 15:40:16 INFO Vacuumed table table=objects17252026/08/16 15:40:16 OK 20251210153512_drop_unused_gin_index.sql (13.36ms)17262026/08/16 15:40:16 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001727--- PASS: TestService_createPendingClosureHandler (3.24s)17282026/08/16 15:40:16 WARN Failed to register uploaded object key=pxprqmdx5fiqprpc2in631kq3rjqygcc.ls error="server returned 404: 404 page not found\n"17292026/08/16 15:40:16 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17302026/08/16 15:40:16 INFO Signed narinfos id=1 count=117312026/08/16 15:40:16 INFO Uploading 1 narinfos17322026/08/16 15:40:16 OK 20251218171726_add_pins.sql (46.12ms)17332026/08/16 15:40:16 OK 20251218171726_add_pins.sql (50.11ms)17342026/08/16 15:40:16 WARN Failed to register uploaded object key=pxprqmdx5fiqprpc2in631kq3rjqygcc.narinfo error="server returned 404: 404 page not found\n"17352026/08/16 15:40:16 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17362026/08/16 15:40:16 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=383.271584ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17372026/08/16 15:40:16 OK 20260628120000_add_object_size_and_stats.sql (42.48ms)17382026/08/16 15:40:16 goose: successfully migrated database to version: 2026062812000017392026/08/16 15:40:16 INFO Completed upload id=117402026/08/16 15:40:16 INFO Upload complete. (304ms)17412026/08/16 15:40:16 OK 1_commit_pending_closure.sql (3.69ms)1742=== NAME TestClientCADerivations1743 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-4114-2679204974/TestClientCADerivations3765270438/001/store/pxprqmdx5fiqprpc2in631kq3rjqygcc-ca-test1744 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1745 Compression: zstd1746 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1747 NarSize: 1441748 References: 1749 Deriver: /nix/var/nix/builds/nix-4114-2679204974/TestClientCADerivations3765270438/001/store/60gp8z2sq0fvc6zbl8zxdc7gwkrghqqw-ca-test.drv1750 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1751 client_ca_test.go:185: Checking for realisation files in S3...17522026/08/16 15:40:16 OK 2_object_stats_trigger.sql (732.88µs)17532026/08/16 15:40:16 goose: up to current file version: 21754 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1755 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache17562026/08/16 15:40:16 OK 20260628120000_add_object_size_and_stats.sql (40.9ms)17572026/08/16 15:40:16 goose: successfully migrated database to version: 2026062812000017582026/08/16 15:40:16 OK 1_commit_pending_closure.sql (12.85ms)17592026/08/16 15:40:16 OK 2_object_stats_trigger.sql (403.38µs)17602026/08/16 15:40:16 goose: up to current file version: 217612026/08/16 15:40:16 OK 20241026095416_initial_model.sql (233.24ms)1762 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket40?endpoint=http://localhost:55995®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-4114-2679204974/TestClientCADerivations3765270438/001/store'1763 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 117642026/08/16 15:40:16 OK 20251210153512_drop_unused_gin_index.sql (13.29ms)17652026/08/16 15:40:16 OK 20251218171726_add_pins.sql (26.57ms)17662026/08/16 15:40:16 OK 20260628120000_add_object_size_and_stats.sql (37.76ms)17672026/08/16 15:40:16 goose: successfully migrated database to version: 2026062812000017682026/08/16 15:40:16 OK 1_commit_pending_closure.sql (11.36ms)17692026/08/16 15:40:16 OK 2_object_stats_trigger.sql (406.33µs)17702026/08/16 15:40:16 goose: up to current file version: 217712026/08/16 15:40:16 WARN mTLS auth: subject not in bound subjects subject="CN=writer"1772--- PASS: TestService_ReadAuthMiddleware (2.39s)1773--- PASS: TestClientCADerivations (3.14s)1774=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1775=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1776=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1777=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1778=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1779=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1780=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1781=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1782=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1783=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1784=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected1785=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected17862026/08/16 15:40:16 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]17872026/08/16 15:40:16 INFO OIDC auth successful provider=test17882026/08/16 15:40:16 WARN Authentication failed token_preview=eyJhbGciOi...JUuYUrqFqQ 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]1789--- PASS: TestService_AuthMiddleware_OIDC (2.44s)1790 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1791 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1792 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)1793 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)17942026/08/16 15:40:16 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=749.436883ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config17952026/08/16 15:40:16 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17962026/08/16 15:40:16 WARN mTLS auth: bound subjects configured but subject DN unavailable17972026/08/16 15:40:16 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1798--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.52s)17992026-08-16 15:40:16.986 UTC [4506] ERROR: relation "goose_db_version" does not exist at character 3618002026-08-16 15:40:16.986 UTC [4506] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18012026/08/16 15:40:17 OK 20241026095416_initial_model.sql (153.9ms)18022026/08/16 15:40:17 OK 20251210153512_drop_unused_gin_index.sql (8.62ms)18032026/08/16 15:40:17 OK 20251218171726_add_pins.sql (32.3ms)18042026/08/16 15:40:17 OK 20260628120000_add_object_size_and_stats.sql (21.08ms)18052026/08/16 15:40:17 goose: successfully migrated database to version: 2026062812000018062026/08/16 15:40:17 OK 1_commit_pending_closure.sql (9.91ms)18072026/08/16 15:40:17 OK 2_object_stats_trigger.sql (1ms)18082026/08/16 15:40:17 goose: up to current file version: 21809--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.80s)18102026/08/16 15:40:17 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.556476869s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config18112026-08-16 15:40:17.683 UTC [4507] ERROR: relation "goose_db_version" does not exist at character 3618122026-08-16 15:40:17.683 UTC [4507] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18132026/08/16 15:40:17 OK 20241026095416_initial_model.sql (142.05ms)18142026/08/16 15:40:17 OK 20251210153512_drop_unused_gin_index.sql (12.68ms)18152026/08/16 15:40:17 OK 20251218171726_add_pins.sql (20.77ms)18162026/08/16 15:40:17 OK 20260628120000_add_object_size_and_stats.sql (21.58ms)18172026/08/16 15:40:17 goose: successfully migrated database to version: 2026062812000018182026/08/16 15:40:17 OK 1_commit_pending_closure.sql (8.13ms)18192026/08/16 15:40:17 OK 2_object_stats_trigger.sql (1.12ms)18202026/08/16 15:40:17 goose: up to current file version: 218212026-08-16 15:40:17.966 UTC [4508] ERROR: relation "goose_db_version" does not exist at character 3618222026-08-16 15:40:17.966 UTC [4508] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC18232026/08/16 15:40:18 OK 20241026095416_initial_model.sql (101.36ms)18242026/08/16 15:40:18 OK 20251210153512_drop_unused_gin_index.sql (10.35ms)18252026/08/16 15:40:18 OK 20251218171726_add_pins.sql (11.83ms)18262026/08/16 15:40:18 OK 20260628120000_add_object_size_and_stats.sql (21.54ms)18272026/08/16 15:40:18 goose: successfully migrated database to version: 2026062812000018282026/08/16 15:40:18 OK 1_commit_pending_closure.sql (6.06ms)18292026/08/16 15:40:18 OK 2_object_stats_trigger.sql (280.63µs)18302026/08/16 15:40:18 goose: up to current file version: 218312026/08/16 15:40:18 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"18322026/08/16 15:40:18 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18332026/08/16 15:40:19 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused"18342026/08/16 15:40:19 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18352026/08/16 15:40:19 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=189.346897ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18362026/08/16 15:40:19 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=402.128363ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18372026/08/16 15:40:19 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=790.73269ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures18382026/08/16 15:40:20 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.718141024s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1839=== NAME TestOrphanedObjectsGCStressTest1840 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1841 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1842 orphaned_objects_gc_test.go:509: Stress test completed successfully:1843 orphaned_objects_gc_test.go:510: - Active objects preserved: 201844 orphaned_objects_gc_test.go:511: - Objects deleted: 2101845 orphaned_objects_gc_test.go:512: - Total GC'd: 2101846--- PASS: TestOrphanedObjectsGCStressTest (8.18s)1847--- PASS: TestClientErrorHandling (0.00s)1848 --- PASS: TestClientErrorHandling/InvalidStorePath (2.63s)1849 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.68s)1850 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.60s)1851PASS1852{"timestamp":"2026-08-16T15:40:22.43946Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:56096","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":1836,"threadName":"rustfs-worker","threadId":"ThreadId(7)"}18532026-08-16 15:40:22.547 UTC [4178] LOG: received smart shutdown request18542026-08-16 15:40:22.548 UTC [4178] LOG: background worker "logical replication launcher" (PID 4188) exited with exit code 118552026-08-16 15:40:22.556 UTC [4183] LOG: shutting down18562026-08-16 15:40:22.556 UTC [4183] LOG: checkpoint starting: shutdown immediate18572026-08-16 15:40:23.617 UTC [4183] LOG: checkpoint complete: wrote 13440 buffers (82.0%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 13 recycled; write=0.794 s, sync=0.266 s, total=1.061 s; sync files=15496, longest=0.001 s, average=0.001 s; distance=217155 kB, estimate=217155 kB; lsn=0/EB9BBF0, redo lsn=0/EB9BBF018582026-08-16 15:40:23.621 UTC [4178] LOG: database system is shut down1859Running OIDC tests...1860=== RUN TestGlobMatch1861=== PAUSE TestGlobMatch1862=== RUN TestAudienceForIssuer1863=== PAUSE TestAudienceForIssuer1864=== RUN TestValidateToken_ValidToken1865=== PAUSE TestValidateToken_ValidToken1866=== RUN TestValidateToken_WrongAudience1867=== PAUSE TestValidateToken_WrongAudience1868=== RUN TestValidateToken_Expired1869=== PAUSE TestValidateToken_Expired1870=== RUN TestValidateToken_BoundClaimsMismatch1871=== PAUSE TestValidateToken_BoundClaimsMismatch1872=== RUN TestValidateToken_BoundSubjectMismatch1873=== PAUSE TestValidateToken_BoundSubjectMismatch1874=== RUN TestValidateToken_MultipleProviders1875=== PAUSE TestValidateToken_MultipleProviders1876=== RUN TestValidateToken_NoMatchingProvider1877=== PAUSE TestValidateToken_NoMatchingProvider1878=== CONT TestGlobMatch1879=== CONT TestValidateToken_WrongAudience1880=== CONT TestValidateToken_BoundClaimsMismatch1881=== CONT TestValidateToken_Expired1882=== RUN TestGlobMatch/foo_foo1883=== PAUSE TestGlobMatch/foo_foo1884=== RUN TestGlobMatch/foo_bar1885=== PAUSE TestGlobMatch/foo_bar1886=== RUN TestGlobMatch/*_1887=== PAUSE TestGlobMatch/*_1888=== RUN TestGlobMatch/*_anything1889=== PAUSE TestGlobMatch/*_anything1890=== RUN TestGlobMatch/foo*_foo1891=== PAUSE TestGlobMatch/foo*_foo1892=== RUN TestGlobMatch/foo*_foobar1893=== PAUSE TestGlobMatch/foo*_foobar1894=== RUN TestGlobMatch/foo*_bar1895=== PAUSE TestGlobMatch/foo*_bar1896=== RUN TestGlobMatch/*bar_bar1897=== CONT TestValidateToken_ValidToken1898=== CONT TestAudienceForIssuer1899--- PASS: TestAudienceForIssuer (0.00s)1900=== CONT TestValidateToken_MultipleProviders1901=== CONT TestValidateToken_NoMatchingProvider1902=== CONT TestValidateToken_BoundSubjectMismatch1903=== PAUSE TestGlobMatch/*bar_bar1904=== RUN TestGlobMatch/*bar_foobar1905=== PAUSE TestGlobMatch/*bar_foobar1906=== RUN TestGlobMatch/*bar_foo1907=== PAUSE TestGlobMatch/*bar_foo1908=== RUN TestGlobMatch/foo*bar_foobar1909=== PAUSE TestGlobMatch/foo*bar_foobar1910=== RUN TestGlobMatch/foo*bar_foo123bar1911=== PAUSE TestGlobMatch/foo*bar_foo123bar1912=== RUN TestGlobMatch/foo*bar_foobarbaz1913=== PAUSE TestGlobMatch/foo*bar_foobarbaz1914=== RUN TestGlobMatch/*/*_foo/bar1915=== PAUSE TestGlobMatch/*/*_foo/bar1916=== RUN TestGlobMatch/*/*_foo1917=== PAUSE TestGlobMatch/*/*_foo1918=== RUN TestGlobMatch/refs/heads/*_refs/heads/main1919=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main1920=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.01921=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.01922=== RUN TestGlobMatch/refs/*/main_refs/heads/main1923=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main1924=== RUN TestGlobMatch/fo?_foo1925=== PAUSE TestGlobMatch/fo?_foo1926=== RUN TestGlobMatch/fo?_fo1927=== PAUSE TestGlobMatch/fo?_fo1928=== RUN TestGlobMatch/fo?_fooo1929=== PAUSE TestGlobMatch/fo?_fooo1930=== RUN TestGlobMatch/?oo_foo1931=== PAUSE TestGlobMatch/?oo_foo1932=== RUN TestGlobMatch/?oo_boo1933=== PAUSE TestGlobMatch/?oo_boo1934=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1935=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1936=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1937=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1938=== CONT TestGlobMatch/foo_foo1939=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main1940=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main1941=== CONT TestGlobMatch/?oo_boo1942=== CONT TestGlobMatch/?oo_foo1943=== CONT TestGlobMatch/fo?_fooo1944=== CONT TestGlobMatch/fo?_fo1945=== CONT TestGlobMatch/fo?_foo1946=== CONT TestGlobMatch/refs/*/main_refs/heads/main1947=== CONT TestGlobMatch/*bar_foo1948=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.01949=== CONT TestGlobMatch/refs/heads/*_refs/heads/main1950=== CONT TestGlobMatch/foo*_foobar1951=== CONT TestGlobMatch/*bar_foobar1952=== CONT TestGlobMatch/foo*bar_foo123bar1953=== CONT TestGlobMatch/*bar_bar1954=== CONT TestGlobMatch/foo*_bar1955=== CONT TestGlobMatch/foo*bar_foobar1956=== CONT TestGlobMatch/*_anything1957=== CONT TestGlobMatch/foo*_foo1958=== CONT TestGlobMatch/*_1959=== CONT TestGlobMatch/foo_bar1960=== CONT TestGlobMatch/*/*_foo1961=== CONT TestGlobMatch/foo*bar_foobarbaz1962=== CONT TestGlobMatch/*/*_foo/bar1963--- PASS: TestGlobMatch (0.00s)1964 --- PASS: TestGlobMatch/foo_foo (0.00s)1965 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)1966 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)1967 --- PASS: TestGlobMatch/?oo_boo (0.00s)1968 --- PASS: TestGlobMatch/?oo_foo (0.00s)1969 --- PASS: TestGlobMatch/fo?_fooo (0.00s)1970 --- PASS: TestGlobMatch/fo?_fo (0.00s)1971 --- PASS: TestGlobMatch/fo?_foo (0.00s)1972 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)1973 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)1974 --- PASS: TestGlobMatch/foo*_foobar (0.00s)1975 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)1976 --- PASS: TestGlobMatch/*bar_foobar (0.00s)1977 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)1978 --- PASS: TestGlobMatch/*bar_bar (0.00s)1979 --- PASS: TestGlobMatch/foo*_bar (0.00s)1980 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)1981 --- PASS: TestGlobMatch/*bar_foo (0.00s)1982 --- PASS: TestGlobMatch/*_anything (0.00s)1983 --- PASS: TestGlobMatch/foo*_foo (0.00s)1984 --- PASS: TestGlobMatch/*_ (0.00s)1985 --- PASS: TestGlobMatch/foo_bar (0.00s)1986 --- PASS: TestGlobMatch/*/*_foo (0.00s)1987 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)1988 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)19892026/08/16 15:40:24 INFO OIDC provider initialized name=provider119902026/08/16 15:40:24 INFO OIDC provider initialized name=test19912026/08/16 15:40:24 INFO OIDC provider initialized name=test19922026/08/16 15:40:24 INFO OIDC provider initialized name=test19932026/08/16 15:40:24 INFO OIDC provider initialized name=test19942026/08/16 15:40:24 INFO OIDC provider initialized name=test19952026/08/16 15:40:24 INFO OIDC provider initialized name=provider219962026/08/16 15:40:24 INFO OIDC provider initialized name=provider11997--- PASS: TestValidateToken_WrongAudience (0.01s)1998--- PASS: TestValidateToken_Expired (0.01s)1999--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2000--- PASS: TestValidateToken_ValidToken (0.01s)2001--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2002--- PASS: TestValidateToken_NoMatchingProvider (0.01s)2003--- PASS: TestValidateToken_MultipleProviders (0.01s)2004PASS2005Running hook tests...2006=== RUN TestSendPathsEmpty2007=== PAUSE TestSendPathsEmpty2008=== RUN TestQueueEnqueueAndFetch2009=== PAUSE TestQueueEnqueueAndFetch2010=== RUN TestQueueDeduplication2011=== PAUSE TestQueueDeduplication2012=== RUN TestQueueRemove2013=== PAUSE TestQueueRemove2014=== RUN TestQueueFetchBatchLimit2015=== PAUSE TestQueueFetchBatchLimit2016=== RUN TestQueueFetchRemoveLifecycle2017=== PAUSE TestQueueFetchRemoveLifecycle2018=== RUN TestQueueConcurrentWriters2019=== PAUSE TestQueueConcurrentWriters2020=== RUN TestServerClientIntegration2021=== PAUSE TestServerClientIntegration2022=== RUN TestServerQueueError2023=== PAUSE TestServerQueueError2024=== RUN TestGetListenerSocketActivation2025 server_test.go:210: === RUN TestGetListenerSocketActivation2026 --- PASS: TestGetListenerSocketActivation (0.00s)2027 PASS2028 2029--- PASS: TestGetListenerSocketActivation (0.01s)2030=== RUN TestWorkerUploadsAndRemoves2031=== PAUSE TestWorkerUploadsAndRemoves2032=== RUN TestWorkerSkipsGCdPaths2033=== PAUSE TestWorkerSkipsGCdPaths2034=== RUN TestWorkerPrunesClosureDeps2035=== PAUSE TestWorkerPrunesClosureDeps2036=== CONT TestSendPathsEmpty2037--- PASS: TestSendPathsEmpty (0.00s)2038=== CONT TestQueueFetchRemoveLifecycle2039=== CONT TestQueueConcurrentWriters2040=== CONT TestWorkerPrunesClosureDeps2041=== CONT TestQueueRemove2042=== CONT TestQueueFetchBatchLimit2043=== CONT TestServerQueueError2044=== CONT TestQueueDeduplication2045=== CONT TestWorkerSkipsGCdPaths2046=== CONT TestQueueEnqueueAndFetch2047=== CONT TestWorkerUploadsAndRemoves20482026/08/16 15:40:24 ERROR Failed to queue paths error="permission denied" count=12049--- PASS: TestServerQueueError (0.00s)2050=== CONT TestServerClientIntegration2051--- PASS: TestServerClientIntegration (0.00s)2052--- PASS: TestQueueRemove (0.01s)20532026/08/16 15:40:24 INFO Upload queue status pending=220542026/08/16 15:40:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-4114-2679204974/TestWorkerSkipsGCdPaths1806344448/002/nonexistent20552026/08/16 15:40:24 INFO Upload queue status pending=220562026/08/16 15:40:24 INFO Uploading batch count=12057--- PASS: TestQueueFetchBatchLimit (0.01s)2058--- PASS: TestQueueDeduplication (0.01s)20592026/08/16 15:40:24 INFO Uploading batch count=12060--- PASS: TestQueueEnqueueAndFetch (0.01s)20612026/08/16 15:40:24 INFO Upload queue status pending=220622026/08/16 15:40:24 INFO Uploading batch count=22063--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2064--- PASS: TestWorkerSkipsGCdPaths (0.06s)2065--- PASS: TestWorkerUploadsAndRemoves (0.06s)2066--- PASS: TestWorkerPrunesClosureDeps (0.06s)2067--- PASS: TestQueueConcurrentWriters (0.16s)2068PASS