niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #446
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure18=== PAUSE TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure19=== RUN TestUploadMultipart_PartsInParallel20=== PAUSE TestUploadMultipart_PartsInParallel21=== RUN TestUploadMultipart_FailedPartBufferNotReused22=== PAUSE TestUploadMultipart_FailedPartBufferNotReused23=== RUN TestUploadMultipart_ProducerErrorIsNotEOF24=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestUploadMultipart_SupersededByPeer28=== PAUSE TestUploadMultipart_SupersededByPeer29=== RUN TestDumpPathCaseHackMatchesNix30--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)31=== RUN TestDumpPathCaseHackCollision32--- PASS: TestDumpPathCaseHackCollision (0.00s)33=== RUN TestSupersededNARStillUploadsListing34=== PAUSE TestSupersededNARStillUploadsListing35=== RUN TestTruncatedNARDumpIsNotCompleted36=== PAUSE TestTruncatedNARDumpIsNotCompleted37=== RUN TestDumpPathMatchesNix38=== PAUSE TestDumpPathMatchesNix39=== RUN TestDumpPathSingleFile40=== PAUSE TestDumpPathSingleFile41=== RUN TestDumpPathWriterError42=== PAUSE TestDumpPathWriterError43=== RUN TestDumpPathWriterErrorStopsReading44 nar_test.go:289: read 24690 of 32768000 bytes45--- PASS: TestDumpPathWriterErrorStopsReading (0.58s)46=== RUN TestEncodeNixBase3247=== PAUSE TestEncodeNixBase3248=== RUN TestEncodeNixBase32WithRealHash49=== PAUSE TestEncodeNixBase32WithRealHash50=== RUN TestConvertHashToNix3251=== PAUSE TestConvertHashToNix3252=== RUN TestGetStorePathHash53=== PAUSE TestGetStorePathHash54=== RUN TestPathInfoHashCompatibility55=== PAUSE TestPathInfoHashCompatibility56=== RUN TestParsePathInfoJSON57=== PAUSE TestParsePathInfoJSON58=== RUN TestParsePathInfoJSONMultiplePaths59=== PAUSE TestParsePathInfoJSONMultiplePaths60=== RUN TestPathInfoCACompatibility61=== PAUSE TestPathInfoCACompatibility62=== RUN TestUploadPendingObjectsStopsStartingAfterFailure63--- PASS: TestUploadPendingObjectsStopsStartingAfterFailure (0.02s)64=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent65=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent66=== RUN TestCompletePendingClosure_NotFoundWithoutKey67=== PAUSE TestCompletePendingClosure_NotFoundWithoutKey68=== RUN TestRateLimiterFeedback69=== PAUSE TestRateLimiterFeedback70=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess71=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess72=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer73=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer74=== RUN TestResolveStorePath75=== PAUSE TestResolveStorePath76=== RUN TestDoWithRetry_BodyReplayedViaGetBody77=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody78=== RUN TestRetryTimeoutOutlastsMaxRetries79=== PAUSE TestRetryTimeoutOutlastsMaxRetries80=== RUN TestDoWithRetry_FinalResponseBodyReadable81=== PAUSE TestDoWithRetry_FinalResponseBodyReadable82=== RUN TestShellSplit83=== PAUSE TestShellSplit84=== RUN TestShellSplitErrors85=== PAUSE TestShellSplitErrors86=== RUN TestStreamPushReportsEveryPath87=== PAUSE TestStreamPushReportsEveryPath88=== RUN TestStreamPushBatchesUnderLoad89=== PAUSE TestStreamPushBatchesUnderLoad90=== RUN TestStreamPushIsolatesFailures91=== PAUSE TestStreamPushIsolatesFailures92=== RUN TestStreamPushGivesUpOnDeadServer93=== PAUSE TestStreamPushGivesUpOnDeadServer94=== RUN TestStreamPushRequestLine95=== PAUSE TestStreamPushRequestLine96=== RUN TestStreamPushReportsSignatures97=== PAUSE TestStreamPushReportsSignatures98=== RUN TestStreamPushReportsSkippedPaths99=== PAUSE TestStreamPushReportsSkippedPaths100=== RUN TestClientSignaturesByStorePath101=== PAUSE TestClientSignaturesByStorePath102=== RUN TestStreamPushStopsWhenCanceled103=== PAUSE TestStreamPushStopsWhenCanceled104=== RUN TestStreamPushStopsOnCancel105=== PAUSE TestStreamPushStopsOnCancel106=== RUN TestStreamPushStartsNothingOnSlotFreedByCancel107=== PAUSE TestStreamPushStartsNothingOnSlotFreedByCancel108=== RUN TestSetClientTLS109=== PAUSE TestSetClientTLS110=== RUN TestSetClientTLSDoesNotMutateDefaultTransport111=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport112=== RUN TestSetClientTLSErrors113=== PAUSE TestSetClientTLSErrors114=== RUN TestStaticToken115=== PAUSE TestStaticToken116=== RUN TestFileTokenReadsAndCaches117=== PAUSE TestFileTokenReadsAndCaches118=== RUN TestFileTokenMissing119=== PAUSE TestFileTokenMissing120=== RUN TestFileTokenEmpty121=== PAUSE TestFileTokenEmpty122=== RUN TestScriptTokenNoExpiryRerunsEveryCall123=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall124=== RUN TestScriptTokenCachesUntilRefresh125=== PAUSE TestScriptTokenCachesUntilRefresh126=== RUN TestScriptTokenEmptyToken127=== PAUSE TestScriptTokenEmptyToken128=== RUN TestScriptTokenBadJSON129=== PAUSE TestScriptTokenBadJSON130=== RUN TestScriptTokenScriptFails131=== PAUSE TestScriptTokenScriptFails132=== RUN TestScriptTokenEmptyCommand133=== PAUSE TestScriptTokenEmptyCommand134=== RUN TestScriptTokenDoesNotWaitForItsChildren135=== PAUSE TestScriptTokenDoesNotWaitForItsChildren136=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry137=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer138=== CONT TestShellSplitErrors139=== CONT TestScriptTokenNoExpiryRerunsEveryCall140=== CONT TestScriptTokenScriptFails141=== CONT TestDumpPathSingleFile142=== CONT TestScriptTokenEmptyCommand143=== CONT TestStreamPushBatchesUnderLoad144=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess145=== CONT TestScriptTokenCachesUntilRefresh146=== CONT TestStreamPushReportsSkippedPaths147=== CONT TestStreamPushReportsSignatures148=== CONT TestStreamPushGivesUpOnDeadServer149=== CONT TestRateLimiterFeedback150=== RUN TestRateLimiterFeedback/429_enables_limiter151=== CONT TestStreamPushRequestLine152=== CONT TestParsePathInfoJSON153=== CONT TestConvertHashToNix32154=== CONT TestDoWithRetry_BodyReplayedViaGetBody155=== CONT TestUploadMultipart_PartsInParallel156=== CONT TestFileTokenMissing157=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure158=== CONT TestFilterOversizedClosures159=== CONT TestStreamPushStopsOnCancel160=== CONT TestFileTokenReadsAndCaches161=== CONT TestDumpPathMatchesNix162--- PASS: TestShellSplitErrors (0.00s)163=== CONT TestUploadMultipart_SupersededByPeer164=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false165=== PAUSE TestRateLimiterFeedback/429_enables_limiter166=== RUN TestRateLimiterFeedback/503_enables_limiter167=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false168=== PAUSE TestRateLimiterFeedback/503_enables_limiter169=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true170=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter171=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true172=== RUN TestParsePathInfoJSON/Nix_format173=== RUN TestConvertHashToNix32/SRI_format_to_Nix32174=== RUN TestStreamPushStopsOnCancel/waiting_for_input175=== RUN TestFilterOversizedClosures/no_limit_keeps_everything176=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32177=== RUN TestUploadMultipart_SupersededByPeer/exists178--- PASS: TestScriptTokenEmptyCommand (0.00s)179=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter180=== CONT TestSetClientTLS181=== CONT TestUploadMultipart_ProducerErrorIsNotEOF182=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input183=== CONT TestFileTokenEmpty184=== PAUSE TestParsePathInfoJSON/Nix_format185=== RUN TestConvertHashToNix32/already_Nix32_format186--- PASS: TestFileTokenMissing (0.00s)187=== PAUSE TestUploadMultipart_SupersededByPeer/exists188=== RUN TestParsePathInfoJSON/Lix_format189=== RUN TestUploadMultipart_SupersededByPeer/missing190=== CONT TestSetClientTLSDoesNotMutateDefaultTransport191=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part192=== CONT TestStreamPushStopsWhenCanceled193=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot194=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter195=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot196=== CONT TestPartSizeForNAR197=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything198--- PASS: TestStreamPushReportsSkippedPaths (0.00s)199=== PAUSE TestConvertHashToNix32/already_Nix32_format200=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped201=== PAUSE TestUploadMultipart_SupersededByPeer/missing202=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped203=== CONT TestStreamPushReportsEveryPath204=== RUN TestFilterOversizedClosures/all_closures_skipped205=== CONT TestScriptTokenBadJSON206=== PAUSE TestFilterOversizedClosures/all_closures_skipped207=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part208=== CONT TestStreamPushStartsNothingOnSlotFreedByCancel209=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary210=== CONT TestCompletePendingClosure_NotFoundWithoutKey211=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter212=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot213=== CONT TestClientSignaturesByStorePath214=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot215=== RUN TestPartSizeForNAR/zero_stays_at_minimum216--- PASS: TestFileTokenReadsAndCaches (0.00s)217=== RUN TestConvertHashToNix32/invalid_format218=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent219=== PAUSE TestParsePathInfoJSON/Lix_format220=== PAUSE TestConvertHashToNix32/invalid_format221=== RUN TestParsePathInfoJSON/empty_input222=== CONT TestDoWithRetry_FinalResponseBodyReadable223=== PAUSE TestParsePathInfoJSON/empty_input224=== CONT TestResolveStorePath225=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot226=== RUN TestParsePathInfoJSON/whitespace_only227--- PASS: TestScriptTokenScriptFails (0.02s)228=== PAUSE TestParsePathInfoJSON/whitespace_only229=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum230=== CONT TestPathInfoCACompatibility231=== RUN TestPathInfoCACompatibility/null_ca_field232=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary233=== CONT TestStreamPushIsolatesFailures234=== PAUSE TestPathInfoCACompatibility/null_ca_field235=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot236=== RUN TestParsePathInfoJSON/invalid_JSON237=== CONT TestPathInfoHashCompatibility238=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot239=== CONT TestParsePathInfoJSONMultiplePaths240=== CONT TestScriptTokenDoesNotWaitForItsChildren241=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot242=== CONT TestShellSplit243=== CONT TestEncodeNixBase32244=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken245--- PASS: TestStreamPushReportsSignatures (0.01s)246=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken247=== RUN TestPathInfoCACompatibility/old_string_format_-_text248=== RUN TestPartSizeForNAR/small_stays_at_minimum249=== PAUSE TestParsePathInfoJSON/invalid_JSON250=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)251=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier252=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths253=== CONT TestGetStorePathHash254=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs255=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths256=== CONT TestRetryTimeoutOutlastsMaxRetries257=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths258=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths259=== RUN TestEncodeNixBase32/test_string_hash260=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun261=== PAUSE TestEncodeNixBase32/test_string_hash262--- PASS: TestFileTokenEmpty (0.00s)263=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text264=== CONT TestDoServerRequestAttachesToken265=== CONT TestEncodeNixBase32WithRealHash266=== PAUSE TestPartSizeForNAR/small_stays_at_minimum267=== CONT TestRegisterUploadedObjectReusesConnections268=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum269=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)270=== CONT TestTruncatedNARDumpIsNotCompleted271=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier272=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica273=== RUN TestGetStorePathHash/valid_store_path274=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs275=== RUN TestEncodeNixBase32/empty_input276=== PAUSE TestGetStorePathHash/valid_store_path277--- PASS: TestStreamPushStopsWhenCanceled (0.00s)278=== RUN TestGetStorePathHash/basename_without_hyphen_should_error279--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)280=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error281=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive282--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)283=== CONT TestSupersededNARStillUploadsListing284=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum285=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon286=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon287=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up288=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout289=== PAUSE TestEncodeNixBase32/empty_input290=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error291=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout292=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive293--- PASS: TestStreamPushReportsEveryPath (0.00s)294--- PASS: TestClientSignaturesByStorePath (0.00s)295--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.02s)296=== CONT TestStaticToken297=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts298=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up299=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI300=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI301=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier302=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error303=== CONT TestSetClientTLSErrors304=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier305=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error306=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client307--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.00s)308=== RUN TestPathInfoCACompatibility/new_structured_format_-_text309=== CONT TestScriptTokenEmptyToken310=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts311=== RUN TestSupersededNARStillUploadsListing/small_NAR312=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512313=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error314=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client315=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512316=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client317=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client318=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text319=== RUN TestPartSizeForNAR/1_TiB320=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method321=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false322=== CONT TestCaseHackSuffix323=== PAUSE TestSupersededNARStillUploadsListing/small_NAR324=== RUN TestSupersededNARStillUploadsListing/dump_cut_short325=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method326=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true327--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)328=== PAUSE TestPartSizeForNAR/1_TiB329--- PASS: TestStreamPushIsolatesFailures (0.00s)330=== RUN TestPartSizeForNAR/5_TiB_S3_max_object331=== CONT TestUploadMultipart_FailedPartBufferNotReused332=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short333=== CONT TestUploadMultipart_SupersededByPeer/missing334=== CONT TestDumpPathWriterError335=== CONT TestFilterOversizedClosures/no_limit_keeps_everything336=== CONT TestFilterOversizedClosures/all_closures_skipped337=== CONT TestUploadMultipart_SupersededByPeer/exists338=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter339=== CONT TestRateLimiterFeedback/429_enables_limiter340=== CONT TestRateLimiterFeedback/503_enables_limiter341--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)342=== RUN TestSetClientTLSErrors/missing_cert_file343=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object344=== PAUSE TestSetClientTLSErrors/missing_cert_file345=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped346=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails347--- PASS: TestShellSplit (0.00s)348--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)349--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)350=== RUN TestPartSizeForNAR/capped_at_5_GiB351=== PAUSE TestPartSizeForNAR/capped_at_5_GiB352=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter353=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails354--- PASS: TestResolveStorePath (0.00s)355--- PASS: TestEncodeNixBase32WithRealHash (0.00s)356=== RUN TestSetClientTLSErrors/missing_key_file357=== CONT TestConvertHashToNix32/invalid_format358=== CONT TestConvertHashToNix32/already_Nix32_format359=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part360=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary361=== CONT TestConvertHashToNix32/SRI_format_to_Nix32362=== RUN TestSetClientTLS/rejects_connection_without_client_cert363=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert364--- PASS: TestScriptTokenBadJSON (0.01s)365=== PAUSE TestSetClientTLSErrors/missing_key_file366=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken367=== CONT TestParsePathInfoJSON/invalid_JSON368=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA369=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot370=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot371--- PASS: TestStaticToken (0.00s)372--- PASS: TestDoServerRequestAttachesToken (0.15s)373=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot374=== RUN TestSetClientTLSErrors/missing_ca_file375=== CONT TestStreamPushStopsOnCancel/waiting_for_input376=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot377=== CONT TestParsePathInfoJSON/Lix_format378=== CONT TestParsePathInfoJSON/whitespace_only379=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA380--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.15s)381=== PAUSE TestSetClientTLSErrors/missing_ca_file382=== RUN TestSetClientTLS/preserves_debug_logging_transport383=== CONT TestParsePathInfoJSON/empty_input384--- PASS: TestScriptTokenEmptyToken (0.01s)385=== RUN TestSetClientTLSErrors/invalid_ca_file386--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.16s)387=== PAUSE TestSetClientTLSErrors/invalid_ca_file388=== PAUSE TestSetClientTLS/preserves_debug_logging_transport389=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths390=== CONT TestParsePathInfoJSON/Nix_format391=== CONT TestEncodeNixBase32/test_string_hash392--- PASS: TestFilterOversizedClosures (0.01s)393 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)394 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)395 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)396=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths397=== CONT TestEncodeNixBase32/empty_input398=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs399=== CONT TestGetStorePathHash/basename_without_hyphen_should_error400=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512401=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout402=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier403=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error404=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error405=== CONT TestGetStorePathHash/valid_store_path406=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client407=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client408=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon409=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)410=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up411=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier412--- PASS: TestDumpPathSingleFile (0.47s)413--- PASS: TestCaseHackSuffix (0.30s)414--- PASS: TestStreamPushBatchesUnderLoad (0.01s)415 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)416 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)417--- PASS: TestConvertHashToNix32 (0.01s)418 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)419 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)420 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)421--- PASS: TestRateLimiterFeedback (0.01s)422 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)423 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)424 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.29s)425 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.28s)426--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)427 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)428 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.29s)429--- PASS: TestParsePathInfoJSON (0.01s)430 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)431 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)432 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)433 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)434 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)435=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI436--- PASS: TestEncodeNixBase32 (0.15s)437 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)438 --- PASS: TestEncodeNixBase32/empty_input (0.00s)439--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)440 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)441 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)442--- PASS: TestGetStorePathHash (0.15s)443 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)444 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)445 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)446 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)447=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive448--- PASS: TestPathInfoHashCompatibility (0.15s)449 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)450 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)451 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)452 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)453=== CONT TestPathInfoCACompatibility/new_structured_format_-_text454=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method455--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.15s)456 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.00s)457 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.00s)458 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.00s)459 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.01s)460 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.00s)461=== CONT TestPathInfoCACompatibility/old_string_format_-_text462=== CONT TestPathInfoCACompatibility/null_ca_field463=== CONT TestPartSizeForNAR/zero_stays_at_minimum464=== CONT TestPartSizeForNAR/5_TiB_S3_max_object465--- PASS: TestPathInfoCACompatibility (0.15s)466 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)467 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)468 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)469 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)470 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)471=== CONT TestPartSizeForNAR/capped_at_5_GiB472=== CONT TestPartSizeForNAR/1_TiB473=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts474=== CONT TestPartSizeForNAR/small_stays_at_minimum475=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum476=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails477=== CONT TestSupersededNARStillUploadsListing/dump_cut_short478=== CONT TestSupersededNARStillUploadsListing/small_NAR479=== CONT TestSetClientTLSErrors/missing_cert_file480=== CONT TestSetClientTLSErrors/invalid_ca_file481=== CONT TestSetClientTLSErrors/missing_ca_file482=== CONT TestSetClientTLS/rejects_connection_without_client_cert483--- PASS: TestPartSizeForNAR (0.16s)484 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)485 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)486 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)487 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)488 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)489 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)490 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)491--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.48s)492--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.51s)493=== CONT TestSetClientTLSErrors/missing_key_file494=== CONT TestSetClientTLS/preserves_debug_logging_transport495--- PASS: TestSetClientTLSErrors (0.31s)496 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)497 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)498 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)499 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)500=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA501--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.00s)502 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.35s)503 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.62s)504--- PASS: TestStreamPushStopsOnCancel (0.01s)505 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.05s)506 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.05s)507 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.05s)508 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.05s)509 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)510 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.33s)511--- PASS: TestDumpPathWriterError (0.65s)512--- PASS: TestStreamPushStartsNothingOnSlotFreedByCancel (0.82s)513--- PASS: TestSetClientTLS (0.47s)514 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.28s)515 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.28s)516 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.39s)517--- PASS: TestRegisterUploadedObjectReusesConnections (0.92s)518--- PASS: TestStreamPushRequestLine (0.94s)519--- PASS: TestDumpPathMatchesNix (0.95s)520--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)521--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.01s)522--- PASS: TestSupersededNARStillUploadsListing (0.16s)523 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.03s)524 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.30s)525 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.02s)526--- PASS: TestUploadMultipart_PartsInParallel (1.58s)527--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.46s)528--- PASS: TestTruncatedNARDumpIsNotCompleted (1.69s)529--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.15s)530 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.01s)531 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.33s)532PASS533Running server tests...534The files belonging to this database system will be owned by user "nixbld".535This user must also own the server process.536537The database cluster will be initialized with locale "C".538The default database encoding has accordingly been set to "SQL_ASCII".539The default text search configuration will be set to "english".540541Data page checksums are enabled.542543creating directory /build/postgres374956422/data ... ok544creating subdirectories ... ok545selecting dynamic shared memory implementation ... posix546selecting default "max_connections" ... 100547selecting default "shared_buffers" ... 128MB548selecting default time zone ... UTC549creating configuration files ... ok550running bootstrap script ... ok551performing post-bootstrap initialization ... ok552syncing data to disk ... ok553554initdb: warning: enabling "trust" authentication for local connections555initdb: 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.556557Success. You can now start the database server using:558559 pg_ctl -D /build/postgres374956422/data -l logfile start560561/build/postgres374956422:5432 - no response5622026-10-28 14:31:27.721 UTC [170] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit5632026-10-28 14:31:27.722 UTC [170] LOG: listening on Unix socket "/build/postgres374956422/.s.PGSQL.5432"5642026-10-28 14:31:27.727 UTC [177] LOG: database system was shut down at 2026-10-28 14:31:27 UTC5652026-10-28 14:31:27.730 UTC [170] LOG: database system is ready to accept connections566/build/postgres374956422:5432 - accepting connections567{"timestamp":"2026-10-28T14:31:28.027584336Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"3f549ffa-0d05-4958-803f-47bb3b20a7c0","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":502,"threadName":"rustfs-worker","threadId":"ThreadId(398)"}568=== RUN TestService_AuthMiddleware569=== PAUSE TestService_AuthMiddleware570=== RUN TestService_AuthMiddleware_MTLSProxyHeader571=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader572=== RUN TestService_AuthMiddleware_MTLSBoundSubjects573=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects574=== RUN TestService_ReadAuthMiddleware575=== PAUSE TestService_ReadAuthMiddleware576=== RUN TestService_AuthMiddleware_OIDC577=== PAUSE TestService_AuthMiddleware_OIDC578=== RUN TestService_RequireScope_OIDC579=== PAUSE TestService_RequireScope_OIDC580=== RUN TestService_ReadScope_PublicByDefault581=== PAUSE TestService_ReadScope_PublicByDefault582=== RUN TestCacheConfigHandler583=== PAUSE TestCacheConfigHandler584=== RUN TestCacheStatsHandler585=== PAUSE TestCacheStatsHandler586=== RUN TestClientCADerivations587=== PAUSE TestClientCADerivations588=== RUN TestClientErrorHandling589=== PAUSE TestClientErrorHandling590=== RUN TestClientIntegration591=== PAUSE TestClientIntegration592=== RUN TestClientMultipleUploads593=== PAUSE TestClientMultipleUploads594=== RUN TestClientWithDependencies595=== PAUSE TestClientWithDependencies596=== RUN TestClientSharedPathCommittedMidPush597=== PAUSE TestClientSharedPathCommittedMidPush598=== RUN TestPinProtectsFromGC599=== PAUSE TestPinProtectsFromGC600=== RUN TestClientPushesUseOnePush601=== PAUSE TestClientPushesUseOnePush602=== RUN TestClientFallsBackToClosures603=== PAUSE TestClientFallsBackToClosures604=== RUN TestDeleteClosuresRacingPins605=== PAUSE TestDeleteClosuresRacingPins606=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock607=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock608=== RUN TestResolveDBConnectionString609=== PAUSE TestResolveDBConnectionString610=== RUN TestConnectWaitsForAPeerMigration611=== PAUSE TestConnectWaitsForAPeerMigration612=== RUN TestConnectSerialisesConcurrentMigrations613=== PAUSE TestConnectSerialisesConcurrentMigrations614=== RUN TestLeadElectsOneAndHandsOver615=== PAUSE TestLeadElectsOneAndHandsOver616=== RUN TestLeadIncumbentWinsAfterRestart6172026/10/28 14:31:28 INFO lead: acquired remote=192.0.2.1:12346182026/10/28 14:31:28 INFO lead: released remote=192.0.2.1:12346192026/10/28 14:31:28 INFO lead: acquired remote=192.0.2.1:12346202026/10/28 14:31:30 INFO lead: released remote=192.0.2.1:1234621--- PASS: TestLeadIncumbentWinsAfterRestart (1.91s)622=== RUN TestLeadIncumbentAnnouncesAtOnce623=== PAUSE TestLeadIncumbentAnnouncesAtOnce624=== RUN TestLeadEndsOnShutdown625=== PAUSE TestLeadEndsOnShutdown626=== RUN TestLeadEndsWhenItsConnectionHangs6272026/10/28 14:31:30 INFO lead: acquired remote=192.0.2.1:12346282026-10-28 14:31:31.587 UTC [621] FATAL: terminating connection due to administrator command6292026/10/28 14:31:31 INFO lead: acquired remote=192.0.2.1:12346302026/10/28 14:31:32 WARN lead: lock connection lost error="timeout: context deadline exceeded"6312026/10/28 14:31:32 INFO lead: released remote=192.0.2.1:12346322026/10/28 14:31:33 INFO lead: released remote=192.0.2.1:1234633--- PASS: TestLeadEndsWhenItsConnectionHangs (3.15s)634=== RUN TestGCAdvisoryLockBlocksConcurrentRun635=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun636=== RUN TestGCBugBareHashReferences637=== PAUSE TestGCBugBareHashReferences638=== RUN TestGCMetrics639=== PAUSE TestGCMetrics640=== RUN TestPushDedupSurvivesConcurrentGC641=== PAUSE TestPushDedupSurvivesConcurrentGC642=== RUN TestDeduplicatedObjectsRecordedAsPending643=== PAUSE TestDeduplicatedObjectsRecordedAsPending644=== RUN TestGCSweepSkipsPendingObjects645=== PAUSE TestGCSweepSkipsPendingObjects646=== RUN TestTombstonedObjectOfferedWithoutWaiting647=== PAUSE TestTombstonedObjectOfferedWithoutWaiting648=== RUN TestGCSweepDeliversEachKeyOnce649=== PAUSE TestGCSweepDeliversEachKeyOnce650=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection651=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection652=== RUN TestForceGCDuringPushOffersSweptObject653=== PAUSE TestForceGCDuringPushOffersSweptObject654=== RUN TestFailedS3DeleteKeepsTombstone655=== PAUSE TestFailedS3DeleteKeepsTombstone656=== RUN TestSweepSkipsRowsLockedByPush657=== PAUSE TestSweepSkipsRowsLockedByPush658=== RUN TestRegisterCompletedObjectNeedsPendingRow659=== PAUSE TestRegisterCompletedObjectNeedsPendingRow660=== RUN TestGetExistingObjectsLocksRows661=== PAUSE TestGetExistingObjectsLocksRows662=== RUN TestSweepRechecksPendingAfterLocking663=== PAUSE TestSweepRechecksPendingAfterLocking664=== RUN TestPushWaitsForSweepHoldingRow665=== PAUSE TestPushWaitsForSweepHoldingRow666=== RUN TestCommitRacingPendingCleanupKeepsObjects667=== PAUSE TestCommitRacingPendingCleanupKeepsObjects668=== RUN TestGCEndsOnShutdown669=== PAUSE TestGCEndsOnShutdown670=== RUN TestGCTaskStore_StartNew671=== PAUSE TestGCTaskStore_StartNew672=== RUN TestGCTaskStore_DeduplicateSameParams673=== PAUSE TestGCTaskStore_DeduplicateSameParams674=== RUN TestGCTaskStore_ConflictDifferentParams675=== PAUSE TestGCTaskStore_ConflictDifferentParams676=== RUN TestGCTaskStore_GetEmpty677=== PAUSE TestGCTaskStore_GetEmpty678=== RUN TestGCTaskStore_GetReturnsLatest679=== PAUSE TestGCTaskStore_GetReturnsLatest680=== RUN TestGCTaskStore_CompletedAllowsNewTask681=== PAUSE TestGCTaskStore_CompletedAllowsNewTask682=== RUN TestGCTaskStore_PhaseUpdates683=== PAUSE TestGCTaskStore_PhaseUpdates684=== RUN TestGCTaskStore_Fail685=== PAUSE TestGCTaskStore_Fail686=== RUN TestGracefulShutdownDrainsInflight687=== PAUSE TestGracefulShutdownDrainsInflight688=== RUN TestService_healthCheckHandler689=== PAUSE TestService_healthCheckHandler690=== RUN TestService_readinessHandler691=== PAUSE TestService_readinessHandler692=== RUN TestGenerateLandingPage693=== PAUSE TestGenerateLandingPage694=== RUN TestChildrenInheritRaisedFileLimit695=== PAUSE TestChildrenInheritRaisedFileLimit696=== RUN TestCacheConfigHandlerMaxNarSize697=== PAUSE TestCacheConfigHandlerMaxNarSize698=== RUN TestCreatePendingClosureRejectsOversizedNAR699=== PAUSE TestCreatePendingClosureRejectsOversizedNAR700=== RUN TestNARDeduplicationMetadataUploadBug701=== PAUSE TestNARDeduplicationMetadataUploadBug702=== RUN TestMetricsInventory703=== PAUSE TestMetricsInventory704=== RUN TestMetricsCommit705=== PAUSE TestMetricsCommit706=== RUN TestService_NativeMTLS707=== PAUSE TestService_NativeMTLS708=== RUN TestServerTLSConfig709=== PAUSE TestServerTLSConfig710=== RUN TestMultipartCleanup711=== PAUSE TestMultipartCleanup712=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded713=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded714=== RUN TestPendingCleanupUsesOneCutoff715=== PAUSE TestPendingCleanupUsesOneCutoff716=== RUN TestPendingClosureFailureTracksEveryUpload717=== PAUSE TestPendingClosureFailureTracksEveryUpload718=== RUN TestPendingClosureFailureAbortsItsUploads719=== PAUSE TestPendingClosureFailureAbortsItsUploads720=== RUN TestObjectStatsTrigger721=== PAUSE TestObjectStatsTrigger722=== RUN TestObjectStatsUpdatedOncePerCommit723=== PAUSE TestObjectStatsUpdatedOncePerCommit724=== RUN TestReconnectLeavesObjectsUnlocked725=== PAUSE TestReconnectLeavesObjectsUnlocked726=== RUN TestOrphanedObjectsGC727=== PAUSE TestOrphanedObjectsGC728=== RUN TestOrphanedObjectsGCStressTest729=== PAUSE TestOrphanedObjectsGCStressTest730=== RUN TestCreatePin_ReservedPins731=== PAUSE TestCreatePin_ReservedPins732=== RUN TestConcurrentPinUpdatesAgree733=== PAUSE TestConcurrentPinUpdatesAgree734=== RUN TestCreatePinRejectsBadInput735=== PAUSE TestCreatePinRejectsBadInput736=== RUN TestDeletePinKeepsRowWhenS3Fails737=== PAUSE TestDeletePinKeepsRowWhenS3Fails738=== RUN TestPresentReportsOnlyClosureRoots739=== PAUSE TestPresentReportsOnlyClosureRoots740=== RUN TestPresentRefreshesOnlyStaleClosures741=== PAUSE TestPresentRefreshesOnlyStaleClosures742=== RUN TestPresentNotReportedWhileGCDeletesClosure743=== PAUSE TestPresentNotReportedWhileGCDeletesClosure744=== RUN TestParseSingleRange745=== PAUSE TestParseSingleRange746=== RUN TestProxyHeadersOnlyTrustedOnSocket7472026/10/28 14:31:33 INFO Starting HTTP server address=127.0.0.1:417937482026/10/28 14:31:33 INFO Starting HTTP server address=proxy.sock7492026/10/28 14:31:33 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7502026/10/28 14:31:33 INFO Shutdown signal received, draining in-flight requests timeout=10s751--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.15s)752=== RUN TestIsValidCachePath753=== PAUSE TestIsValidCachePath754=== RUN TestReadProxyNarinfo755=== PAUSE TestReadProxyNarinfo756=== RUN TestReadProxyNarinfoAlreadyDecompressed757=== PAUSE TestReadProxyNarinfoAlreadyDecompressed758=== RUN TestReadProxyContentNegotiation759=== PAUSE TestReadProxyContentNegotiation760=== RUN TestReadProxyNarStreaming761=== PAUSE TestReadProxyNarStreaming762=== RUN TestReadProxy404And429763=== PAUSE TestReadProxy404And429764=== RUN TestReadProxyInvalidPath765=== PAUSE TestReadProxyInvalidPath766=== RUN TestReadProxyHead767=== PAUSE TestReadProxyHead768=== RUN TestReadProxyOutlastsServerWriteTimeout769=== PAUSE TestReadProxyOutlastsServerWriteTimeout770=== RUN TestReadProxyConditionalGet771=== PAUSE TestReadProxyConditionalGet772=== RUN TestReadProxyRootRedirectsToIndexHTML773=== PAUSE TestReadProxyRootRedirectsToIndexHTML774=== RUN TestReadProxyDisabled775=== PAUSE TestReadProxyDisabled776=== RUN TestReadRedirectNar777=== PAUSE TestReadRedirectNar778=== RUN TestReadRedirectKeepsNarinfoProxied779=== PAUSE TestReadRedirectKeepsNarinfoProxied780=== RUN TestReadProxyRangeRequest781=== PAUSE TestReadProxyRangeRequest782=== RUN TestReadRedirectUsesPublicS3URL783=== PAUSE TestReadRedirectUsesPublicS3URL784=== RUN TestPush_OverlappingRootsStoreOneRowPerKey785=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey786=== RUN TestPush_CompleteCommitsEveryRoot787=== PAUSE TestPush_CompleteCommitsEveryRoot788=== RUN TestPush_RepeatedRootCommitsOnce789=== PAUSE TestPush_RepeatedRootCommitsOnce790=== RUN TestPush_CompleteWaitsForCleanupOfThePush791=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush792=== RUN TestPush_RootsAreLockedInByteOrder793=== PAUSE TestPush_RootsAreLockedInByteOrder794=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit795=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit796=== RUN TestPush_RejectsBadRequests797=== PAUSE TestPush_RejectsBadRequests798=== RUN TestPush_SignsNarinfosOfItsPendingObjects799=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects800=== RUN TestRedundantMultipartUpload801=== PAUSE TestRedundantMultipartUpload802=== RUN TestCompleteMultipartUpload_ErrorButObjectExists803=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists804=== RUN TestCompletedNarNotReofferedAcrossClosures805=== PAUSE TestCompletedNarNotReofferedAcrossClosures806=== RUN TestPresignedUploadRegisteredBeforeCommit807=== PAUSE TestPresignedUploadRegisteredBeforeCommit808=== RUN TestService_Rustfstest809=== PAUSE TestService_Rustfstest810=== RUN TestParseSize811=== PAUSE TestParseSize812=== RUN TestSkippedUploadsHandler813=== PAUSE TestSkippedUploadsHandler814=== RUN TestSystemdListenerNotActivated815--- PASS: TestSystemdListenerNotActivated (0.00s)816=== RUN TestWatchdogBeatsWhenHealthy817--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)818=== RUN TestWatchdogSkipsWhenUnhealthy8192026/10/28 14:31:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8202026/10/28 14:31:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8212026/10/28 14:31:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8222026/10/28 14:31:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8232026/10/28 14:31:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8242026/10/28 14:31:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8252026/10/28 14:31:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8262026/10/28 14:31:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8272026/10/28 14:31:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8282026/10/28 14:31:33 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"829--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)830=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle831=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle832=== RUN TestProxyWriteTimeout833=== PAUSE TestProxyWriteTimeout834=== RUN TestPendingClosureWriteTimeout835=== PAUSE TestPendingClosureWriteTimeout836=== RUN TestIsValidUploadKey837=== PAUSE TestIsValidUploadKey838=== RUN TestUploadHandlersRejectInvalidKeys839=== PAUSE TestUploadHandlersRejectInvalidKeys840=== RUN TestUploadHandlersRejectOversizedBody841=== PAUSE TestUploadHandlersRejectOversizedBody842=== RUN TestService_cleanupPendingClosuresHandler843=== PAUSE TestService_cleanupPendingClosuresHandler844=== RUN TestService_createPendingClosureHandler845=== PAUSE TestService_createPendingClosureHandler846=== RUN TestService_verifyS3Integrity847=== PAUSE TestService_verifyS3Integrity848=== RUN TestCompleteMultipartUnregistered849=== PAUSE TestCompleteMultipartUnregistered850=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT851=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT852=== CONT TestPush_CompleteWaitsForCleanupOfThePush853=== CONT TestService_AuthMiddleware854=== CONT TestPush_CompleteCommitsEveryRoot855=== CONT TestPush_RepeatedRootCommitsOnce856=== CONT TestPush_OverlappingRootsStoreOneRowPerKey857=== CONT TestGCTaskStore_GetEmpty858=== CONT TestGCTaskStore_ConflictDifferentParams859=== CONT TestGCTaskStore_DeduplicateSameParams860=== CONT TestGCTaskStore_GetReturnsLatest861=== CONT TestObjectStatsTrigger862=== CONT TestGCEndsOnShutdown863=== CONT TestSweepRechecksPendingAfterLocking864=== CONT TestGCTaskStore_StartNew865=== CONT TestCommitRacingPendingCleanupKeepsObjects866=== CONT TestGCTaskStore_Fail867=== CONT TestGetExistingObjectsLocksRows868=== CONT TestRegisterCompletedObjectNeedsPendingRow869=== CONT TestReadRedirectUsesPublicS3URL870=== CONT TestFailedS3DeleteKeepsTombstone871=== CONT TestReadRedirectKeepsNarinfoProxied872=== CONT TestSweepSkipsRowsLockedByPush873=== CONT TestForceGCDuringPushOffersSweptObject874=== CONT TestReconnectLeavesObjectsUnlocked875=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection876=== CONT TestObjectStatsUpdatedOncePerCommit877=== CONT TestTombstonedObjectOfferedWithoutWaiting878--- PASS: TestGCTaskStore_GetEmpty (0.00s)879=== CONT TestGCSweepDeliversEachKeyOnce880=== CONT TestReadRedirectNar881=== RUN TestGCEndsOnShutdown/before_the_run882=== CONT TestClientSharedPathCommittedMidPush883=== CONT TestReadProxyRangeRequest884=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows885--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)886=== PAUSE TestGCEndsOnShutdown/before_the_run887--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)888=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete889=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows890--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)891=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check892--- PASS: TestGCTaskStore_StartNew (0.00s)893--- PASS: TestGCTaskStore_Fail (0.00s)894=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check895=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete896=== CONT TestClientWithDependencies897=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark898=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark899=== CONT TestGCBugBareHashReferences9002026/10/28 14:31:34 INFO Received push request method=POST path=/api/pushes9012026/10/28 14:31:34 INFO Received uploads request method=POST path=/api/pending_closures9022026/10/28 14:31:34 INFO Aborted multipart uploads count=0 kept=09032026/10/28 14:31:34 WARN Force mode enabled - objects will be deleted immediately without grace period9042026/10/28 14:31:34 INFO Aborted multipart uploads count=0 kept=09052026/10/28 14:31:34 WARN Force mode enabled - objects will be deleted immediately without grace period9062026/10/28 14:31:34 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=09072026/10/28 14:31:34 INFO Vacuumed table table=pending_closures9082026/10/28 14:31:34 INFO Vacuumed table table=pending_objects9092026/10/28 14:31:34 INFO Vacuumed table table=multipart_uploads9102026/10/28 14:31:34 INFO Vacuumed table table=closures9112026/10/28 14:31:34 INFO Vacuumed table table=objects9122026/10/28 14:31:34 INFO Aborted multipart uploads count=0 kept=09132026/10/28 14:31:34 WARN Force mode enabled - objects will be deleted immediately without grace period9142026/10/28 14:31:34 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=09152026/10/28 14:31:34 INFO Vacuumed table table=pending_closures9162026/10/28 14:31:34 INFO Received push request method=POST path=/api/pushes9172026/10/28 14:31:34 INFO Vacuumed table table=pending_objects9182026/10/28 14:31:34 INFO Vacuumed table table=multipart_uploads9192026/10/28 14:31:34 INFO Vacuumed table table=closures9202026/10/28 14:31:34 INFO Vacuumed table table=objects921=== CONT TestServerTLSConfig922--- PASS: TestObjectStatsTrigger (0.83s)923=== RUN TestServerTLSConfig/no_client_CA924=== PAUSE TestServerTLSConfig/no_client_CA925=== RUN TestServerTLSConfig/missing_CA_file926=== PAUSE TestServerTLSConfig/missing_CA_file927=== RUN TestServerTLSConfig/not_a_PEM_file928=== PAUSE TestServerTLSConfig/not_a_PEM_file929=== CONT TestReadProxyNarinfo9302026/10/28 14:31:34 INFO Aborted multipart uploads count=0 kept=09312026/10/28 14:31:34 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=09322026/10/28 14:31:34 INFO Vacuumed table table=pending_closures9332026/10/28 14:31:34 INFO Vacuumed table table=pending_objects9342026/10/28 14:31:34 INFO Vacuumed table table=multipart_uploads9352026/10/28 14:31:34 INFO Vacuumed table table=closures9362026/10/28 14:31:34 INFO Received push request method=POST path=/api/pushes937--- PASS: TestGCSweepDeliversEachKeyOnce (0.85s)938=== CONT TestLeadEndsOnShutdown9392026/10/28 14:31:34 WARN Force mode enabled - objects will be deleted immediately without grace period9402026/10/28 14:31:34 INFO Vacuumed table table=objects9412026/10/28 14:31:34 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."9422026/10/28 14:31:34 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."943--- PASS: TestSweepSkipsRowsLockedByPush (0.87s)944=== CONT TestLeadElectsOneAndHandsOver9452026/10/28 14:31:34 INFO Received push request method=POST path=/api/pushes946=== CONT TestDeletePinKeepsRowWhenS3Fails947--- PASS: TestFailedS3DeleteKeepsTombstone (0.88s)948=== CONT TestConnectSerialisesConcurrentMigrations949--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.94s)9502026/10/28 14:31:34 INFO Aborted multipart uploads count=0 kept=09512026/10/28 14:31:34 WARN Force mode enabled - objects will be deleted immediately without grace period9522026-10-28 14:31:34.667 UTC [761] ERROR: duplicate key value violates unique constraint "pg_type_typname_nsp_index"9532026-10-28 14:31:34.667 UTC [761] DETAIL: Key (typname, typnamespace)=(goose_db_version, 2200) already exists.9542026-10-28 14:31:34.667 UTC [761] STATEMENT: CREATE TABLE goose_db_version (955 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,956 version_id bigint NOT NULL,957 is_applied boolean NOT NULL,958 tstamp timestamp NOT NULL DEFAULT now()959 )960--- PASS: TestReadRedirectUsesPublicS3URL (1.07s)961=== CONT TestRedundantMultipartUpload962=== CONT TestResolveDBConnectionString963--- PASS: TestObjectStatsUpdatedOncePerCommit (1.08s)964=== RUN TestResolveDBConnectionString/flag_wins965=== PAUSE TestResolveDBConnectionString/flag_wins966=== RUN TestResolveDBConnectionString/file_when_flag_empty967=== PAUSE TestResolveDBConnectionString/file_when_flag_empty968=== RUN TestResolveDBConnectionString/missing_file_is_an_error969=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error970=== RUN TestResolveDBConnectionString/PGHOST_allows_empty971=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty972=== RUN TestResolveDBConnectionString/nothing_configured973=== PAUSE TestResolveDBConnectionString/nothing_configured974=== CONT TestPresignedUploadRegisteredBeforeCommit9752026/10/28 14:31:34 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=09762026/10/28 14:31:34 INFO Vacuumed table table=pending_closures9772026/10/28 14:31:34 INFO Vacuumed table table=pending_objects9782026/10/28 14:31:34 INFO Vacuumed table table=multipart_uploads9792026/10/28 14:31:34 INFO Vacuumed table table=closures9802026/10/28 14:31:34 INFO Vacuumed table table=objects981=== CONT TestClientFallsBackToClosures982--- PASS: TestSweepRechecksPendingAfterLocking (1.12s)9832026/10/28 14:31:34 INFO Aborted multipart uploads count=0 kept=09842026/10/28 14:31:34 WARN Force mode enabled - objects will be deleted immediately without grace period9852026/10/28 14:31:34 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=09862026/10/28 14:31:34 INFO Vacuumed table table=pending_closures987--- PASS: TestRegisterCompletedObjectNeedsPendingRow (1.13s)988=== CONT TestCompleteMultipartUpload_ErrorButObjectExists9892026/10/28 14:31:34 INFO Vacuumed table table=pending_objects9902026/10/28 14:31:34 INFO Vacuumed table table=multipart_uploads9912026/10/28 14:31:34 INFO Vacuumed table table=closures9922026/10/28 14:31:34 INFO Vacuumed table table=objects993--- PASS: TestCommitRacingPendingCleanupKeepsObjects (1.17s)994=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT995=== NAME TestClientWithDependencies996 client_integration_test.go:722: Built derivation: /build/TestClientWithDependencies4123479322/001/store/mypr874p6xfjw1y1y5jji2lashypibak-test-script9972026/10/28 14:31:34 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"998--- PASS: TestReadProxyRangeRequest (1.25s)999=== CONT TestPresentNotReportedWhileGCDeletesClosure1000=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1001=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1002=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1003=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1004=== CONT TestParseSingleRange1005=== RUN TestParseSingleRange/none1006=== PAUSE TestParseSingleRange/none1007=== RUN TestParseSingleRange/unknown_unit1008=== PAUSE TestParseSingleRange/unknown_unit1009=== RUN TestParseSingleRange/multi-range_ignored1010=== PAUSE TestParseSingleRange/multi-range_ignored1011=== RUN TestParseSingleRange/malformed_no_dash1012=== PAUSE TestParseSingleRange/malformed_no_dash1013=== RUN TestParseSingleRange/malformed_both_empty1014=== PAUSE TestParseSingleRange/malformed_both_empty1015=== RUN TestParseSingleRange/malformed_end_before_start1016=== PAUSE TestParseSingleRange/malformed_end_before_start1017=== RUN TestParseSingleRange/closed1018=== PAUSE TestParseSingleRange/closed1019=== RUN TestParseSingleRange/open-ended1020=== PAUSE TestParseSingleRange/open-ended1021=== RUN TestParseSingleRange/end_clamped_to_size1022=== PAUSE TestParseSingleRange/end_clamped_to_size1023=== RUN TestParseSingleRange/suffix1024=== PAUSE TestParseSingleRange/suffix1025=== RUN TestParseSingleRange/suffix_exceeds_size1026=== PAUSE TestParseSingleRange/suffix_exceeds_size1027=== RUN TestParseSingleRange/single_byte1028=== PAUSE TestParseSingleRange/single_byte1029=== RUN TestParseSingleRange/start_past_EOF1030=== PAUSE TestParseSingleRange/start_past_EOF1031=== RUN TestParseSingleRange/start_far_past_EOF1032=== PAUSE TestParseSingleRange/start_far_past_EOF1033=== CONT TestOrphanedObjectsGC1034=== CONT TestConnectWaitsForAPeerMigration1035--- PASS: TestService_AuthMiddleware (1.26s)1036=== NAME TestClientWithDependencies1037 client_integration_test.go:724: Found 1 dependencies (including self)10382026/10/28 14:31:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1039--- PASS: TestReconnectLeavesObjectsUnlocked (1.36s)1040=== CONT TestGCSweepSkipsPendingObjects10412026/10/28 14:31:34 INFO Received push request method=POST path=/api/pushes10422026/10/28 14:31:34 INFO Received uploads request method=POST path=/api/pending_closures10432026/10/28 14:31:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10442026/10/28 14:31:34 INFO Uploading mypr874p6xfjw1y1y5jji2lashypibak-test-script (136B)10452026/10/28 14:31:34 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LmFkNmEyNWU0LTZmYjQtNDhjNy1hOWU0LTQyNTBhNzBiMzFhNXgxNzkzMTk3ODk0MzMwNjU1MzA2 parts=101046--- PASS: TestTombstonedObjectOfferedWithoutWaiting (1.40s)10472026/10/28 14:31:35 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"1048=== CONT TestReadProxyContentNegotiation10492026/10/28 14:31:35 WARN Failed to register uploaded object key=log/2lixq39np3r43103v248yyv1y00n8hyw-test-script.drv error="server returned 404: 404 page not found\n"10502026/10/28 14:31:35 WARN Failed to register uploaded object key=mypr874p6xfjw1y1y5jji2lashypibak.ls error="server returned 404: 404 page not found\n"10512026/10/28 14:31:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10522026/10/28 14:31:35 INFO Signed narinfos id=1 count=110532026/10/28 14:31:35 INFO Uploading 1 narinfos10542026/10/28 14:31:35 INFO Received push request method=POST path=/api/pushes1055--- PASS: TestGetExistingObjectsLocksRows (1.44s)1056=== CONT TestDeduplicatedObjectsRecordedAsPending1057--- PASS: TestGCBugBareHashReferences (1.44s)1058=== CONT TestPushDedupSurvivesConcurrentGC10592026/10/28 14:31:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10602026/10/28 14:31:35 INFO Received complete push request method=POST path=/api/pushes/1/complete10612026/10/28 14:31:35 WARN Failed to register uploaded object key=mypr874p6xfjw1y1y5jji2lashypibak.narinfo error="server returned 404: 404 page not found\n"10622026/10/28 14:31:35 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)10632026/10/28 14:31:35 INFO Uploading 5sfiiigsrar24nyiq47qv71dp3dc0f9d-top (224B)10642026/10/28 14:31:35 INFO Uploading 6fwmz40kk68w8qfknsvhafpyxn3nf7yx-shared-dep (136B)10652026/10/28 14:31:35 INFO Completed push id=1 objects=4 duration=9.880049ms10662026/10/28 14:31:35 INFO Upload complete. (133ms)10672026/10/28 14:31:35 INFO Received uploads request method=POST path=/api/pending_closures10682026/10/28 14:31:35 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LjI2NDI5ZWIyLTRhNGYtNDNhNi1hOTIwLWFhODkxNTMwZTA1OHgxNzkzMTk3ODk0NDUwNTM2MTM3 parts=1010692026/10/28 14:31:35 INFO Aborted multipart uploads count=0 kept=010702026/10/28 14:31:35 WARN Failed to register uploaded object key=nar/0gyf7p6j6fvk9c4ha5an3p82ybaw02pr6v7qqk4v61xjymkgc12k.nar.zst error="server returned 404: 404 page not found\n"1071--- PASS: TestReadRedirectNar (1.47s)1072=== CONT TestClientErrorHandling1073=== RUN TestClientErrorHandling/InvalidStorePath1074=== PAUSE TestClientErrorHandling/InvalidStorePath1075=== RUN TestClientErrorHandling/InvalidAuthToken1076=== PAUSE TestClientErrorHandling/InvalidAuthToken1077=== RUN TestClientErrorHandling/ServerNotAvailable1078=== PAUSE TestClientErrorHandling/ServerNotAvailable1079=== CONT TestReadProxyDisabled10802026/10/28 14:31:35 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10812026/10/28 14:31:35 WARN Force mode enabled - objects will be deleted immediately without grace period10822026/10/28 14:31:35 WARN Failed to register uploaded object key=6fwmz40kk68w8qfknsvhafpyxn3nf7yx.ls error="server returned 404: 404 page not found\n"10832026/10/28 14:31:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10842026/10/28 14:31:35 WARN Failed to register uploaded object key=5sfiiigsrar24nyiq47qv71dp3dc0f9d.ls error="server returned 404: 404 page not found\n"10852026/10/28 14:31:35 INFO Signed narinfos id=1 count=210862026/10/28 14:31:35 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=010872026/10/28 14:31:35 INFO Uploading 2 narinfos10882026/10/28 14:31:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10892026/10/28 14:31:35 INFO Vacuumed table table=pending_closures10902026/10/28 14:31:35 INFO Vacuumed table table=pending_objects10912026/10/28 14:31:35 INFO Vacuumed table table=multipart_uploads10922026/10/28 14:31:35 INFO Vacuumed table table=closures10932026/10/28 14:31:35 INFO Vacuumed table table=objects10942026/10/28 14:31:35 INFO Received complete push request method=POST path=/api/pushes/1/complete10952026/10/28 14:31:35 WARN Failed to register uploaded object key=5sfiiigsrar24nyiq47qv71dp3dc0f9d.narinfo error="server returned 404: 404 page not found\n"10962026/10/28 14:31:35 WARN Failed to register uploaded object key=6fwmz40kk68w8qfknsvhafpyxn3nf7yx.narinfo error="server returned 404: 404 page not found\n"1097=== NAME TestClientWithDependencies1098 client_integration_test.go:740: Skipping nix copy test - isolated store (/build/TestClientWithDependencies4123479322/001/store) requires matching store prefix10992026/10/28 14:31:35 INFO Completed push id=1 objects=6 duration=12.848175ms11002026/10/28 14:31:35 INFO Upload complete. (133ms)11012026/10/28 14:31:35 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2Ljg5NzlkN2NiLWQ5NTgtNGI2OC1iZmMwLTllNWU5OWU4ZTY5ZngxNzkzMTk3ODk0NDIyMjAzMzYy parts=1011022026/10/28 14:31:35 INFO lead: acquired remote=192.0.2.1:12341103=== NAME TestClientSharedPathCommittedMidPush1104 client_integration_test.go:803: Retrieved narinfo from S3:1105 StorePath: /build/TestClientSharedPathCommittedMidPush416141443/001/store/6fwmz40kk68w8qfknsvhafpyxn3nf7yx-shared-dep1106 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1107 Compression: zstd1108 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821109 NarSize: 1361110 References: 1111 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1112 client_integration_test.go:803: Retrieved narinfo from S3:1113 StorePath: /build/TestClientSharedPathCommittedMidPush416141443/001/store/5sfiiigsrar24nyiq47qv71dp3dc0f9d-top1114 URL: nar/0gyf7p6j6fvk9c4ha5an3p82ybaw02pr6v7qqk4v61xjymkgc12k.nar.zst1115 Compression: zstd1116 NarHash: sha256:0gyf7p6j6fvk9c4ha5an3p82ybaw02pr6v7qqk4v61xjymkgc12k1117 NarSize: 2241118 References: /build/TestClientSharedPathCommittedMidPush416141443/001/store/6fwmz40kk68w8qfknsvhafpyxn3nf7yx-shared-dep1119 CA: text:sha256:19zfl6gma3k4xxszzdw6lm9g3jm89mpdv6mq95jx4fgl4pny6h1411202026/10/28 14:31:35 INFO lead: acquired remote=192.0.2.1:12341121--- PASS: TestClientWithDependencies (1.55s)1122=== CONT TestReadProxyConditionalGet1123--- PASS: TestClientSharedPathCommittedMidPush (1.59s)1124=== CONT TestPendingClosureFailureAbortsItsUploads1125--- PASS: TestReadRedirectKeepsNarinfoProxied (1.59s)1126=== CONT TestGCMetrics11272026/10/28 14:31:35 INFO Received create pin request method=POST path=/api/pins/app11282026/10/28 14:31:35 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo11292026/10/28 14:31:35 INFO Received delete pin request method=DELETE path=/api/pins/app11302026/10/28 14:31:35 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket31/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11312026/10/28 14:31:35 INFO Received delete pin request method=DELETE path=/api/pins/app11322026/10/28 14:31:35 INFO Received uploads request method=POST path=/api/pending_closures11332026/10/28 14:31:35 INFO Deleted pin name=app11342026/10/28 14:31:35 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11352026/10/28 14:31:35 INFO Received uploads request method=POST path=/api/pending_closures11362026/10/28 14:31:35 INFO Received uploads request method=POST path=/api/pending_closures1137=== CONT TestReadProxyOutlastsServerWriteTimeout1138--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.80s)1139--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.61s)1140=== CONT TestReadProxyRootRedirectsToIndexHTML11412026/10/28 14:31:35 INFO Received uploads request method=POST path=/api/pending_closures1142=== CONT TestOrphanedObjectsGCStressTest1143--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (1.72s)11442026/10/28 14:31:35 INFO Received uploads request method=POST path=/api/pending_closures11452026-10-28 14:31:35.428 UTC [993] ERROR: Push does not exist: id=111462026-10-28 14:31:35.428 UTC [993] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE11472026-10-28 14:31:35.428 UTC [993] STATEMENT: SELECT commit_push($1)11482026/10/28 14:31:35 INFO Received uploads request method=POST path=/api/pending_closures1149--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.88s)1150=== CONT TestPendingClosureFailureTracksEveryUpload1151=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1152=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1153=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1154=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1155=== CONT TestReadProxyInvalidPath1156=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1157--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.73s)11582026/10/28 14:31:35 INFO Received uploads request method=POST path=/api/pending_closures11592026/10/28 14:31:35 INFO Aborted multipart uploads count=0 kept=011602026/10/28 14:31:35 INFO Received uploads request method=POST path=/api/pending_closures11612026/10/28 14:31:35 WARN Force mode enabled - objects will be deleted immediately without grace period11622026/10/28 14:31:35 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=011632026/10/28 14:31:35 INFO Vacuumed table table=pending_closures11642026/10/28 14:31:35 INFO Vacuumed table table=pending_objects11652026/10/28 14:31:35 INFO Vacuumed table table=multipart_uploads11662026/10/28 14:31:35 INFO Vacuumed table table=closures11672026/10/28 14:31:35 INFO Received uploads request method=POST path=/api/pending_closures11682026/10/28 14:31:35 INFO Vacuumed table table=objects11692026/10/28 14:31:35 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11702026/10/28 14:31:35 INFO Uploading 0wxiglp3rgm39b9m8rq4cxs1vaszizqs-shared-dep (136B)11712026/10/28 14:31:35 INFO Uploading l31pm98prh6kmq9rv1vkgwcayxf8wmnk-b (216B)11722026/10/28 14:31:35 INFO Received uploads request method=POST path=/api/pending_closures11732026/10/28 14:31:35 WARN Failed to register uploaded object key=0z3mspcgr07f9ws8lizzc599bgsrkhns.ls error="server returned 404: 404 page not found\n"1174--- PASS: TestGCSweepSkipsPendingObjects (0.64s)1175=== CONT TestReadProxyHead11762026/10/28 14:31:35 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11772026/10/28 14:31:35 WARN Failed to register uploaded object key=l31pm98prh6kmq9rv1vkgwcayxf8wmnk.ls error="server returned 404: 404 page not found\n"11782026/10/28 14:31:35 WARN Failed to register uploaded object key=nar/1fn0n7brskmmvyjs47jdwmdlv62vmkwhvy0aaxz587xw4wanl19s.nar.zst error="server returned 404: 404 page not found\n"11792026/10/28 14:31:35 INFO Received uploads request method=POST path=/api/pending_closures11802026/10/28 14:31:35 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11812026/10/28 14:31:35 WARN Failed to register uploaded object key=0wxiglp3rgm39b9m8rq4cxs1vaszizqs.ls error="server returned 404: 404 page not found\n"11822026/10/28 14:31:35 INFO Signed narinfos id=1 count=211832026/10/28 14:31:35 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11842026/10/28 14:31:35 INFO Signed narinfos id=2 count=211852026/10/28 14:31:35 INFO Uploading 4 narinfos1186--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.61s)1187=== CONT TestPendingCleanupUsesOneCutoff11882026/10/28 14:31:35 WARN Failed to register uploaded object key=0z3mspcgr07f9ws8lizzc599bgsrkhns.narinfo error="server returned 404: 404 page not found\n"11892026/10/28 14:31:35 WARN Failed to register uploaded object key=0wxiglp3rgm39b9m8rq4cxs1vaszizqs.narinfo error="server returned 404: 404 page not found\n"11902026/10/28 14:31:35 WARN Failed to register uploaded object key=l31pm98prh6kmq9rv1vkgwcayxf8wmnk.narinfo error="server returned 404: 404 page not found\n"11912026/10/28 14:31:35 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11922026/10/28 14:31:35 WARN Failed to register uploaded object key=0wxiglp3rgm39b9m8rq4cxs1vaszizqs.narinfo error="server returned 404: 404 page not found\n"1193=== CONT TestReadProxyNarStreaming1194--- PASS: TestReadProxyDisabled (0.60s)11952026/10/28 14:31:35 INFO Completed upload id=1 objects=6 duration=12.655964ms11962026/10/28 14:31:35 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11972026/10/28 14:31:35 INFO Completed upload id=2 objects=6 duration=2.968776ms11982026/10/28 14:31:35 INFO Upload complete. (176ms)1199=== NAME TestClientFallsBackToClosures1200 client_pushes_test.go:112: Retrieved narinfo from S3:1201 StorePath: /build/TestClientFallsBackToClosures3618262285/001/store/0wxiglp3rgm39b9m8rq4cxs1vaszizqs-shared-dep1202 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1203 Compression: zstd1204 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821205 NarSize: 1361206 References: 1207 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1208--- PASS: TestConnectSerialisesConcurrentMigrations (1.15s)1209=== CONT TestMultipartCleanup1210=== NAME TestClientFallsBackToClosures1211 client_pushes_test.go:112: Retrieved narinfo from S3:1212 StorePath: /build/TestClientFallsBackToClosures3618262285/001/store/0z3mspcgr07f9ws8lizzc599bgsrkhns-a1213 URL: nar/1fn0n7brskmmvyjs47jdwmdlv62vmkwhvy0aaxz587xw4wanl19s.nar.zst1214 Compression: zstd1215 NarHash: sha256:1fn0n7brskmmvyjs47jdwmdlv62vmkwhvy0aaxz587xw4wanl19s1216 NarSize: 2161217 References: /build/TestClientFallsBackToClosures3618262285/001/store/0wxiglp3rgm39b9m8rq4cxs1vaszizqs-shared-dep1218 CA: text:sha256:06p8d9chb6wbp6yj6l5birqyb0q3fad809mna7vm28h0r15g6lz51219 client_pushes_test.go:112: Retrieved narinfo from S3:1220 StorePath: /build/TestClientFallsBackToClosures3618262285/001/store/l31pm98prh6kmq9rv1vkgwcayxf8wmnk-b1221 URL: nar/1fn0n7brskmmvyjs47jdwmdlv62vmkwhvy0aaxz587xw4wanl19s.nar.zst1222 Compression: zstd1223 NarHash: sha256:1fn0n7brskmmvyjs47jdwmdlv62vmkwhvy0aaxz587xw4wanl19s1224 NarSize: 2161225 References: /build/TestClientFallsBackToClosures3618262285/001/store/0wxiglp3rgm39b9m8rq4cxs1vaszizqs-shared-dep1226 CA: text:sha256:06p8d9chb6wbp6yj6l5birqyb0q3fad809mna7vm28h0r15g6lz512272026/10/28 14:31:35 INFO Aborted multipart uploads count=0 kept=012282026/10/28 14:31:35 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=012292026/10/28 14:31:35 INFO Aborted multipart uploads count=0 kept=012302026/10/28 14:31:35 INFO Vacuumed table table=pending_closures12312026/10/28 14:31:35 WARN Force mode enabled - objects will be deleted immediately without grace period12322026/10/28 14:31:35 INFO Vacuumed table table=pending_objects12332026/10/28 14:31:35 INFO Vacuumed table table=multipart_uploads12342026/10/28 14:31:35 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=012352026/10/28 14:31:35 INFO Vacuumed table table=pending_closures12362026/10/28 14:31:35 INFO Vacuumed table table=closures12372026/10/28 14:31:35 INFO Vacuumed table table=pending_objects12382026/10/28 14:31:35 INFO Vacuumed table table=multipart_uploads12392026/10/28 14:31:35 INFO Vacuumed table table=closures12402026/10/28 14:31:35 INFO Vacuumed table table=objects12412026/10/28 14:31:35 INFO Vacuumed table table=objects12422026/10/28 14:31:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12432026/10/28 14:31:35 INFO Aborted multipart uploads count=0 kept=012442026/10/28 14:31:35 WARN Force mode enabled - objects will be deleted immediately without grace period1245--- PASS: TestClientFallsBackToClosures (1.03s)1246=== CONT TestReadProxy404And42912472026/10/28 14:31:35 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=012482026/10/28 14:31:35 INFO Vacuumed table table=pending_closures12492026/10/28 14:31:35 INFO Received uploads request method=POST path=/api/pending_closures12502026/10/28 14:31:35 INFO Vacuumed table table=pending_objects12512026/10/28 14:31:35 INFO Vacuumed table table=multipart_uploads12522026/10/28 14:31:35 INFO Vacuumed table table=closures12532026/10/28 14:31:35 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2Ljg4MjNhYzRhLWE0NjQtNDEyZC05ZGQxLWM2ZDE1Y2I4YWIyY3gxNzkzMTk3ODk0MzI5NTYzMzE0 parts=1012542026/10/28 14:31:35 INFO Vacuumed table table=objects12552026/10/28 14:31:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12562026/10/28 14:31:35 INFO Received complete push request method=POST path=/api/pushes/1/complete1257--- PASS: TestGCMetrics (0.61s)1258=== CONT TestReadProxyNarinfoAlreadyDecompressed12592026/10/28 14:31:35 INFO Completed push id=1 objects=4 duration=11.517683ms1260=== CONT TestPresentReportsOnlyClosureRoots1261--- PASS: TestPushDedupSurvivesConcurrentGC (0.76s)12622026/10/28 14:31:35 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LjgwZWVlMDA3LTBhNTUtNDA4OS04NzBmLTM5OGI5NzkwNjFlNHgxNzkzMTk3ODk0NDUxODI2NjI5 parts=101263--- PASS: TestPush_RepeatedRootCommitsOnce (2.23s)1264=== CONT TestGCAdvisoryLockBlocksConcurrentRun1265=== CONT TestLeadIncumbentAnnouncesAtOnce1266--- PASS: TestPendingClosureFailureAbortsItsUploads (0.64s)1267--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.56s)1268=== CONT TestClientMultipleUploads12692026/10/28 14:31:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12702026/10/28 14:31:35 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LjdhNTUyNTlmLWFlYWEtNDg1My04NGE3LTk2MDU2YmZmYjIyY3gxNzkzMTk3ODk1NDA0ODEyNDEx1271--- PASS: TestReadProxyInvalidPath (0.44s)1272=== CONT TestIsValidCachePath1273=== RUN TestIsValidCachePath/narinfo1274=== PAUSE TestIsValidCachePath/narinfo1275=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1276=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1277=== RUN TestIsValidCachePath/nar_zst1278=== PAUSE TestIsValidCachePath/nar_zst1279=== RUN TestIsValidCachePath/nar_xz1280=== PAUSE TestIsValidCachePath/nar_xz1281=== RUN TestIsValidCachePath/nar_bz21282=== PAUSE TestIsValidCachePath/nar_bz21283=== RUN TestIsValidCachePath/nar_uncompressed1284=== PAUSE TestIsValidCachePath/nar_uncompressed1285=== RUN TestIsValidCachePath/ls1286=== PAUSE TestIsValidCachePath/ls1287=== RUN TestIsValidCachePath/log1288=== PAUSE TestIsValidCachePath/log1289=== RUN TestIsValidCachePath/realisation1290=== PAUSE TestIsValidCachePath/realisation1291=== RUN TestIsValidCachePath/nix-cache-info1292=== PAUSE TestIsValidCachePath/nix-cache-info1293=== RUN TestIsValidCachePath/index.html1294=== PAUSE TestIsValidCachePath/index.html1295=== RUN TestIsValidCachePath/traversal_parent1296=== PAUSE TestIsValidCachePath/traversal_parent1297=== RUN TestIsValidCachePath/traversal_in_middle1298=== PAUSE TestIsValidCachePath/traversal_in_middle1299=== RUN TestIsValidCachePath/invalid_char_e1300=== PAUSE TestIsValidCachePath/invalid_char_e1301=== RUN TestIsValidCachePath/invalid_char_u1302=== PAUSE TestIsValidCachePath/invalid_char_u1303=== RUN TestIsValidCachePath/random_path1304=== PAUSE TestIsValidCachePath/random_path13052026/10/28 14:31:35 INFO Received uploads request method=POST path=/api/pending_closures1306=== RUN TestIsValidCachePath/empty1307=== PAUSE TestIsValidCachePath/empty1308=== RUN TestIsValidCachePath/leading_slash1309=== PAUSE TestIsValidCachePath/leading_slash1310=== RUN TestIsValidCachePath/wrong_extension1311=== PAUSE TestIsValidCachePath/wrong_extension1312=== RUN TestIsValidCachePath/short_hash1313=== PAUSE TestIsValidCachePath/short_hash1314=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1315=== CONT TestService_AuthMiddleware_MTLSProxyHeader1316--- PASS: TestReadProxyConditionalGet (0.77s)1317=== NAME TestOrphanedObjectsGC1318 orphaned_objects_gc_test.go:287: GC Test Summary:1319 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1320 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1321 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1322 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1323 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1324--- PASS: TestOrphanedObjectsGC (1.13s)1325=== CONT TestPushWaitsForSweepHoldingRow13262026/10/28 14:31:36 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LjdhNTUyNTlmLWFlYWEtNDg1My04NGE3LTk2MDU2YmZmYjIyY3gxNzkzMTk3ODk1NDA0ODEyNDEx error="Delete \"http://localhost:38123/bucket35/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LjdhNTUyNTlmLWFlYWEtNDg1My04NGE3LTk2MDU2YmZmYjIyY3gxNzkzMTk3ODk1NDA0ODEyNDEx\": injected: abort refused"1327--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.54s)1328=== CONT TestService_AuthMiddleware_OIDC13292026/10/28 14:31:36 INFO Received uploads request method=POST path=/api/pending_closures13302026/10/28 14:31:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13312026/10/28 14:31:36 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LjdhNTUyNTlmLWFlYWEtNDg1My04NGE3LTk2MDU2YmZmYjIyY3gxNzkzMTk3ODk1NDA0ODEyNDEx13322026/10/28 14:31:36 ERROR Failed to register completed object error="get pending object \"nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst\": context canceled" object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst13332026/10/28 14:31:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13342026/10/28 14:31:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13352026/10/28 14:31:36 INFO Received uploads request method=POST path=/api/pending_closures13362026/10/28 14:31:36 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified multipart upload does not exist. The upload ID may be invalid, or the upload may have been aborted or completed." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LjdhNTUyNTlmLWFlYWEtNDg1My04NGE3LTk2MDU2YmZmYjIyY3gxNzkzMTk3ODk1NDA0ODEyNDEx13372026/10/28 14:31:36 INFO Received cleanup request method=DELETE path=/api/pending_closures13382026/10/28 14:31:36 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LjdhNTUyNTlmLWFlYWEtNDg1My04NGE3LTk2MDU2YmZmYjIyY3gxNzkzMTk3ODk1NDA0ODEyNDEx parts=11339=== CONT TestService_NativeMTLS1340--- PASS: TestReadProxyNarStreaming (0.46s)1341--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.41s)1342=== CONT TestService_RequireScope_OIDC13432026/10/28 14:31:36 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LjE2ZDNjYjc4LTM1YTgtNDIyMS1hMjkyLTA1NzFjODQ0MzEzMngxNzkzMTk3ODk1MjcwNzk5OTIz parts=1213442026/10/28 14:31:36 INFO lead: released remote=192.0.2.1:123413452026/10/28 14:31:36 INFO Received uploads request method=POST path=/api/pending_closures13462026/10/28 14:31:36 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1347--- PASS: TestLeadEndsOnShutdown (1.78s)1348=== CONT TestMetricsCommit13492026/10/28 14:31:36 INFO Received uploads request method=POST path=/api/pending_closures1350--- PASS: TestReadProxyNarinfo (1.81s)1351=== CONT TestMetricsInventory13522026/10/28 14:31:36 INFO Received uploads request method=POST path=/api/pending_closures13532026/10/28 14:31:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36963/oidc1354=== CONT TestService_ReadAuthMiddleware1355--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.55s)1356=== CONT TestCreatePinRejectsBadInput1357--- PASS: TestReadProxyHead (0.74s)13582026/10/28 14:31:36 INFO lead: released remote=192.0.2.1:123413592026/10/28 14:31:36 INFO Received cleanup request method=DELETE path=/api/pending_closures13602026/10/28 14:31:36 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket54/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""13612026/10/28 14:31:36 INFO Aborted multipart uploads count=0 kept=113622026/10/28 14:31:36 INFO lead: acquired remote=192.0.2.1:123413632026/10/28 14:31:36 INFO lead: released remote=192.0.2.1:123413642026/10/28 14:31:36 INFO Received cleanup request method=DELETE path=/api/pending_closures13652026/10/28 14:31:36 INFO Aborted multipart uploads count=1 kept=01366=== CONT TestClientIntegration1367--- PASS: TestPresentReportsOnlyClosureRoots (0.59s)1368--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.57s)1369=== CONT TestCreatePin_ReservedPins13702026/10/28 14:31:36 INFO lead: acquired remote=192.0.2.1:12341371--- PASS: TestMultipartCleanup (0.72s)1372=== CONT TestPinProtectsFromGC13732026/10/28 14:31:36 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"13742026/10/28 14:31:36 WARN mTLS auth: bound subjects configured but subject DN unavailable13752026/10/28 14:31:36 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1376--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.54s)1377=== CONT TestConcurrentPinUpdatesAgree1378=== NAME TestClientMultipleUploads1379 client_integration_test.go:467: Created store path 0: /build/TestClientMultipleUploads4092304733/001/store/s3im9kflb337fpxpn6xpd0q98nd8a74i-test-file-0.txt13802026/10/28 14:31:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40415/oidc1381--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.57s)1382=== CONT TestNARDeduplicationMetadataUploadBug1383--- PASS: TestReadProxyContentNegotiation (1.50s)1384=== CONT TestClientCADerivations1385=== NAME TestClientMultipleUploads1386 client_integration_test.go:467: Created store path 1: /build/TestClientMultipleUploads4092304733/001/store/l2l9xwy6nmphyzw8flcbs3knjj3g7vgk-test-file-1.txt13872026/10/28 14:31:36 INFO Received uploads request method=POST path=/api/pending_closures13882026/10/28 14:31:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13892026/10/28 14:31:36 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13902026/10/28 14:31:36 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1391 client_integration_test.go:467: Created store path 2: /build/TestClientMultipleUploads4092304733/001/store/hz7d6mpnql928mlh82hcb7br3w4mm9gy-test-file-2.txt1392--- PASS: TestService_NativeMTLS (0.43s)1393=== CONT TestGenerateLandingPage13942026/10/28 14:31:36 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LmY0ZDY2MzY1LTUzZjEtNGU2Ni1iZGEwLWJmNTFkNzc3YTRlMHgxNzkzMTk3ODk0NDUxMjYzOTg4 parts=101395--- PASS: TestGenerateLandingPage (0.01s)1396=== CONT TestService_ReadScope_PublicByDefault13972026/10/28 14:31:36 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"13982026/10/28 14:31:36 INFO Received complete push request method=POST path=/api/pushes/1/complete13992026/10/28 14:31:36 INFO Completed push id=1 objects=6 duration=18.434196ms14002026/10/28 14:31:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42571/oidc14012026/10/28 14:31:36 INFO Received push request method=POST path=/api/pushes14022026/10/28 14:31:36 INFO Received push request method=POST path=/api/pushes1403=== CONT TestParseSize1404--- PASS: TestPush_CompleteCommitsEveryRoot (3.05s)1405--- PASS: TestParseSize (0.00s)1406=== CONT TestUploadHandlersRejectInvalidKeys1407=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1408=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1409=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1410=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1411=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1412=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1413=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1414=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1415--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.82s)1416=== CONT TestDeleteClosuresRacingPins1417=== CONT TestService_cleanupPendingClosuresHandler14182026/10/28 14:31:36 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14192026/10/28 14:31:36 INFO Uploading hz7d6mpnql928mlh82hcb7br3w4mm9gy-test-file-2.txt (160B)14202026/10/28 14:31:36 INFO Uploading l2l9xwy6nmphyzw8flcbs3knjj3g7vgk-test-file-1.txt (160B)14212026/10/28 14:31:36 INFO Uploading s3im9kflb337fpxpn6xpd0q98nd8a74i-test-file-0.txt (160B)14222026/10/28 14:31:36 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14232026/10/28 14:31:36 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14242026/10/28 14:31:36 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"1425=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1426=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1427=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1428=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1429=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1430=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1431=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1432=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1433=== CONT TestClientPushesUseOnePush14342026/10/28 14:31:36 WARN Failed to register uploaded object key=l2l9xwy6nmphyzw8flcbs3knjj3g7vgk.ls error="server returned 404: 404 page not found\n"14352026/10/28 14:31:36 WARN Failed to register uploaded object key=hz7d6mpnql928mlh82hcb7br3w4mm9gy.ls error="server returned 404: 404 page not found\n"14362026/10/28 14:31:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14372026/10/28 14:31:36 WARN Failed to register uploaded object key=s3im9kflb337fpxpn6xpd0q98nd8a74i.ls error="server returned 404: 404 page not found\n"14382026/10/28 14:31:36 INFO Signed narinfos id=1 count=314392026/10/28 14:31:36 INFO Uploading 3 narinfos14402026/10/28 14:31:36 INFO Received create pin request method=POST path=/api/pins/deploy14412026/10/28 14:31:36 INFO Received create pin request method=POST path=/api/pins/deploy14422026/10/28 14:31:36 INFO Received create pin request method=POST path=/api/pins/deploy14432026/10/28 14:31:36 INFO Received create pin request method=POST path=/api/pins/deploy14442026/10/28 14:31:36 INFO Received create pin request method=POST path=/api/pins/deploy14452026/10/28 14:31:36 INFO Received create pin request method=POST path=/api/pins/deploy14462026/10/28 14:31:36 INFO Received create pin request method=POST path=/api/pins/deploy14472026/10/28 14:31:36 INFO Received create pin request method=POST path=/api/pins/deploy14482026/10/28 14:31:36 INFO Received complete push request method=POST path=/api/pushes/1/complete14492026/10/28 14:31:36 WARN Failed to register uploaded object key=s3im9kflb337fpxpn6xpd0q98nd8a74i.narinfo error="server returned 404: 404 page not found\n"14502026/10/28 14:31:36 WARN Failed to register uploaded object key=l2l9xwy6nmphyzw8flcbs3knjj3g7vgk.narinfo error="server returned 404: 404 page not found\n"14512026/10/28 14:31:36 WARN Failed to register uploaded object key=hz7d6mpnql928mlh82hcb7br3w4mm9gy.narinfo error="server returned 404: 404 page not found\n"1452--- PASS: TestMetricsInventory (0.53s)1453=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock14542026/10/28 14:31:36 INFO Completed push id=1 objects=9 duration=13.018805ms14552026/10/28 14:31:36 INFO Upload complete. (189ms)1456=== NAME TestClientMultipleUploads1457 client_integration_test.go:478: Uploaded 3 paths in 225.979765ms1458--- PASS: TestService_ReadAuthMiddleware (0.44s)1459=== CONT TestCompleteMultipartUnregistered14602026/10/28 14:31:36 INFO Received create pin request method=POST path=/api/pins/deploy1461--- PASS: TestClientMultipleUploads (0.99s)1462=== CONT TestService_verifyS3Integrity1463=== NAME TestClientIntegration1464 client_integration_test.go:331: Created store path: /build/TestClientIntegration947834883/002/store/cj3b7awwqxjdqrc0m1q78zhzvwwkjxpn-test-file.txt14652026/10/28 14:31:36 INFO Received create pin request method=POST path=/api/pins/app14662026/10/28 14:31:36 INFO Received create pin request method=POST path=/api/pins/app14672026/10/28 14:31:36 INFO Received push request method=POST path=/api/pushes1468=== NAME TestPinProtectsFromGC1469 client_integration_test.go:854: Pinned store path: /build/TestPinProtectsFromGC1864708213/001/store/hdy85q5j77d4cza51fpx1vjybq3nngyl-pinned-file.txt1470 client_integration_test.go:855: Unpinned store path: /build/TestPinProtectsFromGC1864708213/001/store/nlx2zkmam88mnjydfncrnai9n2nszw2f-unpinned-file.txt14712026/10/28 14:31:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14722026/10/28 14:31:36 INFO Uploading cj3b7awwqxjdqrc0m1q78zhzvwwkjxpn-test-file.txt (152B)1473=== NAME TestNARDeduplicationMetadataUploadBug1474 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug4149771890/001/store/dg3mp3p71ywqjnjn4gl4gdd7gxagf5yg-file1.txt14752026/10/28 14:31:36 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"14762026/10/28 14:31:36 WARN Rate limiter enabled after throttle name=s3-test rate=514772026/10/28 14:31:36 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."14782026/10/28 14:31:36 WARN Failed to register uploaded object key=cj3b7awwqxjdqrc0m1q78zhzvwwkjxpn.ls error="server returned 404: 404 page not found\n"14792026/10/28 14:31:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14802026/10/28 14:31:36 INFO Signed narinfos id=1 count=114812026/10/28 14:31:36 INFO Uploading 1 narinfos14822026/10/28 14:31:37 INFO Received complete push request method=POST path=/api/pushes/1/complete14832026/10/28 14:31:37 WARN Failed to register uploaded object key=cj3b7awwqxjdqrc0m1q78zhzvwwkjxpn.narinfo error="server returned 404: 404 page not found\n"14842026/10/28 14:31:37 INFO Completed push id=1 objects=3 duration=5.623531ms14852026/10/28 14:31:37 INFO Upload complete. (133ms)14862026/10/28 14:31:37 INFO Received push request method=POST path=/api/pushes14872026/10/28 14:31:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14882026/10/28 14:31:37 INFO Uploading hdy85q5j77d4cza51fpx1vjybq3nngyl-pinned-file.txt (128B)1489--- PASS: TestPushWaitsForSweepHoldingRow (1.01s)1490=== CONT TestGCTaskStore_CompletedAllowsNewTask1491--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1492=== CONT TestService_createPendingClosureHandler14932026/10/28 14:31:37 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14942026/10/28 14:31:37 INFO Received push request method=POST path=/api/pushes14952026/10/28 14:31:37 INFO All 1 paths already cached1496=== NAME TestClientIntegration1497 client_integration_test.go:357: Retrieved narinfo from S3:1498 StorePath: /build/TestClientIntegration947834883/002/store/cj3b7awwqxjdqrc0m1q78zhzvwwkjxpn-test-file.txt1499 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1500 Compression: zstd1501 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11502 NarSize: 1521503 References: 1504 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk115052026/10/28 14:31:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15062026/10/28 14:31:37 WARN Failed to register uploaded object key=hdy85q5j77d4cza51fpx1vjybq3nngyl.ls error="server returned 404: 404 page not found\n"15072026/10/28 14:31:37 INFO Signed narinfos id=1 count=115082026/10/28 14:31:37 INFO Uploading 1 narinfos1509 client_integration_test.go:358: Retrieved .ls file from S3 (compressed size: 77 bytes)1510 client_integration_test.go:358: Decompressed .ls content (64 bytes):1511 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}15122026/10/28 14:31:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15132026/10/28 14:31:37 INFO Uploading dg3mp3p71ywqjnjn4gl4gdd7gxagf5yg-file1.txt (160B)15142026/10/28 14:31:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1515=== RUN TestService_RequireScope_OIDC/builder_may_write1516=== PAUSE TestService_RequireScope_OIDC/builder_may_write1517=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1518=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1519=== RUN TestService_RequireScope_OIDC/ops_may_admin1520=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1521=== RUN TestService_RequireScope_OIDC/ops_may_not_write1522=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1523=== RUN TestService_RequireScope_OIDC/reader_may_not_write1524=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1525=== RUN TestService_RequireScope_OIDC/static_token_may_admin1526=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1527=== RUN TestService_RequireScope_OIDC/static_token_may_write1528=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1529=== RUN TestService_RequireScope_OIDC/reader_may_read1530=== PAUSE TestService_RequireScope_OIDC/reader_may_read1531=== RUN TestService_RequireScope_OIDC/writer_implies_read1532=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1533=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1534=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1535=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1536=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1537=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1538=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1539=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1540=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1541=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1542=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1543=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit15442026/10/28 14:31:37 INFO Received complete push request method=POST path=/api/pushes/1/complete15452026/10/28 14:31:37 WARN Failed to register uploaded object key=hdy85q5j77d4cza51fpx1vjybq3nngyl.narinfo error="server returned 404: 404 page not found\n"1546=== CONT TestCompletedNarNotReofferedAcrossClosures1547--- PASS: TestService_ReadScope_PublicByDefault (0.52s)15482026/10/28 14:31:37 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"15492026/10/28 14:31:37 INFO Completed push id=1 objects=3 duration=9.948409ms15502026/10/28 14:31:37 INFO Upload complete. (106ms)15512026/10/28 14:31:37 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LjM5MDVlOTcxLThiMDktNDA0Ni05MTBjLTEyNTI1MjNkZGIzMXgxNzkzMTk3ODk2MjMxMjE2MDU4 error="Get \"http://127.0.0.1:1/bucket33/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"15522026/10/28 14:31:37 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LjZjODI4NTFmLWQ5NTctNDY1NS1iMGI2LTVlNzcyNGM5Y2ZjZngxNzkzMTk3ODk2MjAwMDA1MDk4 parts=1215532026/10/28 14:31:37 WARN Failed to register uploaded object key=dg3mp3p71ywqjnjn4gl4gdd7gxagf5yg.ls error="server returned 404: 404 page not found\n"15542026/10/28 14:31:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15552026/10/28 14:31:37 INFO Signed narinfos id=1 count=115562026/10/28 14:31:37 INFO Received cleanup request method=DELETE path=/api/pending_closures15572026/10/28 14:31:37 INFO Uploading 1 narinfos15582026/10/28 14:31:37 INFO Aborted multipart uploads count=1 kept=01559=== NAME TestClientCADerivations1560 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3055989128/001/store/36mv0cm3gy2q2x7l5m0mpzxbqh789hlz-ca-test15612026/10/28 14:31:37 INFO Received complete push request method=POST path=/api/pushes/1/complete15622026/10/28 14:31:37 WARN Failed to register uploaded object key=dg3mp3p71ywqjnjn4gl4gdd7gxagf5yg.narinfo error="server returned 404: 404 page not found\n"15632026/10/28 14:31:37 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15642026/10/28 14:31:37 WARN Refused reserved pin name=worker-x86_64-linux15652026/10/28 14:31:37 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15662026/10/28 14:31:37 INFO Received create pin request method=POST path=/api/pins/my-app15672026/10/28 14:31:37 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15682026/10/28 14:31:37 INFO Received cleanup request method=DELETE path=/api/pending_closures15692026/10/28 14:31:37 INFO Aborted multipart uploads count=0 kept=015702026/10/28 14:31:37 INFO Received uploads request method=POST path=/api/pending_closures1571 client_ca_test.go:139: Found 1 dependencies (including self)15722026/10/28 14:31:37 INFO Completed push id=1 objects=3 duration=24.643807ms1573--- PASS: TestCreatePin_ReservedPins (0.74s)1574=== CONT TestPendingClosureWriteTimeout1575=== RUN TestPendingClosureWriteTimeout/empty1576=== PAUSE TestPendingClosureWriteTimeout/empty1577=== CONT TestUploadHandlersRejectOversizedBody15782026/10/28 14:31:37 INFO Upload complete. (124ms)1579=== RUN TestPendingClosureWriteTimeout/400_objects1580--- PASS: TestRedundantMultipartUpload (2.47s)1581=== PAUSE TestPendingClosureWriteTimeout/400_objects1582=== RUN TestPendingClosureWriteTimeout/670k_objects1583=== PAUSE TestPendingClosureWriteTimeout/670k_objects1584=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1585=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1586=== CONT TestPush_SignsNarinfosOfItsPendingObjects1587=== NAME TestNARDeduplicationMetadataUploadBug1588 metadata_upload_test.go:54: Retrieved narinfo from S3:1589 StorePath: /build/TestNARDeduplicationMetadataUploadBug4149771890/001/store/dg3mp3p71ywqjnjn4gl4gdd7gxagf5yg-file1.txt1590 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1591 Compression: zstd1592 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1593 NarSize: 1601594 References: 1595 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf15962026/10/28 14:31:37 INFO Received push request method=POST path=/api/pushes1597 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1598 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1599 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}16002026/10/28 14:31:37 INFO Object in database but missing from S3 key=cj3b7awwqxjdqrc0m1q78zhzvwwkjxpn.ls16012026/10/28 14:31:37 WARN Found objects in DB but missing from S3, will re-upload count=116022026/10/28 14:31:37 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16032026/10/28 14:31:37 INFO Received push request method=POST path=/api/pushes16042026/10/28 14:31:37 INFO Received cleanup request method=DELETE path=/api/pending_closures16052026/10/28 14:31:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16062026/10/28 14:31:37 INFO Uploading nlx2zkmam88mnjydfncrnai9n2nszw2f-unpinned-file.txt (128B)16072026/10/28 14:31:37 INFO Aborted multipart uploads count=1 kept=016082026/10/28 14:31:37 INFO Received complete push request method=POST path=/api/pushes/2/complete16092026/10/28 14:31:37 WARN Failed to register uploaded object key=cj3b7awwqxjdqrc0m1q78zhzvwwkjxpn.ls error="server returned 404: 404 page not found\n"16102026/10/28 14:31:37 WARN Rate limiter backed off name=s3-test rate=516112026/10/28 14:31:37 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."16122026/10/28 14:31:37 INFO Completed push id=2 objects=3 duration=2.562834ms16132026/10/28 14:31:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16142026/10/28 14:31:37 INFO Upload complete. (51ms)16152026-10-28 14:31:37.167 UTC [1333] ERROR: Closure does not exist: id=116162026-10-28 14:31:37.167 UTC [1333] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE16172026-10-28 14:31:37.167 UTC [1333] STATEMENT: -- name: CommitPendingClosure :one1618 SELECT commit_pending_closure($1::bigint)::bigint1619 1620=== NAME TestClientIntegration1621 client_integration_test.go:375: Retrieved .ls file from S3 (compressed size: 62 bytes)16222026/10/28 14:31:37 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"1623 client_integration_test.go:375: Decompressed .ls content (49 bytes):1624 {"version":1,"root":{"type":"regular","size":39}}16252026/10/28 14:31:37 WARN Failed to register uploaded object key=nlx2zkmam88mnjydfncrnai9n2nszw2f.ls error="server returned 404: 404 page not found\n"16262026/10/28 14:31:37 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16272026/10/28 14:31:37 INFO Signed narinfos id=2 count=116282026/10/28 14:31:37 INFO Uploading 1 narinfos1629--- PASS: TestService_cleanupPendingClosuresHandler (0.54s)1630=== CONT TestGCTaskStore_PhaseUpdates1631--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1632=== CONT TestIsValidUploadKey1633=== RUN TestIsValidUploadKey/narinfo1634=== PAUSE TestIsValidUploadKey/narinfo1635=== RUN TestIsValidUploadKey/nar_zst1636=== PAUSE TestIsValidUploadKey/nar_zst1637=== RUN TestIsValidUploadKey/nar_xz1638=== PAUSE TestIsValidUploadKey/nar_xz1639=== RUN TestIsValidUploadKey/nar_plain1640=== PAUSE TestIsValidUploadKey/nar_plain1641=== RUN TestIsValidUploadKey/listing1642=== PAUSE TestIsValidUploadKey/listing1643=== RUN TestIsValidUploadKey/build_log1644=== PAUSE TestIsValidUploadKey/build_log1645=== RUN TestIsValidUploadKey/build_log_home-manager_file1646=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1647=== RUN TestIsValidUploadKey/build_log_plus_in_name1648=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1649=== RUN TestIsValidUploadKey/build_log_question_mark1650=== PAUSE TestIsValidUploadKey/build_log_question_mark1651=== RUN TestIsValidUploadKey/build_log_equals1652=== PAUSE TestIsValidUploadKey/build_log_equals1653=== RUN TestIsValidUploadKey/realisation1654=== PAUSE TestIsValidUploadKey/realisation1655=== RUN TestIsValidUploadKey/realisation_plus_in_output1656=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1657=== RUN TestIsValidUploadKey/nix-cache-info1658=== PAUSE TestIsValidUploadKey/nix-cache-info1659=== RUN TestIsValidUploadKey/index.html1660=== PAUSE TestIsValidUploadKey/index.html1661=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1662=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1663=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1664=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1665=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1666=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1667=== RUN TestIsValidUploadKey/traversal1668=== PAUSE TestIsValidUploadKey/traversal1669=== RUN TestIsValidUploadKey/traversal_nar1670=== PAUSE TestIsValidUploadKey/traversal_nar1671=== RUN TestIsValidUploadKey/absolute1672=== PAUSE TestIsValidUploadKey/absolute1673=== RUN TestIsValidUploadKey/empty_key1674=== PAUSE TestIsValidUploadKey/empty_key1675=== RUN TestIsValidUploadKey/unknown_type1676=== PAUSE TestIsValidUploadKey/unknown_type1677=== CONT TestPresentRefreshesOnlyStaleClosures1678--- PASS: TestReadProxy404And429 (1.45s)1679=== CONT TestGracefulShutdownDrainsInflight16802026/10/28 14:31:37 INFO Starting HTTP server address=127.0.0.1:4268516812026/10/28 14:31:37 INFO Received complete push request method=POST path=/api/pushes/2/complete16822026/10/28 14:31:37 WARN Failed to register uploaded object key=nlx2zkmam88mnjydfncrnai9n2nszw2f.narinfo error="server returned 404: 404 page not found\n"1683=== NAME TestNARDeduplicationMetadataUploadBug16842026/10/28 14:31:37 INFO Completed push id=2 objects=3 duration=5.794161ms1685 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug4149771890/001/store/h1m5gpzpmds9fcb9694ihr43ny6zx9sg-file2.txt16862026/10/28 14:31:37 INFO Upload complete. (84ms)16872026/10/28 14:31:37 INFO Shutdown signal received, draining in-flight requests timeout=10s16882026/10/28 14:31:37 INFO Received push request method=POST path=/api/pushes16892026/10/28 14:31:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16902026/10/28 14:31:37 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst16912026/10/28 14:31:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16922026/10/28 14:31:37 INFO Uploading 36mv0cm3gy2q2x7l5m0mpzxbqh789hlz-ca-test (144B)16932026/10/28 14:31:37 INFO Starting cleanup of old closures method=DELETE path=/api/closures16942026/10/28 14:31:37 INFO Garbage collection started1695=== CONT TestCacheStatsHandler1696--- PASS: TestCompleteMultipartUnregistered (0.49s)16972026/10/28 14:31:37 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16982026/10/28 14:31:37 INFO Received uploads request method=POST path=/api/pending_closures16992026/10/28 14:31:37 INFO Aborted multipart uploads count=0 kept=017002026/10/28 14:31:37 INFO Received push request method=POST path=/api/pushes1701--- PASS: TestGracefulShutdownDrainsInflight (0.09s)1702=== CONT TestProxyWriteTimeout1703=== RUN TestProxyWriteTimeout/narinfo1704=== PAUSE TestProxyWriteTimeout/narinfo1705=== RUN TestProxyWriteTimeout/1_GiB_nar1706=== PAUSE TestProxyWriteTimeout/1_GiB_nar1707=== RUN TestProxyWriteTimeout/10_GiB_nar1708=== PAUSE TestProxyWriteTimeout/10_GiB_nar1709=== RUN TestProxyWriteTimeout/unknown_size1710=== PAUSE TestProxyWriteTimeout/unknown_size1711=== CONT TestPush_RootsAreLockedInByteOrder17122026/10/28 14:31:37 WARN Failed to register uploaded object key=log/22g6av1pn9vx59j9ha63zfyx7irw3sp2-ca-test.drv error="server returned 404: 404 page not found\n"17132026/10/28 14:31:37 WARN Force mode enabled - objects will be deleted immediately without grace period17142026/10/28 14:31:37 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17152026/10/28 14:31:37 WARN Failed to register uploaded object key=36mv0cm3gy2q2x7l5m0mpzxbqh789hlz.ls error="server returned 404: 404 page not found\n"17162026/10/28 14:31:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17172026/10/28 14:31:37 INFO Signed narinfos id=1 count=117182026/10/28 14:31:37 INFO Uploading 1 narinfos17192026/10/28 14:31:37 INFO Received complete push request method=POST path=/api/pushes/3/complete17202026/10/28 14:31:37 WARN Failed to register uploaded object key=cj3b7awwqxjdqrc0m1q78zhzvwwkjxpn.ls error="server returned 404: 404 page not found\n"17212026/10/28 14:31:37 INFO Received push request method=POST path=/api/pushes17222026/10/28 14:31:37 INFO Received complete push request method=POST path=/api/pushes/1/complete17232026/10/28 14:31:37 WARN Failed to register uploaded object key=36mv0cm3gy2q2x7l5m0mpzxbqh789hlz.narinfo error="server returned 404: 404 page not found\n"17242026/10/28 14:31:37 INFO Completed push id=3 objects=3 duration=3.777997ms17252026/10/28 14:31:37 INFO Upload complete. (55ms)1726=== NAME TestClientIntegration1727 client_integration_test.go:392: Retrieved .ls file from S3 (compressed size: 62 bytes)17282026/10/28 14:31:37 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1729 client_integration_test.go:392: Decompressed .ls content (49 bytes):1730 {"version":1,"root":{"type":"regular","size":39}}17312026/10/28 14:31:37 INFO Completed push id=1 objects=4 duration=6.612263ms17322026/10/28 14:31:37 INFO Upload complete. (144ms)1733=== NAME TestClientCADerivations1734 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3055989128/001/store/36mv0cm3gy2q2x7l5m0mpzxbqh789hlz-ca-test17352026/10/28 14:31:37 INFO Received uploads request method=POST path=/api/pending_closures1736 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1737 Compression: zstd17382026/10/28 14:31:37 WARN Failed to register uploaded object key=h1m5gpzpmds9fcb9694ihr43ny6zx9sg.ls error="server returned 404: 404 page not found\n"1739 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n17402026/10/28 14:31:37 INFO Received uploads request method=POST path=/api/pending_closures1741 NarSize: 1441742 References: 17432026/10/28 14:31:37 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign1744 Deriver: /build/TestClientCADerivations3055989128/001/store/22g6av1pn9vx59j9ha63zfyx7irw3sp2-ca-test.drv1745 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1746 client_ca_test.go:185: Checking for realisation files in S3...17472026/10/28 14:31:37 INFO Received uploads request method=POST path=/api/pending_closures17482026/10/28 14:31:37 INFO Signed narinfos id=2 count=117492026/10/28 14:31:37 INFO Uploading 1 narinfos1750 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1751 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache17522026/10/28 14:31:37 INFO Received complete push request method=POST path=/api/pushes/2/complete17532026/10/28 14:31:37 WARN Failed to register uploaded object key=h1m5gpzpmds9fcb9694ihr43ny6zx9sg.narinfo error="server returned 404: 404 page not found\n"17542026/10/28 14:31:37 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=017552026/10/28 14:31:37 INFO Completed push id=2 objects=3 duration=3.765647ms17562026/10/28 14:31:37 INFO Upload complete. (77ms)1757=== NAME TestNARDeduplicationMetadataUploadBug1758 metadata_upload_test.go:76: Retrieved narinfo from S3:1759 StorePath: /build/TestNARDeduplicationMetadataUploadBug4149771890/001/store/h1m5gpzpmds9fcb9694ihr43ny6zx9sg-file2.txt1760 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1761 Compression: zstd1762 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf17632026/10/28 14:31:37 INFO Vacuumed table table=pending_closures1764 NarSize: 1601765 References: 1766 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf17672026/10/28 14:31:37 INFO Vacuumed table table=pending_objects17682026/10/28 14:31:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17692026/10/28 14:31:37 INFO Vacuumed table table=multipart_uploads17702026/10/28 14:31:37 INFO Received push request method=POST path=/api/pushes1771 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1772 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):17732026/10/28 14:31:37 INFO Vacuumed table table=closures1774 {"version":1,"root":{"type":"regular","size":44}}17752026/10/28 14:31:37 INFO Vacuumed table table=objects17762026/10/28 14:31:37 INFO Received uploads request method=POST path=/api/pending_closures17772026/10/28 14:31:37 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LmMzMmMwNWM3LWNhOGItNGYyMC05ZDU1LWZhOTgyMWViMDZiZngxNzkzMTk3ODk2NjUwMDQ2ODYz parts=1017782026/10/28 14:31:37 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo1779=== CONT TestService_readinessHandler1780--- PASS: TestNARDeduplicationMetadataUploadBug (0.89s)17812026/10/28 14:31:37 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo17822026/10/28 14:31:37 INFO Received push request method=POST path=/api/pushes17832026/10/28 14:31:37 INFO Received push request method=POST path=/api/pushes17842026/10/28 14:31:37 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17852026/10/28 14:31:37 INFO Uploading gnq8cb1m89v4ffjhgilbwgdxazjvz88z-a (216B)17862026/10/28 14:31:37 INFO Uploading ynviqnqkpdfbwqrz3c5cm1nh4drcyvd2-shared-dep (136B)1787=== NAME TestClientCADerivations1788 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1789 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1790 error: binary cache 's3://bucket75?endpoint=http://localhost:38123®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3055989128/001/store'1791 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 117922026/10/28 14:31:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1793--- PASS: TestConcurrentPinUpdatesAgree (0.97s)1794=== CONT TestChildrenInheritRaisedFileLimit17952026/10/28 14:31:37 INFO Received push request method=POST path=/api/pushes17962026/10/28 14:31:37 INFO Signed narinfos id=1 count=117972026/10/28 14:31:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17982026/10/28 14:31:37 WARN Failed to register uploaded object key=nar/0z94fqc75kfz7ypl5kys8lpvddn4mjfwgi65g2jjkvhwxfhbq3z1.nar.zst error="server returned 404: 404 page not found\n"1799=== CONT TestCacheConfigHandlerMaxNarSize18002026/10/28 14:31:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1801=== CONT TestPush_RejectsBadRequests1802--- PASS: TestChildrenInheritRaisedFileLimit (0.00s)1803--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)18042026/10/28 14:31:37 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"18052026/10/28 14:31:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18062026/10/28 14:31:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18072026/10/28 14:31:37 INFO Uploading ccjmlnpy9vlhqmwjpsnbmnri1wnc9m9j-lost-commit.txt (152B)18082026/10/28 14:31:37 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"18092026/10/28 14:31:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18102026/10/28 14:31:37 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=118112026/10/28 14:31:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18122026/10/28 14:31:37 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo18132026/10/28 14:31:37 WARN Failed to register uploaded object key=2yi989nvjs0qwh8gq84hasfnqnbb6zjl.ls error="server returned 404: 404 page not found\n"18142026/10/28 14:31:37 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"18152026/10/28 14:31:37 WARN Failed to register uploaded object key=ynviqnqkpdfbwqrz3c5cm1nh4drcyvd2.ls error="server returned 404: 404 page not found\n"18162026/10/28 14:31:37 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18172026/10/28 14:31:37 WARN Failed to register uploaded object key=gnq8cb1m89v4ffjhgilbwgdxazjvz88z.ls error="server returned 404: 404 page not found\n"18182026/10/28 14:31:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18192026/10/28 14:31:37 INFO Signed narinfos id=1 count=318202026/10/28 14:31:37 INFO Uploading 3 narinfos18212026/10/28 14:31:37 WARN Failed to register uploaded object key=ccjmlnpy9vlhqmwjpsnbmnri1wnc9m9j.ls error="server returned 404: 404 page not found\n"18222026/10/28 14:31:37 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign18232026/10/28 14:31:37 INFO Signed narinfos id=4 count=118242026/10/28 14:31:37 INFO Uploading 1 narinfos1825--- PASS: TestClientCADerivations (0.95s)1826=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle18272026/10/28 14:31:37 WARN Failed to register uploaded object key=2yi989nvjs0qwh8gq84hasfnqnbb6zjl.narinfo error="server returned 404: 404 page not found\n"1828--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.31s)1829=== CONT TestService_Rustfstest1830=== CONT TestSkippedUploadsHandler1831--- PASS: TestPresentRefreshesOnlyStaleClosures (0.26s)18322026/10/28 14:31:37 INFO Client skipped oversized paths paths=3 nar_bytes=500000000018332026/10/28 14:31:37 WARN Failed to register uploaded object key=ynviqnqkpdfbwqrz3c5cm1nh4drcyvd2.narinfo error="server returned 404: 404 page not found\n"18342026/10/28 14:31:37 INFO Received complete push request method=POST path=/api/pushes/4/complete18352026/10/28 14:31:37 WARN Failed to register uploaded object key=ccjmlnpy9vlhqmwjpsnbmnri1wnc9m9j.narinfo error="server returned 404: 404 page not found\n"18362026/10/28 14:31:37 INFO Received complete push request method=POST path=/api/pushes/1/complete18372026/10/28 14:31:37 WARN Failed to register uploaded object key=gnq8cb1m89v4ffjhgilbwgdxazjvz88z.narinfo error="server returned 404: 404 page not found\n"18382026/10/28 14:31:37 INFO Completed push id=4 objects=3 duration=2.984096ms18392026/10/28 14:31:37 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:46737/api/pushes/4/complete\": EOF" url=http://127.0.0.1:46737/api/pushes/4/complete18402026/10/28 14:31:37 INFO Completed push id=1 objects=8 duration=10.56954ms18412026/10/28 14:31:37 INFO Upload complete. (113ms)1842=== NAME TestClientPushesUseOnePush1843 client_pushes_test.go:97: Retrieved narinfo from S3:1844 StorePath: /build/TestClientPushesUseOnePush1383460445/001/store/ynviqnqkpdfbwqrz3c5cm1nh4drcyvd2-shared-dep1845 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1846 Compression: zstd1847 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821848 NarSize: 1361849 References: 1850 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n18512026/10/28 14:31:37 INFO Received push request method=POST path=/api/pushes1852--- PASS: TestCacheStatsHandler (0.21s)1853=== CONT TestCreatePendingClosureRejectsOversizedNAR18542026/10/28 14:31:37 INFO Received uploads request method=POST path=/api/pending_closures1855--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1856=== CONT TestCacheConfigHandler1857=== RUN TestCacheConfigHandler/full_config,_no_issuer1858=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1859=== RUN TestCacheConfigHandler/no_cache_url_configured1860=== PAUSE TestCacheConfigHandler/no_cache_url_configured1861=== RUN TestCacheConfigHandler/no_signing_keys1862=== PAUSE TestCacheConfigHandler/no_signing_keys1863=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1864=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1865=== CONT TestService_healthCheckHandler1866=== NAME TestClientPushesUseOnePush1867 client_pushes_test.go:97: Retrieved narinfo from S3:1868 StorePath: /build/TestClientPushesUseOnePush1383460445/001/store/gnq8cb1m89v4ffjhgilbwgdxazjvz88z-a1869 URL: nar/0z94fqc75kfz7ypl5kys8lpvddn4mjfwgi65g2jjkvhwxfhbq3z1.nar.zst1870 Compression: zstd1871 NarHash: sha256:0z94fqc75kfz7ypl5kys8lpvddn4mjfwgi65g2jjkvhwxfhbq3z11872 NarSize: 2161873 References: /build/TestClientPushesUseOnePush1383460445/001/store/ynviqnqkpdfbwqrz3c5cm1nh4drcyvd2-shared-dep1874 CA: text:sha256:1z051aav6cvv43v4j82h37ns9pa774vs86n8hliw028mizn093fq1875 client_pushes_test.go:97: Retrieved narinfo from S3:1876 StorePath: /build/TestClientPushesUseOnePush1383460445/001/store/2yi989nvjs0qwh8gq84hasfnqnbb6zjl-b1877 URL: nar/0z94fqc75kfz7ypl5kys8lpvddn4mjfwgi65g2jjkvhwxfhbq3z1.nar.zst1878 Compression: zstd1879 NarHash: sha256:0z94fqc75kfz7ypl5kys8lpvddn4mjfwgi65g2jjkvhwxfhbq3z11880 NarSize: 2161881 References: /build/TestClientPushesUseOnePush1383460445/001/store/ynviqnqkpdfbwqrz3c5cm1nh4drcyvd2-shared-dep1882 CA: text:sha256:1z051aav6cvv43v4j82h37ns9pa774vs86n8hliw028mizn093fq1883--- PASS: TestSkippedUploadsHandler (0.04s)1884=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18852026/10/28 14:31:37 INFO Received create pin request method=POST path=/api/pins/deploy18862026/10/28 14:31:37 INFO lead: released remote=192.0.2.1:123418872026/10/28 14:31:37 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo1888=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1889--- PASS: TestClientPushesUseOnePush (0.86s)1890=== CONT TestGCEndsOnShutdown/before_the_run1891--- PASS: TestCreatePinRejectsBadInput (1.21s)1892=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1893--- PASS: TestLeadElectsOneAndHandsOver (3.08s)18942026/10/28 14:31:37 INFO Received complete push request method=POST path=/api/pushes/4/complete18952026-10-28 14:31:37.571 UTC [1230] ERROR: Push does not exist: id=418962026-10-28 14:31:37.571 UTC [1230] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE18972026-10-28 14:31:37.571 UTC [1230] STATEMENT: -- name: CommitPush :one1898 SELECT commit_push($1::bigint)::bigint1899 19002026/10/28 14:31:37 WARN Push not found id=419012026/10/28 14:31:37 INFO Upload complete. (192ms)1902=== NAME TestClientIntegration1903 client_integration_test.go:422: Retrieved narinfo from S3:1904 StorePath: /build/TestClientIntegration947834883/002/store/ccjmlnpy9vlhqmwjpsnbmnri1wnc9m9j-lost-commit.txt1905 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1906 Compression: zstd1907 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1908 NarSize: 1521909 References: 1910 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1911 client_integration_test.go:425: Testing garbage collection...19122026/10/28 14:31:37 WARN readiness check failed error="closed pool"1913=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1914--- PASS: TestService_readinessHandler (0.23s)19152026/10/28 14:31:37 INFO Starting cleanup of old closures method=DELETE path=/api/closures19162026/10/28 14:31:37 INFO Garbage collection started19172026/10/28 14:31:37 INFO Aborted multipart uploads count=0 kept=019182026/10/28 14:31:37 WARN Force mode enabled - objects will be deleted immediately without grace period1919=== RUN TestPush_RejectsBadRequests/bad_root1920=== PAUSE TestPush_RejectsBadRequests/bad_root1921=== RUN TestPush_RejectsBadRequests/root_not_in_objects1922=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1923=== RUN TestPush_RejectsBadRequests/no_roots1924=== PAUSE TestPush_RejectsBadRequests/no_roots1925=== RUN TestPush_RejectsBadRequests/no_objects1926=== PAUSE TestPush_RejectsBadRequests/no_objects1927=== CONT TestServerTLSConfig/no_client_CA1928=== CONT TestServerTLSConfig/not_a_PEM_file1929=== CONT TestServerTLSConfig/missing_CA_file1930=== CONT TestResolveDBConnectionString/file_when_flag_empty1931--- PASS: TestServerTLSConfig (0.00s)1932 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1933 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1934 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1935=== CONT TestResolveDBConnectionString/nothing_configured1936=== CONT TestResolveDBConnectionString/missing_file_is_an_error1937=== CONT TestResolveDBConnectionString/flag_wins1938=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1939=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1940--- PASS: TestResolveDBConnectionString (0.00s)1941 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1942 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1943 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1944 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1945 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1946=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1947--- PASS: TestService_Rustfstest (0.25s)19482026/10/28 14:31:37 INFO Received uploads request method=POST path=/api/pending_closures19492026/10/28 14:31: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=019502026/10/28 14:31:37 INFO Vacuumed table table=pending_closures19512026/10/28 14:31:37 INFO Vacuumed table table=pending_objects19522026/10/28 14:31:37 INFO Vacuumed table table=multipart_uploads19532026/10/28 14:31:37 INFO Vacuumed table table=closures19542026/10/28 14:31:37 INFO Vacuumed table table=objects1955--- PASS: TestService_healthCheckHandler (0.37s)1956=== CONT TestParseSingleRange/none1957=== CONT TestParseSingleRange/start_far_past_EOF1958=== CONT TestParseSingleRange/single_byte1959=== CONT TestParseSingleRange/start_past_EOF1960=== CONT TestParseSingleRange/suffix_exceeds_size1961=== CONT TestParseSingleRange/suffix1962=== CONT TestParseSingleRange/malformed_no_dash1963=== CONT TestParseSingleRange/multi-range_ignored1964=== CONT TestParseSingleRange/malformed_both_empty1965=== CONT TestParseSingleRange/open-ended1966=== CONT TestParseSingleRange/unknown_unit1967=== CONT TestParseSingleRange/closed1968=== CONT TestParseSingleRange/malformed_end_before_start1969=== CONT TestParseSingleRange/end_clamped_to_size1970=== CONT TestClientErrorHandling/InvalidAuthToken1971--- PASS: TestParseSingleRange (0.00s)1972 --- PASS: TestParseSingleRange/none (0.00s)1973 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1974 --- PASS: TestParseSingleRange/single_byte (0.00s)1975 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1976 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1977 --- PASS: TestParseSingleRange/suffix (0.00s)1978 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1979 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1980 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1981 --- PASS: TestParseSingleRange/open-ended (0.00s)1982 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1983 --- PASS: TestParseSingleRange/closed (0.00s)1984 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1985 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)19862026/10/28 14:31:37 INFO Received uploads request method=POST path=/api/pending_closures1987=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1988=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1989=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1990=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1991=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1992=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1993=== CONT TestClientErrorHandling/ServerNotAvailable19942026/10/28 14:31:38 INFO Aborted multipart uploads count=0 kept=019952026/10/28 14:31:38 WARN Force mode enabled - objects will be deleted immediately without grace period19962026/10/28 14:31:38 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=019972026/10/28 14:31:38 INFO Vacuumed table table=pending_closures19982026/10/28 14:31:38 INFO Vacuumed table table=pending_objects19992026/10/28 14:31:38 INFO Vacuumed table table=multipart_uploads20002026/10/28 14:31:38 INFO Vacuumed table table=closures20012026/10/28 14:31:38 INFO Vacuumed table table=objects2002--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.36s)2003=== CONT TestClientErrorHandling/InvalidStorePath2004=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false20052026/10/28 14:31:38 INFO Received uploads request method=POST path=/api/pending_closures20062026/10/28 14:31:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20072026/10/28 14:31:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20082026/10/28 14:31:38 INFO Aborted multipart uploads count=0 kept=020092026/10/28 14:31:38 WARN Force mode enabled - objects will be deleted immediately without grace period20102026/10/28 14:31:38 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2011=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true20122026/10/28 14:31:38 INFO Aborted multipart uploads count=0 kept=020132026/10/28 14:31:38 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LmVjNzc3ZDVlLThmZjItNGI2Yy04YjFlLWZkNDhmNjMyY2JiNXgxNzkzMTk3ODk3Mjk0MjM5MjUx parts=1020142026/10/28 14:31:38 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20152026/10/28 14:31:38 WARN Force mode enabled - objects will be deleted immediately without grace period20162026/10/28 14:31:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20172026/10/28 14:31:38 INFO Completed upload id=1 objects=2 duration=6.451282ms20182026/10/28 14:31:38 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:38123/bucket100/?delete=\": context canceled"20192026/10/28 14:31:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20202026/10/28 14:31:38 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=020212026/10/28 14:31:38 INFO Vacuumed table table=pending_closures20222026/10/28 14:31:38 INFO Vacuumed table table=pending_objects20232026/10/28 14:31:38 INFO Vacuumed table table=multipart_uploads20242026/10/28 14:31:38 INFO Vacuumed table table=closures2025=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2026=== CONT TestIsValidCachePath/short_hash2027=== CONT TestIsValidCachePath/wrong_extension2028=== CONT TestIsValidCachePath/leading_slash2029=== CONT TestIsValidCachePath/empty2030=== CONT TestIsValidCachePath/nar_xz2031=== CONT TestIsValidCachePath/realisation2032=== CONT TestIsValidCachePath/log2033=== CONT TestIsValidCachePath/nar_zst20342026/10/28 14:31:38 INFO Received uploads request method=POST path=/api/pending_closures2035=== CONT TestIsValidCachePath/invalid_char_e2036=== CONT TestIsValidCachePath/nar_uncompressed2037=== CONT TestIsValidCachePath/random_path2038=== CONT TestIsValidCachePath/nix-cache-info2039=== CONT TestIsValidCachePath/index.html2040=== CONT TestIsValidCachePath/nar_bz22041=== CONT TestIsValidCachePath/ls2042=== CONT TestIsValidCachePath/invalid_char_u20432026/10/28 14:31:38 INFO Vacuumed table table=objects2044=== CONT TestIsValidCachePath/traversal_parent2045=== CONT TestIsValidCachePath/narinfo2046=== CONT TestIsValidCachePath/traversal_in_middle2047=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key2048--- PASS: TestIsValidCachePath (0.01s)2049 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2050 --- PASS: TestIsValidCachePath/short_hash (0.00s)2051 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2052 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2053 --- PASS: TestIsValidCachePath/empty (0.00s)2054 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2055 --- PASS: TestIsValidCachePath/realisation (0.00s)2056 --- PASS: TestIsValidCachePath/log (0.00s)2057 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2058 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2059 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2060 --- PASS: TestIsValidCachePath/random_path (0.00s)2061 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2062 --- PASS: TestIsValidCachePath/index.html (0.00s)2063 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2064 --- PASS: TestIsValidCachePath/ls (0.00s)2065 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2066 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2067 --- PASS: TestIsValidCachePath/narinfo (0.00s)2068 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)20692026/10/28 14:31:38 INFO Received request for more parts method=POST path=/20702026/10/28 14:31:38 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LmZkZGE0OTVkLTgxZDAtNDQxZC05NGQzLWY5YjMxMjlmMThkOXgxNzkzMTk3ODk3MzM1MzI3Njgw parts=102071=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key20722026/10/28 14:31:38 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20732026/10/28 14:31:38 INFO Received complete multipart upload request method=POST path=/2074=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal20752026/10/28 14:31:38 INFO Received uploads request method=POST path=/2076=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info20772026/10/28 14:31:38 INFO Received uploads request method=POST path=/2078=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2079--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2080 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2081 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2082 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2083 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)20842026/10/28 14:31:38 INFO Received uploads request method=POST path=/api/pending_closures20852026/10/28 14:31:38 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LjQ3YmQ2MTk1LWI1NzgtNDUyZS05NmM5LTUxYzY0M2Q1Y2I5MngxNzkzMTk3ODk2NjQ5MzQ2MTYy parts=1020862026/10/28 14:31:38 INFO Received complete push request method=POST path=/api/pushes/1/complete2087=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20882026/10/28 14:31:38 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]2089=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2090=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20912026/10/28 14:31:38 INFO Completed upload id=1 objects=2 duration=6.242362ms20922026/10/28 14:31:38 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000020932026/10/28 14:31:38 INFO Completed push id=1 objects=4 duration=7.337854ms20942026/10/28 14:31:38 INFO Received uploads request method=POST path=/api/pending_closures20952026/10/28 14:31:38 WARN Authentication failed token_preview=eyJhbGciOi...JR7ZADDS1A token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2096=== CONT TestService_RequireScope_OIDC/builder_may_write20972026/10/28 14:31:38 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo20982026/10/28 14:31:38 WARN Found objects in DB but missing from S3, will re-upload count=120992026/10/28 14:31:38 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete2100=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read21012026/10/28 14:31:38 INFO Completed upload id=2 objects=2 duration=1.641443ms21022026/10/28 14:31:38 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]2103=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2104=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc21052026/10/28 14:31:38 INFO Starting cleanup of old closures method=DELETE path=/api/closures2106=== CONT TestService_RequireScope_OIDC/reader_may_not_write2107=== CONT TestService_RequireScope_OIDC/static_token_may_admin2108=== CONT TestService_RequireScope_OIDC/ops_may_not_write2109=== CONT TestService_RequireScope_OIDC/ops_may_admin21102026/10/28 14:31:38 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete2111=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2112=== CONT TestService_RequireScope_OIDC/writer_implies_read2113=== CONT TestService_RequireScope_OIDC/static_token_may_write21142026/10/28 14:31:38 INFO Completed upload id=3 objects=2 duration=2.564765ms2115=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2116=== CONT TestService_RequireScope_OIDC/reader_may_read21172026-10-28 14:31:38.233 UTC [175] LOG: checkpoints are occurring too frequently (11 seconds apart)21182026-10-28 14:31:38.233 UTC [175] HINT: Consider increasing the configuration parameter "max_wal_size".21192026-10-28 14:31:38.234 UTC [175] LOG: checkpoint starting: wal2120=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2121=== CONT TestPendingClosureWriteTimeout/670k_objects2122=== CONT TestPendingClosureWriteTimeout/empty2123=== CONT TestPendingClosureWriteTimeout/400_objects2124=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline21252026/10/28 14:31:38 INFO Aborted multipart uploads count=0 kept=021262026/10/28 14:31:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21272026/10/28 14:31:38 INFO Aborted multipart uploads count=0 kept=021282026/10/28 14:31:38 WARN Force mode enabled - objects will be deleted immediately without grace period2129--- PASS: TestService_AuthMiddleware_OIDC (0.68s)2130 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2131 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2132 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2133 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)21342026/10/28 14:31:38 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=02135=== CONT TestIsValidUploadKey/nar_zst2136--- PASS: TestService_verifyS3Integrity (1.42s)21372026/10/28 14:31:38 INFO Vacuumed table table=pending_closures2138=== CONT TestIsValidUploadKey/realisation2139=== CONT TestIsValidUploadKey/nix-cache-info2140=== CONT TestIsValidUploadKey/empty_key2141=== CONT TestIsValidUploadKey/build_log_plus_in_name2142=== CONT TestIsValidUploadKey/listing2143=== CONT TestIsValidUploadKey/nar_xz2144=== CONT TestIsValidUploadKey/build_log_home-manager_file2145=== CONT TestIsValidUploadKey/realisation_plus_in_output2146=== CONT TestIsValidUploadKey/build_log_question_mark2147=== CONT TestIsValidUploadKey/build_log_equals2148=== CONT TestIsValidUploadKey/traversal_nar2149=== CONT TestIsValidUploadKey/unknown_type2150=== CONT TestIsValidUploadKey/traversal2151=== CONT TestIsValidUploadKey/nar_plain21522026/10/28 14:31:38 INFO Vacuumed table table=pending_objects2153=== CONT TestIsValidUploadKey/build_log2154=== CONT TestIsValidUploadKey/index.html2155=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2156=== CONT TestIsValidUploadKey/narinfo2157=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2158=== CONT TestIsValidUploadKey/absolute2159=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2160=== CONT TestProxyWriteTimeout/narinfo2161--- PASS: TestIsValidUploadKey (0.01s)2162 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2163 --- PASS: TestIsValidUploadKey/realisation (0.00s)2164 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2165 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2166 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2167 --- PASS: TestIsValidUploadKey/listing (0.00s)2168 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2169 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2170 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2171 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2172 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2173 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2174 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2175 --- PASS: TestIsValidUploadKey/traversal (0.00s)2176 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2177 --- PASS: TestIsValidUploadKey/build_log (0.00s)2178 --- PASS: TestIsValidUploadKey/index.html (0.00s)2179 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2180 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2181 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2182 --- PASS: TestIsValidUploadKey/absolute (0.00s)2183 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2184=== CONT TestProxyWriteTimeout/1_GiB_nar2185=== CONT TestProxyWriteTimeout/10_GiB_nar2186=== CONT TestProxyWriteTimeout/unknown_size2187=== CONT TestCacheConfigHandler/full_config,_no_issuer2188--- PASS: TestProxyWriteTimeout (0.00s)2189 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2190 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2191 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2192 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2193--- PASS: TestService_RequireScope_OIDC (0.96s)2194 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2195 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2196 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2197 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2198 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2199 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2200 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2201 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2202 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2203 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2204 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2205 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2206 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2207 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2208=== CONT TestCacheConfigHandler/no_cache_url_configured2209=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2210=== CONT TestCacheConfigHandler/no_signing_keys2211=== CONT TestPush_RejectsBadRequests/bad_root2212--- PASS: TestCacheConfigHandler (0.00s)2213 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2214 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2215 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2216 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)22172026/10/28 14:31:38 INFO Received push request method=POST path=/api/pushes2218=== CONT TestPush_RejectsBadRequests/no_objects22192026/10/28 14:31:38 INFO Received push request method=POST path=/api/pushes22202026/10/28 14:31:38 INFO Vacuumed table table=multipart_uploads2221=== CONT TestPush_RejectsBadRequests/no_roots22222026/10/28 14:31:38 INFO Received push request method=POST path=/api/pushes2223=== CONT TestPush_RejectsBadRequests/root_not_in_objects22242026/10/28 14:31:38 INFO Received push request method=POST path=/api/pushes2225=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts22262026/10/28 14:31:38 WARN Request failed, retrying attempt=2 backoff=207.32181ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22272026/10/28 14:31:38 INFO Received request for more parts method=POST path=/2228=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart22292026/10/28 14:31:38 INFO Received complete multipart upload request method=POST path=/2230--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2231 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.67s)2232 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.72s)22332026/10/28 14:31:38 INFO Vacuumed table table=closures22342026/10/28 14:31:38 INFO Vacuumed table table=objects22352026/10/28 14:31:38 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LmQyNDM4ZDEwLTUyN2QtNDA2Yi04YzU2LTZhN2Y1MWRjYThkMngxNzkzMTk3ODk3MzY1NTAwNjk4 parts=102236--- PASS: TestMetricsCommit (2.05s)2237=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure22382026/10/28 14:31:38 INFO Received uploads request method=POST path=/22392026/10/28 14:31:38 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000002240--- PASS: TestGCEndsOnShutdown (0.01s)2241 --- PASS: TestGCEndsOnShutdown/before_the_run (0.58s)2242 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.65s)2243 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.67s)2244--- PASS: TestPush_RejectsBadRequests (0.25s)2245 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2246 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2247 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2248 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)22492026/10/28 14:31:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2250--- PASS: TestService_createPendingClosureHandler (1.27s)22512026/10/28 14:31:38 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LjRiNWY5NzZiLWM4YzktNGU4Yi05ZjczLTFlNzdkODFmN2YzOHgxNzkzMTk3ODk3Mzg0NTQ5NTc1 parts=1222522026/10/28 14:31:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22532026/10/28 14:31:38 INFO Received uploads request method=POST path=/api/pending_closures22542026/10/28 14:31:38 INFO Received uploads request method=POST path=/api/pending_closures22552026/10/28 14:31:38 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LjQyOTgyOWIxLTlmOTQtNDY5Yi1iNmZhLTg0NDlmZDE4NGVjYngxNzkzMTk3ODk3NTAwMDAwNjU2 parts=102256--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.28s)22572026/10/28 14:31:38 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22582026/10/28 14:31:38 INFO Received uploads request method=POST path=/api/pending_closures22592026/10/28 14:31:38 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22602026/10/28 14:31:38 WARN Request failed, retrying attempt=3 backoff=390.929079ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22612026/10/28 14:31:38 INFO Received uploads request method=POST path=/api/pending_closures2262--- PASS: TestDeleteClosuresRacingPins (1.96s)2263--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2264 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (1.05s)2265 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (1.09s)2266=== NAME TestOrphanedObjectsGCStressTest2267 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2268 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion22692026/10/28 14:31:38 WARN Request failed, retrying attempt=4 backoff=738.694972ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22702026/10/28 14:31:38 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LmRlNWVlN2M4LWQ3NWQtNGNjNS1hODI0LWM1OGFkNDU0MmE4ZngxNzkzMTk3ODk4MzkyOTE3MTMy error="Access Denied"22712026/10/28 14:31:38 WARN keeping failed pending closure for cleanup to retry the abort id=12272--- PASS: TestPendingClosureFailureTracksEveryUpload (0.00s)2273 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (0.79s)2274 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (0.77s)22752026/10/28 14:31:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22762026/10/28 14:31:38 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LmM5OGZkM2M1LWFjMGQtNGEzMy04MmVhLTAyMGI2ZDA0MjUxYXgxNzkzMTk3ODk3MzY3Mjc5MTkx parts=1022772026/10/28 14:31:38 INFO Received complete push request method=POST path=/api/pushes/1/complete22782026/10/28 14:31:38 INFO Completed push id=1 objects=4 duration=5.10782ms22792026/10/28 14:31:38 INFO Received push request method=POST path=/api/pushes22802026/10/28 14:31:39 INFO Aborted multipart uploads count=0 kept=022812026/10/28 14:31:39 WARN Force mode enabled - objects will be deleted immediately without grace period22822026/10/28 14:31:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22832026/10/28 14:31:39 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LmEwOWY3MGIwLWFmNTAtNDg4Yi1iYjdjLWQ5NDc5NGI0NjFkN3gxNzkzMTk3ODk3NDk5ODkzMzk2 parts=1022842026/10/28 14:31:39 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=022852026/10/28 14:31:39 INFO Vacuumed table table=pending_closures22862026/10/28 14:31:39 INFO Vacuumed table table=pending_objects22872026/10/28 14:31:39 INFO Vacuumed table table=multipart_uploads22882026/10/28 14:31:39 INFO Vacuumed table table=closures22892026/10/28 14:31:39 INFO Vacuumed table table=objects22902026/10/28 14:31:39 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=022912026/10/28 14:31:39 INFO Received create pin request method=POST path=/api/pins/myapp22922026/10/28 14:31:39 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1864708213/001/store/hdy85q5j77d4cza51fpx1vjybq3nngyl-pinned-file.txt narinfo_key=hdy85q5j77d4cza51fpx1vjybq3nngyl.narinfo22932026/10/28 14:31:39 INFO Starting cleanup of old closures method=DELETE path=/api/closures22942026/10/28 14:31:39 INFO Garbage collection started22952026/10/28 14:31:39 INFO Aborted multipart uploads count=0 kept=02296--- PASS: TestPendingClosureWriteTimeout (0.00s)2297 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2298 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2299 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2300 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.08s)23012026/10/28 14:31:39 WARN Force mode enabled - objects will be deleted immediately without grace period23022026/10/28 14:31:39 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=023032026/10/28 14:31:39 INFO Vacuumed table table=pending_closures23042026/10/28 14:31:39 INFO Vacuumed table table=pending_objects23052026/10/28 14:31:39 INFO Vacuumed table table=multipart_uploads23062026/10/28 14:31:39 INFO Vacuumed table table=closures23072026/10/28 14:31:39 INFO Vacuumed table table=objects23082026/10/28 14:31:39 WARN Request failed, retrying attempt=5 backoff=1.660965628s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23092026/10/28 14:31:39 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02310=== NAME TestClientIntegration2311 client_integration_test.go:432: Objects in database after GC:2312 client_integration_test.go:432: Successfully deleted all objects with GC --force2313--- PASS: TestClientIntegration (3.28s)23142026/10/28 14:31:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23152026/10/28 14:31:39 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LjMwOTIzZjg0LTVmMWUtNDhjOC04NmFiLWI0YjVjYzllYTM5ZXgxNzkzMTk3ODk3NDk5OTkxODk2 parts=1023162026/10/28 14:31:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23172026/10/28 14:31:39 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LjRjZDQ4NzljLTAxMDktNGMxNC1iNDlhLTJiOTc5ODk4ZmEwZXgxNzkzMTk3ODk4OTg2NDA5MDAz parts=1023182026/10/28 14:31:39 INFO Received complete push request method=POST path=/api/pushes/2/complete23192026/10/28 14:31:39 INFO Completed push id=2 objects=4 duration=3.053856ms2320--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.73s)2321--- PASS: TestConnectWaitsForAPeerMigration (5.17s)2322=== NAME TestOrphanedObjectsGCStressTest2323 orphaned_objects_gc_test.go:503: Stress test completed successfully:2324 orphaned_objects_gc_test.go:504: - Active objects preserved: 202325 orphaned_objects_gc_test.go:505: - Objects deleted: 2102326 orphaned_objects_gc_test.go:506: - Total GC'd: 2102327--- PASS: TestOrphanedObjectsGCStressTest (4.94s)2328--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.02s)23292026/10/28 14:31:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23302026/10/28 14:31:40 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LmI3ZGRjMDZjLTNiMjUtNDcyYS04YWVkLTQwMTFhYzdlYzJhMHgxNzkzMTk3ODk3NDk4MzIzNTIz parts=1023312026/10/28 14:31:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23322026/10/28 14:31:41 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LjY0ZDVkYmEwLTVjOWItNDM5Ni05OTM3LWNiNGMxYmI4MTdkOXgxNzkzMTk3ODk3NDk5ODE3ODY2 parts=102333=== NAME TestPinProtectsFromGC2334 client_integration_test.go:963: Pin successfully protected closure from garbage collection23352026/10/28 14:31:41 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2336--- PASS: TestPinProtectsFromGC (4.92s)23372026/10/28 14:31:41 WARN Request failed, retrying attempt=2 backoff=207.043767ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23382026/10/28 14:31:41 WARN Request failed, retrying attempt=3 backoff=375.979793ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23392026/10/28 14:31:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23402026/10/28 14:31:41 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=YWI1YjA4YzYtN2EwNC00ZGZlLThiMDctZTg1YWQ4ZGU5NjI2LjY2Mzk2NTkzLTBiZGQtNDJiMC1iYjYwLTJlOWU5NTdhZTk0N3gxNzkzMTk3ODk3NDk5OTM3MjM2 parts=1023412026-10-28 14:31:41.718 UTC [2244] ERROR: could not obtain lock on row in relation "closures"23422026-10-28 14:31:41.718 UTC [2244] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23432026-10-28 14:31:41.719 UTC [2244] ERROR: could not obtain lock on row in relation "closures"23442026-10-28 14:31:41.719 UTC [2244] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23452026-10-28 14:31:41.720 UTC [2244] ERROR: could not obtain lock on row in relation "closures"23462026-10-28 14:31:41.720 UTC [2244] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23472026-10-28 14:31:41.721 UTC [2244] ERROR: could not obtain lock on row in relation "closures"23482026-10-28 14:31:41.721 UTC [2244] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23492026-10-28 14:31:41.722 UTC [2244] ERROR: could not obtain lock on row in relation "closures"23502026-10-28 14:31:41.722 UTC [2244] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT2351--- PASS: TestPush_RootsAreLockedInByteOrder (4.48s)23522026/10/28 14:31:42 WARN Request failed, retrying attempt=4 backoff=807.873567ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23532026/10/28 14:31:42 INFO Aborted multipart uploads count=1 kept=023542026/10/28 14:31:42 INFO Received cleanup request method=DELETE path=/api/pending_closures23552026/10/28 14:31:42 INFO Aborted multipart uploads count=1 kept=023562026/10/28 14:31:42 WARN Rate limiter enabled after throttle name=s3-test rate=523572026/10/28 14:31:42 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2358=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2359 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102360 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002361--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.69s)2362--- PASS: TestPendingCleanupUsesOneCutoff (6.50s)23632026/10/28 14:31:42 WARN Request failed, retrying attempt=5 backoff=1.448921177s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23642026/10/28 14:31:44 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"23652026/10/28 14:31:44 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23662026/10/28 14:31:44 WARN Request failed, retrying attempt=2 backoff=184.680736ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23672026/10/28 14:31:44 WARN Request failed, retrying attempt=3 backoff=369.582946ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2368--- PASS: TestUploadHandlersRejectOversizedBody (0.95s)2369 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.55s)2370 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.60s)2371 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (6.43s)23722026/10/28 14:31:44 WARN Request failed, retrying attempt=4 backoff=750.860949ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23732026/10/28 14:31:45 WARN Request failed, retrying attempt=5 backoff=1.752033684s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23742026/10/28 14:31:47 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23752026/10/28 14:31:47 WARN Request failed, retrying attempt=2 backoff=206.889071ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23762026/10/28 14:31:47 WARN Request failed, retrying attempt=3 backoff=437.14306ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23772026/10/28 14:31:48 WARN Request failed, retrying attempt=4 backoff=775.199926ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23782026/10/28 14:31:48 WARN Request failed, retrying attempt=5 backoff=1.744249422s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2379--- PASS: TestClientErrorHandling (0.00s)2380 --- PASS: TestClientErrorHandling/InvalidStorePath (0.26s)2381 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.57s)2382 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.64s)2383PASS2384{"timestamp":"2026-10-28T14:31:50.728420587Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:37288","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(394)"}2385{"timestamp":"2026-10-28T14:31:50.729076898Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:37148","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(391)"}2386{"timestamp":"2026-10-28T14:31:50.729184308Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:37152","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(387)"}23872026-10-28 14:31:51.166 UTC [170] LOG: received smart shutdown request23882026-10-28 14:31:51.172 UTC [170] LOG: background worker "logical replication launcher" (PID 180) exited with exit code 123892026-10-28 14:31:52.391 UTC [175] LOG: checkpoint complete: wrote 9324 buffers (56.9%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=13.137 s, sync=0.951 s, total=14.157 s; sync files=37079, longest=0.003 s, average=0.001 s; distance=533244 kB, estimate=533244 kB; lsn=0/22BC10A8, redo lsn=0/22024DC823902026-10-28 14:31:52.394 UTC [175] LOG: shutting down23912026-10-28 14:31:52.394 UTC [175] LOG: checkpoint starting: shutdown immediate23922026-10-28 14:31:52.510 UTC [175] LOG: checkpoint complete: wrote 1108 buffers (6.8%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.020 s, sync=0.093 s, total=0.117 s; sync files=408, longest=0.001 s, average=0.001 s; distance=11888 kB, estimate=481108 kB; lsn=0/22BC1120, redo lsn=0/22BC112023932026-10-28 14:31:52.581 UTC [170] LOG: database system is shut down2394Running OIDC tests...2395=== RUN TestAudienceForIssuer2396=== PAUSE TestAudienceForIssuer2397=== RUN TestHTTPClientForHasTimeouts2398=== PAUSE TestHTTPClientForHasTimeouts2399=== RUN TestGlobMatch2400=== PAUSE TestGlobMatch2401=== RUN TestValidateToken_ValidToken2402=== PAUSE TestValidateToken_ValidToken2403=== RUN TestValidateToken_WrongAudience2404=== PAUSE TestValidateToken_WrongAudience2405=== RUN TestValidateToken_Expired2406=== PAUSE TestValidateToken_Expired2407=== RUN TestValidateToken_BoundClaimsMismatch2408=== PAUSE TestValidateToken_BoundClaimsMismatch2409=== RUN TestValidateToken_BoundSubjectMismatch2410=== PAUSE TestValidateToken_BoundSubjectMismatch2411=== RUN TestValidateToken_MultipleProviders2412=== PAUSE TestValidateToken_MultipleProviders2413=== RUN TestValidateToken_NoMatchingProvider2414=== PAUSE TestValidateToken_NoMatchingProvider2415=== RUN TestValidateToken_KubernetesServiceAccount2416=== PAUSE TestValidateToken_KubernetesServiceAccount2417=== RUN TestNewValidator_KubernetesRequiresCA2418=== PAUSE TestNewValidator_KubernetesRequiresCA2419=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2420=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2421=== RUN TestPins_ReservedForMatchingRule2422=== PAUSE TestPins_ReservedForMatchingRule2423=== RUN TestPins_TopLevelShorthand2424=== PAUSE TestPins_TopLevelShorthand2425=== RUN TestPins_ConfigValidation2426=== PAUSE TestPins_ConfigValidation2427=== RUN TestScopes_LegacyProviderDefaultsToWrite2428=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2429=== RUN TestScopes_Rules2430=== PAUSE TestScopes_Rules2431=== RUN TestScopes_ConfigValidation2432=== PAUSE TestScopes_ConfigValidation2433=== CONT TestHTTPClientForHasTimeouts2434=== CONT TestNewValidator_KubernetesRequiresCA2435=== CONT TestPins_TopLevelShorthand2436=== CONT TestPins_ConfigValidation2437=== CONT TestScopes_ConfigValidation2438=== CONT TestScopes_Rules2439=== CONT TestScopes_LegacyProviderDefaultsToWrite2440=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2441=== CONT TestValidateToken_KubernetesServiceAccount2442=== CONT TestPins_ReservedForMatchingRule2443--- PASS: TestPins_ConfigValidation (0.00s)2444=== CONT TestValidateToken_Expired2445=== CONT TestValidateToken_NoMatchingProvider2446=== CONT TestValidateToken_BoundSubjectMismatch2447=== CONT TestValidateToken_BoundClaimsMismatch2448=== CONT TestValidateToken_MultipleProviders2449=== CONT TestGlobMatch2450=== CONT TestValidateToken_WrongAudience2451=== CONT TestValidateToken_ValidToken2452=== CONT TestAudienceForIssuer2453--- PASS: TestScopes_ConfigValidation (0.00s)2454=== RUN TestGlobMatch/foo_foo2455=== PAUSE TestGlobMatch/foo_foo2456=== RUN TestGlobMatch/foo_bar2457=== PAUSE TestGlobMatch/foo_bar2458=== RUN TestGlobMatch/*_2459=== PAUSE TestGlobMatch/*_2460=== RUN TestGlobMatch/*_anything2461--- PASS: TestAudienceForIssuer (0.00s)2462=== PAUSE TestGlobMatch/*_anything2463=== RUN TestGlobMatch/foo*_foo2464=== PAUSE TestGlobMatch/foo*_foo2465=== RUN TestGlobMatch/foo*_foobar2466=== PAUSE TestGlobMatch/foo*_foobar2467=== RUN TestGlobMatch/foo*_bar2468=== PAUSE TestGlobMatch/foo*_bar2469=== RUN TestGlobMatch/*bar_bar2470=== PAUSE TestGlobMatch/*bar_bar2471=== RUN TestGlobMatch/*bar_foobar2472=== PAUSE TestGlobMatch/*bar_foobar2473=== RUN TestGlobMatch/*bar_foo2474=== PAUSE TestGlobMatch/*bar_foo2475=== RUN TestGlobMatch/foo*bar_foobar2476=== PAUSE TestGlobMatch/foo*bar_foobar2477=== RUN TestGlobMatch/foo*bar_foo123bar2478=== PAUSE TestGlobMatch/foo*bar_foo123bar2479=== RUN TestGlobMatch/foo*bar_foobarbaz2480=== PAUSE TestGlobMatch/foo*bar_foobarbaz2481=== RUN TestGlobMatch/*/*_foo/bar2482=== PAUSE TestGlobMatch/*/*_foo/bar2483=== RUN TestGlobMatch/*/*_foo2484=== PAUSE TestGlobMatch/*/*_foo2485=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2486=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2487=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02488=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02489=== RUN TestGlobMatch/refs/*/main_refs/heads/main2490=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2491=== RUN TestGlobMatch/fo?_foo2492=== PAUSE TestGlobMatch/fo?_foo2493=== RUN TestGlobMatch/fo?_fo2494=== PAUSE TestGlobMatch/fo?_fo2495=== RUN TestGlobMatch/fo?_fooo2496=== PAUSE TestGlobMatch/fo?_fooo2497=== RUN TestGlobMatch/?oo_foo2498=== PAUSE TestGlobMatch/?oo_foo2499=== RUN TestGlobMatch/?oo_boo2500=== PAUSE TestGlobMatch/?oo_boo2501=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2502=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2503=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2504=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2505=== CONT TestGlobMatch/*_2506=== CONT TestGlobMatch/fo?_fo2507=== CONT TestGlobMatch/*/*_foo2508=== CONT TestGlobMatch/foo*_foobar2509=== CONT TestGlobMatch/foo_bar2510=== CONT TestGlobMatch/fo?_fooo2511=== CONT TestGlobMatch/fo?_foo2512=== CONT TestGlobMatch/foo_foo2513=== CONT TestGlobMatch/foo*bar_foobarbaz2514=== CONT TestGlobMatch/?oo_foo2515=== CONT TestGlobMatch/foo*_foo2516=== CONT TestGlobMatch/*_anything2517=== CONT TestGlobMatch/?oo_boo2518=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2519=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2520=== CONT TestGlobMatch/*bar_bar2521=== CONT TestGlobMatch/*bar_foo2522=== CONT TestGlobMatch/foo*bar_foobar2523=== CONT TestGlobMatch/foo*_bar2524=== CONT TestGlobMatch/foo*bar_foo123bar2525=== CONT TestGlobMatch/*bar_foobar2526=== CONT TestGlobMatch/refs/*/main_refs/heads/main2527=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02528=== CONT TestGlobMatch/*/*_foo/bar2529=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2530--- PASS: TestGlobMatch (0.01s)2531 --- PASS: TestGlobMatch/*/*_foo (0.00s)2532 --- PASS: TestGlobMatch/*_ (0.00s)2533 --- PASS: TestGlobMatch/fo?_fo (0.00s)2534 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2535 --- PASS: TestGlobMatch/foo_bar (0.00s)2536 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2537 --- PASS: TestGlobMatch/fo?_foo (0.00s)2538 --- PASS: TestGlobMatch/foo_foo (0.00s)2539 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2540 --- PASS: TestGlobMatch/?oo_foo (0.00s)2541 --- PASS: TestGlobMatch/foo*_foo (0.00s)2542 --- PASS: TestGlobMatch/*_anything (0.00s)2543 --- PASS: TestGlobMatch/?oo_boo (0.00s)2544 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2545 --- PASS: TestGlobMatch/*bar_foo (0.00s)2546 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2547 --- PASS: TestGlobMatch/foo*_bar (0.00s)2548 --- PASS: TestGlobMatch/*bar_bar (0.00s)2549 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2550 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2551 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2552 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2553 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2554 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2555 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)25562026/10/28 14:31:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42737/oidc2557--- PASS: TestValidateToken_ValidToken (0.02s)25582026/10/28 14:31:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33853/oidc25592026/10/28 14:31:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36933/oidc2560--- PASS: TestPins_TopLevelShorthand (0.05s)25612026/10/28 14:31:56 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12325622026/10/28 14:31:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46275/oidc2563--- PASS: TestScopes_Rules (0.05s)2564--- PASS: TestValidateToken_BoundClaimsMismatch (0.05s)2565--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.06s)25662026/10/28 14:31:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39309/oidc2567--- PASS: TestValidateToken_Expired (0.07s)25682026/10/28 14:31:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38459/oidc25692026/10/28 14:31:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38191/oidc2570--- PASS: TestValidateToken_WrongAudience (0.10s)2571--- PASS: TestPins_ReservedForMatchingRule (0.10s)25722026/10/28 14:31:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42779/oidc2573--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.12s)25742026/10/28 14:31:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41131/oidc25752026/10/28 14:31:56 http: TLS handshake error from 127.0.0.1:48218: remote error: tls: bad certificate2576--- PASS: TestNewValidator_KubernetesRequiresCA (0.16s)2577--- PASS: TestValidateToken_BoundSubjectMismatch (0.15s)25782026/10/28 14:31:56 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37071/oidc2579--- PASS: TestValidateToken_NoMatchingProvider (0.16s)25802026/10/28 14:31:56 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:390972581--- PASS: TestValidateToken_KubernetesServiceAccount (0.21s)25822026/10/28 14:31:56 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:44969/oidc25832026/10/28 14:31:56 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:35147/oidc2584--- PASS: TestValidateToken_MultipleProviders (0.25s)2585--- PASS: TestHTTPClientForHasTimeouts (0.41s)2586PASS2587Running hook tests...2588=== RUN TestSendPathsEmpty2589=== PAUSE TestSendPathsEmpty2590=== RUN TestQueueEnqueueAndFetch2591=== PAUSE TestQueueEnqueueAndFetch2592=== RUN TestQueueDeduplication2593=== PAUSE TestQueueDeduplication2594=== RUN TestQueueRemove2595=== PAUSE TestQueueRemove2596=== RUN TestQueueFetchBatchLimit2597=== PAUSE TestQueueFetchBatchLimit2598=== RUN TestQueueRetryMovesToBack2599=== PAUSE TestQueueRetryMovesToBack2600=== RUN TestQueueFetchRemoveLifecycle2601=== PAUSE TestQueueFetchRemoveLifecycle2602=== RUN TestQueueConcurrentWriters2603=== PAUSE TestQueueConcurrentWriters2604=== RUN TestQueueRemoveLargeClosure2605=== PAUSE TestQueueRemoveLargeClosure2606=== RUN TestServerClientIntegration2607--- PASS: TestServerClientIntegration (0.00s)2608=== RUN TestServerQueueError26092026/10/28 14:31:57 ERROR Failed to queue paths error="permission denied" count=12610--- PASS: TestServerQueueError (0.00s)2611=== RUN TestServerRefusesOversizedAndNonStoreRequests2612=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2613=== RUN TestGetListenerSocketActivation2614 server_test.go:309: === RUN TestGetListenerSocketActivation2615 --- PASS: TestGetListenerSocketActivation (0.00s)2616 PASS2617 2618--- PASS: TestGetListenerSocketActivation (1.02s)2619=== RUN TestServerStalledClientDoesNotBlockShutdown2620=== PAUSE TestServerStalledClientDoesNotBlockShutdown2621=== RUN TestServerBacksOffOnAcceptErrors2622=== PAUSE TestServerBacksOffOnAcceptErrors2623=== RUN TestDrainIsolatesPoisonPath2624=== PAUSE TestDrainIsolatesPoisonPath2625=== RUN TestRunNotBlockedByPoisonHead2626=== PAUSE TestRunNotBlockedByPoisonHead2627=== RUN TestDrainGivesUpWhenServerDown2628=== PAUSE TestDrainGivesUpWhenServerDown2629=== RUN TestFailedPathPrunedByLaterClosure2630=== PAUSE TestFailedPathPrunedByLaterClosure2631=== RUN TestWorkerUploadsAndRemoves2632=== PAUSE TestWorkerUploadsAndRemoves2633=== RUN TestWorkerSkipsGCdPaths2634=== PAUSE TestWorkerSkipsGCdPaths2635=== RUN TestWorkerPrunesClosureDeps2636=== PAUSE TestWorkerPrunesClosureDeps2637=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2638=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2639=== RUN TestDrainTimeout2640=== PAUSE TestDrainTimeout2641=== RUN TestDrainTimeoutDuringIsolation2642=== PAUSE TestDrainTimeoutDuringIsolation2643=== RUN TestShutdownFinishesInFlightPush2644=== PAUSE TestShutdownFinishesInFlightPush2645=== RUN TestWorkerRemoveFailureIsNotProgress2646=== PAUSE TestWorkerRemoveFailureIsNotProgress2647=== RUN TestWorkerKeepsPathItCannotStat2648=== PAUSE TestWorkerKeepsPathItCannotStat2649=== CONT TestQueueEnqueueAndFetch2650=== CONT TestDrainIsolatesPoisonPath2651=== CONT TestWorkerPrunesClosureDeps2652=== CONT TestWorkerKeepsPathItCannotStat2653=== CONT TestShutdownFinishesInFlightPush2654=== CONT TestDrainTimeoutDuringIsolation2655=== CONT TestDrainTimeout2656=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2657=== CONT TestQueueConcurrentWriters2658=== CONT TestWorkerSkipsGCdPaths2659=== CONT TestQueueRemoveLargeClosure2660=== CONT TestServerRefusesOversizedAndNonStoreRequests2661=== CONT TestFailedPathPrunedByLaterClosure2662=== CONT TestWorkerRemoveFailureIsNotProgress2663=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2664=== CONT TestQueueFetchRemoveLifecycle2665=== CONT TestServerStalledClientDoesNotBlockShutdown2666=== CONT TestQueueFetchBatchLimit26672026/10/28 14:31:58 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2668=== CONT TestQueueRetryMovesToBack2669=== CONT TestServerBacksOffOnAcceptErrors2670=== CONT TestQueueRemove2671=== CONT TestQueueDeduplication2672=== CONT TestWorkerUploadsAndRemoves2673=== CONT TestSendPathsEmpty2674=== CONT TestDrainGivesUpWhenServerDown26752026/10/28 14:31:58 ERROR Refusing path outside the store path=/nix/store store=/nix/store2676=== RUN TestShutdownFinishesInFlightPush/completes2677=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short26782026/10/28 14:31:58 ERROR Accept failed error="too many open files"2679=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2680--- PASS: TestSendPathsEmpty (0.00s)2681=== CONT TestRunNotBlockedByPoisonHead2682=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2683=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2684=== PAUSE TestShutdownFinishesInFlightPush/completes2685=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2686=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2687=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2688=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2689=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2690=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2691=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2692=== CONT TestShutdownFinishesInFlightPush/completes2693=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2694=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline26952026/10/28 14:31:58 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store26962026/10/28 14:31:58 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store26972026/10/28 14:31:58 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store26982026/10/28 14:31:58 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26992026/10/28 14:31:58 ERROR Accept failed error="too many open files"27002026/10/28 14:31:58 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27012026/10/28 14:31:58 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store27022026/10/28 14:31:58 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store27032026/10/28 14:31:58 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store27042026/10/28 14:31:58 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store27052026/10/28 14:31:58 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store27062026/10/28 14:31:58 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store27072026/10/28 14:31:58 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store27082026/10/28 14:31:58 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store27092026/10/28 14:31:58 ERROR Failed to decode request error="unexpected EOF"2710--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2711=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short27122026/10/28 14:31:58 ERROR Accept failed error="too many open files"27132026/10/28 14:31:58 ERROR Accept failed error="too many open files"27142026/10/28 14:31:58 INFO Uploading batch count=127152026/10/28 14:31:58 ERROR Upload failed error="upload failed" count=127162026/10/28 14:31:58 INFO Upload queue status pending=227172026/10/28 14:31:58 INFO Upload queue status pending=327182026/10/28 14:31:58 INFO Upload queue status pending=227192026/10/28 14:31:58 INFO Uploading batch count=127202026/10/28 14:31:58 ERROR Upload failed error="upload failed" count=127212026/10/28 14:31:58 INFO Uploading batch count=227222026/10/28 14:31:58 INFO Uploading batch count=227232026/10/28 14:31:58 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3487562503/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat3487562503/002/locked/aaa: permission denied"27242026/10/28 14:31:58 INFO Upload queue status pending=227252026/10/28 14:31:58 INFO Uploading batch count=427262026/10/28 14:31:58 ERROR Upload failed error="upload failed" count=427272026/10/28 14:31:58 INFO Upload queue status pending=227282026/10/28 14:31:58 INFO Uploading batch count=22729--- PASS: TestQueueFetchBatchLimit (0.07s)2730=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27312026/10/28 14:31:58 INFO Uploading batch count=127322026/10/28 14:31:58 INFO Uploading batch count=127332026/10/28 14:31:58 INFO Upload queue status pending=227342026/10/28 14:31:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2927612058/002/bbb27352026/10/28 14:31:58 INFO Uploading batch count=427362026/10/28 14:31:58 ERROR Upload failed error="upload failed" count=427372026/10/28 14:31:58 INFO Uploading batch count=427382026/10/28 14:31:58 ERROR Upload failed error="upload failed" count=427392026/10/28 14:31:58 INFO Uploading batch count=227402026/10/28 14:31:58 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3487562503/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat3487562503/002/locked/aaa: permission denied"27412026/10/28 14:31:58 INFO Uploading batch count=227422026/10/28 14:31:58 INFO Uploading batch count=227432026/10/28 14:31:58 ERROR Upload failed error="upload failed" count=227442026/10/28 14:31:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3993386638/002/a27452026/10/28 14:31:58 INFO Upload queue status pending=327462026/10/28 14:31:58 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2808007808/002/nonexistent2747--- PASS: TestQueueDeduplication (0.08s)2748=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch27492026/10/28 14:31:58 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3487562503/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat3487562503/002/locked/aaa: permission denied"27502026/10/28 14:31:58 ERROR Accept failed error="too many open files"27512026/10/28 14:31:58 INFO Uploading batch count=127522026/10/28 14:31:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3993386638/002/b2753--- PASS: TestQueueRetryMovesToBack (0.08s)2754=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths27552026/10/28 14:31:58 INFO Uploading batch count=22756--- PASS: TestQueueEnqueueAndFetch (0.08s)2757--- PASS: TestQueueRemove (0.08s)27582026/10/28 14:31:58 ERROR Drain finished with paths left in queue remaining=12759--- PASS: TestQueueFetchRemoveLifecycle (0.08s)27602026/10/28 14:31:58 INFO Uploading batch count=227612026/10/28 14:31:58 ERROR Upload failed error="upload failed" count=227622026/10/28 14:31:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3993386638/002/c27632026/10/28 14:31:58 INFO Uploading batch count=127642026/10/28 14:31:58 ERROR Upload failed error="upload failed" count=127652026/10/28 14:31:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3993386638/002/d27662026/10/28 14:31:58 INFO Uploading batch count=127672026/10/28 14:31:58 ERROR Upload failed error="upload failed" count=12768--- PASS: TestWorkerKeepsPathItCannotStat (0.09s)2769--- PASS: TestFailedPathPrunedByLaterClosure (0.09s)27702026/10/28 14:31:58 INFO Uploading batch count=227712026/10/28 14:31:58 ERROR Upload failed error="upload failed" count=227722026/10/28 14:31:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3993386638/002/e27732026/10/28 14:31:58 INFO Uploading batch count=127742026/10/28 14:31:58 ERROR Upload failed error="upload failed" count=12775--- PASS: TestWorkerUploadsAndRemoves (0.09s)27762026/10/28 14:31:58 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3993386638/002/f2777--- PASS: TestWorkerPrunesClosureDeps (0.10s)27782026/10/28 14:31:58 ERROR Drain finished with paths left in queue remaining=12779--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.10s)27802026/10/28 14:31:58 ERROR Drain finished with paths left in queue remaining=102781--- PASS: TestDrainIsolatesPoisonPath (0.10s)2782--- PASS: TestWorkerSkipsGCdPaths (0.10s)27832026/10/28 14:31:58 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path1083900160/001/nonexistent2784--- PASS: TestDrainGivesUpWhenServerDown (0.10s)27852026/10/28 14:31:58 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127862026/10/28 14:31:58 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path1083900160/001/nonexistent27872026/10/28 14:31:58 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127882026/10/28 14:31:58 INFO Uploading batch count=227892026/10/28 14:31:58 ERROR Upload failed error="upload failed" count=227902026/10/28 14:31:58 INFO Uploading batch count=227912026/10/28 14:31:58 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path1083900160/001/nonexistent27922026/10/28 14:31:58 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227932026/10/28 14:31:58 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127942026/10/28 14:31:58 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127952026/10/28 14:31:58 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127962026/10/28 14:31:58 ERROR Drain finished with paths left in queue remaining=127972026/10/28 14:31:58 INFO Uploading batch count=227982026/10/28 14:31:58 INFO Uploading batch count=227992026/10/28 14:31:58 ERROR Upload failed error="upload failed" count=228002026/10/28 14:31:58 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228012026/10/28 14:31:58 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128022026/10/28 14:31:58 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128032026/10/28 14:31:58 INFO Uploading batch count=228042026/10/28 14:31:58 INFO Uploading batch count=228052026/10/28 14:31:58 ERROR Upload failed error="upload failed" count=228062026/10/28 14:31:58 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228072026/10/28 14:31:58 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128082026/10/28 14:31:58 ERROR Drain finished with paths left in queue remaining=228092026/10/28 14:31:58 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128102026/10/28 14:31:58 ERROR Drain finished with paths left in queue remaining=22811--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2812 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.05s)2813 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.04s)2814 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.04s)28152026/10/28 14:31:58 ERROR Accept failed error="too many open files"28162026/10/28 14:31:58 ERROR Failed to decode request error="read unix /build/hook3009360584/test.sock->@: i/o timeout"28172026/10/28 14:31:58 ERROR Failed to write response error="write unix /build/hook3009360584/test.sock->@: i/o timeout"2818--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)28192026/10/28 14:31:58 ERROR Upload failed error="context canceled" count=228202026/10/28 14:31:58 ERROR Drain finished with paths left in queue remaining=428212026/10/28 14:31:58 ERROR Upload failed error="context canceled" count=228222026/10/28 14:31:58 ERROR Drain finished with paths left in queue remaining=228232026/10/28 14:31:58 ERROR Drain finished with paths left in queue remaining=42824--- PASS: TestDrainTimeout (0.27s)2825--- PASS: TestShutdownFinishesInFlightPush (0.00s)2826 --- PASS: TestShutdownFinishesInFlightPush/completes (0.17s)2827 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.27s)28282026/10/28 14:31:58 ERROR Accept failed error="too many open files"28292026/10/28 14:31:59 ERROR Drain finished with paths left in queue remaining=32830--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2831 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.26s)2832 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.38s)28332026/10/28 14:31:59 ERROR Accept failed error="too many open files"2834--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)2835--- PASS: TestQueueConcurrentWriters (0.69s)28362026/10/28 14:31:59 INFO Uploading batch count=128372026/10/28 14:31:59 INFO Uploading batch count=128382026/10/28 14:31:59 INFO Uploading batch count=128392026/10/28 14:31:59 ERROR Upload failed error="upload failed" count=128402026/10/28 14:31:59 INFO Uploading batch count=128412026/10/28 14:31:59 ERROR Upload failed error="upload failed" count=128422026/10/28 14:31:59 INFO Uploading batch count=128432026/10/28 14:31:59 ERROR Upload failed error="upload failed" count=128442026/10/28 14:31:59 INFO Uploading batch count=128452026/10/28 14:31:59 ERROR Upload failed error="upload failed" count=128462026/10/28 14:31:59 ERROR Drain finished with paths left in queue remaining=12847--- PASS: TestRunNotBlockedByPoisonHead (1.10s)2848--- PASS: TestQueueRemoveLargeClosure (1.56s)2849PASS2850Running signing tests...2851=== RUN TestExternalSigner2852=== PAUSE TestExternalSigner2853=== RUN TestExternalSignerWrongPublicKey2854=== PAUSE TestExternalSignerWrongPublicKey2855=== RUN TestExternalSignerErrors2856=== PAUSE TestExternalSignerErrors2857=== RUN TestExternalSignerRestartsAfterCrash2858=== PAUSE TestExternalSignerRestartsAfterCrash2859=== RUN TestExternalSignerProgramErrorKeepsProcess2860=== PAUSE TestExternalSignerProgramErrorKeepsProcess2861=== RUN TestExternalSignerClose2862=== PAUSE TestExternalSignerClose2863=== RUN TestExternalSignerRejectsInvalidPublicKey2864=== PAUSE TestExternalSignerRejectsInvalidPublicKey2865=== RUN TestExternalSignerCancellation2866=== PAUSE TestExternalSignerCancellation2867=== RUN TestGenerateFingerprint2868=== PAUSE TestGenerateFingerprint2869=== RUN TestParseSigningKey2870=== PAUSE TestParseSigningKey2871=== RUN TestSign2872=== PAUSE TestSign2873=== RUN TestSignBatch2874=== PAUSE TestSignBatch2875=== RUN TestNilKeyPublicKey2876=== PAUSE TestNilKeyPublicKey2877=== RUN TestSignErrors2878=== PAUSE TestSignErrors2879=== CONT TestExternalSigner2880=== CONT TestExternalSignerRestartsAfterCrash2881=== CONT TestExternalSignerCancellation2882=== CONT TestNilKeyPublicKey2883=== CONT TestGenerateFingerprint2884--- PASS: TestNilKeyPublicKey (0.00s)2885=== RUN TestGenerateFingerprint/basic_with_references2886=== PAUSE TestGenerateFingerprint/basic_with_references2887=== CONT TestParseSigningKey2888=== RUN TestParseSigningKey/valid_32-byte_key2889=== CONT TestSignErrors2890=== CONT TestSignBatch2891=== CONT TestExternalSignerClose2892=== CONT TestExternalSignerWrongPublicKey2893=== CONT TestSign2894=== CONT TestExternalSignerErrors2895=== CONT TestExternalSignerProgramErrorKeepsProcess2896=== CONT TestExternalSignerRejectsInvalidPublicKey2897=== RUN TestGenerateFingerprint/no_references2898=== PAUSE TestParseSigningKey/valid_32-byte_key2899=== PAUSE TestGenerateFingerprint/no_references2900=== RUN TestExternalSignerErrors/invalid_signature_base642901=== PAUSE TestExternalSignerErrors/invalid_signature_base642902=== RUN TestExternalSignerRejectsInvalidPublicKey/#002903=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2904=== RUN TestExternalSignerErrors/exit_at_startup2905=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002906=== PAUSE TestExternalSignerErrors/exit_at_startup2907=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2908=== RUN TestExternalSignerErrors/null2909=== RUN TestParseSigningKey/no_colon2910=== PAUSE TestParseSigningKey/no_colon2911=== RUN TestParseSigningKey/empty_name2912=== PAUSE TestParseSigningKey/empty_name2913=== RUN TestParseSigningKey/invalid_base642914=== PAUSE TestExternalSignerErrors/null2915=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2916=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2917=== RUN TestExternalSignerErrors/wrong_id2918=== RUN TestSignErrors/nil_key2919=== PAUSE TestParseSigningKey/invalid_base642920=== PAUSE TestExternalSignerErrors/wrong_id2921=== RUN TestParseSigningKey/wrong_length2922=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2923=== RUN TestExternalSignerErrors/null_signatures2924=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2925=== PAUSE TestExternalSignerErrors/null_signatures2926--- PASS: TestSign (0.00s)2927=== PAUSE TestParseSigningKey/wrong_length2928=== PAUSE TestSignErrors/nil_key2929=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2930=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2931=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2932=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2933=== RUN TestExternalSignerErrors/program_error2934=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2935--- PASS: TestExternalSignerClose (0.00s)2936=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2937=== CONT TestParseSigningKey/no_colon2938=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2939=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2940=== CONT TestParseSigningKey/invalid_base642941=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2942=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2943=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2944=== CONT TestParseSigningKey/wrong_length2945=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2946=== CONT TestExternalSignerRejectsInvalidPublicKey/#002947=== CONT TestParseSigningKey/valid_32-byte_key2948=== CONT TestParseSigningKey/empty_name2949=== RUN TestSignErrors/nil_narinfo2950=== RUN TestGenerateFingerprint/invalid_nar_hash_length2951=== PAUSE TestExternalSignerErrors/program_error2952=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2953=== RUN TestExternalSignerErrors/exit_on_request2954=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2955--- PASS: TestExternalSignerWrongPublicKey (0.00s)2956=== PAUSE TestSignErrors/nil_narinfo2957=== PAUSE TestExternalSignerErrors/exit_on_request2958=== RUN TestSignErrors/invalid_narinfo2959=== RUN TestExternalSignerErrors/wrong_shape2960=== PAUSE TestExternalSignerErrors/wrong_shape2961=== RUN TestGenerateFingerprint/invalid_store_path_prefix2962=== RUN TestExternalSignerErrors/wrong_signatures_shape2963=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2964=== PAUSE TestSignErrors/invalid_narinfo2965=== RUN TestGenerateFingerprint/invalid_reference_prefix2966=== RUN TestSignErrors/canceled2967--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2968 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2969 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2970 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2971 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2972 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2973=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2974=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2975=== PAUSE TestSignErrors/canceled2976=== CONT TestGenerateFingerprint/no_references2977=== CONT TestSignErrors/nil_narinfo2978=== CONT TestGenerateFingerprint/invalid_reference_prefix2979=== RUN TestExternalSignerErrors/unrequested_key2980=== CONT TestGenerateFingerprint/invalid_store_path_prefix2981=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2982=== CONT TestSignErrors/nil_key2983--- PASS: TestParseSigningKey (0.00s)2984 --- PASS: TestParseSigningKey/no_colon (0.00s)2985 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2986 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2987 --- PASS: TestParseSigningKey/wrong_length (0.00s)2988 --- PASS: TestParseSigningKey/empty_name (0.00s)2989 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2990--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2991=== CONT TestGenerateFingerprint/invalid_nar_hash_length2992=== CONT TestSignErrors/canceled2993=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2994=== CONT TestGenerateFingerprint/basic_with_references2995=== CONT TestSignErrors/invalid_narinfo2996=== PAUSE TestExternalSignerErrors/unrequested_key2997--- PASS: TestSignBatch (0.01s)2998=== RUN TestExternalSignerErrors/missing_signature_name2999=== PAUSE TestExternalSignerErrors/missing_signature_name3000=== RUN TestExternalSignerErrors/wrong_signature_length3001=== PAUSE TestExternalSignerErrors/wrong_signature_length3002=== RUN TestExternalSignerErrors/invalid_JSON3003=== PAUSE TestExternalSignerErrors/invalid_JSON3004=== RUN TestExternalSignerErrors/missing_signatures3005--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)3006--- PASS: TestSignErrors (0.01s)3007 --- PASS: TestSignErrors/nil_narinfo (0.00s)3008 --- PASS: TestSignErrors/nil_key (0.00s)3009 --- PASS: TestSignErrors/canceled (0.00s)3010 --- PASS: TestSignErrors/invalid_narinfo (0.00s)3011=== PAUSE TestExternalSignerErrors/missing_signatures3012--- PASS: TestGenerateFingerprint (0.01s)3013 --- PASS: TestGenerateFingerprint/no_references (0.00s)3014 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)3015 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)3016 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)3017 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)3018 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)3019 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)3020=== RUN TestExternalSignerErrors/too_few_signatures3021=== PAUSE TestExternalSignerErrors/too_few_signatures3022--- PASS: TestExternalSigner (0.01s)3023=== RUN TestExternalSignerErrors/wrong_signature_name3024=== PAUSE TestExternalSignerErrors/wrong_signature_name3025=== CONT TestExternalSignerErrors/exit_at_startup3026=== CONT TestExternalSignerErrors/missing_signature_name3027=== CONT TestExternalSignerErrors/wrong_id3028=== CONT TestExternalSignerErrors/wrong_signature_length3029=== CONT TestExternalSignerErrors/wrong_signatures_shape3030=== CONT TestExternalSignerErrors/wrong_signature_name3031=== CONT TestExternalSignerErrors/too_few_signatures3032=== CONT TestExternalSignerErrors/unrequested_key3033=== CONT TestExternalSignerErrors/invalid_JSON3034=== CONT TestExternalSignerErrors/wrong_shape3035=== CONT TestExternalSignerErrors/program_error3036=== CONT TestExternalSignerErrors/exit_on_request3037=== CONT TestExternalSignerErrors/null_signatures3038=== CONT TestExternalSignerErrors/null3039=== CONT TestExternalSignerErrors/invalid_signature_base643040=== CONT TestExternalSignerErrors/missing_signatures3041--- PASS: TestExternalSignerErrors (0.01s)3042 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)3043 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)3044 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)3045 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)3046 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)3047 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)3048 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)3049 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)3050 --- PASS: TestExternalSignerErrors/null (0.01s)3051 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)3052 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)3053 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)3054 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)3055 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)3056 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)3057 --- PASS: TestExternalSignerErrors/program_error (0.01s)3058--- PASS: TestExternalSignerCancellation (0.02s)3059PASS3060Running OpenBao signer tests...3061=== RUN TestSign3062=== PAUSE TestSign3063=== RUN TestSignErrors3064=== PAUSE TestSignErrors3065=== RUN TestServe3066=== PAUSE TestServe3067=== RUN TestServeRejectsGarbage3068=== PAUSE TestServeRejectsGarbage3069=== CONT TestSignErrors3070=== CONT TestServe3071=== RUN TestSignErrors/invalid_base643072=== CONT TestServeRejectsGarbage3073=== PAUSE TestSignErrors/invalid_base643074=== CONT TestSign3075=== RUN TestSignErrors/http_error3076=== PAUSE TestSignErrors/http_error3077=== RUN TestSignErrors/invalid_json3078--- PASS: TestServeRejectsGarbage (0.00s)3079=== PAUSE TestSignErrors/invalid_json3080=== RUN TestSignErrors/no_prefix3081=== PAUSE TestSignErrors/no_prefix3082=== CONT TestSignErrors/no_prefix3083=== CONT TestSignErrors/http_error3084--- PASS: TestServe (0.00s)3085=== CONT TestSignErrors/invalid_json3086=== CONT TestSignErrors/invalid_base643087--- PASS: TestSign (0.01s)3088--- PASS: TestSignErrors (0.00s)3089 --- PASS: TestSignErrors/invalid_json (0.01s)3090 --- PASS: TestSignErrors/http_error (0.01s)3091 --- PASS: TestSignErrors/no_prefix (0.01s)3092 --- PASS: TestSignErrors/invalid_base64 (0.01s)3093PASS3094Running niks3-hook command tests...3095=== RUN TestServeSecondSignalEndsDrain3096=== PAUSE TestServeSecondSignalEndsDrain3097=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown3098=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown3099=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown3100=== CONT TestServeSecondSignalEndsDrain3101--- PASS: TestServeSecondSignalEndsDrain (0.08s)31022026/10/28 14:32:03 INFO Upload queue status pending=131032026/10/28 14:32:03 INFO Uploading batch count=13104--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.13s)3105PASS3106Running rate limiter tests...3107=== RUN TestAdaptiveRateLimiter_ThreadSafety3108=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3109=== CONT TestAdaptiveRateLimiter_ThreadSafety31102026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=112.7357000000000731112026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=78.9149900000000531122026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=55.2404930000000331132026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=38.6683451000000231142026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=27.0678415700000131152026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=18.94748909900000631162026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=13.26324236930000431172026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=9.28426965851000231182026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=6.49898876095700131192026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531202026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=5.63678500000000131212026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531222026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531232026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531242026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531252026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531262026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531272026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531282026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531292026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531302026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531312026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531322026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531332026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531342026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531352026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531362026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531372026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531382026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=5.12435000000000131392026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531402026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531412026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531422026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531432026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531442026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531452026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531462026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531472026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=5.12435000000000131482026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531492026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531502026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531512026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531522026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531532026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531542026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531552026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531562026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=6.200463500000001531572026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531582026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531592026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531602026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531612026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531622026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531632026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=5.12435000000000131642026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531652026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531662026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531672026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531682026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531692026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531702026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531712026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531722026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531732026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531742026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531752026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531762026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531772026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531782026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531792026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531802026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531812026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531822026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531832026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531842026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531852026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531862026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531872026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531882026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531892026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531902026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531912026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531922026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531932026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531942026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531952026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531962026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531972026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=531982026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=5.12435000000000131992026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=532002026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=532012026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=532022026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=532032026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=532042026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=532052026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=532062026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=532072026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=532082026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=532092026/10/28 14:32:04 WARN Rate limiter backed off name=test rate=53210--- PASS: TestAdaptiveRateLimiter_ThreadSafety (0.01s)3211PASS