niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #444
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure18=== PAUSE TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure19=== RUN TestUploadMultipart_PartsInParallel20=== PAUSE TestUploadMultipart_PartsInParallel21=== RUN TestUploadMultipart_FailedPartBufferNotReused22=== PAUSE TestUploadMultipart_FailedPartBufferNotReused23=== RUN TestUploadMultipart_ProducerErrorIsNotEOF24=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestUploadMultipart_SupersededByPeer28=== PAUSE TestUploadMultipart_SupersededByPeer29=== RUN TestDumpPathCaseHackMatchesNix30--- PASS: TestDumpPathCaseHackMatchesNix (0.06s)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.66s)46=== RUN TestEncodeNixBase3247=== PAUSE TestEncodeNixBase3248=== RUN TestEncodeNixBase32WithRealHash49=== PAUSE TestEncodeNixBase32WithRealHash50=== RUN TestConvertHashToNix3251=== PAUSE TestConvertHashToNix3252=== RUN TestGetStorePathHash53=== PAUSE TestGetStorePathHash54=== RUN TestPathInfoHashCompatibility55=== PAUSE TestPathInfoHashCompatibility56=== RUN TestParsePathInfoJSON57=== PAUSE TestParsePathInfoJSON58=== RUN TestParsePathInfoJSONMultiplePaths59=== PAUSE TestParsePathInfoJSONMultiplePaths60=== RUN TestPathInfoCACompatibility61=== PAUSE TestPathInfoCACompatibility62=== RUN TestUploadPendingObjectsStopsStartingAfterFailure63--- PASS: TestUploadPendingObjectsStopsStartingAfterFailure (0.02s)64=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent65=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent66=== RUN TestCompletePendingClosure_NotFoundWithoutKey67=== PAUSE TestCompletePendingClosure_NotFoundWithoutKey68=== RUN TestRateLimiterFeedback69=== PAUSE TestRateLimiterFeedback70=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess71=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess72=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer73=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer74=== RUN TestResolveStorePath75=== PAUSE TestResolveStorePath76=== RUN TestDoWithRetry_BodyReplayedViaGetBody77=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody78=== RUN TestRetryTimeoutOutlastsMaxRetries79=== PAUSE TestRetryTimeoutOutlastsMaxRetries80=== RUN TestDoWithRetry_FinalResponseBodyReadable81=== PAUSE TestDoWithRetry_FinalResponseBodyReadable82=== RUN TestShellSplit83=== PAUSE TestShellSplit84=== RUN TestShellSplitErrors85=== PAUSE TestShellSplitErrors86=== RUN TestStreamPushReportsEveryPath87=== PAUSE TestStreamPushReportsEveryPath88=== RUN TestStreamPushBatchesUnderLoad89=== PAUSE TestStreamPushBatchesUnderLoad90=== RUN TestStreamPushIsolatesFailures91=== PAUSE TestStreamPushIsolatesFailures92=== RUN TestStreamPushGivesUpOnDeadServer93=== PAUSE TestStreamPushGivesUpOnDeadServer94=== RUN TestStreamPushRequestLine95=== PAUSE TestStreamPushRequestLine96=== RUN TestStreamPushReportsSignatures97=== PAUSE TestStreamPushReportsSignatures98=== RUN TestStreamPushReportsSkippedPaths99=== PAUSE TestStreamPushReportsSkippedPaths100=== RUN TestClientSignaturesByStorePath101=== PAUSE TestClientSignaturesByStorePath102=== RUN TestStreamPushStopsWhenCanceled103=== PAUSE TestStreamPushStopsWhenCanceled104=== RUN TestStreamPushStopsOnCancel105=== PAUSE TestStreamPushStopsOnCancel106=== RUN TestStreamPushStartsNothingOnSlotFreedByCancel107=== PAUSE TestStreamPushStartsNothingOnSlotFreedByCancel108=== RUN TestSetClientTLS109=== PAUSE TestSetClientTLS110=== RUN TestSetClientTLSDoesNotMutateDefaultTransport111=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport112=== RUN TestSetClientTLSErrors113=== PAUSE TestSetClientTLSErrors114=== RUN TestStaticToken115=== PAUSE TestStaticToken116=== RUN TestFileTokenReadsAndCaches117=== PAUSE TestFileTokenReadsAndCaches118=== RUN TestFileTokenMissing119=== PAUSE TestFileTokenMissing120=== RUN TestFileTokenEmpty121=== PAUSE TestFileTokenEmpty122=== RUN TestScriptTokenNoExpiryRerunsEveryCall123=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall124=== RUN TestScriptTokenCachesUntilRefresh125=== PAUSE TestScriptTokenCachesUntilRefresh126=== RUN TestScriptTokenEmptyToken127=== PAUSE TestScriptTokenEmptyToken128=== RUN TestScriptTokenBadJSON129=== PAUSE TestScriptTokenBadJSON130=== RUN TestScriptTokenScriptFails131=== PAUSE TestScriptTokenScriptFails132=== RUN TestScriptTokenEmptyCommand133=== PAUSE TestScriptTokenEmptyCommand134=== RUN TestScriptTokenDoesNotWaitForItsChildren135=== PAUSE TestScriptTokenDoesNotWaitForItsChildren136=== CONT TestSetClientTLS137=== CONT TestRetryTimeoutOutlastsMaxRetries138=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure139=== CONT TestUploadMultipart_PartsInParallel140=== CONT TestPathInfoHashCompatibility141=== CONT TestParsePathInfoJSONMultiplePaths142=== CONT TestPathInfoCACompatibility143=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)144=== CONT TestStreamPushStartsNothingOnSlotFreedByCancel145=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths146=== CONT TestParsePathInfoJSON147=== RUN TestParsePathInfoJSON/Nix_format148=== CONT TestStreamPushStopsOnCancel149=== RUN TestStreamPushStopsOnCancel/waiting_for_input150=== CONT TestUploadMultipart_ProducerErrorIsNotEOF151=== CONT TestSetClientTLSDoesNotMutateDefaultTransport152=== CONT TestPartSizeForNAR153=== CONT TestGetStorePathHash154=== CONT TestStreamPushStopsWhenCanceled155=== CONT TestFilterOversizedClosures156=== CONT TestClientSignaturesByStorePath157=== CONT TestEncodeNixBase32158=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun159=== CONT TestDumpPathSingleFile160=== CONT TestRegisterUploadedObjectReusesConnections161=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica162--- PASS: TestClientSignaturesByStorePath (0.00s)163=== CONT TestDoServerRequestAttachesToken164=== RUN TestPathInfoCACompatibility/null_ca_field165=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)166=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon167=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon168=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI169=== PAUSE TestPathInfoCACompatibility/null_ca_field170=== RUN TestPathInfoCACompatibility/old_string_format_-_text171=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text172=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive173=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths174=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI175=== PAUSE TestParsePathInfoJSON/Nix_format176=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part177=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input178=== RUN TestGetStorePathHash/valid_store_path179=== RUN TestPartSizeForNAR/zero_stays_at_minimum180=== RUN TestFilterOversizedClosures/no_limit_keeps_everything181=== RUN TestEncodeNixBase32/test_string_hash182=== CONT TestDumpPathWriterError183=== CONT TestShellSplitErrors184=== CONT TestRateLimiterFeedback185--- PASS: TestStreamPushStopsWhenCanceled (0.00s)186=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths187=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive188=== RUN TestParsePathInfoJSON/Lix_format189=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512190=== PAUSE TestGetStorePathHash/valid_store_path191=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part192=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot193=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum194=== CONT TestScriptTokenEmptyCommand195=== CONT TestShellSplit196=== PAUSE TestEncodeNixBase32/test_string_hash197=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything198=== RUN TestRateLimiterFeedback/429_enables_limiter199=== RUN TestSetClientTLS/rejects_connection_without_client_cert200=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths201--- PASS: TestDoServerRequestAttachesToken (0.00s)202=== RUN TestPathInfoCACompatibility/new_structured_format_-_text203=== PAUSE TestParsePathInfoJSON/Lix_format204=== RUN TestGetStorePathHash/basename_without_hyphen_should_error205=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512206=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot207=== RUN TestPartSizeForNAR/small_stays_at_minimum208=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary209=== CONT TestFileTokenEmpty210=== RUN TestEncodeNixBase32/empty_input211=== CONT TestResolveStorePath212=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry213=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error214=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot215=== CONT TestScriptTokenCachesUntilRefresh216=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error217=== PAUSE TestPartSizeForNAR/small_stays_at_minimum218=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum219=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot220=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum221=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot222=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error223=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary224=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot225=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts226=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts227=== RUN TestPartSizeForNAR/1_TiB228=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot229=== PAUSE TestEncodeNixBase32/empty_input230=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot231=== CONT TestStreamPushRequestLine232=== PAUSE TestPartSizeForNAR/1_TiB233=== CONT TestScriptTokenBadJSON234=== RUN TestPartSizeForNAR/5_TiB_S3_max_object235=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object236=== RUN TestPartSizeForNAR/capped_at_5_GiB237=== CONT TestCaseHackSuffix238=== PAUSE TestPartSizeForNAR/capped_at_5_GiB239=== CONT TestStreamPushReportsSkippedPaths240=== CONT TestSupersededNARStillUploadsListing241=== RUN TestSupersededNARStillUploadsListing/small_NAR242=== PAUSE TestSupersededNARStillUploadsListing/small_NAR243--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)244=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text245=== RUN TestParsePathInfoJSON/empty_input246=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer247=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped248=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error249=== CONT TestStreamPushReportsEveryPath250=== CONT TestScriptTokenNoExpiryRerunsEveryCall251=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken252=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert253=== CONT TestUploadMultipart_FailedPartBufferNotReused254=== RUN TestSupersededNARStillUploadsListing/dump_cut_short255--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)256=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short257=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method258=== PAUSE TestParsePathInfoJSON/empty_input259=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped260=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken261=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA262=== RUN TestParsePathInfoJSON/whitespace_only263=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA264=== PAUSE TestParsePathInfoJSON/whitespace_only265--- PASS: TestScriptTokenEmptyCommand (0.00s)266=== RUN TestParsePathInfoJSON/invalid_JSON267=== PAUSE TestRateLimiterFeedback/429_enables_limiter268=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method269=== CONT TestDoWithRetry_FinalResponseBodyReadable270=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails271=== RUN TestSetClientTLS/preserves_debug_logging_transport272=== PAUSE TestSetClientTLS/preserves_debug_logging_transport273=== CONT TestConvertHashToNix32274=== RUN TestConvertHashToNix32/SRI_format_to_Nix32275=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails276=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error277--- PASS: TestShellSplitErrors (0.00s)278=== CONT TestEncodeNixBase32WithRealHash279=== CONT TestTruncatedNARDumpIsNotCompleted280=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32281=== PAUSE TestParsePathInfoJSON/invalid_JSON282=== CONT TestStreamPushBatchesUnderLoad283=== CONT TestStreamPushGivesUpOnDeadServer284=== RUN TestFilterOversizedClosures/all_closures_skipped285=== RUN TestRateLimiterFeedback/503_enables_limiter286=== CONT TestDumpPathMatchesNix287=== CONT TestUploadMultipart_SupersededByPeer288--- PASS: TestShellSplit (0.00s)289=== PAUSE TestRateLimiterFeedback/503_enables_limiter290--- PASS: TestFileTokenEmpty (0.00s)291--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)292=== RUN TestUploadMultipart_SupersededByPeer/exists293=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter294=== PAUSE TestUploadMultipart_SupersededByPeer/exists295=== RUN TestConvertHashToNix32/already_Nix32_format296=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false297=== RUN TestUploadMultipart_SupersededByPeer/missing298=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter299=== PAUSE TestFilterOversizedClosures/all_closures_skipped300=== CONT TestScriptTokenDoesNotWaitForItsChildren301--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)302=== CONT TestScriptTokenScriptFails303--- PASS: TestResolveStorePath (0.00s)304--- PASS: TestStreamPushReportsSkippedPaths (0.00s)305--- PASS: TestScriptTokenBadJSON (0.00s)306--- PASS: TestStreamPushReportsEveryPath (0.01s)307--- PASS: TestEncodeNixBase32WithRealHash (0.00s)308=== PAUSE TestUploadMultipart_SupersededByPeer/missing309=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false310=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess311=== PAUSE TestConvertHashToNix32/already_Nix32_format312=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter313=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true314=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter315=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true316=== CONT TestFileTokenMissing317=== CONT TestDoWithRetry_BodyReplayedViaGetBody318=== CONT TestCompletePendingClosure_NotFoundWithoutKey319=== CONT TestScriptTokenEmptyToken320=== CONT TestStreamPushReportsSignatures321=== RUN TestConvertHashToNix32/invalid_format322=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs323--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)324=== CONT TestSetClientTLSErrors325=== CONT TestStreamPushIsolatesFailures326--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.02s)327=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent328=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs329=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout330=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier331=== CONT TestStaticToken332=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier333=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout334=== RUN TestSetClientTLSErrors/missing_cert_file335=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up336=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths337=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up338=== PAUSE TestConvertHashToNix32/invalid_format339=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI340=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512341=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths342=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon343=== CONT TestFileTokenReadsAndCaches344=== PAUSE TestSetClientTLSErrors/missing_cert_file345--- PASS: TestScriptTokenScriptFails (0.00s)346=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)347=== CONT TestEncodeNixBase32/test_string_hash348=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part349=== CONT TestPartSizeForNAR/zero_stays_at_minimum350=== CONT TestPartSizeForNAR/capped_at_5_GiB351=== CONT TestPartSizeForNAR/1_TiB352=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum353=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts354=== CONT TestPartSizeForNAR/small_stays_at_minimum355=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot356=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken357=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier358=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot359=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier360=== RUN TestSetClientTLSErrors/missing_key_file361=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot362=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot363--- PASS: TestFileTokenMissing (0.00s)364=== CONT TestEncodeNixBase32/empty_input365--- PASS: TestDumpPathSingleFile (0.03s)366--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)367=== CONT TestStreamPushStopsOnCancel/waiting_for_input368=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary369=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client370=== PAUSE TestSetClientTLSErrors/missing_key_file371=== CONT TestPartSizeForNAR/5_TiB_S3_max_object372--- PASS: TestStreamPushReportsSignatures (0.00s)373--- PASS: TestStreamPushIsolatesFailures (0.00s)374--- PASS: TestStaticToken (0.00s)375--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.00s)376=== RUN TestSetClientTLSErrors/missing_ca_file377=== CONT TestPathInfoCACompatibility/old_string_format_-_text378=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client379=== PAUSE TestSetClientTLSErrors/missing_ca_file380--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)381--- PASS: TestScriptTokenEmptyToken (0.00s)382=== RUN TestSetClientTLSErrors/invalid_ca_file383=== PAUSE TestSetClientTLSErrors/invalid_ca_file384=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive385--- PASS: TestEncodeNixBase32 (0.02s)386 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)387 --- PASS: TestEncodeNixBase32/empty_input (0.00s)388=== CONT TestPathInfoCACompatibility/null_ca_field389--- PASS: TestFileTokenReadsAndCaches (0.00s)390=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method391=== CONT TestSetClientTLS/preserves_debug_logging_transport392--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)393=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA394=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails395=== CONT TestSupersededNARStillUploadsListing/dump_cut_short396=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client397=== CONT TestPathInfoCACompatibility/new_structured_format_-_text398=== CONT TestSupersededNARStillUploadsListing/small_NAR399=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error400=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client401=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error402--- PASS: TestPathInfoHashCompatibility (0.01s)403 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)404 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)405 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)406 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)407--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)408 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)409 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)410=== CONT TestGetStorePathHash/valid_store_path411=== CONT TestParsePathInfoJSON/empty_input412=== CONT TestParsePathInfoJSON/invalid_JSON413=== CONT TestSetClientTLS/rejects_connection_without_client_cert414--- PASS: TestCaseHackSuffix (0.25s)415=== CONT TestGetStorePathHash/basename_without_hyphen_should_error416=== CONT TestParsePathInfoJSON/Lix_format417=== CONT TestParsePathInfoJSON/whitespace_only418=== CONT TestFilterOversizedClosures/all_closures_skipped419=== CONT TestFilterOversizedClosures/no_limit_keeps_everything420--- PASS: TestPartSizeForNAR (0.02s)421 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)422 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)423 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)424 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)425 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)426 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)427 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)428=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped429--- PASS: TestPathInfoCACompatibility (0.02s)430 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)431 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)432 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)433 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)434 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)435=== CONT TestParsePathInfoJSON/Nix_format436=== CONT TestUploadMultipart_SupersededByPeer/exists437=== CONT TestRateLimiterFeedback/429_enables_limiter438=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter439=== CONT TestUploadMultipart_SupersededByPeer/missing440--- PASS: TestStreamPushStopsOnCancel (0.02s)441 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.23s)442 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.23s)443 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.23s)444 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.23s)445 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.23s)446 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.23s)447--- PASS: TestGetStorePathHash (0.03s)448 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)449 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)450 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)451 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)452--- PASS: TestFilterOversizedClosures (0.03s)453 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)454 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)455 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)456--- PASS: TestParsePathInfoJSON (0.03s)457 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)458 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)459 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)460 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)461 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)462=== CONT TestRateLimiterFeedback/503_enables_limiter463=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter464=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true465--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)466 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)467 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)468=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false469=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs470--- PASS: TestStreamPushBatchesUnderLoad (0.00s)471 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)472 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)473=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout474=== CONT TestConvertHashToNix32/SRI_format_to_Nix32475=== CONT TestConvertHashToNix32/invalid_format476--- PASS: TestRateLimiterFeedback (0.02s)477 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)478 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)479 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)480 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)481=== CONT TestConvertHashToNix32/already_Nix32_format482=== CONT TestSetClientTLSErrors/invalid_ca_file483--- PASS: TestConvertHashToNix32 (0.01s)484 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)485 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)486 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)487=== CONT TestSetClientTLSErrors/missing_ca_file488=== CONT TestSetClientTLSErrors/missing_key_file489=== CONT TestSetClientTLSErrors/missing_cert_file490=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier491=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier492--- PASS: TestSetClientTLSErrors (0.23s)493 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)494 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)495 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)496 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)497=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client498=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up499--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.28s)500=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client501--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.23s)502 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.00s)503 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.00s)504 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.00s)505 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.00s)506 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.00s)507--- PASS: TestDumpPathWriterError (0.30s)508--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.31s)509--- PASS: TestStreamPushStartsNothingOnSlotFreedByCancel (0.56s)510--- PASS: TestSetClientTLS (0.03s)511 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)512 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)513 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.30s)514--- PASS: TestRegisterUploadedObjectReusesConnections (0.64s)515--- PASS: TestDumpPathMatchesNix (0.63s)516--- PASS: TestStreamPushRequestLine (0.64s)517--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.01s)518 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.55s)519 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.63s)520--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)521--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)522--- PASS: TestTruncatedNARDumpIsNotCompleted (1.28s)523--- PASS: TestUploadMultipart_PartsInParallel (1.40s)524--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.39s)525--- PASS: TestSupersededNARStillUploadsListing (0.01s)526 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.02s)527 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.02s)528 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.27s)529--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.01s)530 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.01s)531 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.26s)532PASS533Running server tests...534The files belonging to this database system will be owned by user "nixbld".535This user must also own the server process.536537The database cluster will be initialized with locale "C".538The default database encoding has accordingly been set to "SQL_ASCII".539The default text search configuration will be set to "english".540541Data page checksums are enabled.542543creating directory /build/postgres1739901770/data ... ok544creating subdirectories ... ok545selecting dynamic shared memory implementation ... posix546selecting default "max_connections" ... 100547selecting default "shared_buffers" ... 128MB548selecting default time zone ... UTC549creating configuration files ... ok550running bootstrap script ... ok551performing post-bootstrap initialization ... ok552syncing data to disk ... ok553554initdb: warning: enabling "trust" authentication for local connections555initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.556557Success. You can now start the database server using:558559 pg_ctl -D /build/postgres1739901770/data -l logfile start560561/build/postgres1739901770:5432 - no response5622026-10-27 13:03:56.011 UTC [172] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5632026-10-27 13:03:56.011 UTC [172] LOG: listening on Unix socket "/build/postgres1739901770/.s.PGSQL.5432"5642026-10-27 13:03:56.016 UTC [179] LOG: database system was shut down at 2026-10-27 13:03:55 UTC5652026-10-27 13:03:56.019 UTC [172] LOG: database system is ready to accept connections566/build/postgres1739901770:5432 - accepting connections567{"timestamp":"2026-10-27T13:03:56.323031603Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"9e0e34b3-caea-4fa4-b461-9c0b787621a6","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":3,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(209)"}568=== RUN TestService_AuthMiddleware569=== PAUSE TestService_AuthMiddleware570=== RUN TestService_AuthMiddleware_MTLSProxyHeader571=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader572=== RUN TestService_AuthMiddleware_MTLSBoundSubjects573=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects574=== RUN TestService_ReadAuthMiddleware575=== PAUSE TestService_ReadAuthMiddleware576=== RUN TestService_AuthMiddleware_OIDC577=== PAUSE TestService_AuthMiddleware_OIDC578=== RUN TestService_RequireScope_OIDC579=== PAUSE TestService_RequireScope_OIDC580=== RUN TestService_ReadScope_PublicByDefault581=== PAUSE TestService_ReadScope_PublicByDefault582=== RUN TestCacheConfigHandler583=== PAUSE TestCacheConfigHandler584=== RUN TestCacheStatsHandler585=== PAUSE TestCacheStatsHandler586=== RUN TestClientCADerivations587=== PAUSE TestClientCADerivations588=== RUN TestClientErrorHandling589=== PAUSE TestClientErrorHandling590=== RUN TestClientIntegration591=== PAUSE TestClientIntegration592=== RUN TestClientMultipleUploads593=== PAUSE TestClientMultipleUploads594=== RUN TestClientWithDependencies595=== PAUSE TestClientWithDependencies596=== RUN TestClientSharedPathCommittedMidPush597=== PAUSE TestClientSharedPathCommittedMidPush598=== RUN TestPinProtectsFromGC599=== PAUSE TestPinProtectsFromGC600=== RUN TestClientPushesUseOnePush601=== PAUSE TestClientPushesUseOnePush602=== RUN TestClientFallsBackToClosures603=== PAUSE TestClientFallsBackToClosures604=== RUN TestDeleteClosuresRacingPins605=== PAUSE TestDeleteClosuresRacingPins606=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock607=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock608=== RUN TestResolveDBConnectionString609=== PAUSE TestResolveDBConnectionString610=== RUN TestConnectWaitsForAPeerMigration611=== PAUSE TestConnectWaitsForAPeerMigration612=== RUN TestConnectSerialisesConcurrentMigrations613=== PAUSE TestConnectSerialisesConcurrentMigrations614=== RUN TestLeadElectsOneAndHandsOver615=== PAUSE TestLeadElectsOneAndHandsOver616=== RUN TestLeadIncumbentWinsAfterRestart6172026/10/27 13:03:56 INFO lead: acquired remote=192.0.2.1:12346182026/10/27 13:03:57 INFO lead: released remote=192.0.2.1:12346192026/10/27 13:03:57 INFO lead: acquired remote=192.0.2.1:12346202026/10/27 13:03:58 INFO lead: released remote=192.0.2.1:1234621--- PASS: TestLeadIncumbentWinsAfterRestart (1.89s)622=== RUN TestLeadIncumbentAnnouncesAtOnce623=== PAUSE TestLeadIncumbentAnnouncesAtOnce624=== RUN TestLeadEndsOnShutdown625=== PAUSE TestLeadEndsOnShutdown626=== RUN TestLeadEndsWhenItsConnectionHangs6272026/10/27 13:03:58 INFO lead: acquired remote=192.0.2.1:12346282026-10-27 13:03:59.851 UTC [428] FATAL: terminating connection due to administrator command6292026/10/27 13:04:00 INFO lead: acquired remote=192.0.2.1:12346302026/10/27 13:04:01 WARN lead: lock connection lost error="timeout: context deadline exceeded"6312026/10/27 13:04:01 INFO lead: released remote=192.0.2.1:12346322026/10/27 13:04:01 INFO lead: released remote=192.0.2.1:1234633--- PASS: TestLeadEndsWhenItsConnectionHangs (3.15s)634=== RUN TestGCAdvisoryLockBlocksConcurrentRun635=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun636=== RUN TestGCBugBareHashReferences637=== PAUSE TestGCBugBareHashReferences638=== RUN TestGCMetrics639=== PAUSE TestGCMetrics640=== RUN TestPushDedupSurvivesConcurrentGC641=== PAUSE TestPushDedupSurvivesConcurrentGC642=== RUN TestDeduplicatedObjectsRecordedAsPending643=== PAUSE TestDeduplicatedObjectsRecordedAsPending644=== RUN TestGCSweepSkipsPendingObjects645=== PAUSE TestGCSweepSkipsPendingObjects646=== RUN TestTombstonedObjectOfferedWithoutWaiting647=== PAUSE TestTombstonedObjectOfferedWithoutWaiting648=== RUN TestGCSweepDeliversEachKeyOnce649=== PAUSE TestGCSweepDeliversEachKeyOnce650=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection651=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection652=== RUN TestForceGCDuringPushOffersSweptObject653=== PAUSE TestForceGCDuringPushOffersSweptObject654=== RUN TestFailedS3DeleteKeepsTombstone655=== PAUSE TestFailedS3DeleteKeepsTombstone656=== RUN TestSweepSkipsRowsLockedByPush657=== PAUSE TestSweepSkipsRowsLockedByPush658=== RUN TestRegisterCompletedObjectNeedsPendingRow659=== PAUSE TestRegisterCompletedObjectNeedsPendingRow660=== RUN TestGetExistingObjectsLocksRows661=== PAUSE TestGetExistingObjectsLocksRows662=== RUN TestSweepRechecksPendingAfterLocking663=== PAUSE TestSweepRechecksPendingAfterLocking664=== RUN TestPushWaitsForSweepHoldingRow665=== PAUSE TestPushWaitsForSweepHoldingRow666=== RUN TestCommitRacingPendingCleanupKeepsObjects667=== PAUSE TestCommitRacingPendingCleanupKeepsObjects668=== RUN TestGCEndsOnShutdown669=== PAUSE TestGCEndsOnShutdown670=== RUN TestGCTaskStore_StartNew671=== PAUSE TestGCTaskStore_StartNew672=== RUN TestGCTaskStore_DeduplicateSameParams673=== PAUSE TestGCTaskStore_DeduplicateSameParams674=== RUN TestGCTaskStore_ConflictDifferentParams675=== PAUSE TestGCTaskStore_ConflictDifferentParams676=== RUN TestGCTaskStore_GetEmpty677=== PAUSE TestGCTaskStore_GetEmpty678=== RUN TestGCTaskStore_GetReturnsLatest679=== PAUSE TestGCTaskStore_GetReturnsLatest680=== RUN TestGCTaskStore_CompletedAllowsNewTask681=== PAUSE TestGCTaskStore_CompletedAllowsNewTask682=== RUN TestGCTaskStore_PhaseUpdates683=== PAUSE TestGCTaskStore_PhaseUpdates684=== RUN TestGCTaskStore_Fail685=== PAUSE TestGCTaskStore_Fail686=== RUN TestGracefulShutdownDrainsInflight687=== PAUSE TestGracefulShutdownDrainsInflight688=== RUN TestService_healthCheckHandler689=== PAUSE TestService_healthCheckHandler690=== RUN TestService_readinessHandler691=== PAUSE TestService_readinessHandler692=== RUN TestGenerateLandingPage693=== PAUSE TestGenerateLandingPage694=== RUN TestChildrenInheritRaisedFileLimit695=== PAUSE TestChildrenInheritRaisedFileLimit696=== RUN TestCacheConfigHandlerMaxNarSize697=== PAUSE TestCacheConfigHandlerMaxNarSize698=== RUN TestCreatePendingClosureRejectsOversizedNAR699=== PAUSE TestCreatePendingClosureRejectsOversizedNAR700=== RUN TestNARDeduplicationMetadataUploadBug701=== PAUSE TestNARDeduplicationMetadataUploadBug702=== RUN TestMetricsInventory703=== PAUSE TestMetricsInventory704=== RUN TestMetricsCommit705=== PAUSE TestMetricsCommit706=== RUN TestService_NativeMTLS707=== PAUSE TestService_NativeMTLS708=== RUN TestServerTLSConfig709=== PAUSE TestServerTLSConfig710=== RUN TestMultipartCleanup711=== PAUSE TestMultipartCleanup712=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded713=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded714=== RUN TestPendingCleanupUsesOneCutoff715=== PAUSE TestPendingCleanupUsesOneCutoff716=== RUN TestPendingClosureFailureTracksEveryUpload717=== PAUSE TestPendingClosureFailureTracksEveryUpload718=== RUN TestPendingClosureFailureAbortsItsUploads719=== PAUSE TestPendingClosureFailureAbortsItsUploads720=== RUN TestObjectStatsTrigger721=== PAUSE TestObjectStatsTrigger722=== RUN TestObjectStatsUpdatedOncePerCommit723=== PAUSE TestObjectStatsUpdatedOncePerCommit724=== RUN TestReconnectLeavesObjectsUnlocked725=== PAUSE TestReconnectLeavesObjectsUnlocked726=== RUN TestOrphanedObjectsGC727=== PAUSE TestOrphanedObjectsGC728=== RUN TestOrphanedObjectsGCStressTest729=== PAUSE TestOrphanedObjectsGCStressTest730=== RUN TestCreatePin_ReservedPins731=== PAUSE TestCreatePin_ReservedPins732=== RUN TestConcurrentPinUpdatesAgree733=== PAUSE TestConcurrentPinUpdatesAgree734=== RUN TestCreatePinRejectsBadInput735=== PAUSE TestCreatePinRejectsBadInput736=== RUN TestDeletePinKeepsRowWhenS3Fails737=== PAUSE TestDeletePinKeepsRowWhenS3Fails738=== RUN TestPresentReportsOnlyClosureRoots739=== PAUSE TestPresentReportsOnlyClosureRoots740=== RUN TestPresentRefreshesOnlyStaleClosures741=== PAUSE TestPresentRefreshesOnlyStaleClosures742=== RUN TestPresentNotReportedWhileGCDeletesClosure743=== PAUSE TestPresentNotReportedWhileGCDeletesClosure744=== RUN TestParseSingleRange745=== PAUSE TestParseSingleRange746=== RUN TestProxyHeadersOnlyTrustedOnSocket7472026/10/27 13:04:01 INFO Starting HTTP server address=127.0.0.1:328177482026/10/27 13:04:01 INFO Starting HTTP server address=proxy.sock7492026/10/27 13:04:01 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7502026/10/27 13:04:01 INFO Shutdown signal received, draining in-flight requests timeout=10s751--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.14s)752=== RUN TestIsValidCachePath753=== PAUSE TestIsValidCachePath754=== RUN TestReadProxyNarinfo755=== PAUSE TestReadProxyNarinfo756=== RUN TestReadProxyNarinfoAlreadyDecompressed757=== PAUSE TestReadProxyNarinfoAlreadyDecompressed758=== RUN TestReadProxyContentNegotiation759=== PAUSE TestReadProxyContentNegotiation760=== RUN TestReadProxyNarStreaming761=== PAUSE TestReadProxyNarStreaming762=== RUN TestReadProxy404And429763=== PAUSE TestReadProxy404And429764=== RUN TestReadProxyInvalidPath765=== PAUSE TestReadProxyInvalidPath766=== RUN TestReadProxyHead767=== PAUSE TestReadProxyHead768=== RUN TestReadProxyOutlastsServerWriteTimeout769=== PAUSE TestReadProxyOutlastsServerWriteTimeout770=== RUN TestReadProxyConditionalGet771=== PAUSE TestReadProxyConditionalGet772=== RUN TestReadProxyRootRedirectsToIndexHTML773=== PAUSE TestReadProxyRootRedirectsToIndexHTML774=== RUN TestReadProxyDisabled775=== PAUSE TestReadProxyDisabled776=== RUN TestReadRedirectNar777=== PAUSE TestReadRedirectNar778=== RUN TestReadRedirectKeepsNarinfoProxied779=== PAUSE TestReadRedirectKeepsNarinfoProxied780=== RUN TestReadProxyRangeRequest781=== PAUSE TestReadProxyRangeRequest782=== RUN TestReadRedirectUsesPublicS3URL783=== PAUSE TestReadRedirectUsesPublicS3URL784=== RUN TestPush_OverlappingRootsStoreOneRowPerKey785=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey786=== RUN TestPush_CompleteCommitsEveryRoot787=== PAUSE TestPush_CompleteCommitsEveryRoot788=== RUN TestPush_RepeatedRootCommitsOnce789=== PAUSE TestPush_RepeatedRootCommitsOnce790=== RUN TestPush_CompleteWaitsForCleanupOfThePush791=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush792=== RUN TestPush_RootsAreLockedInByteOrder793=== PAUSE TestPush_RootsAreLockedInByteOrder794=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit795=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit796=== RUN TestPush_RejectsBadRequests797=== PAUSE TestPush_RejectsBadRequests798=== RUN TestPush_SignsNarinfosOfItsPendingObjects799=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects800=== RUN TestRedundantMultipartUpload801=== PAUSE TestRedundantMultipartUpload802=== RUN TestCompleteMultipartUpload_ErrorButObjectExists803=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists804=== RUN TestCompletedNarNotReofferedAcrossClosures805=== PAUSE TestCompletedNarNotReofferedAcrossClosures806=== RUN TestPresignedUploadRegisteredBeforeCommit807=== PAUSE TestPresignedUploadRegisteredBeforeCommit808=== RUN TestService_Rustfstest809=== PAUSE TestService_Rustfstest810=== RUN TestParseSize811=== PAUSE TestParseSize812=== RUN TestSkippedUploadsHandler813=== PAUSE TestSkippedUploadsHandler814=== RUN TestSystemdListenerNotActivated815--- PASS: TestSystemdListenerNotActivated (0.00s)816=== RUN TestWatchdogBeatsWhenHealthy817--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)818=== RUN TestWatchdogSkipsWhenUnhealthy8192026/10/27 13:04:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8202026/10/27 13:04:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8212026/10/27 13:04:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8222026/10/27 13:04:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8232026/10/27 13:04:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8242026/10/27 13:04:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8252026/10/27 13:04:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8262026/10/27 13:04:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8272026/10/27 13:04:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8282026/10/27 13:04:01 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"829--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)830=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle831=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle832=== RUN TestProxyWriteTimeout833=== PAUSE TestProxyWriteTimeout834=== RUN TestPendingClosureWriteTimeout835=== PAUSE TestPendingClosureWriteTimeout836=== RUN TestIsValidUploadKey837=== PAUSE TestIsValidUploadKey838=== RUN TestUploadHandlersRejectInvalidKeys839=== PAUSE TestUploadHandlersRejectInvalidKeys840=== RUN TestUploadHandlersRejectOversizedBody841=== PAUSE TestUploadHandlersRejectOversizedBody842=== RUN TestService_cleanupPendingClosuresHandler843=== PAUSE TestService_cleanupPendingClosuresHandler844=== RUN TestService_createPendingClosureHandler845=== PAUSE TestService_createPendingClosureHandler846=== RUN TestService_verifyS3Integrity847=== PAUSE TestService_verifyS3Integrity848=== RUN TestCompleteMultipartUnregistered849=== PAUSE TestCompleteMultipartUnregistered850=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT851=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT852=== CONT TestSkippedUploadsHandler853=== CONT TestService_createPendingClosureHandler854=== CONT TestPush_RepeatedRootCommitsOnce855=== CONT TestService_AuthMiddleware856=== CONT TestGCTaskStore_ConflictDifferentParams857--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)858=== CONT TestCompleteMultipartUpload_ErrorButObjectExists859=== CONT TestGCTaskStore_StartNew860=== CONT TestService_Rustfstest861=== CONT TestPresignedUploadRegisteredBeforeCommit862=== CONT TestUploadHandlersRejectOversizedBody863=== CONT TestParseSize864=== CONT TestService_verifyS3Integrity865=== CONT TestCompletedNarNotReofferedAcrossClosures866=== CONT TestService_NativeMTLS867=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT868=== CONT TestPush_RejectsBadRequests869=== CONT TestPush_SignsNarinfosOfItsPendingObjects870=== CONT TestRedundantMultipartUpload871=== CONT TestCompleteMultipartUnregistered872=== CONT TestGCTaskStore_Fail873=== CONT TestDeletePinKeepsRowWhenS3Fails874=== CONT TestGCTaskStore_CompletedAllowsNewTask875=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit876=== CONT TestGCTaskStore_PhaseUpdates877=== CONT TestGCTaskStore_GetEmpty878=== CONT TestService_healthCheckHandler879--- PASS: TestGCTaskStore_StartNew (0.00s)880=== CONT TestCreatePinRejectsBadInput881=== CONT TestPresentReportsOnlyClosureRoots882--- PASS: TestParseSize (0.00s)883--- PASS: TestGCTaskStore_Fail (0.00s)884--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)8852026/10/27 13:04:01 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000886--- PASS: TestGCTaskStore_GetEmpty (0.00s)887--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)888=== CONT TestOrphanedObjectsGC889=== CONT TestConnectWaitsForAPeerMigration890=== CONT TestCreatePin_ReservedPins891=== CONT TestMultipartCleanup892--- PASS: TestSkippedUploadsHandler (0.04s)8932026/10/27 13:04:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40865/oidc8942026/10/27 13:04:02 INFO Received uploads request method=POST path=/api/pending_closures8952026/10/27 13:04:02 INFO Received uploads request method=POST path=/api/pending_closures8962026/10/27 13:04:02 INFO Received uploads request method=POST path=/api/pending_closures8972026/10/27 13:04:02 INFO Received uploads request method=POST path=/api/pending_closures8982026/10/27 13:04:02 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"8992026/10/27 13:04:02 INFO Received uploads request method=POST path=/api/pending_closures900=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure901=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure902=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart903=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart904=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts905=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts906=== CONT TestMetricsInventory907--- PASS: TestService_AuthMiddleware (0.51s)908=== CONT TestReconnectLeavesObjectsUnlocked9092026/10/27 13:04:02 INFO Received uploads request method=POST path=/api/pending_closures9102026/10/27 13:04:02 INFO Received uploads request method=POST path=/api/pending_closures9112026/10/27 13:04:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9122026/10/27 13:04:02 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLjI2NDQ3MTFjLTZhOGEtNDhlMS1hZWQ3LThjN2ZmYzJiYzU5MHgxNzkzMTA2MjQyMTgzMTU4MTY4913=== RUN TestPush_RejectsBadRequests/no_roots914=== PAUSE TestPush_RejectsBadRequests/no_roots915=== RUN TestPush_RejectsBadRequests/no_objects916=== PAUSE TestPush_RejectsBadRequests/no_objects917=== RUN TestPush_RejectsBadRequests/bad_root918=== PAUSE TestPush_RejectsBadRequests/bad_root919=== RUN TestPush_RejectsBadRequests/root_not_in_objects920=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects921=== CONT TestPush_RootsAreLockedInByteOrder922--- PASS: TestService_Rustfstest (0.55s)923=== CONT TestPinProtectsFromGC9242026/10/27 13:04:02 INFO Received uploads request method=POST path=/api/pending_closures9252026/10/27 13:04:02 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9262026/10/27 13:04:02 WARN mTLS auth: subject not in bound subjects subject="CN=reader"9272026/10/27 13:04:02 INFO Received uploads request method=POST path=/api/pending_closures9282026/10/27 13:04:02 WARN mTLS auth: subject not in bound subjects subject="CN=reader"929--- PASS: TestService_NativeMTLS (0.61s)930=== CONT TestService_readinessHandler9312026/10/27 13:04:02 INFO Received create pin request method=POST path=/api/pins/app932=== CONT TestClientSharedPathCommittedMidPush933--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.63s)9342026/10/27 13:04:02 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo9352026/10/27 13:04:02 INFO Received delete pin request method=DELETE path=/api/pins/app9362026/10/27 13:04:02 INFO Received push request method=POST path=/api/pushes9372026/10/27 13:04:02 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket13/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"9382026/10/27 13:04:02 INFO Received delete pin request method=DELETE path=/api/pins/app9392026/10/27 13:04:02 INFO Received push request method=POST path=/api/pushes9402026/10/27 13:04:02 INFO Deleted pin name=app9412026/10/27 13:04:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign942=== CONT TestRegisterCompletedObjectNeedsPendingRow943--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.70s)9442026/10/27 13:04:02 INFO Signed narinfos id=1 count=19452026/10/27 13:04:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9462026/10/27 13:04:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9472026/10/27 13:04:02 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9482026/10/27 13:04:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9492026/10/27 13:04:02 INFO Received uploads request method=POST path=/api/pending_closures9502026/10/27 13:04:02 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9512026/10/27 13:04:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9522026/10/27 13:04:02 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19532026/10/27 13:04:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9542026/10/27 13:04:02 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo9552026/10/27 13:04:02 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLjI2NDQ3MTFjLTZhOGEtNDhlMS1hZWQ3LThjN2ZmYzJiYzU5MHgxNzkzMTA2MjQyMTgzMTU4MTY4 error="Delete \"http://localhost:39805/bucket5/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLjI2NDQ3MTFjLTZhOGEtNDhlMS1hZWQ3LThjN2ZmYzJiYzU5MHgxNzkzMTA2MjQyMTgzMTU4MTY4\": injected: abort refused"9562026/10/27 13:04:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9572026/10/27 13:04:02 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLjI2NDQ3MTFjLTZhOGEtNDhlMS1hZWQ3LThjN2ZmYzJiYzU5MHgxNzkzMTA2MjQyMTgzMTU4MTY4958--- PASS: TestService_healthCheckHandler (0.73s)959=== CONT TestCacheConfigHandlerMaxNarSize960=== CONT TestCacheConfigHandler961--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.74s)962=== RUN TestCacheConfigHandler/full_config,_no_issuer963=== CONT TestFailedS3DeleteKeepsTombstone964--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)965=== PAUSE TestCacheConfigHandler/full_config,_no_issuer966=== RUN TestCacheConfigHandler/no_cache_url_configured967=== PAUSE TestCacheConfigHandler/no_cache_url_configured968=== RUN TestCacheConfigHandler/no_signing_keys969=== PAUSE TestCacheConfigHandler/no_signing_keys970=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator971=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator972=== CONT TestCreatePendingClosureRejectsOversizedNAR9732026/10/27 13:04:02 INFO Received uploads request method=POST path=/api/pending_closures974--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)975=== CONT TestForceGCDuringPushOffersSweptObject976=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows977=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows978=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check979=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check980=== CONT TestService_AuthMiddleware_OIDC9812026/10/27 13:04:02 ERROR Failed to register completed object error="get pending object \"nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst\": context canceled" object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst9822026/10/27 13:04:02 INFO Received push request method=POST path=/api/pushes9832026/10/27 13:04:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete984--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.74s)985=== CONT TestReadProxyHead9862026/10/27 13:04:02 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified multipart upload does not exist. The upload ID may be invalid, or the upload may have been aborted or completed." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLjI2NDQ3MTFjLTZhOGEtNDhlMS1hZWQ3LThjN2ZmYzJiYzU5MHgxNzkzMTA2MjQyMTgzMTU4MTY49872026/10/27 13:04:02 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLjI2NDQ3MTFjLTZhOGEtNDhlMS1hZWQ3LThjN2ZmYzJiYzU5MHgxNzkzMTA2MjQyMTgzMTU4MTY4 parts=19882026/10/27 13:04:02 INFO Received create pin request method=POST path=/api/pins/deploy9892026/10/27 13:04:02 INFO Received create pin request method=POST path=/api/pins/deploy9902026/10/27 13:04:02 INFO Received create pin request method=POST path=/api/pins/deploy9912026/10/27 13:04:02 INFO Received create pin request method=POST path=/api/pins/deploy9922026/10/27 13:04:02 INFO Received create pin request method=POST path=/api/pins/deploy9932026/10/27 13:04:02 INFO Received create pin request method=POST path=/api/pins/deploy9942026/10/27 13:04:02 INFO Received create pin request method=POST path=/api/pins/deploy9952026/10/27 13:04:02 INFO Received create pin request method=POST path=/api/pins/deploy996--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.79s)997=== CONT TestDeduplicatedObjectsRecordedAsPending9982026/10/27 13:04:02 INFO Received uploads request method=POST path=/api/pending_closures9992026/10/27 13:04:02 INFO Received create pin request method=POST path=/api/pins/deploy10002026/10/27 13:04:02 INFO Received uploads request method=POST path=/api/pending_closures10012026/10/27 13:04:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10022026/10/27 13:04:02 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst10032026/10/27 13:04:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1004--- PASS: TestCompleteMultipartUnregistered (0.88s)1005=== CONT TestLeadEndsOnShutdown10062026/10/27 13:04:02 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLjIzYmMwYmVmLTIyNTEtNDI4Yi1hMjE1LTUxYTJmZTRhNzVhNngxNzkzMTA2MjQyMTYzNjAzNzU0 parts=1010072026/10/27 13:04:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10082026/10/27 13:04:02 INFO Completed upload id=1 objects=2 duration=2.482722ms10092026/10/27 13:04:02 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010102026/10/27 13:04:02 INFO Received uploads request method=POST path=/api/pending_closures10112026/10/27 13:04:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures10122026/10/27 13:04:02 INFO Aborted multipart uploads count=0 kept=010132026/10/27 13:04:02 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=01014--- PASS: TestPresentReportsOnlyClosureRoots (0.91s)1015=== CONT TestGCSweepSkipsPendingObjects10162026/10/27 13:04:02 INFO Vacuumed table table=pending_closures10172026/10/27 13:04:02 INFO Vacuumed table table=pending_objects10182026/10/27 13:04:02 INFO Vacuumed table table=multipart_uploads10192026/10/27 13:04:02 INFO Vacuumed table table=closures10202026/10/27 13:04:02 INFO Received cleanup request method=DELETE path=/api/pending_closures10212026/10/27 13:04:02 INFO Vacuumed table table=objects10222026/10/27 13:04:02 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket20/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10232026/10/27 13:04:02 INFO Aborted multipart uploads count=0 kept=110242026/10/27 13:04:02 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10252026/10/27 13:04:02 WARN Refused reserved pin name=worker-x86_64-linux10262026/10/27 13:04:02 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10272026/10/27 13:04:02 INFO Received create pin request method=POST path=/api/pins/my-app10282026/10/27 13:04:02 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10292026/10/27 13:04:02 INFO Received cleanup request method=DELETE path=/api/pending_closures10302026/10/27 13:04:02 INFO Aborted multipart uploads count=1 kept=010312026/10/27 13:04:02 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001032=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1033--- PASS: TestCreatePin_ReservedPins (0.94s)1034--- PASS: TestMultipartCleanup (0.92s)1035=== CONT TestService_ReadAuthMiddleware1036--- PASS: TestService_createPendingClosureHandler (0.96s)1037=== CONT TestService_RequireScope_OIDC1038=== CONT TestGCEndsOnShutdown1039--- PASS: TestMetricsInventory (0.49s)1040=== RUN TestGCEndsOnShutdown/before_the_run1041=== PAUSE TestGCEndsOnShutdown/before_the_run1042=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1043=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1044=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1045=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1046=== CONT TestPush_OverlappingRootsStoreOneRowPerKey10472026/10/27 13:04:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1048--- PASS: TestReconnectLeavesObjectsUnlocked (0.50s)1049=== CONT TestUploadHandlersRejectInvalidKeys1050=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1051=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1052=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1053=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1054=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1055=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1056=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1057=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1058=== CONT TestReadRedirectNar10592026/10/27 13:04:02 INFO Received push request method=POST path=/api/pushes10602026/10/27 13:04:02 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLjRhZjMyM2Y4LThhNjMtNDQ5OC1iNGQzLTI2N2FmOTY3ZDZhYngxNzkzMTA2MjQyMzU3NjQ5MTcy parts=1010612026/10/27 13:04:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10622026/10/27 13:04:02 INFO Completed upload id=1 objects=2 duration=4.897664ms10632026/10/27 13:04:02 WARN readiness check failed error="closed pool"10642026/10/27 13:04:02 INFO Received uploads request method=POST path=/api/pending_closures10652026/10/27 13:04:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37839/oidc10662026/10/27 13:04:02 INFO Received uploads request method=POST path=/api/pending_closures10672026/10/27 13:04:02 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10682026/10/27 13:04:02 WARN Found objects in DB but missing from S3, will re-upload count=11069=== CONT TestLeadIncumbentAnnouncesAtOnce1070--- PASS: TestService_readinessHandler (0.45s)10712026/10/27 13:04:02 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete10722026/10/27 13:04:02 INFO Completed upload id=3 objects=2 duration=10.05137ms1073=== NAME TestPinProtectsFromGC1074 client_integration_test.go:854: Pinned store path: /build/TestPinProtectsFromGC3301523025/001/store/p4pq2sb200k51m5ydih23f2079allm57-pinned-file.txt1075 client_integration_test.go:855: Unpinned store path: /build/TestPinProtectsFromGC3301523025/001/store/v767jnkpmwaa33l8a4d1ycaygr3kpslh-unpinned-file.txt10762026/10/27 13:04:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1077=== CONT TestPendingClosureWriteTimeout1078=== RUN TestPendingClosureWriteTimeout/empty1079--- PASS: TestService_verifyS3Integrity (1.11s)1080=== PAUSE TestPendingClosureWriteTimeout/empty1081=== RUN TestPendingClosureWriteTimeout/400_objects1082=== PAUSE TestPendingClosureWriteTimeout/400_objects1083=== RUN TestPendingClosureWriteTimeout/670k_objects1084=== PAUSE TestPendingClosureWriteTimeout/670k_objects1085=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1086=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1087=== CONT TestIsValidCachePath1088=== RUN TestIsValidCachePath/narinfo1089=== PAUSE TestIsValidCachePath/narinfo1090=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1091=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1092=== RUN TestIsValidCachePath/nar_zst1093=== PAUSE TestIsValidCachePath/nar_zst1094=== RUN TestIsValidCachePath/nar_xz1095=== PAUSE TestIsValidCachePath/nar_xz1096=== RUN TestIsValidCachePath/nar_bz21097=== PAUSE TestIsValidCachePath/nar_bz21098=== RUN TestIsValidCachePath/nar_uncompressed1099=== PAUSE TestIsValidCachePath/nar_uncompressed1100=== RUN TestIsValidCachePath/ls1101=== PAUSE TestIsValidCachePath/ls1102=== RUN TestIsValidCachePath/log1103=== PAUSE TestIsValidCachePath/log1104=== RUN TestIsValidCachePath/realisation1105=== PAUSE TestIsValidCachePath/realisation1106=== RUN TestIsValidCachePath/nix-cache-info1107=== PAUSE TestIsValidCachePath/nix-cache-info1108=== RUN TestIsValidCachePath/index.html1109=== PAUSE TestIsValidCachePath/index.html1110=== RUN TestIsValidCachePath/traversal_parent1111=== PAUSE TestIsValidCachePath/traversal_parent1112=== RUN TestIsValidCachePath/traversal_in_middle1113=== PAUSE TestIsValidCachePath/traversal_in_middle1114=== RUN TestIsValidCachePath/invalid_char_e1115=== PAUSE TestIsValidCachePath/invalid_char_e1116=== RUN TestIsValidCachePath/invalid_char_u1117=== PAUSE TestIsValidCachePath/invalid_char_u1118=== RUN TestIsValidCachePath/random_path1119=== PAUSE TestIsValidCachePath/random_path1120=== RUN TestIsValidCachePath/empty1121=== PAUSE TestIsValidCachePath/empty1122=== RUN TestIsValidCachePath/leading_slash1123=== PAUSE TestIsValidCachePath/leading_slash1124=== RUN TestIsValidCachePath/wrong_extension1125=== PAUSE TestIsValidCachePath/wrong_extension1126=== RUN TestIsValidCachePath/short_hash1127=== PAUSE TestIsValidCachePath/short_hash1128=== CONT TestReadProxyContentNegotiation11292026/10/27 13:04:02 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLmYzOGQ5MmNmLWUxNGItNDFlOS1iNmY0LWVmODkwMzU5MDFiN3gxNzkzMTA2MjQyMjYwODI4NjY1 parts=1211302026/10/27 13:04:02 INFO Received uploads request method=POST path=/api/pending_closures11312026/10/27 13:04:02 INFO Received uploads request method=POST path=/api/pending_closures11322026/10/27 13:04:03 INFO Received uploads request method=POST path=/api/pending_closures1133--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.46s)1134=== CONT TestReadProxyNarinfo11352026/10/27 13:04:03 INFO Received push request method=POST path=/api/pushes11362026/10/27 13:04:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11372026/10/27 13:04:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11382026/10/27 13:04:03 INFO Uploading p4pq2sb200k51m5ydih23f2079allm57-pinned-file.txt (128B)11392026/10/27 13:04:03 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLjlhZTkzOTdmLWJiMjctNDg0My05YmY1LWUzZjg3MjJkNGM5ZngxNzkzMTA2MjQyNTAwMzY3Njkx parts=1011402026/10/27 13:04:03 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11412026/10/27 13:04:03 WARN Failed to register uploaded object key=p4pq2sb200k51m5ydih23f2079allm57.ls error="server returned 404: 404 page not found\n"11422026/10/27 13:04:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11432026/10/27 13:04:03 INFO Received uploads request method=POST path=/api/pending_closures11442026/10/27 13:04:03 INFO Signed narinfos id=1 count=111452026/10/27 13:04:03 INFO Uploading 1 narinfos11462026/10/27 13:04:03 INFO Received complete push request method=POST path=/api/pushes/1/complete11472026/10/27 13:04:03 WARN Failed to register uploaded object key=p4pq2sb200k51m5ydih23f2079allm57.narinfo error="server returned 404: 404 page not found\n"11482026/10/27 13:04:03 INFO Completed push id=1 objects=3 duration=6.229076ms11492026/10/27 13:04:03 INFO Upload complete. (96ms)11502026/10/27 13:04:03 INFO lead: acquired remote=192.0.2.1:12341151--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.45s)1152=== CONT TestReadProxyNarStreaming11532026/10/27 13:04:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11542026/10/27 13:04:03 INFO Aborted multipart uploads count=0 kept=011552026/10/27 13:04:03 WARN Force mode enabled - objects will be deleted immediately without grace period11562026/10/27 13:04:03 INFO Received push request method=POST path=/api/pushes11572026/10/27 13:04:03 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLmJjMTIyN2NkLTdjZWYtNDFhYi1hNDA3LTU1OTUzYzM3OWY1NngxNzkzMTA2MjQyNTk1OTkwMjg4 parts=1011582026/10/27 13:04:03 INFO Received uploads request method=POST path=/api/pending_closures11592026/10/27 13:04:03 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11602026/10/27 13:04:03 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."11612026/10/27 13:04:03 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)1162=== NAME TestOrphanedObjectsGC1163 orphaned_objects_gc_test.go:287: GC Test Summary:11642026/10/27 13:04:03 INFO Uploading xwp95n8r9s1gy5wr4n4aays9lxn8a92l-top (224B)1165 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A11662026/10/27 13:04:03 INFO Uploading aj07lxwsslv867g75c9lkkii16m48rbj-shared-dep (136B)1167 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1168 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1169 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1170 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects11712026/10/27 13:04:03 WARN Failed to register uploaded object key=nar/1h9hbgn1ivkhcvgn4j0wry8izmc9fjv4r5infqyj7plb0f8kx5za.nar.zst error="server returned 404: 404 page not found\n"11722026/10/27 13:04:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11732026/10/27 13:04:03 WARN Failed to register uploaded object key=xwp95n8r9s1gy5wr4n4aays9lxn8a92l.ls error="server returned 404: 404 page not found\n"11742026/10/27 13:04:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11752026/10/27 13:04:03 WARN Failed to register uploaded object key=aj07lxwsslv867g75c9lkkii16m48rbj.ls error="server returned 404: 404 page not found\n"11762026/10/27 13:04:03 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"11772026/10/27 13:04:03 WARN mTLS auth: bound subjects configured but subject DN unavailable11782026/10/27 13:04:03 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"11792026/10/27 13:04:03 INFO Signed narinfos id=1 count=211802026/10/27 13:04:03 INFO Uploading 2 narinfos11812026/10/27 13:04:03 INFO Aborted multipart uploads count=0 kept=01182--- PASS: TestFailedS3DeleteKeepsTombstone (0.55s)1183=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded11842026/10/27 13:04:03 WARN Force mode enabled - objects will be deleted immediately without grace period11852026/10/27 13:04:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46669/oidc11862026/10/27 13:04:03 WARN Failed to register uploaded object key=aj07lxwsslv867g75c9lkkii16m48rbj.narinfo error="server returned 404: 404 page not found\n"11872026/10/27 13:04:03 INFO Received complete push request method=POST path=/api/pushes/1/complete11882026/10/27 13:04:03 WARN Failed to register uploaded object key=xwp95n8r9s1gy5wr4n4aays9lxn8a92l.narinfo error="server returned 404: 404 page not found\n"11892026/10/27 13:04: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=011902026/10/27 13:04:03 INFO Vacuumed table table=pending_closures11912026/10/27 13:04:03 INFO Received push request method=POST path=/api/pushes11922026/10/27 13:04:03 INFO Vacuumed table table=pending_objects11932026/10/27 13:04:03 INFO Vacuumed table table=multipart_uploads11942026/10/27 13:04:03 INFO Vacuumed table table=closures11952026/10/27 13:04:03 INFO Completed push id=1 objects=6 duration=7.379686ms11962026/10/27 13:04:03 INFO Upload complete. (90ms)11972026/10/27 13:04:03 INFO Vacuumed table table=objects11982026/10/27 13:04:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11992026/10/27 13:04:03 INFO Uploading v767jnkpmwaa33l8a4d1ycaygr3kpslh-unpinned-file.txt (128B)1200=== NAME TestClientSharedPathCommittedMidPush1201 client_integration_test.go:803: Retrieved narinfo from S3:1202 StorePath: /build/TestClientSharedPathCommittedMidPush2399994116/001/store/aj07lxwsslv867g75c9lkkii16m48rbj-shared-dep1203 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1204 Compression: zstd1205 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821206 NarSize: 1361207 References: 1208 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1209--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.37s)1210=== CONT TestConcurrentPinUpdatesAgree1211--- PASS: TestReadProxyHead (0.58s)1212=== CONT TestServerTLSConfig1213--- PASS: TestOrphanedObjectsGC (1.32s)1214=== CONT TestService_cleanupPendingClosuresHandler1215=== RUN TestServerTLSConfig/no_client_CA1216=== PAUSE TestServerTLSConfig/no_client_CA1217=== RUN TestServerTLSConfig/missing_CA_file1218=== PAUSE TestServerTLSConfig/missing_CA_file1219=== RUN TestServerTLSConfig/not_a_PEM_file1220=== PAUSE TestServerTLSConfig/not_a_PEM_file1221=== CONT TestPush_CompleteWaitsForCleanupOfThePush1222=== NAME TestClientSharedPathCommittedMidPush1223 client_integration_test.go:803: Retrieved narinfo from S3:1224 StorePath: /build/TestClientSharedPathCommittedMidPush2399994116/001/store/xwp95n8r9s1gy5wr4n4aays9lxn8a92l-top1225 URL: nar/1h9hbgn1ivkhcvgn4j0wry8izmc9fjv4r5infqyj7plb0f8kx5za.nar.zst1226 Compression: zstd1227 NarHash: sha256:1h9hbgn1ivkhcvgn4j0wry8izmc9fjv4r5infqyj7plb0f8kx5za1228 NarSize: 2241229 References: /build/TestClientSharedPathCommittedMidPush2399994116/001/store/aj07lxwsslv867g75c9lkkii16m48rbj-shared-dep1230 CA: text:sha256:19pspl6f865grn5468djdfw2l4sv4gqpp5b642zmda6f9xm4344m12312026/10/27 13:04:03 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"12322026/10/27 13:04:03 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12332026/10/27 13:04:03 WARN Failed to register uploaded object key=v767jnkpmwaa33l8a4d1ycaygr3kpslh.ls error="server returned 404: 404 page not found\n"12342026/10/27 13:04:03 INFO Signed narinfos id=2 count=11235--- PASS: TestService_ReadAuthMiddleware (0.38s)1236=== CONT TestConnectSerialisesConcurrentMigrations12372026/10/27 13:04:03 INFO Uploading 1 narinfos1238=== CONT TestGCTaskStore_DeduplicateSameParams1239--- PASS: TestGCSweepSkipsPendingObjects (0.43s)1240=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1241--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)12422026/10/27 13:04:03 INFO Received complete push request method=POST path=/api/pushes/2/complete12432026/10/27 13:04:03 WARN Failed to register uploaded object key=v767jnkpmwaa33l8a4d1ycaygr3kpslh.narinfo error="server returned 404: 404 page not found\n"1244=== CONT TestDeleteClosuresRacingPins1245--- PASS: TestClientSharedPathCommittedMidPush (0.73s)12462026/10/27 13:04:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12472026/10/27 13:04:03 INFO Completed push id=2 objects=3 duration=11.052899ms12482026/10/27 13:04:03 INFO Upload complete. (96ms)12492026/10/27 13:04:03 INFO Received push request method=POST path=/api/pushes1250--- PASS: TestReadRedirectNar (0.37s)1251=== CONT TestOrphanedObjectsGCStressTest12522026/10/27 13:04:03 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLjM5NzM5NTA5LTMzOTctNDVjMy1iYjVkLTI0ZGU3YWZlMTQ5MngxNzkzMTA2MjQyNjY4MDU3MDEz parts=1212532026/10/27 13:04:03 INFO Received uploads request method=POST path=/api/pending_closures1254=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1255=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1256=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1257=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1258=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1259=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1260=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1261=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1262=== CONT TestPushWaitsForSweepHoldingRow12632026/10/27 13:04:03 INFO Starting cleanup of old closures method=DELETE path=/api/closures12642026/10/27 13:04:03 INFO Garbage collection started12652026/10/27 13:04:03 INFO Aborted multipart uploads count=0 kept=01266=== CONT TestObjectStatsUpdatedOncePerCommit1267--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.42s)1268--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.42s)1269=== CONT TestResolveDBConnectionString1270=== RUN TestResolveDBConnectionString/flag_wins1271=== PAUSE TestResolveDBConnectionString/flag_wins1272=== RUN TestResolveDBConnectionString/file_when_flag_empty1273=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1274=== RUN TestResolveDBConnectionString/missing_file_is_an_error1275=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1276=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1277=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1278=== RUN TestResolveDBConnectionString/nothing_configured1279=== PAUSE TestResolveDBConnectionString/nothing_configured1280=== CONT TestObjectStatsTrigger12812026/10/27 13:04:03 INFO lead: acquired remote=192.0.2.1:123412822026/10/27 13:04:03 INFO lead: released remote=192.0.2.1:123412832026/10/27 13:04:03 WARN Force mode enabled - objects will be deleted immediately without grace period1284--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.38s)1285=== CONT TestCommitRacingPendingCleanupKeepsObjects12862026-10-27 13:04:03.295 UTC [886] ERROR: duplicate key value violates unique constraint "pg_type_typname_nsp_index"12872026-10-27 13:04:03.295 UTC [886] DETAIL: Key (typname, typnamespace)=(goose_db_version, 2200) already exists.12882026-10-27 13:04:03.295 UTC [886] STATEMENT: CREATE TABLE goose_db_version (1289 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1290 version_id bigint NOT NULL,1291 is_applied boolean NOT NULL,1292 tstamp timestamp NOT NULL DEFAULT now()1293 )12942026/10/27 13:04:03 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=012952026/10/27 13:04:03 INFO Vacuumed table table=pending_closures12962026/10/27 13:04:03 INFO Vacuumed table table=pending_objects12972026/10/27 13:04:03 INFO Vacuumed table table=multipart_uploads12982026/10/27 13:04:03 INFO Vacuumed table table=closures12992026/10/27 13:04:03 INFO Vacuumed table table=objects13002026/10/27 13:04:03 INFO Received uploads request method=POST path=/api/pending_closures13012026/10/27 13:04:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1302--- PASS: TestReadProxyNarStreaming (0.32s)1303=== CONT TestClientPushesUseOnePush13042026/10/27 13:04:03 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLjBkM2VmYzllLWQ3ZDEtNGQwOS04YjA3LWFkMGM0OGY4MzIzZXgxNzkzMTA2MjQyODcxMjExMDkz parts=101305--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.30s)1306=== CONT TestPendingClosureFailureTracksEveryUpload1307=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1308=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1309=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1310=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1311=== CONT TestSweepRechecksPendingAfterLocking1312=== RUN TestService_RequireScope_OIDC/builder_may_write1313=== PAUSE TestService_RequireScope_OIDC/builder_may_write1314=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1315=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1316=== RUN TestService_RequireScope_OIDC/ops_may_admin1317=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1318=== RUN TestService_RequireScope_OIDC/ops_may_not_write1319=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1320=== RUN TestService_RequireScope_OIDC/reader_may_not_write1321=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1322=== RUN TestService_RequireScope_OIDC/static_token_may_admin1323=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1324=== RUN TestService_RequireScope_OIDC/static_token_may_write1325=== PAUSE TestService_RequireScope_OIDC/static_token_may_write13262026/10/27 13:04:03 INFO Received cleanup request method=DELETE path=/api/pending_closures1327=== RUN TestService_RequireScope_OIDC/reader_may_read1328=== PAUSE TestService_RequireScope_OIDC/reader_may_read1329=== RUN TestService_RequireScope_OIDC/writer_implies_read1330=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1331=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1332=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1333=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1334=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1335=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1336=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1337=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1338=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1339=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1340=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1341=== CONT TestClientFallsBackToClosures13422026/10/27 13:04:03 INFO Aborted multipart uploads count=0 kept=013432026/10/27 13:04:03 INFO Received uploads request method=POST path=/api/pending_closures13442026/10/27 13:04:03 INFO Received cleanup request method=DELETE path=/api/pending_closures13452026/10/27 13:04:03 INFO Aborted multipart uploads count=1 kept=013462026/10/27 13:04:03 INFO Received create pin request method=POST path=/api/pins/app13472026/10/27 13:04:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13482026-10-27 13:04:03.466 UTC [882] ERROR: Closure does not exist: id=113492026-10-27 13:04:03.466 UTC [882] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE13502026-10-27 13:04:03.466 UTC [882] STATEMENT: -- name: CommitPendingClosure :one1351 SELECT commit_pending_closure($1::bigint)::bigint1352 13532026/10/27 13:04:03 INFO Received create pin request method=POST path=/api/pins/app1354--- PASS: TestService_cleanupPendingClosuresHandler (0.31s)1355=== CONT TestPendingCleanupUsesOneCutoff13562026/10/27 13:04:03 INFO Received push request method=POST path=/api/pushes13572026/10/27 13:04:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13582026/10/27 13:04:03 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLjk2NjAxOTA0LWRhOGQtNDY2ZS04OGVmLWVhZDc2ZjBhM2JhNHgxNzkzMTA2MjQyNTAwOTU5Mzk2 parts=1013592026/10/27 13:04:03 INFO Received complete push request method=POST path=/api/pushes/1/complete13602026/10/27 13:04:03 INFO Completed push id=1 objects=4 duration=11.555383ms13612026/10/27 13:04:03 INFO Received create pin request method=POST path=/api/pins/deploy13622026/10/27 13:04:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13632026/10/27 13:04:03 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo1364=== CONT TestClientWithDependencies1365--- PASS: TestPush_RepeatedRootCommitsOnce (1.73s)13662026/10/27 13:04:03 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLjUzYmRiNDAzLWJjOGUtNDM2Zi1iYzY1LTk4ZjMwMDVjZDdlZHgxNzkzMTA2MjQyNTk2NzMzNjc0 parts=1013672026/10/27 13:04:03 INFO Received complete push request method=POST path=/api/pushes/1/complete13682026/10/27 13:04:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13692026/10/27 13:04:03 INFO Completed push id=1 objects=4 duration=9.497725ms13702026/10/27 13:04:03 INFO Received push request method=POST path=/api/pushes1371--- PASS: TestCreatePinRejectsBadInput (1.75s)1372=== CONT TestGetExistingObjectsLocksRows13732026/10/27 13:04:03 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLmE3MjIxNWMwLTMxYTUtNDk0OS1iMzU4LTAyZDQ4NjY3MTJjMXgxNzkzMTA2MjQyOTkzNzk2MDcy error="Get \"http://127.0.0.1:1/bucket7/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"13742026/10/27 13:04:03 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLjA5YWI3OWM4LWE5MTEtNDE1Ny1hOGQ0LTVhMmNkMWIzMDVjNHgxNzkzMTA2MjQyOTc3MjI2MTAz parts=1213752026/10/27 13:04:03 INFO Received cleanup request method=DELETE path=/api/pending_closures13762026/10/27 13:04:03 INFO Aborted multipart uploads count=1 kept=013772026/10/27 13:04:03 INFO Received uploads request method=POST path=/api/pending_closures1378--- PASS: TestRedundantMultipartUpload (1.80s)1379=== CONT TestSweepSkipsRowsLockedByPush13802026/10/27 13:04:03 INFO Aborted multipart uploads count=0 kept=013812026/10/27 13:04:03 WARN Force mode enabled - objects will be deleted immediately without grace period1382--- PASS: TestObjectStatsTrigger (0.42s)1383=== CONT TestPendingClosureFailureAbortsItsUploads13842026/10/27 13:04:03 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=013852026/10/27 13:04:03 INFO Vacuumed table table=pending_closures13862026/10/27 13:04:03 INFO Vacuumed table table=pending_objects1387--- PASS: TestReadProxyContentNegotiation (0.76s)1388=== CONT TestClientIntegration13892026/10/27 13:04:03 INFO Vacuumed table table=multipart_uploads13902026/10/27 13:04:03 INFO Vacuumed table table=closures13912026/10/27 13:04:03 INFO Vacuumed table table=objects1392--- PASS: TestObjectStatsUpdatedOncePerCommit (0.47s)1393=== CONT TestGenerateLandingPage1394=== CONT TestClientMultipleUploads1395--- PASS: TestGenerateLandingPage (0.01s)13962026/10/27 13:04:03 INFO Aborted multipart uploads count=0 kept=013972026/10/27 13:04:03 WARN Force mode enabled - objects will be deleted immediately without grace period13982026/10/27 13:04: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=013992026/10/27 13:04:03 INFO Vacuumed table table=pending_closures14002026/10/27 13:04:03 INFO Vacuumed table table=pending_objects14012026/10/27 13:04:03 INFO Vacuumed table table=multipart_uploads14022026/10/27 13:04:03 INFO Vacuumed table table=closures14032026/10/27 13:04:03 INFO Vacuumed table table=objects14042026/10/27 13:04:03 INFO Aborted multipart uploads count=0 kept=01405=== CONT TestMetricsCommit1406--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.51s)14072026/10/27 13:04:03 WARN Force mode enabled - objects will be deleted immediately without grace period14082026/10/27 13:04:03 INFO Received uploads request method=POST path=/api/pending_closures14092026/10/27 13:04:03 INFO Received uploads request method=POST path=/api/pending_closures14102026/10/27 13:04: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=014112026/10/27 13:04:03 INFO Vacuumed table table=pending_closures14122026/10/27 13:04:03 INFO Vacuumed table table=pending_objects14132026/10/27 13:04:03 INFO Vacuumed table table=multipart_uploads14142026/10/27 13:04:03 INFO Vacuumed table table=closures14152026/10/27 13:04:03 INFO Vacuumed table table=objects14162026/10/27 13:04:03 INFO Received cleanup request method=DELETE path=/api/pending_closures1417--- PASS: TestSweepRechecksPendingAfterLocking (0.42s)1418=== CONT TestClientErrorHandling1419=== RUN TestClientErrorHandling/InvalidStorePath1420=== PAUSE TestClientErrorHandling/InvalidStorePath1421=== RUN TestClientErrorHandling/InvalidAuthToken1422=== PAUSE TestClientErrorHandling/InvalidAuthToken1423=== RUN TestClientErrorHandling/ServerNotAvailable1424=== PAUSE TestClientErrorHandling/ServerNotAvailable1425=== CONT TestClientCADerivations1426--- PASS: TestGetExistingObjectsLocksRows (0.29s)1427=== CONT TestNARDeduplicationMetadataUploadBug14282026/10/27 13:04:03 INFO Received uploads request method=POST path=/api/pending_closures14292026/10/27 13:04:03 INFO Aborted multipart uploads count=0 kept=014302026/10/27 13:04:03 INFO Received push request method=POST path=/api/pushes14312026/10/27 13:04:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14322026/10/27 13:04:03 WARN Force mode enabled - objects will be deleted immediately without grace period14332026/10/27 13:04: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=014342026/10/27 13:04:03 INFO Vacuumed table table=pending_closures14352026/10/27 13:04:03 INFO Vacuumed table table=pending_objects14362026/10/27 13:04:03 INFO Vacuumed table table=multipart_uploads14372026/10/27 13:04:03 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14382026/10/27 13:04:03 INFO Vacuumed table table=closures14392026/10/27 13:04:03 INFO Uploading 2y5bgaml7yzcvmmsjx4kldi9mwf5m7h7-a (216B)14402026/10/27 13:04:03 INFO Uploading w9kp5rvnvqbpnfnrwk07wz9zzp9ic2hp-shared-dep (136B)1441=== NAME TestClientWithDependencies1442 client_integration_test.go:722: Built derivation: /build/TestClientWithDependencies101057100/001/store/kg7ami94mwvb4qwhfxljy1s8xh1v6999-test-script14432026/10/27 13:04:03 INFO Vacuumed table table=objects14442026/10/27 13:04:03 INFO Aborted multipart uploads count=0 kept=014452026/10/27 13:04:03 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLjdhZjQyMzRiLWM3M2ItNDRmNS05MjhjLTRkNzM4OWQ3ZmMxMngxNzkzMTA2MjQyODcxMjg3Nzc0 parts=1014462026/10/27 13:04:03 WARN Force mode enabled - objects will be deleted immediately without grace period14472026/10/27 13:04:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14482026/10/27 13:04:03 WARN Failed to register uploaded object key=2gd8pv0nm1hz61manwh0cnj82k84i8jg.ls error="server returned 404: 404 page not found\n"14492026/10/27 13:04:03 WARN Failed to register uploaded object key=nar/1xydlalxh22k6nxr280dr6hf2crzq2kbvyi51r91z2pqwqifg3hk.nar.zst error="server returned 404: 404 page not found\n"14502026/10/27 13:04:03 INFO Received uploads request method=POST path=/api/pending_closures14512026/10/27 13:04:03 WARN Failed to register uploaded object key=2y5bgaml7yzcvmmsjx4kldi9mwf5m7h7.ls error="server returned 404: 404 page not found\n"14522026/10/27 13:04:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14532026/10/27 13:04:03 WARN Failed to register uploaded object key=w9kp5rvnvqbpnfnrwk07wz9zzp9ic2hp.ls error="server returned 404: 404 page not found\n"14542026/10/27 13:04:03 INFO Signed narinfos id=1 count=314552026/10/27 13:04:03 INFO Uploading 3 narinfos14562026/10/27 13:04:03 INFO Received uploads request method=POST path=/api/pending_closures14572026/10/27 13:04:03 WARN Failed to register uploaded object key=w9kp5rvnvqbpnfnrwk07wz9zzp9ic2hp.narinfo error="server returned 404: 404 page not found\n"14582026/10/27 13:04:03 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14592026/10/27 13:04:03 INFO Uploading 5lp9bsmljsx0yjg925amw1dwzixw31z4-shared-dep (136B)14602026/10/27 13:04:03 INFO Uploading b6gkvfhknvdf79gix9f34dfzvjhxb8pq-b (216B)14612026/10/27 13:04:03 WARN Failed to register uploaded object key=2gd8pv0nm1hz61manwh0cnj82k84i8jg.narinfo error="server returned 404: 404 page not found\n"14622026/10/27 13:04:03 INFO Received complete push request method=POST path=/api/pushes/1/complete14632026/10/27 13:04:03 WARN Failed to register uploaded object key=2y5bgaml7yzcvmmsjx4kldi9mwf5m7h7.narinfo error="server returned 404: 404 page not found\n"14642026/10/27 13:04:03 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=01465 client_integration_test.go:724: Found 1 dependencies (including self)14662026/10/27 13:04:03 INFO Vacuumed table table=pending_closures1467=== CONT TestGCMetrics1468--- PASS: TestPendingClosureFailureAbortsItsUploads (0.28s)14692026/10/27 13:04:03 INFO Vacuumed table table=pending_objects14702026/10/27 13:04:03 INFO Vacuumed table table=multipart_uploads14712026/10/27 13:04:03 INFO Vacuumed table table=closures14722026/10/27 13:04:03 INFO Completed push id=1 objects=8 duration=6.854781ms14732026/10/27 13:04:03 INFO Vacuumed table table=objects14742026/10/27 13:04:03 INFO Upload complete. (95ms)1475=== NAME TestClientPushesUseOnePush1476 client_pushes_test.go:97: Retrieved narinfo from S3:1477 StorePath: /build/TestClientPushesUseOnePush1118544053/001/store/w9kp5rvnvqbpnfnrwk07wz9zzp9ic2hp-shared-dep1478 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1479 Compression: zstd1480 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821481 NarSize: 1361482 References: 1483 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n14842026/10/27 13:04:03 WARN Failed to register uploaded object key=8vk8vwg1cky28fi0rr17hrbp87ghj9ki.ls error="server returned 404: 404 page not found\n"14852026/10/27 13:04:03 WARN Failed to register uploaded object key=nar/19jxy83jswbz96r57l7xyrp924wqn117j1xrib1mlyy5h7w90fwx.nar.zst error="server returned 404: 404 page not found\n"14862026/10/27 13:04:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1487 client_pushes_test.go:97: Retrieved narinfo from S3:1488 StorePath: /build/TestClientPushesUseOnePush1118544053/001/store/2y5bgaml7yzcvmmsjx4kldi9mwf5m7h7-a1489 URL: nar/1xydlalxh22k6nxr280dr6hf2crzq2kbvyi51r91z2pqwqifg3hk.nar.zst1490 Compression: zstd1491 NarHash: sha256:1xydlalxh22k6nxr280dr6hf2crzq2kbvyi51r91z2pqwqifg3hk1492 NarSize: 2161493 References: /build/TestClientPushesUseOnePush1118544053/001/store/w9kp5rvnvqbpnfnrwk07wz9zzp9ic2hp-shared-dep1494 CA: text:sha256:0g8vzbi2gq1d6vskqvkjscx3n1pwm10flyxq9xki23lsiadsn5wf14952026/10/27 13:04:03 WARN Failed to register uploaded object key=b6gkvfhknvdf79gix9f34dfzvjhxb8pq.ls error="server returned 404: 404 page not found\n"14962026/10/27 13:04:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14972026/10/27 13:04:03 WARN Failed to register uploaded object key=5lp9bsmljsx0yjg925amw1dwzixw31z4.ls error="server returned 404: 404 page not found\n"14982026/10/27 13:04:03 INFO Signed narinfos id=1 count=214992026/10/27 13:04:03 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo15002026/10/27 13:04:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15012026/10/27 13:04:03 INFO Signed narinfos id=2 count=215022026/10/27 13:04:03 INFO Uploading 4 narinfos1503 client_pushes_test.go:97: Retrieved narinfo from S3:1504 StorePath: /build/TestClientPushesUseOnePush1118544053/001/store/2gd8pv0nm1hz61manwh0cnj82k84i8jg-b1505 URL: nar/1xydlalxh22k6nxr280dr6hf2crzq2kbvyi51r91z2pqwqifg3hk.nar.zst1506 Compression: zstd1507 NarHash: sha256:1xydlalxh22k6nxr280dr6hf2crzq2kbvyi51r91z2pqwqifg3hk1508 NarSize: 2161509 References: /build/TestClientPushesUseOnePush1118544053/001/store/w9kp5rvnvqbpnfnrwk07wz9zzp9ic2hp-shared-dep1510 CA: text:sha256:0g8vzbi2gq1d6vskqvkjscx3n1pwm10flyxq9xki23lsiadsn5wf15112026/10/27 13:04:03 INFO Received push request method=POST path=/api/pushes1512=== NAME TestClientIntegration1513 client_integration_test.go:331: Created store path: /build/TestClientIntegration67421258/002/store/gx8mmhyzn57yphsa75ygp9084klg2frq-test-file.txt1514--- PASS: TestSweepSkipsRowsLockedByPush (0.34s)1515=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection15162026/10/27 13:04:03 WARN Failed to register uploaded object key=8vk8vwg1cky28fi0rr17hrbp87ghj9ki.narinfo error="server returned 404: 404 page not found\n"15172026/10/27 13:04:03 WARN Failed to register uploaded object key=b6gkvfhknvdf79gix9f34dfzvjhxb8pq.narinfo error="server returned 404: 404 page not found\n"15182026/10/27 13:04:03 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo15192026/10/27 13:04:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15202026/10/27 13:04:04 WARN Failed to register uploaded object key=5lp9bsmljsx0yjg925amw1dwzixw31z4.narinfo error="server returned 404: 404 page not found\n"1521=== NAME TestClientMultipleUploads1522 client_integration_test.go:467: Created store path 0: /build/TestClientMultipleUploads1810792605/001/store/yw3bmivlglv0j0y2y3k5z2sqxivymxp0-test-file-0.txt15232026/10/27 13:04:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15242026/10/27 13:04:04 WARN Failed to register uploaded object key=5lp9bsmljsx0yjg925amw1dwzixw31z4.narinfo error="server returned 404: 404 page not found\n"15252026/10/27 13:04:04 INFO Completed upload id=1 objects=6 duration=5.710771ms15262026/10/27 13:04:04 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15272026/10/27 13:04:04 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLmMyMTg2OWZmLTZjYTUtNDM1ZC05MjNmLTQxYTkwZmE3OWJiY3gxNzkzMTA2MjQzNDkzNTUxMzQ5 parts=1015282026/10/27 13:04:04 INFO Completed upload id=2 objects=6 duration=2.048319ms15292026/10/27 13:04:04 INFO Upload complete. (117ms)1530=== NAME TestClientFallsBackToClosures1531 client_pushes_test.go:112: Retrieved narinfo from S3:1532 StorePath: /build/TestClientFallsBackToClosures3921681254/001/store/5lp9bsmljsx0yjg925amw1dwzixw31z4-shared-dep1533 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1534 Compression: zstd1535 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821536 NarSize: 1361537 References: 1538 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1539 client_pushes_test.go:112: Retrieved narinfo from S3:1540 StorePath: /build/TestClientFallsBackToClosures3921681254/001/store/8vk8vwg1cky28fi0rr17hrbp87ghj9ki-a1541 URL: nar/19jxy83jswbz96r57l7xyrp924wqn117j1xrib1mlyy5h7w90fwx.nar.zst1542 Compression: zstd1543 NarHash: sha256:19jxy83jswbz96r57l7xyrp924wqn117j1xrib1mlyy5h7w90fwx1544 NarSize: 2161545 References: /build/TestClientFallsBackToClosures3921681254/001/store/5lp9bsmljsx0yjg925amw1dwzixw31z4-shared-dep1546 CA: text:sha256:0n7lly22gf6nvi782r1yh1c1pfppd1yvqrprcdpyb8mlwacf6swy1547 client_pushes_test.go:112: Retrieved narinfo from S3:1548 StorePath: /build/TestClientFallsBackToClosures3921681254/001/store/b6gkvfhknvdf79gix9f34dfzvjhxb8pq-b1549 URL: nar/19jxy83jswbz96r57l7xyrp924wqn117j1xrib1mlyy5h7w90fwx.nar.zst1550 Compression: zstd1551 NarHash: sha256:19jxy83jswbz96r57l7xyrp924wqn117j1xrib1mlyy5h7w90fwx1552 NarSize: 2161553 References: /build/TestClientFallsBackToClosures3921681254/001/store/5lp9bsmljsx0yjg925amw1dwzixw31z4-shared-dep1554 CA: text:sha256:0n7lly22gf6nvi782r1yh1c1pfppd1yvqrprcdpyb8mlwacf6swy1555--- PASS: TestConcurrentPinUpdatesAgree (0.87s)1556=== CONT TestCacheStatsHandler1557=== CONT TestPushDedupSurvivesConcurrentGC1558--- PASS: TestClientPushesUseOnePush (0.65s)1559=== NAME TestClientMultipleUploads1560 client_integration_test.go:467: Created store path 1: /build/TestClientMultipleUploads1810792605/001/store/bkz15wag5iznknpcpavhmp04dp8y6c40-test-file-1.txt15612026/10/27 13:04:04 INFO Received push request method=POST path=/api/pushes15622026/10/27 13:04:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15632026/10/27 13:04:04 INFO Uploading kg7ami94mwvb4qwhfxljy1s8xh1v6999-test-script (136B)1564=== CONT TestGCSweepDeliversEachKeyOnce1565--- PASS: TestClientFallsBackToClosures (0.64s)1566=== NAME TestClientMultipleUploads1567 client_integration_test.go:467: Created store path 2: /build/TestClientMultipleUploads1810792605/001/store/zhwy2a1l19fcpwwpp2ssmmg5dwp3ld9s-test-file-2.txt15682026/10/27 13:04:04 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15692026/10/27 13:04:04 WARN Failed to register uploaded object key=kg7ami94mwvb4qwhfxljy1s8xh1v6999.ls error="server returned 404: 404 page not found\n"15702026/10/27 13:04:04 INFO Received push request method=POST path=/api/pushes15712026/10/27 13:04:04 WARN Failed to register uploaded object key=log/swfzi2z1syi7x7w149i9zjv02dj7yszz-test-script.drv error="server returned 404: 404 page not found\n"15722026/10/27 13:04:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15732026/10/27 13:04:04 INFO Signed narinfos id=1 count=115742026/10/27 13:04:04 INFO Uploading 1 narinfos15752026/10/27 13:04:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15762026/10/27 13:04:04 INFO Uploading gx8mmhyzn57yphsa75ygp9084klg2frq-test-file.txt (152B)15772026/10/27 13:04:04 INFO Received complete push request method=POST path=/api/pushes/1/complete15782026/10/27 13:04:04 WARN Failed to register uploaded object key=kg7ami94mwvb4qwhfxljy1s8xh1v6999.narinfo error="server returned 404: 404 page not found\n"15792026/10/27 13:04:04 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15802026/10/27 13:04:04 INFO Completed push id=1 objects=4 duration=7.352025ms15812026/10/27 13:04:04 WARN Failed to register uploaded object key=gx8mmhyzn57yphsa75ygp9084klg2frq.ls error="server returned 404: 404 page not found\n"15822026/10/27 13:04:04 INFO Upload complete. (120ms)15832026/10/27 13:04:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15842026/10/27 13:04:04 INFO Signed narinfos id=1 count=115852026/10/27 13:04:04 INFO Uploading 1 narinfos15862026/10/27 13:04:04 INFO Received complete push request method=POST path=/api/pushes/1/complete15872026/10/27 13:04:04 WARN Failed to register uploaded object key=gx8mmhyzn57yphsa75ygp9084klg2frq.narinfo error="server returned 404: 404 page not found\n"15882026/10/27 13:04:04 INFO lead: released remote=192.0.2.1:123415892026/10/27 13:04:04 INFO Aborted multipart uploads count=0 kept=015902026/10/27 13:04:04 INFO Completed push id=1 objects=3 duration=6.801801ms15912026/10/27 13:04:04 INFO Upload complete. (79ms)15922026/10/27 13:04:04 WARN Force mode enabled - objects will be deleted immediately without grace period15932026/10/27 13:04: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=01594=== NAME TestClientCADerivations1595 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3544636448/001/store/5bha6p129darvr7dxcgm8hk169wrjwy2-ca-test15962026/10/27 13:04:04 INFO Vacuumed table table=pending_closures15972026/10/27 13:04:04 INFO Vacuumed table table=pending_objects15982026/10/27 13:04:04 INFO Vacuumed table table=multipart_uploads15992026/10/27 13:04:04 INFO Vacuumed table table=closures1600=== NAME TestNARDeduplicationMetadataUploadBug1601 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3731778199/001/store/kl5fcapbwzjaz7wjkygm63q1vpvmgzvx-file1.txt1602=== CONT TestService_ReadScope_PublicByDefault1603--- PASS: TestPushWaitsForSweepHoldingRow (0.91s)1604--- PASS: TestLeadEndsOnShutdown (1.43s)1605=== CONT TestGCAdvisoryLockBlocksConcurrentRun16062026/10/27 13:04:04 INFO Vacuumed table table=objects1607=== NAME TestClientWithDependencies1608 client_integration_test.go:740: Skipping nix copy test - isolated store (/build/TestClientWithDependencies101057100/001/store) requires matching store prefix16092026/10/27 13:04:04 INFO Received push request method=POST path=/api/pushes16102026/10/27 13:04:04 INFO All 1 paths already cached16112026/10/27 13:04:04 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16122026/10/27 13:04:04 INFO Uploading bkz15wag5iznknpcpavhmp04dp8y6c40-test-file-1.txt (160B)16132026/10/27 13:04:04 INFO Uploading yw3bmivlglv0j0y2y3k5z2sqxivymxp0-test-file-0.txt (160B)16142026/10/27 13:04:04 INFO Uploading zhwy2a1l19fcpwwpp2ssmmg5dwp3ld9s-test-file-2.txt (160B)16152026/10/27 13:04:04 INFO Aborted multipart uploads count=0 kept=01616=== NAME TestClientIntegration1617 client_integration_test.go:357: Retrieved narinfo from S3:1618 StorePath: /build/TestClientIntegration67421258/002/store/gx8mmhyzn57yphsa75ygp9084klg2frq-test-file.txt1619 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1620 Compression: zstd1621 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11622 NarSize: 1521623 References: 1624 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11625=== NAME TestClientCADerivations1626 client_ca_test.go:139: Found 1 dependencies (including self)16272026/10/27 13:04:04 WARN Force mode enabled - objects will be deleted immediately without grace period1628=== NAME TestClientIntegration1629 client_integration_test.go:358: Retrieved .ls file from S3 (compressed size: 77 bytes)1630 client_integration_test.go:358: Decompressed .ls content (64 bytes):16312026/10/27 13:04:04 WARN Failed to register uploaded object key=yw3bmivlglv0j0y2y3k5z2sqxivymxp0.ls error="server returned 404: 404 page not found\n"1632 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}16332026/10/27 13:04:04 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"1634--- PASS: TestClientWithDependencies (0.61s)16352026/10/27 13:04: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=01636=== CONT TestGCBugBareHashReferences16372026/10/27 13:04:04 INFO Vacuumed table table=pending_closures16382026/10/27 13:04:04 INFO Vacuumed table table=pending_objects16392026/10/27 13:04:04 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16402026/10/27 13:04:04 WARN Failed to register uploaded object key=zhwy2a1l19fcpwwpp2ssmmg5dwp3ld9s.ls error="server returned 404: 404 page not found\n"16412026/10/27 13:04:04 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16422026/10/27 13:04:04 INFO Vacuumed table table=multipart_uploads16432026/10/27 13:04:04 INFO Vacuumed table table=closures16442026/10/27 13:04:04 INFO Vacuumed table table=objects16452026/10/27 13:04:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16462026/10/27 13:04:04 WARN Failed to register uploaded object key=bkz15wag5iznknpcpavhmp04dp8y6c40.ls error="server returned 404: 404 page not found\n"16472026/10/27 13:04:04 INFO Signed narinfos id=1 count=316482026/10/27 13:04:04 INFO Uploading 3 narinfos16492026/10/27 13:04:04 WARN Failed to register uploaded object key=bkz15wag5iznknpcpavhmp04dp8y6c40.narinfo error="server returned 404: 404 page not found\n"16502026/10/27 13:04:04 WARN Failed to register uploaded object key=zhwy2a1l19fcpwwpp2ssmmg5dwp3ld9s.narinfo error="server returned 404: 404 page not found\n"16512026/10/27 13:04:04 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>16522026/10/27 13:04:04 INFO Received complete push request method=POST path=/api/pushes/1/complete16532026/10/27 13:04:04 WARN Failed to register uploaded object key=yw3bmivlglv0j0y2y3k5z2sqxivymxp0.narinfo error="server returned 404: 404 page not found\n"16542026/10/27 13:04:04 INFO Received uploads request method=POST path=/api/pending_closures16552026/10/27 13:04:04 INFO Completed push id=1 objects=9 duration=7.633789ms16562026/10/27 13:04:04 INFO Upload complete. (91ms)1657=== NAME TestClientMultipleUploads1658 client_integration_test.go:478: Uploaded 3 paths in 122.472878ms16592026/10/27 13:04:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1660--- PASS: TestReadProxyNarinfo (1.22s)1661=== CONT TestChildrenInheritRaisedFileLimit1662=== CONT TestTombstonedObjectOfferedWithoutWaiting1663--- PASS: TestChildrenInheritRaisedFileLimit (0.00s)16642026/10/27 13:04:04 INFO Received push request method=POST path=/api/pushes16652026/10/27 13:04:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16662026/10/27 13:04:04 INFO Uploading kl5fcapbwzjaz7wjkygm63q1vpvmgzvx-file1.txt (160B)1667=== CONT TestPush_CompleteCommitsEveryRoot1668--- PASS: TestGCMetrics (0.27s)16692026/10/27 13:04:04 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLjM1ZmEwY2M5LTBmYzItNGQwZC05YmJlLWY5MDRmNjk5NTk5ZHgxNzkzMTA2MjQzNjA0MjExODYx parts=1016702026/10/27 13:04:04 INFO Received complete push request method=POST path=/api/pushes/2/complete16712026/10/27 13:04:04 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"1672--- PASS: TestCacheStatsHandler (0.21s)1673=== CONT TestLeadElectsOneAndHandsOver16742026/10/27 13:04:04 INFO Completed push id=2 objects=4 duration=3.774914ms1675--- PASS: TestClientMultipleUploads (0.51s)1676=== CONT TestReadRedirectUsesPublicS3URL16772026/10/27 13:04:04 WARN Failed to register uploaded object key=kl5fcapbwzjaz7wjkygm63q1vpvmgzvx.ls error="server returned 404: 404 page not found\n"16782026/10/27 13:04:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16792026/10/27 13:04:04 INFO Signed narinfos id=1 count=11680--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.06s)16812026/10/27 13:04:04 INFO Uploading 1 narinfos1682=== CONT TestReadProxyRangeRequest16832026/10/27 13:04:04 INFO Received complete push request method=POST path=/api/pushes/1/complete16842026/10/27 13:04:04 WARN Failed to register uploaded object key=kl5fcapbwzjaz7wjkygm63q1vpvmgzvx.narinfo error="server returned 404: 404 page not found\n"16852026/10/27 13:04:04 INFO Completed push id=1 objects=3 duration=6.545519ms16862026/10/27 13:04:04 INFO Upload complete. (76ms)1687=== NAME TestNARDeduplicationMetadataUploadBug1688 metadata_upload_test.go:54: Retrieved narinfo from S3:1689 StorePath: /build/TestNARDeduplicationMetadataUploadBug3731778199/001/store/kl5fcapbwzjaz7wjkygm63q1vpvmgzvx-file1.txt1690 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1691 Compression: zstd1692 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1693 NarSize: 1601694 References: 1695 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1696 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1697 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):16982026/10/27 13:04:04 INFO Received push request method=POST path=/api/pushes1699 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1700--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.43s)1701=== CONT TestService_AuthMiddleware_MTLSProxyHeader17022026/10/27 13:04:04 INFO Received uploads request method=POST path=/api/pending_closures17032026/10/27 13:04:04 INFO Object in database but missing from S3 key=gx8mmhyzn57yphsa75ygp9084klg2frq.ls17042026/10/27 13:04:04 WARN Found objects in DB but missing from S3, will re-upload count=117052026/10/27 13:04:04 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17062026/10/27 13:04:04 INFO Received push request method=POST path=/api/pushes17072026/10/27 13:04:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17082026/10/27 13:04:04 INFO Uploading 5bha6p129darvr7dxcgm8hk169wrjwy2-ca-test (144B)17092026/10/27 13:04:04 INFO Received complete push request method=POST path=/api/pushes/2/complete17102026/10/27 13:04:04 WARN Failed to register uploaded object key=gx8mmhyzn57yphsa75ygp9084klg2frq.ls error="server returned 404: 404 page not found\n"17112026-10-27 13:04:04.349 UTC [1259] ERROR: Push does not exist: id=117122026-10-27 13:04:04.349 UTC [1259] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE17132026-10-27 13:04:04.349 UTC [1259] STATEMENT: SELECT commit_push($1)17142026/10/27 13:04:04 INFO Completed push id=2 objects=3 duration=22.713983ms17152026/10/27 13:04:04 INFO Upload complete. (123ms)1716=== NAME TestNARDeduplicationMetadataUploadBug1717 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3731778199/001/store/m12z334062dns73jkshb4bwzp7mcnkh1-file2.txt1718=== NAME TestClientIntegration1719 client_integration_test.go:375: Retrieved .ls file from S3 (compressed size: 62 bytes)1720 client_integration_test.go:375: Decompressed .ls content (49 bytes):1721 {"version":1,"root":{"type":"regular","size":39}}17222026/10/27 13:04:04 WARN Failed to register uploaded object key=5bha6p129darvr7dxcgm8hk169wrjwy2.ls error="server returned 404: 404 page not found\n"17232026/10/27 13:04:04 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"17242026/10/27 13:04:04 WARN Failed to register uploaded object key=log/vr2sqg9n6qdlyxf7qwrpjnpk2rh98lac-ca-test.drv error="server returned 404: 404 page not found\n"17252026/10/27 13:04:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17262026/10/27 13:04:04 INFO Signed narinfos id=1 count=117272026/10/27 13:04:04 INFO Uploading 1 narinfos1728=== CONT TestGracefulShutdownDrainsInflight1729--- PASS: TestConnectSerialisesConcurrentMigrations (1.18s)17302026/10/27 13:04:04 INFO Starting HTTP server address=127.0.0.1:4092117312026/10/27 13:04:04 INFO Shutdown signal received, draining in-flight requests timeout=10s1732--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.20s)1733=== CONT TestIsValidUploadKey1734=== RUN TestIsValidUploadKey/narinfo1735=== PAUSE TestIsValidUploadKey/narinfo1736=== RUN TestIsValidUploadKey/nar_zst1737=== PAUSE TestIsValidUploadKey/nar_zst1738=== RUN TestIsValidUploadKey/nar_xz1739=== PAUSE TestIsValidUploadKey/nar_xz1740=== RUN TestIsValidUploadKey/nar_plain1741=== PAUSE TestIsValidUploadKey/nar_plain1742=== RUN TestIsValidUploadKey/listing1743=== PAUSE TestIsValidUploadKey/listing1744=== RUN TestIsValidUploadKey/build_log1745=== PAUSE TestIsValidUploadKey/build_log1746=== RUN TestIsValidUploadKey/build_log_home-manager_file1747=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1748=== RUN TestIsValidUploadKey/build_log_plus_in_name1749=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1750=== RUN TestIsValidUploadKey/build_log_question_mark1751=== PAUSE TestIsValidUploadKey/build_log_question_mark1752=== RUN TestIsValidUploadKey/build_log_equals1753=== PAUSE TestIsValidUploadKey/build_log_equals1754=== RUN TestIsValidUploadKey/realisation1755=== PAUSE TestIsValidUploadKey/realisation1756=== RUN TestIsValidUploadKey/realisation_plus_in_output1757=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1758=== RUN TestIsValidUploadKey/nix-cache-info1759=== PAUSE TestIsValidUploadKey/nix-cache-info1760=== RUN TestIsValidUploadKey/index.html1761=== PAUSE TestIsValidUploadKey/index.html1762=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1763=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1764=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1765=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1766=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1767=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1768=== RUN TestIsValidUploadKey/traversal1769=== PAUSE TestIsValidUploadKey/traversal1770=== RUN TestIsValidUploadKey/traversal_nar1771=== PAUSE TestIsValidUploadKey/traversal_nar17722026/10/27 13:04:04 INFO Received complete push request method=POST path=/api/pushes/1/complete1773=== RUN TestIsValidUploadKey/absolute1774=== PAUSE TestIsValidUploadKey/absolute1775=== RUN TestIsValidUploadKey/empty_key1776=== PAUSE TestIsValidUploadKey/empty_key1777=== RUN TestIsValidUploadKey/unknown_type1778=== PAUSE TestIsValidUploadKey/unknown_type17792026/10/27 13:04:04 WARN Failed to register uploaded object key=5bha6p129darvr7dxcgm8hk169wrjwy2.narinfo error="server returned 404: 404 page not found\n"1780=== CONT TestReadProxyConditionalGet17812026/10/27 13:04:04 INFO Completed push id=1 objects=4 duration=8.648738ms17822026/10/27 13:04:04 INFO Upload complete. (171ms)1783=== NAME TestClientCADerivations1784 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3544636448/001/store/5bha6p129darvr7dxcgm8hk169wrjwy2-ca-test1785 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1786 Compression: zstd1787 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1788 NarSize: 1441789 References: 1790 Deriver: /build/TestClientCADerivations3544636448/001/store/vr2sqg9n6qdlyxf7qwrpjnpk2rh98lac-ca-test.drv1791 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1792 client_ca_test.go:185: Checking for realisation files in S3...17932026/10/27 13:04:04 INFO Aborted multipart uploads count=0 kept=01794 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1795 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache17962026/10/27 13:04:04 WARN Force mode enabled - objects will be deleted immediately without grace period17972026/10/27 13:04:04 INFO Received push request method=POST path=/api/pushes17982026/10/27 13:04:04 INFO Aborted multipart uploads count=0 kept=01799--- PASS: TestGracefulShutdownDrainsInflight (0.07s)18002026/10/27 13:04:04 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=01801=== CONT TestReadRedirectKeepsNarinfoProxied18022026/10/27 13:04:04 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18032026/10/27 13:04:04 INFO Vacuumed table table=pending_closures18042026/10/27 13:04:04 INFO Vacuumed table table=pending_objects18052026/10/27 13:04:04 INFO Vacuumed table table=multipart_uploads18062026/10/27 13:04:04 INFO Vacuumed table table=closures1807--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.46s)1808=== CONT TestReadProxyOutlastsServerWriteTimeout18092026/10/27 13:04:04 INFO Vacuumed table table=objects18102026/10/27 13:04:04 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=018112026/10/27 13:04:04 INFO Vacuumed table table=pending_closures18122026/10/27 13:04:04 INFO Vacuumed table table=pending_objects18132026/10/27 13:04:04 WARN Failed to register uploaded object key=m12z334062dns73jkshb4bwzp7mcnkh1.ls error="server returned 404: 404 page not found\n"18142026/10/27 13:04:04 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18152026/10/27 13:04:04 INFO Vacuumed table table=multipart_uploads18162026/10/27 13:04:04 INFO Signed narinfos id=2 count=118172026/10/27 13:04:04 INFO Uploading 1 narinfos18182026/10/27 13:04:04 INFO Vacuumed table table=closures18192026/10/27 13:04:04 INFO Vacuumed table table=objects18202026/10/27 13:04:04 INFO Aborted multipart uploads count=0 kept=018212026/10/27 13:04:04 WARN Force mode enabled - objects will be deleted immediately without grace period1822--- PASS: TestGCSweepDeliversEachKeyOnce (0.38s)1823=== CONT TestReadProxyRootRedirectsToIndexHTML18242026/10/27 13:04:04 INFO Received complete push request method=POST path=/api/pushes/2/complete18252026/10/27 13:04: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=018262026/10/27 13:04:04 WARN Failed to register uploaded object key=m12z334062dns73jkshb4bwzp7mcnkh1.narinfo error="server returned 404: 404 page not found\n"1827--- PASS: TestService_ReadScope_PublicByDefault (0.31s)1828=== CONT TestReadProxyDisabled18292026/10/27 13:04:04 INFO Received push request method=POST path=/api/pushes18302026/10/27 13:04:04 INFO Completed push id=2 objects=3 duration=10.270332ms18312026/10/27 13:04:04 INFO Upload complete. (82ms)18322026/10/27 13:04:04 INFO Vacuumed table table=pending_closures1833=== NAME TestNARDeduplicationMetadataUploadBug1834 metadata_upload_test.go:76: Retrieved narinfo from S3:1835 StorePath: /build/TestNARDeduplicationMetadataUploadBug3731778199/001/store/m12z334062dns73jkshb4bwzp7mcnkh1-file2.txt1836 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1837 Compression: zstd1838 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1839 NarSize: 1601840 References: 1841 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf18422026/10/27 13:04:04 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18432026/10/27 13:04:04 INFO Vacuumed table table=pending_objects18442026/10/27 13:04:04 INFO Vacuumed table table=multipart_uploads18452026/10/27 13:04:04 INFO Vacuumed table table=closures1846 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)18472026/10/27 13:04:04 INFO Vacuumed table table=objects1848 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1849 {"version":1,"root":{"type":"regular","size":44}}18502026/10/27 13:04:04 INFO Received complete push request method=POST path=/api/pushes/3/complete18512026/10/27 13:04:04 WARN Failed to register uploaded object key=gx8mmhyzn57yphsa75ygp9084klg2frq.ls error="server returned 404: 404 page not found\n"18522026/10/27 13:04:04 INFO Completed push id=3 objects=3 duration=3.32783ms18532026/10/27 13:04:04 INFO Upload complete. (67ms)1854=== NAME TestClientIntegration1855 client_integration_test.go:392: Retrieved .ls file from S3 (compressed size: 62 bytes)1856 client_integration_test.go:392: Decompressed .ls content (49 bytes):1857 {"version":1,"root":{"type":"regular","size":39}}1858--- PASS: TestPushDedupSurvivesConcurrentGC (0.45s)1859=== CONT TestReadProxyNarinfoAlreadyDecompressed1860--- PASS: TestNARDeduplicationMetadataUploadBug (0.62s)1861=== CONT TestReadProxyInvalidPath1862=== NAME TestClientCADerivations1863 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1864 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1865 error: binary cache 's3://bucket70?endpoint=http://localhost:39805®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3544636448/001/store'1866 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 118672026/10/27 13:04:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18682026/10/27 13:04:04 INFO Received uploads request method=POST path=/api/pending_closures18692026/10/27 13:04:04 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLjQ4NmM4NDE3LTYxZDctNDFmMC1iZDdiLTg0ZGNlMDkzNjg0ZngxNzkzMTA2MjQyODcxMzAwMDU0 parts=1018702026/10/27 13:04:04 INFO Received push request method=POST path=/api/pushes1871--- PASS: TestClientCADerivations (0.69s)1872=== CONT TestProxyWriteTimeout1873=== RUN TestProxyWriteTimeout/narinfo1874=== PAUSE TestProxyWriteTimeout/narinfo1875=== RUN TestProxyWriteTimeout/1_GiB_nar1876=== PAUSE TestProxyWriteTimeout/1_GiB_nar1877=== RUN TestProxyWriteTimeout/10_GiB_nar1878=== PAUSE TestProxyWriteTimeout/10_GiB_nar1879=== RUN TestProxyWriteTimeout/unknown_size1880=== PAUSE TestProxyWriteTimeout/unknown_size1881=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1882=== CONT TestParseSingleRange1883=== RUN TestParseSingleRange/none1884--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.32s)1885=== PAUSE TestParseSingleRange/none1886=== RUN TestParseSingleRange/unknown_unit1887=== PAUSE TestParseSingleRange/unknown_unit1888=== RUN TestParseSingleRange/multi-range_ignored1889=== PAUSE TestParseSingleRange/multi-range_ignored1890=== RUN TestParseSingleRange/malformed_no_dash1891=== PAUSE TestParseSingleRange/malformed_no_dash1892=== RUN TestParseSingleRange/malformed_both_empty1893=== PAUSE TestParseSingleRange/malformed_both_empty1894=== RUN TestParseSingleRange/malformed_end_before_start1895=== PAUSE TestParseSingleRange/malformed_end_before_start1896=== RUN TestParseSingleRange/closed1897=== PAUSE TestParseSingleRange/closed1898=== RUN TestParseSingleRange/open-ended1899=== PAUSE TestParseSingleRange/open-ended1900=== RUN TestParseSingleRange/end_clamped_to_size1901=== PAUSE TestParseSingleRange/end_clamped_to_size1902=== RUN TestParseSingleRange/suffix1903=== PAUSE TestParseSingleRange/suffix1904=== RUN TestParseSingleRange/suffix_exceeds_size1905=== PAUSE TestParseSingleRange/suffix_exceeds_size1906=== RUN TestParseSingleRange/single_byte1907=== PAUSE TestParseSingleRange/single_byte1908=== RUN TestParseSingleRange/start_past_EOF1909=== PAUSE TestParseSingleRange/start_past_EOF1910=== RUN TestParseSingleRange/start_far_past_EOF1911=== PAUSE TestParseSingleRange/start_far_past_EOF1912=== CONT TestPresentNotReportedWhileGCDeletesClosure1913=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1914=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1915=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1916=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1917=== CONT TestGCTaskStore_GetReturnsLatest1918--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1919=== CONT TestPresentRefreshesOnlyStaleClosures19202026/10/27 13:04:04 INFO Received push request method=POST path=/api/pushes19212026/10/27 13:04:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19222026/10/27 13:04:04 INFO Uploading 16965xwiz7glk4lmbgrp3w1vibjlxdcp-lost-commit.txt (152B)19232026/10/27 13:04:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1924=== CONT TestReadProxy404And4291925--- PASS: TestReadProxyRangeRequest (0.37s)19262026/10/27 13:04:04 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"19272026/10/27 13:04:04 INFO lead: acquired remote=192.0.2.1:123419282026/10/27 13:04:04 WARN Failed to register uploaded object key=16965xwiz7glk4lmbgrp3w1vibjlxdcp.ls error="server returned 404: 404 page not found\n"19292026/10/27 13:04:04 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign19302026/10/27 13:04:04 INFO Signed narinfos id=4 count=119312026/10/27 13:04:04 INFO Uploading 1 narinfos19322026/10/27 13:04:04 INFO Received complete push request method=POST path=/api/pushes/4/complete19332026/10/27 13:04:04 WARN Failed to register uploaded object key=16965xwiz7glk4lmbgrp3w1vibjlxdcp.narinfo error="server returned 404: 404 page not found\n"19342026/10/27 13:04:04 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLmVhM2JkNjFmLWNmMjQtNDE0NC1hZjUwLTk5OWRiMGNhZWJmMXgxNzkzMTA2MjQzOTkzOTY2NTEz parts=1019352026/10/27 13:04:04 INFO Completed push id=4 objects=3 duration=3.293329ms19362026/10/27 13:04:04 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:35967/api/pushes/4/complete\": EOF" url=http://127.0.0.1:35967/api/pushes/4/complete1937--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.40s)1938=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19392026/10/27 13:04:04 INFO Received complete multipart upload request method=POST path=/19402026/10/27 13:04:04 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"1941--- PASS: TestGCBugBareHashReferences (0.55s)1942=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19432026/10/27 13:04:04 INFO Received request for more parts method=POST path=/19442026/10/27 13:04:04 INFO Received complete push request method=POST path=/api/pushes/4/complete19452026-10-27 13:04:04.750 UTC [1004] ERROR: Push does not exist: id=419462026-10-27 13:04:04.750 UTC [1004] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE19472026-10-27 13:04:04.750 UTC [1004] STATEMENT: -- name: CommitPush :one1948 SELECT commit_push($1::bigint)::bigint1949 19502026/10/27 13:04:04 WARN Push not found id=419512026/10/27 13:04:04 INFO Upload complete. (193ms)1952=== NAME TestClientIntegration1953 client_integration_test.go:422: Retrieved narinfo from S3:1954 StorePath: /build/TestClientIntegration67421258/002/store/16965xwiz7glk4lmbgrp3w1vibjlxdcp-lost-commit.txt1955 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1956 Compression: zstd1957 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1958 NarSize: 1521959 References: 1960 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1961 client_integration_test.go:425: Testing garbage collection...1962--- PASS: TestReadRedirectUsesPublicS3URL (0.54s)1963=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19642026/10/27 13:04:04 INFO Received uploads request method=POST path=/1965--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.64s)1966=== CONT TestPush_RejectsBadRequests/no_roots19672026/10/27 13:04:04 INFO Received push request method=POST path=/api/pushes1968=== CONT TestPush_RejectsBadRequests/root_not_in_objects19692026/10/27 13:04:04 INFO Received push request method=POST path=/api/pushes1970=== CONT TestPush_RejectsBadRequests/no_objects19712026/10/27 13:04:04 INFO Received push request method=POST path=/api/pushes1972=== CONT TestPush_RejectsBadRequests/bad_root19732026/10/27 13:04:04 INFO Received push request method=POST path=/api/pushes1974=== CONT TestCacheConfigHandler/no_cache_url_configured1975=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1976=== CONT TestCacheConfigHandler/no_signing_keys1977=== CONT TestCacheConfigHandler/full_config,_no_issuer1978=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1979--- PASS: TestCacheConfigHandler (0.00s)1980 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1981 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1982 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1983 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)19842026/10/27 13:04:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures19852026/10/27 13:04:04 INFO Garbage collection started19862026/10/27 13:04:04 INFO Aborted multipart uploads count=0 kept=01987=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1988--- PASS: TestReadProxyDisabled (0.34s)1989--- PASS: TestReadProxyConditionalGet (0.44s)1990=== CONT TestGCEndsOnShutdown/before_the_run1991--- PASS: TestPush_RejectsBadRequests (0.56s)1992 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1993 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1994 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1995 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)19962026/10/27 13:04:04 WARN Force mode enabled - objects will be deleted immediately without grace period1997--- PASS: TestReadRedirectKeepsNarinfoProxied (0.40s)1998=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1999=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete2000--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.38s)20012026/10/27 13:04:04 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=020022026/10/27 13:04:04 INFO Vacuumed table table=pending_closures2003=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info2004--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.37s)20052026/10/27 13:04:04 INFO Received uploads request method=POST path=/2006=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key20072026/10/27 13:04:04 INFO Received request for more parts method=POST path=/2008=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key20092026/10/27 13:04:04 INFO Received complete multipart upload request method=POST path=/2010=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal20112026/10/27 13:04:04 INFO Received uploads request method=POST path=/2012--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2013 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2014 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2015 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2016 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2017=== CONT TestPendingClosureWriteTimeout/400_objects2018=== CONT TestPendingClosureWriteTimeout/670k_objects2019=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline20202026/10/27 13:04:04 INFO Vacuumed table table=pending_objects20212026/10/27 13:04:04 INFO Vacuumed table table=multipart_uploads20222026/10/27 13:04:04 INFO Vacuumed table table=closures2023--- PASS: TestReadProxyInvalidPath (0.38s)2024=== CONT TestPendingClosureWriteTimeout/empty2025=== CONT TestIsValidCachePath/nar_xz2026=== CONT TestIsValidCachePath/invalid_char_u2027=== CONT TestIsValidCachePath/empty2028=== CONT TestIsValidCachePath/nar_uncompressed2029=== CONT TestIsValidCachePath/short_hash2030=== CONT TestIsValidCachePath/random_path2031=== CONT TestIsValidCachePath/traversal_parent2032=== CONT TestIsValidCachePath/leading_slash2033=== CONT TestIsValidCachePath/nar_bz22034=== CONT TestIsValidCachePath/nix-cache-info2035=== CONT TestIsValidCachePath/narinfo2036=== CONT TestIsValidCachePath/wrong_extension2037=== CONT TestIsValidCachePath/ls2038=== CONT TestIsValidCachePath/nar_zst2039=== CONT TestIsValidCachePath/invalid_char_e2040=== CONT TestIsValidCachePath/traversal_in_middle2041=== CONT TestIsValidCachePath/realisation2042=== CONT TestIsValidCachePath/index.html2043=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars20442026/10/27 13:04:04 INFO Vacuumed table table=objects2045=== CONT TestIsValidCachePath/log2046=== CONT TestServerTLSConfig/no_client_CA2047--- PASS: TestIsValidCachePath (0.00s)2048 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2049 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2050 --- PASS: TestIsValidCachePath/empty (0.00s)2051 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2052 --- PASS: TestIsValidCachePath/short_hash (0.00s)2053 --- PASS: TestIsValidCachePath/random_path (0.00s)2054 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2055 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2056 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2057 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2058 --- PASS: TestIsValidCachePath/narinfo (0.00s)2059 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2060 --- PASS: TestIsValidCachePath/ls (0.00s)2061 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2062 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2063 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2064 --- PASS: TestIsValidCachePath/realisation (0.00s)2065 --- PASS: TestIsValidCachePath/index.html (0.00s)2066 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2067 --- PASS: TestIsValidCachePath/log (0.00s)2068=== CONT TestServerTLSConfig/not_a_PEM_file2069=== CONT TestServerTLSConfig/missing_CA_file2070=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2071--- PASS: TestServerTLSConfig (0.00s)2072 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2073 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2074 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2075=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20762026/10/27 13:04:04 INFO Received uploads request method=POST path=/api/pending_closures20772026/10/27 13:04:04 WARN Authentication failed token_preview=eyJhbGciOi...tChDZowBgA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2078=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20792026/10/27 13:04:04 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]2080=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2081=== CONT TestResolveDBConnectionString/flag_wins2082=== CONT TestResolveDBConnectionString/file_when_flag_empty2083=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2084=== CONT TestResolveDBConnectionString/missing_file_is_an_error2085=== CONT TestResolveDBConnectionString/nothing_configured2086=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false2087--- PASS: TestResolveDBConnectionString (0.00s)2088 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2089 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2090 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2091 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2092 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2093--- PASS: TestService_AuthMiddleware_OIDC (0.68s)2094 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2095 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)2096 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2097 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2098=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true2099--- PASS: TestPresentRefreshesOnlyStaleClosures (0.41s)21002026/10/27 13:04:04 INFO Received uploads request method=POST path=/api/pending_closures21012026/10/27 13:04:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21022026/10/27 13:04:05 INFO Aborted multipart uploads count=0 kept=021032026/10/27 13:04:05 WARN Force mode enabled - objects will be deleted immediately without grace period21042026/10/27 13:04:05 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=021052026/10/27 13:04:05 INFO Vacuumed table table=pending_closures21062026/10/27 13:04:05 INFO Vacuumed table table=pending_objects21072026/10/27 13:04:05 INFO Vacuumed table table=multipart_uploads21082026/10/27 13:04:05 INFO Vacuumed table table=closures21092026/10/27 13:04:05 INFO Vacuumed table table=objects21102026/10/27 13:04:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2111=== CONT TestService_RequireScope_OIDC/builder_may_write2112=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2113=== CONT TestService_RequireScope_OIDC/static_token_may_write2114=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2115=== CONT TestService_RequireScope_OIDC/writer_implies_read2116=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2117=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc21182026/10/27 13:04:05 INFO Received uploads request method=POST path=/api/pending_closures2119=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read21202026/10/27 13:04:05 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]2121=== CONT TestService_RequireScope_OIDC/reader_may_read2122=== CONT TestService_RequireScope_OIDC/reader_may_not_write2123=== CONT TestService_RequireScope_OIDC/ops_may_admin2124=== CONT TestService_RequireScope_OIDC/static_token_may_admin2125=== CONT TestService_RequireScope_OIDC/ops_may_not_write2126=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2127=== CONT TestClientErrorHandling/InvalidStorePath21282026/10/27 13:04:05 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLmI1OTk5YmFiLWU0NDctNGJkMy05NjkzLWExMmVkYjQxMmUwNHgxNzkzMTA2MjQyODcxNDM0MTE1 parts=1021292026/10/27 13:04:05 INFO Aborted multipart uploads count=0 kept=021302026/10/27 13:04:05 WARN Force mode enabled - objects will be deleted immediately without grace period2131=== CONT TestClientErrorHandling/ServerNotAvailable2132--- PASS: TestService_RequireScope_OIDC (0.65s)2133 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2134 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2135 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2136 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2137 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2138 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2139 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2140 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2141 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2142 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2143 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2144 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2145 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2146 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)21472026/10/27 13:04:05 INFO Aborted multipart uploads count=0 kept=021482026/10/27 13:04:05 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=021492026/10/27 13:04:05 INFO Vacuumed table table=pending_closures21502026/10/27 13:04:05 INFO Vacuumed table table=pending_objects21512026/10/27 13:04:05 INFO Vacuumed table table=multipart_uploads21522026/10/27 13:04:05 INFO Vacuumed table table=closures21532026/10/27 13:04:05 WARN Force mode enabled - objects will be deleted immediately without grace period21542026/10/27 13:04:05 INFO Vacuumed table table=objects21552026/10/27 13:04:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21562026-10-27 13:04:05.101 UTC [2027] ERROR: canceling statement due to user request21572026-10-27 13:04:05.101 UTC [2027] CONTEXT: SQL statement "UPDATE object_stats s2158 SET object_count = s.object_count + n.n - o.n,2159 total_bytes = s.total_bytes + n.bytes - o.bytes2160 FROM (2161 SELECT count(*) AS n, coalesce(sum(size), 0) AS bytes2162 FROM new_rows WHERE deleted_at IS NULL2163 ) AS n,2164 (2165 SELECT count(*) AS n, coalesce(sum(size), 0) AS bytes2166 FROM old_rows WHERE deleted_at IS NULL2167 ) AS o2168 WHERE s.id AND (n.n <> o.n OR n.bytes <> o.bytes)"2169 PL/pgSQL function object_stats_update() line 3 at SQL statement21702026-10-27 13:04:05.101 UTC [2027] STATEMENT: -- name: MarkStaleObjects :execrows2171 WITH RECURSIVE ct AS (2172 SELECT timezone('UTC', now()) AS now2173 ),2174 closure_reach AS (2175 -- Start with all closure keys2176 SELECT o.key, o.refs2177 FROM objects o2178 INNER JOIN closures c ON o.key = c.key2179 UNION2180 -- Recursively add all referenced objects2181 SELECT o.key, o.refs2182 FROM objects o2183 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2184 ),2185 reachable_objects AS (2186 SELECT DISTINCT key FROM closure_reach2187 ),2188 stale_objects AS (2189 SELECT o.key2190 FROM objects AS o, ct2191 WHERE2192 NOT EXISTS (2193 SELECT 12194 FROM reachable_objects ro2195 WHERE ro.key = o.key2196 )2197 AND NOT EXISTS (2198 SELECT 12199 FROM pending_objects AS po2200 WHERE po.key = o.key2201 )2202 AND o.deleted_at IS NULL -- Only mark fresh objects2203 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2204 FOR UPDATE2205 )2206 UPDATE objects2207 SET2208 deleted_at = ct.now,2209 first_deleted_at = COALESCE(first_deleted_at, ct.now)2210 FROM stale_objects, ct2211 WHERE objects.key = stale_objects.key2212 22132026/10/27 13:04:05 INFO Aborted multipart uploads count=0 kept=022142026/10/27 13:04:05 WARN Force mode enabled - objects will be deleted immediately without grace period2215=== CONT TestClientErrorHandling/InvalidAuthToken2216--- PASS: TestDeleteClosuresRacingPins (1.91s)22172026/10/27 13:04:05 INFO Received uploads request method=POST path=/api/pending_closures22182026/10/27 13:04:05 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLjE5MWU1NDIyLTkzMzEtNDJlMS04YzlmLTZmYjAzYjJlODY3NngxNzkzMTA2MjQ0NTQ3MjA2NTMw parts=1022192026/10/27 13:04:05 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:39805/bucket101/?delete=\": context canceled"2220=== CONT TestIsValidUploadKey/nar_zst2221=== CONT TestIsValidUploadKey/nix-cache-info2222=== CONT TestIsValidUploadKey/realisation_plus_in_output2223=== CONT TestIsValidUploadKey/build_log_plus_in_name2224=== CONT TestIsValidUploadKey/unknown_type2225=== CONT TestIsValidUploadKey/build_log2226=== CONT TestIsValidUploadKey/absolute2227=== CONT TestIsValidUploadKey/listing2228=== CONT TestIsValidUploadKey/traversal2229=== CONT TestIsValidUploadKey/realisation2230=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2231=== CONT TestIsValidUploadKey/empty_key2232=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2233=== CONT TestIsValidUploadKey/nar_xz2234=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2235=== CONT TestIsValidUploadKey/traversal_nar2236=== CONT TestIsValidUploadKey/narinfo2237=== CONT TestIsValidUploadKey/nar_plain2238=== CONT TestIsValidUploadKey/index.html2239=== CONT TestIsValidUploadKey/build_log_equals2240=== CONT TestIsValidUploadKey/build_log_question_mark2241=== CONT TestIsValidUploadKey/build_log_home-manager_file2242=== CONT TestProxyWriteTimeout/unknown_size2243=== CONT TestProxyWriteTimeout/1_GiB_nar2244--- PASS: TestIsValidUploadKey (0.00s)2245 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2246 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2247 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2248 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2249 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2250 --- PASS: TestIsValidUploadKey/build_log (0.00s)2251 --- PASS: TestIsValidUploadKey/absolute (0.00s)2252 --- PASS: TestIsValidUploadKey/listing (0.00s)2253 --- PASS: TestIsValidUploadKey/traversal (0.00s)2254 --- PASS: TestIsValidUploadKey/realisation (0.00s)2255 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2256 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2257 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2258 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2259 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2260 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2261 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2262 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2263 --- PASS: TestIsValidUploadKey/index.html (0.00s)2264 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2265 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2266 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2267=== CONT TestProxyWriteTimeout/10_GiB_nar2268=== CONT TestProxyWriteTimeout/narinfo2269=== CONT TestParseSingleRange/none2270--- PASS: TestProxyWriteTimeout (0.00s)2271 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2272 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2273 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2274 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2275=== CONT TestParseSingleRange/open-ended2276=== CONT TestParseSingleRange/start_far_past_EOF2277=== CONT TestParseSingleRange/single_byte2278=== CONT TestParseSingleRange/suffix_exceeds_size2279=== CONT TestParseSingleRange/start_past_EOF2280=== CONT TestParseSingleRange/end_clamped_to_size2281=== CONT TestParseSingleRange/suffix2282=== CONT TestParseSingleRange/malformed_both_empty2283=== CONT TestParseSingleRange/malformed_end_before_start2284=== CONT TestParseSingleRange/closed2285=== CONT TestParseSingleRange/unknown_unit2286=== CONT TestParseSingleRange/malformed_no_dash2287=== CONT TestParseSingleRange/multi-range_ignored2288=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale22892026/10/27 13:04:05 INFO Received uploads request method=POST path=/api/pending_closures2290--- PASS: TestParseSingleRange (0.00s)2291 --- PASS: TestParseSingleRange/none (0.00s)2292 --- PASS: TestParseSingleRange/open-ended (0.00s)2293 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2294 --- PASS: TestParseSingleRange/single_byte (0.00s)2295 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2296 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2297 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2298 --- PASS: TestParseSingleRange/suffix (0.00s)2299 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2300 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2301 --- PASS: TestParseSingleRange/closed (0.00s)2302 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2303 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2304 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)23052026/10/27 13:04:05 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/present2306=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh2307--- PASS: TestGCEndsOnShutdown (0.00s)2308 --- PASS: TestGCEndsOnShutdown/before_the_run (0.23s)2309 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.29s)2310 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.30s)2311--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2312 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.27s)2313 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.33s)23142026/10/27 13:04:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23152026-10-27 13:04:05.172 UTC [177] LOG: checkpoints are occurring too frequently (9 seconds apart)23162026-10-27 13:04:05.172 UTC [177] HINT: Consider increasing the configuration parameter "max_wal_size".23172026-10-27 13:04:05.173 UTC [177] LOG: checkpoint starting: wal23182026/10/27 13:04:05 INFO Received uploads request method=POST path=/api/pending_closures23192026/10/27 13:04:05 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLmI5ZDQ2YTZmLTAyNTItNDNlYy05NTkxLTA1ZTA0MjdmZGNhNHgxNzkzMTA2MjQzOTkwNzY2MjQ0 parts=1023202026/10/27 13:04:05 INFO Received complete push request method=POST path=/api/pushes/1/complete23212026/10/27 13:04:05 INFO Completed push id=1 objects=4 duration=7.284345ms23222026/10/27 13:04:05 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete23232026/10/27 13:04:05 INFO Completed upload id=2 objects=2 duration=1.764035ms23242026/10/27 13:04:05 WARN Request failed, retrying attempt=2 backoff=187.428663ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23252026/10/27 13:04:05 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=023262026/10/27 13:04:05 INFO Received create pin request method=POST path=/api/pins/myapp2327--- PASS: TestMetricsCommit (1.46s)23282026/10/27 13:04:05 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3301523025/001/store/p4pq2sb200k51m5ydih23f2079allm57-pinned-file.txt narinfo_key=p4pq2sb200k51m5ydih23f2079allm57.narinfo23292026/10/27 13:04:05 INFO Starting cleanup of old closures method=DELETE path=/api/closures23302026/10/27 13:04:05 INFO Garbage collection started23312026/10/27 13:04:05 INFO Aborted multipart uploads count=0 kept=023322026/10/27 13:04:05 WARN Force mode enabled - objects will be deleted immediately without grace period23332026/10/27 13:04:05 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=023342026/10/27 13:04:05 INFO Vacuumed table table=pending_closures23352026/10/27 13:04:05 INFO Vacuumed table table=pending_objects23362026/10/27 13:04:05 INFO Vacuumed table table=multipart_uploads23372026/10/27 13:04:05 INFO Vacuumed table table=closures23382026/10/27 13:04:05 INFO Vacuumed table table=objects23392026/10/27 13:04:05 WARN Rate limiter enabled after throttle name=s3-test rate=523402026/10/27 13:04:05 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."23412026/10/27 13:04:05 WARN Rate limiter backed off name=s3-test rate=523422026/10/27 13:04:05 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."2343--- PASS: TestReadProxy404And429 (0.72s)23442026/10/27 13:04:05 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"23452026/10/27 13:04:05 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"23462026/10/27 13:04:05 WARN Request failed, retrying attempt=3 backoff=396.713785ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23472026/10/27 13:04:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23482026/10/27 13:04:05 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLmUyMzJhZGRmLWVkOWEtNGM2Yy1hYjU2LWI2MWQyZjBhNzY5NngxNzkzMTA2MjQyODcxMjM1NzM0 parts=1023492026/10/27 13:04:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23502026/10/27 13:04:05 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLjBlNzhjODAyLTBmNmItNGQ5ZS1hOWFjLWExYWQzYWUyNmNkM3gxNzkzMTA2MjQ0NTQ3OTcwNjE3 parts=102351=== NAME TestOrphanedObjectsGCStressTest2352 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2353 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion23542026/10/27 13:04:05 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLjRiNTM5MDE4LWQ4NmYtNDUyYS1hNDMyLTIxNjZhM2E4ODJkM3gxNzkzMTA2MjQ1MTg4ODA1Mzk5 error="Access Denied"23552026/10/27 13:04:05 WARN keeping failed pending closure for cleanup to retry the abort id=12356--- PASS: TestPendingClosureFailureTracksEveryUpload (0.00s)2357 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (0.78s)2358 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (0.76s)23592026/10/27 13:04:05 INFO lead: released remote=192.0.2.1:123423602026/10/27 13:04:05 WARN Request failed, retrying attempt=4 backoff=756.278431ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2361--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2362 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.68s)2363 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.71s)23642026/10/27 13:04:05 INFO lead: acquired remote=192.0.2.1:12342365--- PASS: TestPendingClosureWriteTimeout (0.00s)2366 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2367 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2368 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2369 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.07s)23702026/10/27 13:04:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23712026/10/27 13:04:05 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLmMyMmI4Mjk5LTU4NzItNDY4ZS05MmZjLTFhODMzMDFiMTJlZXgxNzkzMTA2MjQyODcwNTcwOTY4 parts=1023722026-10-27 13:04:05.988 UTC [630] ERROR: could not obtain lock on row in relation "closures"23732026-10-27 13:04:05.988 UTC [630] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23742026-10-27 13:04:05.989 UTC [630] ERROR: could not obtain lock on row in relation "closures"23752026-10-27 13:04:05.989 UTC [630] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23762026-10-27 13:04:05.989 UTC [630] ERROR: could not obtain lock on row in relation "closures"23772026-10-27 13:04:05.989 UTC [630] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23782026-10-27 13:04:05.990 UTC [630] ERROR: could not obtain lock on row in relation "closures"23792026-10-27 13:04:05.990 UTC [630] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23802026-10-27 13:04:05.990 UTC [630] ERROR: could not obtain lock on row in relation "closures"23812026-10-27 13:04:05.990 UTC [630] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT2382--- PASS: TestPush_RootsAreLockedInByteOrder (3.63s)23832026/10/27 13:04:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23842026/10/27 13:04:06 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=OTc3NWQ1NGItMzE5MC00NmE4LWE4NGYtZWY2NGVlYjdkOTdjLjY0NmVmOTE0LTYzY2YtNDM2Ni04MGUyLTEyNmVjODMwNTdjNHgxNzkzMTA2MjQ0NTQ4MDQyNDk3 parts=1023852026/10/27 13:04:06 INFO Received complete push request method=POST path=/api/pushes/1/complete23862026/10/27 13:04:06 INFO Completed push id=1 objects=6 duration=5.127726ms2387--- PASS: TestPush_CompleteCommitsEveryRoot (1.86s)2388=== NAME TestOrphanedObjectsGCStressTest2389 orphaned_objects_gc_test.go:503: Stress test completed successfully:2390 orphaned_objects_gc_test.go:504: - Active objects preserved: 202391 orphaned_objects_gc_test.go:505: - Objects deleted: 2102392 orphaned_objects_gc_test.go:506: - Total GC'd: 2102393--- PASS: TestOrphanedObjectsGCStressTest (3.22s)23942026/10/27 13:04:06 WARN Request failed, retrying attempt=5 backoff=1.509856504s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23952026/10/27 13:04:06 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02396=== NAME TestClientIntegration2397 client_integration_test.go:432: Objects in database after GC:2398 client_integration_test.go:432: Successfully deleted all objects with GC --force2399--- PASS: TestClientIntegration (3.10s)24002026/10/27 13:04:06 INFO lead: released remote=192.0.2.1:12342401--- PASS: TestLeadElectsOneAndHandsOver (2.71s)24022026/10/27 13:04:06 WARN Rate limiter enabled after throttle name=s3-test rate=524032026/10/27 13:04:06 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2404=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2405 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102406 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002407--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (2.46s)2408--- PASS: TestConnectWaitsForAPeerMigration (5.34s)2409=== NAME TestPinProtectsFromGC2410 client_integration_test.go:963: Pin successfully protected closure from garbage collection2411--- PASS: TestPinProtectsFromGC (4.91s)24122026/10/27 13:04:08 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-config24132026/10/27 13:04:08 WARN Request failed, retrying attempt=2 backoff=214.306856ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24142026/10/27 13:04:08 WARN Request failed, retrying attempt=3 backoff=387.333035ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24152026/10/27 13:04:08 WARN Request failed, retrying attempt=4 backoff=806.118729ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2416--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.63s)24172026/10/27 13:04:09 WARN Request failed, retrying attempt=5 backoff=1.698551998s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24182026/10/27 13:04:09 INFO Aborted multipart uploads count=1 kept=024192026/10/27 13:04:09 INFO Received cleanup request method=DELETE path=/api/pending_closures24202026/10/27 13:04:09 INFO Aborted multipart uploads count=1 kept=02421--- PASS: TestPendingCleanupUsesOneCutoff (6.41s)24222026/10/27 13:04:11 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"24232026/10/27 13:04:11 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-config24242026/10/27 13:04:11 WARN Request failed, retrying attempt=2 backoff=218.913816ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24252026/10/27 13:04:11 WARN Request failed, retrying attempt=3 backoff=381.675763ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24262026/10/27 13:04:12 WARN Request failed, retrying attempt=4 backoff=804.821994ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24272026/10/27 13:04:12 WARN Request failed, retrying attempt=5 backoff=1.5500973s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24282026/10/27 13:04:14 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_closures24292026/10/27 13:04:14 WARN Request failed, retrying attempt=2 backoff=200.416506ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24302026/10/27 13:04:14 WARN Request failed, retrying attempt=3 backoff=439.534989ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24312026/10/27 13:04:15 WARN Request failed, retrying attempt=4 backoff=847.955553ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24322026/10/27 13:04:16 WARN Request failed, retrying attempt=5 backoff=1.451327492s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2433--- PASS: TestUploadHandlersRejectOversizedBody (0.50s)2434 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.80s)2435 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.86s)2436 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (12.63s)2437--- PASS: TestClientErrorHandling (0.00s)2438 --- PASS: TestClientErrorHandling/InvalidStorePath (0.23s)2439 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.30s)2440 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.41s)2441PASS2442{"timestamp":"2026-10-27T13:04:17.477021995Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:41536","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(207)"}2443{"timestamp":"2026-10-27T13:04:17.477024775Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:41670","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(198)"}24442026-10-27 13:04:17.757 UTC [172] LOG: received smart shutdown request24452026-10-27 13:04:17.762 UTC [172] LOG: background worker "logical replication launcher" (PID 182) exited with exit code 124462026-10-27 13:04:18.711 UTC [177] LOG: checkpoint complete: wrote 9525 buffers (58.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=12.780 s, sync=0.705 s, total=13.538 s; sync files=37079, longest=0.002 s, average=0.001 s; distance=534766 kB, estimate=534766 kB; lsn=0/22A14868, redo lsn=0/221A16C824472026-10-27 13:04:18.716 UTC [177] LOG: shutting down24482026-10-27 13:04:18.716 UTC [177] LOG: checkpoint starting: shutdown immediate24492026-10-27 13:04:18.786 UTC [177] LOG: checkpoint complete: wrote 1123 buffers (6.9%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.022 s, sync=0.046 s, total=0.070 s; sync files=416, longest=0.001 s, average=0.001 s; distance=8652 kB, estimate=482155 kB; lsn=0/22A148E0, redo lsn=0/22A148E024502026-10-27 13:04:18.871 UTC [172] LOG: database system is shut down2451Running OIDC tests...2452=== RUN TestAudienceForIssuer2453=== PAUSE TestAudienceForIssuer2454=== RUN TestHTTPClientForHasTimeouts2455=== PAUSE TestHTTPClientForHasTimeouts2456=== RUN TestGlobMatch2457=== PAUSE TestGlobMatch2458=== RUN TestValidateToken_ValidToken2459=== PAUSE TestValidateToken_ValidToken2460=== RUN TestValidateToken_WrongAudience2461=== PAUSE TestValidateToken_WrongAudience2462=== RUN TestValidateToken_Expired2463=== PAUSE TestValidateToken_Expired2464=== RUN TestValidateToken_BoundClaimsMismatch2465=== PAUSE TestValidateToken_BoundClaimsMismatch2466=== RUN TestValidateToken_BoundSubjectMismatch2467=== PAUSE TestValidateToken_BoundSubjectMismatch2468=== RUN TestValidateToken_MultipleProviders2469=== PAUSE TestValidateToken_MultipleProviders2470=== RUN TestValidateToken_NoMatchingProvider2471=== PAUSE TestValidateToken_NoMatchingProvider2472=== RUN TestValidateToken_KubernetesServiceAccount2473=== PAUSE TestValidateToken_KubernetesServiceAccount2474=== RUN TestNewValidator_KubernetesRequiresCA2475=== PAUSE TestNewValidator_KubernetesRequiresCA2476=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2477=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2478=== RUN TestPins_ReservedForMatchingRule2479=== PAUSE TestPins_ReservedForMatchingRule2480=== RUN TestPins_TopLevelShorthand2481=== PAUSE TestPins_TopLevelShorthand2482=== RUN TestPins_ConfigValidation2483=== PAUSE TestPins_ConfigValidation2484=== RUN TestScopes_LegacyProviderDefaultsToWrite2485=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2486=== RUN TestScopes_Rules2487=== PAUSE TestScopes_Rules2488=== RUN TestScopes_ConfigValidation2489=== PAUSE TestScopes_ConfigValidation2490=== CONT TestValidateToken_ValidToken2491=== CONT TestPins_ConfigValidation2492=== CONT TestAudienceForIssuer2493=== CONT TestValidateToken_MultipleProviders2494=== CONT TestPins_TopLevelShorthand2495--- PASS: TestAudienceForIssuer (0.00s)2496=== CONT TestScopes_ConfigValidation2497=== CONT TestScopes_LegacyProviderDefaultsToWrite2498=== CONT TestScopes_Rules2499=== CONT TestGlobMatch2500=== RUN TestGlobMatch/foo_foo2501=== CONT TestValidateToken_WrongAudience2502=== PAUSE TestGlobMatch/foo_foo2503=== RUN TestGlobMatch/foo_bar2504=== PAUSE TestGlobMatch/foo_bar2505=== RUN TestGlobMatch/*_2506=== PAUSE TestGlobMatch/*_2507=== RUN TestGlobMatch/*_anything2508=== PAUSE TestGlobMatch/*_anything2509=== RUN TestGlobMatch/foo*_foo2510=== PAUSE TestGlobMatch/foo*_foo2511=== RUN TestGlobMatch/foo*_foobar2512=== PAUSE TestGlobMatch/foo*_foobar2513=== RUN TestGlobMatch/foo*_bar2514--- PASS: TestPins_ConfigValidation (0.00s)2515=== PAUSE TestGlobMatch/foo*_bar2516=== RUN TestGlobMatch/*bar_bar2517=== CONT TestHTTPClientForHasTimeouts2518=== CONT TestValidateToken_BoundSubjectMismatch2519=== CONT TestValidateToken_NoMatchingProvider2520=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2521=== CONT TestPins_ReservedForMatchingRule2522--- PASS: TestScopes_ConfigValidation (0.01s)2523=== CONT TestNewValidator_KubernetesRequiresCA2524=== CONT TestValidateToken_BoundClaimsMismatch2525=== CONT TestValidateToken_KubernetesServiceAccount2526=== CONT TestValidateToken_Expired2527=== PAUSE TestGlobMatch/*bar_bar2528=== RUN TestGlobMatch/*bar_foobar2529=== PAUSE TestGlobMatch/*bar_foobar2530=== RUN TestGlobMatch/*bar_foo2531=== PAUSE TestGlobMatch/*bar_foo2532=== RUN TestGlobMatch/foo*bar_foobar2533=== PAUSE TestGlobMatch/foo*bar_foobar2534=== RUN TestGlobMatch/foo*bar_foo123bar2535=== PAUSE TestGlobMatch/foo*bar_foo123bar2536=== RUN TestGlobMatch/foo*bar_foobarbaz2537=== PAUSE TestGlobMatch/foo*bar_foobarbaz2538=== RUN TestGlobMatch/*/*_foo/bar2539=== PAUSE TestGlobMatch/*/*_foo/bar2540=== RUN TestGlobMatch/*/*_foo2541=== PAUSE TestGlobMatch/*/*_foo2542=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2543=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2544=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02545=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02546=== RUN TestGlobMatch/refs/*/main_refs/heads/main2547=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2548=== RUN TestGlobMatch/fo?_foo2549=== PAUSE TestGlobMatch/fo?_foo2550=== RUN TestGlobMatch/fo?_fo2551=== PAUSE TestGlobMatch/fo?_fo2552=== RUN TestGlobMatch/fo?_fooo2553=== PAUSE TestGlobMatch/fo?_fooo2554=== RUN TestGlobMatch/?oo_foo2555=== PAUSE TestGlobMatch/?oo_foo2556=== RUN TestGlobMatch/?oo_boo2557=== PAUSE TestGlobMatch/?oo_boo2558=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2559=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2560=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2561=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2562=== CONT TestGlobMatch/foo_foo2563=== CONT TestGlobMatch/?oo_foo2564=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2565=== CONT TestGlobMatch/foo*bar_foo123bar2566=== CONT TestGlobMatch/?oo_boo2567=== CONT TestGlobMatch/*_anything2568=== CONT TestGlobMatch/*bar_foo2569=== CONT TestGlobMatch/foo*_bar2570=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2571=== CONT TestGlobMatch/*bar_bar2572=== CONT TestGlobMatch/foo*bar_foobarbaz2573=== CONT TestGlobMatch/*/*_foo/bar2574=== CONT TestGlobMatch/fo?_fo2575=== CONT TestGlobMatch/*/*_foo2576=== CONT TestGlobMatch/*bar_foobar2577=== CONT TestGlobMatch/*_2578=== CONT TestGlobMatch/foo*_foo2579=== CONT TestGlobMatch/foo*bar_foobar2580=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2581=== CONT TestGlobMatch/fo?_foo2582=== CONT TestGlobMatch/refs/*/main_refs/heads/main2583=== CONT TestGlobMatch/fo?_fooo2584=== CONT TestGlobMatch/foo_bar2585=== CONT TestGlobMatch/foo*_foobar2586=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02587--- PASS: TestGlobMatch (0.01s)2588 --- PASS: TestGlobMatch/foo_foo (0.00s)2589 --- PASS: TestGlobMatch/?oo_foo (0.00s)2590 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2591 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2592 --- PASS: TestGlobMatch/*_anything (0.00s)2593 --- PASS: TestGlobMatch/*bar_foo (0.00s)2594 --- PASS: TestGlobMatch/?oo_boo (0.00s)2595 --- PASS: TestGlobMatch/foo*_bar (0.00s)2596 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2597 --- PASS: TestGlobMatch/*bar_bar (0.00s)2598 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2599 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2600 --- PASS: TestGlobMatch/fo?_fo (0.00s)2601 --- PASS: TestGlobMatch/*/*_foo (0.00s)2602 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2603 --- PASS: TestGlobMatch/*_ (0.00s)2604 --- PASS: TestGlobMatch/foo*_foo (0.00s)2605 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2606 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2607 --- PASS: TestGlobMatch/fo?_foo (0.00s)2608 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2609 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2610 --- PASS: TestGlobMatch/foo_bar (0.00s)2611 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2612 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)26132026/10/27 13:04:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34635/oidc2614--- PASS: TestPins_TopLevelShorthand (0.06s)26152026/10/27 13:04:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37017/oidc2616--- PASS: TestValidateToken_BoundClaimsMismatch (0.06s)26172026/10/27 13:04:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33737/oidc2618--- PASS: TestScopes_Rules (0.14s)26192026/10/27 13:04:22 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:410032620--- PASS: TestValidateToken_KubernetesServiceAccount (0.15s)26212026/10/27 13:04:22 http: TLS handshake error from 127.0.0.1:48074: remote error: tls: bad certificate2622--- PASS: TestNewValidator_KubernetesRequiresCA (0.15s)26232026/10/27 13:04:22 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37737/oidc26242026/10/27 13:04:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33727/oidc2625--- PASS: TestValidateToken_NoMatchingProvider (0.18s)2626--- PASS: TestValidateToken_Expired (0.18s)26272026/10/27 13:04:22 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12326282026/10/27 13:04:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39913/oidc2629--- PASS: TestValidateToken_BoundSubjectMismatch (0.31s)2630--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.32s)2631--- PASS: TestHTTPClientForHasTimeouts (0.41s)26322026/10/27 13:04:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34875/oidc2633--- PASS: TestValidateToken_WrongAudience (0.45s)26342026/10/27 13:04:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36623/oidc2635--- PASS: TestPins_ReservedForMatchingRule (0.47s)26362026/10/27 13:04:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44373/oidc2637--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.51s)26382026/10/27 13:04:22 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:43729/oidc26392026/10/27 13:04:22 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:35285/oidc2640--- PASS: TestValidateToken_MultipleProviders (0.56s)26412026/10/27 13:04:22 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45859/oidc2642--- PASS: TestValidateToken_ValidToken (0.64s)2643PASS2644Running hook tests...2645=== RUN TestSendPathsEmpty2646=== PAUSE TestSendPathsEmpty2647=== RUN TestQueueEnqueueAndFetch2648=== PAUSE TestQueueEnqueueAndFetch2649=== RUN TestQueueDeduplication2650=== PAUSE TestQueueDeduplication2651=== RUN TestQueueRemove2652=== PAUSE TestQueueRemove2653=== RUN TestQueueFetchBatchLimit2654=== PAUSE TestQueueFetchBatchLimit2655=== RUN TestQueueRetryMovesToBack2656=== PAUSE TestQueueRetryMovesToBack2657=== RUN TestQueueFetchRemoveLifecycle2658=== PAUSE TestQueueFetchRemoveLifecycle2659=== RUN TestQueueConcurrentWriters2660=== PAUSE TestQueueConcurrentWriters2661=== RUN TestQueueRemoveLargeClosure2662=== PAUSE TestQueueRemoveLargeClosure2663=== RUN TestServerClientIntegration2664--- PASS: TestServerClientIntegration (0.00s)2665=== RUN TestServerQueueError26662026/10/27 13:04:23 ERROR Failed to queue paths error="permission denied" count=12667--- PASS: TestServerQueueError (0.00s)2668=== RUN TestServerRefusesOversizedAndNonStoreRequests2669=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2670=== RUN TestGetListenerSocketActivation2671 server_test.go:309: === RUN TestGetListenerSocketActivation2672 --- PASS: TestGetListenerSocketActivation (0.00s)2673 PASS2674 2675--- PASS: TestGetListenerSocketActivation (1.02s)2676=== RUN TestServerStalledClientDoesNotBlockShutdown2677=== PAUSE TestServerStalledClientDoesNotBlockShutdown2678=== RUN TestServerBacksOffOnAcceptErrors2679=== PAUSE TestServerBacksOffOnAcceptErrors2680=== RUN TestDrainIsolatesPoisonPath2681=== PAUSE TestDrainIsolatesPoisonPath2682=== RUN TestRunNotBlockedByPoisonHead2683=== PAUSE TestRunNotBlockedByPoisonHead2684=== RUN TestDrainGivesUpWhenServerDown2685=== PAUSE TestDrainGivesUpWhenServerDown2686=== RUN TestFailedPathPrunedByLaterClosure2687=== PAUSE TestFailedPathPrunedByLaterClosure2688=== RUN TestWorkerUploadsAndRemoves2689=== PAUSE TestWorkerUploadsAndRemoves2690=== RUN TestWorkerSkipsGCdPaths2691=== PAUSE TestWorkerSkipsGCdPaths2692=== RUN TestWorkerPrunesClosureDeps2693=== PAUSE TestWorkerPrunesClosureDeps2694=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2695=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2696=== RUN TestDrainTimeout2697=== PAUSE TestDrainTimeout2698=== RUN TestDrainTimeoutDuringIsolation2699=== PAUSE TestDrainTimeoutDuringIsolation2700=== RUN TestShutdownFinishesInFlightPush2701=== PAUSE TestShutdownFinishesInFlightPush2702=== RUN TestWorkerRemoveFailureIsNotProgress2703=== PAUSE TestWorkerRemoveFailureIsNotProgress2704=== RUN TestWorkerKeepsPathItCannotStat2705=== PAUSE TestWorkerKeepsPathItCannotStat2706=== CONT TestSendPathsEmpty2707=== CONT TestRunNotBlockedByPoisonHead2708=== CONT TestDrainTimeout2709=== CONT TestShutdownFinishesInFlightPush2710=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2711=== CONT TestQueueFetchRemoveLifecycle2712=== CONT TestQueueFetchBatchLimit2713=== CONT TestWorkerKeepsPathItCannotStat2714=== CONT TestServerBacksOffOnAcceptErrors2715=== CONT TestWorkerRemoveFailureIsNotProgress2716=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2717=== CONT TestQueueEnqueueAndFetch2718=== CONT TestDrainGivesUpWhenServerDown2719=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2720=== CONT TestDrainTimeoutDuringIsolation2721=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short27222026/10/27 13:04:24 ERROR Accept failed error="too many open files"2723=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2724=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2725=== CONT TestServerStalledClientDoesNotBlockShutdown2726=== CONT TestWorkerPrunesClosureDeps2727=== CONT TestFailedPathPrunedByLaterClosure2728=== CONT TestDrainIsolatesPoisonPath2729=== CONT TestQueueRemove2730=== CONT TestQueueRemoveLargeClosure2731=== CONT TestQueueRetryMovesToBack2732=== CONT TestQueueDeduplication2733=== CONT TestWorkerUploadsAndRemoves2734--- PASS: TestSendPathsEmpty (0.00s)2735=== CONT TestServerRefusesOversizedAndNonStoreRequests2736=== CONT TestWorkerSkipsGCdPaths2737=== CONT TestQueueConcurrentWriters2738=== RUN TestShutdownFinishesInFlightPush/completes2739=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2740=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2741=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2742=== PAUSE TestShutdownFinishesInFlightPush/completes2743=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2744=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2745=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short2746=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2747=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2748=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths27492026/10/27 13:04:24 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2750=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout27512026/10/27 13:04:24 ERROR Refusing path outside the store path=/nix/store store=/nix/store27522026/10/27 13:04:24 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store27532026/10/27 13:04:24 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store27542026/10/27 13:04:24 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store27552026/10/27 13:04:24 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27562026/10/27 13:04:24 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27572026/10/27 13:04:24 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store27582026/10/27 13:04:24 ERROR Accept failed error="too many open files"27592026/10/27 13:04:24 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store27602026/10/27 13:04:24 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store27612026/10/27 13:04:24 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store27622026/10/27 13:04:24 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store27632026/10/27 13:04:24 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store27642026/10/27 13:04:24 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store27652026/10/27 13:04:24 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store27662026/10/27 13:04:24 ERROR Failed to decode request error="unexpected EOF"2767=== CONT TestShutdownFinishesInFlightPush/completes2768--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)27692026/10/27 13:04:24 ERROR Accept failed error="too many open files"27702026/10/27 13:04:24 ERROR Accept failed error="too many open files"27712026/10/27 13:04:24 INFO Upload queue status pending=227722026/10/27 13:04:24 INFO Upload queue status pending=327732026/10/27 13:04:24 INFO Uploading batch count=127742026/10/27 13:04:24 INFO Uploading batch count=127752026/10/27 13:04:24 ERROR Upload failed error="upload failed" count=127762026/10/27 13:04:24 INFO Uploading batch count=427772026/10/27 13:04:24 ERROR Upload failed error="upload failed" count=427782026/10/27 13:04:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1068732058/002/nonexistent27792026/10/27 13:04:24 INFO Uploading batch count=427802026/10/27 13:04:24 ERROR Upload failed error="upload failed" count=427812026/10/27 13:04:24 INFO Uploading batch count=227822026/10/27 13:04:24 INFO Upload queue status pending=227832026/10/27 13:04:24 INFO Upload queue status pending=227842026/10/27 13:04:24 INFO Uploading batch count=227852026/10/27 13:04:24 ERROR Accept failed error="too many open files"27862026/10/27 13:04:24 INFO Upload queue status pending=227872026/10/27 13:04:24 INFO Uploading batch count=427882026/10/27 13:04:24 ERROR Upload failed error="upload failed" count=427892026/10/27 13:04:24 INFO Uploading batch count=227902026/10/27 13:04:24 INFO Uploading batch count=227912026/10/27 13:04:24 INFO Uploading batch count=227922026/10/27 13:04:24 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1228630467/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat1228630467/002/locked/aaa: permission denied"27932026/10/27 13:04:24 INFO Uploading batch count=127942026/10/27 13:04:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath688759305/002/bbb2795--- PASS: TestQueueFetchRemoveLifecycle (0.08s)2796=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27972026/10/27 13:04:24 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1228630467/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat1228630467/002/locked/aaa: permission denied"27982026/10/27 13:04:24 INFO Upload queue status pending=227992026/10/27 13:04:24 INFO Upload queue status pending=328002026/10/27 13:04:24 INFO Uploading batch count=128012026/10/27 13:04:24 ERROR Upload failed error="upload failed" count=128022026/10/27 13:04:24 INFO Uploading batch count=128032026/10/27 13:04:24 INFO Uploading batch count=22804--- PASS: TestQueueEnqueueAndFetch (0.09s)2805=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch2806--- PASS: TestQueueFetchBatchLimit (0.09s)28072026/10/27 13:04:24 INFO Uploading batch count=228082026/10/27 13:04:24 ERROR Upload failed error="upload failed" count=228092026/10/27 13:04:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2205422754/002/a2810--- PASS: TestQueueDeduplication (0.09s)28112026/10/27 13:04:24 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1228630467/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat1228630467/002/locked/aaa: permission denied"2812=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths28132026/10/27 13:04:24 INFO Uploading batch count=128142026/10/27 13:04:24 ERROR Upload failed error="upload failed" count=128152026/10/27 13:04:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2205422754/002/b28162026/10/27 13:04:24 ERROR Drain finished with paths left in queue remaining=12817--- PASS: TestQueueRetryMovesToBack (0.09s)28182026/10/27 13:04:24 INFO Uploading batch count=128192026/10/27 13:04:24 ERROR Upload failed error="upload failed" count=128202026/10/27 13:04:24 INFO Uploading batch count=228212026/10/27 13:04:24 ERROR Upload failed error="upload failed" count=228222026/10/27 13:04:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2205422754/002/c28232026/10/27 13:04:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2205422754/002/d2824--- PASS: TestQueueRemove (0.09s)28252026/10/27 13:04:24 INFO Uploading batch count=128262026/10/27 13:04:24 ERROR Upload failed error="upload failed" count=12827--- PASS: TestWorkerKeepsPathItCannotStat (0.10s)2828--- PASS: TestWorkerPrunesClosureDeps (0.10s)2829--- PASS: TestWorkerSkipsGCdPaths (0.10s)28302026/10/27 13:04:24 ERROR Drain finished with paths left in queue remaining=128312026/10/27 13:04:24 INFO Uploading batch count=228322026/10/27 13:04:24 ERROR Upload failed error="upload failed" count=228332026/10/27 13:04:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2205422754/002/e2834--- PASS: TestFailedPathPrunedByLaterClosure (0.10s)2835--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.10s)28362026/10/27 13:04:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2205422754/002/f2837--- PASS: TestWorkerUploadsAndRemoves (0.10s)2838--- PASS: TestDrainIsolatesPoisonPath (0.10s)28392026/10/27 13:04:24 ERROR Drain finished with paths left in queue remaining=102840--- PASS: TestDrainGivesUpWhenServerDown (0.11s)28412026/10/27 13:04:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path3510050768/001/nonexistent28422026/10/27 13:04:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128432026/10/27 13:04:24 INFO Uploading batch count=228442026/10/27 13:04:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path3510050768/001/nonexistent28452026/10/27 13:04:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228462026/10/27 13:04:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128472026/10/27 13:04:24 INFO Uploading batch count=228482026/10/27 13:04:24 ERROR Upload failed error="upload failed" count=228492026/10/27 13:04:24 INFO Uploading batch count=228502026/10/27 13:04:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path3510050768/001/nonexistent28512026/10/27 13:04:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128522026/10/27 13:04:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128532026/10/27 13:04:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228542026/10/27 13:04:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128552026/10/27 13:04:24 ERROR Drain finished with paths left in queue remaining=128562026/10/27 13:04:24 INFO Uploading batch count=228572026/10/27 13:04:24 INFO Uploading batch count=228582026/10/27 13:04:24 ERROR Upload failed error="upload failed" count=228592026/10/27 13:04:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228602026/10/27 13:04:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128612026/10/27 13:04:24 ERROR Drain finished with paths left in queue remaining=228622026/10/27 13:04:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128632026/10/27 13:04:24 INFO Uploading batch count=228642026/10/27 13:04:24 ERROR Upload failed error="upload failed" count=228652026/10/27 13:04:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128662026/10/27 13:04:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128672026/10/27 13:04:24 ERROR Drain finished with paths left in queue remaining=22868--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2869 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.05s)2870 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.04s)2871 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.05s)28722026/10/27 13:04:25 ERROR Accept failed error="too many open files"28732026/10/27 13:04:25 ERROR Failed to decode request error="read unix /build/hook1143518650/test.sock->@: i/o timeout"28742026/10/27 13:04:25 ERROR Failed to write response error="write unix /build/hook1143518650/test.sock->@: i/o timeout"2875--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)28762026/10/27 13:04:25 ERROR Drain finished with paths left in queue remaining=428772026/10/27 13:04:25 ERROR Upload failed error="context canceled" count=228782026/10/27 13:04:25 ERROR Drain finished with paths left in queue remaining=428792026/10/27 13:04:25 ERROR Upload failed error="context canceled" count=228802026/10/27 13:04:25 ERROR Drain finished with paths left in queue remaining=22881--- PASS: TestDrainTimeout (0.28s)2882--- PASS: TestShutdownFinishesInFlightPush (0.00s)2883 --- PASS: TestShutdownFinishesInFlightPush/completes (0.18s)2884 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.28s)28852026/10/27 13:04:25 ERROR Accept failed error="too many open files"28862026/10/27 13:04:25 ERROR Drain finished with paths left in queue remaining=32887--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2888 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.27s)2889 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.38s)2890--- PASS: TestQueueConcurrentWriters (0.54s)28912026/10/27 13:04:25 ERROR Accept failed error="too many open files"2892--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)28932026/10/27 13:04:25 INFO Uploading batch count=128942026/10/27 13:04:25 INFO Uploading batch count=128952026/10/27 13:04:25 INFO Uploading batch count=128962026/10/27 13:04:25 ERROR Upload failed error="upload failed" count=128972026/10/27 13:04:25 INFO Uploading batch count=128982026/10/27 13:04:25 ERROR Upload failed error="upload failed" count=128992026/10/27 13:04:25 INFO Uploading batch count=129002026/10/27 13:04:25 ERROR Upload failed error="upload failed" count=129012026/10/27 13:04:25 INFO Uploading batch count=129022026/10/27 13:04:25 ERROR Upload failed error="upload failed" count=129032026/10/27 13:04:25 ERROR Drain finished with paths left in queue remaining=12904--- PASS: TestRunNotBlockedByPoisonHead (1.11s)2905--- PASS: TestQueueRemoveLargeClosure (2.40s)2906PASS2907Running signing tests...2908=== RUN TestExternalSigner2909=== PAUSE TestExternalSigner2910=== RUN TestExternalSignerWrongPublicKey2911=== PAUSE TestExternalSignerWrongPublicKey2912=== RUN TestExternalSignerErrors2913=== PAUSE TestExternalSignerErrors2914=== RUN TestExternalSignerRestartsAfterCrash2915=== PAUSE TestExternalSignerRestartsAfterCrash2916=== RUN TestExternalSignerProgramErrorKeepsProcess2917=== PAUSE TestExternalSignerProgramErrorKeepsProcess2918=== RUN TestExternalSignerClose2919=== PAUSE TestExternalSignerClose2920=== RUN TestExternalSignerRejectsInvalidPublicKey2921=== PAUSE TestExternalSignerRejectsInvalidPublicKey2922=== RUN TestExternalSignerCancellation2923=== PAUSE TestExternalSignerCancellation2924=== RUN TestGenerateFingerprint2925=== PAUSE TestGenerateFingerprint2926=== RUN TestParseSigningKey2927=== PAUSE TestParseSigningKey2928=== RUN TestSign2929=== PAUSE TestSign2930=== RUN TestSignBatch2931=== PAUSE TestSignBatch2932=== RUN TestNilKeyPublicKey2933=== PAUSE TestNilKeyPublicKey2934=== RUN TestSignErrors2935=== PAUSE TestSignErrors2936=== CONT TestExternalSignerRestartsAfterCrash2937=== CONT TestExternalSignerCancellation2938=== CONT TestExternalSignerWrongPublicKey2939=== CONT TestExternalSignerProgramErrorKeepsProcess2940=== CONT TestExternalSignerClose2941=== CONT TestExternalSignerRejectsInvalidPublicKey2942=== RUN TestExternalSignerRejectsInvalidPublicKey/#002943=== CONT TestExternalSignerErrors2944=== RUN TestExternalSignerErrors/wrong_id2945=== PAUSE TestExternalSignerErrors/wrong_id2946=== CONT TestExternalSigner2947=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002948=== CONT TestSign2949=== RUN TestExternalSignerErrors/null2950=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2951=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2952=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2953=== PAUSE TestExternalSignerErrors/null2954=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2955=== RUN TestExternalSignerErrors/null_signatures2956=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2957=== CONT TestSignErrors2958=== CONT TestSignBatch2959=== CONT TestParseSigningKey2960=== CONT TestNilKeyPublicKey2961=== CONT TestGenerateFingerprint2962=== PAUSE TestExternalSignerErrors/null_signatures2963--- PASS: TestNilKeyPublicKey (0.00s)2964=== RUN TestExternalSignerErrors/wrong_signatures_shape2965=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2966=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2967=== RUN TestParseSigningKey/valid_32-byte_key2968=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2969=== PAUSE TestParseSigningKey/valid_32-byte_key2970=== RUN TestExternalSignerErrors/invalid_JSON2971=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2972=== PAUSE TestExternalSignerErrors/invalid_JSON2973=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2974=== RUN TestGenerateFingerprint/basic_with_references2975=== RUN TestExternalSignerErrors/missing_signatures2976=== PAUSE TestGenerateFingerprint/basic_with_references2977=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2978=== PAUSE TestExternalSignerErrors/missing_signatures2979=== CONT TestExternalSignerRejectsInvalidPublicKey/#002980=== RUN TestParseSigningKey/no_colon2981=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2982=== PAUSE TestParseSigningKey/no_colon2983=== RUN TestGenerateFingerprint/no_references2984=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2985=== PAUSE TestGenerateFingerprint/no_references2986=== RUN TestExternalSignerErrors/too_few_signatures2987=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2988=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2989=== RUN TestParseSigningKey/empty_name2990=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2991=== PAUSE TestParseSigningKey/empty_name2992=== PAUSE TestExternalSignerErrors/too_few_signatures2993=== RUN TestParseSigningKey/invalid_base642994--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2995 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2996 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2997 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2998 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2999 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)3000=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted3001=== RUN TestExternalSignerErrors/unrequested_key3002=== PAUSE TestExternalSignerErrors/unrequested_key3003=== PAUSE TestParseSigningKey/invalid_base643004=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix3005=== RUN TestParseSigningKey/wrong_length3006=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix3007=== RUN TestExternalSignerErrors/wrong_shape3008=== PAUSE TestParseSigningKey/wrong_length3009=== PAUSE TestExternalSignerErrors/wrong_shape3010=== CONT TestParseSigningKey/no_colon3011=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name3012=== CONT TestParseSigningKey/empty_name3013=== CONT TestParseSigningKey/wrong_length3014=== CONT TestParseSigningKey/valid_32-byte_key3015=== RUN TestGenerateFingerprint/invalid_nar_hash_length3016=== CONT TestParseSigningKey/invalid_base643017=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length3018=== RUN TestExternalSignerErrors/missing_signature_name3019=== RUN TestGenerateFingerprint/invalid_store_path_prefix3020=== PAUSE TestExternalSignerErrors/missing_signature_name3021=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix3022=== RUN TestExternalSignerErrors/wrong_signature_name3023=== RUN TestGenerateFingerprint/invalid_reference_prefix3024=== PAUSE TestExternalSignerErrors/wrong_signature_name3025--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)3026=== PAUSE TestGenerateFingerprint/invalid_reference_prefix3027=== RUN TestExternalSignerErrors/invalid_signature_base643028=== CONT TestGenerateFingerprint/basic_with_references3029=== CONT TestGenerateFingerprint/invalid_reference_prefix3030=== CONT TestGenerateFingerprint/invalid_nar_hash_length3031=== PAUSE TestExternalSignerErrors/invalid_signature_base643032=== CONT TestGenerateFingerprint/unsorted_references_get_sorted3033=== CONT TestGenerateFingerprint/invalid_store_path_prefix3034=== RUN TestExternalSignerErrors/wrong_signature_length3035=== CONT TestGenerateFingerprint/no_references3036=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix3037=== PAUSE TestExternalSignerErrors/wrong_signature_length3038=== RUN TestExternalSignerErrors/program_error3039--- PASS: TestGenerateFingerprint (0.00s)3040 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)3041 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)3042 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)3043 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)3044 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)3045 --- PASS: TestGenerateFingerprint/no_references (0.00s)3046 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)3047=== PAUSE TestExternalSignerErrors/program_error3048=== RUN TestExternalSignerErrors/exit_at_startup3049=== PAUSE TestExternalSignerErrors/exit_at_startup3050=== RUN TestExternalSignerErrors/exit_on_request3051=== PAUSE TestExternalSignerErrors/exit_on_request3052=== CONT TestExternalSignerErrors/null_signatures3053=== CONT TestExternalSignerErrors/program_error3054=== CONT TestExternalSignerErrors/wrong_shape3055=== CONT TestExternalSignerErrors/exit_on_request3056=== CONT TestExternalSignerErrors/wrong_signature_name3057=== CONT TestExternalSignerErrors/missing_signature_name3058=== CONT TestExternalSignerErrors/exit_at_startup3059=== CONT TestExternalSignerErrors/wrong_signatures_shape3060=== CONT TestExternalSignerErrors/invalid_signature_base643061=== CONT TestExternalSignerErrors/too_few_signatures3062=== CONT TestExternalSignerErrors/wrong_signature_length3063=== CONT TestExternalSignerErrors/missing_signatures3064=== CONT TestExternalSignerErrors/wrong_id3065=== CONT TestExternalSignerErrors/unrequested_key3066--- PASS: TestExternalSignerWrongPublicKey (0.01s)3067=== CONT TestExternalSignerErrors/null3068--- PASS: TestExternalSignerClose (0.01s)3069=== CONT TestExternalSignerErrors/invalid_JSON3070--- PASS: TestExternalSignerErrors (0.00s)3071 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)3072 --- PASS: TestExternalSignerErrors/program_error (0.01s)3073 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)3074 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)3075 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)3076 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)3077 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)3078 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)3079 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)3080 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)3081 --- PASS: TestExternalSignerErrors/invalid_JSON (0.00s)3082 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)3083 --- PASS: TestExternalSignerErrors/null (0.00s)3084 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)3085 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)3086 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)3087--- PASS: TestExternalSignerRestartsAfterCrash (0.02s)3088=== RUN TestSignErrors/nil_key3089=== PAUSE TestSignErrors/nil_key3090=== RUN TestSignErrors/nil_narinfo3091=== PAUSE TestSignErrors/nil_narinfo3092=== RUN TestSignErrors/invalid_narinfo3093--- PASS: TestParseSigningKey (0.00s)3094 --- PASS: TestParseSigningKey/no_colon (0.00s)3095 --- PASS: TestParseSigningKey/empty_name (0.00s)3096 --- PASS: TestParseSigningKey/wrong_length (0.00s)3097 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)3098 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.02s)3099 --- PASS: TestParseSigningKey/valid_32-byte_key (0.01s)3100=== PAUSE TestSignErrors/invalid_narinfo3101=== RUN TestSignErrors/canceled3102=== PAUSE TestSignErrors/canceled3103=== CONT TestSignErrors/nil_narinfo3104=== CONT TestSignErrors/canceled3105=== CONT TestSignErrors/invalid_narinfo3106=== CONT TestSignErrors/nil_key3107--- PASS: TestSignErrors (0.02s)3108 --- PASS: TestSignErrors/nil_narinfo (0.00s)3109 --- PASS: TestSignErrors/canceled (0.00s)3110 --- PASS: TestSignErrors/invalid_narinfo (0.00s)3111 --- PASS: TestSignErrors/nil_key (0.00s)3112--- PASS: TestSign (0.02s)3113--- PASS: TestExternalSignerCancellation (0.02s)3114--- PASS: TestExternalSigner (0.02s)3115--- PASS: TestSignBatch (0.03s)3116PASS3117Running OpenBao signer tests...3118=== RUN TestSign3119=== PAUSE TestSign3120=== RUN TestSignErrors3121=== PAUSE TestSignErrors3122=== RUN TestServe3123=== PAUSE TestServe3124=== RUN TestServeRejectsGarbage3125=== PAUSE TestServeRejectsGarbage3126=== CONT TestSign3127=== CONT TestSignErrors3128=== RUN TestSignErrors/http_error3129=== CONT TestServe3130=== CONT TestServeRejectsGarbage3131=== PAUSE TestSignErrors/http_error3132--- PASS: TestServeRejectsGarbage (0.00s)3133=== RUN TestSignErrors/invalid_json3134=== PAUSE TestSignErrors/invalid_json3135=== RUN TestSignErrors/no_prefix3136=== PAUSE TestSignErrors/no_prefix3137=== RUN TestSignErrors/invalid_base643138=== PAUSE TestSignErrors/invalid_base643139=== CONT TestSignErrors/http_error3140=== CONT TestSignErrors/invalid_base643141=== CONT TestSignErrors/invalid_json3142=== CONT TestSignErrors/no_prefix3143--- PASS: TestServe (0.00s)3144--- PASS: TestSign (0.01s)3145--- PASS: TestSignErrors (0.00s)3146 --- PASS: TestSignErrors/invalid_json (0.01s)3147 --- PASS: TestSignErrors/no_prefix (0.01s)3148 --- PASS: TestSignErrors/invalid_base64 (0.01s)3149 --- PASS: TestSignErrors/http_error (0.01s)3150PASS3151Running niks3-hook command tests...3152=== RUN TestServeSecondSignalEndsDrain3153=== PAUSE TestServeSecondSignalEndsDrain3154=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown3155=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown3156=== CONT TestServeSecondSignalEndsDrain3157=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown3158--- PASS: TestServeSecondSignalEndsDrain (0.08s)31592026/10/27 13:04:30 INFO Upload queue status pending=131602026/10/27 13:04:30 INFO Uploading batch count=13161--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.14s)3162PASS3163Running rate limiter tests...3164=== RUN TestAdaptiveRateLimiter_ThreadSafety3165=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3166=== CONT TestAdaptiveRateLimiter_ThreadSafety31672026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=112.7357000000000731682026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=78.9149900000000531692026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=55.2404930000000331702026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=38.6683451000000231712026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=27.0678415700000131722026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=18.94748909900000631732026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=13.26324236930000431742026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=9.28426965851000231752026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=6.49898876095700131762026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=531772026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=531782026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=531792026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=531802026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=531812026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=531822026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=531832026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=531842026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=531852026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=531862026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=531872026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=531882026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=531892026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=531902026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=531912026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=531922026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=531932026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=531942026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=531952026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=531962026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=531972026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=531982026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=531992026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532002026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532012026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=5.63678500000000132022026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532032026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532042026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532052026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532062026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532072026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532082026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532092026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532102026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532112026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532122026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532132026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532142026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532152026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532162026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532172026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532182026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532192026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532202026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532212026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532222026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532232026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532242026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532252026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532262026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532272026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532282026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532292026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532302026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532312026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532322026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=5.12435000000000132332026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532342026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532352026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532362026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532372026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532382026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532392026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=7.50256083500000332402026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=5.25179258450000232412026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532422026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532432026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532442026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532452026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532462026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532472026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532482026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532492026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=19.45971059722283832502026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=13.62179741805598532512026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=9.53525819263918932522026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=6.67468073484743232532026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532542026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532552026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532562026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532572026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532582026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532592026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532602026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532612026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532622026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532632026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532642026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532652026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=532662026/10/27 13:04:31 WARN Rate limiter backed off name=test rate=53267--- PASS: TestAdaptiveRateLimiter_ThreadSafety (0.10s)3268PASS