niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #401
· 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_ProducerErrorIsNotEOF22=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF23=== RUN TestUploadMultipart_FailedPartBufferNotReused24=== PAUSE TestUploadMultipart_FailedPartBufferNotReused25=== 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 114 of 32768000 bytes45--- PASS: TestDumpPathWriterErrorStopsReading (0.68s)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 TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade79=== PAUSE TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade80=== RUN TestRetryTimeoutOutlastsMaxRetries81=== PAUSE TestRetryTimeoutOutlastsMaxRetries82=== RUN TestDoWithRetry_FinalResponseBodyReadable83=== PAUSE TestDoWithRetry_FinalResponseBodyReadable84=== RUN TestShellSplit85=== PAUSE TestShellSplit86=== RUN TestShellSplitErrors87=== PAUSE TestShellSplitErrors88=== RUN TestStreamPushReportsEveryPath89=== PAUSE TestStreamPushReportsEveryPath90=== RUN TestStreamPushBatchesUnderLoad91=== PAUSE TestStreamPushBatchesUnderLoad92=== RUN TestStreamPushIsolatesFailures93=== PAUSE TestStreamPushIsolatesFailures94=== RUN TestStreamPushGivesUpOnDeadServer95=== PAUSE TestStreamPushGivesUpOnDeadServer96=== RUN TestStreamPushRequestLine97=== PAUSE TestStreamPushRequestLine98=== RUN TestStreamPushReportsSignatures99=== PAUSE TestStreamPushReportsSignatures100=== RUN TestStreamPushReportsSkippedPaths101=== PAUSE TestStreamPushReportsSkippedPaths102=== RUN TestClientSignaturesByStorePath103=== PAUSE TestClientSignaturesByStorePath104=== RUN TestStreamPushStopsWhenCanceled105=== PAUSE TestStreamPushStopsWhenCanceled106=== RUN TestStreamPushStopsOnCancel107=== PAUSE TestStreamPushStopsOnCancel108=== 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 TestRunGarbageCollection_FinishedOnAnotherReplica137=== CONT TestClientSignaturesByStorePath138=== CONT TestStaticToken139=== CONT TestStreamPushStopsWhenCanceled140=== CONT TestStreamPushReportsEveryPath141=== CONT TestScriptTokenDoesNotWaitForItsChildren142=== CONT TestSetClientTLSDoesNotMutateDefaultTransport143=== CONT TestScriptTokenEmptyCommand144=== CONT TestStreamPushReportsSignatures145=== CONT TestScriptTokenScriptFails146=== CONT TestTruncatedNARDumpIsNotCompleted147=== CONT TestStreamPushReportsSkippedPaths148=== CONT TestScriptTokenCachesUntilRefresh149=== CONT TestStreamPushIsolatesFailures150=== CONT TestScriptTokenNoExpiryRerunsEveryCall151=== CONT TestScriptTokenBadJSON152=== CONT TestFileTokenMissing153=== CONT TestFileTokenEmpty154=== CONT TestScriptTokenEmptyToken155=== CONT TestSetClientTLS156=== CONT TestStreamPushRequestLine157=== CONT TestCompletePendingClosure_NotFoundWithoutKey158=== CONT TestStreamPushGivesUpOnDeadServer159=== CONT TestStreamPushStopsOnCancel160=== CONT TestRetryTimeoutOutlastsMaxRetries161=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer162=== CONT TestFileTokenReadsAndCaches163--- PASS: TestClientSignaturesByStorePath (0.00s)164=== CONT TestDoWithRetry_FinalResponseBodyReadable165=== CONT TestDumpPathSingleFile166=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs167=== CONT TestUploadMultipart_FailedPartBufferNotReused168=== CONT TestUploadMultipart_SupersededByPeer169=== CONT TestSetClientTLSErrors170=== CONT TestParsePathInfoJSONMultiplePaths171=== RUN TestStreamPushStopsOnCancel/waiting_for_input172--- PASS: TestStaticToken (0.00s)173=== CONT TestParsePathInfoJSON174=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs175=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent176=== CONT TestUploadMultipart_PartsInParallel177=== CONT TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade178=== RUN TestUploadMultipart_SupersededByPeer/exists179--- PASS: TestFileTokenReadsAndCaches (0.00s)180=== CONT TestPartSizeForNAR181=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input182=== RUN TestParsePathInfoJSON/Nix_format183=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths184=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout185=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier186=== RUN TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0187=== PAUSE TestUploadMultipart_SupersededByPeer/exists188--- PASS: TestStreamPushStopsWhenCanceled (0.00s)189=== CONT TestStreamPushBatchesUnderLoad190=== CONT TestShellSplit191=== RUN TestPartSizeForNAR/zero_stays_at_minimum192=== PAUSE TestParsePathInfoJSON/Nix_format193=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths194=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout195=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot196=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier197=== PAUSE TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0198--- PASS: TestScriptTokenEmptyCommand (0.00s)199=== RUN TestStreamPushBatchesUnderLoad/together200=== RUN TestUploadMultipart_SupersededByPeer/missing201=== RUN TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=5202=== PAUSE TestStreamPushBatchesUnderLoad/together203=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum204=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time205=== RUN TestPartSizeForNAR/small_stays_at_minimum206=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time207=== CONT TestSupersededNARStillUploadsListing208=== RUN TestSetClientTLSErrors/missing_cert_file209=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess210=== RUN TestSupersededNARStillUploadsListing/small_NAR211=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths212=== PAUSE TestSupersededNARStillUploadsListing/small_NAR213=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths214=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot215=== CONT TestRateLimiterFeedback216=== RUN TestSupersededNARStillUploadsListing/dump_cut_short217--- PASS: TestStreamPushReportsSkippedPaths (0.00s)218=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up219=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up220=== PAUSE TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=5221=== PAUSE TestUploadMultipart_SupersededByPeer/missing222=== RUN TestParsePathInfoJSON/Lix_format223=== PAUSE TestPartSizeForNAR/small_stays_at_minimum224=== CONT TestUploadMultipart_ProducerErrorIsNotEOF225=== CONT TestDumpPathMatchesNix226=== PAUSE TestSetClientTLSErrors/missing_cert_file227=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum228=== CONT TestGetStorePathHash229=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part230=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum231=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot232=== RUN TestRateLimiterFeedback/429_enables_limiter233=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short234=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part235--- PASS: TestScriptTokenScriptFails (0.00s)236=== CONT TestPathInfoCACompatibility237--- PASS: TestStreamPushReportsEveryPath (0.00s)238=== CONT TestEncodeNixBase32239=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier240=== CONT TestDoWithRetry_BodyReplayedViaGetBody241=== CONT TestResolveStorePath242=== RUN TestSetClientTLSErrors/missing_key_file243=== PAUSE TestParsePathInfoJSON/Lix_format244=== RUN TestGetStorePathHash/valid_store_path245=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts246=== RUN TestParsePathInfoJSON/empty_input247=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts248=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot249=== PAUSE TestRateLimiterFeedback/429_enables_limiter250=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot251=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails252=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary253=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails254=== RUN TestPathInfoCACompatibility/null_ca_field255--- PASS: TestStreamPushReportsSignatures (0.14s)256=== RUN TestEncodeNixBase32/test_string_hash257=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier258=== PAUSE TestSetClientTLSErrors/missing_key_file259=== PAUSE TestGetStorePathHash/valid_store_path260=== PAUSE TestParsePathInfoJSON/empty_input261=== CONT TestEncodeNixBase32WithRealHash262=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot263=== RUN TestRateLimiterFeedback/503_enables_limiter264=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot265=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary266=== CONT TestPathInfoHashCompatibility267--- PASS: TestStreamPushIsolatesFailures (0.14s)268=== PAUSE TestPathInfoCACompatibility/null_ca_field269=== PAUSE TestEncodeNixBase32/test_string_hash270=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client271=== RUN TestSetClientTLSErrors/missing_ca_file272=== RUN TestPartSizeForNAR/1_TiB273=== PAUSE TestSetClientTLSErrors/missing_ca_file274=== PAUSE TestPartSizeForNAR/1_TiB275=== RUN TestGetStorePathHash/basename_without_hyphen_should_error276=== RUN TestParsePathInfoJSON/whitespace_only277=== CONT TestConvertHashToNix32278=== PAUSE TestRateLimiterFeedback/503_enables_limiter279=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot280=== CONT TestShellSplitErrors281=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken282=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken283=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)284--- PASS: TestFileTokenMissing (0.00s)285=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)286=== RUN TestPathInfoCACompatibility/old_string_format_-_text287=== RUN TestEncodeNixBase32/empty_input288=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client289=== RUN TestSetClientTLSErrors/invalid_ca_file290=== RUN TestPartSizeForNAR/5_TiB_S3_max_object291=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error292=== PAUSE TestParsePathInfoJSON/whitespace_only293=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object294=== RUN TestParsePathInfoJSON/invalid_JSON295=== RUN TestPartSizeForNAR/capped_at_5_GiB296=== RUN TestConvertHashToNix32/SRI_format_to_Nix32297=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter298=== CONT TestCaseHackSuffix299=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun300--- PASS: TestScriptTokenBadJSON (0.14s)301=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure302=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon303=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text304=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon305=== PAUSE TestEncodeNixBase32/empty_input306=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client307=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry308=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI309=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client310=== PAUSE TestSetClientTLSErrors/invalid_ca_file311=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error312=== PAUSE TestParsePathInfoJSON/invalid_JSON313=== PAUSE TestPartSizeForNAR/capped_at_5_GiB314=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32315=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter316--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)317=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive318=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter319--- PASS: TestFileTokenEmpty (0.00s)320=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI321=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512322=== CONT TestDoServerRequestAttachesToken323=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512324=== CONT TestFilterOversizedClosures325=== CONT TestRegisterUploadedObjectReusesConnections326=== RUN TestFilterOversizedClosures/no_limit_keeps_everything327=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything328=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs329=== CONT TestDumpPathWriterError330=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error331--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.00s)332=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive333=== RUN TestConvertHashToNix32/already_Nix32_format334=== RUN TestPathInfoCACompatibility/new_structured_format_-_text335=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter336=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout337=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped338--- PASS: TestScriptTokenEmptyToken (0.01s)339--- PASS: TestShellSplit (0.00s)340=== RUN TestSetClientTLS/rejects_connection_without_client_cert341=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped342=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error343=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert344=== PAUSE TestConvertHashToNix32/already_Nix32_format345=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths346=== RUN TestConvertHashToNix32/invalid_format347=== PAUSE TestConvertHashToNix32/invalid_format348=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths349=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error350=== CONT TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=5351=== CONT TestUploadMultipart_SupersededByPeer/missing352=== CONT TestStreamPushBatchesUnderLoad/together353=== RUN TestFilterOversizedClosures/all_closures_skipped354=== CONT TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0355=== CONT TestUploadMultipart_SupersededByPeer/exists356=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time357=== PAUSE TestFilterOversizedClosures/all_closures_skipped358=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails359=== CONT TestSupersededNARStillUploadsListing/dump_cut_short360--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)361=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA362=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA363=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text364--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.15s)365=== RUN TestSetClientTLS/preserves_debug_logging_transport366=== CONT TestSupersededNARStillUploadsListing/small_NAR367--- PASS: TestScriptTokenCachesUntilRefresh (0.15s)368=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part369=== PAUSE TestSetClientTLS/preserves_debug_logging_transport370=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method371=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method372=== CONT TestStreamPushStopsOnCancel/waiting_for_input373=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary374=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken375--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.15s)376--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.15s)377--- PASS: TestEncodeNixBase32WithRealHash (0.00s)378--- PASS: TestShellSplitErrors (0.00s)379--- PASS: TestResolveStorePath (0.00s)380=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot381--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)382--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)383--- PASS: TestDoServerRequestAttachesToken (0.01s)384=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot385--- PASS: TestDumpPathSingleFile (0.19s)386--- PASS: TestCaseHackSuffix (0.18s)387--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)388 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)389 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)390--- PASS: TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade (0.01s)391 --- PASS: TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0 (0.00s)392 --- PASS: TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=5 (0.01s)393--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)394 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)395 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)396--- PASS: TestStreamPushBatchesUnderLoad (0.00s)397 --- PASS: TestStreamPushBatchesUnderLoad/together (0.01s)398 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)399=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot400--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.19s)401=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot402=== CONT TestEncodeNixBase32/test_string_hash403=== CONT TestEncodeNixBase32/empty_input404=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier405--- PASS: TestEncodeNixBase32 (0.01s)406 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)407 --- PASS: TestEncodeNixBase32/empty_input (0.00s)408--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.23s)409=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client410=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client411=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up412=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier413=== CONT TestSetClientTLSErrors/missing_ca_file414=== CONT TestSetClientTLSErrors/invalid_ca_file415=== CONT TestSetClientTLSErrors/missing_cert_file416=== CONT TestParsePathInfoJSON/invalid_JSON417--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.01s)418 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.01s)419 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.01s)420 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.00s)421 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.01s)422 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.01s)423=== CONT TestParsePathInfoJSON/Lix_format424=== CONT TestParsePathInfoJSON/whitespace_only425=== CONT TestPartSizeForNAR/zero_stays_at_minimum426=== CONT TestParsePathInfoJSON/Nix_format427=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum428=== CONT TestParsePathInfoJSON/empty_input429=== CONT TestPartSizeForNAR/1_TiB430=== CONT TestPartSizeForNAR/5_TiB_S3_max_object431=== CONT TestSetClientTLSErrors/missing_key_file432=== CONT TestPartSizeForNAR/capped_at_5_GiB433=== CONT TestPartSizeForNAR/small_stays_at_minimum434--- PASS: TestParsePathInfoJSON (0.01s)435 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)436 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)437 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)438 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)439 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)440=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon441=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts442=== CONT TestRateLimiterFeedback/429_enables_limiter443--- PASS: TestSetClientTLSErrors (0.01s)444 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)445 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)446 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)447 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)448=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI449=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512450=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter451=== CONT TestRateLimiterFeedback/503_enables_limiter452=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)453=== CONT TestConvertHashToNix32/invalid_format454=== CONT TestConvertHashToNix32/already_Nix32_format455=== CONT TestConvertHashToNix32/SRI_format_to_Nix32456=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error457--- PASS: TestPartSizeForNAR (0.01s)458 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)459 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)460 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)461 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)462 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)463 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)464 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)465=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error466=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter467=== CONT TestFilterOversizedClosures/all_closures_skipped468=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped469=== CONT TestGetStorePathHash/valid_store_path470=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA471=== CONT TestFilterOversizedClosures/no_limit_keeps_everything472=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive473=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method474--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.24s)475=== CONT TestSetClientTLS/rejects_connection_without_client_cert476=== CONT TestSetClientTLS/preserves_debug_logging_transport477--- PASS: TestPathInfoHashCompatibility (0.00s)478 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)479 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)480 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)481 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)482=== CONT TestPathInfoCACompatibility/null_ca_field483=== CONT TestPathInfoCACompatibility/new_structured_format_-_text484=== CONT TestGetStorePathHash/basename_without_hyphen_should_error485=== CONT TestPathInfoCACompatibility/old_string_format_-_text486--- PASS: TestStreamPushStopsOnCancel (0.01s)487 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.21s)488 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.21s)489 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.05s)490 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.06s)491 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.05s)492 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)493--- PASS: TestConvertHashToNix32 (0.01s)494 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)495 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)496 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)497--- PASS: TestFilterOversizedClosures (0.01s)498 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)499 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)500 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)501--- PASS: TestRateLimiterFeedback (0.01s)502 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)503 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)504 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)505 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)506--- PASS: TestGetStorePathHash (0.01s)507 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)508 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)509 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)510 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)511--- PASS: TestPathInfoCACompatibility (0.03s)512 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)513 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.01s)514 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)515 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)516 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)517--- PASS: TestDumpPathWriterError (0.26s)518--- PASS: TestSetClientTLS (0.03s)519 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)520 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)521 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.08s)522--- PASS: TestStreamPushRequestLine (0.38s)523--- PASS: TestRegisterUploadedObjectReusesConnections (0.38s)524--- PASS: TestDumpPathMatchesNix (0.46s)525--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.00s)526 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.40s)527 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.45s)528--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)529--- PASS: TestTruncatedNARDumpIsNotCompleted (1.38s)530--- PASS: TestSupersededNARStillUploadsListing (0.00s)531 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.20s)532 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.21s)533 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.35s)534--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.39s)535--- PASS: TestUploadMultipart_PartsInParallel (1.41s)536--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (2.00s)537--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.15s)538 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.01s)539 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.20s)540PASS541Running server tests...542The files belonging to this database system will be owned by user "nixbld".543This user must also own the server process.544545The database cluster will be initialized with locale "C".546The default database encoding has accordingly been set to "SQL_ASCII".547The default text search configuration will be set to "english".548549Data page checksums are enabled.550551creating directory /build/postgres2827063538/data ... ok552creating subdirectories ... ok553selecting dynamic shared memory implementation ... posix554selecting default "max_connections" ... 100555selecting default "shared_buffers" ... 128MB556selecting default time zone ... UTC557creating configuration files ... ok558running bootstrap script ... ok559performing post-bootstrap initialization ... ok560syncing data to disk ... ok561562initdb: warning: enabling "trust" authentication for local connections563initdb: 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.564565Success. You can now start the database server using:566567 pg_ctl -D /build/postgres2827063538/data -l logfile start568569/build/postgres2827063538:5432 - no response5702026-10-08 21:39:53.733 UTC [171] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit5712026-10-08 21:39:53.733 UTC [171] LOG: listening on Unix socket "/build/postgres2827063538/.s.PGSQL.5432"5722026-10-08 21:39:53.739 UTC [178] LOG: database system was shut down at 2026-10-08 21:39:53 UTC5732026-10-08 21:39:53.743 UTC [171] LOG: database system is ready to accept connections574/build/postgres2827063538:5432 - accepting connections575{"timestamp":"2026-10-08T21:39:54.042845355Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"b5233933-fb06-41a0-8248-32d320a748c6","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(391)"}576=== RUN TestService_AuthMiddleware577=== PAUSE TestService_AuthMiddleware578=== RUN TestService_AuthMiddleware_MTLSProxyHeader579=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader580=== RUN TestService_AuthMiddleware_MTLSBoundSubjects581=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects582=== RUN TestService_ReadAuthMiddleware583=== PAUSE TestService_ReadAuthMiddleware584=== RUN TestService_AuthMiddleware_OIDC585=== PAUSE TestService_AuthMiddleware_OIDC586=== RUN TestService_RequireScope_OIDC587=== PAUSE TestService_RequireScope_OIDC588=== RUN TestService_ReadScope_PublicByDefault589=== PAUSE TestService_ReadScope_PublicByDefault590=== RUN TestCacheConfigHandler591=== PAUSE TestCacheConfigHandler592=== RUN TestCacheStatsHandler593=== PAUSE TestCacheStatsHandler594=== RUN TestClientCADerivations595=== PAUSE TestClientCADerivations596=== RUN TestClientErrorHandling597=== PAUSE TestClientErrorHandling598=== RUN TestClientIntegration599=== PAUSE TestClientIntegration600=== RUN TestClientMultipleUploads601=== PAUSE TestClientMultipleUploads602=== RUN TestClientWithDependencies603=== PAUSE TestClientWithDependencies604=== RUN TestClientSharedPathCommittedMidPush605=== PAUSE TestClientSharedPathCommittedMidPush606=== RUN TestPinProtectsFromGC607=== PAUSE TestPinProtectsFromGC608=== RUN TestClientPushesUseOnePush609=== PAUSE TestClientPushesUseOnePush610=== RUN TestClientFallsBackToClosures611=== PAUSE TestClientFallsBackToClosures612=== RUN TestDeleteClosuresRacingPins613=== PAUSE TestDeleteClosuresRacingPins614=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock615=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock616=== RUN TestResolveDBConnectionString617=== PAUSE TestResolveDBConnectionString618=== RUN TestConnectWaitsForAPeerMigration619=== PAUSE TestConnectWaitsForAPeerMigration620=== RUN TestConnectSerialisesConcurrentMigrations621=== PAUSE TestConnectSerialisesConcurrentMigrations622=== RUN TestLeadElectsOneAndHandsOver623=== PAUSE TestLeadElectsOneAndHandsOver624=== RUN TestLeadIncumbentWinsAfterRestart6252026/10/08 21:39:54 INFO lead: acquired remote=192.0.2.1:12346262026/10/08 21:39:54 INFO lead: released remote=192.0.2.1:12346272026/10/08 21:39:55 INFO lead: acquired remote=192.0.2.1:12346282026/10/08 21:39:56 INFO lead: released remote=192.0.2.1:1234629--- PASS: TestLeadIncumbentWinsAfterRestart (1.92s)630=== RUN TestLeadIncumbentAnnouncesAtOnce631=== PAUSE TestLeadIncumbentAnnouncesAtOnce632=== RUN TestLeadEndsOnShutdown633=== PAUSE TestLeadEndsOnShutdown634=== RUN TestLeadEndsWhenItsConnectionHangs6352026/10/08 21:39:56 INFO lead: acquired remote=192.0.2.1:12346362026-10-08 21:39:57.608 UTC [619] FATAL: terminating connection due to administrator command6372026/10/08 21:39:57 INFO lead: acquired remote=192.0.2.1:12346382026/10/08 21:39:58 WARN lead: lock connection lost error="timeout: context deadline exceeded"6392026/10/08 21:39:58 INFO lead: released remote=192.0.2.1:12346402026/10/08 21:39:59 INFO lead: released remote=192.0.2.1:1234641--- PASS: TestLeadEndsWhenItsConnectionHangs (2.96s)642=== RUN TestGCAdvisoryLockBlocksConcurrentRun643=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun644=== RUN TestGCBugBareHashReferences645=== PAUSE TestGCBugBareHashReferences646=== RUN TestGCMetrics647=== PAUSE TestGCMetrics648=== RUN TestPushDedupSurvivesConcurrentGC649=== PAUSE TestPushDedupSurvivesConcurrentGC650=== RUN TestDeduplicatedObjectsRecordedAsPending651=== PAUSE TestDeduplicatedObjectsRecordedAsPending652=== RUN TestGCSweepSkipsPendingObjects653=== PAUSE TestGCSweepSkipsPendingObjects654=== RUN TestTombstonedObjectOfferedWithoutWaiting655=== PAUSE TestTombstonedObjectOfferedWithoutWaiting656=== RUN TestGCSweepDeliversEachKeyOnce657=== PAUSE TestGCSweepDeliversEachKeyOnce658=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection659=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection660=== RUN TestForceGCDuringPushOffersSweptObject661=== PAUSE TestForceGCDuringPushOffersSweptObject662=== RUN TestFailedS3DeleteKeepsTombstone663=== PAUSE TestFailedS3DeleteKeepsTombstone664=== RUN TestSweepSkipsRowsLockedByPush665=== PAUSE TestSweepSkipsRowsLockedByPush666=== RUN TestRegisterCompletedObjectNeedsPendingRow667=== PAUSE TestRegisterCompletedObjectNeedsPendingRow668=== RUN TestGetExistingObjectsLocksRows669=== PAUSE TestGetExistingObjectsLocksRows670=== RUN TestSweepRechecksPendingAfterLocking671=== PAUSE TestSweepRechecksPendingAfterLocking672=== RUN TestPushWaitsForSweepHoldingRow673=== PAUSE TestPushWaitsForSweepHoldingRow674=== RUN TestCommitRacingPendingCleanupKeepsObjects675=== PAUSE TestCommitRacingPendingCleanupKeepsObjects676=== RUN TestGCEndsOnShutdown677=== PAUSE TestGCEndsOnShutdown678=== RUN TestGCTaskStore_StartNew679=== PAUSE TestGCTaskStore_StartNew680=== RUN TestGCTaskStore_DeduplicateSameParams681=== PAUSE TestGCTaskStore_DeduplicateSameParams682=== RUN TestGCTaskStore_ConflictDifferentParams683=== PAUSE TestGCTaskStore_ConflictDifferentParams684=== RUN TestGCTaskStore_GetEmpty685=== PAUSE TestGCTaskStore_GetEmpty686=== RUN TestGCTaskStore_GetReturnsLatest687=== PAUSE TestGCTaskStore_GetReturnsLatest688=== RUN TestGCTaskStore_CompletedAllowsNewTask689=== PAUSE TestGCTaskStore_CompletedAllowsNewTask690=== RUN TestGCTaskStore_PhaseUpdates691=== PAUSE TestGCTaskStore_PhaseUpdates692=== RUN TestGCTaskStore_Fail693=== PAUSE TestGCTaskStore_Fail694=== RUN TestGracefulShutdownDrainsInflight695=== PAUSE TestGracefulShutdownDrainsInflight696=== RUN TestService_healthCheckHandler697=== PAUSE TestService_healthCheckHandler698=== RUN TestService_readinessHandler699=== PAUSE TestService_readinessHandler700=== RUN TestGenerateLandingPage701=== PAUSE TestGenerateLandingPage702=== RUN TestCacheConfigHandlerMaxNarSize703=== PAUSE TestCacheConfigHandlerMaxNarSize704=== RUN TestCreatePendingClosureRejectsOversizedNAR705=== PAUSE TestCreatePendingClosureRejectsOversizedNAR706=== RUN TestNARDeduplicationMetadataUploadBug707=== PAUSE TestNARDeduplicationMetadataUploadBug708=== RUN TestMetricsInventory709=== PAUSE TestMetricsInventory710=== RUN TestMetricsCommit711=== PAUSE TestMetricsCommit712=== RUN TestService_NativeMTLS713=== PAUSE TestService_NativeMTLS714=== RUN TestServerTLSConfig715=== PAUSE TestServerTLSConfig716=== RUN TestMultipartCleanup717=== PAUSE TestMultipartCleanup718=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded719=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded720=== RUN TestPendingCleanupUsesOneCutoff721=== PAUSE TestPendingCleanupUsesOneCutoff722=== RUN TestPendingClosureFailureTracksEveryUpload723=== PAUSE TestPendingClosureFailureTracksEveryUpload724=== RUN TestPendingClosureFailureAbortsItsUploads725=== PAUSE TestPendingClosureFailureAbortsItsUploads726=== RUN TestObjectStatsTrigger727=== PAUSE TestObjectStatsTrigger728=== RUN TestObjectStatsLargeCommit729=== PAUSE TestObjectStatsLargeCommit730=== RUN TestReconnectLeavesObjectsUnlocked731=== PAUSE TestReconnectLeavesObjectsUnlocked732=== RUN TestOrphanedObjectsGC733=== PAUSE TestOrphanedObjectsGC734=== RUN TestOrphanedObjectsGCStressTest735=== PAUSE TestOrphanedObjectsGCStressTest736=== RUN TestCreatePin_ReservedPins737=== PAUSE TestCreatePin_ReservedPins738=== RUN TestConcurrentPinUpdatesAgree739=== PAUSE TestConcurrentPinUpdatesAgree740=== RUN TestCreatePinRejectsBadInput741=== PAUSE TestCreatePinRejectsBadInput742=== RUN TestDeletePinKeepsRowWhenS3Fails743=== PAUSE TestDeletePinKeepsRowWhenS3Fails744=== RUN TestPresentReportsOnlyClosureRoots745=== PAUSE TestPresentReportsOnlyClosureRoots746=== RUN TestPresentRefreshesOnlyStaleClosures747=== PAUSE TestPresentRefreshesOnlyStaleClosures748=== RUN TestPresentNotReportedWhileGCDeletesClosure749=== PAUSE TestPresentNotReportedWhileGCDeletesClosure750=== RUN TestParseSingleRange751=== PAUSE TestParseSingleRange752=== RUN TestProxyHeadersOnlyTrustedOnSocket7532026/10/08 21:39:59 INFO Starting HTTP server address=127.0.0.1:428517542026/10/08 21:39:59 INFO Starting HTTP server address=proxy.sock7552026/10/08 21:39:59 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7562026/10/08 21:39:59 INFO Shutdown signal received, draining in-flight requests timeout=10s757--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.14s)758=== RUN TestIsValidCachePath759=== PAUSE TestIsValidCachePath760=== RUN TestReadProxyNarinfo761=== PAUSE TestReadProxyNarinfo762=== RUN TestReadProxyNarinfoAlreadyDecompressed763=== PAUSE TestReadProxyNarinfoAlreadyDecompressed764=== RUN TestReadProxyContentNegotiation765=== PAUSE TestReadProxyContentNegotiation766=== RUN TestReadProxyNarStreaming767=== PAUSE TestReadProxyNarStreaming768=== RUN TestReadProxy404769=== PAUSE TestReadProxy404770=== RUN TestReadProxyInvalidPath771=== PAUSE TestReadProxyInvalidPath772=== RUN TestReadProxyHead773=== PAUSE TestReadProxyHead774=== RUN TestReadProxyOutlastsServerWriteTimeout775=== PAUSE TestReadProxyOutlastsServerWriteTimeout776=== RUN TestReadProxyConditionalGet777=== PAUSE TestReadProxyConditionalGet778=== RUN TestReadProxyRootRedirectsToIndexHTML779=== PAUSE TestReadProxyRootRedirectsToIndexHTML780=== RUN TestReadProxyDisabled781=== PAUSE TestReadProxyDisabled782=== RUN TestReadRedirectNar783=== PAUSE TestReadRedirectNar784=== RUN TestReadRedirectKeepsNarinfoProxied785=== PAUSE TestReadRedirectKeepsNarinfoProxied786=== RUN TestReadProxyRangeRequest787=== PAUSE TestReadProxyRangeRequest788=== RUN TestReadRedirectUsesPublicS3URL789=== PAUSE TestReadRedirectUsesPublicS3URL790=== RUN TestPush_OverlappingRootsStoreOneRowPerKey791=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey792=== RUN TestPush_CompleteCommitsEveryRoot793=== PAUSE TestPush_CompleteCommitsEveryRoot794=== RUN TestPush_RepeatedRootCommitsOnce795=== PAUSE TestPush_RepeatedRootCommitsOnce796=== RUN TestPush_CompleteWaitsForCleanupOfThePush797=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush798=== RUN TestPush_RootsAreLockedInByteOrder799=== PAUSE TestPush_RootsAreLockedInByteOrder800=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit801=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit802=== RUN TestPush_RejectsBadRequests803=== PAUSE TestPush_RejectsBadRequests804=== RUN TestPush_SignsNarinfosOfItsPendingObjects805=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects806=== RUN TestRedundantMultipartUpload807=== PAUSE TestRedundantMultipartUpload808=== RUN TestCompleteMultipartUpload_ErrorButObjectExists809=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists810=== RUN TestCompletedNarNotReofferedAcrossClosures811=== PAUSE TestCompletedNarNotReofferedAcrossClosures812=== RUN TestPresignedUploadRegisteredBeforeCommit813=== PAUSE TestPresignedUploadRegisteredBeforeCommit814=== RUN TestService_Rustfstest815=== PAUSE TestService_Rustfstest816=== RUN TestParseSize817=== PAUSE TestParseSize818=== RUN TestSkippedUploadsHandler819=== PAUSE TestSkippedUploadsHandler820=== RUN TestSystemdListenerNotActivated821--- PASS: TestSystemdListenerNotActivated (0.00s)822=== RUN TestWatchdogBeatsWhenHealthy823--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)824=== RUN TestWatchdogSkipsWhenUnhealthy8252026/10/08 21:39:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8262026/10/08 21:39:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8272026/10/08 21:39:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8282026/10/08 21:39:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8292026/10/08 21:39:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8302026/10/08 21:39:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8312026/10/08 21:39:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8322026/10/08 21:39:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8332026/10/08 21:39:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8342026/10/08 21:39:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"835--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)836=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle837=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle838=== RUN TestProxyWriteTimeout839=== PAUSE TestProxyWriteTimeout840=== RUN TestPendingClosureWriteTimeout841=== PAUSE TestPendingClosureWriteTimeout842=== RUN TestIsValidUploadKey843=== PAUSE TestIsValidUploadKey844=== RUN TestUploadHandlersRejectInvalidKeys845=== PAUSE TestUploadHandlersRejectInvalidKeys846=== RUN TestUploadHandlersRejectOversizedBody847=== PAUSE TestUploadHandlersRejectOversizedBody848=== RUN TestService_cleanupPendingClosuresHandler849=== PAUSE TestService_cleanupPendingClosuresHandler850=== RUN TestService_createPendingClosureHandler851=== PAUSE TestService_createPendingClosureHandler852=== RUN TestService_verifyS3Integrity853=== PAUSE TestService_verifyS3Integrity854=== RUN TestCompleteMultipartUnregistered855=== PAUSE TestCompleteMultipartUnregistered856=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT857=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT858=== CONT TestService_AuthMiddleware859=== CONT TestUploadHandlersRejectOversizedBody860=== CONT TestRedundantMultipartUpload861=== CONT TestReadProxyDisabled862=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit863=== CONT TestPush_CompleteCommitsEveryRoot864=== CONT TestCompleteMultipartUnregistered865=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT866=== CONT TestService_verifyS3Integrity867=== CONT TestService_createPendingClosureHandler868=== CONT TestService_cleanupPendingClosuresHandler869=== CONT TestUploadHandlersRejectInvalidKeys870=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info871=== CONT TestIsValidUploadKey872=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info873=== RUN TestIsValidUploadKey/narinfo874=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal875=== CONT TestProxyWriteTimeout876=== CONT TestPendingClosureWriteTimeout877=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle878=== CONT TestParseSize879=== CONT TestService_Rustfstest880=== CONT TestPresignedUploadRegisteredBeforeCommit881=== CONT TestSkippedUploadsHandler882=== CONT TestCompleteMultipartUpload_ErrorButObjectExists883=== CONT TestCompletedNarNotReofferedAcrossClosures884=== CONT TestPush_RootsAreLockedInByteOrder885=== CONT TestPush_RejectsBadRequests886=== PAUSE TestIsValidUploadKey/narinfo887=== RUN TestProxyWriteTimeout/narinfo888=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal889=== RUN TestPendingClosureWriteTimeout/empty890--- PASS: TestParseSize (0.00s)891=== CONT TestPush_RepeatedRootCommitsOnce892=== RUN TestIsValidUploadKey/nar_zst893=== PAUSE TestProxyWriteTimeout/narinfo894=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key895=== PAUSE TestPendingClosureWriteTimeout/empty896=== PAUSE TestIsValidUploadKey/nar_zst897=== RUN TestIsValidUploadKey/nar_xz898=== PAUSE TestIsValidUploadKey/nar_xz899=== RUN TestProxyWriteTimeout/1_GiB_nar900=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key901=== RUN TestPendingClosureWriteTimeout/400_objects902=== PAUSE TestProxyWriteTimeout/1_GiB_nar903=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key904=== RUN TestProxyWriteTimeout/10_GiB_nar905=== PAUSE TestPendingClosureWriteTimeout/400_objects906=== RUN TestIsValidUploadKey/nar_plain907=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key908=== PAUSE TestProxyWriteTimeout/10_GiB_nar909=== RUN TestPendingClosureWriteTimeout/670k_objects910=== CONT TestPush_CompleteWaitsForCleanupOfThePush911=== PAUSE TestIsValidUploadKey/nar_plain912=== RUN TestProxyWriteTimeout/unknown_size913=== RUN TestIsValidUploadKey/listing914=== PAUSE TestIsValidUploadKey/listing915=== PAUSE TestProxyWriteTimeout/unknown_size916=== PAUSE TestPendingClosureWriteTimeout/670k_objects917=== CONT TestPush_OverlappingRootsStoreOneRowPerKey9182026/10/08 21:39:59 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000919=== RUN TestIsValidUploadKey/build_log920=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline921=== PAUSE TestIsValidUploadKey/build_log922=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline923=== RUN TestIsValidUploadKey/build_log_home-manager_file924=== CONT TestReadRedirectKeepsNarinfoProxied925=== PAUSE TestIsValidUploadKey/build_log_home-manager_file926=== RUN TestIsValidUploadKey/build_log_plus_in_name927=== PAUSE TestIsValidUploadKey/build_log_plus_in_name928=== RUN TestIsValidUploadKey/build_log_question_mark929=== PAUSE TestIsValidUploadKey/build_log_question_mark930=== RUN TestIsValidUploadKey/build_log_equals931=== PAUSE TestIsValidUploadKey/build_log_equals932=== RUN TestIsValidUploadKey/realisation933=== PAUSE TestIsValidUploadKey/realisation934=== RUN TestIsValidUploadKey/realisation_plus_in_output935=== PAUSE TestIsValidUploadKey/realisation_plus_in_output936=== RUN TestIsValidUploadKey/nix-cache-info937=== PAUSE TestIsValidUploadKey/nix-cache-info938=== RUN TestIsValidUploadKey/index.html939=== PAUSE TestIsValidUploadKey/index.html940=== RUN TestIsValidUploadKey/narinfo_key,_nar_type941=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type942=== RUN TestIsValidUploadKey/nar_key,_narinfo_type943=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type944=== RUN TestIsValidUploadKey/listing_key,_narinfo_type945=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type946=== RUN TestIsValidUploadKey/traversal947=== PAUSE TestIsValidUploadKey/traversal948=== RUN TestIsValidUploadKey/traversal_nar949=== PAUSE TestIsValidUploadKey/traversal_nar950=== RUN TestIsValidUploadKey/absolute951=== PAUSE TestIsValidUploadKey/absolute952=== RUN TestIsValidUploadKey/empty_key953=== PAUSE TestIsValidUploadKey/empty_key954=== RUN TestIsValidUploadKey/unknown_type955=== PAUSE TestIsValidUploadKey/unknown_type956=== CONT TestReadProxyRangeRequest957--- PASS: TestSkippedUploadsHandler (0.03s)958=== CONT TestReadRedirectUsesPublicS3URL9592026/10/08 21:39:59 INFO Received push request method=POST path=/api/pushes9602026/10/08 21:39:59 INFO Received push request method=POST path=/api/pushes961--- PASS: TestReadProxyDisabled (0.42s)962=== CONT TestReadProxyRootRedirectsToIndexHTML9632026/10/08 21:39:59 INFO Received uploads request method=POST path=/api/pending_closures9642026/10/08 21:39:59 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"9652026/10/08 21:39:59 INFO Received uploads request method=POST path=/api/pending_closures966--- PASS: TestService_AuthMiddleware (0.47s)967=== CONT TestReadRedirectNar9682026/10/08 21:39:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9692026/10/08 21:39:59 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst970=== CONT TestGCTaskStore_StartNew971--- PASS: TestCompleteMultipartUnregistered (0.50s)972=== CONT TestReadProxyHead973--- PASS: TestGCTaskStore_StartNew (0.00s)9742026/10/08 21:39:59 INFO Received uploads request method=POST path=/api/pending_closures9752026/10/08 21:39:59 INFO Received uploads request method=POST path=/api/pending_closures9762026/10/08 21:39:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9772026/10/08 21:40:00 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjhiYjFlNTc4LWM5NTQtNDg3MS05NDc3LTY4ZDk1ZGMzYzdkOXgxNzkxNDk1NTk5OTM1OTIxMDA1978--- PASS: TestService_Rustfstest (0.58s)979=== CONT TestReadProxyOutlastsServerWriteTimeout9802026/10/08 21:40:00 INFO Received push request method=POST path=/api/pushes9812026/10/08 21:40:00 INFO Received uploads request method=POST path=/api/pending_closures9822026/10/08 21:40:00 INFO Received push request method=POST path=/api/pushes983=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure984=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure985=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart986=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart987=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts988=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts989=== CONT TestReadProxy4049902026/10/08 21:40:00 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjhiYjFlNTc4LWM5NTQtNDg3MS05NDc3LTY4ZDk1ZGMzYzdkOXgxNzkxNDk1NTk5OTM1OTIxMDA1 error="Delete \"http://localhost:43651/bucket10/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjhiYjFlNTc4LWM5NTQtNDg3MS05NDc3LTY4ZDk1ZGMzYzdkOXgxNzkxNDk1NTk5OTM1OTIxMDA1\": injected: abort refused"9912026/10/08 21:40:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9922026/10/08 21:40:00 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjhiYjFlNTc4LWM5NTQtNDg3MS05NDc3LTY4ZDk1ZGMzYzdkOXgxNzkxNDk1NTk5OTM1OTIxMDA19932026/10/08 21:40:00 INFO Received push request method=POST path=/api/pushes9942026/10/08 21:40:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjhiYjFlNTc4LWM5NTQtNDg3MS05NDc3LTY4ZDk1ZGMzYzdkOXgxNzkxNDk1NTk5OTM1OTIxMDA1 parts=1995--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.72s)996=== CONT TestReadProxyInvalidPath9972026/10/08 21:40:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9982026/10/08 21:40:00 INFO Received cleanup request method=DELETE path=/api/pending_closures9992026/10/08 21:40:00 INFO Aborted multipart uploads count=0 kept=010002026/10/08 21:40:00 INFO Received uploads request method=POST path=/api/pending_closures10012026/10/08 21:40:00 INFO Received cleanup request method=DELETE path=/api/pending_closures10022026/10/08 21:40:00 INFO Aborted multipart uploads count=1 kept=010032026/10/08 21:40:00 INFO Received uploads request method=POST path=/api/pending_closures10042026/10/08 21:40:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10052026/10/08 21:40:00 INFO Received uploads request method=POST path=/api/pending_closures10062026/10/08 21:40:00 INFO Received uploads request method=POST path=/api/pending_closures10072026-10-08 21:40:00.228 UTC [707] ERROR: Closure does not exist: id=110082026-10-08 21:40:00.228 UTC [707] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE10092026-10-08 21:40:00.228 UTC [707] STATEMENT: -- name: CommitPendingClosure :one1010 SELECT commit_pending_closure($1::bigint)::bigint1011 1012--- PASS: TestService_cleanupPendingClosuresHandler (0.83s)1013=== CONT TestReadProxyNarStreaming10142026/10/08 21:40:00 INFO Received push request method=POST path=/api/pushes1015--- PASS: TestReadRedirectUsesPublicS3URL (0.84s)1016=== CONT TestReadProxyNarinfoAlreadyDecompressed10172026/10/08 21:40:00 INFO Received uploads request method=POST path=/api/pending_closures1018--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.89s)1019=== CONT TestReadProxyContentNegotiation1020--- PASS: TestReadProxyRangeRequest (0.89s)1021=== CONT TestParseSingleRange1022=== RUN TestParseSingleRange/none1023=== PAUSE TestParseSingleRange/none1024=== RUN TestParseSingleRange/unknown_unit1025=== PAUSE TestParseSingleRange/unknown_unit1026=== RUN TestParseSingleRange/multi-range_ignored1027=== PAUSE TestParseSingleRange/multi-range_ignored1028=== RUN TestParseSingleRange/malformed_no_dash1029=== PAUSE TestParseSingleRange/malformed_no_dash1030=== RUN TestParseSingleRange/malformed_both_empty1031=== PAUSE TestParseSingleRange/malformed_both_empty1032=== RUN TestParseSingleRange/malformed_end_before_start1033=== PAUSE TestParseSingleRange/malformed_end_before_start1034=== RUN TestParseSingleRange/closed1035=== PAUSE TestParseSingleRange/closed1036=== RUN TestParseSingleRange/open-ended1037=== PAUSE TestParseSingleRange/open-ended1038=== RUN TestParseSingleRange/end_clamped_to_size1039=== PAUSE TestParseSingleRange/end_clamped_to_size1040=== RUN TestParseSingleRange/suffix1041=== PAUSE TestParseSingleRange/suffix1042=== RUN TestParseSingleRange/suffix_exceeds_size1043=== PAUSE TestParseSingleRange/suffix_exceeds_size1044=== RUN TestParseSingleRange/single_byte1045=== PAUSE TestParseSingleRange/single_byte1046=== RUN TestParseSingleRange/start_past_EOF1047=== PAUSE TestParseSingleRange/start_past_EOF1048=== RUN TestParseSingleRange/start_far_past_EOF1049=== PAUSE TestParseSingleRange/start_far_past_EOF1050=== CONT TestReadProxyConditionalGet1051--- PASS: TestReadRedirectKeepsNarinfoProxied (0.90s)1052=== CONT TestReadProxyNarinfo1053=== RUN TestPush_RejectsBadRequests/no_roots1054=== PAUSE TestPush_RejectsBadRequests/no_roots1055=== RUN TestPush_RejectsBadRequests/no_objects1056=== PAUSE TestPush_RejectsBadRequests/no_objects1057=== RUN TestPush_RejectsBadRequests/bad_root1058=== PAUSE TestPush_RejectsBadRequests/bad_root1059=== RUN TestPush_RejectsBadRequests/root_not_in_objects1060=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1061=== CONT TestIsValidCachePath1062=== RUN TestIsValidCachePath/narinfo1063=== PAUSE TestIsValidCachePath/narinfo1064=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1065=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1066=== RUN TestIsValidCachePath/nar_zst1067=== PAUSE TestIsValidCachePath/nar_zst1068=== RUN TestIsValidCachePath/nar_xz1069=== PAUSE TestIsValidCachePath/nar_xz1070=== RUN TestIsValidCachePath/nar_bz21071=== PAUSE TestIsValidCachePath/nar_bz21072=== RUN TestIsValidCachePath/nar_uncompressed1073=== PAUSE TestIsValidCachePath/nar_uncompressed1074=== RUN TestIsValidCachePath/ls1075=== PAUSE TestIsValidCachePath/ls1076=== RUN TestIsValidCachePath/log1077=== PAUSE TestIsValidCachePath/log1078=== RUN TestIsValidCachePath/realisation1079=== PAUSE TestIsValidCachePath/realisation1080=== RUN TestIsValidCachePath/nix-cache-info1081=== PAUSE TestIsValidCachePath/nix-cache-info1082=== RUN TestIsValidCachePath/index.html1083=== PAUSE TestIsValidCachePath/index.html1084=== RUN TestIsValidCachePath/traversal_parent1085=== PAUSE TestIsValidCachePath/traversal_parent1086=== RUN TestIsValidCachePath/traversal_in_middle1087=== PAUSE TestIsValidCachePath/traversal_in_middle1088=== RUN TestIsValidCachePath/invalid_char_e1089=== PAUSE TestIsValidCachePath/invalid_char_e1090=== RUN TestIsValidCachePath/invalid_char_u1091=== PAUSE TestIsValidCachePath/invalid_char_u1092=== RUN TestIsValidCachePath/random_path1093=== PAUSE TestIsValidCachePath/random_path1094=== RUN TestIsValidCachePath/empty1095=== PAUSE TestIsValidCachePath/empty1096=== RUN TestIsValidCachePath/leading_slash1097=== PAUSE TestIsValidCachePath/leading_slash1098=== RUN TestIsValidCachePath/wrong_extension1099=== PAUSE TestIsValidCachePath/wrong_extension1100=== RUN TestIsValidCachePath/short_hash1101=== PAUSE TestIsValidCachePath/short_hash1102=== CONT TestPresentNotReportedWhileGCDeletesClosure1103=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1104=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1105=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1106=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1107=== CONT TestPresentRefreshesOnlyStaleClosures11082026/10/08 21:40:00 INFO Received uploads request method=POST path=/api/pending_closures11092026/10/08 21:40:00 INFO Received uploads request method=POST path=/api/pending_closures11102026/10/08 21:40:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1111--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.00s)1112=== CONT TestCreatePinRejectsBadInput11132026/10/08 21:40:00 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11142026/10/08 21:40:00 INFO Received uploads request method=POST path=/api/pending_closures11152026/10/08 21:40:00 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjdhNzE1YjllLWVkOTUtNGNkNS1hMWUzLWQzYzU2N2MxNzYzNHgxNzkxNDk1NTk5NzYzNDU3MzI0 parts=101116--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.04s)1117=== CONT TestDeletePinKeepsRowWhenS3Fails1118--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.63s)1119=== CONT TestCreatePin_ReservedPins11202026/10/08 21:40:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1121--- PASS: TestReadRedirectNar (0.61s)1122=== CONT TestConcurrentPinUpdatesAgree11232026/10/08 21:40:00 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjExNGNjYTE5LTI1MjQtNGJjZS04MWI4LTQ2YzU4NjEwMjZjMHgxNzkxNDk1NTk5Nzk0NjQwNzA0 parts=1011242026/10/08 21:40:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11252026/10/08 21:40:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjUyZWU0OWQ4LThjNjktNGZhNC05MzhjLTFiNzJiMTM1YjdjNngxNzkxNDk1NTk5ODczMjkwMzI0 parts=1211262026/10/08 21:40:00 INFO Received uploads request method=POST path=/api/pending_closures1127=== CONT TestNARDeduplicationMetadataUploadBug1128--- PASS: TestReadProxyInvalidPath (0.48s)11292026/10/08 21:40:00 INFO Received uploads request method=POST path=/api/pending_closures11302026/10/08 21:40:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11312026/10/08 21:40:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1132--- PASS: TestReadProxyNarStreaming (0.43s)1133=== CONT TestGracefulShutdownDrainsInflight11342026/10/08 21:40:00 INFO Starting HTTP server address=127.0.0.1:4119111352026/10/08 21:40:00 INFO Shutdown signal received, draining in-flight requests timeout=10s11362026/10/08 21:40:00 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLmRhNDNiYzg4LThiODMtNGNhZC1hNzI2LTkyMjcyMGYzZDFjM3gxNzkxNDk1NjAwMDI2NDgxOTQy parts=1011372026/10/08 21:40:00 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjdmYjljNTI1LWQzYWQtNGRkMC04NjZjLThjN2ZmNzQ2YTAyYXgxNzkxNDk1NjAwMDg4MTYyNjQ1 parts=1011382026/10/08 21:40:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1139--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.42s)1140=== CONT TestGCTaskStore_Fail1141--- PASS: TestGCTaskStore_Fail (0.00s)1142=== CONT TestCreatePendingClosureRejectsOversizedNAR11432026/10/08 21:40:00 INFO Received uploads request method=POST path=/api/pending_closures1144--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1145=== CONT TestGCTaskStore_GetReturnsLatest1146--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1147=== CONT TestMetricsInventory11482026/10/08 21:40:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39747/oidc11492026/10/08 21:40:00 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLmU4NWQzY2M4LTczODMtNGNhMC05NjQ0LTU4NTBlYmRhMTE0OHgxNzkxNDk1NTk5OTc4NDg2NTg0 parts=121150--- PASS: TestReadProxyHead (0.84s)1151=== CONT TestGenerateLandingPage11522026/10/08 21:40:00 INFO Received uploads request method=POST path=/api/pending_closures1153--- PASS: TestGracefulShutdownDrainsInflight (0.07s)11542026/10/08 21:40:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1155=== CONT TestOrphanedObjectsGCStressTest1156=== CONT TestService_readinessHandler1157--- PASS: TestGenerateLandingPage (0.03s)11582026/10/08 21:40:00 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjgxZGYyMTg0LWIzZTktNGIyMi04MzcwLWY0YjJkZDNiN2YzZngxNzkxNDk1NjAwMTIyNDI1MjM5 parts=101159--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.37s)1160=== CONT TestService_healthCheckHandler1161=== CONT TestReconnectLeavesObjectsUnlocked1162--- PASS: TestPresentRefreshesOnlyStaleClosures (0.49s)11632026/10/08 21:40:00 INFO Received create pin request method=POST path=/api/pins/deploy11642026/10/08 21:40:00 INFO Received create pin request method=POST path=/api/pins/deploy11652026/10/08 21:40:00 INFO Received create pin request method=POST path=/api/pins/deploy11662026/10/08 21:40:00 INFO Received create pin request method=POST path=/api/pins/deploy11672026/10/08 21:40:00 INFO Received create pin request method=POST path=/api/pins/deploy11682026/10/08 21:40:00 INFO Received create pin request method=POST path=/api/pins/deploy11692026/10/08 21:40:00 INFO Received create pin request method=POST path=/api/pins/deploy11702026/10/08 21:40:00 INFO Received create pin request method=POST path=/api/pins/deploy11712026/10/08 21:40:00 INFO Received create pin request method=POST path=/api/pins/app11722026/10/08 21:40:00 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo11732026/10/08 21:40:00 INFO Received delete pin request method=DELETE path=/api/pins/app11742026/10/08 21:40:00 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket40/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11752026/10/08 21:40:00 INFO Received delete pin request method=DELETE path=/api/pins/app11762026/10/08 21:40:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11772026/10/08 21:40:00 INFO Deleted pin name=app11782026/10/08 21:40:00 INFO Received create pin request method=POST path=/api/pins/app11792026/10/08 21:40:00 INFO Received create pin request method=POST path=/api/pins/app1180--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.48s)1181=== CONT TestPendingClosureFailureTracksEveryUpload1182=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1183=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1184=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1185=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1186=== CONT TestObjectStatsLargeCommit11872026/10/08 21:40:00 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjg1M2QyZmE3LTZkNWMtNDk3OS05ZjcwLTRlOTc0OTY5OGFhZHgxNzkxNDk1NjAwMjQwMjM5NzM1 parts=1011882026/10/08 21:40:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11892026/10/08 21:40:00 INFO Completed upload id=1 objects=2 duration=4.596211ms11902026/10/08 21:40:00 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011912026/10/08 21:40:00 INFO Received uploads request method=POST path=/api/pending_closures11922026/10/08 21:40:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11932026/10/08 21:40:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures11942026/10/08 21:40:00 INFO Received create pin request method=POST path=/api/pins/deploy11952026/10/08 21:40:01 INFO Aborted multipart uploads count=0 kept=01196=== NAME TestNARDeduplicationMetadataUploadBug1197 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3131895791/001/store/zq8sqphfniv9s5s1j9pd9x3mgj1kzizg-file1.txt11982026/10/08 21:40:01 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjIyNDlhOTJhLTQyNzgtNDNlYi1hOTg3LTUwODYwZWM5ZDZlOHgxNzkxNDk1NjAwMzIzNjAwOTQ2 parts=1011992026-10-08 21:40:01.033 UTC [827] ERROR: Push does not exist: id=112002026-10-08 21:40:01.033 UTC [827] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE12012026-10-08 21:40:01.033 UTC [827] STATEMENT: SELECT commit_push($1)12022026/10/08 21:40:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12032026/10/08 21:40:01 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=012042026/10/08 21:40:01 INFO Completed upload id=1 objects=2 duration=5.147271ms12052026/10/08 21:40:01 INFO Vacuumed table table=pending_closures12062026/10/08 21:40:01 INFO Vacuumed table table=pending_objects12072026/10/08 21:40:01 INFO Received uploads request method=POST path=/api/pending_closures12082026/10/08 21:40:01 INFO Vacuumed table table=multipart_uploads12092026/10/08 21:40:01 INFO Vacuumed table table=closures12102026/10/08 21:40:01 INFO Received uploads request method=POST path=/api/pending_closures12112026/10/08 21:40:01 INFO Vacuumed table table=objects12122026/10/08 21:40:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1213--- PASS: TestMetricsInventory (0.33s)1214=== CONT TestMetricsCommit1215=== CONT TestLeadElectsOneAndHandsOver1216--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.63s)12172026/10/08 21:40:01 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo12182026/10/08 21:40:01 WARN Found objects in DB but missing from S3, will re-upload count=112192026/10/08 21:40:01 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete12202026/10/08 21:40:01 INFO Completed upload id=3 objects=2 duration=1.860557ms12212026/10/08 21:40:01 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjk4ZmZjYjJlLTAzZWYtNDliMi04MWUwLWNlODg5NjZiZjlkMngxNzkxNDk1NTk5NzY0NTk4OTgx parts=1012222026/10/08 21:40:01 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12232026/10/08 21:40:01 WARN Refused reserved pin name=worker-x86_64-linux12242026/10/08 21:40:01 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12252026/10/08 21:40:01 INFO Received create pin request method=POST path=/api/pins/my-app12262026/10/08 21:40:01 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12272026/10/08 21:40:01 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001228=== CONT TestPush_SignsNarinfosOfItsPendingObjects1229--- PASS: TestService_verifyS3Integrity (1.67s)12302026/10/08 21:40:01 INFO Received push request method=POST path=/api/pushes12312026/10/08 21:40:01 WARN readiness check failed error="closed pool"12322026/10/08 21:40:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12332026/10/08 21:40:01 INFO Uploading zq8sqphfniv9s5s1j9pd9x3mgj1kzizg-file1.txt (160B)1234--- PASS: TestReadProxyConditionalGet (0.78s)1235=== CONT TestResolveDBConnectionString1236--- PASS: TestCreatePin_ReservedPins (0.64s)1237=== CONT TestPendingClosureFailureAbortsItsUploads1238=== RUN TestResolveDBConnectionString/flag_wins1239=== PAUSE TestResolveDBConnectionString/flag_wins1240=== RUN TestResolveDBConnectionString/file_when_flag_empty1241=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1242=== RUN TestResolveDBConnectionString/missing_file_is_an_error1243=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1244=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1245=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1246=== RUN TestResolveDBConnectionString/nothing_configured1247=== PAUSE TestResolveDBConnectionString/nothing_configured1248=== CONT TestGCSweepSkipsPendingObjects1249--- PASS: TestService_createPendingClosureHandler (1.69s)1250=== CONT TestRegisterCompletedObjectNeedsPendingRow1251=== CONT TestGCEndsOnShutdown1252=== RUN TestGCEndsOnShutdown/before_the_run1253--- PASS: TestService_readinessHandler (0.34s)1254=== PAUSE TestGCEndsOnShutdown/before_the_run1255=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1256=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1257=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1258=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1259=== CONT TestPushDedupSurvivesConcurrentGC12602026/10/08 21:40:01 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12612026/10/08 21:40:01 WARN Failed to register uploaded object key=zq8sqphfniv9s5s1j9pd9x3mgj1kzizg.ls error="server returned 404: 404 page not found\n"12622026/10/08 21:40:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12632026/10/08 21:40:01 INFO Signed narinfos id=1 count=112642026/10/08 21:40:01 INFO Uploading 1 narinfos1265--- PASS: TestService_healthCheckHandler (0.36s)1266=== CONT TestClientWithDependencies12672026/10/08 21:40:01 INFO Received complete push request method=POST path=/api/pushes/1/complete12682026/10/08 21:40:01 WARN Failed to register uploaded object key=zq8sqphfniv9s5s1j9pd9x3mgj1kzizg.narinfo error="server returned 404: 404 page not found\n"12692026/10/08 21:40:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12702026/10/08 21:40:01 INFO Completed push id=1 objects=3 duration=19.961202ms12712026/10/08 21:40:01 INFO Upload complete. (133ms)1272=== NAME TestNARDeduplicationMetadataUploadBug1273 metadata_upload_test.go:54: Retrieved narinfo from S3:1274 StorePath: /build/TestNARDeduplicationMetadataUploadBug3131895791/001/store/zq8sqphfniv9s5s1j9pd9x3mgj1kzizg-file1.txt1275 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1276 Compression: zstd1277 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1278 NarSize: 1601279 References: 1280 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1281 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1282 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1283 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12842026/10/08 21:40:01 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjg4NTI0ZDUwLWZkMTYtNGQzMS1iYWZhLTE2YjBjOWJjZDFkY3gxNzkxNDk1NTk5Nzk1NzQ5MzMy parts=101285--- PASS: TestReconnectLeavesObjectsUnlocked (0.39s)1286=== CONT TestFailedS3DeleteKeepsTombstone12872026/10/08 21:40:01 INFO Received complete push request method=POST path=/api/pushes/1/complete1288=== NAME TestNARDeduplicationMetadataUploadBug1289 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3131895791/001/store/3mxfmy2dyrqncwjx0wi8yc1wf3h7g8f1-file2.txt12902026/10/08 21:40:01 INFO Completed push id=1 objects=4 duration=22.803386ms12912026/10/08 21:40:01 INFO Received push request method=POST path=/api/pushes12922026/10/08 21:40:01 WARN Rate limiter enabled after throttle name=s3-test rate=512932026/10/08 21:40:01 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."12942026/10/08 21:40:01 INFO Received push request method=POST path=/api/pushes12952026/10/08 21:40:01 INFO Received push request method=POST path=/api/pushes12962026/10/08 21:40:01 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12972026/10/08 21:40:01 WARN Rate limiter backed off name=s3-test rate=512982026/10/08 21:40:01 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."12992026/10/08 21:40:01 INFO Aborted multipart uploads count=0 kept=013002026/10/08 21:40:01 WARN Force mode enabled - objects will be deleted immediately without grace period13012026/10/08 21:40:01 INFO lead: acquired remote=192.0.2.1:12341302--- PASS: TestReadProxy404 (1.27s)1303=== CONT TestGetExistingObjectsLocksRows13042026/10/08 21:40:01 WARN Failed to register uploaded object key=3mxfmy2dyrqncwjx0wi8yc1wf3h7g8f1.ls error="server returned 404: 404 page not found\n"13052026/10/08 21:40:01 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13062026/10/08 21:40:01 INFO Signed narinfos id=2 count=113072026/10/08 21:40:01 INFO Uploading 1 narinfos13082026/10/08 21:40:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13092026/10/08 21:40:01 INFO Received uploads request method=POST path=/api/pending_closures13102026/10/08 21:40:01 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=013112026/10/08 21:40:01 INFO Received complete push request method=POST path=/api/pushes/2/complete13122026/10/08 21:40:01 WARN Failed to register uploaded object key=3mxfmy2dyrqncwjx0wi8yc1wf3h7g8f1.narinfo error="server returned 404: 404 page not found\n"13132026/10/08 21:40:01 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjBiMmI5NWE0LTU3YmItNGZiMy1hNGRkLWY5Yzk3YjUwNWZlMXgxNzkxNDk1NjAwMDI2MjQ0Njgz parts=1013142026/10/08 21:40:01 INFO Completed push id=2 objects=3 duration=4.050152ms13152026/10/08 21:40:01 INFO Upload complete. (115ms)13162026/10/08 21:40:01 INFO Vacuumed table table=pending_closures1317=== NAME TestNARDeduplicationMetadataUploadBug1318 metadata_upload_test.go:76: Retrieved narinfo from S3:1319 StorePath: /build/TestNARDeduplicationMetadataUploadBug3131895791/001/store/3mxfmy2dyrqncwjx0wi8yc1wf3h7g8f1-file2.txt1320 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1321 Compression: zstd1322 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1323 NarSize: 1601324 References: 1325 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf13262026/10/08 21:40:01 INFO Vacuumed table table=pending_objects13272026/10/08 21:40:01 INFO Vacuumed table table=multipart_uploads1328 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1329 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1330 {"version":1,"root":{"type":"regular","size":44}}13312026/10/08 21:40:01 INFO Vacuumed table table=closures13322026/10/08 21:40:01 INFO Vacuumed table table=objects13332026/10/08 21:40:01 INFO Received push request method=POST path=/api/pushes13342026/10/08 21:40:01 INFO Aborted multipart uploads count=0 kept=013352026/10/08 21:40:01 WARN Force mode enabled - objects will be deleted immediately without grace period13362026/10/08 21:40:01 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=013372026/10/08 21:40:01 INFO Vacuumed table table=pending_closures13382026/10/08 21:40:01 INFO Vacuumed table table=pending_objects13392026/10/08 21:40:01 INFO Vacuumed table table=multipart_uploads13402026/10/08 21:40:01 INFO Vacuumed table table=closures13412026/10/08 21:40:01 INFO Vacuumed table table=objects13422026/10/08 21:40:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13432026/10/08 21:40:01 INFO Signed narinfos id=1 count=113442026/10/08 21:40:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13452026/10/08 21:40:01 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo13462026/10/08 21:40:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13472026/10/08 21:40:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13482026/10/08 21:40:01 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"13492026/10/08 21:40:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13502026/10/08 21:40:01 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"13512026/10/08 21:40:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1352--- PASS: TestNARDeduplicationMetadataUploadBug (0.82s)1353=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection13542026/10/08 21:40:01 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=113552026/10/08 21:40:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13562026/10/08 21:40:01 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo13572026/10/08 21:40:01 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo13582026/10/08 21:40:01 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjY3MGUzY2U5LTMwMjAtNDA5ZS1hY2YxLWY4Zjg3MDczNjRhZXgxNzkxNDk1NjAwMTIwNjQzNzUz parts=1013592026/10/08 21:40:01 INFO Received complete push request method=POST path=/api/pushes/1/complete13602026/10/08 21:40:01 INFO Received uploads request method=POST path=/api/pending_closures1361=== CONT TestDeduplicatedObjectsRecordedAsPending1362--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.36s)1363--- PASS: TestGCSweepSkipsPendingObjects (0.37s)1364=== CONT TestGCTaskStore_CompletedAllowsNewTask1365--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1366=== CONT TestClientMultipleUploads1367=== CONT TestPinProtectsFromGC1368--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.39s)13692026/10/08 21:40:01 INFO Completed push id=1 objects=4 duration=11.941408ms1370=== CONT TestService_RequireScope_OIDC1371--- PASS: TestConcurrentPinUpdatesAgree (0.99s)13722026/10/08 21:40:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1373--- PASS: TestPush_RepeatedRootCommitsOnce (2.10s)1374=== CONT TestClientIntegration13752026/10/08 21:40:01 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjc5YzlhYzM5LTdhOWUtNGUyZS05NjNlLTMwNDZkNmMwOWJiM3gxNzkxNDk1NjAwNjU2ODAwNjYx error="Get \"http://127.0.0.1:1/bucket7/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"13762026/10/08 21:40:01 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLmYzNTAzZjYzLTdjNDYtNDcwZi1iZDM4LWRkMWIzNTA1ZWUzZHgxNzkxNDk1NjAwNjM4MDk4OTM3 parts=1213772026/10/08 21:40:01 INFO Received cleanup request method=DELETE path=/api/pending_closures13782026/10/08 21:40:01 INFO Aborted multipart uploads count=1 kept=013792026/10/08 21:40:01 INFO Received uploads request method=POST path=/api/pending_closures1380=== CONT TestPendingCleanupUsesOneCutoff1381--- PASS: TestPendingClosureFailureAbortsItsUploads (0.46s)13822026/10/08 21:40:01 INFO Received uploads request method=POST path=/api/pending_closures13832026/10/08 21:40:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45129/oidc1384--- PASS: TestRedundantMultipartUpload (2.17s)1385=== CONT TestClientCADerivations13862026/10/08 21:40:01 INFO Aborted multipart uploads count=0 kept=01387=== NAME TestClientWithDependencies1388 client_integration_test.go:735: Built derivation: /build/TestClientWithDependencies447718432/001/store/ydl7sbyf0f4b9ii28im7gf3jwinvwlwd-test-script13892026/10/08 21:40:01 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=01390--- PASS: TestGetExistingObjectsLocksRows (0.29s)1391=== CONT TestGCTaskStore_PhaseUpdates1392--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1393=== CONT TestService_ReadScope_PublicByDefault13942026/10/08 21:40:01 INFO Vacuumed table table=pending_closures13952026/10/08 21:40:01 INFO Vacuumed table table=pending_objects13962026/10/08 21:40:01 INFO Vacuumed table table=multipart_uploads13972026/10/08 21:40:01 INFO Vacuumed table table=closures1398--- PASS: TestReadProxyContentNegotiation (1.33s)1399=== CONT TestCacheConfigHandler1400=== RUN TestCacheConfigHandler/full_config,_no_issuer1401=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1402=== RUN TestCacheConfigHandler/no_cache_url_configured1403=== PAUSE TestCacheConfigHandler/no_cache_url_configured14042026/10/08 21:40:01 INFO Vacuumed table table=objects1405=== RUN TestCacheConfigHandler/no_signing_keys1406=== PAUSE TestCacheConfigHandler/no_signing_keys1407=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1408=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1409=== CONT TestCacheStatsHandler14102026/10/08 21:40:01 INFO Aborted multipart uploads count=0 kept=014112026/10/08 21:40:01 WARN Force mode enabled - objects will be deleted immediately without grace period14122026/10/08 21:40:01 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=01413=== NAME TestClientWithDependencies1414 client_integration_test.go:737: Found 1 dependencies (including self)14152026/10/08 21:40:01 INFO Vacuumed table table=pending_closures14162026/10/08 21:40:01 INFO Aborted multipart uploads count=0 kept=014172026/10/08 21:40:01 INFO Vacuumed table table=pending_objects14182026/10/08 21:40:01 INFO Vacuumed table table=multipart_uploads14192026/10/08 21:40:01 INFO Vacuumed table table=closures14202026/10/08 21:40:01 INFO Vacuumed table table=objects14212026/10/08 21:40:01 WARN Force mode enabled - objects will be deleted immediately without grace period14222026/10/08 21:40:01 INFO Received uploads request method=POST path=/api/pending_closures14232026/10/08 21:40:01 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."14242026/10/08 21:40:01 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."14252026/10/08 21:40:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1426=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1427--- PASS: TestPushDedupSurvivesConcurrentGC (0.62s)1428=== CONT TestPresentReportsOnlyClosureRoots1429--- PASS: TestFailedS3DeleteKeepsTombstone (0.54s)14302026/10/08 21:40:01 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjZjY2FiMzlhLWQzYjItNGY1NC05ZmNjLWYzYmFlZDFlZDgxZHgxNzkxNDk1NTk5NzYyNTY3NTU1 parts=1014312026/10/08 21:40:01 INFO Received complete push request method=POST path=/api/pushes/1/complete14322026/10/08 21:40:01 INFO Received push request method=POST path=/api/pushes14332026/10/08 21:40:01 INFO Received uploads request method=POST path=/api/pending_closures1434=== NAME TestClientMultipleUploads1435 client_integration_test.go:480: Created store path 0: /build/TestClientMultipleUploads2339359545/001/store/lswikx3idzrc1h0npn08s43212kp4mm5-test-file-0.txt14362026/10/08 21:40:01 INFO Received create pin request method=POST path=/api/pins/deploy14372026/10/08 21:40:01 INFO Completed push id=1 objects=6 duration=31.65924ms14382026/10/08 21:40:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14392026/10/08 21:40:01 INFO Uploading ydl7sbyf0f4b9ii28im7gf3jwinvwlwd-test-script (136B)14402026/10/08 21:40:01 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo1441 client_integration_test.go:480: Created store path 1: /build/TestClientMultipleUploads2339359545/001/store/pdvi247d47jq8kvbyfyq1f3m12gx2arg-test-file-1.txt14422026/10/08 21:40:01 WARN Failed to register uploaded object key=log/hz00n2qzk36h4rr6w96pfcsv99cpd408-test-script.drv error="server returned 404: 404 page not found\n"14432026/10/08 21:40:01 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"1444--- PASS: TestCreatePinRejectsBadInput (1.43s)1445=== CONT TestClientErrorHandling1446--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.38s)1447=== CONT TestOrphanedObjectsGC1448=== RUN TestClientErrorHandling/InvalidStorePath1449=== PAUSE TestClientErrorHandling/InvalidStorePath1450=== RUN TestClientErrorHandling/InvalidAuthToken1451=== PAUSE TestClientErrorHandling/InvalidAuthToken1452=== RUN TestClientErrorHandling/ServerNotAvailable1453=== PAUSE TestClientErrorHandling/ServerNotAvailable1454=== CONT TestService_AuthMiddleware_MTLSProxyHeader14552026/10/08 21:40:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14562026/10/08 21:40:01 WARN Failed to register uploaded object key=ydl7sbyf0f4b9ii28im7gf3jwinvwlwd.ls error="server returned 404: 404 page not found\n"14572026/10/08 21:40:01 INFO Signed narinfos id=1 count=114582026/10/08 21:40:01 INFO Uploading 1 narinfos1459--- PASS: TestPush_CompleteCommitsEveryRoot (2.45s)1460=== CONT TestService_ReadAuthMiddleware1461=== NAME TestClientMultipleUploads1462 client_integration_test.go:480: Created store path 2: /build/TestClientMultipleUploads2339359545/001/store/9j6d1mdc9962ip9adcrjmlr6k4m2brck-test-file-2.txt14632026/10/08 21:40:01 INFO Received complete push request method=POST path=/api/pushes/1/complete14642026/10/08 21:40:01 WARN Failed to register uploaded object key=ydl7sbyf0f4b9ii28im7gf3jwinvwlwd.narinfo error="server returned 404: 404 page not found\n"14652026/10/08 21:40:01 INFO Received uploads request method=POST path=/api/pending_closures14662026/10/08 21:40:01 INFO Completed push id=1 objects=4 duration=10.12142ms14672026/10/08 21:40:01 INFO Upload complete. (174ms)14682026/10/08 21:40:01 INFO Received uploads request method=POST path=/api/pending_closures14692026/10/08 21:40:01 INFO Aborted multipart uploads count=0 kept=01470=== NAME TestClientIntegration1471 client_integration_test.go:334: Created store path: /build/TestClientIntegration2272875049/002/store/pwg7zfx9zljfvldmmi53s62yw71paw7m-test-file.txt14722026/10/08 21:40:01 WARN Force mode enabled - objects will be deleted immediately without grace period1473=== NAME TestPinProtectsFromGC1474 client_integration_test.go:867: Pinned store path: /build/TestPinProtectsFromGC1211330628/001/store/6ch6p9nmz9dsk3fjy8aac93zgyshgvfc-pinned-file.txt1475 client_integration_test.go:868: Unpinned store path: /build/TestPinProtectsFromGC1211330628/001/store/jqjnka3mdz66pdpzv3i0y5ssysj2xrna-unpinned-file.txt14762026/10/08 21:40:01 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=014772026/10/08 21:40:01 INFO Received cleanup request method=DELETE path=/api/pending_closures14782026/10/08 21:40:01 INFO Vacuumed table table=pending_closures14792026/10/08 21:40:01 INFO Vacuumed table table=pending_objects14802026/10/08 21:40:01 INFO Vacuumed table table=multipart_uploads14812026/10/08 21:40:01 INFO Vacuumed table table=closures1482--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.48s)1483=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded14842026/10/08 21:40:01 INFO Vacuumed table table=objects1485=== NAME TestClientWithDependencies1486 client_integration_test.go:753: Skipping nix copy test - isolated store (/build/TestClientWithDependencies447718432/001/store) requires matching store prefix14872026/10/08 21:40:01 INFO Received push request method=POST path=/api/pushes14882026/10/08 21:40:01 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14892026/10/08 21:40:01 INFO Uploading pdvi247d47jq8kvbyfyq1f3m12gx2arg-test-file-1.txt (160B)14902026/10/08 21:40:01 INFO Uploading 9j6d1mdc9962ip9adcrjmlr6k4m2brck-test-file-2.txt (160B)14912026/10/08 21:40:01 INFO Uploading lswikx3idzrc1h0npn08s43212kp4mm5-test-file-0.txt (160B)14922026/10/08 21:40:01 WARN Failed to register uploaded object key=lswikx3idzrc1h0npn08s43212kp4mm5.ls error="server returned 404: 404 page not found\n"14932026/10/08 21:40:01 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"1494=== RUN TestService_RequireScope_OIDC/builder_may_write1495=== PAUSE TestService_RequireScope_OIDC/builder_may_write1496=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1497=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1498=== RUN TestService_RequireScope_OIDC/ops_may_admin1499=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1500=== RUN TestService_RequireScope_OIDC/ops_may_not_write1501=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1502=== RUN TestService_RequireScope_OIDC/reader_may_not_write1503=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1504=== RUN TestService_RequireScope_OIDC/static_token_may_admin1505=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1506=== RUN TestService_RequireScope_OIDC/static_token_may_write1507--- PASS: TestClientWithDependencies (0.82s)1508=== CONT TestCacheConfigHandlerMaxNarSize1509=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1510--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1511=== RUN TestService_RequireScope_OIDC/reader_may_read1512=== CONT TestClientPushesUseOnePush1513=== PAUSE TestService_RequireScope_OIDC/reader_may_read1514=== RUN TestService_RequireScope_OIDC/writer_implies_read1515=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1516=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1517=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1518=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1519=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1520=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1521=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1522=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1523=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1524=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1525=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1526=== CONT TestConnectWaitsForAPeerMigration15272026/10/08 21:40:01 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15282026/10/08 21:40:01 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15292026/10/08 21:40:01 INFO Received push request method=POST path=/api/pushes15302026/10/08 21:40:01 INFO Received push request method=POST path=/api/pushes15312026/10/08 21:40:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15322026/10/08 21:40:01 INFO Uploading 6ch6p9nmz9dsk3fjy8aac93zgyshgvfc-pinned-file.txt (128B)15332026/10/08 21:40:01 WARN Failed to register uploaded object key=9j6d1mdc9962ip9adcrjmlr6k4m2brck.ls error="server returned 404: 404 page not found\n"15342026/10/08 21:40:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15352026/10/08 21:40:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15362026/10/08 21:40:01 INFO Uploading pwg7zfx9zljfvldmmi53s62yw71paw7m-test-file.txt (152B)15372026/10/08 21:40:01 WARN Failed to register uploaded object key=pdvi247d47jq8kvbyfyq1f3m12gx2arg.ls error="server returned 404: 404 page not found\n"15382026/10/08 21:40:01 INFO Signed narinfos id=1 count=315392026/10/08 21:40:01 INFO Uploading 3 narinfos15402026/10/08 21:40:02 WARN Failed to register uploaded object key=6ch6p9nmz9dsk3fjy8aac93zgyshgvfc.ls error="server returned 404: 404 page not found\n"15412026/10/08 21:40:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15422026/10/08 21:40:02 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15432026/10/08 21:40:02 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15442026/10/08 21:40:02 WARN Failed to register uploaded object key=lswikx3idzrc1h0npn08s43212kp4mm5.narinfo error="server returned 404: 404 page not found\n"15452026/10/08 21:40:02 WARN Failed to register uploaded object key=9j6d1mdc9962ip9adcrjmlr6k4m2brck.narinfo error="server returned 404: 404 page not found\n"15462026/10/08 21:40:02 INFO Signed narinfos id=1 count=115472026/10/08 21:40:02 INFO Uploading 1 narinfos15482026/10/08 21:40:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15492026/10/08 21:40:02 WARN Failed to register uploaded object key=pwg7zfx9zljfvldmmi53s62yw71paw7m.ls error="server returned 404: 404 page not found\n"15502026/10/08 21:40:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15512026/10/08 21:40:02 INFO Received complete push request method=POST path=/api/pushes/1/complete15522026/10/08 21:40:02 WARN Failed to register uploaded object key=6ch6p9nmz9dsk3fjy8aac93zgyshgvfc.narinfo error="server returned 404: 404 page not found\n"15532026/10/08 21:40:02 INFO Signed narinfos id=1 count=115542026/10/08 21:40:02 INFO Uploading 1 narinfos15552026/10/08 21:40:02 INFO Received complete push request method=POST path=/api/pushes/1/complete1556--- PASS: TestCacheStatsHandler (0.36s)15572026/10/08 21:40:02 WARN Failed to register uploaded object key=pdvi247d47jq8kvbyfyq1f3m12gx2arg.narinfo error="server returned 404: 404 page not found\n"1558=== CONT TestForceGCDuringPushOffersSweptObject1559=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1560=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1561=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1562=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1563=== CONT TestConnectSerialisesConcurrentMigrations15642026/10/08 21:40:02 INFO Received complete push request method=POST path=/api/pushes/1/complete1565=== NAME TestClientCADerivations15662026/10/08 21:40:02 WARN Failed to register uploaded object key=pwg7zfx9zljfvldmmi53s62yw71paw7m.narinfo error="server returned 404: 404 page not found\n"1567 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2832418698/001/store/gxvrdxwdwa91c980qsj4fin4sbf59qmb-ca-test15682026/10/08 21:40:02 INFO Completed push id=1 objects=3 duration=10.90659ms15692026/10/08 21:40:02 INFO Upload complete. (78ms)1570--- PASS: TestService_ReadScope_PublicByDefault (0.38s)1571=== CONT TestGCTaskStore_DeduplicateSameParams1572=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1573--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)15742026/10/08 21:40:02 INFO Completed push id=1 objects=9 duration=19.549703ms15752026/10/08 21:40:02 INFO Completed push id=1 objects=3 duration=15.7331ms15762026/10/08 21:40:02 INFO Upload complete. (126ms)15772026/10/08 21:40:02 INFO Upload complete. (92ms)1578=== NAME TestClientMultipleUploads1579 client_integration_test.go:491: Uploaded 3 paths in 162.52832ms15802026/10/08 21:40:02 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjQ5M2I1ODNjLWMzNzMtNDNlYy1hYjJhLTRkMDBhNjNjNjY1N3gxNzkxNDk1NjAxMzI1MzE2MTM4 parts=1015812026/10/08 21:40:02 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15822026/10/08 21:40:02 WARN mTLS auth: bound subjects configured but subject DN unavailable15832026/10/08 21:40:02 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1584=== NAME TestClientCADerivations1585 client_ca_test.go:139: Found 1 dependencies (including self)1586--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.32s)1587=== CONT TestCommitRacingPendingCleanupKeepsObjects15882026/10/08 21:40:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15892026/10/08 21:40:02 INFO All 1 paths already cached1590=== NAME TestClientIntegration1591 client_integration_test.go:360: Retrieved narinfo from S3:1592 StorePath: /build/TestClientIntegration2272875049/002/store/pwg7zfx9zljfvldmmi53s62yw71paw7m-test-file.txt1593 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1594 Compression: zstd1595 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11596 NarSize: 1521597 References: 1598 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11599 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)1600 client_integration_test.go:361: Decompressed .ls content (64 bytes):1601 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}16022026/10/08 21:40:02 INFO Received push request method=POST path=/api/pushes16032026/10/08 21:40:02 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjdlNjAxODkwLTZlYzctNDhiMC04NzFhLWMxNzE4OGQzZTQ1MHgxNzkxNDk1NjAwMDI0NzIxMTk2 parts=101604--- PASS: TestClientMultipleUploads (0.63s)1605=== CONT TestPushWaitsForSweepHoldingRow16062026/10/08 21:40:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1607--- PASS: TestPresentReportsOnlyClosureRoots (0.36s)16082026/10/08 21:40:02 INFO Uploading jqjnka3mdz66pdpzv3i0y5ssysj2xrna-unpinned-file.txt (128B)1609=== CONT TestGCBugBareHashReferences16102026/10/08 21:40:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16112026/10/08 21:40:02 INFO Received push request method=POST path=/api/pushes16122026/10/08 21:40:02 INFO Received push request method=POST path=/api/pushes1613--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.35s)1614=== CONT TestSweepRechecksPendingAfterLocking16152026/10/08 21:40:02 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>16162026/10/08 21:40:02 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjU3OThiODc2LWRiODQtNGYwNS1hOWJmLWNkYzViMTYzNDgxZHgxNzkxNDk1NjAxMjYzNTI2NTU1 parts=1016172026/10/08 21:40:02 INFO Received complete push request method=POST path=/api/pushes/2/complete16182026-10-08 21:40:02.216 UTC [1594] ERROR: relation "goose_db_version" already exists16192026-10-08 21:40:02.216 UTC [1594] STATEMENT: CREATE TABLE goose_db_version (1620 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1621 version_id bigint NOT NULL,1622 is_applied boolean NOT NULL,1623 tstamp timestamp NOT NULL DEFAULT now()1624 )16252026/10/08 21:40:02 INFO Object in database but missing from S3 key=pwg7zfx9zljfvldmmi53s62yw71paw7m.ls16262026/10/08 21:40:02 WARN Found objects in DB but missing from S3, will re-upload count=116272026/10/08 21:40:02 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16282026/10/08 21:40:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16292026/10/08 21:40:02 INFO Uploading gxvrdxwdwa91c980qsj4fin4sbf59qmb-ca-test (144B)16302026/10/08 21:40:02 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16312026/10/08 21:40:02 INFO Completed push id=2 objects=4 duration=7.019947ms1632--- PASS: TestService_ReadAuthMiddleware (0.36s)1633=== CONT TestClientFallsBackToClosures16342026/10/08 21:40:02 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16352026/10/08 21:40:02 WARN Failed to register uploaded object key=jqjnka3mdz66pdpzv3i0y5ssysj2xrna.ls error="server returned 404: 404 page not found\n"16362026/10/08 21:40:02 INFO Signed narinfos id=2 count=116372026/10/08 21:40:02 WARN Failed to register uploaded object key=log/7vcvfhx2ryw2m1whwi83dz50xphj6dah-ca-test.drv error="server returned 404: 404 page not found\n"16382026/10/08 21:40:02 INFO Uploading 1 narinfos1639--- PASS: TestReadProxyNarinfo (1.92s)1640=== CONT TestTombstonedObjectOfferedWithoutWaiting16412026/10/08 21:40:02 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16422026/10/08 21:40:02 WARN Failed to register uploaded object key=gxvrdxwdwa91c980qsj4fin4sbf59qmb.ls error="server returned 404: 404 page not found\n"16432026/10/08 21:40:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16442026/10/08 21:40:02 INFO Received complete push request method=POST path=/api/pushes/2/complete16452026/10/08 21:40:02 WARN Failed to register uploaded object key=pwg7zfx9zljfvldmmi53s62yw71paw7m.ls error="server returned 404: 404 page not found\n"16462026/10/08 21:40:02 INFO Signed narinfos id=1 count=116472026/10/08 21:40:02 INFO Uploading 1 narinfos1648=== CONT TestDeleteClosuresRacingPins16492026/10/08 21:40:02 INFO Completed push id=2 objects=3 duration=4.062312ms1650--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.84s)16512026/10/08 21:40:02 INFO Upload complete. (118ms)1652=== NAME TestClientIntegration1653 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)1654 client_integration_test.go:389: Decompressed .ls content (49 bytes):16552026/10/08 21:40:02 INFO Received complete push request method=POST path=/api/pushes/2/complete1656 {"version":1,"root":{"type":"regular","size":39}}16572026/10/08 21:40:02 WARN Failed to register uploaded object key=jqjnka3mdz66pdpzv3i0y5ssysj2xrna.narinfo error="server returned 404: 404 page not found\n"16582026/10/08 21:40:02 INFO Completed push id=2 objects=3 duration=4.148002ms16592026/10/08 21:40:02 INFO Upload complete. (210ms)16602026/10/08 21:40:02 INFO Received complete push request method=POST path=/api/pushes/1/complete16612026/10/08 21:40:02 WARN Failed to register uploaded object key=gxvrdxwdwa91c980qsj4fin4sbf59qmb.narinfo error="server returned 404: 404 page not found\n"16622026/10/08 21:40:02 INFO Completed push id=1 objects=4 duration=10.35872ms16632026/10/08 21:40:02 INFO Upload complete. (195ms)16642026/10/08 21:40:02 INFO Received uploads request method=POST path=/api/pending_closures1665=== NAME TestClientCADerivations1666 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2832418698/001/store/gxvrdxwdwa91c980qsj4fin4sbf59qmb-ca-test1667 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1668 Compression: zstd1669 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1670 NarSize: 1441671 References: 1672 Deriver: /build/TestClientCADerivations2832418698/001/store/7vcvfhx2ryw2m1whwi83dz50xphj6dah-ca-test.drv1673 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1674 client_ca_test.go:185: Checking for realisation files in S3...1675 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1676 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache16772026/10/08 21:40:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures16782026/10/08 21:40:02 INFO Garbage collection started16792026/10/08 21:40:02 INFO Aborted multipart uploads count=0 kept=016802026/10/08 21:40:02 WARN Force mode enabled - objects will be deleted immediately without grace period16812026/10/08 21:40:02 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=016822026/10/08 21:40:02 INFO Vacuumed table table=pending_closures16832026/10/08 21:40:02 INFO Vacuumed table table=pending_objects16842026/10/08 21:40:02 INFO Vacuumed table table=multipart_uploads16852026/10/08 21:40:02 INFO Vacuumed table table=closures16862026/10/08 21:40:02 INFO Vacuumed table table=objects1687--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.43s)1688=== CONT TestSweepSkipsRowsLockedByPush16892026/10/08 21:40:02 INFO Received push request method=POST path=/api/pushes16902026/10/08 21:40:02 INFO Received uploads request method=POST path=/api/pending_closures16912026/10/08 21:40:02 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16922026/10/08 21:40:02 INFO Aborted multipart uploads count=0 kept=016932026/10/08 21:40:02 INFO Received complete push request method=POST path=/api/pushes/3/complete16942026/10/08 21:40:02 WARN Failed to register uploaded object key=pwg7zfx9zljfvldmmi53s62yw71paw7m.ls error="server returned 404: 404 page not found\n"16952026/10/08 21:40:02 WARN Force mode enabled - objects will be deleted immediately without grace period16962026/10/08 21:40:02 INFO Completed push id=3 objects=3 duration=4.104132ms16972026/10/08 21:40:02 INFO Upload complete. (93ms)16982026/10/08 21:40:02 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=01699=== NAME TestClientIntegration1700 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)1701 client_integration_test.go:405: Decompressed .ls content (49 bytes):1702 {"version":1,"root":{"type":"regular","size":39}}17032026/10/08 21:40:02 INFO Vacuumed table table=pending_closures17042026/10/08 21:40:02 INFO Vacuumed table table=pending_objects17052026/10/08 21:40:02 INFO Vacuumed table table=multipart_uploads17062026/10/08 21:40:02 INFO Vacuumed table table=closures17072026/10/08 21:40:02 INFO Vacuumed table table=objects1708=== NAME TestClientCADerivations1709 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1710 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1711 error: binary cache 's3://bucket66?endpoint=http://localhost:43651®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2832418698/001/store'1712 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11713--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.38s)1714=== CONT TestGCMetrics1715--- PASS: TestClientCADerivations (0.87s)1716=== CONT TestGCTaskStore_ConflictDifferentParams1717--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1718=== CONT TestGCSweepDeliversEachKeyOnce17192026/10/08 21:40:02 INFO Aborted multipart uploads count=0 kept=017202026/10/08 21:40:02 WARN Force mode enabled - objects will be deleted immediately without grace period17212026/10/08 21:40:02 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=017222026/10/08 21:40:02 INFO Vacuumed table table=pending_closures17232026/10/08 21:40:02 INFO Vacuumed table table=pending_objects17242026/10/08 21:40:02 INFO Vacuumed table table=multipart_uploads17252026/10/08 21:40:02 INFO Vacuumed table table=closures17262026/10/08 21:40:02 INFO Vacuumed table table=objects17272026/10/08 21:40:02 INFO Received push request method=POST path=/api/pushes17282026/10/08 21:40:02 INFO Received uploads request method=POST path=/api/pending_closures17292026/10/08 21:40:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17302026/10/08 21:40:02 INFO Uploading pnc1kx3pal6j13hw0i6bcx8825l8yj3r-lost-commit.txt (152B)17312026/10/08 21:40:02 INFO Received push request method=POST path=/api/pushes1732--- PASS: TestSweepRechecksPendingAfterLocking (0.32s)1733=== CONT TestClientSharedPathCommittedMidPush17342026/10/08 21:40:02 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17352026/10/08 21:40:02 INFO Uploading jj3cl0rijf6n81bnm6lw7wj5bgxhd63y-shared-dep (136B)17362026/10/08 21:40:02 INFO Uploading 6siy9r7hz1yvihlf3blk3cj1dj1740sk-a (216B)17372026/10/08 21:40:02 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"1738=== CONT TestGCTaskStore_GetEmpty1739--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.30s)1740=== CONT TestLeadEndsOnShutdown1741--- PASS: TestGCTaskStore_GetEmpty (0.00s)17422026/10/08 21:40:02 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign17432026/10/08 21:40:02 INFO Signed narinfos id=4 count=117442026/10/08 21:40:02 INFO Uploading 1 narinfos17452026/10/08 21:40:02 WARN Failed to register uploaded object key=pnc1kx3pal6j13hw0i6bcx8825l8yj3r.ls error="server returned 404: 404 page not found\n"17462026/10/08 21:40:02 WARN Failed to register uploaded object key=l4rzkjbq20x0gsqd5l2ra167j1ha1b49.ls error="server returned 404: 404 page not found\n"17472026/10/08 21:40:02 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17482026/10/08 21:40:02 WARN Failed to register uploaded object key=nar/16ymhvp11pccngaksby1hc6i102nfcz5qrbv0n19n34h1smbdfl2.nar.zst error="server returned 404: 404 page not found\n"17492026/10/08 21:40:02 WARN Failed to register uploaded object key=jj3cl0rijf6n81bnm6lw7wj5bgxhd63y.ls error="server returned 404: 404 page not found\n"17502026/10/08 21:40:02 INFO Received complete push request method=POST path=/api/pushes/4/complete17512026/10/08 21:40:02 WARN Failed to register uploaded object key=6siy9r7hz1yvihlf3blk3cj1dj1740sk.ls error="server returned 404: 404 page not found\n"17522026/10/08 21:40:02 WARN Failed to register uploaded object key=pnc1kx3pal6j13hw0i6bcx8825l8yj3r.narinfo error="server returned 404: 404 page not found\n"17532026/10/08 21:40:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17542026/10/08 21:40:02 INFO Signed narinfos id=1 count=317552026/10/08 21:40:02 INFO Uploading 3 narinfos17562026/10/08 21:40:02 WARN Failed to register uploaded object key=jj3cl0rijf6n81bnm6lw7wj5bgxhd63y.narinfo error="server returned 404: 404 page not found\n"17572026/10/08 21:40:02 WARN Failed to register uploaded object key=6siy9r7hz1yvihlf3blk3cj1dj1740sk.narinfo error="server returned 404: 404 page not found\n"17582026/10/08 21:40:02 INFO Completed push id=4 objects=3 duration=12.499846ms17592026/10/08 21:40:02 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:42487/api/pushes/4/complete\": EOF" url=http://127.0.0.1:42487/api/pushes/4/complete17602026/10/08 21:40:02 INFO lead: released remote=192.0.2.1:123417612026/10/08 21:40:02 INFO Received complete push request method=POST path=/api/pushes/1/complete17622026/10/08 21:40:02 WARN Failed to register uploaded object key=l4rzkjbq20x0gsqd5l2ra167j1ha1b49.narinfo error="server returned 404: 404 page not found\n"17632026/10/08 21:40:02 INFO Aborted multipart uploads count=0 kept=017642026/10/08 21:40:02 WARN Force mode enabled - objects will be deleted immediately without grace period17652026/10/08 21:40:02 INFO Completed push id=1 objects=8 duration=11.117859ms17662026/10/08 21:40:02 INFO Upload complete. (127ms)1767=== NAME TestClientPushesUseOnePush17682026/10/08 21:40:02 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=01769 client_pushes_test.go:97: Retrieved narinfo from S3:1770 StorePath: /build/TestClientPushesUseOnePush2419951528/001/store/jj3cl0rijf6n81bnm6lw7wj5bgxhd63y-shared-dep1771 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1772 Compression: zstd1773 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821774 NarSize: 1361775 References: 1776 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17772026/10/08 21:40:02 INFO Vacuumed table table=pending_closures17782026/10/08 21:40:02 INFO Vacuumed table table=pending_objects17792026/10/08 21:40:02 INFO Vacuumed table table=multipart_uploads17802026/10/08 21:40:02 INFO Vacuumed table table=closures17812026/10/08 21:40:02 INFO Vacuumed table table=objects1782 client_pushes_test.go:97: Retrieved narinfo from S3:1783 StorePath: /build/TestClientPushesUseOnePush2419951528/001/store/6siy9r7hz1yvihlf3blk3cj1dj1740sk-a1784 URL: nar/16ymhvp11pccngaksby1hc6i102nfcz5qrbv0n19n34h1smbdfl2.nar.zst1785 Compression: zstd1786 NarHash: sha256:16ymhvp11pccngaksby1hc6i102nfcz5qrbv0n19n34h1smbdfl21787 NarSize: 2161788 References: /build/TestClientPushesUseOnePush2419951528/001/store/jj3cl0rijf6n81bnm6lw7wj5bgxhd63y-shared-dep1789 CA: text:sha256:1lx3zk6ppk1wnslqwdpal80fr3g2mikviizpa4d64w9zg5yi5kd317902026/10/08 21:40:02 INFO Aborted multipart uploads count=0 kept=017912026/10/08 21:40:02 WARN Force mode enabled - objects will be deleted immediately without grace period1792 client_pushes_test.go:97: Retrieved narinfo from S3:1793 StorePath: /build/TestClientPushesUseOnePush2419951528/001/store/l4rzkjbq20x0gsqd5l2ra167j1ha1b49-b1794 URL: nar/16ymhvp11pccngaksby1hc6i102nfcz5qrbv0n19n34h1smbdfl2.nar.zst1795 Compression: zstd1796 NarHash: sha256:16ymhvp11pccngaksby1hc6i102nfcz5qrbv0n19n34h1smbdfl21797 NarSize: 2161798 References: /build/TestClientPushesUseOnePush2419951528/001/store/jj3cl0rijf6n81bnm6lw7wj5bgxhd63y-shared-dep1799 CA: text:sha256:1lx3zk6ppk1wnslqwdpal80fr3g2mikviizpa4d64w9zg5yi5kd31800--- PASS: TestObjectStatsLargeCommit (1.69s)1801=== CONT TestService_NativeMTLS1802=== NAME TestOrphanedObjectsGC1803 orphaned_objects_gc_test.go:287: GC Test Summary:1804 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1805 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1806 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1807 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1808 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects18092026/10/08 21:40:02 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=018102026/10/08 21:40:02 INFO Vacuumed table table=pending_closures18112026/10/08 21:40:02 INFO Vacuumed table table=pending_objects18122026/10/08 21:40:02 INFO Vacuumed table table=multipart_uploads18132026/10/08 21:40:02 INFO Vacuumed table table=closures18142026/10/08 21:40:02 INFO lead: acquired remote=192.0.2.1:123418152026/10/08 21:40:02 INFO Vacuumed table table=objects18162026/10/08 21:40:02 INFO Aborted multipart uploads count=0 kept=018172026/10/08 21:40:02 WARN Force mode enabled - objects will be deleted immediately without grace period1818--- PASS: TestOrphanedObjectsGC (0.81s)1819=== CONT TestServerTLSConfig1820=== RUN TestServerTLSConfig/no_client_CA1821=== PAUSE TestServerTLSConfig/no_client_CA1822=== RUN TestServerTLSConfig/missing_CA_file1823=== PAUSE TestServerTLSConfig/missing_CA_file1824=== RUN TestServerTLSConfig/not_a_PEM_file1825=== PAUSE TestServerTLSConfig/not_a_PEM_file1826=== CONT TestLeadIncumbentAnnouncesAtOnce1827--- PASS: TestClientPushesUseOnePush (0.70s)1828--- PASS: TestSweepSkipsRowsLockedByPush (0.30s)1829=== CONT TestMultipartCleanup1830=== CONT TestGCAdvisoryLockBlocksConcurrentRun18312026/10/08 21:40:02 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=018322026/10/08 21:40:02 INFO Vacuumed table table=pending_closures18332026/10/08 21:40:02 INFO Vacuumed table table=pending_objects18342026/10/08 21:40:02 INFO Vacuumed table table=multipart_uploads18352026/10/08 21:40:02 INFO Vacuumed table table=closures18362026/10/08 21:40:02 INFO Vacuumed table table=objects1837--- PASS: TestGCBugBareHashReferences (0.57s)1838=== CONT TestObjectStatsTrigger18392026/10/08 21:40:02 INFO Received uploads request method=POST path=/api/pending_closures18402026/10/08 21:40:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18412026/10/08 21:40:02 INFO Received complete push request method=POST path=/api/pushes/4/complete18422026-10-08 21:40:02.696 UTC [1070] ERROR: Push does not exist: id=418432026-10-08 21:40:02.696 UTC [1070] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE18442026-10-08 21:40:02.696 UTC [1070] STATEMENT: -- name: CommitPush :one1845 SELECT commit_push($1::bigint)::bigint1846 18472026/10/08 21:40:02 WARN Push not found id=418482026/10/08 21:40:02 INFO Upload complete. (224ms)1849=== NAME TestClientIntegration1850 client_integration_test.go:435: Retrieved narinfo from S3:1851 StorePath: /build/TestClientIntegration2272875049/002/store/pnc1kx3pal6j13hw0i6bcx8825l8yj3r-lost-commit.txt1852 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1853 Compression: zstd1854 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1855 NarSize: 1521856 References: 1857 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl18582026/10/08 21:40:02 INFO Received uploads request method=POST path=/api/pending_closures1859 client_integration_test.go:438: Testing garbage collection...1860--- PASS: TestGCMetrics (0.27s)1861=== CONT TestService_AuthMiddleware_OIDC18622026/10/08 21:40:02 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)18632026/10/08 21:40:02 INFO Uploading sqp1p55a05i5238kcnfpf1vbv2nz9xmk-a (216B)18642026/10/08 21:40:02 INFO Uploading 39cixn6c6hiahfvdivqijy84x05nl183-shared-dep (136B)18652026/10/08 21:40:02 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjYxODM3OTEwLWU4ZGEtNGI1YS1hZTNhLWEzOGQyZWYxZWJhZXgxNzkxNDk1NjAxMzIyOTYxNzky parts=1018662026/10/08 21:40:02 INFO Received complete push request method=POST path=/api/pushes/1/complete18672026/10/08 21:40:02 WARN Failed to register uploaded object key=0v0r6ss7iryc17myj4rhbklzqbkpwc7r.ls error="server returned 404: 404 page not found\n"18682026/10/08 21:40:02 WARN Failed to register uploaded object key=nar/1spwq4pw1ilikijrq3js2i36ryk6d4mbhmjag52scj77hk298gxq.nar.zst error="server returned 404: 404 page not found\n"18692026/10/08 21:40:02 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18702026/10/08 21:40:02 INFO Completed push id=1 objects=4 duration=13.132636ms18712026/10/08 21:40:02 INFO Aborted multipart uploads count=0 kept=018722026/10/08 21:40:02 WARN Failed to register uploaded object key=sqp1p55a05i5238kcnfpf1vbv2nz9xmk.ls error="server returned 404: 404 page not found\n"18732026/10/08 21:40:02 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18742026/10/08 21:40:02 WARN Failed to register uploaded object key=39cixn6c6hiahfvdivqijy84x05nl183.ls error="server returned 404: 404 page not found\n"18752026/10/08 21:40:02 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18762026/10/08 21:40:02 WARN Force mode enabled - objects will be deleted immediately without grace period18772026/10/08 21:40:02 INFO Completed upload id=2 objects=2 duration=3.307943ms18782026/10/08 21:40:02 INFO Signed narinfos id=1 count=218792026/10/08 21:40:02 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18802026/10/08 21:40:02 INFO Signed narinfos id=2 count=218812026/10/08 21:40:02 INFO Uploading 4 narinfos18822026/10/08 21:40:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18832026/10/08 21:40:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures18842026/10/08 21:40:02 INFO Garbage collection started18852026/10/08 21:40:02 WARN Failed to register uploaded object key=39cixn6c6hiahfvdivqijy84x05nl183.narinfo error="server returned 404: 404 page not found\n"18862026/10/08 21:40:02 WARN Failed to register uploaded object key=0v0r6ss7iryc17myj4rhbklzqbkpwc7r.narinfo error="server returned 404: 404 page not found\n"18872026/10/08 21:40:02 WARN Failed to register uploaded object key=39cixn6c6hiahfvdivqijy84x05nl183.narinfo error="server returned 404: 404 page not found\n"18882026/10/08 21:40:02 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18892026/10/08 21:40:02 WARN Failed to register uploaded object key=sqp1p55a05i5238kcnfpf1vbv2nz9xmk.narinfo error="server returned 404: 404 page not found\n"18902026/10/08 21:40:02 INFO Aborted multipart uploads count=0 kept=018912026/10/08 21:40:02 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=018922026/10/08 21:40:02 INFO Vacuumed table table=pending_closures18932026/10/08 21:40:02 INFO Vacuumed table table=pending_objects18942026/10/08 21:40:02 INFO Vacuumed table table=multipart_uploads18952026/10/08 21:40:02 INFO Vacuumed table table=closures18962026/10/08 21:40:02 INFO lead: acquired remote=192.0.2.1:123418972026/10/08 21:40:02 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjAzYzAyYWI0LTNkNGMtNDQxZi1hYmM1LTE0Y2ZmMmJhMTkxN3gxNzkxNDk1NjAwMDI3MTA3MTUx parts=1018982026/10/08 21:40:02 INFO Vacuumed table table=objects18992026/10/08 21:40:02 INFO Completed upload id=2 objects=6 duration=22.547907ms19002026/10/08 21:40:02 WARN Force mode enabled - objects will be deleted immediately without grace period19012026/10/08 21:40:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19022026/10/08 21:40:02 INFO Completed upload id=1 objects=6 duration=5.08663ms19032026/10/08 21:40:02 INFO Upload complete. (145ms)1904=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1905--- PASS: TestMetricsCommit (1.74s)19062026/10/08 21:40:02 INFO Received uploads request method=POST path=/1907=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19082026/10/08 21:40:02 INFO Received complete multipart upload request method=POST path=/1909=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1910=== NAME TestClientFallsBackToClosures19112026/10/08 21:40:02 INFO Received uploads request method=POST path=/1912 client_pushes_test.go:112: Retrieved narinfo from S3:1913 StorePath: /build/TestClientFallsBackToClosures2505920638/001/store/39cixn6c6hiahfvdivqijy84x05nl183-shared-dep1914 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1915 Compression: zstd1916 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821917 NarSize: 1361918 References: 1919 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n19202026/10/08 21:40:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34119/oidc1921=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19222026/10/08 21:40:02 INFO Received request for more parts method=POST path=/1923=== CONT TestProxyWriteTimeout/1_GiB_nar1924=== CONT TestProxyWriteTimeout/10_GiB_nar1925--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)1926 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1927 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1928 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1929 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1930=== CONT TestProxyWriteTimeout/unknown_size1931=== CONT TestProxyWriteTimeout/narinfo1932=== CONT TestPendingClosureWriteTimeout/400_objects1933--- PASS: TestProxyWriteTimeout (0.01s)1934 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1935 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1936 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1937 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1938=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1939=== NAME TestClientFallsBackToClosures1940 client_pushes_test.go:112: Retrieved narinfo from S3:1941 StorePath: /build/TestClientFallsBackToClosures2505920638/001/store/sqp1p55a05i5238kcnfpf1vbv2nz9xmk-a1942 URL: nar/1spwq4pw1ilikijrq3js2i36ryk6d4mbhmjag52scj77hk298gxq.nar.zst1943 Compression: zstd1944 NarHash: sha256:1spwq4pw1ilikijrq3js2i36ryk6d4mbhmjag52scj77hk298gxq1945 NarSize: 2161946 References: /build/TestClientFallsBackToClosures2505920638/001/store/39cixn6c6hiahfvdivqijy84x05nl183-shared-dep1947 CA: text:sha256:03d5yhcy790wng9z6pni5rpi2k2ffgr1x70m2vnmp98mb5v8i3k11948=== CONT TestPendingClosureWriteTimeout/670k_objects1949=== CONT TestPendingClosureWriteTimeout/empty1950--- PASS: TestGCSweepDeliversEachKeyOnce (0.35s)1951=== CONT TestIsValidUploadKey/nar_xz1952=== CONT TestIsValidUploadKey/realisation1953=== CONT TestIsValidUploadKey/unknown_type1954=== CONT TestIsValidUploadKey/absolute1955=== CONT TestIsValidUploadKey/empty_key1956=== CONT TestIsValidUploadKey/traversal_nar1957=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1958=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1959=== CONT TestIsValidUploadKey/traversal1960=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1961=== CONT TestIsValidUploadKey/index.html1962=== CONT TestIsValidUploadKey/realisation_plus_in_output1963=== CONT TestIsValidUploadKey/build_log_plus_in_name1964=== NAME TestClientFallsBackToClosures1965 client_pushes_test.go:112: Retrieved narinfo from S3:1966 StorePath: /build/TestClientFallsBackToClosures2505920638/001/store/0v0r6ss7iryc17myj4rhbklzqbkpwc7r-b1967 URL: nar/1spwq4pw1ilikijrq3js2i36ryk6d4mbhmjag52scj77hk298gxq.nar.zst1968 Compression: zstd1969 NarHash: sha256:1spwq4pw1ilikijrq3js2i36ryk6d4mbhmjag52scj77hk298gxq1970 NarSize: 2161971 References: /build/TestClientFallsBackToClosures2505920638/001/store/39cixn6c6hiahfvdivqijy84x05nl183-shared-dep1972 CA: text:sha256:03d5yhcy790wng9z6pni5rpi2k2ffgr1x70m2vnmp98mb5v8i3k11973=== CONT TestIsValidUploadKey/nix-cache-info1974=== CONT TestIsValidUploadKey/build_log_question_mark1975=== CONT TestIsValidUploadKey/build_log_home-manager_file1976=== CONT TestIsValidUploadKey/nar_plain1977=== CONT TestIsValidUploadKey/listing1978=== CONT TestIsValidUploadKey/build_log_equals1979=== CONT TestIsValidUploadKey/build_log1980=== CONT TestIsValidUploadKey/nar_zst1981=== CONT TestIsValidUploadKey/narinfo1982=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure1983--- PASS: TestIsValidUploadKey (0.01s)1984 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1985 --- PASS: TestIsValidUploadKey/realisation (0.00s)1986 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1987 --- PASS: TestIsValidUploadKey/absolute (0.00s)1988 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1989 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1990 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1991 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1992 --- PASS: TestIsValidUploadKey/traversal (0.00s)1993 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1994 --- PASS: TestIsValidUploadKey/index.html (0.00s)1995 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1996 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1997 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1998 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1999 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2000 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2001 --- PASS: TestIsValidUploadKey/listing (0.00s)2002 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2003 --- PASS: TestIsValidUploadKey/build_log (0.00s)2004 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2005 --- PASS: TestIsValidUploadKey/narinfo (0.00s)20062026/10/08 21:40:02 INFO Received uploads request method=POST path=/20072026/10/08 21:40:02 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=020082026/10/08 21:40:02 INFO Vacuumed table table=pending_closures20092026/10/08 21:40:02 INFO Vacuumed table table=pending_objects20102026/10/08 21:40:02 INFO Vacuumed table table=multipart_uploads20112026/10/08 21:40:02 INFO Vacuumed table table=closures20122026/10/08 21:40:02 INFO Vacuumed table table=objects20132026/10/08 21:40:02 WARN mTLS auth: subject not in bound subjects subject="CN=reader"20142026/10/08 21:40:02 WARN mTLS auth: subject not in bound subjects subject="CN=reader"2015--- PASS: TestClientFallsBackToClosures (0.64s)2016=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts20172026/10/08 21:40:02 INFO Received request for more parts method=POST path=/2018=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart2019--- PASS: TestService_NativeMTLS (0.24s)20202026/10/08 21:40:02 INFO Received complete multipart upload request method=POST path=/2021--- PASS: TestPushWaitsForSweepHoldingRow (0.82s)2022=== CONT TestParseSingleRange/multi-range_ignored2023=== CONT TestParseSingleRange/start_past_EOF2024=== CONT TestParseSingleRange/single_byte2025=== CONT TestParseSingleRange/start_far_past_EOF2026=== CONT TestParseSingleRange/malformed_both_empty2027=== CONT TestParseSingleRange/malformed_end_before_start2028=== CONT TestParseSingleRange/malformed_no_dash2029=== CONT TestParseSingleRange/unknown_unit2030=== CONT TestParseSingleRange/none2031=== CONT TestParseSingleRange/suffix2032=== CONT TestParseSingleRange/closed2033=== CONT TestParseSingleRange/end_clamped_to_size2034=== CONT TestParseSingleRange/suffix_exceeds_size2035=== CONT TestParseSingleRange/open-ended2036=== CONT TestPush_RejectsBadRequests/no_roots2037--- PASS: TestParseSingleRange (0.00s)2038 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2039 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2040 --- PASS: TestParseSingleRange/single_byte (0.00s)2041 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2042 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2043 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2044 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2045 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2046 --- PASS: TestParseSingleRange/none (0.00s)2047 --- PASS: TestParseSingleRange/suffix (0.00s)2048 --- PASS: TestParseSingleRange/closed (0.00s)2049 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2050 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2051 --- PASS: TestParseSingleRange/open-ended (0.00s)20522026/10/08 21:40:02 INFO Received push request method=POST path=/api/pushes2053=== CONT TestPush_RejectsBadRequests/root_not_in_objects20542026/10/08 21:40:02 INFO Received push request method=POST path=/api/pushes2055=== CONT TestPush_RejectsBadRequests/bad_root20562026/10/08 21:40:02 INFO Received push request method=POST path=/api/pushes2057=== CONT TestPush_RejectsBadRequests/no_objects20582026/10/08 21:40:02 INFO Received push request method=POST path=/api/pushes2059=== CONT TestIsValidCachePath/narinfo2060=== CONT TestIsValidCachePath/realisation2061=== CONT TestIsValidCachePath/traversal_parent2062=== CONT TestIsValidCachePath/log2063=== CONT TestIsValidCachePath/ls2064=== CONT TestIsValidCachePath/nar_uncompressed2065=== CONT TestIsValidCachePath/nar_bz22066=== CONT TestIsValidCachePath/nix-cache-info2067=== CONT TestIsValidCachePath/nar_xz2068=== CONT TestIsValidCachePath/short_hash2069=== CONT TestIsValidCachePath/random_path2070=== CONT TestIsValidCachePath/invalid_char_e2071=== CONT TestIsValidCachePath/invalid_char_u2072=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2073=== CONT TestIsValidCachePath/empty2074=== CONT TestIsValidCachePath/leading_slash2075=== CONT TestIsValidCachePath/nar_zst2076=== CONT TestIsValidCachePath/index.html2077=== CONT TestIsValidCachePath/wrong_extension2078=== CONT TestIsValidCachePath/traversal_in_middle2079=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale2080--- PASS: TestIsValidCachePath (0.00s)2081 --- PASS: TestIsValidCachePath/narinfo (0.00s)2082 --- PASS: TestIsValidCachePath/realisation (0.00s)2083 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2084 --- PASS: TestIsValidCachePath/log (0.00s)2085 --- PASS: TestIsValidCachePath/ls (0.00s)2086 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2087 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2088 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2089 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2090 --- PASS: TestIsValidCachePath/short_hash (0.00s)2091 --- PASS: TestIsValidCachePath/random_path (0.00s)2092 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2093 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2094 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2095 --- PASS: TestIsValidCachePath/empty (0.00s)2096 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2097 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2098 --- PASS: TestIsValidCachePath/index.html (0.00s)2099 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2100 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)21012026/10/08 21:40:02 INFO Received push request method=POST path=/api/pushes2102--- PASS: TestPush_RejectsBadRequests (0.95s)2103 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2104 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2105 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2106 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)21072026/10/08 21:40:02 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)21082026/10/08 21:40:02 INFO Uploading bk99lhvaans2rjbijkrzqrvnsm9f4sf0-top (224B)21092026/10/08 21:40:02 INFO Uploading zyq7ax5r3qw2nwfllqwy09p2ipir0gz8-shared-dep (136B)21102026/10/08 21:40:02 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"21112026/10/08 21:40:02 WARN Failed to register uploaded object key=nar/0a6cs212b0dk0vdlfgalcv7m7jhcvxm8bl0dhib55ikig1rsp013.nar.zst error="server returned 404: 404 page not found\n"21122026/10/08 21:40:02 INFO Received uploads request method=POST path=/api/pending_closures21132026/10/08 21:40:02 WARN Failed to register uploaded object key=bk99lhvaans2rjbijkrzqrvnsm9f4sf0.ls error="server returned 404: 404 page not found\n"21142026/10/08 21:40:02 WARN Failed to register uploaded object key=zyq7ax5r3qw2nwfllqwy09p2ipir0gz8.ls error="server returned 404: 404 page not found\n"21152026/10/08 21:40:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21162026/10/08 21:40:03 INFO Signed narinfos id=1 count=221172026/10/08 21:40:03 INFO Uploading 2 narinfos2118--- PASS: TestObjectStatsTrigger (0.31s)2119=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh21202026/10/08 21:40:03 WARN Failed to register uploaded object key=bk99lhvaans2rjbijkrzqrvnsm9f4sf0.narinfo error="server returned 404: 404 page not found\n"21212026/10/08 21:40:03 INFO Received complete push request method=POST path=/api/pushes/1/complete21222026/10/08 21:40:03 WARN Failed to register uploaded object key=zyq7ax5r3qw2nwfllqwy09p2ipir0gz8.narinfo error="server returned 404: 404 page not found\n"21232026/10/08 21:40:03 INFO lead: acquired remote=192.0.2.1:123421242026/10/08 21:40:03 INFO lead: released remote=192.0.2.1:123421252026/10/08 21:40:03 INFO Completed push id=1 objects=6 duration=9.403372ms21262026/10/08 21:40:03 INFO Upload complete. (132ms)2127=== NAME TestClientSharedPathCommittedMidPush2128 client_integration_test.go:816: Retrieved narinfo from S3:2129 StorePath: /build/TestClientSharedPathCommittedMidPush3272012999/001/store/zyq7ax5r3qw2nwfllqwy09p2ipir0gz8-shared-dep2130 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2131 Compression: zstd2132 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822133 NarSize: 1362134 References: 2135 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2136--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.37s)2137=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false2138=== NAME TestClientSharedPathCommittedMidPush2139 client_integration_test.go:816: Retrieved narinfo from S3:2140 StorePath: /build/TestClientSharedPathCommittedMidPush3272012999/001/store/bk99lhvaans2rjbijkrzqrvnsm9f4sf0-top2141 URL: nar/0a6cs212b0dk0vdlfgalcv7m7jhcvxm8bl0dhib55ikig1rsp013.nar.zst2142 Compression: zstd2143 NarHash: sha256:0a6cs212b0dk0vdlfgalcv7m7jhcvxm8bl0dhib55ikig1rsp0132144 NarSize: 2242145 References: /build/TestClientSharedPathCommittedMidPush3272012999/001/store/zyq7ax5r3qw2nwfllqwy09p2ipir0gz8-shared-dep2146 CA: text:sha256:0jkxf0aj8d5g8ilmzafpavkivrzq09lw6qny62a7yd3zq85xmj3g2147=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true2148--- PASS: TestClientSharedPathCommittedMidPush (0.54s)2149=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2150=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2151=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2152=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2153=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2154=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2155=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2156=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2157=== CONT TestResolveDBConnectionString/file_when_flag_empty2158=== CONT TestResolveDBConnectionString/nothing_configured2159=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2160=== CONT TestResolveDBConnectionString/missing_file_is_an_error2161=== CONT TestResolveDBConnectionString/flag_wins2162=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete2163--- PASS: TestResolveDBConnectionString (0.00s)2164 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2165 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2166 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2167 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2168 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)21692026/10/08 21:40:03 INFO Received uploads request method=POST path=/api/pending_closures21702026/10/08 21:40:03 INFO Received cleanup request method=DELETE path=/api/pending_closures21712026/10/08 21:40:03 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket92/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""21722026/10/08 21:40:03 INFO Aborted multipart uploads count=0 kept=121732026/10/08 21:40:03 INFO Received cleanup request method=DELETE path=/api/pending_closures21742026-10-08 21:40:03.133 UTC [176] LOG: checkpoints are occurring too frequently (10 seconds apart)21752026-10-08 21:40:03.133 UTC [176] HINT: Consider increasing the configuration parameter "max_wal_size".21762026/10/08 21:40:03 INFO Aborted multipart uploads count=1 kept=021772026-10-08 21:40:03.134 UTC [176] LOG: checkpoint starting: wal2178=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark2179--- PASS: TestMultipartCleanup (0.51s)2180--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.20s)2181=== CONT TestGCEndsOnShutdown/before_the_run2182--- PASS: TestConnectSerialisesConcurrentMigrations (1.24s)2183=== CONT TestCacheConfigHandler/no_cache_url_configured2184=== CONT TestCacheConfigHandler/no_signing_keys2185=== CONT TestCacheConfigHandler/full_config,_no_issuer2186=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2187=== CONT TestClientErrorHandling/InvalidAuthToken2188--- PASS: TestCacheConfigHandler (0.00s)2189 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2190 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2191 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2192 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)21932026/10/08 21:40:03 INFO Received uploads request method=POST path=/api/pending_closures21942026/10/08 21:40:03 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"2195--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.69s)2196=== CONT TestClientErrorHandling/ServerNotAvailable21972026/10/08 21:40:03 INFO Aborted multipart uploads count=0 kept=021982026/10/08 21:40:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21992026/10/08 21:40:03 WARN Force mode enabled - objects will be deleted immediately without grace period22002026/10/08 21:40:03 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:43651/bucket101/?delete=\": context canceled"22012026/10/08 21:40:03 INFO Received uploads request method=POST path=/api/pending_closures22022026/10/08 21:40:03 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjljNTBmMWU4LTk1MTktNDY1Yy05MWNhLWRmZThkMDc2ZGFhMXgxNzkxNDk1NjAwMDI2MzY4Mjkz parts=102203=== CONT TestClientErrorHandling/InvalidStorePath22042026/10/08 21:40:03 INFO Aborted multipart uploads count=0 kept=022052026/10/08 21:40:03 WARN Force mode enabled - objects will be deleted immediately without grace period22062026/10/08 21:40:03 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/present2207=== NAME TestOrphanedObjectsGCStressTest2208 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2209 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion2210=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2211--- PASS: TestGCEndsOnShutdown (0.00s)2212 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.32s)2213 --- PASS: TestGCEndsOnShutdown/before_the_run (0.24s)2214 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.29s)2215=== CONT TestService_RequireScope_OIDC/static_token_may_write2216=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2217=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2218=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read22192026/10/08 21:40:03 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]2220=== CONT TestService_RequireScope_OIDC/reader_may_read2221=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2222=== CONT TestService_RequireScope_OIDC/reader_may_not_write2223=== CONT TestService_RequireScope_OIDC/writer_implies_read2224=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2225=== CONT TestService_RequireScope_OIDC/static_token_may_admin2226=== CONT TestService_RequireScope_OIDC/builder_may_write2227=== CONT TestService_RequireScope_OIDC/ops_may_not_write2228=== CONT TestService_RequireScope_OIDC/ops_may_admin2229=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check2230=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows2231--- PASS: TestService_RequireScope_OIDC (0.51s)2232 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2233 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2234 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2235 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2236 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2237 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2238 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2239 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2240 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2241 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2242 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2243 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2244 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2245 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)22462026/10/08 21:40:03 WARN Rate limiter enabled after throttle name=s3-test rate=522472026/10/08 21:40:03 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2248=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2249 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102250 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002251--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.12s)2252=== CONT TestServerTLSConfig/no_client_CA2253=== CONT TestServerTLSConfig/not_a_PEM_file22542026/10/08 21:40:03 WARN Request failed, retrying attempt=2 backoff=191.635028ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2255=== CONT TestServerTLSConfig/missing_CA_file2256=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2257--- PASS: TestServerTLSConfig (0.00s)2258 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2259 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)2260 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)22612026/10/08 21:40:03 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2262=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2263=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected22642026/10/08 21:40:03 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]2265=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected22662026/10/08 21:40:03 WARN Authentication failed token_preview=eyJhbGciOi...fmAA_S0d2Q token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]22672026/10/08 21:40:03 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2268--- PASS: TestService_AuthMiddleware_OIDC (0.39s)2269 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2270 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2271 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2272 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)22732026/10/08 21:40:03 INFO Received uploads request method=POST path=/api/pending_closures22742026/10/08 21:40:03 INFO Aborted multipart uploads count=0 kept=022752026/10/08 21:40:03 WARN Force mode enabled - objects will be deleted immediately without grace period22762026/10/08 21:40:03 INFO Received uploads request method=POST path=/api/pending_closures22772026/10/08 21:40:03 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=022782026/10/08 21:40:03 INFO Vacuumed table table=pending_closures22792026/10/08 21:40:03 INFO Vacuumed table table=pending_objects22802026/10/08 21:40:03 INFO Vacuumed table table=multipart_uploads22812026/10/08 21:40:03 INFO Vacuumed table table=closures22822026/10/08 21:40:03 INFO Vacuumed table table=objects22832026/10/08 21:40:03 WARN Request failed, retrying attempt=3 backoff=430.51288ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22842026/10/08 21:40:03 INFO Aborted multipart uploads count=0 kept=022852026/10/08 21:40:03 WARN Force mode enabled - objects will be deleted immediately without grace period22862026/10/08 21:40:03 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=022872026/10/08 21:40:03 INFO Vacuumed table table=pending_closures22882026/10/08 21:40:03 INFO Vacuumed table table=pending_objects22892026/10/08 21:40:03 INFO Vacuumed table table=multipart_uploads22902026/10/08 21:40:03 INFO Vacuumed table table=closures22912026/10/08 21:40:03 INFO Vacuumed table table=objects22922026/10/08 21:40:03 INFO lead: released remote=192.0.2.1:12342293--- PASS: TestLeadElectsOneAndHandsOver (2.73s)2294--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2295 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.74s)2296 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.78s)2297--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2298 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.30s)2299 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.31s)23002026/10/08 21:40:03 INFO lead: released remote=192.0.2.1:12342301--- PASS: TestLeadEndsOnShutdown (1.30s)2302--- PASS: TestDeleteClosuresRacingPins (1.60s)23032026/10/08 21:40:03 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLmYxNzI1YTBkLTY0OTAtNDVkZi05ZTcwLWQ0NTY5YTBhM2MzZHgxNzkxNDk1NjAzMzk1MzY3Njkz error="Access Denied"23042026/10/08 21:40:03 WARN keeping failed pending closure for cleanup to retry the abort id=12305--- PASS: TestPendingClosureFailureTracksEveryUpload (0.00s)2306 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (0.81s)2307 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (0.85s)2308=== NAME TestOrphanedObjectsGCStressTest2309 orphaned_objects_gc_test.go:503: Stress test completed successfully:2310 orphaned_objects_gc_test.go:504: - Active objects preserved: 202311 orphaned_objects_gc_test.go:505: - Objects deleted: 2102312 orphaned_objects_gc_test.go:506: - Total GC'd: 2102313--- PASS: TestPendingClosureWriteTimeout (0.01s)2314 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2315 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2316 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2317 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.15s)2318--- PASS: TestOrphanedObjectsGCStressTest (3.22s)23192026/10/08 21:40:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23202026/10/08 21:40:04 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=OTQ3YjU1ODYtZDIzNS00MjliLTgwMDAtZWQ0NjcyY2U0NjNlLjkwNGNlYTdmLTRiYjMtNDhjMi1hMDFhLTExOGQwODQ4YzFmOHgxNzkxNDk1NjAwMDI2MDYxODcz parts=1023212026-10-08 21:40:04.080 UTC [741] ERROR: could not obtain lock on row in relation "closures"23222026-10-08 21:40:04.080 UTC [741] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23232026-10-08 21:40:04.081 UTC [741] ERROR: could not obtain lock on row in relation "closures"23242026-10-08 21:40:04.081 UTC [741] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23252026-10-08 21:40:04.082 UTC [741] ERROR: could not obtain lock on row in relation "closures"23262026-10-08 21:40:04.082 UTC [741] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23272026-10-08 21:40:04.083 UTC [741] ERROR: could not obtain lock on row in relation "closures"23282026-10-08 21:40:04.083 UTC [741] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23292026-10-08 21:40:04.084 UTC [741] ERROR: could not obtain lock on row in relation "closures"23302026-10-08 21:40:04.084 UTC [741] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT2331--- PASS: TestPush_RootsAreLockedInByteOrder (4.71s)23322026/10/08 21:40:04 WARN Request failed, retrying attempt=4 backoff=739.799072ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23332026/10/08 21:40:04 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=023342026/10/08 21:40:04 INFO Received create pin request method=POST path=/api/pins/myapp23352026/10/08 21:40:04 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1211330628/001/store/6ch6p9nmz9dsk3fjy8aac93zgyshgvfc-pinned-file.txt narinfo_key=6ch6p9nmz9dsk3fjy8aac93zgyshgvfc.narinfo23362026/10/08 21:40:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures23372026/10/08 21:40:04 INFO Garbage collection started23382026/10/08 21:40:04 INFO Aborted multipart uploads count=0 kept=023392026/10/08 21:40:04 WARN Force mode enabled - objects will be deleted immediately without grace period23402026/10/08 21:40:04 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=023412026/10/08 21:40:04 INFO Vacuumed table table=pending_closures23422026/10/08 21:40:04 INFO Vacuumed table table=pending_objects23432026/10/08 21:40:04 INFO Vacuumed table table=multipart_uploads23442026/10/08 21:40:04 INFO Vacuumed table table=closures23452026/10/08 21:40:04 INFO Vacuumed table table=objects23462026/10/08 21:40:04 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02347=== NAME TestClientIntegration2348 client_integration_test.go:445: Objects in database after GC:2349 client_integration_test.go:445: Successfully deleted all objects with GC --force2350--- PASS: TestClientIntegration (3.26s)23512026/10/08 21:40:04 WARN Request failed, retrying attempt=5 backoff=1.742686922s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2352--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.04s)2353=== NAME TestPinProtectsFromGC2354 client_integration_test.go:976: Pin successfully protected closure from garbage collection2355--- PASS: TestPinProtectsFromGC (4.91s)23562026/10/08 21:40:06 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-config23572026/10/08 21:40:06 WARN Request failed, retrying attempt=2 backoff=208.40618ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23582026/10/08 21:40:07 WARN Request failed, retrying attempt=3 backoff=417.178241ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2359--- PASS: TestConnectWaitsForAPeerMigration (5.21s)23602026/10/08 21:40:07 WARN Request failed, retrying attempt=4 backoff=815.374435ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23612026/10/08 21:40:07 INFO Aborted multipart uploads count=1 kept=023622026/10/08 21:40:07 INFO Received cleanup request method=DELETE path=/api/pending_closures23632026/10/08 21:40:07 INFO Aborted multipart uploads count=1 kept=02364--- PASS: TestPendingCleanupUsesOneCutoff (6.42s)23652026/10/08 21:40:08 WARN Request failed, retrying attempt=5 backoff=1.593341627s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23662026/10/08 21:40:09 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"23672026/10/08 21:40:09 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-config23682026/10/08 21:40:09 WARN Request failed, retrying attempt=2 backoff=194.944693ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2369--- PASS: TestUploadHandlersRejectOversizedBody (0.67s)2370 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.68s)2371 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.75s)2372 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (7.32s)23732026/10/08 21:40:10 WARN Request failed, retrying attempt=3 backoff=394.598321ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23742026/10/08 21:40:10 WARN Request failed, retrying attempt=4 backoff=781.190514ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23752026/10/08 21:40:11 WARN Request failed, retrying attempt=5 backoff=1.691238628s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23762026/10/08 21:40:13 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_closures23772026/10/08 21:40:13 WARN Request failed, retrying attempt=2 backoff=215.379884ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23782026/10/08 21:40:13 WARN Request failed, retrying attempt=3 backoff=405.599427ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23792026/10/08 21:40:13 WARN Request failed, retrying attempt=4 backoff=727.848617ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23802026/10/08 21:40:14 WARN Request failed, retrying attempt=5 backoff=1.495834623s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2381--- PASS: TestClientErrorHandling (0.00s)2382 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.39s)2383 --- PASS: TestClientErrorHandling/InvalidStorePath (0.24s)2384 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.63s)2385PASS2386{"timestamp":"2026-10-08T21:40:15.9999122Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:47422","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(392)"}23872026-10-08 21:40:16.520 UTC [171] LOG: received smart shutdown request23882026-10-08 21:40:16.526 UTC [171] LOG: background worker "logical replication launcher" (PID 181) exited with exit code 123892026-10-08 21:40:17.393 UTC [176] LOG: checkpoint complete: wrote 5791 buffers (35.3%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=13.510 s, sync=0.674 s, total=14.260 s; sync files=37078, longest=0.003 s, average=0.001 s; distance=533674 kB, estimate=533674 kB; lsn=0/251C1BA8, redo lsn=0/2209066023902026-10-08 21:40:17.396 UTC [176] LOG: shutting down23912026-10-08 21:40:17.396 UTC [176] LOG: checkpoint starting: shutdown immediate23922026-10-08 21:40:17.968 UTC [176] LOG: checkpoint complete: wrote 5241 buffers (32.0%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 3 recycled; write=0.098 s, sync=0.457 s, total=0.572 s; sync files=1589, longest=0.007 s, average=0.001 s; distance=50373 kB, estimate=485344 kB; lsn=0/251C1C20, redo lsn=0/251C1C2023932026-10-08 21:40:18.064 UTC [171] 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 TestAudienceForIssuer2434=== CONT TestValidateToken_BoundClaimsMismatch2435=== CONT TestPins_ReservedForMatchingRule2436=== CONT TestScopes_Rules2437=== CONT TestScopes_LegacyProviderDefaultsToWrite2438=== CONT TestScopes_ConfigValidation2439=== CONT TestPins_TopLevelShorthand2440=== CONT TestPins_ConfigValidation2441=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2442=== CONT TestNewValidator_KubernetesRequiresCA2443=== CONT TestValidateToken_KubernetesServiceAccount2444--- PASS: TestAudienceForIssuer (0.00s)2445=== CONT TestValidateToken_WrongAudience2446=== CONT TestValidateToken_ValidToken2447=== CONT TestValidateToken_NoMatchingProvider2448=== CONT TestHTTPClientForHasTimeouts2449=== CONT TestValidateToken_MultipleProviders2450=== CONT TestValidateToken_BoundSubjectMismatch2451=== CONT TestValidateToken_Expired2452=== CONT TestGlobMatch2453=== RUN TestGlobMatch/foo_foo2454--- PASS: TestScopes_ConfigValidation (0.00s)2455--- PASS: TestPins_ConfigValidation (0.00s)2456=== PAUSE TestGlobMatch/foo_foo2457=== RUN TestGlobMatch/foo_bar2458=== PAUSE TestGlobMatch/foo_bar2459=== RUN TestGlobMatch/*_2460=== PAUSE TestGlobMatch/*_2461=== RUN TestGlobMatch/*_anything2462=== 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/foo_bar2506=== CONT TestGlobMatch/*bar_foo2507=== CONT TestGlobMatch/fo?_fo2508=== CONT TestGlobMatch/foo*bar_foobar2509=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2510=== CONT TestGlobMatch/foo*_bar2511=== CONT TestGlobMatch/*/*_foo/bar2512=== CONT TestGlobMatch/?oo_boo2513=== CONT TestGlobMatch/*bar_foobar2514=== CONT TestGlobMatch/fo?_foo2515=== CONT TestGlobMatch/?oo_foo2516=== CONT TestGlobMatch/foo*bar_foobarbaz2517=== CONT TestGlobMatch/foo*bar_foo123bar2518=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2519=== CONT TestGlobMatch/fo?_fooo2520=== CONT TestGlobMatch/foo*_foobar2521=== CONT TestGlobMatch/foo_foo2522=== CONT TestGlobMatch/*_2523=== CONT TestGlobMatch/*_anything2524=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02525=== CONT TestGlobMatch/refs/*/main_refs/heads/main2526=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2527=== CONT TestGlobMatch/foo*_foo2528=== CONT TestGlobMatch/*/*_foo2529=== CONT TestGlobMatch/*bar_bar2530--- PASS: TestGlobMatch (0.01s)2531 --- PASS: TestGlobMatch/*bar_foo (0.00s)2532 --- PASS: TestGlobMatch/foo_bar (0.00s)2533 --- PASS: TestGlobMatch/fo?_fo (0.00s)2534 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2535 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2536 --- PASS: TestGlobMatch/foo*_bar (0.00s)2537 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2538 --- PASS: TestGlobMatch/?oo_boo (0.00s)2539 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2540 --- PASS: TestGlobMatch/fo?_foo (0.00s)2541 --- PASS: TestGlobMatch/?oo_foo (0.00s)2542 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2543 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2544 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2545 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2546 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2547 --- PASS: TestGlobMatch/*_ (0.00s)2548 --- PASS: TestGlobMatch/foo_foo (0.00s)2549 --- PASS: TestGlobMatch/*_anything (0.00s)2550 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2551 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2552 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2553 --- PASS: TestGlobMatch/foo*_foo (0.00s)2554 --- PASS: TestGlobMatch/*/*_foo (0.00s)2555 --- PASS: TestGlobMatch/*bar_bar (0.00s)25562026/10/08 21:40:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33285/oidc25572026/10/08 21:40:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44895/oidc2558--- PASS: TestPins_TopLevelShorthand (0.03s)25592026/10/08 21:40:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34247/oidc2560--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.03s)2561--- PASS: TestValidateToken_BoundClaimsMismatch (0.04s)25622026/10/08 21:40:22 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12325632026/10/08 21:40:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46275/oidc2564--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.05s)2565--- PASS: TestScopes_Rules (0.06s)25662026/10/08 21:40:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43525/oidc2567--- PASS: TestPins_ReservedForMatchingRule (0.07s)25682026/10/08 21:40:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36663/oidc2569--- PASS: TestValidateToken_WrongAudience (0.07s)25702026/10/08 21:40:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39915/oidc2571--- PASS: TestValidateToken_ValidToken (0.09s)25722026/10/08 21:40:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42015/oidc2573--- PASS: TestValidateToken_BoundSubjectMismatch (0.10s)25742026/10/08 21:40:22 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:374852575--- PASS: TestValidateToken_KubernetesServiceAccount (0.12s)25762026/10/08 21:40:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45019/oidc2577--- PASS: TestValidateToken_Expired (0.15s)25782026/10/08 21:40:22 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:44507/oidc2579--- PASS: TestValidateToken_NoMatchingProvider (0.19s)25802026/10/08 21:40:22 http: TLS handshake error from 127.0.0.1:51034: remote error: tls: bad certificate2581--- PASS: TestNewValidator_KubernetesRequiresCA (0.21s)2582--- PASS: TestHTTPClientForHasTimeouts (0.20s)25832026/10/08 21:40:22 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:44103/oidc25842026/10/08 21:40:22 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:41769/oidc2585--- PASS: TestValidateToken_MultipleProviders (0.31s)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 TestQueueEnqueueWaitsOutSlowWriter2605=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2606=== RUN TestQueueRemoveLargeClosure2607=== PAUSE TestQueueRemoveLargeClosure2608=== RUN TestServerClientIntegration2609--- PASS: TestServerClientIntegration (0.00s)2610=== RUN TestServerQueueError26112026/10/08 21:40:23 ERROR Failed to queue paths error="permission denied" count=12612--- PASS: TestServerQueueError (0.00s)2613=== RUN TestServerRefusesOversizedAndNonStoreRequests2614=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2615=== RUN TestGetListenerSocketActivation2616 server_test.go:329: === RUN TestGetListenerSocketActivation2617 --- PASS: TestGetListenerSocketActivation (0.00s)2618 PASS2619 2620--- PASS: TestGetListenerSocketActivation (1.02s)2621=== RUN TestServerStalledClientDoesNotBlockShutdown2622=== PAUSE TestServerStalledClientDoesNotBlockShutdown2623=== RUN TestServerBacksOffOnAcceptErrors2624=== PAUSE TestServerBacksOffOnAcceptErrors2625=== RUN TestDrainIsolatesPoisonPath2626=== PAUSE TestDrainIsolatesPoisonPath2627=== RUN TestRunNotBlockedByPoisonHead2628=== PAUSE TestRunNotBlockedByPoisonHead2629=== RUN TestDrainGivesUpWhenServerDown2630=== PAUSE TestDrainGivesUpWhenServerDown2631=== RUN TestFailedPathPrunedByLaterClosure2632=== PAUSE TestFailedPathPrunedByLaterClosure2633=== RUN TestWorkerUploadsAndRemoves2634=== PAUSE TestWorkerUploadsAndRemoves2635=== RUN TestWorkerSkipsGCdPaths2636=== PAUSE TestWorkerSkipsGCdPaths2637=== RUN TestWorkerPrunesClosureDeps2638=== PAUSE TestWorkerPrunesClosureDeps2639=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2640=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2641=== RUN TestDrainTimeout2642=== PAUSE TestDrainTimeout2643=== RUN TestDrainTimeoutDuringIsolation2644=== PAUSE TestDrainTimeoutDuringIsolation2645=== RUN TestShutdownFinishesInFlightPush2646=== PAUSE TestShutdownFinishesInFlightPush2647=== RUN TestWorkerRemoveFailureIsNotProgress2648=== PAUSE TestWorkerRemoveFailureIsNotProgress2649=== RUN TestWorkerKeepsPathItCannotStat2650=== PAUSE TestWorkerKeepsPathItCannotStat2651=== CONT TestSendPathsEmpty2652=== CONT TestServerBacksOffOnAcceptErrors2653=== CONT TestQueueFetchRemoveLifecycle2654=== CONT TestDrainGivesUpWhenServerDown2655=== CONT TestServerRefusesOversizedAndNonStoreRequests26562026/10/08 21:40:24 ERROR Accept failed error="too many open files"2657=== CONT TestServerStalledClientDoesNotBlockShutdown2658=== CONT TestQueueEnqueueWaitsOutSlowWriter2659=== CONT TestQueueRemoveLargeClosure2660--- PASS: TestSendPathsEmpty (0.00s)26612026/10/08 21:40:24 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2662=== CONT TestQueueEnqueueAndFetch2663=== CONT TestQueueRemove2664=== CONT TestQueueRetryMovesToBack26652026/10/08 21:40:24 ERROR Refusing path outside the store path=/nix/store store=/nix/store2666=== CONT TestQueueDeduplication2667=== CONT TestQueueConcurrentWriters2668=== CONT TestQueueFetchBatchLimit2669=== CONT TestFailedPathPrunedByLaterClosure2670=== CONT TestWorkerSkipsGCdPaths26712026/10/08 21:40:24 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store2672=== CONT TestShutdownFinishesInFlightPush2673=== RUN TestShutdownFinishesInFlightPush/completes2674=== CONT TestWorkerPrunesClosureDeps2675=== CONT TestWorkerUploadsAndRemoves2676=== CONT TestDrainTimeoutDuringIsolation2677=== CONT TestRunNotBlockedByPoisonHead2678=== CONT TestWorkerRemoveFailureIsNotProgress2679=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2680=== CONT TestDrainTimeout2681=== CONT TestWorkerKeepsPathItCannotStat2682=== PAUSE TestShutdownFinishesInFlightPush/completes2683=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2684=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout26852026/10/08 21:40:24 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store2686=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2687=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2688=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2689=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline26902026/10/08 21:40:24 ERROR Accept failed error="too many open files"2691=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2692=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2693=== CONT TestDrainIsolatesPoisonPath26942026/10/08 21:40:24 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store2695=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2696=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2697=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2698=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths26992026/10/08 21:40:24 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store2700=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2701=== CONT TestShutdownFinishesInFlightPush/completes27022026/10/08 21:40:24 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27032026/10/08 21:40:24 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store27042026/10/08 21:40:24 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store27052026/10/08 21:40:24 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store27062026/10/08 21:40:24 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store27072026/10/08 21:40:24 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store27082026/10/08 21:40:24 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store27092026/10/08 21:40:24 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store27102026/10/08 21:40:24 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store27112026/10/08 21:40:24 ERROR Failed to decode request error="unexpected EOF"2712=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline27132026/10/08 21:40:24 ERROR Accept failed error="too many open files"2714--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.02s)27152026/10/08 21:40:24 ERROR Accept failed error="too many open files"27162026/10/08 21:40:24 INFO Upload queue status pending=227172026/10/08 21:40:24 INFO Uploading batch count=127182026/10/08 21:40:24 INFO Uploading batch count=227192026/10/08 21:40:24 INFO Uploading batch count=427202026/10/08 21:40:24 ERROR Upload failed error="upload failed" count=427212026/10/08 21:40:24 INFO Upload queue status pending=327222026/10/08 21:40:24 INFO Uploading batch count=127232026/10/08 21:40:24 ERROR Upload failed error="upload failed" count=127242026/10/08 21:40:24 INFO Uploading batch count=127252026/10/08 21:40:24 ERROR Upload failed error="upload failed" count=127262026/10/08 21:40:24 INFO Upload queue status pending=227272026/10/08 21:40:24 INFO Upload queue status pending=327282026/10/08 21:40:24 INFO Upload queue status pending=227292026/10/08 21:40:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath969000194/002/bbb27302026/10/08 21:40:24 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat891288431/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat891288431/002/locked/aaa: permission denied"27312026/10/08 21:40:24 INFO Uploading batch count=227322026/10/08 21:40:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths363603372/002/nonexistent27332026/10/08 21:40:24 INFO Upload queue status pending=227342026/10/08 21:40:24 INFO Upload queue status pending=227352026/10/08 21:40:24 INFO Uploading batch count=227362026/10/08 21:40:24 INFO Uploading batch count=227372026/10/08 21:40:24 INFO Uploading batch count=22738--- PASS: TestQueueFetchRemoveLifecycle (0.08s)2739=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short27402026/10/08 21:40:24 INFO Uploading batch count=22741--- PASS: TestQueueDeduplication (0.07s)27422026/10/08 21:40:24 INFO Uploading batch count=22743=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch27442026/10/08 21:40:24 ERROR Upload failed error="upload failed" count=227452026/10/08 21:40:24 INFO Uploading batch count=127462026/10/08 21:40:24 ERROR Accept failed error="too many open files"27472026/10/08 21:40:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3148070597/002/a27482026/10/08 21:40:24 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat891288431/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat891288431/002/locked/aaa: permission denied"27492026/10/08 21:40:24 INFO Uploading batch count=127502026/10/08 21:40:24 INFO Uploading batch count=127512026/10/08 21:40:24 ERROR Upload failed error="upload failed" count=12752--- PASS: TestQueueFetchBatchLimit (0.08s)2753=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths2754--- PASS: TestQueueEnqueueAndFetch (0.08s)2755=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27562026/10/08 21:40:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3148070597/002/b27572026/10/08 21:40:24 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat891288431/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat891288431/002/locked/aaa: permission denied"2758--- PASS: TestQueueRetryMovesToBack (0.08s)27592026/10/08 21:40:24 INFO Uploading batch count=427602026/10/08 21:40:24 ERROR Upload failed error="upload failed" count=42761--- PASS: TestQueueRemove (0.08s)27622026/10/08 21:40:24 INFO Uploading batch count=127632026/10/08 21:40:24 ERROR Upload failed error="upload failed" count=127642026/10/08 21:40:24 ERROR Drain finished with paths left in queue remaining=127652026/10/08 21:40:24 INFO Uploading batch count=227662026/10/08 21:40:24 ERROR Upload failed error="upload failed" count=227672026/10/08 21:40:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3148070597/002/c27682026/10/08 21:40:24 INFO Uploading batch count=127692026/10/08 21:40:24 ERROR Upload failed error="upload failed" count=127702026/10/08 21:40:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3148070597/002/d27712026/10/08 21:40:24 ERROR Drain finished with paths left in queue remaining=12772--- PASS: TestWorkerKeepsPathItCannotStat (0.09s)27732026/10/08 21:40:24 INFO Uploading batch count=227742026/10/08 21:40:24 ERROR Upload failed error="upload failed" count=227752026/10/08 21:40:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3148070597/002/e2776--- PASS: TestWorkerPrunesClosureDeps (0.09s)2777--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.09s)2778--- PASS: TestFailedPathPrunedByLaterClosure (0.09s)27792026/10/08 21:40:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3148070597/002/f2780--- PASS: TestDrainIsolatesPoisonPath (0.09s)2781--- PASS: TestWorkerUploadsAndRemoves (0.09s)2782--- PASS: TestWorkerSkipsGCdPaths (0.10s)27832026/10/08 21:40:24 ERROR Drain finished with paths left in queue remaining=1027842026/10/08 21:40:24 INFO Uploading batch count=427852026/10/08 21:40:24 ERROR Upload failed error="upload failed" count=42786--- PASS: TestDrainGivesUpWhenServerDown (0.11s)27872026/10/08 21:40:24 INFO Uploading batch count=227882026/10/08 21:40:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227892026/10/08 21:40:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path4020212304/001/nonexistent27902026/10/08 21:40:24 INFO Uploading batch count=227912026/10/08 21:40:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227922026/10/08 21:40:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127932026/10/08 21:40:24 INFO Uploading batch count=227942026/10/08 21:40:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227952026/10/08 21:40:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path4020212304/001/nonexistent27962026/10/08 21:40:24 ERROR Drain finished with paths left in queue remaining=227972026/10/08 21:40:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127982026/10/08 21:40:24 INFO Uploading batch count=227992026/10/08 21:40:24 ERROR Upload failed error="upload failed" count=228002026/10/08 21:40:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128012026/10/08 21:40:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path4020212304/001/nonexistent28022026/10/08 21:40:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128032026/10/08 21:40:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128042026/10/08 21:40:24 ERROR Drain finished with paths left in queue remaining=128052026/10/08 21:40:24 INFO Uploading batch count=228062026/10/08 21:40:24 ERROR Upload failed error="upload failed" count=228072026/10/08 21:40:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128082026/10/08 21:40:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128092026/10/08 21:40:24 INFO Uploading batch count=228102026/10/08 21:40:24 ERROR Upload failed error="upload failed" count=228112026/10/08 21:40:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128122026/10/08 21:40:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128132026/10/08 21:40:24 ERROR Drain finished with paths left in queue remaining=22814--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2815 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.04s)2816 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.04s)2817 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.05s)28182026/10/08 21:40:24 ERROR Accept failed error="too many open files"28192026/10/08 21:40:24 ERROR Failed to decode request error="read unix /build/hook1186697443/test.sock->@: i/o timeout"28202026/10/08 21:40:24 ERROR Failed to write response error="write unix /build/hook1186697443/test.sock->@: i/o timeout"2821--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)28222026/10/08 21:40:24 ERROR Upload failed error="context canceled" count=228232026/10/08 21:40:24 ERROR Drain finished with paths left in queue remaining=42824--- PASS: TestDrainTimeout (0.26s)28252026/10/08 21:40:24 ERROR Upload failed error="context canceled" count=228262026/10/08 21:40:24 ERROR Drain finished with paths left in queue remaining=22827--- PASS: TestShutdownFinishesInFlightPush (0.00s)2828 --- PASS: TestShutdownFinishesInFlightPush/completes (0.18s)2829 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.27s)28302026/10/08 21:40:24 ERROR Drain finished with paths left in queue remaining=428312026/10/08 21:40:24 ERROR Accept failed error="too many open files"28322026/10/08 21:40:24 ERROR Drain finished with paths left in queue remaining=32833--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2834 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.23s)2835 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.38s)28362026/10/08 21:40:25 ERROR Accept failed error="too many open files"2837--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)2838--- PASS: TestQueueConcurrentWriters (0.74s)28392026/10/08 21:40:25 INFO Uploading batch count=128402026/10/08 21:40:25 INFO Uploading batch count=128412026/10/08 21:40:25 INFO Uploading batch count=128422026/10/08 21:40:25 ERROR Upload failed error="upload failed" count=128432026/10/08 21:40:25 INFO Uploading batch count=128442026/10/08 21:40:25 ERROR Upload failed error="upload failed" count=128452026/10/08 21:40:25 INFO Uploading batch count=128462026/10/08 21:40:25 ERROR Upload failed error="upload failed" count=128472026/10/08 21:40:25 INFO Uploading batch count=128482026/10/08 21:40:25 ERROR Upload failed error="upload failed" count=128492026/10/08 21:40:25 ERROR Drain finished with paths left in queue remaining=12850--- PASS: TestRunNotBlockedByPoisonHead (1.10s)2851--- PASS: TestQueueRemoveLargeClosure (1.55s)2852--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.08s)2853PASS2854Running signing tests...2855=== RUN TestExternalSigner2856=== PAUSE TestExternalSigner2857=== RUN TestExternalSignerWrongPublicKey2858=== PAUSE TestExternalSignerWrongPublicKey2859=== RUN TestExternalSignerErrors2860=== PAUSE TestExternalSignerErrors2861=== RUN TestExternalSignerRestartsAfterCrash2862=== PAUSE TestExternalSignerRestartsAfterCrash2863=== RUN TestExternalSignerProgramErrorKeepsProcess2864=== PAUSE TestExternalSignerProgramErrorKeepsProcess2865=== RUN TestExternalSignerClose2866=== PAUSE TestExternalSignerClose2867=== RUN TestExternalSignerRejectsInvalidPublicKey2868=== PAUSE TestExternalSignerRejectsInvalidPublicKey2869=== RUN TestExternalSignerCancellation2870=== PAUSE TestExternalSignerCancellation2871=== RUN TestGenerateFingerprint2872=== PAUSE TestGenerateFingerprint2873=== RUN TestParseSigningKey2874=== PAUSE TestParseSigningKey2875=== RUN TestSign2876=== PAUSE TestSign2877=== RUN TestSignBatch2878=== PAUSE TestSignBatch2879=== RUN TestNilKeyPublicKey2880=== PAUSE TestNilKeyPublicKey2881=== RUN TestSignErrors2882=== PAUSE TestSignErrors2883=== CONT TestExternalSigner2884=== CONT TestExternalSignerRejectsInvalidPublicKey2885=== RUN TestExternalSignerRejectsInvalidPublicKey/#002886=== CONT TestSign2887=== CONT TestSignErrors2888=== CONT TestSignBatch2889=== CONT TestParseSigningKey2890=== CONT TestExternalSignerRestartsAfterCrash2891=== CONT TestExternalSignerCancellation2892=== CONT TestExternalSignerProgramErrorKeepsProcess2893=== CONT TestExternalSignerWrongPublicKey2894=== RUN TestSignErrors/nil_key2895=== PAUSE TestSignErrors/nil_key2896=== RUN TestSignErrors/nil_narinfo2897=== PAUSE TestSignErrors/nil_narinfo2898=== RUN TestSignErrors/invalid_narinfo2899=== PAUSE TestSignErrors/invalid_narinfo2900=== RUN TestSignErrors/canceled2901=== PAUSE TestSignErrors/canceled2902=== CONT TestSignErrors/nil_narinfo2903=== CONT TestSignErrors/invalid_narinfo2904=== CONT TestExternalSignerErrors2905=== CONT TestSignErrors/nil_key2906=== CONT TestNilKeyPublicKey2907=== CONT TestExternalSignerClose2908=== CONT TestGenerateFingerprint2909=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002910=== RUN TestParseSigningKey/valid_32-byte_key2911=== CONT TestSignErrors/canceled2912=== PAUSE TestParseSigningKey/valid_32-byte_key2913--- PASS: TestSign (0.00s)2914=== RUN TestExternalSignerErrors/exit_on_request2915--- PASS: TestNilKeyPublicKey (0.00s)2916=== PAUSE TestExternalSignerErrors/exit_on_request2917=== RUN TestGenerateFingerprint/basic_with_references2918=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2919=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2920--- PASS: TestSignErrors (0.00s)2921 --- PASS: TestSignErrors/nil_narinfo (0.00s)2922 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2923 --- PASS: TestSignErrors/nil_key (0.00s)2924 --- PASS: TestSignErrors/canceled (0.00s)2925=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2926=== RUN TestExternalSignerErrors/null2927=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2928=== PAUSE TestExternalSignerErrors/null2929=== PAUSE TestGenerateFingerprint/basic_with_references2930=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2931=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2932=== RUN TestExternalSignerErrors/missing_signature_name2933=== RUN TestParseSigningKey/no_colon2934=== PAUSE TestExternalSignerErrors/missing_signature_name2935=== RUN TestGenerateFingerprint/no_references2936=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2937=== PAUSE TestParseSigningKey/no_colon2938=== RUN TestExternalSignerErrors/wrong_signature_name2939=== PAUSE TestExternalSignerErrors/wrong_signature_name2940=== PAUSE TestGenerateFingerprint/no_references2941=== RUN TestExternalSignerErrors/wrong_signature_length2942=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2943=== PAUSE TestExternalSignerErrors/wrong_signature_length2944=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2945--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2946=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2947=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2948=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2949=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2950=== RUN TestParseSigningKey/empty_name2951--- PASS: TestExternalSignerWrongPublicKey (0.01s)2952=== PAUSE TestParseSigningKey/empty_name2953=== RUN TestParseSigningKey/invalid_base642954=== RUN TestExternalSignerErrors/wrong_id2955=== RUN TestGenerateFingerprint/invalid_nar_hash_length2956=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2957=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2958=== PAUSE TestExternalSignerErrors/wrong_id2959=== RUN TestGenerateFingerprint/invalid_store_path_prefix2960=== RUN TestExternalSignerErrors/wrong_signatures_shape2961=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2962=== RUN TestGenerateFingerprint/invalid_reference_prefix2963--- PASS: TestSignBatch (0.01s)2964=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2965=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2966=== PAUSE TestParseSigningKey/invalid_base642967=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2968=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2969=== RUN TestExternalSignerErrors/unrequested_key2970=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2971=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2972=== CONT TestExternalSignerRejectsInvalidPublicKey/#002973=== CONT TestGenerateFingerprint/basic_with_references2974=== CONT TestGenerateFingerprint/invalid_reference_prefix2975--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.01s)2976 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2977 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2978 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2979 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2980 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2981=== CONT TestGenerateFingerprint/invalid_nar_hash_length2982=== CONT TestGenerateFingerprint/invalid_store_path_prefix2983=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2984=== CONT TestGenerateFingerprint/no_references2985=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2986=== RUN TestParseSigningKey/wrong_length2987=== PAUSE TestExternalSignerErrors/unrequested_key2988=== RUN TestExternalSignerErrors/invalid_signature_base642989--- PASS: TestGenerateFingerprint (0.00s)2990 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2991 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2992 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2993 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2994 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2995 --- PASS: TestGenerateFingerprint/no_references (0.00s)2996 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2997=== PAUSE TestParseSigningKey/wrong_length2998=== PAUSE TestExternalSignerErrors/invalid_signature_base642999--- PASS: TestExternalSignerClose (0.00s)3000=== CONT TestParseSigningKey/valid_32-byte_key3001=== CONT TestParseSigningKey/wrong_length3002=== CONT TestParseSigningKey/empty_name3003=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name3004=== CONT TestParseSigningKey/no_colon3005=== RUN TestExternalSignerErrors/program_error3006=== PAUSE TestExternalSignerErrors/program_error3007=== CONT TestParseSigningKey/invalid_base643008=== RUN TestExternalSignerErrors/wrong_shape3009=== PAUSE TestExternalSignerErrors/wrong_shape3010=== RUN TestExternalSignerErrors/missing_signatures3011--- PASS: TestParseSigningKey (0.01s)3012 --- PASS: TestParseSigningKey/wrong_length (0.00s)3013 --- PASS: TestParseSigningKey/empty_name (0.00s)3014 --- PASS: TestParseSigningKey/no_colon (0.00s)3015 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)3016 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)3017 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)3018=== PAUSE TestExternalSignerErrors/missing_signatures3019=== RUN TestExternalSignerErrors/null_signatures3020=== PAUSE TestExternalSignerErrors/null_signatures3021=== RUN TestExternalSignerErrors/too_few_signatures3022=== PAUSE TestExternalSignerErrors/too_few_signatures3023=== RUN TestExternalSignerErrors/exit_at_startup3024=== PAUSE TestExternalSignerErrors/exit_at_startup3025=== RUN TestExternalSignerErrors/invalid_JSON3026=== PAUSE TestExternalSignerErrors/invalid_JSON3027=== CONT TestExternalSignerErrors/missing_signature_name3028=== CONT TestExternalSignerErrors/missing_signatures3029=== CONT TestExternalSignerErrors/unrequested_key3030=== CONT TestExternalSignerErrors/program_error3031=== CONT TestExternalSignerErrors/wrong_id3032=== CONT TestExternalSignerErrors/exit_at_startup3033=== CONT TestExternalSignerErrors/wrong_signatures_shape3034=== CONT TestExternalSignerErrors/too_few_signatures3035=== CONT TestExternalSignerErrors/null3036=== CONT TestExternalSignerErrors/wrong_signature_length3037=== CONT TestExternalSignerErrors/wrong_signature_name3038=== CONT TestExternalSignerErrors/exit_on_request3039=== CONT TestExternalSignerErrors/wrong_shape3040=== CONT TestExternalSignerErrors/invalid_signature_base643041=== CONT TestExternalSignerErrors/null_signatures3042=== CONT TestExternalSignerErrors/invalid_JSON3043--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)3044--- PASS: TestExternalSigner (0.02s)3045--- PASS: TestExternalSignerErrors (0.01s)3046 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)3047 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)3048 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)3049 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)3050 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)3051 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)3052 --- PASS: TestExternalSignerErrors/program_error (0.01s)3053 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)3054 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)3055 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)3056 --- PASS: TestExternalSignerErrors/null (0.01s)3057 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)3058 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)3059 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)3060 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)3061 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)3062--- PASS: TestExternalSignerCancellation (0.02s)3063PASS3064Running OpenBao signer tests...3065=== RUN TestSign3066=== PAUSE TestSign3067=== RUN TestSignErrors3068=== PAUSE TestSignErrors3069=== RUN TestServe3070=== PAUSE TestServe3071=== RUN TestServeRejectsGarbage3072=== PAUSE TestServeRejectsGarbage3073=== CONT TestServe3074=== CONT TestSign3075=== CONT TestSignErrors3076=== CONT TestServeRejectsGarbage3077--- PASS: TestServe (0.00s)3078=== RUN TestSignErrors/no_prefix3079=== PAUSE TestSignErrors/no_prefix3080=== RUN TestSignErrors/invalid_base643081=== PAUSE TestSignErrors/invalid_base643082--- PASS: TestServeRejectsGarbage (0.00s)3083=== RUN TestSignErrors/http_error3084=== PAUSE TestSignErrors/http_error3085=== RUN TestSignErrors/invalid_json3086=== PAUSE TestSignErrors/invalid_json3087=== CONT TestSignErrors/invalid_json3088=== CONT TestSignErrors/no_prefix3089=== CONT TestSignErrors/invalid_base643090=== CONT TestSignErrors/http_error3091--- PASS: TestSign (0.01s)3092--- PASS: TestSignErrors (0.00s)3093 --- PASS: TestSignErrors/invalid_json (0.00s)3094 --- PASS: TestSignErrors/invalid_base64 (0.00s)3095 --- PASS: TestSignErrors/http_error (0.00s)3096 --- PASS: TestSignErrors/no_prefix (0.01s)3097PASS3098Running niks3-hook command tests...3099=== RUN TestServeSecondSignalEndsDrain3100=== PAUSE TestServeSecondSignalEndsDrain3101=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown3102=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown3103=== CONT TestServeSecondSignalEndsDrain3104=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown3105--- PASS: TestServeSecondSignalEndsDrain (0.08s)31062026/10/08 21:40:33 INFO Upload queue status pending=131072026/10/08 21:40:33 INFO Uploading batch count=13108--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.13s)3109PASS3110Running rate limiter tests...3111=== RUN TestAdaptiveRateLimiter_ThreadSafety3112=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3113=== CONT TestAdaptiveRateLimiter_ThreadSafety31142026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=7031152026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=4931162026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=34.331172026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=24.00999999999999831182026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=16.80731192026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=11.76489999999999931202026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=8.2354331212026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=5.76480099999999931222026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531232026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531242026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531252026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531262026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531272026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531282026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531292026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531302026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531312026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531322026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531332026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531342026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531352026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531362026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531372026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531382026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531392026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531402026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531412026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531422026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531432026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531442026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531452026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531462026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531472026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531482026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531492026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531502026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531512026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=6.200463500000001531522026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531532026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531542026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531552026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531562026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531572026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531582026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531592026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=7.50256083500000331602026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=5.25179258450000231612026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531622026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531632026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531642026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531652026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531662026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531672026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531682026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531692026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531702026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531712026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531722026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531732026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531742026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531752026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531762026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531772026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531782026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531792026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531802026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531812026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531822026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531832026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=5.12435000000000131842026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531852026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531862026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531872026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531882026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531892026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=7.50256083500000331902026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=5.25179258450000231912026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531922026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531932026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531942026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531952026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531962026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=5.12435000000000131972026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=5.25179258450000231982026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=531992026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=532002026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=532012026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=532022026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=532032026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=532042026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=532052026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=532062026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=532072026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=532082026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=532092026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=532102026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=532112026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=532122026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=532132026/10/08 21:40:34 WARN Rate limiter backed off name=test rate=53214--- PASS: TestAdaptiveRateLimiter_ThreadSafety (0.10s)3215PASS