niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #360
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry5=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry6=== RUN TestRegisterUploadedObjectReusesConnections7=== PAUSE TestRegisterUploadedObjectReusesConnections8=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica9=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica10=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun11=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun12=== RUN TestCaseHackSuffix13=== PAUSE TestCaseHackSuffix14=== RUN TestFilterOversizedClosures15=== PAUSE TestFilterOversizedClosures16=== RUN TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure17=== PAUSE TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure18=== RUN TestUploadMultipart_PartsInParallel19=== PAUSE TestUploadMultipart_PartsInParallel20=== RUN TestUploadMultipart_ProducerErrorIsNotEOF21=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF22=== RUN TestUploadMultipart_FailedPartBufferNotReused23=== PAUSE TestUploadMultipart_FailedPartBufferNotReused24=== RUN TestPartSizeForNAR25=== PAUSE TestPartSizeForNAR26=== RUN TestUploadMultipart_SupersededByPeer27=== PAUSE TestUploadMultipart_SupersededByPeer28=== RUN TestDumpPathCaseHackMatchesNix29--- PASS: TestDumpPathCaseHackMatchesNix (0.06s)30=== RUN TestDumpPathCaseHackCollision31--- PASS: TestDumpPathCaseHackCollision (0.00s)32=== RUN TestSupersededNARStillUploadsListing33=== PAUSE TestSupersededNARStillUploadsListing34=== RUN TestTruncatedNARDumpIsNotCompleted35=== PAUSE TestTruncatedNARDumpIsNotCompleted36=== RUN TestDumpPathMatchesNix37=== PAUSE TestDumpPathMatchesNix38=== RUN TestDumpPathSingleFile39=== PAUSE TestDumpPathSingleFile40=== RUN TestDumpPathWriterError41=== PAUSE TestDumpPathWriterError42=== RUN TestDumpPathWriterErrorStopsReading43 nar_test.go:280: no /proc/self/io: open /proc/self/io: no such file or directory44--- SKIP: TestDumpPathWriterErrorStopsReading (0.36s)45=== RUN TestEncodeNixBase3246=== PAUSE TestEncodeNixBase3247=== RUN TestEncodeNixBase32WithRealHash48=== PAUSE TestEncodeNixBase32WithRealHash49=== RUN TestConvertHashToNix3250=== PAUSE TestConvertHashToNix3251=== RUN TestGetStorePathHash52=== PAUSE TestGetStorePathHash53=== RUN TestPathInfoHashCompatibility54=== PAUSE TestPathInfoHashCompatibility55=== RUN TestParsePathInfoJSON56=== PAUSE TestParsePathInfoJSON57=== RUN TestParsePathInfoJSONMultiplePaths58=== PAUSE TestParsePathInfoJSONMultiplePaths59=== RUN TestPathInfoCACompatibility60=== PAUSE TestPathInfoCACompatibility61=== RUN TestUploadPendingObjectsStopsStartingAfterFailure62--- PASS: TestUploadPendingObjectsStopsStartingAfterFailure (0.01s)63=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent64=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent65=== RUN TestCompletePendingClosure_NotFoundWithoutKey66=== PAUSE TestCompletePendingClosure_NotFoundWithoutKey67=== RUN TestRateLimiterFeedback68=== PAUSE TestRateLimiterFeedback69=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess70=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess71=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer72=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer73=== RUN TestResolveStorePath74=== PAUSE TestResolveStorePath75=== RUN TestDoWithRetry_BodyReplayedViaGetBody76=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody77=== RUN TestDoWithRetry_FinalResponseBodyReadable78=== PAUSE TestDoWithRetry_FinalResponseBodyReadable79=== RUN TestShellSplit80=== PAUSE TestShellSplit81=== RUN TestShellSplitErrors82=== PAUSE TestShellSplitErrors83=== RUN TestStreamPushReportsEveryPath84=== PAUSE TestStreamPushReportsEveryPath85=== RUN TestStreamPushBatchesUnderLoad86=== PAUSE TestStreamPushBatchesUnderLoad87=== RUN TestStreamPushIsolatesFailures88=== PAUSE TestStreamPushIsolatesFailures89=== RUN TestStreamPushGivesUpOnDeadServer90=== PAUSE TestStreamPushGivesUpOnDeadServer91=== RUN TestStreamPushRequestLine92=== PAUSE TestStreamPushRequestLine93=== RUN TestStreamPushReportsSignatures94=== PAUSE TestStreamPushReportsSignatures95=== RUN TestClientSignaturesByStorePath96=== PAUSE TestClientSignaturesByStorePath97=== RUN TestStreamPushStopsOnCancel98=== PAUSE TestStreamPushStopsOnCancel99=== RUN TestSetClientTLS100=== PAUSE TestSetClientTLS101=== RUN TestSetClientTLSDoesNotMutateDefaultTransport102=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport103=== RUN TestSetClientTLSErrors104=== PAUSE TestSetClientTLSErrors105=== RUN TestStaticToken106=== PAUSE TestStaticToken107=== RUN TestFileTokenReadsAndCaches108=== PAUSE TestFileTokenReadsAndCaches109=== RUN TestFileTokenMissing110=== PAUSE TestFileTokenMissing111=== RUN TestFileTokenEmpty112=== PAUSE TestFileTokenEmpty113=== RUN TestScriptTokenNoExpiryRerunsEveryCall114=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall115=== RUN TestScriptTokenCachesUntilRefresh116=== PAUSE TestScriptTokenCachesUntilRefresh117=== RUN TestScriptTokenEmptyToken118=== PAUSE TestScriptTokenEmptyToken119=== RUN TestScriptTokenBadJSON120=== PAUSE TestScriptTokenBadJSON121=== RUN TestScriptTokenScriptFails122=== PAUSE TestScriptTokenScriptFails123=== RUN TestScriptTokenEmptyCommand124=== PAUSE TestScriptTokenEmptyCommand125=== RUN TestScriptTokenDoesNotWaitForItsChildren126=== PAUSE TestScriptTokenDoesNotWaitForItsChildren127=== CONT TestRegisterUploadedObjectReusesConnections128=== CONT TestFileTokenEmpty129=== CONT TestDumpPathSingleFile130=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer131=== CONT TestScriptTokenScriptFails132--- PASS: TestFileTokenEmpty (0.00s)133=== CONT TestRateLimiterFeedback134=== RUN TestRateLimiterFeedback/429_enables_limiter135=== PAUSE TestRateLimiterFeedback/429_enables_limiter136=== RUN TestRateLimiterFeedback/503_enables_limiter137=== CONT TestScriptTokenDoesNotWaitForItsChildren138=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs139=== CONT TestScriptTokenEmptyCommand140=== PAUSE TestRateLimiterFeedback/503_enables_limiter141=== CONT TestScriptTokenBadJSON142=== CONT TestScriptTokenEmptyToken143=== CONT TestScriptTokenCachesUntilRefresh144--- PASS: TestScriptTokenEmptyCommand (0.00s)145=== CONT TestCompletePendingClosure_NotFoundWithoutKey146=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter147=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter148=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter149=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs150=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout151=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout152=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent153=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier154=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter155=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier156=== CONT TestParsePathInfoJSONMultiplePaths157=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths158=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up159=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up160=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths161=== CONT TestParsePathInfoJSON162=== RUN TestParsePathInfoJSON/Nix_format163=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths164=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths165=== PAUSE TestParsePathInfoJSON/Nix_format166=== RUN TestParsePathInfoJSON/Lix_format167=== CONT TestPathInfoCACompatibility168=== RUN TestPathInfoCACompatibility/null_ca_field169=== PAUSE TestPathInfoCACompatibility/null_ca_field170=== PAUSE TestParsePathInfoJSON/Lix_format171=== RUN TestPathInfoCACompatibility/old_string_format_-_text172=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text173=== RUN TestParsePathInfoJSON/empty_input174=== PAUSE TestParsePathInfoJSON/empty_input175=== RUN TestParsePathInfoJSON/whitespace_only176=== PAUSE TestParsePathInfoJSON/whitespace_only177=== RUN TestParsePathInfoJSON/invalid_JSON178=== PAUSE TestParsePathInfoJSON/invalid_JSON179=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive180=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive181=== CONT TestPathInfoHashCompatibility182=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)183=== RUN TestPathInfoCACompatibility/new_structured_format_-_text184=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text185=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method186=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method187=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)188=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon189=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon190=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI191=== CONT TestGetStorePathHash192=== RUN TestGetStorePathHash/valid_store_path193=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI194=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512195=== PAUSE TestGetStorePathHash/valid_store_path196=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512197=== RUN TestGetStorePathHash/basename_without_hyphen_should_error198=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error199=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error200=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error201=== CONT TestConvertHashToNix32202=== RUN TestConvertHashToNix32/SRI_format_to_Nix32203=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error204=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error205=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32206=== RUN TestConvertHashToNix32/already_Nix32_format207=== PAUSE TestConvertHashToNix32/already_Nix32_format208=== CONT TestEncodeNixBase32209=== RUN TestEncodeNixBase32/test_string_hash210=== RUN TestConvertHashToNix32/invalid_format211=== PAUSE TestEncodeNixBase32/test_string_hash212=== RUN TestEncodeNixBase32/empty_input213=== PAUSE TestConvertHashToNix32/invalid_format214=== PAUSE TestEncodeNixBase32/empty_input215=== CONT TestDumpPathWriterError216=== CONT TestEncodeNixBase32WithRealHash217=== CONT TestFileTokenMissing218--- PASS: TestScriptTokenScriptFails (0.02s)219=== CONT TestDumpPathMatchesNix220=== CONT TestStreamPushReportsSignatures221--- PASS: TestScriptTokenBadJSON (0.01s)222--- PASS: TestEncodeNixBase32WithRealHash (0.00s)223--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.01s)224=== CONT TestScriptTokenNoExpiryRerunsEveryCall225--- PASS: TestStreamPushReportsSignatures (0.00s)226=== CONT TestFileTokenReadsAndCaches227--- PASS: TestFileTokenMissing (0.00s)228=== CONT TestStaticToken229--- PASS: TestStaticToken (0.00s)230=== CONT TestSetClientTLSErrors231--- PASS: TestScriptTokenEmptyToken (0.02s)232=== RUN TestSetClientTLSErrors/missing_cert_file233=== PAUSE TestSetClientTLSErrors/missing_cert_file234=== RUN TestSetClientTLSErrors/missing_key_file235=== PAUSE TestSetClientTLSErrors/missing_key_file236=== RUN TestSetClientTLSErrors/missing_ca_file237=== PAUSE TestSetClientTLSErrors/missing_ca_file238=== RUN TestSetClientTLSErrors/invalid_ca_file239=== PAUSE TestSetClientTLSErrors/invalid_ca_file240=== CONT TestSetClientTLSDoesNotMutateDefaultTransport241--- PASS: TestFileTokenReadsAndCaches (0.00s)242=== CONT TestClientSignaturesByStorePath243--- PASS: TestClientSignaturesByStorePath (0.00s)244=== CONT TestStreamPushStopsOnCancel245=== RUN TestStreamPushStopsOnCancel/waiting_for_input246=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input247=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot248=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot249=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot250=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot251=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot252=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot253=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot254=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot255=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken256=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken257=== CONT TestSetClientTLS258=== CONT TestStreamPushRequestLine259--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)260=== CONT TestShellSplit261--- PASS: TestShellSplit (0.00s)262=== CONT TestStreamPushIsolatesFailures263--- PASS: TestStreamPushIsolatesFailures (0.00s)264=== CONT TestStreamPushBatchesUnderLoad265=== RUN TestStreamPushBatchesUnderLoad/together266=== PAUSE TestStreamPushBatchesUnderLoad/together267=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time268=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time269=== CONT TestStreamPushReportsEveryPath270--- PASS: TestStreamPushReportsEveryPath (0.00s)271=== CONT TestStreamPushGivesUpOnDeadServer272=== RUN TestSetClientTLS/rejects_connection_without_client_cert273=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert274=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA275=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA276=== RUN TestSetClientTLS/preserves_debug_logging_transport277=== PAUSE TestSetClientTLS/preserves_debug_logging_transport278=== CONT TestUploadMultipart_PartsInParallel279--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)280=== CONT TestTruncatedNARDumpIsNotCompleted281--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)282=== CONT TestSupersededNARStillUploadsListing283=== RUN TestSupersededNARStillUploadsListing/small_NAR284=== PAUSE TestSupersededNARStillUploadsListing/small_NAR285=== RUN TestSupersededNARStillUploadsListing/dump_cut_short286=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short287=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails288=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails289=== CONT TestPartSizeForNAR290=== RUN TestPartSizeForNAR/zero_stays_at_minimum291=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum292=== RUN TestPartSizeForNAR/small_stays_at_minimum293=== PAUSE TestPartSizeForNAR/small_stays_at_minimum294=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum295=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum296=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts297=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts298=== RUN TestPartSizeForNAR/1_TiB299=== PAUSE TestPartSizeForNAR/1_TiB300=== RUN TestPartSizeForNAR/5_TiB_S3_max_object301=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object302=== RUN TestPartSizeForNAR/capped_at_5_GiB303=== PAUSE TestPartSizeForNAR/capped_at_5_GiB304=== CONT TestUploadMultipart_FailedPartBufferNotReused305--- PASS: TestDumpPathSingleFile (0.05s)306=== CONT TestUploadMultipart_SupersededByPeer307=== RUN TestUploadMultipart_SupersededByPeer/exists308=== PAUSE TestUploadMultipart_SupersededByPeer/exists309=== RUN TestUploadMultipart_SupersededByPeer/missing310=== PAUSE TestUploadMultipart_SupersededByPeer/missing311=== CONT TestUploadMultipart_ProducerErrorIsNotEOF312=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part313=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part314=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary315=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary316=== CONT TestResolveStorePath317--- PASS: TestResolveStorePath (0.00s)318=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess319--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)320=== CONT TestDoWithRetry_FinalResponseBodyReadable321--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)322=== CONT TestShellSplitErrors323--- PASS: TestShellSplitErrors (0.00s)324=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun325--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)326=== CONT TestFilterOversizedClosures327=== RUN TestFilterOversizedClosures/no_limit_keeps_everything328=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything329=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped330=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped331=== RUN TestFilterOversizedClosures/all_closures_skipped332=== PAUSE TestFilterOversizedClosures/all_closures_skipped333=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure334--- PASS: TestDumpPathWriterError (0.08s)335=== CONT TestCaseHackSuffix336--- PASS: TestStreamPushRequestLine (0.10s)337=== CONT TestDoWithRetry_BodyReplayedViaGetBody338--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)339=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry340--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.01s)341=== CONT TestDoServerRequestAttachesToken342--- PASS: TestDoServerRequestAttachesToken (0.00s)343=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica344--- PASS: TestCaseHackSuffix (0.05s)345=== CONT TestRateLimiterFeedback/429_enables_limiter346--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)347=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout348=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs349--- PASS: TestDumpPathMatchesNix (0.16s)350=== CONT TestRateLimiterFeedback/503_enables_limiter351=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter352=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter353--- PASS: TestRateLimiterFeedback (0.01s)354 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)355 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)356 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)357 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)358=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up359=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier360--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.00s)361 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.00s)362 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.00s)363=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths364=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths365=== CONT TestParsePathInfoJSON/Nix_format366--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)367 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)368 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)369=== CONT TestParsePathInfoJSON/invalid_JSON370=== CONT TestParsePathInfoJSON/whitespace_only371=== CONT TestParsePathInfoJSON/empty_input372=== CONT TestParsePathInfoJSON/Lix_format373=== CONT TestPathInfoCACompatibility/old_string_format_-_text374--- PASS: TestParsePathInfoJSON (0.00s)375 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)376 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)377 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)378 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)379 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)380=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method381=== CONT TestPathInfoCACompatibility/new_structured_format_-_text382=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive383=== CONT TestPathInfoCACompatibility/null_ca_field384--- PASS: TestPathInfoCACompatibility (0.00s)385 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)386 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)387 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)388 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)389 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)390=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon391=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512392=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI393=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)394=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error395--- PASS: TestPathInfoHashCompatibility (0.00s)396 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)397 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)398 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)399 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)400=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error401=== CONT TestGetStorePathHash/basename_without_hyphen_should_error402=== CONT TestGetStorePathHash/valid_store_path403=== CONT TestConvertHashToNix32/invalid_format404=== CONT TestEncodeNixBase32/empty_input405--- PASS: TestGetStorePathHash (0.00s)406 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)407 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)408 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)409 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)410=== CONT TestConvertHashToNix32/already_Nix32_format411=== CONT TestConvertHashToNix32/SRI_format_to_Nix32412--- PASS: TestConvertHashToNix32 (0.00s)413 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)414 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)415 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)416=== CONT TestEncodeNixBase32/test_string_hash417--- PASS: TestEncodeNixBase32 (0.00s)418 --- PASS: TestEncodeNixBase32/empty_input (0.00s)419 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)420=== CONT TestSetClientTLSErrors/missing_ca_file421=== CONT TestSetClientTLSErrors/missing_key_file422=== CONT TestSetClientTLSErrors/invalid_ca_file423=== CONT TestSetClientTLSErrors/missing_cert_file424=== CONT TestStreamPushStopsOnCancel/waiting_for_input425--- PASS: TestSetClientTLSErrors (0.00s)426 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)427 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)428 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)429 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)430--- PASS: TestRegisterUploadedObjectReusesConnections (0.20s)431=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot432--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.14s)433=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot434=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot435=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken436=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot437=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time438=== CONT TestStreamPushBatchesUnderLoad/together439=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA440--- PASS: TestStreamPushBatchesUnderLoad (0.00s)441 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)442 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)443=== CONT TestSetClientTLS/preserves_debug_logging_transport444=== CONT TestSetClientTLS/rejects_connection_without_client_cert445=== CONT TestSupersededNARStillUploadsListing/small_NAR446=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails447--- PASS: TestStreamPushStopsOnCancel (0.00s)448 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.05s)449 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.05s)450 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.05s)451 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)452 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.05s)453 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.05s)454=== CONT TestSupersededNARStillUploadsListing/dump_cut_short455--- PASS: TestSetClientTLS (0.00s)456 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)457 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)458 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)459=== CONT TestPartSizeForNAR/zero_stays_at_minimum460=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts461=== CONT TestPartSizeForNAR/5_TiB_S3_max_object462=== CONT TestPartSizeForNAR/1_TiB463=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum464=== CONT TestPartSizeForNAR/capped_at_5_GiB465=== CONT TestPartSizeForNAR/small_stays_at_minimum466=== CONT TestUploadMultipart_SupersededByPeer/missing467--- PASS: TestPartSizeForNAR (0.00s)468 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)469 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)470 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)471 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)472 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)473 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)474 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)475=== CONT TestUploadMultipart_SupersededByPeer/exists476=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part477--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)478 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)479 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)480=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary481=== CONT TestFilterOversizedClosures/all_closures_skipped482=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped483=== CONT TestFilterOversizedClosures/no_limit_keeps_everything484--- PASS: TestFilterOversizedClosures (0.00s)485 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)486 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)487 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)488--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.00s)489 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.03s)490 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.03s)491--- PASS: TestTruncatedNARDumpIsNotCompleted (0.40s)492--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.64s)493--- PASS: TestUploadMultipart_PartsInParallel (0.66s)494--- PASS: TestSupersededNARStillUploadsListing (0.00s)495 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.00s)496 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.01s)497 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.59s)498--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)499--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (2.00s)500--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.01s)501 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.02s)502 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.21s)503PASS504Running server tests...505The files belonging to this database system will be owned by user "_nixbld1".506This user must also own the server process.507508The database cluster will be initialized with locale "C".509The default database encoding has accordingly been set to "SQL_ASCII".510The default text search configuration will be set to "english".511512Data page checksums are enabled.513514creating directory /nix/var/nix/builds/nix-97026-1645623550/postgres714126437/data ... ok515creating subdirectories ... ok516selecting dynamic shared memory implementation ... posix517selecting default "max_connections" ... 100518selecting default "shared_buffers" ... 128MB519selecting default time zone ... UTC520creating configuration files ... ok521running bootstrap script ... ok522performing post-bootstrap initialization ... ok523syncing data to disk ... ok524525initdb: warning: enabling "trust" authentication for local connections526initdb: 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.527528Success. You can now start the database server using:529530 pg_ctl -D /nix/var/nix/builds/nix-97026-1645623550/postgres714126437/data -l logfile start531532/nix/var/nix/builds/nix-97026-1645623550/postgres714126437:5432 - no response5332026-10-05 12:09:14.893 UTC [97072] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5342026-10-05 12:09:14.893 UTC [97072] LOG: listening on Unix socket "/nix/var/nix/builds/nix-97026-1645623550/postgres714126437/.s.PGSQL.5432"5352026-10-05 12:09:14.895 UTC [97079] LOG: database system was shut down at 2026-10-05 12:09:14 UTC5362026-10-05 12:09:14.896 UTC [97072] LOG: database system is ready to accept connections537/nix/var/nix/builds/nix-97026-1645623550/postgres714126437:5432 - accepting connections538{"timestamp":"2026-10-05T12:09:15.114629Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"b9a33997-47cf-495c-bedc-54e0201f3049","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(5)"}539=== RUN TestService_AuthMiddleware540=== PAUSE TestService_AuthMiddleware541=== RUN TestService_AuthMiddleware_MTLSProxyHeader542=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader543=== RUN TestService_AuthMiddleware_MTLSBoundSubjects544=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects545=== RUN TestService_ReadAuthMiddleware546=== PAUSE TestService_ReadAuthMiddleware547=== RUN TestService_AuthMiddleware_OIDC548=== PAUSE TestService_AuthMiddleware_OIDC549=== RUN TestService_RequireScope_OIDC550=== PAUSE TestService_RequireScope_OIDC551=== RUN TestService_ReadScope_PublicByDefault552=== PAUSE TestService_ReadScope_PublicByDefault553=== RUN TestCacheConfigHandler554=== PAUSE TestCacheConfigHandler555=== RUN TestCacheStatsHandler556=== PAUSE TestCacheStatsHandler557=== RUN TestClientCADerivations558=== PAUSE TestClientCADerivations559=== RUN TestClientErrorHandling560=== PAUSE TestClientErrorHandling561=== RUN TestClientIntegration562=== PAUSE TestClientIntegration563=== RUN TestClientMultipleUploads564=== PAUSE TestClientMultipleUploads565=== RUN TestClientWithDependencies566=== PAUSE TestClientWithDependencies567=== RUN TestClientSharedPathCommittedMidPush568=== PAUSE TestClientSharedPathCommittedMidPush569=== RUN TestPinProtectsFromGC570=== PAUSE TestPinProtectsFromGC571=== RUN TestClientPushesUseOnePush572=== PAUSE TestClientPushesUseOnePush573=== RUN TestClientFallsBackToClosures574=== PAUSE TestClientFallsBackToClosures575=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock576=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock577=== RUN TestResolveDBConnectionString578=== PAUSE TestResolveDBConnectionString579=== RUN TestConnectWaitsForAPeerMigration580=== PAUSE TestConnectWaitsForAPeerMigration581=== RUN TestConnectSerialisesConcurrentMigrations582=== PAUSE TestConnectSerialisesConcurrentMigrations583=== RUN TestLeadElectsOneAndHandsOver584=== PAUSE TestLeadElectsOneAndHandsOver585=== RUN TestLeadIncumbentWinsAfterRestart5862026/10/05 12:09:15 INFO lead: acquired remote=192.0.2.1:12345872026/10/05 12:09:15 INFO lead: released remote=192.0.2.1:12345882026/10/05 12:09:16 INFO lead: acquired remote=192.0.2.1:12345892026/10/05 12:09:17 INFO lead: released remote=192.0.2.1:1234590--- PASS: TestLeadIncumbentWinsAfterRestart (1.90s)591=== RUN TestLeadIncumbentAnnouncesAtOnce592=== PAUSE TestLeadIncumbentAnnouncesAtOnce593=== RUN TestLeadEndsOnShutdown594=== PAUSE TestLeadEndsOnShutdown595=== RUN TestLeadEndsWhenItsConnectionHangs5962026/10/05 12:09:17 INFO lead: acquired remote=192.0.2.1:12345972026-10-05 12:09:18.481 UTC [97115] FATAL: terminating connection due to administrator command5982026/10/05 12:09:18 INFO lead: acquired remote=192.0.2.1:12345992026/10/05 12:09:19 WARN lead: lock connection lost error="timeout: context deadline exceeded"6002026/10/05 12:09:19 INFO lead: released remote=192.0.2.1:12346012026/10/05 12:09:19 INFO lead: released remote=192.0.2.1:1234602--- PASS: TestLeadEndsWhenItsConnectionHangs (2.78s)603=== RUN TestGCAdvisoryLockBlocksConcurrentRun604=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun605=== RUN TestGCBugBareHashReferences606=== PAUSE TestGCBugBareHashReferences607=== RUN TestGCMetrics608=== PAUSE TestGCMetrics609=== RUN TestPushDedupSurvivesConcurrentGC610=== PAUSE TestPushDedupSurvivesConcurrentGC611=== RUN TestDeduplicatedObjectsRecordedAsPending612=== PAUSE TestDeduplicatedObjectsRecordedAsPending613=== RUN TestGCSweepSkipsPendingObjects614=== PAUSE TestGCSweepSkipsPendingObjects615=== RUN TestTombstonedObjectOfferedWithoutWaiting616=== PAUSE TestTombstonedObjectOfferedWithoutWaiting617=== RUN TestGCSweepDeliversEachKeyOnce618=== PAUSE TestGCSweepDeliversEachKeyOnce619=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection620=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection621=== RUN TestForceGCDuringPushOffersSweptObject622=== PAUSE TestForceGCDuringPushOffersSweptObject623=== RUN TestFailedS3DeleteKeepsTombstone624=== PAUSE TestFailedS3DeleteKeepsTombstone625=== RUN TestSweepSkipsRowsLockedByPush626=== PAUSE TestSweepSkipsRowsLockedByPush627=== RUN TestRegisterCompletedObjectNeedsPendingRow628=== PAUSE TestRegisterCompletedObjectNeedsPendingRow629=== RUN TestGetExistingObjectsLocksRows630=== PAUSE TestGetExistingObjectsLocksRows631=== RUN TestSweepRechecksPendingAfterLocking632=== PAUSE TestSweepRechecksPendingAfterLocking633=== RUN TestPushWaitsForSweepHoldingRow634=== PAUSE TestPushWaitsForSweepHoldingRow635=== RUN TestCommitRacingPendingCleanupKeepsObjects636=== PAUSE TestCommitRacingPendingCleanupKeepsObjects637=== RUN TestGCEndsOnShutdown638=== PAUSE TestGCEndsOnShutdown639=== RUN TestGCTaskStore_StartNew640=== PAUSE TestGCTaskStore_StartNew641=== RUN TestGCTaskStore_DeduplicateSameParams642=== PAUSE TestGCTaskStore_DeduplicateSameParams643=== RUN TestGCTaskStore_ConflictDifferentParams644=== PAUSE TestGCTaskStore_ConflictDifferentParams645=== RUN TestGCTaskStore_GetEmpty646=== PAUSE TestGCTaskStore_GetEmpty647=== RUN TestGCTaskStore_GetReturnsLatest648=== PAUSE TestGCTaskStore_GetReturnsLatest649=== RUN TestGCTaskStore_CompletedAllowsNewTask650=== PAUSE TestGCTaskStore_CompletedAllowsNewTask651=== RUN TestGCTaskStore_PhaseUpdates652=== PAUSE TestGCTaskStore_PhaseUpdates653=== RUN TestGCTaskStore_Fail654=== PAUSE TestGCTaskStore_Fail655=== RUN TestGracefulShutdownDrainsInflight656=== PAUSE TestGracefulShutdownDrainsInflight657=== RUN TestService_healthCheckHandler658=== PAUSE TestService_healthCheckHandler659=== RUN TestService_readinessHandler660=== PAUSE TestService_readinessHandler661=== RUN TestGenerateLandingPage662=== PAUSE TestGenerateLandingPage663=== RUN TestCacheConfigHandlerMaxNarSize664=== PAUSE TestCacheConfigHandlerMaxNarSize665=== RUN TestCreatePendingClosureRejectsOversizedNAR666=== PAUSE TestCreatePendingClosureRejectsOversizedNAR667=== RUN TestNARDeduplicationMetadataUploadBug668=== PAUSE TestNARDeduplicationMetadataUploadBug669=== RUN TestMetricsInventory670=== PAUSE TestMetricsInventory671=== RUN TestService_NativeMTLS672=== PAUSE TestService_NativeMTLS673=== RUN TestServerTLSConfig674=== PAUSE TestServerTLSConfig675=== RUN TestMultipartCleanup676=== PAUSE TestMultipartCleanup677=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded678=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded679=== RUN TestPendingCleanupUsesOneCutoff680=== PAUSE TestPendingCleanupUsesOneCutoff681=== RUN TestPendingClosureFailureTracksEveryUpload682=== PAUSE TestPendingClosureFailureTracksEveryUpload683=== RUN TestPendingClosureFailureAbortsItsUploads684=== PAUSE TestPendingClosureFailureAbortsItsUploads685=== RUN TestObjectStatsTrigger686=== PAUSE TestObjectStatsTrigger687=== RUN TestReconnectLeavesObjectsUnlocked688=== PAUSE TestReconnectLeavesObjectsUnlocked689=== RUN TestOrphanedObjectsGC690=== PAUSE TestOrphanedObjectsGC691=== RUN TestOrphanedObjectsGCStressTest692=== PAUSE TestOrphanedObjectsGCStressTest693=== RUN TestCreatePin_ReservedPins694=== PAUSE TestCreatePin_ReservedPins695=== RUN TestConcurrentPinUpdatesAgree696=== PAUSE TestConcurrentPinUpdatesAgree697=== RUN TestCreatePinRejectsBadInput698=== PAUSE TestCreatePinRejectsBadInput699=== RUN TestDeletePinKeepsRowWhenS3Fails700=== PAUSE TestDeletePinKeepsRowWhenS3Fails701=== RUN TestPresentReportsOnlyClosureRoots702=== PAUSE TestPresentReportsOnlyClosureRoots703=== RUN TestPresentNotReportedWhileGCDeletesClosure704=== PAUSE TestPresentNotReportedWhileGCDeletesClosure705=== RUN TestParseSingleRange706=== PAUSE TestParseSingleRange707=== RUN TestProxyHeadersOnlyTrustedOnSocket708=== PAUSE TestProxyHeadersOnlyTrustedOnSocket709=== RUN TestIsValidCachePath710=== PAUSE TestIsValidCachePath711=== RUN TestReadProxyNarinfo712=== PAUSE TestReadProxyNarinfo713=== RUN TestReadProxyNarinfoAlreadyDecompressed714=== PAUSE TestReadProxyNarinfoAlreadyDecompressed715=== RUN TestReadProxyNarStreaming716=== PAUSE TestReadProxyNarStreaming717=== RUN TestReadProxy404718=== PAUSE TestReadProxy404719=== RUN TestReadProxyInvalidPath720=== PAUSE TestReadProxyInvalidPath721=== RUN TestReadProxyHead722=== PAUSE TestReadProxyHead723=== RUN TestReadProxyOutlastsServerWriteTimeout724=== PAUSE TestReadProxyOutlastsServerWriteTimeout725=== RUN TestReadProxyConditionalGet726=== PAUSE TestReadProxyConditionalGet727=== RUN TestReadProxyRootRedirectsToIndexHTML728=== PAUSE TestReadProxyRootRedirectsToIndexHTML729=== RUN TestReadProxyDisabled730=== PAUSE TestReadProxyDisabled731=== RUN TestReadRedirectNar732=== PAUSE TestReadRedirectNar733=== RUN TestReadRedirectKeepsNarinfoProxied734=== PAUSE TestReadRedirectKeepsNarinfoProxied735=== RUN TestReadProxyRangeRequest736=== PAUSE TestReadProxyRangeRequest737=== RUN TestReadRedirectUsesPublicS3URL738=== PAUSE TestReadRedirectUsesPublicS3URL739=== RUN TestPush_OverlappingRootsStoreOneRowPerKey740=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey741=== RUN TestPush_CompleteCommitsEveryRoot742=== PAUSE TestPush_CompleteCommitsEveryRoot743=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit744=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit745=== RUN TestPush_RejectsBadRequests746=== PAUSE TestPush_RejectsBadRequests747=== RUN TestPush_SignsNarinfosOfItsPendingObjects748=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects749=== RUN TestRedundantMultipartUpload750=== PAUSE TestRedundantMultipartUpload751=== RUN TestCompleteMultipartUpload_ErrorButObjectExists752=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists753=== RUN TestCompletedNarNotReofferedAcrossClosures754=== PAUSE TestCompletedNarNotReofferedAcrossClosures755=== RUN TestPresignedUploadRegisteredBeforeCommit756=== PAUSE TestPresignedUploadRegisteredBeforeCommit757=== RUN TestService_Rustfstest758=== PAUSE TestService_Rustfstest759=== RUN TestParseSize760=== PAUSE TestParseSize761=== RUN TestSkippedUploadsHandler762=== PAUSE TestSkippedUploadsHandler763=== RUN TestSystemdListenerNotActivated764--- PASS: TestSystemdListenerNotActivated (0.00s)765=== RUN TestWatchdogBeatsWhenHealthy766--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)767=== RUN TestWatchdogSkipsWhenUnhealthy7682026/10/05 12:09:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/10/05 12:09:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/10/05 12:09:19 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/10/05 12:09:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/10/05 12:09:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/10/05 12:09:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/10/05 12:09:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7752026/10/05 12:09:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7762026/10/05 12:09:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7772026/10/05 12:09:20 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"778--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)779=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle780=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle781=== RUN TestProxyWriteTimeout782=== PAUSE TestProxyWriteTimeout783=== RUN TestPendingClosureWriteTimeout784=== PAUSE TestPendingClosureWriteTimeout785=== RUN TestIsValidUploadKey786=== PAUSE TestIsValidUploadKey787=== RUN TestUploadHandlersRejectInvalidKeys788=== PAUSE TestUploadHandlersRejectInvalidKeys789=== RUN TestUploadHandlersRejectOversizedBody790=== PAUSE TestUploadHandlersRejectOversizedBody791=== RUN TestService_cleanupPendingClosuresHandler792=== PAUSE TestService_cleanupPendingClosuresHandler793=== RUN TestService_createPendingClosureHandler794=== PAUSE TestService_createPendingClosureHandler795=== RUN TestService_verifyS3Integrity796=== PAUSE TestService_verifyS3Integrity797=== RUN TestCompleteMultipartUnregistered798=== PAUSE TestCompleteMultipartUnregistered799=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT800=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT801=== CONT TestIsValidCachePath802=== CONT TestCreatePinRejectsBadInput803=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit804=== RUN TestIsValidCachePath/narinfo805=== PAUSE TestIsValidCachePath/narinfo806=== CONT TestService_AuthMiddleware_MTLSProxyHeader807=== CONT TestResolveDBConnectionString808=== CONT TestRegisterCompletedObjectNeedsPendingRow809=== CONT TestPresentNotReportedWhileGCDeletesClosure810=== CONT TestPresentReportsOnlyClosureRoots811=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock812=== CONT TestSweepSkipsRowsLockedByPush813=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars814=== RUN TestResolveDBConnectionString/flag_wins815=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars816=== PAUSE TestResolveDBConnectionString/flag_wins817=== RUN TestResolveDBConnectionString/file_when_flag_empty818=== RUN TestIsValidCachePath/nar_zst819=== PAUSE TestResolveDBConnectionString/file_when_flag_empty820=== PAUSE TestIsValidCachePath/nar_zst821=== RUN TestResolveDBConnectionString/missing_file_is_an_error822=== RUN TestIsValidCachePath/nar_xz823=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error824=== PAUSE TestIsValidCachePath/nar_xz825=== RUN TestIsValidCachePath/nar_bz2826=== PAUSE TestIsValidCachePath/nar_bz2827=== RUN TestResolveDBConnectionString/PGHOST_allows_empty828=== RUN TestIsValidCachePath/nar_uncompressed829=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty830=== PAUSE TestIsValidCachePath/nar_uncompressed831=== RUN TestResolveDBConnectionString/nothing_configured832=== RUN TestIsValidCachePath/ls833=== PAUSE TestResolveDBConnectionString/nothing_configured834=== PAUSE TestIsValidCachePath/ls835=== RUN TestIsValidCachePath/log836=== PAUSE TestIsValidCachePath/log837=== CONT TestPushWaitsForSweepHoldingRow838=== RUN TestIsValidCachePath/realisation839=== PAUSE TestIsValidCachePath/realisation840=== RUN TestIsValidCachePath/nix-cache-info841=== PAUSE TestIsValidCachePath/nix-cache-info842=== RUN TestIsValidCachePath/index.html843=== PAUSE TestIsValidCachePath/index.html844=== RUN TestIsValidCachePath/traversal_parent845=== PAUSE TestIsValidCachePath/traversal_parent846=== RUN TestIsValidCachePath/traversal_in_middle847=== PAUSE TestIsValidCachePath/traversal_in_middle848=== RUN TestIsValidCachePath/invalid_char_e849=== PAUSE TestIsValidCachePath/invalid_char_e850=== RUN TestIsValidCachePath/invalid_char_u851=== PAUSE TestIsValidCachePath/invalid_char_u852=== RUN TestIsValidCachePath/random_path853=== PAUSE TestIsValidCachePath/random_path854=== RUN TestIsValidCachePath/empty855=== PAUSE TestIsValidCachePath/empty856=== RUN TestIsValidCachePath/leading_slash857=== PAUSE TestIsValidCachePath/leading_slash858=== RUN TestIsValidCachePath/wrong_extension859=== PAUSE TestIsValidCachePath/wrong_extension860=== RUN TestIsValidCachePath/short_hash861=== PAUSE TestIsValidCachePath/short_hash862=== CONT TestForceGCDuringPushOffersSweptObject863=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows864=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows865=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check866=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check867=== CONT TestClientPushesUseOnePush868--- PASS: TestPresentReportsOnlyClosureRoots (0.44s)869=== CONT TestFailedS3DeleteKeepsTombstone870--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.73s)871=== CONT TestGCSweepDeliversEachKeyOnce8722026/10/05 12:09:21 INFO Received push request method=POST path=/api/pushes8732026/10/05 12:09:21 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)8742026/10/05 12:09:21 INFO Uploading ckbsnhmp2wrqkrxv52mf46jwr0l9pd5p-a (248B)8752026/10/05 12:09:21 INFO Uploading z367yb7shi9qrcn4mnqn1mz6fq6jllib-shared-dep (136B)8762026/10/05 12:09:21 WARN Failed to register uploaded object key=580i3w7hxnnslvl3h6b4glvfdaw6bk9a.ls error="server returned 404: 404 page not found\n"8772026/10/05 12:09:21 WARN Failed to register uploaded object key=z367yb7shi9qrcn4mnqn1mz6fq6jllib.ls error="server returned 404: 404 page not found\n"8782026/10/05 12:09:21 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"8792026/10/05 12:09:21 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8802026/10/05 12:09:21 WARN Failed to register uploaded object key=nar/1f2yq611iabfqbm18cc59fs9j3wrrnikjg72cgjzljah1mzrvkbm.nar.zst error="server returned 404: 404 page not found\n"8812026/10/05 12:09:21 WARN Failed to register uploaded object key=ckbsnhmp2wrqkrxv52mf46jwr0l9pd5p.ls error="server returned 404: 404 page not found\n"8822026/10/05 12:09:21 INFO Signed narinfos id=1 count=38832026/10/05 12:09:21 INFO Uploading 3 narinfos8842026/10/05 12:09:21 INFO Received complete push request method=POST path=/api/pushes/1/complete8852026/10/05 12:09:21 WARN Failed to register uploaded object key=z367yb7shi9qrcn4mnqn1mz6fq6jllib.narinfo error="server returned 404: 404 page not found\n"8862026/10/05 12:09:21 WARN Failed to register uploaded object key=580i3w7hxnnslvl3h6b4glvfdaw6bk9a.narinfo error="server returned 404: 404 page not found\n"8872026/10/05 12:09:21 WARN Failed to register uploaded object key=ckbsnhmp2wrqkrxv52mf46jwr0l9pd5p.narinfo error="server returned 404: 404 page not found\n"8882026/10/05 12:09:21 INFO Upload complete. (88ms)889=== NAME TestClientPushesUseOnePush890 client_pushes_test.go:97: Retrieved narinfo from S3:891 StorePath: /nix/var/nix/builds/nix-97026-1645623550/TestClientPushesUseOnePush4079838540/001/store/z367yb7shi9qrcn4mnqn1mz6fq6jllib-shared-dep892 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst893 Compression: zstd894 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82895 NarSize: 136896 References: 897 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n898 client_pushes_test.go:97: Retrieved narinfo from S3:899 StorePath: /nix/var/nix/builds/nix-97026-1645623550/TestClientPushesUseOnePush4079838540/001/store/ckbsnhmp2wrqkrxv52mf46jwr0l9pd5p-a900 URL: nar/1f2yq611iabfqbm18cc59fs9j3wrrnikjg72cgjzljah1mzrvkbm.nar.zst901 Compression: zstd902 NarHash: sha256:1f2yq611iabfqbm18cc59fs9j3wrrnikjg72cgjzljah1mzrvkbm903 NarSize: 248904 References: /nix/var/nix/builds/nix-97026-1645623550/TestClientPushesUseOnePush4079838540/001/store/z367yb7shi9qrcn4mnqn1mz6fq6jllib-shared-dep905 CA: text:sha256:083amb574120pz9kjcrwv5qqw1bg6bahcxvg036rmjkwaxvm6qaa906 client_pushes_test.go:97: Retrieved narinfo from S3:907 StorePath: /nix/var/nix/builds/nix-97026-1645623550/TestClientPushesUseOnePush4079838540/001/store/580i3w7hxnnslvl3h6b4glvfdaw6bk9a-b908 URL: nar/1f2yq611iabfqbm18cc59fs9j3wrrnikjg72cgjzljah1mzrvkbm.nar.zst909 Compression: zstd910 NarHash: sha256:1f2yq611iabfqbm18cc59fs9j3wrrnikjg72cgjzljah1mzrvkbm911 NarSize: 248912 References: /nix/var/nix/builds/nix-97026-1645623550/TestClientPushesUseOnePush4079838540/001/store/z367yb7shi9qrcn4mnqn1mz6fq6jllib-shared-dep913 CA: text:sha256:083amb574120pz9kjcrwv5qqw1bg6bahcxvg036rmjkwaxvm6qaa914--- PASS: TestClientPushesUseOnePush (1.01s)915=== CONT TestTombstonedObjectOfferedWithoutWaiting9162026/10/05 12:09:21 INFO Received create pin request method=POST path=/api/pins/deploy9172026/10/05 12:09:21 INFO Received create pin request method=POST path=/api/pins/deploy9182026/10/05 12:09:21 INFO Received create pin request method=POST path=/api/pins/deploy9192026/10/05 12:09:21 INFO Received create pin request method=POST path=/api/pins/deploy9202026/10/05 12:09:21 INFO Received create pin request method=POST path=/api/pins/deploy9212026/10/05 12:09:21 INFO Received create pin request method=POST path=/api/pins/deploy9222026/10/05 12:09:21 INFO Received create pin request method=POST path=/api/pins/deploy9232026/10/05 12:09:21 INFO Received create pin request method=POST path=/api/pins/deploy9242026/10/05 12:09:21 INFO Received create pin request method=POST path=/api/pins/deploy925--- PASS: TestRegisterCompletedObjectNeedsPendingRow (1.36s)926=== CONT TestGCSweepSkipsPendingObjects927--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.44s)928=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection9292026/10/05 12:09:21 INFO Received create pin request method=POST path=/api/pins/deploy9302026/10/05 12:09:21 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo931--- PASS: TestCreatePinRejectsBadInput (1.53s)932=== CONT TestPushDedupSurvivesConcurrentGC9332026/10/05 12:09:21 INFO Aborted multipart uploads count=0 kept=09342026/10/05 12:09:21 WARN Force mode enabled - objects will be deleted immediately without grace period9352026/10/05 12:09:21 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=09362026/10/05 12:09:21 INFO Vacuumed table table=pending_closures9372026/10/05 12:09:21 INFO Vacuumed table table=pending_objects9382026/10/05 12:09:21 INFO Vacuumed table table=multipart_uploads9392026/10/05 12:09:21 INFO Vacuumed table table=closures9402026/10/05 12:09:21 INFO Vacuumed table table=objects9412026/10/05 12:09:21 INFO Aborted multipart uploads count=0 kept=09422026/10/05 12:09:21 WARN Force mode enabled - objects will be deleted immediately without grace period9432026/10/05 12:09:21 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=09442026/10/05 12:09:21 INFO Vacuumed table table=pending_closures9452026/10/05 12:09:21 INFO Vacuumed table table=pending_objects9462026/10/05 12:09:21 INFO Vacuumed table table=multipart_uploads9472026/10/05 12:09:21 INFO Vacuumed table table=closures9482026/10/05 12:09:21 INFO Vacuumed table table=objects949--- PASS: TestSweepSkipsRowsLockedByPush (1.58s)950=== CONT TestDeduplicatedObjectsRecordedAsPending9512026/10/05 12:09:21 INFO Received push request method=POST path=/api/pushes9522026/10/05 12:09:22 INFO Received uploads request method=POST path=/api/pending_closures953--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (2.08s)954=== CONT TestPinProtectsFromGC9552026/10/05 12:09:22 INFO Received uploads request method=POST path=/api/pending_closures9562026/10/05 12:09:22 INFO Aborted multipart uploads count=0 kept=09572026/10/05 12:09:22 WARN Force mode enabled - objects will be deleted immediately without grace period9582026/10/05 12:09:22 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."9592026/10/05 12:09:22 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."960--- PASS: TestFailedS3DeleteKeepsTombstone (1.85s)961=== CONT TestGCMetrics962--- PASS: TestPushWaitsForSweepHoldingRow (2.44s)963=== CONT TestGCAdvisoryLockBlocksConcurrentRun9642026/10/05 12:09:22 INFO Aborted multipart uploads count=0 kept=09652026/10/05 12:09:22 WARN Force mode enabled - objects will be deleted immediately without grace period9662026/10/05 12:09:22 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=09672026/10/05 12:09:22 INFO Vacuumed table table=pending_closures9682026/10/05 12:09:22 INFO Vacuumed table table=pending_objects9692026/10/05 12:09:22 INFO Vacuumed table table=multipart_uploads9702026/10/05 12:09:22 INFO Vacuumed table table=closures9712026/10/05 12:09:22 INFO Vacuumed table table=objects972--- PASS: TestGCSweepDeliversEachKeyOnce (1.90s)973=== CONT TestClientSharedPathCommittedMidPush9742026/10/05 12:09:22 INFO Received uploads request method=POST path=/api/pending_closures975--- PASS: TestTombstonedObjectOfferedWithoutWaiting (1.73s)976=== CONT TestLeadEndsOnShutdown9772026/10/05 12:09:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9782026/10/05 12:09:23 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=YjFlODMyMTktMmE1ZS00NWRkLTliZjgtNWFlYTIzYzNmYTViLjFhY2RmMTU3LTZjNzMtNGQxZi1iOWQzLWJmYjc4YzNmNGQ0YngxNzkxMjAyMTYxODQ5MTIwMDAw parts=109792026/10/05 12:09:23 INFO Received uploads request method=POST path=/api/pending_closures9802026/10/05 12:09:23 INFO Aborted multipart uploads count=0 kept=09812026/10/05 12:09:23 WARN Force mode enabled - objects will be deleted immediately without grace period9822026/10/05 12:09:23 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=09832026/10/05 12:09:23 INFO Vacuumed table table=pending_closures9842026/10/05 12:09:23 INFO Vacuumed table table=pending_objects9852026/10/05 12:09:23 INFO Vacuumed table table=multipart_uploads9862026/10/05 12:09:23 INFO Vacuumed table table=closures9872026/10/05 12:09:23 INFO Vacuumed table table=objects988=== CONT TestCacheConfigHandlerMaxNarSize989--- PASS: TestGCSweepSkipsPendingObjects (2.00s)990--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)991=== CONT TestConcurrentPinUpdatesAgree9922026/10/05 12:09:23 INFO Received uploads request method=POST path=/api/pending_closures9932026/10/05 12:09:23 INFO Aborted multipart uploads count=0 kept=09942026/10/05 12:09:23 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09952026/10/05 12:09:23 INFO Vacuumed table table=pending_closures9962026/10/05 12:09:23 INFO Received uploads request method=POST path=/api/pending_closures9972026/10/05 12:09:23 INFO Vacuumed table table=pending_objects9982026/10/05 12:09:23 INFO Vacuumed table table=multipart_uploads9992026/10/05 12:09:23 INFO Vacuumed table table=closures10002026/10/05 12:09:23 INFO Vacuumed table table=objects10012026/10/05 12:09:23 INFO Aborted multipart uploads count=0 kept=010022026/10/05 12:09:23 WARN Force mode enabled - objects will be deleted immediately without grace period10032026/10/05 12:09:23 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=010042026/10/05 12:09:23 INFO Vacuumed table table=pending_closures10052026/10/05 12:09:23 INFO Vacuumed table table=pending_objects10062026/10/05 12:09:23 INFO Vacuumed table table=multipart_uploads10072026/10/05 12:09:23 INFO Vacuumed table table=closures10082026/10/05 12:09:23 INFO Vacuumed table table=objects1009--- PASS: TestPushDedupSurvivesConcurrentGC (2.36s)1010=== CONT TestLeadIncumbentAnnouncesAtOnce1011--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (2.55s)1012=== CONT TestClientWithDependencies10132026/10/05 12:09:24 INFO Received uploads request method=POST path=/api/pending_closures1014--- PASS: TestDeduplicatedObjectsRecordedAsPending (2.46s)1015=== CONT TestOrphanedObjectsGC10162026/10/05 12:09:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10172026/10/05 12:09:24 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=YjFlODMyMTktMmE1ZS00NWRkLTliZjgtNWFlYTIzYzNmYTViLmE5ZWVhMjQxLTY0M2UtNDRhYS1iZjczLWYyMTVhZGNhMWY4M3gxNzkxMjAyMTYxODQ4NzEwMDAw parts=1010182026/10/05 12:09:24 INFO Received complete push request method=POST path=/api/pushes/1/complete10192026/10/05 12:09:24 INFO Received push request method=POST path=/api/pushes10202026/10/05 12:09:24 INFO Aborted multipart uploads count=0 kept=010212026/10/05 12:09:24 WARN Force mode enabled - objects will be deleted immediately without grace period10222026/10/05 12:09:24 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=010232026/10/05 12:09:24 INFO Vacuumed table table=pending_closures10242026/10/05 12:09:24 INFO Vacuumed table table=pending_objects10252026/10/05 12:09:24 INFO Vacuumed table table=multipart_uploads10262026/10/05 12:09:24 INFO Vacuumed table table=closures10272026/10/05 12:09:24 INFO Vacuumed table table=objects10282026/10/05 12:09:24 INFO Aborted multipart uploads count=0 kept=010292026/10/05 12:09:24 WARN Force mode enabled - objects will be deleted immediately without grace period10302026/10/05 12:09:24 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=010312026/10/05 12:09:24 INFO Vacuumed table table=pending_closures10322026/10/05 12:09:24 INFO Vacuumed table table=pending_objects10332026/10/05 12:09:24 INFO Vacuumed table table=multipart_uploads10342026/10/05 12:09:24 INFO Vacuumed table table=closures10352026/10/05 12:09:24 INFO Vacuumed table table=objects1036--- PASS: TestGCMetrics (2.32s)1037=== CONT TestLeadElectsOneAndHandsOver1038=== NAME TestPinProtectsFromGC1039 client_integration_test.go:867: Pinned store path: /nix/var/nix/builds/nix-97026-1645623550/TestPinProtectsFromGC493992681/001/store/cmk6726yqqrz33lk2s0qdy0h922dci7z-pinned-file.txt1040 client_integration_test.go:868: Unpinned store path: /nix/var/nix/builds/nix-97026-1645623550/TestPinProtectsFromGC493992681/001/store/76zlyjv8dk1j08c3na9xf1m56dwdcrpd-unpinned-file.txt10412026/10/05 12:09:24 INFO Received push request method=POST path=/api/pushes10422026/10/05 12:09:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10432026/10/05 12:09:24 INFO Uploading cmk6726yqqrz33lk2s0qdy0h922dci7z-pinned-file.txt (128B)10442026/10/05 12:09:24 WARN Failed to register uploaded object key=cmk6726yqqrz33lk2s0qdy0h922dci7z.ls error="server returned 404: 404 page not found\n"10452026/10/05 12:09:24 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10462026/10/05 12:09:24 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"10472026/10/05 12:09:24 INFO Signed narinfos id=1 count=110482026/10/05 12:09:24 INFO Uploading 1 narinfos10492026/10/05 12:09:24 INFO Received complete push request method=POST path=/api/pushes/1/complete10502026/10/05 12:09:24 WARN Failed to register uploaded object key=cmk6726yqqrz33lk2s0qdy0h922dci7z.narinfo error="server returned 404: 404 page not found\n"10512026/10/05 12:09:25 INFO Upload complete. (191ms)10522026/10/05 12:09:25 INFO Received push request method=POST path=/api/pushes10532026/10/05 12:09:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10542026/10/05 12:09:25 INFO Uploading 76zlyjv8dk1j08c3na9xf1m56dwdcrpd-unpinned-file.txt (128B)10552026/10/05 12:09:25 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"10562026/10/05 12:09:25 WARN Failed to register uploaded object key=76zlyjv8dk1j08c3na9xf1m56dwdcrpd.ls error="server returned 404: 404 page not found\n"10572026/10/05 12:09:25 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign10582026/10/05 12:09:25 INFO Signed narinfos id=2 count=110592026/10/05 12:09:25 INFO Uploading 1 narinfos10602026/10/05 12:09:25 INFO Received complete push request method=POST path=/api/pushes/2/complete10612026/10/05 12:09:25 WARN Failed to register uploaded object key=76zlyjv8dk1j08c3na9xf1m56dwdcrpd.narinfo error="server returned 404: 404 page not found\n"10622026/10/05 12:09:25 INFO Upload complete. (99ms)10632026/10/05 12:09:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures10642026/10/05 12:09:25 INFO Garbage collection started10652026/10/05 12:09:25 INFO Aborted multipart uploads count=0 kept=010662026/10/05 12:09:25 WARN Force mode enabled - objects will be deleted immediately without grace period10672026/10/05 12:09:25 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=010682026/10/05 12:09:25 INFO Vacuumed table table=pending_closures10692026/10/05 12:09:25 INFO Vacuumed table table=pending_objects10702026/10/05 12:09:25 INFO Vacuumed table table=multipart_uploads10712026/10/05 12:09:25 INFO Vacuumed table table=closures10722026/10/05 12:09:25 INFO Vacuumed table table=objects10732026/10/05 12:09:25 INFO lead: acquired remote=192.0.2.1:123410742026/10/05 12:09:25 INFO Received push request method=POST path=/api/pushes10752026/10/05 12:09:25 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)10762026/10/05 12:09:25 INFO Uploading mnp1cmx1p1kyf86z8bh6q5myczdk6h7s-top (256B)10772026/10/05 12:09:25 INFO Uploading fx21cyzi7pyj1rr0caixv551csz1z5r2-shared-dep (136B)10782026/10/05 12:09:25 WARN Failed to register uploaded object key=nar/1ps87v3582rhxhf0rwmpqxkag7076iw5qy0mm15a9jk60jyirm8i.nar.zst error="server returned 404: 404 page not found\n"10792026/10/05 12:09:25 WARN Failed to register uploaded object key=fx21cyzi7pyj1rr0caixv551csz1z5r2.ls error="server returned 404: 404 page not found\n"10802026/10/05 12:09:25 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10812026/10/05 12:09:25 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10822026/10/05 12:09:25 WARN Failed to register uploaded object key=mnp1cmx1p1kyf86z8bh6q5myczdk6h7s.ls error="server returned 404: 404 page not found\n"10832026/10/05 12:09:25 INFO Signed narinfos id=1 count=210842026/10/05 12:09:25 INFO Uploading 2 narinfos10852026/10/05 12:09:25 WARN Failed to register uploaded object key=mnp1cmx1p1kyf86z8bh6q5myczdk6h7s.narinfo error="server returned 404: 404 page not found\n"10862026/10/05 12:09:25 INFO Received complete push request method=POST path=/api/pushes/1/complete10872026/10/05 12:09:25 WARN Failed to register uploaded object key=fx21cyzi7pyj1rr0caixv551csz1z5r2.narinfo error="server returned 404: 404 page not found\n"10882026/10/05 12:09:25 INFO Upload complete. (140ms)1089=== NAME TestClientSharedPathCommittedMidPush1090 client_integration_test.go:816: Retrieved narinfo from S3:1091 StorePath: /nix/var/nix/builds/nix-97026-1645623550/TestClientSharedPathCommittedMidPush2740760564/001/store/fx21cyzi7pyj1rr0caixv551csz1z5r2-shared-dep1092 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1093 Compression: zstd1094 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821095 NarSize: 1361096 References: 1097 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1098 client_integration_test.go:816: Retrieved narinfo from S3:1099 StorePath: /nix/var/nix/builds/nix-97026-1645623550/TestClientSharedPathCommittedMidPush2740760564/001/store/mnp1cmx1p1kyf86z8bh6q5myczdk6h7s-top1100 URL: nar/1ps87v3582rhxhf0rwmpqxkag7076iw5qy0mm15a9jk60jyirm8i.nar.zst1101 Compression: zstd1102 NarHash: sha256:1ps87v3582rhxhf0rwmpqxkag7076iw5qy0mm15a9jk60jyirm8i1103 NarSize: 2561104 References: /nix/var/nix/builds/nix-97026-1645623550/TestClientSharedPathCommittedMidPush2740760564/001/store/fx21cyzi7pyj1rr0caixv551csz1z5r2-shared-dep1105 CA: text:sha256:0ryypy7vj8xqbwbqkr8ckb1kk6bhgdny85vfmv095666mfh0lbh311062026/10/05 12:09:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11072026/10/05 12:09:25 INFO Received create pin request method=POST path=/api/pins/app11082026/10/05 12:09:25 INFO Received create pin request method=POST path=/api/pins/app11092026/10/05 12:09:25 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=YjFlODMyMTktMmE1ZS00NWRkLTliZjgtNWFlYTIzYzNmYTViLmZhYjA3MTg3LWNiYjktNDcwOC05YzMzLTg3NGEyY2EzYmM2Y3gxNzkxMjAyMTY0NDIxMzc1MDAw parts=1011102026/10/05 12:09:25 INFO Received complete push request method=POST path=/api/pushes/2/complete1111--- PASS: TestClientSharedPathCommittedMidPush (3.08s)1112=== CONT TestClientMultipleUploads1113--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (5.73s)1114=== CONT TestGCBugBareHashReferences11152026/10/05 12:09:26 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo11162026/10/05 12:09:26 INFO lead: acquired remote=192.0.2.1:123411172026/10/05 12:09:26 INFO lead: released remote=192.0.2.1:12341118--- PASS: TestLeadIncumbentAnnouncesAtOnce (2.34s)1119=== CONT TestObjectStatsTrigger11202026/10/05 12:09:26 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo1121--- PASS: TestConcurrentPinUpdatesAgree (2.91s)1122=== CONT TestClientFallsBackToClosures1123=== NAME TestClientWithDependencies1124 client_integration_test.go:735: Built derivation: /nix/var/nix/builds/nix-97026-1645623550/TestClientWithDependencies3063717347/001/store/g9zbsv4mdhar77nn0pi3ja3ywr61a8bc-test-script11252026/10/05 12:09:26 INFO lead: released remote=192.0.2.1:12341126--- PASS: TestLeadEndsOnShutdown (3.70s)1127=== CONT TestPendingCleanupUsesOneCutoff1128=== NAME TestClientWithDependencies1129 client_integration_test.go:737: Found 1 dependencies (including self)11302026/10/05 12:09:26 INFO Received push request method=POST path=/api/pushes11312026/10/05 12:09:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11322026/10/05 12:09:26 INFO Uploading g9zbsv4mdhar77nn0pi3ja3ywr61a8bc-test-script (136B)11332026/10/05 12:09:26 WARN Failed to register uploaded object key=g9zbsv4mdhar77nn0pi3ja3ywr61a8bc.ls error="server returned 404: 404 page not found\n"11342026/10/05 12:09:26 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"11352026/10/05 12:09:26 WARN Failed to register uploaded object key=log/vghn2j62gzifl4bna2hc7bhfxz9kvfmp-test-script.drv error="server returned 404: 404 page not found\n"11362026/10/05 12:09:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11372026/10/05 12:09:26 INFO Signed narinfos id=1 count=111382026/10/05 12:09:26 INFO Uploading 1 narinfos11392026/10/05 12:09:26 WARN Failed to register uploaded object key=g9zbsv4mdhar77nn0pi3ja3ywr61a8bc.narinfo error="server returned 404: 404 page not found\n"11402026/10/05 12:09:26 INFO Received complete push request method=POST path=/api/pushes/1/complete11412026/10/05 12:09:26 INFO Upload complete. (162ms)11422026/10/05 12:09:26 INFO Aborted multipart uploads count=0 kept=011432026/10/05 12:09:26 WARN Force mode enabled - objects will be deleted immediately without grace period11442026/10/05 12:09:26 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=011452026/10/05 12:09:26 INFO lead: acquired remote=192.0.2.1:123411462026/10/05 12:09:26 INFO Vacuumed table table=pending_closures11472026/10/05 12:09:26 INFO Vacuumed table table=pending_objects11482026/10/05 12:09:26 INFO Vacuumed table table=multipart_uploads11492026/10/05 12:09:26 INFO Vacuumed table table=closures11502026/10/05 12:09:26 INFO Vacuumed table table=objects1151 client_integration_test.go:753: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-97026-1645623550/TestClientWithDependencies3063717347/001/store) requires matching store prefix1152--- PASS: TestClientWithDependencies (2.94s)1153=== CONT TestConnectWaitsForAPeerMigration11542026/10/05 12:09:27 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_nixbld1 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1155--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (4.58s)1156=== CONT TestPendingClosureFailureTracksEveryUpload11572026/10/05 12:09:27 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=011582026/10/05 12:09:27 INFO Received create pin request method=POST path=/api/pins/myapp11592026/10/05 12:09:27 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-97026-1645623550/TestPinProtectsFromGC493992681/001/store/cmk6726yqqrz33lk2s0qdy0h922dci7z-pinned-file.txt narinfo_key=cmk6726yqqrz33lk2s0qdy0h922dci7z.narinfo11602026/10/05 12:09:27 INFO Starting cleanup of old closures method=DELETE path=/api/closures11612026/10/05 12:09:27 INFO Garbage collection started11622026/10/05 12:09:27 INFO Aborted multipart uploads count=0 kept=011632026/10/05 12:09:27 WARN Force mode enabled - objects will be deleted immediately without grace period11642026/10/05 12:09:27 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=011652026/10/05 12:09:27 INFO Vacuumed table table=pending_closures11662026/10/05 12:09:27 INFO Vacuumed table table=pending_objects11672026/10/05 12:09:27 INFO Vacuumed table table=multipart_uploads11682026/10/05 12:09:27 INFO Vacuumed table table=closures11692026/10/05 12:09:27 INFO Vacuumed table table=objects1170=== NAME TestOrphanedObjectsGC1171 orphaned_objects_gc_test.go:290: GC Test Summary:1172 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1173 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1174 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1175 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1176 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1177--- PASS: TestOrphanedObjectsGC (3.11s)1178=== CONT TestClientErrorHandling1179=== RUN TestClientErrorHandling/InvalidStorePath1180=== PAUSE TestClientErrorHandling/InvalidStorePath1181=== RUN TestClientErrorHandling/InvalidAuthToken1182=== PAUSE TestClientErrorHandling/InvalidAuthToken1183=== RUN TestClientErrorHandling/ServerNotAvailable1184=== PAUSE TestClientErrorHandling/ServerNotAvailable1185=== CONT TestConnectSerialisesConcurrentMigrations11862026/10/05 12:09:28 INFO lead: released remote=192.0.2.1:12341187=== NAME TestClientMultipleUploads1188 client_integration_test.go:480: Created store path 0: /nix/var/nix/builds/nix-97026-1645623550/TestClientMultipleUploads448314949/001/store/zjyrgq6idrw1ww1vkhxrhdnhhp170zyc-test-file-0.txt11892026/10/05 12:09:28 INFO lead: acquired remote=192.0.2.1:12341190 client_integration_test.go:480: Created store path 1: /nix/var/nix/builds/nix-97026-1645623550/TestClientMultipleUploads448314949/001/store/wm97lj4iqgii94bva2gdf6ix5dysisdb-test-file-1.txt1191 client_integration_test.go:480: Created store path 2: /nix/var/nix/builds/nix-97026-1645623550/TestClientMultipleUploads448314949/001/store/xl85sgy98fr0dinc09ww5g97zlbvbcqw-test-file-2.txt1192--- PASS: TestGCBugBareHashReferences (2.50s)1193=== CONT TestServerTLSConfig1194=== RUN TestServerTLSConfig/no_client_CA1195=== PAUSE TestServerTLSConfig/no_client_CA1196=== RUN TestServerTLSConfig/missing_CA_file1197=== PAUSE TestServerTLSConfig/missing_CA_file1198=== RUN TestServerTLSConfig/not_a_PEM_file1199=== PAUSE TestServerTLSConfig/not_a_PEM_file1200=== CONT TestOrphanedObjectsGCStressTest12012026/10/05 12:09:28 INFO Received push request method=POST path=/api/pushes12022026/10/05 12:09:28 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)12032026/10/05 12:09:28 INFO Uploading xl85sgy98fr0dinc09ww5g97zlbvbcqw-test-file-2.txt (160B)12042026/10/05 12:09:28 INFO Uploading wm97lj4iqgii94bva2gdf6ix5dysisdb-test-file-1.txt (160B)12052026/10/05 12:09:28 INFO Uploading zjyrgq6idrw1ww1vkhxrhdnhhp170zyc-test-file-0.txt (160B)12062026/10/05 12:09:28 WARN Failed to register uploaded object key=xl85sgy98fr0dinc09ww5g97zlbvbcqw.ls error="server returned 404: 404 page not found\n"12072026/10/05 12:09:28 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"12082026/10/05 12:09:28 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"12092026/10/05 12:09:28 WARN Failed to register uploaded object key=wm97lj4iqgii94bva2gdf6ix5dysisdb.ls error="server returned 404: 404 page not found\n"12102026/10/05 12:09:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12112026/10/05 12:09:28 WARN Failed to register uploaded object key=zjyrgq6idrw1ww1vkhxrhdnhhp170zyc.ls error="server returned 404: 404 page not found\n"12122026/10/05 12:09:28 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"12132026/10/05 12:09:28 INFO Signed narinfos id=1 count=312142026/10/05 12:09:28 INFO Uploading 3 narinfos12152026/10/05 12:09:28 WARN Failed to register uploaded object key=xl85sgy98fr0dinc09ww5g97zlbvbcqw.narinfo error="server returned 404: 404 page not found\n"12162026/10/05 12:09:28 WARN Failed to register uploaded object key=zjyrgq6idrw1ww1vkhxrhdnhhp170zyc.narinfo error="server returned 404: 404 page not found\n"12172026/10/05 12:09:28 INFO Received complete push request method=POST path=/api/pushes/1/complete12182026/10/05 12:09:28 WARN Failed to register uploaded object key=wm97lj4iqgii94bva2gdf6ix5dysisdb.narinfo error="server returned 404: 404 page not found\n"12192026/10/05 12:09:28 INFO Upload complete. (181ms)1220=== NAME TestClientMultipleUploads1221 client_integration_test.go:491: Uploaded 3 paths in 214.36875ms1222--- PASS: TestObjectStatsTrigger (2.18s)1223=== CONT TestPendingClosureFailureAbortsItsUploads1224--- PASS: TestClientMultipleUploads (2.75s)1225=== CONT TestMetricsInventory12262026-10-05 12:09:29.008 UTC [97336] ERROR: duplicate key value violates unique constraint "pg_class_relname_nsp_index"12272026-10-05 12:09:29.008 UTC [97336] DETAIL: Key (relname, relnamespace)=(goose_db_version_id_seq, 2200) already exists.12282026-10-05 12:09:29.008 UTC [97336] STATEMENT: CREATE TABLE goose_db_version (1229 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1230 version_id bigint NOT NULL,1231 is_applied boolean NOT NULL,1232 tstamp timestamp NOT NULL DEFAULT now()1233 )12342026/10/05 12:09:29 INFO Received uploads request method=POST path=/api/pending_closures12352026/10/05 12:09:29 INFO Received uploads request method=POST path=/api/pending_closures12362026/10/05 12:09:29 INFO Received cleanup request method=DELETE path=/api/pending_closures1237=== NAME TestLeadElectsOneAndHandsOver1238 farm_test.go:158: b did not announce leadership 21 heartbeats after taking the lock: {Lead:false}12392026/10/05 12:09:29 INFO lead: released remote=192.0.2.1:12341240--- FAIL: TestLeadElectsOneAndHandsOver (4.42s)1241=== CONT TestService_NativeMTLS12422026/10/05 12:09:29 INFO Received uploads request method=POST path=/api/pending_closures12432026/10/05 12:09:29 INFO Received uploads request method=POST path=/api/pending_closures12442026/10/05 12:09:29 INFO Received uploads request method=POST path=/api/pending_closures12452026/10/05 12:09:29 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12462026/10/05 12:09:29 INFO Uploading l7qql3wgsj1qqcih66ick1pfxdqqyz50-a (248B)12472026/10/05 12:09:29 INFO Uploading p5kvadwpi4w82kls96gkg9dd9rp3gjvz-shared-dep (136B)12482026/10/05 12:09:29 WARN Failed to register uploaded object key=7ipflyvqxba3dvmwky4bmhnyv76cj918.ls error="server returned 404: 404 page not found\n"12492026/10/05 12:09:29 WARN Failed to register uploaded object key=l7qql3wgsj1qqcih66ick1pfxdqqyz50.ls error="server returned 404: 404 page not found\n"12502026/10/05 12:09:29 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12512026/10/05 12:09:29 WARN Failed to register uploaded object key=nar/0jn6vq6xg68lwhysw13szf7vjxa8xihyjkh3p6ybmywss1vk3921.nar.zst error="server returned 404: 404 page not found\n"12522026/10/05 12:09:29 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12532026/10/05 12:09:29 WARN Failed to register uploaded object key=p5kvadwpi4w82kls96gkg9dd9rp3gjvz.ls error="server returned 404: 404 page not found\n"12542026/10/05 12:09:29 INFO Signed narinfos id=1 count=212552026/10/05 12:09:29 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12562026/10/05 12:09:29 INFO Signed narinfos id=2 count=212572026/10/05 12:09:29 INFO Uploading 4 narinfos12582026/10/05 12:09:29 WARN Failed to register uploaded object key=7ipflyvqxba3dvmwky4bmhnyv76cj918.narinfo error="server returned 404: 404 page not found\n"12592026/10/05 12:09:29 WARN Failed to register uploaded object key=l7qql3wgsj1qqcih66ick1pfxdqqyz50.narinfo error="server returned 404: 404 page not found\n"12602026/10/05 12:09:29 WARN Failed to register uploaded object key=p5kvadwpi4w82kls96gkg9dd9rp3gjvz.narinfo error="server returned 404: 404 page not found\n"1261=== NAME TestPinProtectsFromGC1262 client_integration_test.go:976: Pin successfully protected closure from garbage collection12632026/10/05 12:09:29 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12642026/10/05 12:09:29 WARN Failed to register uploaded object key=p5kvadwpi4w82kls96gkg9dd9rp3gjvz.narinfo error="server returned 404: 404 page not found\n"12652026/10/05 12:09:29 INFO Completed upload id=112662026/10/05 12:09:29 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12672026/10/05 12:09:29 INFO Completed upload id=212682026/10/05 12:09:29 INFO Upload complete. (127ms)1269=== NAME TestClientFallsBackToClosures1270 client_pushes_test.go:112: Retrieved narinfo from S3:1271 StorePath: /nix/var/nix/builds/nix-97026-1645623550/TestClientFallsBackToClosures1176836600/001/store/p5kvadwpi4w82kls96gkg9dd9rp3gjvz-shared-dep1272 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1273 Compression: zstd1274 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821275 NarSize: 1361276 References: 1277 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1278 client_pushes_test.go:112: Retrieved narinfo from S3:1279 StorePath: /nix/var/nix/builds/nix-97026-1645623550/TestClientFallsBackToClosures1176836600/001/store/l7qql3wgsj1qqcih66ick1pfxdqqyz50-a1280 URL: nar/0jn6vq6xg68lwhysw13szf7vjxa8xihyjkh3p6ybmywss1vk3921.nar.zst1281 Compression: zstd1282 NarHash: sha256:0jn6vq6xg68lwhysw13szf7vjxa8xihyjkh3p6ybmywss1vk39211283 NarSize: 2481284 References: /nix/var/nix/builds/nix-97026-1645623550/TestClientFallsBackToClosures1176836600/001/store/p5kvadwpi4w82kls96gkg9dd9rp3gjvz-shared-dep1285 CA: text:sha256:095dzwjbvzp7g15mg0kmzj7l98ass3ajl3m5znnzsy9mk0pln8yj1286 client_pushes_test.go:112: Retrieved narinfo from S3:1287 StorePath: /nix/var/nix/builds/nix-97026-1645623550/TestClientFallsBackToClosures1176836600/001/store/7ipflyvqxba3dvmwky4bmhnyv76cj918-b1288 URL: nar/0jn6vq6xg68lwhysw13szf7vjxa8xihyjkh3p6ybmywss1vk3921.nar.zst1289 Compression: zstd1290 NarHash: sha256:0jn6vq6xg68lwhysw13szf7vjxa8xihyjkh3p6ybmywss1vk39211291 NarSize: 2481292 References: /nix/var/nix/builds/nix-97026-1645623550/TestClientFallsBackToClosures1176836600/001/store/p5kvadwpi4w82kls96gkg9dd9rp3gjvz-shared-dep1293 CA: text:sha256:095dzwjbvzp7g15mg0kmzj7l98ass3ajl3m5znnzsy9mk0pln8yj1294--- PASS: TestPinProtectsFromGC (7.07s)1295=== CONT TestNARDeduplicationMetadataUploadBug1296--- PASS: TestClientFallsBackToClosures (2.90s)1297=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded12982026/10/05 12:09:29 INFO Received uploads request method=POST path=/api/pending_closures1299--- PASS: TestPendingClosureFailureTracksEveryUpload (2.62s)1300=== CONT TestMultipartCleanup1301--- PASS: TestPendingClosureFailureAbortsItsUploads (1.31s)1302=== CONT TestDeletePinKeepsRowWhenS3Fails1303--- PASS: TestConnectSerialisesConcurrentMigrations (2.74s)1304=== CONT TestCreatePin_ReservedPins1305--- PASS: TestMetricsInventory (1.43s)1306=== CONT TestReadProxyOutlastsServerWriteTimeout13072026/10/05 12:09:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56405/oidc13082026/10/05 12:09:30 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13092026/10/05 12:09:30 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1310--- PASS: TestService_NativeMTLS (1.32s)1311=== CONT TestPush_CompleteCommitsEveryRoot13122026/10/05 12:09:30 INFO Received uploads request method=POST path=/api/pending_closures1313--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (1.49s)1314=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1315=== NAME TestNARDeduplicationMetadataUploadBug1316 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-97026-1645623550/TestNARDeduplicationMetadataUploadBug1509777376/001/store/5qyhhcxhbpnp4wylvc7glfkalrrv3m3g-file1.txt13172026/10/05 12:09:31 INFO Received push request method=POST path=/api/pushes13182026/10/05 12:09:31 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13192026/10/05 12:09:31 INFO Uploading 5qyhhcxhbpnp4wylvc7glfkalrrv3m3g-file1.txt (160B)13202026/10/05 12:09:31 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"13212026/10/05 12:09:31 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13222026/10/05 12:09:31 WARN Failed to register uploaded object key=5qyhhcxhbpnp4wylvc7glfkalrrv3m3g.ls error="server returned 404: 404 page not found\n"13232026/10/05 12:09:31 INFO Signed narinfos id=1 count=113242026/10/05 12:09:31 INFO Uploading 1 narinfos13252026/10/05 12:09:31 INFO Received complete push request method=POST path=/api/pushes/1/complete13262026/10/05 12:09:31 WARN Failed to register uploaded object key=5qyhhcxhbpnp4wylvc7glfkalrrv3m3g.narinfo error="server returned 404: 404 page not found\n"13272026/10/05 12:09:31 INFO Upload complete. (100ms)1328 metadata_upload_test.go:54: Retrieved narinfo from S3:1329 StorePath: /nix/var/nix/builds/nix-97026-1645623550/TestNARDeduplicationMetadataUploadBug1509777376/001/store/5qyhhcxhbpnp4wylvc7glfkalrrv3m3g-file1.txt1330 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1331 Compression: zstd1332 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1333 NarSize: 1601334 References: 1335 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1336 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1337 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1338 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1339 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-97026-1645623550/TestNARDeduplicationMetadataUploadBug1509777376/001/store/lkyscxlhnk9vdlkjrzj6cizvjqddmwdg-file2.txt13402026/10/05 12:09:31 INFO Received push request method=POST path=/api/pushes13412026/10/05 12:09:31 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13422026/10/05 12:09:31 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13432026/10/05 12:09:31 WARN Failed to register uploaded object key=lkyscxlhnk9vdlkjrzj6cizvjqddmwdg.ls error="server returned 404: 404 page not found\n"13442026/10/05 12:09:31 INFO Signed narinfos id=2 count=113452026/10/05 12:09:31 INFO Uploading 1 narinfos13462026/10/05 12:09:31 INFO Received complete push request method=POST path=/api/pushes/2/complete13472026/10/05 12:09:31 WARN Failed to register uploaded object key=lkyscxlhnk9vdlkjrzj6cizvjqddmwdg.narinfo error="server returned 404: 404 page not found\n"13482026/10/05 12:09:31 INFO Upload complete. (80ms)1349 metadata_upload_test.go:76: Retrieved narinfo from S3:1350 StorePath: /nix/var/nix/builds/nix-97026-1645623550/TestNARDeduplicationMetadataUploadBug1509777376/001/store/lkyscxlhnk9vdlkjrzj6cizvjqddmwdg-file2.txt1351 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1352 Compression: zstd1353 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1354 NarSize: 1601355 References: 1356 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1357 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1358 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1359 {"version":1,"root":{"type":"regular","size":44}}13602026/10/05 12:09:31 INFO Received uploads request method=POST path=/api/pending_closures1361--- PASS: TestNARDeduplicationMetadataUploadBug (2.26s)1362=== CONT TestReadRedirectUsesPublicS3URL13632026/10/05 12:09:31 INFO Received cleanup request method=DELETE path=/api/pending_closures13642026/10/05 12:09:31 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket43/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""13652026/10/05 12:09:31 INFO Aborted multipart uploads count=0 kept=113662026/10/05 12:09:31 INFO Received cleanup request method=DELETE path=/api/pending_closures13672026/10/05 12:09:31 INFO Aborted multipart uploads count=1 kept=01368--- PASS: TestMultipartCleanup (1.93s)1369=== CONT TestPush_RejectsBadRequests13702026/10/05 12:09:31 INFO Received create pin request method=POST path=/api/pins/app13712026/10/05 12:09:31 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo13722026/10/05 12:09:31 INFO Received delete pin request method=DELETE path=/api/pins/app13732026/10/05 12:09:31 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket44/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"13742026/10/05 12:09:31 INFO Received delete pin request method=DELETE path=/api/pins/app13752026/10/05 12:09:31 INFO Deleted pin name=app1376--- PASS: TestDeletePinKeepsRowWhenS3Fails (1.98s)1377=== CONT TestReadProxyRangeRequest13782026/10/05 12:09:32 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13792026/10/05 12:09:32 WARN Refused reserved pin name=worker-x86_64-linux13802026/10/05 12:09:32 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13812026/10/05 12:09:32 INFO Received create pin request method=POST path=/api/pins/my-app13822026/10/05 12:09:32 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1383--- PASS: TestCreatePin_ReservedPins (2.27s)1384=== CONT TestService_AuthMiddleware_OIDC13852026/10/05 12:09:32 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56455/oidc13862026/10/05 12:09:32 INFO Received push request method=POST path=/api/pushes13872026/10/05 12:09:32 INFO Received push request method=POST path=/api/pushes1388--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (2.13s)1389=== CONT TestClientCADerivations1390=== NAME TestOrphanedObjectsGCStressTest1391 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1392 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1393--- PASS: TestReadRedirectUsesPublicS3URL (2.22s)1394=== CONT TestReconnectLeavesObjectsUnlocked13952026/10/05 12:09:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1396=== RUN TestPush_RejectsBadRequests/no_objects1397=== PAUSE TestPush_RejectsBadRequests/no_objects1398=== RUN TestPush_RejectsBadRequests/bad_root1399=== PAUSE TestPush_RejectsBadRequests/bad_root1400=== RUN TestPush_RejectsBadRequests/root_not_in_objects1401=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1402=== RUN TestPush_RejectsBadRequests/no_roots1403=== PAUSE TestPush_RejectsBadRequests/no_roots1404=== CONT TestCacheStatsHandler14052026/10/05 12:09:34 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=YjFlODMyMTktMmE1ZS00NWRkLTliZjgtNWFlYTIzYzNmYTViLmI0ZmFiODA2LWI1NjItNDAzZS1iYzgwLWRlODE1NjJjZmYzZngxNzkxMjAyMTcyNTc5MDQxMDAw parts=101406--- PASS: TestReadProxyRangeRequest (2.41s)1407=== CONT TestService_AuthMiddleware1408--- PASS: TestConnectWaitsForAPeerMigration (7.22s)1409=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1410=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1411=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1412=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1413=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1414=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1415=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1416=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1417=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1418=== CONT TestClientIntegration14192026/10/05 12:09:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14202026/10/05 12:09:35 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=YjFlODMyMTktMmE1ZS00NWRkLTliZjgtNWFlYTIzYzNmYTViLjE3ZTc4YWExLTMyOWMtNDZlMC1iNTA5LTQ2Yzc2NjhkMWFmZHgxNzkxMjAyMTcyNTc4MzYyMDAw parts=1014212026/10/05 12:09:35 INFO Aborted multipart uploads count=1 kept=014222026/10/05 12:09:35 INFO Received cleanup request method=DELETE path=/api/pending_closures14232026/10/05 12:09:35 INFO Aborted multipart uploads count=1 kept=01424--- PASS: TestPendingCleanupUsesOneCutoff (8.57s)1425=== CONT TestReadProxyNarStreaming1426=== NAME TestClientCADerivations1427 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-97026-1645623550/TestClientCADerivations3182689763/001/store/ai68yiimmmspw3jasq3px1m692nyx24x-ca-test1428 client_ca_test.go:139: Found 1 dependencies (including self)14292026/10/05 12:09:35 INFO Received push request method=POST path=/api/pushes14302026/10/05 12:09:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14312026/10/05 12:09:35 INFO Uploading ai68yiimmmspw3jasq3px1m692nyx24x-ca-test (144B)14322026/10/05 12:09:35 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"14332026/10/05 12:09:35 WARN Failed to register uploaded object key=ai68yiimmmspw3jasq3px1m692nyx24x.ls error="server returned 404: 404 page not found\n"14342026/10/05 12:09:35 WARN Failed to register uploaded object key=log/94k9zdhq6wzql65br43iwnjp7vkn049l-ca-test.drv error="server returned 404: 404 page not found\n"14352026/10/05 12:09:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14362026/10/05 12:09:35 INFO Signed narinfos id=1 count=114372026/10/05 12:09:35 INFO Uploading 1 narinfos14382026/10/05 12:09:35 INFO Received complete push request method=POST path=/api/pushes/1/complete14392026/10/05 12:09:35 WARN Failed to register uploaded object key=ai68yiimmmspw3jasq3px1m692nyx24x.narinfo error="server returned 404: 404 page not found\n"14402026/10/05 12:09:35 INFO Upload complete. (254ms)1441 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-97026-1645623550/TestClientCADerivations3182689763/001/store/ai68yiimmmspw3jasq3px1m692nyx24x-ca-test1442 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1443 Compression: zstd1444 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1445 NarSize: 1441446 References: 1447 Deriver: /nix/var/nix/builds/nix-97026-1645623550/TestClientCADerivations3182689763/001/store/94k9zdhq6wzql65br43iwnjp7vkn049l-ca-test.drv1448 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1449 client_ca_test.go:185: Checking for realisation files in S3...1450 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1451 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1452--- PASS: TestCacheStatsHandler (1.59s)1453=== CONT TestService_ReadAuthMiddleware1454=== NAME TestOrphanedObjectsGCStressTest1455 orphaned_objects_gc_test.go:509: Stress test completed successfully:1456 orphaned_objects_gc_test.go:510: - Active objects preserved: 201457 orphaned_objects_gc_test.go:511: - Objects deleted: 2101458 orphaned_objects_gc_test.go:512: - Total GC'd: 2101459--- PASS: TestOrphanedObjectsGCStressTest (7.27s)1460=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT1461=== NAME TestClientCADerivations1462 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket53?endpoint=http://localhost:56127®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-97026-1645623550/TestClientCADerivations3182689763/001/store'1463 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11464--- PASS: TestClientCADerivations (2.81s)1465=== CONT TestService_RequireScope_OIDC1466--- PASS: TestReconnectLeavesObjectsUnlocked (2.01s)1467=== CONT TestCompleteMultipartUnregistered14682026/10/05 12:09:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56520/oidc14692026/10/05 12:09:35 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1470--- PASS: TestService_AuthMiddleware (1.74s)1471=== CONT TestReadProxyInvalidPath14722026/10/05 12:09:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14732026/10/05 12:09:36 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=YjFlODMyMTktMmE1ZS00NWRkLTliZjgtNWFlYTIzYzNmYTViLjc2OTkyY2FhLWU3ZmYtNGNhYi05ZTEyLThjZDE3ZDdmZDQzNngxNzkxMjAyMTcyNTc5MDQ0MDAw parts=1014742026/10/05 12:09:36 INFO Received complete push request method=POST path=/api/pushes/1/complete14752026/10/05 12:09:36 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14762026/10/05 12:09:36 WARN mTLS auth: bound subjects configured but subject DN unavailable14772026/10/05 12:09:36 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1478--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.93s)1479=== CONT TestService_cleanupPendingClosuresHandler1480--- PASS: TestPush_CompleteCommitsEveryRoot (5.75s)1481=== CONT TestGenerateLandingPage1482--- PASS: TestGenerateLandingPage (0.01s)1483=== CONT TestReadProxy4041484--- PASS: TestReadProxyOutlastsServerWriteTimeout (6.24s)1485=== CONT TestService_createPendingClosureHandler1486=== NAME TestClientIntegration1487 client_integration_test.go:334: Created store path: /nix/var/nix/builds/nix-97026-1645623550/TestClientIntegration1754120808/002/store/acm30xfhi5c7chsgrpc20pwf2dnqb9yc-test-file.txt14882026/10/05 12:09:36 INFO Received push request method=POST path=/api/pushes14892026/10/05 12:09:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14902026/10/05 12:09:36 INFO Uploading acm30xfhi5c7chsgrpc20pwf2dnqb9yc-test-file.txt (152B)14912026/10/05 12:09:36 WARN Failed to register uploaded object key=acm30xfhi5c7chsgrpc20pwf2dnqb9yc.ls error="server returned 404: 404 page not found\n"14922026/10/05 12:09:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14932026/10/05 12:09:36 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"14942026/10/05 12:09:36 INFO Signed narinfos id=1 count=114952026/10/05 12:09:36 INFO Uploading 1 narinfos14962026/10/05 12:09:36 INFO Received complete push request method=POST path=/api/pushes/1/complete14972026/10/05 12:09:36 WARN Failed to register uploaded object key=acm30xfhi5c7chsgrpc20pwf2dnqb9yc.narinfo error="server returned 404: 404 page not found\n"14982026/10/05 12:09:36 INFO Upload complete. (146ms)14992026/10/05 12:09:36 INFO All 1 paths already cached1500 client_integration_test.go:360: Retrieved narinfo from S3:1501 StorePath: /nix/var/nix/builds/nix-97026-1645623550/TestClientIntegration1754120808/002/store/acm30xfhi5c7chsgrpc20pwf2dnqb9yc-test-file.txt1502 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1503 Compression: zstd1504 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11505 NarSize: 1521506 References: 1507 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11508 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)1509 client_integration_test.go:361: Decompressed .ls content (64 bytes):1510 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1511--- PASS: TestReadProxyNarStreaming (1.57s)1512=== CONT TestCreatePendingClosureRejectsOversizedNAR15132026/10/05 12:09:36 INFO Received uploads request method=POST path=/api/pending_closures1514--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1515=== CONT TestIsValidUploadKey1516=== RUN TestIsValidUploadKey/narinfo1517=== PAUSE TestIsValidUploadKey/narinfo1518=== RUN TestIsValidUploadKey/nar_zst1519=== PAUSE TestIsValidUploadKey/nar_zst1520=== RUN TestIsValidUploadKey/nar_xz1521=== PAUSE TestIsValidUploadKey/nar_xz1522=== RUN TestIsValidUploadKey/nar_plain1523=== PAUSE TestIsValidUploadKey/nar_plain1524=== RUN TestIsValidUploadKey/listing1525=== PAUSE TestIsValidUploadKey/listing1526=== RUN TestIsValidUploadKey/build_log1527=== PAUSE TestIsValidUploadKey/build_log1528=== RUN TestIsValidUploadKey/build_log_home-manager_file1529=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1530=== RUN TestIsValidUploadKey/build_log_plus_in_name1531=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1532=== RUN TestIsValidUploadKey/build_log_question_mark1533=== PAUSE TestIsValidUploadKey/build_log_question_mark1534=== RUN TestIsValidUploadKey/build_log_equals1535=== PAUSE TestIsValidUploadKey/build_log_equals1536=== RUN TestIsValidUploadKey/realisation1537=== PAUSE TestIsValidUploadKey/realisation1538=== RUN TestIsValidUploadKey/realisation_plus_in_output1539=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1540=== RUN TestIsValidUploadKey/nix-cache-info1541=== PAUSE TestIsValidUploadKey/nix-cache-info1542=== RUN TestIsValidUploadKey/index.html1543=== PAUSE TestIsValidUploadKey/index.html1544=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1545=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1546=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1547=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1548=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1549=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1550=== RUN TestIsValidUploadKey/traversal1551=== PAUSE TestIsValidUploadKey/traversal1552=== RUN TestIsValidUploadKey/traversal_nar1553=== PAUSE TestIsValidUploadKey/traversal_nar1554=== RUN TestIsValidUploadKey/absolute1555=== PAUSE TestIsValidUploadKey/absolute1556=== RUN TestIsValidUploadKey/empty_key1557=== PAUSE TestIsValidUploadKey/empty_key1558=== RUN TestIsValidUploadKey/unknown_type1559=== PAUSE TestIsValidUploadKey/unknown_type1560=== CONT TestReadProxyHead15612026/10/05 12:09:36 INFO Received push request method=POST path=/api/pushes15622026/10/05 12:09:36 INFO Object in database but missing from S3 key=acm30xfhi5c7chsgrpc20pwf2dnqb9yc.ls15632026/10/05 12:09:36 WARN Found objects in DB but missing from S3, will re-upload count=115642026/10/05 12:09:36 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)15652026/10/05 12:09:36 INFO Received complete push request method=POST path=/api/pushes/2/complete15662026/10/05 12:09:36 WARN Failed to register uploaded object key=acm30xfhi5c7chsgrpc20pwf2dnqb9yc.ls error="server returned 404: 404 page not found\n"15672026/10/05 12:09:36 INFO Upload complete. (73ms)1568=== NAME TestClientIntegration1569 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)1570 client_integration_test.go:389: Decompressed .ls content (49 bytes):1571 {"version":1,"root":{"type":"regular","size":39}}15722026/10/05 12:09:36 INFO Received push request method=POST path=/api/pushes15732026/10/05 12:09:36 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)15742026/10/05 12:09:37 INFO Received complete push request method=POST path=/api/pushes/3/complete15752026/10/05 12:09:37 WARN Failed to register uploaded object key=acm30xfhi5c7chsgrpc20pwf2dnqb9yc.ls error="server returned 404: 404 page not found\n"15762026/10/05 12:09:37 INFO Upload complete. (74ms)1577 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)1578 client_integration_test.go:405: Decompressed .ls content (49 bytes):1579 {"version":1,"root":{"type":"regular","size":39}}1580--- PASS: TestService_ReadAuthMiddleware (1.53s)1581=== CONT TestPendingClosureWriteTimeout1582=== RUN TestPendingClosureWriteTimeout/empty1583=== PAUSE TestPendingClosureWriteTimeout/empty1584=== RUN TestPendingClosureWriteTimeout/400_objects1585=== PAUSE TestPendingClosureWriteTimeout/400_objects1586=== RUN TestPendingClosureWriteTimeout/670k_objects1587=== PAUSE TestPendingClosureWriteTimeout/670k_objects1588=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1589=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1590=== CONT TestReadRedirectNar15912026/10/05 12:09:37 INFO Received push request method=POST path=/api/pushes15922026/10/05 12:09:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15932026/10/05 12:09:37 INFO Uploading pa8pmv8n6sdzzmf464kw3j7z6ampdm4z-lost-commit.txt (152B)15942026/10/05 12:09:37 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"15952026/10/05 12:09:37 WARN Failed to register uploaded object key=pa8pmv8n6sdzzmf464kw3j7z6ampdm4z.ls error="server returned 404: 404 page not found\n"15962026/10/05 12:09:37 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign15972026/10/05 12:09:37 INFO Signed narinfos id=4 count=115982026/10/05 12:09:37 INFO Uploading 1 narinfos15992026/10/05 12:09:37 INFO Received complete push request method=POST path=/api/pushes/4/complete16002026/10/05 12:09:37 WARN Failed to register uploaded object key=pa8pmv8n6sdzzmf464kw3j7z6ampdm4z.narinfo error="server returned 404: 404 page not found\n"16012026/10/05 12:09:37 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://127.0.0.1:56539/api/pushes/4/complete\": EOF" url=http://127.0.0.1:56539/api/pushes/4/complete16022026/10/05 12:09:37 INFO Received complete push request method=POST path=/api/pushes/4/complete16032026-10-05 12:09:37.328 UTC [97465] ERROR: Push does not exist: id=416042026-10-05 12:09:37.328 UTC [97465] CONTEXT: PL/pgSQL function commit_push(bigint) line 9 at RAISE16052026-10-05 12:09:37.328 UTC [97465] STATEMENT: -- name: CommitPush :exec1606 SELECT commit_push($1::bigint)1607 16082026/10/05 12:09:37 INFO Upload complete. (221ms)1609=== NAME TestClientIntegration1610 client_integration_test.go:435: Retrieved narinfo from S3:1611 StorePath: /nix/var/nix/builds/nix-97026-1645623550/TestClientIntegration1754120808/002/store/pa8pmv8n6sdzzmf464kw3j7z6ampdm4z-lost-commit.txt1612 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1613 Compression: zstd1614 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1615 NarSize: 1521616 References: 1617 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1618 client_integration_test.go:438: Testing garbage collection...16192026/10/05 12:09:37 INFO Received uploads request method=POST path=/api/pending_closures16202026/10/05 12:09:37 INFO Starting cleanup of old closures method=DELETE path=/api/closures16212026/10/05 12:09:37 INFO Garbage collection started16222026/10/05 12:09:37 INFO Aborted multipart uploads count=0 kept=016232026/10/05 12:09:37 WARN Force mode enabled - objects will be deleted immediately without grace period1624--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.76s)1625=== CONT TestGCTaskStore_GetEmpty1626=== CONT TestGCTaskStore_PhaseUpdates1627--- PASS: TestGCTaskStore_GetEmpty (0.00s)1628--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1629=== CONT TestReadProxyNarinfoAlreadyDecompressed16302026/10/05 12:09:37 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=2 objects-marked-for-deletion=6 objects-deleted-after-grace-period=6 objects-failed-to-delete=016312026/10/05 12:09:37 INFO Vacuumed table table=pending_closures16322026/10/05 12:09:37 INFO Vacuumed table table=pending_objects16332026/10/05 12:09:37 INFO Vacuumed table table=multipart_uploads16342026/10/05 12:09:37 INFO Vacuumed table table=closures16352026/10/05 12:09:37 INFO Vacuumed table table=objects16362026/10/05 12:09:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16372026/10/05 12:09:37 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1638--- PASS: TestCompleteMultipartUnregistered (1.79s)1639=== CONT TestProxyWriteTimeout1640=== RUN TestProxyWriteTimeout/narinfo1641=== PAUSE TestProxyWriteTimeout/narinfo1642=== RUN TestProxyWriteTimeout/1_GiB_nar1643=== PAUSE TestProxyWriteTimeout/1_GiB_nar1644=== RUN TestProxyWriteTimeout/10_GiB_nar1645=== PAUSE TestProxyWriteTimeout/10_GiB_nar1646=== RUN TestProxyWriteTimeout/unknown_size1647=== PAUSE TestProxyWriteTimeout/unknown_size1648=== CONT TestParseSingleRange1649=== RUN TestParseSingleRange/none1650=== PAUSE TestParseSingleRange/none1651=== RUN TestParseSingleRange/unknown_unit1652=== PAUSE TestParseSingleRange/unknown_unit1653=== RUN TestParseSingleRange/multi-range_ignored1654=== PAUSE TestParseSingleRange/multi-range_ignored1655=== RUN TestParseSingleRange/malformed_no_dash1656=== PAUSE TestParseSingleRange/malformed_no_dash1657=== RUN TestParseSingleRange/malformed_both_empty1658=== PAUSE TestParseSingleRange/malformed_both_empty1659=== RUN TestParseSingleRange/malformed_end_before_start1660=== PAUSE TestParseSingleRange/malformed_end_before_start1661=== RUN TestParseSingleRange/closed1662=== PAUSE TestParseSingleRange/closed1663=== RUN TestParseSingleRange/open-ended1664=== PAUSE TestParseSingleRange/open-ended1665=== RUN TestParseSingleRange/end_clamped_to_size1666=== PAUSE TestParseSingleRange/end_clamped_to_size1667=== RUN TestParseSingleRange/suffix1668=== PAUSE TestParseSingleRange/suffix1669=== RUN TestParseSingleRange/suffix_exceeds_size1670=== PAUSE TestParseSingleRange/suffix_exceeds_size1671=== RUN TestParseSingleRange/single_byte1672=== PAUSE TestParseSingleRange/single_byte1673=== RUN TestParseSingleRange/start_past_EOF1674=== PAUSE TestParseSingleRange/start_past_EOF1675=== RUN TestParseSingleRange/start_far_past_EOF1676=== PAUSE TestParseSingleRange/start_far_past_EOF1677=== CONT TestGCTaskStore_Fail1678=== CONT TestGCTaskStore_CompletedAllowsNewTask1679--- PASS: TestGCTaskStore_Fail (0.00s)1680=== CONT TestReadRedirectKeepsNarinfoProxied1681--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1682--- PASS: TestReadProxyInvalidPath (1.77s)1683=== CONT TestCommitRacingPendingCleanupKeepsObjects1684=== RUN TestService_RequireScope_OIDC/builder_may_write1685=== PAUSE TestService_RequireScope_OIDC/builder_may_write1686=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1687=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1688=== RUN TestService_RequireScope_OIDC/ops_may_admin1689=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1690=== RUN TestService_RequireScope_OIDC/ops_may_not_write1691=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1692=== RUN TestService_RequireScope_OIDC/reader_may_not_write1693=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1694=== RUN TestService_RequireScope_OIDC/static_token_may_admin1695=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1696=== RUN TestService_RequireScope_OIDC/static_token_may_write1697=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1698=== RUN TestService_RequireScope_OIDC/reader_may_read1699=== PAUSE TestService_RequireScope_OIDC/reader_may_read1700=== RUN TestService_RequireScope_OIDC/writer_implies_read1701=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1702=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1703=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1704=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1705=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1706=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1707=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1708=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1709=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1710=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1711=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1712=== CONT TestParseSize1713=== CONT TestPresignedUploadRegisteredBeforeCommit1714--- PASS: TestParseSize (0.00s)17152026/10/05 12:09:38 INFO Received cleanup request method=DELETE path=/api/pending_closures17162026/10/05 12:09:38 INFO Aborted multipart uploads count=0 kept=017172026/10/05 12:09:38 INFO Received uploads request method=POST path=/api/pending_closures17182026/10/05 12:09:38 WARN Rate limiter enabled after throttle name=s3-test rate=517192026/10/05 12:09:38 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."17202026/10/05 12:09:38 WARN Rate limiter backed off name=s3-test rate=517212026/10/05 12:09:38 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."17222026/10/05 12:09:38 INFO Received cleanup request method=DELETE path=/api/pending_closures17232026/10/05 12:09:38 INFO Aborted multipart uploads count=1 kept=01724--- PASS: TestReadProxy404 (2.16s)1725=== CONT TestSweepRechecksPendingAfterLocking17262026/10/05 12:09:38 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17272026-10-05 12:09:38.412 UTC [97516] ERROR: Closure does not exist: id=117282026-10-05 12:09:38.412 UTC [97516] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE17292026-10-05 12:09:38.412 UTC [97516] STATEMENT: -- name: CommitPendingClosure :exec1730 SELECT commit_pending_closure($1::bigint)1731 1732--- PASS: TestService_cleanupPendingClosuresHandler (2.21s)1733=== CONT TestService_Rustfstest17342026/10/05 12:09:38 INFO Received uploads request method=POST path=/api/pending_closures17352026/10/05 12:09:38 INFO Received uploads request method=POST path=/api/pending_closures17362026/10/05 12:09:38 INFO Received uploads request method=POST path=/api/pending_closures1737--- PASS: TestReadProxyHead (2.22s)1738=== CONT TestRedundantMultipartUpload1739--- PASS: TestReadRedirectNar (2.13s)1740=== CONT TestPush_SignsNarinfosOfItsPendingObjects17412026/10/05 12:09:39 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=01742=== NAME TestClientIntegration1743 client_integration_test.go:445: Objects in database after GC:1744 client_integration_test.go:445: Successfully deleted all objects with GC --force1745--- PASS: TestClientIntegration (4.97s)1746=== CONT TestGetExistingObjectsLocksRows1747--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.21s)1748=== CONT TestService_ReadScope_PublicByDefault1749--- PASS: TestReadRedirectKeepsNarinfoProxied (2.39s)1750=== CONT TestReadProxyConditionalGet17512026/10/05 12:09:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17522026/10/05 12:09:40 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YjFlODMyMTktMmE1ZS00NWRkLTliZjgtNWFlYTIzYzNmYTViLjJhNTAyYTA1LTJmNDAtNDYzMy1hN2E1LTg0ZjI5MWU4ODhiYXgxNzkxMjAyMTc4NjM1OTI0MDAw parts=1017532026/10/05 12:09:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17542026/10/05 12:09:40 INFO Completed upload id=117552026/10/05 12:09:40 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000017562026/10/05 12:09:40 INFO Received uploads request method=POST path=/api/pending_closures17572026/10/05 12:09:40 INFO Starting cleanup of old closures method=DELETE path=/api/closures17582026/10/05 12:09:40 INFO Aborted multipart uploads count=0 kept=017592026/10/05 12:09:40 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=017602026/10/05 12:09:40 INFO Vacuumed table table=pending_closures17612026/10/05 12:09:40 INFO Vacuumed table table=pending_objects17622026/10/05 12:09:40 INFO Vacuumed table table=multipart_uploads17632026/10/05 12:09:40 INFO Vacuumed table table=closures17642026/10/05 12:09:40 INFO Vacuumed table table=objects17652026/10/05 12:09:40 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001766--- PASS: TestService_createPendingClosureHandler (4.16s)1767=== CONT TestService_verifyS3Integrity17682026/10/05 12:09:40 INFO Aborted multipart uploads count=0 kept=017692026/10/05 12:09:40 WARN Force mode enabled - objects will be deleted immediately without grace period17702026/10/05 12:09:40 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=017712026/10/05 12:09:40 INFO Vacuumed table table=pending_closures17722026/10/05 12:09:40 INFO Vacuumed table table=pending_objects17732026/10/05 12:09:40 INFO Vacuumed table table=multipart_uploads17742026/10/05 12:09:40 INFO Vacuumed table table=closures17752026/10/05 12:09:40 INFO Vacuumed table table=objects1776--- PASS: TestCommitRacingPendingCleanupKeepsObjects (2.85s)1777=== CONT TestCacheConfigHandler1778=== RUN TestCacheConfigHandler/full_config,_no_issuer1779=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1780=== RUN TestCacheConfigHandler/no_cache_url_configured1781=== PAUSE TestCacheConfigHandler/no_cache_url_configured1782=== RUN TestCacheConfigHandler/no_signing_keys1783=== PAUSE TestCacheConfigHandler/no_signing_keys1784=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1785=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1786=== CONT TestUploadHandlersRejectOversizedBody1787=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1788=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1789=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1790=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1791=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1792=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1793=== CONT TestGCTaskStore_ConflictDifferentParams1794--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1795=== CONT TestGCTaskStore_GetReturnsLatest1796--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1797=== CONT TestGCTaskStore_DeduplicateSameParams1798--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1799=== CONT TestGracefulShutdownDrainsInflight18002026/10/05 12:09:40 INFO Starting HTTP server address=127.0.0.1:5665618012026/10/05 12:09:40 INFO Shutdown signal received, draining in-flight requests timeout=10s1802--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1803=== CONT TestUploadHandlersRejectInvalidKeys1804=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1805=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1806=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1807=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1808=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1809=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1810=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1811=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1812=== CONT TestService_healthCheckHandler18132026/10/05 12:09:40 INFO Received uploads request method=POST path=/api/pending_closures18142026/10/05 12:09:40 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst18152026/10/05 12:09:40 INFO Received uploads request method=POST path=/api/pending_closures1816--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.98s)1817=== CONT TestGCTaskStore_StartNew1818--- PASS: TestGCTaskStore_StartNew (0.00s)1819=== CONT TestReadProxyRootRedirectsToIndexHTML18202026/10/05 12:09:41 INFO Aborted multipart uploads count=0 kept=018212026/10/05 12:09:41 WARN Force mode enabled - objects will be deleted immediately without grace period18222026/10/05 12:09:41 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=018232026/10/05 12:09:41 INFO Vacuumed table table=pending_closures18242026/10/05 12:09:41 INFO Vacuumed table table=pending_objects18252026/10/05 12:09:41 INFO Vacuumed table table=multipart_uploads18262026/10/05 12:09:41 INFO Vacuumed table table=closures18272026/10/05 12:09:41 INFO Vacuumed table table=objects1828--- PASS: TestSweepRechecksPendingAfterLocking (3.08s)1829=== CONT TestReadProxyDisabled1830--- PASS: TestService_Rustfstest (3.16s)1831=== CONT TestProxyHeadersOnlyTrustedOnSocket18322026/10/05 12:09:41 INFO Received uploads request method=POST path=/api/pending_closures18332026/10/05 12:09:42 INFO Received uploads request method=POST path=/api/pending_closures18342026/10/05 12:09:42 INFO Received push request method=POST path=/api/pushes18352026/10/05 12:09:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18362026/10/05 12:09:42 INFO Signed narinfos id=1 count=11837--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (3.16s)1838=== CONT TestReadProxyNarinfo1839--- PASS: TestGetExistingObjectsLocksRows (3.04s)1840=== CONT TestService_readinessHandler1841--- PASS: TestService_ReadScope_PublicByDefault (3.27s)1842=== CONT TestCompletedNarNotReofferedAcrossClosures1843--- PASS: TestReadProxyConditionalGet (3.27s)1844=== CONT TestGCEndsOnShutdown1845=== RUN TestGCEndsOnShutdown/before_the_run1846=== PAUSE TestGCEndsOnShutdown/before_the_run1847=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1848=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1849=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1850=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1851=== CONT TestSkippedUploadsHandler18522026/10/05 12:09:43 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001853--- PASS: TestSkippedUploadsHandler (0.00s)1854=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle18552026/10/05 12:09:43 INFO Received uploads request method=POST path=/api/pending_closures1856--- PASS: TestService_healthCheckHandler (3.15s)1857=== CONT TestCompleteMultipartUpload_ErrorButObjectExists18582026/10/05 12:09:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18592026/10/05 12:09:44 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YjFlODMyMTktMmE1ZS00NWRkLTliZjgtNWFlYTIzYzNmYTViLmMzMDQ4NDQzLTA3MWYtNGU1YS1iM2QwLTQ5ZTU5YjMwYTkxYXgxNzkxMjAyMTgxOTYwNTE5MDAw parts=1218602026/10/05 12:09:44 INFO Received uploads request method=POST path=/api/pending_closures18612026/10/05 12:09:44 INFO Received uploads request method=POST path=/api/pending_closures1862--- PASS: TestReadProxyRootRedirectsToIndexHTML (3.39s)1863=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1864=== CONT TestResolveDBConnectionString/missing_file_is_an_error1865=== CONT TestResolveDBConnectionString/nothing_configured1866=== CONT TestResolveDBConnectionString/file_when_flag_empty1867=== CONT TestResolveDBConnectionString/flag_wins1868=== CONT TestIsValidCachePath/narinfo1869=== CONT TestIsValidCachePath/nix-cache-info1870=== CONT TestIsValidCachePath/short_hash1871=== CONT TestIsValidCachePath/wrong_extension1872=== CONT TestIsValidCachePath/leading_slash1873=== CONT TestIsValidCachePath/empty1874=== CONT TestIsValidCachePath/random_path1875=== CONT TestIsValidCachePath/invalid_char_e1876=== CONT TestIsValidCachePath/traversal_in_middle1877=== CONT TestIsValidCachePath/invalid_char_u1878=== CONT TestIsValidCachePath/traversal_parent1879=== CONT TestIsValidCachePath/nar_uncompressed1880=== CONT TestIsValidCachePath/realisation1881=== CONT TestIsValidCachePath/log1882=== CONT TestIsValidCachePath/ls1883=== CONT TestIsValidCachePath/index.html1884=== CONT TestIsValidCachePath/nar_zst1885=== CONT TestIsValidCachePath/nar_bz21886=== CONT TestIsValidCachePath/nar_xz1887=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1888--- PASS: TestIsValidCachePath (0.02s)1889 --- PASS: TestIsValidCachePath/narinfo (0.00s)1890 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1891 --- PASS: TestIsValidCachePath/short_hash (0.00s)1892 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1893 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1894 --- PASS: TestIsValidCachePath/empty (0.00s)1895 --- PASS: TestIsValidCachePath/random_path (0.00s)1896 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1897 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1898 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1899 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1900 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1901 --- PASS: TestIsValidCachePath/realisation (0.00s)1902 --- PASS: TestIsValidCachePath/log (0.00s)1903 --- PASS: TestIsValidCachePath/ls (0.00s)1904 --- PASS: TestIsValidCachePath/index.html (0.00s)1905 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1906 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1907 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1908 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1909=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1910--- PASS: TestResolveDBConnectionString (0.03s)1911 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1912 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1913 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1914 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1915 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1916--- PASS: TestReadProxyDisabled (3.57s)1917=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check19182026/10/05 12:09:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19192026/10/05 12:09:45 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YjFlODMyMTktMmE1ZS00NWRkLTliZjgtNWFlYTIzYzNmYTViLjIyODIzNTNmLTVhOTItNDdjNi05OTQxLTE4Nzc5YTkxNTI2ZngxNzkxMjAyMTgzNTE0ODI3MDAw parts=1019202026/10/05 12:09:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19212026/10/05 12:09:45 INFO Completed upload id=119222026/10/05 12:09:45 INFO Received uploads request method=POST path=/api/pending_closures19232026/10/05 12:09:45 INFO Received uploads request method=POST path=/api/pending_closures19242026/10/05 12:09:45 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo19252026/10/05 12:09:45 WARN Found objects in DB but missing from S3, will re-upload count=119262026/10/05 12:09:45 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete19272026/10/05 12:09:45 INFO Completed upload id=31928--- PASS: TestService_verifyS3Integrity (4.92s)1929=== CONT TestClientErrorHandling/InvalidAuthToken19302026/10/05 12:09:45 INFO Starting HTTP server address=127.0.0.1:5672719312026/10/05 12:09:45 INFO Starting HTTP server address=/nix/var/nix/builds/nix-97026-1645623550/TestProxyHeadersOnlyTrustedOnSocket2122111539/001/proxy.sock19322026/10/05 12:09:45 WARN mTLS auth: subject not in bound subjects subject="CN=someone"19332026/10/05 12:09:45 INFO Shutdown signal received, draining in-flight requests timeout=10s1934--- PASS: TestProxyHeadersOnlyTrustedOnSocket (3.82s)1935=== CONT TestClientErrorHandling/InvalidStorePath19362026/10/05 12:09:45 WARN readiness check failed error="closed pool"1937--- PASS: TestService_readinessHandler (3.07s)1938=== CONT TestClientErrorHandling/ServerNotAvailable19392026/10/05 12:09:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19402026/10/05 12:09:45 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19412026/10/05 12:09:45 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YjFlODMyMTktMmE1ZS00NWRkLTliZjgtNWFlYTIzYzNmYTViLjZiYTA1MTc2LTUzMDctNGEzMy04NDJkLWZhNTliNjQ0MDZkY3gxNzkxMjAyMTg0MTE1NDk0MDAw error="Get \"http://127.0.0.1:1/bucket76/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"19422026/10/05 12:09:45 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YjFlODMyMTktMmE1ZS00NWRkLTliZjgtNWFlYTIzYzNmYTViLjdiMWY2NmRiLWE0NDMtNGEwZC1hMmY0LTQyYjNkZmEyMWExZHgxNzkxMjAyMTg0MDU2NjMyMDAw parts=1219432026/10/05 12:09:45 INFO Received cleanup request method=DELETE path=/api/pending_closures19442026/10/05 12:09:45 INFO Aborted multipart uploads count=1 kept=019452026/10/05 12:09:45 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=190.594863ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1946--- PASS: TestRedundantMultipartUpload (7.02s)1947=== CONT TestServerTLSConfig/no_client_CA1948=== CONT TestServerTLSConfig/missing_CA_file1949=== CONT TestServerTLSConfig/not_a_PEM_file1950=== CONT TestPush_RejectsBadRequests/no_objects1951--- PASS: TestServerTLSConfig (0.00s)1952 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1953 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1954 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)19552026/10/05 12:09:45 INFO Received push request method=POST path=/api/pushes1956=== CONT TestPush_RejectsBadRequests/no_roots19572026/10/05 12:09:45 INFO Received push request method=POST path=/api/pushes1958=== CONT TestPush_RejectsBadRequests/root_not_in_objects19592026/10/05 12:09:45 INFO Received push request method=POST path=/api/pushes1960=== CONT TestPush_RejectsBadRequests/bad_root19612026/10/05 12:09:45 INFO Received push request method=POST path=/api/pushes1962=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19632026/10/05 12:09:46 WARN Authentication failed token_preview=eyJhbGciOi...HES44nEC5w token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1964=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1965=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19662026/10/05 12:09:46 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]1967=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1968=== CONT TestIsValidUploadKey/nar_zst1969=== CONT TestIsValidUploadKey/nix-cache-info1970=== CONT TestIsValidUploadKey/empty_key1971=== CONT TestIsValidUploadKey/absolute1972=== CONT TestIsValidUploadKey/traversal_nar1973=== CONT TestIsValidUploadKey/traversal1974=== CONT TestIsValidUploadKey/unknown_type1975=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1976=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1977=== CONT TestIsValidUploadKey/index.html1978=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1979=== CONT TestIsValidUploadKey/realisation_plus_in_output1980=== CONT TestIsValidUploadKey/realisation1981=== CONT TestIsValidUploadKey/build_log_equals1982=== CONT TestIsValidUploadKey/build_log_home-manager_file1983=== CONT TestIsValidUploadKey/build_log_question_mark1984=== CONT TestIsValidUploadKey/nar_xz1985=== CONT TestIsValidUploadKey/build_log1986=== CONT TestIsValidUploadKey/listing1987=== CONT TestIsValidUploadKey/nar_plain1988=== CONT TestIsValidUploadKey/narinfo1989=== CONT TestIsValidUploadKey/build_log_plus_in_name1990=== CONT TestPendingClosureWriteTimeout/empty1991--- PASS: TestIsValidUploadKey (0.00s)1992 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1993 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1994 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1995 --- PASS: TestIsValidUploadKey/absolute (0.00s)1996 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1997 --- PASS: TestIsValidUploadKey/traversal (0.00s)1998 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1999 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2000 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2001 --- PASS: TestIsValidUploadKey/index.html (0.00s)2002 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2003 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2004 --- PASS: TestIsValidUploadKey/realisation (0.00s)2005 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2006 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2007 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2008 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2009 --- PASS: TestIsValidUploadKey/build_log (0.00s)2010 --- PASS: TestIsValidUploadKey/listing (0.00s)2011 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2012 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2013 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2014=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline20152026/10/05 12:09:46 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"2016--- PASS: TestPush_RejectsBadRequests (2.29s)2017 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2018 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2019 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2020 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2021--- PASS: TestService_AuthMiddleware_OIDC (2.36s)2022 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2023 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2024 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2025 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)20262026/10/05 12:09:46 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=407.809964ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20272026/10/05 12:09:46 INFO Received uploads request method=POST path=/api/pending_closures20282026/10/05 12:09:46 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772162029--- PASS: TestReadProxyNarinfo (4.00s)2030=== CONT TestPendingClosureWriteTimeout/670k_objects2031=== CONT TestPendingClosureWriteTimeout/400_objects2032=== CONT TestProxyWriteTimeout/narinfo2033=== CONT TestProxyWriteTimeout/1_GiB_nar2034=== CONT TestProxyWriteTimeout/unknown_size2035=== CONT TestProxyWriteTimeout/10_GiB_nar2036=== CONT TestParseSingleRange/unknown_unit2037--- PASS: TestProxyWriteTimeout (0.00s)2038 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2039 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2040 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2041 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2042=== CONT TestParseSingleRange/closed2043=== CONT TestParseSingleRange/start_far_past_EOF2044=== CONT TestParseSingleRange/start_past_EOF2045=== CONT TestParseSingleRange/single_byte2046=== CONT TestParseSingleRange/suffix2047=== CONT TestParseSingleRange/end_clamped_to_size2048=== CONT TestParseSingleRange/suffix_exceeds_size2049=== CONT TestParseSingleRange/malformed_end_before_start2050=== CONT TestParseSingleRange/none2051=== CONT TestParseSingleRange/open-ended2052=== CONT TestParseSingleRange/malformed_both_empty2053=== CONT TestParseSingleRange/multi-range_ignored2054=== CONT TestParseSingleRange/malformed_no_dash2055=== CONT TestService_RequireScope_OIDC/builder_may_write2056--- PASS: TestParseSingleRange (0.00s)2057 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2058 --- PASS: TestParseSingleRange/closed (0.00s)2059 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2060 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2061 --- PASS: TestParseSingleRange/single_byte (0.00s)2062 --- PASS: TestParseSingleRange/suffix (0.00s)2063 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2064 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2065 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2066 --- PASS: TestParseSingleRange/none (0.00s)2067 --- PASS: TestParseSingleRange/open-ended (0.00s)2068 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2069 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2070 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2071=== CONT TestService_RequireScope_OIDC/reader_may_read2072=== CONT TestService_RequireScope_OIDC/static_token_may_admin2073=== CONT TestService_RequireScope_OIDC/static_token_may_write2074=== CONT TestService_RequireScope_OIDC/ops_may_not_write2075=== CONT TestService_RequireScope_OIDC/writer_implies_read2076=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2077=== CONT TestService_RequireScope_OIDC/reader_may_not_write2078=== CONT TestService_RequireScope_OIDC/ops_may_admin2079=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2080=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2081=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2082=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2083=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read20842026/10/05 12:09:46 WARN Authentication failed token_preview=wrong token_length=5 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2085=== CONT TestCacheConfigHandler/full_config,_no_issuer2086=== CONT TestCacheConfigHandler/no_signing_keys2087=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2088=== CONT TestCacheConfigHandler/no_cache_url_configured2089=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart20902026/10/05 12:09:46 INFO Received complete multipart upload request method=POST path=/2091--- PASS: TestCacheConfigHandler (0.00s)2092 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2093 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2094 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2095 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2096--- PASS: TestService_RequireScope_OIDC (2.22s)2097 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2098 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2099 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2100 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2101 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2102 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2103 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2104 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2105 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2106 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2107 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2108 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2109 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2110 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)21112026/10/05 12:09:46 INFO Received uploads request method=POST path=/api/pending_closures21122026/10/05 12:09:46 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=726.667192ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2113=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts21142026/10/05 12:09:46 INFO Received request for more parts method=POST path=/21152026/10/05 12:09:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2116=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure21172026/10/05 12:09:46 INFO Received uploads request method=POST path=/21182026/10/05 12:09:46 INFO Received uploads request method=POST path=/api/pending_closures21192026/10/05 12:09:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21202026/10/05 12:09:47 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjFlODMyMTktMmE1ZS00NWRkLTliZjgtNWFlYTIzYzNmYTViLjhhNzA2ZDQwLWZjMzUtNDc5YS1iMDliLTAxNzEyMDVlZjRhMHgxNzkxMjAyMTg2OTQ2MDk0MDAw21212026/10/05 12:09:47 INFO Received uploads request method=POST path=/api/pending_closures21222026/10/05 12:09:47 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjFlODMyMTktMmE1ZS00NWRkLTliZjgtNWFlYTIzYzNmYTViLjhhNzA2ZDQwLWZjMzUtNDc5YS1iMDliLTAxNzEyMDVlZjRhMHgxNzkxMjAyMTg2OTQ2MDk0MDAw error="Delete \"http://localhost:56127/bucket90/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=YjFlODMyMTktMmE1ZS00NWRkLTliZjgtNWFlYTIzYzNmYTViLjhhNzA2ZDQwLWZjMzUtNDc5YS1iMDliLTAxNzEyMDVlZjRhMHgxNzkxMjAyMTg2OTQ2MDk0MDAw\": injected: abort refused"21232026/10/05 12:09:47 INFO Aborted multipart uploads count=0 kept=021242026/10/05 12:09:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21252026/10/05 12:09:47 WARN Force mode enabled - objects will be deleted immediately without grace period21262026/10/05 12:09:47 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjFlODMyMTktMmE1ZS00NWRkLTliZjgtNWFlYTIzYzNmYTViLjhhNzA2ZDQwLWZjMzUtNDc5YS1iMDliLTAxNzEyMDVlZjRhMHgxNzkxMjAyMTg2OTQ2MDk0MDAw21272026/10/05 12:09:47 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YjFlODMyMTktMmE1ZS00NWRkLTliZjgtNWFlYTIzYzNmYTViLjhhNzA2ZDQwLWZjMzUtNDc5YS1iMDliLTAxNzEyMDVlZjRhMHgxNzkxMjAyMTg2OTQ2MDk0MDAw parts=12128--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (3.37s)2129=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal21302026/10/05 12:09:47 INFO Received uploads request method=POST path=/2131=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key21322026/10/05 12:09:47 INFO Received request for more parts method=POST path=/2133=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key21342026/10/05 12:09:47 INFO Received complete multipart upload request method=POST path=/2135=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info21362026/10/05 12:09:47 INFO Received uploads request method=POST path=/2137=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete2138--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2139 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2140 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2141 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2142 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)21432026/10/05 12:09:47 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=021442026/10/05 12:09:47 INFO Vacuumed table table=pending_closures21452026/10/05 12:09:47 INFO Vacuumed table table=pending_objects21462026/10/05 12:09:47 INFO Vacuumed table table=multipart_uploads21472026/10/05 12:09:47 INFO Vacuumed table table=closures21482026/10/05 12:09:47 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.601672257s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21492026/10/05 12:09:47 INFO Vacuumed table table=objects2150=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark21512026/10/05 12:09:47 INFO Received uploads request method=POST path=/api/pending_closures21522026/10/05 12:09:47 INFO Aborted multipart uploads count=0 kept=021532026/10/05 12:09:47 WARN Force mode enabled - objects will be deleted immediately without grace period21542026/10/05 12:09:47 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=021552026/10/05 12:09:47 INFO Vacuumed table table=pending_closures21562026/10/05 12:09:47 INFO Vacuumed table table=pending_objects21572026/10/05 12:09:47 INFO Vacuumed table table=multipart_uploads21582026/10/05 12:09:47 INFO Vacuumed table table=closures21592026/10/05 12:09:47 INFO Vacuumed table table=objects2160=== CONT TestGCEndsOnShutdown/before_the_run2161--- PASS: TestForceGCDuringPushOffersSweptObject (0.01s)2162 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (3.12s)2163 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (2.62s)21642026/10/05 12:09:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21652026/10/05 12:09:47 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YjFlODMyMTktMmE1ZS00NWRkLTliZjgtNWFlYTIzYzNmYTViLjdhNWY0NmUyLTE0NTYtNDE1MS1hZWQ5LTQxNTRjY2U2Yjk5M3gxNzkxMjAyMTg2MjQwMzA3MDAw parts=1221662026/10/05 12:09:47 INFO Received uploads request method=POST path=/api/pending_closures2167--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.85s)21682026/10/05 12:09:48 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21692026/10/05 12:09:48 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21702026/10/05 12:09:48 INFO Received uploads request method=POST path=/api/pending_closures21712026/10/05 12:09:48 INFO Aborted multipart uploads count=0 kept=021722026/10/05 12:09:48 WARN Force mode enabled - objects will be deleted immediately without grace period21732026/10/05 12:09:48 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:56127/bucket96/?delete=\": context canceled"21742026/10/05 12:09:48 INFO Aborted multipart uploads count=0 kept=021752026/10/05 12:09:48 WARN Force mode enabled - objects will be deleted immediately without grace period21762026-10-05 12:09:48.821 UTC [97668] ERROR: canceling statement due to user request21772026-10-05 12:09:48.821 UTC [97668] STATEMENT: -- name: MarkStaleObjects :execrows2178 WITH RECURSIVE ct AS (2179 SELECT timezone('UTC', now()) AS now2180 ),2181 closure_reach AS (2182 -- Start with all closure keys2183 SELECT o.key, o.refs2184 FROM objects o2185 INNER JOIN closures c ON o.key = c.key2186 UNION2187 -- Recursively add all referenced objects2188 SELECT o.key, o.refs2189 FROM objects o2190 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2191 ),2192 reachable_objects AS (2193 SELECT DISTINCT key FROM closure_reach2194 ),2195 stale_objects AS (2196 SELECT o.key2197 FROM objects AS o, ct2198 WHERE2199 NOT EXISTS (2200 SELECT 12201 FROM reachable_objects ro2202 WHERE ro.key = o.key2203 )2204 AND NOT EXISTS (2205 SELECT 12206 FROM pending_objects AS po2207 WHERE po.key = o.key2208 )2209 AND o.deleted_at IS NULL -- Only mark fresh objects2210 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2211 FOR UPDATE2212 )2213 UPDATE objects2214 SET2215 deleted_at = ct.now,2216 first_deleted_at = COALESCE(first_deleted_at, ct.now)2217 FROM stale_objects, ct2218 WHERE objects.key = stale_objects.key2219 2220--- PASS: TestGCEndsOnShutdown (0.00s)2221 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (1.44s)2222 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (1.43s)2223 --- PASS: TestGCEndsOnShutdown/before_the_run (1.24s)22242026/10/05 12:09:48 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22252026/10/05 12:09:49 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=189.858895ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2226--- PASS: TestPendingClosureWriteTimeout (0.00s)2227 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2228 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2229 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2230 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (3.10s)22312026/10/05 12:09:49 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=394.020984ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22322026/10/05 12:09:49 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=729.963796ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22332026/10/05 12:09:50 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.454996364s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22342026/10/05 12:09:50 WARN Rate limiter enabled after throttle name=s3-test rate=522352026/10/05 12:09:50 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2236=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2237 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102238 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002239--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (7.31s)2240--- PASS: TestUploadHandlersRejectOversizedBody (0.06s)2241 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.27s)2242 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.27s)2243 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (4.23s)22442026/10/05 12:09:51 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 [::1]:19999: connect: connection refused"22452026/10/05 12:09:51 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22462026/10/05 12:09:51 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=215.478577ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22472026/10/05 12:09:52 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=374.05298ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22482026/10/05 12:09:52 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=761.627885ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22492026/10/05 12:09:53 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.556534264s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22502026/10/05 12:09:54 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22512026/10/05 12:09:54 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=218.975523ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22522026/10/05 12:09:55 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=419.907091ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22532026/10/05 12:09:55 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=769.892759ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22542026/10/05 12:09:56 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.444289275s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2255--- PASS: TestClientErrorHandling (0.00s)2256 --- PASS: TestClientErrorHandling/InvalidStorePath (2.51s)2257 --- PASS: TestClientErrorHandling/InvalidAuthToken (2.99s)2258 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.19s)2259FAIL2260{"timestamp":"2026-10-05T12:09:57.821737Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:56560","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}2261{"timestamp":"2026-10-05T12:09:57.822589Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:56559","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}22622026-10-05 12:09:57.971 UTC [97072] LOG: received smart shutdown request22632026-10-05 12:09:57.972 UTC [97072] LOG: background worker "logical replication launcher" (PID 97082) exited with exit code 122642026-10-05 12:09:58.008 UTC [97077] LOG: shutting down22652026-10-05 12:09:58.008 UTC [97077] LOG: checkpoint starting: shutdown immediate22662026-10-05 12:09:59.350 UTC [97077] LOG: checkpoint complete: wrote 12966 buffers (79.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 29 recycled; write=0.717 s, sync=0.580 s, total=1.343 s; sync files=33697, longest=0.001 s, average=0.001 s; distance=479684 kB, estimate=479684 kB; lsn=0/1EBFE1E8, redo lsn=0/1EBFE1E822672026-10-05 12:09:59.357 UTC [97072] LOG: database system is shut down