niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #446
· 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.04s)31=== RUN TestDumpPathCaseHackCollision32--- PASS: TestDumpPathCaseHackCollision (0.00s)33=== RUN TestSupersededNARStillUploadsListing34=== PAUSE TestSupersededNARStillUploadsListing35=== RUN TestTruncatedNARDumpIsNotCompleted36=== PAUSE TestTruncatedNARDumpIsNotCompleted37=== RUN TestDumpPathMatchesNix38=== PAUSE TestDumpPathMatchesNix39=== RUN TestDumpPathSingleFile40=== PAUSE TestDumpPathSingleFile41=== RUN TestDumpPathWriterError42=== PAUSE TestDumpPathWriterError43=== RUN TestDumpPathWriterErrorStopsReading44 nar_test.go:289: read 196722 of 32768000 bytes45--- PASS: TestDumpPathWriterErrorStopsReading (0.68s)46=== RUN TestEncodeNixBase3247=== PAUSE TestEncodeNixBase3248=== RUN TestEncodeNixBase32WithRealHash49=== PAUSE TestEncodeNixBase32WithRealHash50=== RUN TestConvertHashToNix3251=== PAUSE TestConvertHashToNix3252=== RUN TestGetStorePathHash53=== PAUSE TestGetStorePathHash54=== RUN TestPathInfoHashCompatibility55=== PAUSE TestPathInfoHashCompatibility56=== RUN TestParsePathInfoJSON57=== PAUSE TestParsePathInfoJSON58=== RUN TestParsePathInfoJSONMultiplePaths59=== PAUSE TestParsePathInfoJSONMultiplePaths60=== RUN TestPathInfoCACompatibility61=== PAUSE TestPathInfoCACompatibility62=== RUN TestUploadPendingObjectsStopsStartingAfterFailure63--- PASS: TestUploadPendingObjectsStopsStartingAfterFailure (0.02s)64=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent65=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent66=== RUN TestCompletePendingClosure_NotFoundWithoutKey67=== PAUSE TestCompletePendingClosure_NotFoundWithoutKey68=== RUN TestRateLimiterFeedback69=== PAUSE TestRateLimiterFeedback70=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess71=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess72=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer73=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer74=== RUN TestResolveStorePath75=== PAUSE TestResolveStorePath76=== RUN TestDoWithRetry_BodyReplayedViaGetBody77=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody78=== RUN 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 TestFileTokenReadsAndCaches137=== CONT TestSetClientTLS138=== CONT TestSupersededNARStillUploadsListing139=== CONT TestRegisterUploadedObjectReusesConnections140=== CONT TestConvertHashToNix32141=== RUN TestConvertHashToNix32/SRI_format_to_Nix32142=== CONT TestDumpPathWriterError143=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32144=== CONT TestSetClientTLSErrors145=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent146=== CONT TestParsePathInfoJSONMultiplePaths147=== CONT TestPathInfoCACompatibility148=== CONT TestPathInfoHashCompatibility149=== CONT TestStaticToken150=== CONT TestGetStorePathHash151=== CONT TestScriptTokenCachesUntilRefresh152=== CONT TestEncodeNixBase32WithRealHash153=== CONT TestScriptTokenDoesNotWaitForItsChildren154=== CONT TestDoWithRetry_FinalResponseBodyReadable155=== CONT TestEncodeNixBase32156=== CONT TestScriptTokenScriptFails157=== CONT TestPartSizeForNAR158=== CONT TestUploadMultipart_FailedPartBufferNotReused159=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure160=== CONT TestScriptTokenEmptyToken161=== CONT TestFilterOversizedClosures162=== CONT TestFileTokenMissing163=== RUN TestSupersededNARStillUploadsListing/small_NAR164=== RUN TestConvertHashToNix32/already_Nix32_format165--- PASS: TestStaticToken (0.00s)166=== CONT TestStreamPushIsolatesFailures167=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier168=== RUN TestPathInfoCACompatibility/null_ca_field169=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths170=== CONT TestCaseHackSuffix171=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)172=== RUN TestGetStorePathHash/valid_store_path173=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs174=== RUN TestEncodeNixBase32/test_string_hash175=== RUN TestPartSizeForNAR/zero_stays_at_minimum176=== RUN TestSetClientTLSErrors/missing_cert_file177--- PASS: TestFileTokenReadsAndCaches (0.00s)178=== PAUSE TestSupersededNARStillUploadsListing/small_NAR179=== RUN TestFilterOversizedClosures/no_limit_keeps_everything180=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier181=== PAUSE TestConvertHashToNix32/already_Nix32_format182=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths183=== CONT TestDoServerRequestAttachesToken184=== PAUSE TestGetStorePathHash/valid_store_path185=== CONT TestShellSplitErrors186=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer187=== PAUSE TestPathInfoCACompatibility/null_ca_field188=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum189=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs190=== RUN TestPathInfoCACompatibility/old_string_format_-_text191=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout192=== RUN TestPartSizeForNAR/small_stays_at_minimum193=== PAUSE TestEncodeNixBase32/test_string_hash194=== CONT TestUploadMultipart_ProducerErrorIsNotEOF195=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part196=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout197=== CONT TestDoWithRetry_BodyReplayedViaGetBody198=== RUN TestEncodeNixBase32/empty_input199=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text200--- PASS: TestEncodeNixBase32WithRealHash (0.00s)201=== PAUSE TestPartSizeForNAR/small_stays_at_minimum202=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum203=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)204=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon205=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon206=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum207--- PASS: TestScriptTokenScriptFails (0.01s)208--- PASS: TestFileTokenMissing (0.00s)209--- PASS: TestScriptTokenEmptyToken (0.01s)210--- PASS: TestShellSplitErrors (0.00s)211=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI212=== CONT TestScriptTokenEmptyCommand213=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts214--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)215=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything216=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped217=== RUN TestConvertHashToNix32/invalid_format218=== RUN TestSetClientTLS/rejects_connection_without_client_cert219=== RUN TestGetStorePathHash/basename_without_hyphen_should_error220=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths221=== PAUSE TestSetClientTLSErrors/missing_cert_file222=== CONT TestStreamPushReportsSignatures223=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part224=== PAUSE TestEncodeNixBase32/empty_input225=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive226=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up227=== RUN TestSupersededNARStillUploadsListing/dump_cut_short228=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts229=== CONT TestParsePathInfoJSON230=== RUN TestParsePathInfoJSON/Nix_format231=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short232=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails233=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up234=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier235=== CONT TestStreamPushStartsNothingOnSlotFreedByCancel236=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails237=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI238=== PAUSE TestConvertHashToNix32/invalid_format239--- PASS: TestStreamPushIsolatesFailures (0.01s)240=== CONT TestDumpPathMatchesNix241=== CONT TestDumpPathSingleFile242=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths243=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error244=== RUN TestSetClientTLSErrors/missing_key_file245=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive246=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped247=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert248=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary249=== RUN TestPartSizeForNAR/1_TiB250=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA251=== PAUSE TestParsePathInfoJSON/Nix_format252=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA253=== RUN TestParsePathInfoJSON/Lix_format254=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary255=== PAUSE TestParsePathInfoJSON/Lix_format256=== CONT TestStreamPushStopsOnCancel257=== RUN TestStreamPushStopsOnCancel/waiting_for_input258=== CONT TestScriptTokenBadJSON259=== CONT TestStreamPushStopsWhenCanceled260--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)261=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input262=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error263=== CONT TestScriptTokenNoExpiryRerunsEveryCall264=== PAUSE TestSetClientTLSErrors/missing_key_file265=== RUN TestPathInfoCACompatibility/new_structured_format_-_text266=== RUN TestFilterOversizedClosures/all_closures_skipped267=== PAUSE TestPartSizeForNAR/1_TiB268=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier269=== RUN TestSetClientTLS/preserves_debug_logging_transport270=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512271=== CONT TestShellSplit272=== RUN TestParsePathInfoJSON/empty_input273--- PASS: TestScriptTokenEmptyCommand (0.00s)274--- PASS: TestStreamPushStopsWhenCanceled (0.00s)275=== PAUSE TestFilterOversizedClosures/all_closures_skipped276=== PAUSE TestParsePathInfoJSON/empty_input277=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client278=== CONT TestRetryTimeoutOutlastsMaxRetries279=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text280=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client281=== CONT TestUploadMultipart_PartsInParallel282=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client283=== RUN TestPartSizeForNAR/5_TiB_S3_max_object284=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object285=== RUN TestPartSizeForNAR/capped_at_5_GiB286=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry287=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client288=== PAUSE TestPartSizeForNAR/capped_at_5_GiB289=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512290=== CONT TestSetClientTLSDoesNotMutateDefaultTransport291=== PAUSE TestSetClientTLS/preserves_debug_logging_transport292=== CONT TestStreamPushReportsEveryPath293=== RUN TestParsePathInfoJSON/whitespace_only294=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error295--- PASS: TestDoServerRequestAttachesToken (0.01s)296=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error297--- PASS: TestStreamPushReportsSignatures (0.00s)298=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error299=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method300=== RUN TestSetClientTLSErrors/missing_ca_file301=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot302=== CONT TestClientSignaturesByStorePath303=== CONT TestFileTokenEmpty304=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica305=== PAUSE TestSetClientTLSErrors/missing_ca_file306=== PAUSE TestParsePathInfoJSON/whitespace_only307=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot308=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot309--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)310--- PASS: TestShellSplit (0.00s)311=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot312=== CONT TestStreamPushGivesUpOnDeadServer313--- PASS: TestScriptTokenBadJSON (0.00s)314--- PASS: TestStreamPushReportsEveryPath (0.00s)315=== RUN TestParsePathInfoJSON/invalid_JSON316=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot317=== PAUSE TestParsePathInfoJSON/invalid_JSON318=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method319--- PASS: TestClientSignaturesByStorePath (0.00s)320=== CONT TestCompletePendingClosure_NotFoundWithoutKey321=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun322=== RUN TestSetClientTLSErrors/invalid_ca_file323=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot324=== PAUSE TestSetClientTLSErrors/invalid_ca_file325=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot326=== CONT TestRateLimiterFeedback327=== CONT TestTruncatedNARDumpIsNotCompleted328--- PASS: TestFileTokenEmpty (0.00s)329=== CONT TestStreamPushBatchesUnderLoad330=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false331=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false332=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true333=== CONT TestUploadMultipart_SupersededByPeer334=== RUN TestUploadMultipart_SupersededByPeer/exists335=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess336=== RUN TestRateLimiterFeedback/429_enables_limiter337=== PAUSE TestUploadMultipart_SupersededByPeer/exists338=== RUN TestUploadMultipart_SupersededByPeer/missing339--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)340=== CONT TestStreamPushRequestLine341--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)342=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot343=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken344=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true345=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken346=== CONT TestStreamPushReportsSkippedPaths347=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs348--- PASS: TestStreamPushReportsSkippedPaths (0.00s)349=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout350=== PAUSE TestRateLimiterFeedback/429_enables_limiter351=== RUN TestRateLimiterFeedback/503_enables_limiter352=== PAUSE TestRateLimiterFeedback/503_enables_limiter353=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter354=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter355=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter356=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter357=== CONT TestEncodeNixBase32/test_string_hash358=== PAUSE TestUploadMultipart_SupersededByPeer/missing359=== CONT TestEncodeNixBase32/empty_input360=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails361--- PASS: TestEncodeNixBase32 (0.02s)362 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)363 --- PASS: TestEncodeNixBase32/empty_input (0.00s)364=== CONT TestSupersededNARStillUploadsListing/small_NAR365=== CONT TestConvertHashToNix32/SRI_format_to_Nix32366=== CONT TestConvertHashToNix32/invalid_format367=== CONT TestConvertHashToNix32/already_Nix32_format368=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths369=== CONT TestResolveStorePath370=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths371--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)372=== CONT TestSupersededNARStillUploadsListing/dump_cut_short373=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary374=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part375=== CONT TestFilterOversizedClosures/no_limit_keeps_everything376=== CONT TestFilterOversizedClosures/all_closures_skipped377--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.01s)378--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)379--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)380--- PASS: TestParsePathInfoJSONMultiplePaths (0.03s)381 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)382 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)383--- PASS: TestConvertHashToNix32 (0.03s)384 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)385 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)386 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)387--- PASS: TestCaseHackSuffix (0.27s)388=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped389--- PASS: TestResolveStorePath (0.24s)390=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier391=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum392=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon393=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier394--- PASS: TestFilterOversizedClosures (0.02s)395 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)396 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.24s)397 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)398=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client399--- PASS: TestDumpPathSingleFile (0.26s)400=== CONT TestPartSizeForNAR/capped_at_5_GiB401=== CONT TestPartSizeForNAR/5_TiB_S3_max_object402=== CONT TestPartSizeForNAR/1_TiB403=== CONT TestPartSizeForNAR/small_stays_at_minimum404=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts405=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512406=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI407=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up408=== CONT TestPartSizeForNAR/zero_stays_at_minimum409--- PASS: TestPartSizeForNAR (0.02s)410 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)411 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)412 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)413 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)414 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)415 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)416 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)417=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)418--- PASS: TestPathInfoHashCompatibility (0.04s)419 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)420 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)421 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)422 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)423=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client424--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.27s)425=== CONT TestSetClientTLS/preserves_debug_logging_transport426=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA427=== CONT TestSetClientTLS/rejects_connection_without_client_cert428=== CONT TestGetStorePathHash/basename_without_hyphen_should_error429=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error430=== CONT TestGetStorePathHash/valid_store_path431=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error432--- PASS: TestGetStorePathHash (0.03s)433 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)434 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)435 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)436 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)437=== CONT TestParsePathInfoJSON/Nix_format438=== CONT TestPathInfoCACompatibility/old_string_format_-_text439=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method440=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive441=== CONT TestPathInfoCACompatibility/new_structured_format_-_text442=== CONT TestPathInfoCACompatibility/null_ca_field443=== CONT TestParsePathInfoJSON/whitespace_only444--- PASS: TestPathInfoCACompatibility (0.04s)445 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)446 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)447 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)448 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)449 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)450=== CONT TestParsePathInfoJSON/invalid_JSON451=== CONT TestParsePathInfoJSON/empty_input452=== CONT TestParsePathInfoJSON/Lix_format453=== CONT TestSetClientTLSErrors/missing_cert_file454--- PASS: TestParsePathInfoJSON (0.01s)455 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)456 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)457 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)458 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)459 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)460=== CONT TestSetClientTLSErrors/missing_key_file461=== CONT TestSetClientTLSErrors/invalid_ca_file462=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true463=== CONT TestSetClientTLSErrors/missing_ca_file464--- PASS: TestSetClientTLSErrors (0.04s)465 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)466 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)467 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)468 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)469=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false470--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.04s)471 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.01s)472 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.01s)473 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.01s)474 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.00s)475 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.01s)476=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot477=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot478--- PASS: TestStreamPushBatchesUnderLoad (0.01s)479 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)480 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)481=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken482=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot483=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot484--- PASS: TestDumpPathWriterError (0.33s)485=== CONT TestStreamPushStopsOnCancel/waiting_for_input486=== CONT TestRateLimiterFeedback/429_enables_limiter487=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter488=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter489=== CONT TestRateLimiterFeedback/503_enables_limiter490--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.30s)491=== CONT TestUploadMultipart_SupersededByPeer/exists492=== CONT TestUploadMultipart_SupersededByPeer/missing493--- PASS: TestRateLimiterFeedback (0.01s)494 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)495 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)496 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)497 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)498--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)499 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)500 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)501--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.33s)502--- PASS: TestStreamPushStopsOnCancel (0.02s)503 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.05s)504 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.05s)505 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.05s)506 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.05s)507 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)508 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.05s)509--- PASS: TestStreamPushStartsNothingOnSlotFreedByCancel (0.35s)510--- PASS: TestSetClientTLS (0.04s)511 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.03s)512 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.03s)513 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.10s)514--- PASS: TestRegisterUploadedObjectReusesConnections (0.42s)515--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.01s)516 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.38s)517 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.39s)518--- PASS: TestDumpPathMatchesNix (0.41s)519--- PASS: TestStreamPushRequestLine (0.43s)520--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)521--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)522--- PASS: TestSupersededNARStillUploadsListing (0.03s)523 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.26s)524 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.27s)525 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.30s)526--- PASS: TestUploadMultipart_PartsInParallel (1.32s)527--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.38s)528--- PASS: TestTruncatedNARDumpIsNotCompleted (1.41s)529--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.01s)530 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.00s)531 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.24s)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/postgres466948315/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/postgres466948315/data -l logfile start560561/build/postgres466948315:5432 - no response5622026-10-28 14:31:51.808 UTC [172] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5632026-10-28 14:31:51.809 UTC [172] LOG: listening on Unix socket "/build/postgres466948315/.s.PGSQL.5432"5642026-10-28 14:31:51.813 UTC [179] LOG: database system was shut down at 2026-10-28 14:31:51 UTC5652026-10-28 14:31:51.817 UTC [172] LOG: database system is ready to accept connections566/build/postgres466948315:5432 - accepting connections567{"timestamp":"2026-10-28T14:31:52.118084121Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"57ef8205-f09c-42f1-a63c-331f9ad99204","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(199)"}568{"timestamp":"2026-10-28T14:31:52.224041892Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"6b5ae58d-d9d2-4fab-88e5-c9b89c88f15b","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(199)"}569{"timestamp":"2026-10-28T14:31:52.326532433Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"c1b18eec-9b42-4b14-bd07-e9b1ca0fb7b8","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(198)"}570{"timestamp":"2026-10-28T14:31:52.428827951Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"693aa182-456b-4dbf-a598-5977a6aed6a9","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(199)"}571=== RUN TestService_AuthMiddleware572=== PAUSE TestService_AuthMiddleware573=== RUN TestService_AuthMiddleware_MTLSProxyHeader574=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader575=== RUN TestService_AuthMiddleware_MTLSBoundSubjects576=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects577=== RUN TestService_ReadAuthMiddleware578=== PAUSE TestService_ReadAuthMiddleware579=== RUN TestService_AuthMiddleware_OIDC580=== PAUSE TestService_AuthMiddleware_OIDC581=== RUN TestService_RequireScope_OIDC582=== PAUSE TestService_RequireScope_OIDC583=== RUN TestService_ReadScope_PublicByDefault584=== PAUSE TestService_ReadScope_PublicByDefault585=== RUN TestCacheConfigHandler586=== PAUSE TestCacheConfigHandler587=== RUN TestCacheStatsHandler588=== PAUSE TestCacheStatsHandler589=== RUN TestClientCADerivations590=== PAUSE TestClientCADerivations591=== RUN TestClientErrorHandling592=== PAUSE TestClientErrorHandling593=== RUN TestClientIntegration594=== PAUSE TestClientIntegration595=== RUN TestClientMultipleUploads596=== PAUSE TestClientMultipleUploads597=== RUN TestClientWithDependencies598=== PAUSE TestClientWithDependencies599=== RUN TestClientSharedPathCommittedMidPush600=== PAUSE TestClientSharedPathCommittedMidPush601=== RUN TestPinProtectsFromGC602=== PAUSE TestPinProtectsFromGC603=== RUN TestClientPushesUseOnePush604=== PAUSE TestClientPushesUseOnePush605=== RUN TestClientFallsBackToClosures606=== PAUSE TestClientFallsBackToClosures607=== RUN TestDeleteClosuresRacingPins608=== PAUSE TestDeleteClosuresRacingPins609=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock610=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock611=== RUN TestResolveDBConnectionString612=== PAUSE TestResolveDBConnectionString613=== RUN TestConnectWaitsForAPeerMigration614=== PAUSE TestConnectWaitsForAPeerMigration615=== RUN TestConnectSerialisesConcurrentMigrations616=== PAUSE TestConnectSerialisesConcurrentMigrations617=== RUN TestLeadElectsOneAndHandsOver618=== PAUSE TestLeadElectsOneAndHandsOver619=== RUN TestLeadIncumbentWinsAfterRestart6202026/10/28 14:31:52 INFO lead: acquired remote=192.0.2.1:12346212026/10/28 14:31:53 INFO lead: released remote=192.0.2.1:12346222026/10/28 14:31:53 INFO lead: acquired remote=192.0.2.1:12346232026/10/28 14:31:54 INFO lead: released remote=192.0.2.1:1234624--- PASS: TestLeadIncumbentWinsAfterRestart (1.88s)625=== RUN TestLeadIncumbentAnnouncesAtOnce626=== PAUSE TestLeadIncumbentAnnouncesAtOnce627=== RUN TestLeadEndsOnShutdown628=== PAUSE TestLeadEndsOnShutdown629=== RUN TestLeadEndsWhenItsConnectionHangs6302026/10/28 14:31:54 INFO lead: acquired remote=192.0.2.1:12346312026-10-28 14:31:56.003 UTC [426] FATAL: terminating connection due to administrator command6322026/10/28 14:31:56 INFO lead: acquired remote=192.0.2.1:12346332026/10/28 14:31:57 WARN lead: lock connection lost error="timeout: context deadline exceeded"6342026/10/28 14:31:57 INFO lead: released remote=192.0.2.1:12346352026/10/28 14:31:57 INFO lead: released remote=192.0.2.1:1234636--- PASS: TestLeadEndsWhenItsConnectionHangs (3.00s)637=== RUN TestGCAdvisoryLockBlocksConcurrentRun638=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun639=== RUN TestGCBugBareHashReferences640=== PAUSE TestGCBugBareHashReferences641=== RUN TestGCMetrics642=== PAUSE TestGCMetrics643=== RUN TestPushDedupSurvivesConcurrentGC644=== PAUSE TestPushDedupSurvivesConcurrentGC645=== RUN TestDeduplicatedObjectsRecordedAsPending646=== PAUSE TestDeduplicatedObjectsRecordedAsPending647=== RUN TestGCSweepSkipsPendingObjects648=== PAUSE TestGCSweepSkipsPendingObjects649=== RUN TestTombstonedObjectOfferedWithoutWaiting650=== PAUSE TestTombstonedObjectOfferedWithoutWaiting651=== RUN TestGCSweepDeliversEachKeyOnce652=== PAUSE TestGCSweepDeliversEachKeyOnce653=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection654=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection655=== RUN TestForceGCDuringPushOffersSweptObject656=== PAUSE TestForceGCDuringPushOffersSweptObject657=== RUN TestFailedS3DeleteKeepsTombstone658=== PAUSE TestFailedS3DeleteKeepsTombstone659=== RUN TestSweepSkipsRowsLockedByPush660=== PAUSE TestSweepSkipsRowsLockedByPush661=== RUN TestRegisterCompletedObjectNeedsPendingRow662=== PAUSE TestRegisterCompletedObjectNeedsPendingRow663=== RUN TestGetExistingObjectsLocksRows664=== PAUSE TestGetExistingObjectsLocksRows665=== RUN TestSweepRechecksPendingAfterLocking666=== PAUSE TestSweepRechecksPendingAfterLocking667=== RUN TestPushWaitsForSweepHoldingRow668=== PAUSE TestPushWaitsForSweepHoldingRow669=== RUN TestCommitRacingPendingCleanupKeepsObjects670=== PAUSE TestCommitRacingPendingCleanupKeepsObjects671=== RUN TestGCEndsOnShutdown672=== PAUSE TestGCEndsOnShutdown673=== RUN TestGCTaskStore_StartNew674=== PAUSE TestGCTaskStore_StartNew675=== RUN TestGCTaskStore_DeduplicateSameParams676=== PAUSE TestGCTaskStore_DeduplicateSameParams677=== RUN TestGCTaskStore_ConflictDifferentParams678=== PAUSE TestGCTaskStore_ConflictDifferentParams679=== RUN TestGCTaskStore_GetEmpty680=== PAUSE TestGCTaskStore_GetEmpty681=== RUN TestGCTaskStore_GetReturnsLatest682=== PAUSE TestGCTaskStore_GetReturnsLatest683=== RUN TestGCTaskStore_CompletedAllowsNewTask684=== PAUSE TestGCTaskStore_CompletedAllowsNewTask685=== RUN TestGCTaskStore_PhaseUpdates686=== PAUSE TestGCTaskStore_PhaseUpdates687=== RUN TestGCTaskStore_Fail688=== PAUSE TestGCTaskStore_Fail689=== RUN TestGracefulShutdownDrainsInflight690=== PAUSE TestGracefulShutdownDrainsInflight691=== RUN TestService_healthCheckHandler692=== PAUSE TestService_healthCheckHandler693=== RUN TestService_readinessHandler694=== PAUSE TestService_readinessHandler695=== RUN TestGenerateLandingPage696=== PAUSE TestGenerateLandingPage697=== RUN TestChildrenInheritRaisedFileLimit698=== PAUSE TestChildrenInheritRaisedFileLimit699=== RUN TestCacheConfigHandlerMaxNarSize700=== PAUSE TestCacheConfigHandlerMaxNarSize701=== RUN TestCreatePendingClosureRejectsOversizedNAR702=== PAUSE TestCreatePendingClosureRejectsOversizedNAR703=== RUN TestNARDeduplicationMetadataUploadBug704=== PAUSE TestNARDeduplicationMetadataUploadBug705=== RUN TestMetricsInventory706=== PAUSE TestMetricsInventory707=== RUN TestMetricsCommit708=== PAUSE TestMetricsCommit709=== RUN TestService_NativeMTLS710=== PAUSE TestService_NativeMTLS711=== RUN TestServerTLSConfig712=== PAUSE TestServerTLSConfig713=== RUN TestMultipartCleanup714=== PAUSE TestMultipartCleanup715=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded716=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded717=== RUN TestPendingCleanupUsesOneCutoff718=== PAUSE TestPendingCleanupUsesOneCutoff719=== RUN TestPendingClosureFailureTracksEveryUpload720=== PAUSE TestPendingClosureFailureTracksEveryUpload721=== RUN TestPendingClosureFailureAbortsItsUploads722=== PAUSE TestPendingClosureFailureAbortsItsUploads723=== RUN TestObjectStatsTrigger724=== PAUSE TestObjectStatsTrigger725=== RUN TestObjectStatsUpdatedOncePerCommit726=== PAUSE TestObjectStatsUpdatedOncePerCommit727=== RUN TestReconnectLeavesObjectsUnlocked728=== PAUSE TestReconnectLeavesObjectsUnlocked729=== RUN TestOrphanedObjectsGC730=== PAUSE TestOrphanedObjectsGC731=== RUN TestOrphanedObjectsGCStressTest732=== PAUSE TestOrphanedObjectsGCStressTest733=== RUN TestCreatePin_ReservedPins734=== PAUSE TestCreatePin_ReservedPins735=== RUN TestConcurrentPinUpdatesAgree736=== PAUSE TestConcurrentPinUpdatesAgree737=== RUN TestCreatePinRejectsBadInput738=== PAUSE TestCreatePinRejectsBadInput739=== RUN TestDeletePinKeepsRowWhenS3Fails740=== PAUSE TestDeletePinKeepsRowWhenS3Fails741=== RUN TestPresentReportsOnlyClosureRoots742=== PAUSE TestPresentReportsOnlyClosureRoots743=== RUN TestPresentRefreshesOnlyStaleClosures744=== PAUSE TestPresentRefreshesOnlyStaleClosures745=== RUN TestPresentNotReportedWhileGCDeletesClosure746=== PAUSE TestPresentNotReportedWhileGCDeletesClosure747=== RUN TestParseSingleRange748=== PAUSE TestParseSingleRange749=== RUN TestProxyHeadersOnlyTrustedOnSocket7502026/10/28 14:31:57 INFO Starting HTTP server address=127.0.0.1:433037512026/10/28 14:31:57 INFO Starting HTTP server address=proxy.sock7522026/10/28 14:31:57 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7532026/10/28 14:31:57 INFO Shutdown signal received, draining in-flight requests timeout=10s754--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.16s)755=== RUN TestIsValidCachePath756=== PAUSE TestIsValidCachePath757=== RUN TestReadProxyNarinfo758=== PAUSE TestReadProxyNarinfo759=== RUN TestReadProxyNarinfoAlreadyDecompressed760=== PAUSE TestReadProxyNarinfoAlreadyDecompressed761=== RUN TestReadProxyContentNegotiation762=== PAUSE TestReadProxyContentNegotiation763=== RUN TestReadProxyNarStreaming764=== PAUSE TestReadProxyNarStreaming765=== RUN TestReadProxy404And429766=== PAUSE TestReadProxy404And429767=== RUN TestReadProxyInvalidPath768=== PAUSE TestReadProxyInvalidPath769=== RUN TestReadProxyHead770=== PAUSE TestReadProxyHead771=== RUN TestReadProxyOutlastsServerWriteTimeout772=== PAUSE TestReadProxyOutlastsServerWriteTimeout773=== RUN TestReadProxyConditionalGet774=== PAUSE TestReadProxyConditionalGet775=== RUN TestReadProxyRootRedirectsToIndexHTML776=== PAUSE TestReadProxyRootRedirectsToIndexHTML777=== RUN TestReadProxyDisabled778=== PAUSE TestReadProxyDisabled779=== RUN TestReadRedirectNar780=== PAUSE TestReadRedirectNar781=== RUN TestReadRedirectKeepsNarinfoProxied782=== PAUSE TestReadRedirectKeepsNarinfoProxied783=== RUN TestReadProxyRangeRequest784=== PAUSE TestReadProxyRangeRequest785=== RUN TestReadRedirectUsesPublicS3URL786=== PAUSE TestReadRedirectUsesPublicS3URL787=== RUN TestPush_OverlappingRootsStoreOneRowPerKey788=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey789=== RUN TestPush_CompleteCommitsEveryRoot790=== PAUSE TestPush_CompleteCommitsEveryRoot791=== RUN TestPush_RepeatedRootCommitsOnce792=== PAUSE TestPush_RepeatedRootCommitsOnce793=== RUN TestPush_CompleteWaitsForCleanupOfThePush794=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush795=== RUN TestPush_RootsAreLockedInByteOrder796=== PAUSE TestPush_RootsAreLockedInByteOrder797=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit798=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit799=== RUN TestPush_RejectsBadRequests800=== PAUSE TestPush_RejectsBadRequests801=== RUN TestPush_SignsNarinfosOfItsPendingObjects802=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects803=== RUN TestRedundantMultipartUpload804=== PAUSE TestRedundantMultipartUpload805=== RUN TestCompleteMultipartUpload_ErrorButObjectExists806=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists807=== RUN TestCompletedNarNotReofferedAcrossClosures808=== PAUSE TestCompletedNarNotReofferedAcrossClosures809=== RUN TestPresignedUploadRegisteredBeforeCommit810=== PAUSE TestPresignedUploadRegisteredBeforeCommit811=== RUN TestService_Rustfstest812=== PAUSE TestService_Rustfstest813=== RUN TestParseSize814=== PAUSE TestParseSize815=== RUN TestSkippedUploadsHandler816=== PAUSE TestSkippedUploadsHandler817=== RUN TestSystemdListenerNotActivated818--- PASS: TestSystemdListenerNotActivated (0.00s)819=== RUN TestWatchdogBeatsWhenHealthy820--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)821=== RUN TestWatchdogSkipsWhenUnhealthy8222026/10/28 14:31:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8232026/10/28 14:31:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8242026/10/28 14:31:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8252026/10/28 14:31:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8262026/10/28 14:31:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8272026/10/28 14:31:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8282026/10/28 14:31:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8292026/10/28 14:31:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8302026/10/28 14:31:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8312026/10/28 14:31:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"832--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)833=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle834=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle835=== RUN TestProxyWriteTimeout836=== PAUSE TestProxyWriteTimeout837=== RUN TestPendingClosureWriteTimeout838=== PAUSE TestPendingClosureWriteTimeout839=== RUN TestIsValidUploadKey840=== PAUSE TestIsValidUploadKey841=== RUN TestUploadHandlersRejectInvalidKeys842=== PAUSE TestUploadHandlersRejectInvalidKeys843=== RUN TestUploadHandlersRejectOversizedBody844=== PAUSE TestUploadHandlersRejectOversizedBody845=== RUN TestService_cleanupPendingClosuresHandler846=== PAUSE TestService_cleanupPendingClosuresHandler847=== RUN TestService_createPendingClosureHandler848=== PAUSE TestService_createPendingClosureHandler849=== RUN TestService_verifyS3Integrity850=== PAUSE TestService_verifyS3Integrity851=== RUN TestCompleteMultipartUnregistered852=== PAUSE TestCompleteMultipartUnregistered853=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT854=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT855=== CONT TestUploadHandlersRejectOversizedBody856=== CONT TestService_healthCheckHandler857=== CONT TestIsValidCachePath858=== RUN TestIsValidCachePath/narinfo859=== PAUSE TestIsValidCachePath/narinfo860=== CONT TestReadProxyNarStreaming861=== CONT TestService_AuthMiddleware862=== CONT TestCacheConfigHandlerMaxNarSize863=== CONT TestGenerateLandingPage864=== CONT TestChildrenInheritRaisedFileLimit865=== CONT TestService_readinessHandler866=== CONT TestReadProxyNarinfo867=== CONT TestReadProxyInvalidPath868=== CONT TestReadProxyContentNegotiation869=== CONT TestPendingClosureWriteTimeout870=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle871=== CONT TestPush_CompleteCommitsEveryRoot872--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)873=== CONT TestParseSize874=== CONT TestSkippedUploadsHandler875--- PASS: TestParseSize (0.00s)876=== CONT TestCompleteMultipartUpload_ErrorButObjectExists877=== CONT TestCompletedNarNotReofferedAcrossClosures878=== CONT TestObjectStatsUpdatedOncePerCommit879=== CONT TestReadProxyRangeRequest880=== CONT TestService_Rustfstest881=== CONT TestReadRedirectKeepsNarinfoProxied882=== CONT TestReadProxyNarinfoAlreadyDecompressed883=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars884=== CONT TestCreatePendingClosureRejectsOversizedNAR885=== RUN TestPendingClosureWriteTimeout/empty886=== CONT TestProxyWriteTimeout887=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars888=== RUN TestIsValidCachePath/nar_zst889=== PAUSE TestIsValidCachePath/nar_zst890=== PAUSE TestPendingClosureWriteTimeout/empty891=== RUN TestPendingClosureWriteTimeout/400_objects892=== PAUSE TestPendingClosureWriteTimeout/400_objects893=== RUN TestPendingClosureWriteTimeout/670k_objects894=== PAUSE TestPendingClosureWriteTimeout/670k_objects8952026/10/28 14:31:57 INFO Received uploads request method=POST path=/api/pending_closures896=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline897=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline898=== RUN TestProxyWriteTimeout/narinfo899=== PAUSE TestProxyWriteTimeout/narinfo900=== CONT TestParseSingleRange901--- PASS: TestChildrenInheritRaisedFileLimit (0.00s)902=== CONT TestReadProxyHead903=== RUN TestIsValidCachePath/nar_xz904=== PAUSE TestIsValidCachePath/nar_xz905--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)906=== RUN TestIsValidCachePath/nar_bz2907=== PAUSE TestIsValidCachePath/nar_bz2908=== RUN TestParseSingleRange/none909=== RUN TestIsValidCachePath/nar_uncompressed910=== CONT TestPresentRefreshesOnlyStaleClosures911=== PAUSE TestIsValidCachePath/nar_uncompressed912=== RUN TestIsValidCachePath/ls913=== PAUSE TestParseSingleRange/none914=== RUN TestProxyWriteTimeout/1_GiB_nar915=== PAUSE TestIsValidCachePath/ls916=== RUN TestIsValidCachePath/log917=== RUN TestParseSingleRange/unknown_unit918=== PAUSE TestIsValidCachePath/log919=== PAUSE TestParseSingleRange/unknown_unit920=== PAUSE TestProxyWriteTimeout/1_GiB_nar921=== RUN TestParseSingleRange/multi-range_ignored922=== RUN TestIsValidCachePath/realisation923=== PAUSE TestIsValidCachePath/realisation924=== RUN TestProxyWriteTimeout/10_GiB_nar925=== PAUSE TestParseSingleRange/multi-range_ignored926=== RUN TestIsValidCachePath/nix-cache-info927=== PAUSE TestProxyWriteTimeout/10_GiB_nar928=== RUN TestParseSingleRange/malformed_no_dash929=== RUN TestProxyWriteTimeout/unknown_size930=== PAUSE TestIsValidCachePath/nix-cache-info931=== PAUSE TestProxyWriteTimeout/unknown_size932=== PAUSE TestParseSingleRange/malformed_no_dash933=== RUN TestIsValidCachePath/index.html934=== CONT TestPresentNotReportedWhileGCDeletesClosure935=== PAUSE TestIsValidCachePath/index.html936=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale937=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale938=== RUN TestParseSingleRange/malformed_both_empty9392026/10/28 14:31:57 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000940=== RUN TestIsValidCachePath/traversal_parent941=== PAUSE TestIsValidCachePath/traversal_parent942=== RUN TestIsValidCachePath/traversal_in_middle943=== PAUSE TestIsValidCachePath/traversal_in_middle944=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh945=== RUN TestIsValidCachePath/invalid_char_e946=== PAUSE TestIsValidCachePath/invalid_char_e947=== PAUSE TestParseSingleRange/malformed_both_empty948=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh949=== RUN TestParseSingleRange/malformed_end_before_start950=== PAUSE TestParseSingleRange/malformed_end_before_start951=== CONT TestRedundantMultipartUpload952=== RUN TestParseSingleRange/closed953=== PAUSE TestParseSingleRange/closed954=== RUN TestParseSingleRange/open-ended955=== PAUSE TestParseSingleRange/open-ended956=== RUN TestIsValidCachePath/invalid_char_u957=== PAUSE TestIsValidCachePath/invalid_char_u958=== RUN TestParseSingleRange/end_clamped_to_size959=== PAUSE TestParseSingleRange/end_clamped_to_size960=== RUN TestIsValidCachePath/random_path961=== PAUSE TestIsValidCachePath/random_path962=== RUN TestIsValidCachePath/empty963=== PAUSE TestIsValidCachePath/empty964=== RUN TestParseSingleRange/suffix965=== RUN TestIsValidCachePath/leading_slash966=== PAUSE TestParseSingleRange/suffix967=== PAUSE TestIsValidCachePath/leading_slash968=== RUN TestParseSingleRange/suffix_exceeds_size969=== PAUSE TestParseSingleRange/suffix_exceeds_size970=== RUN TestIsValidCachePath/wrong_extension971=== PAUSE TestIsValidCachePath/wrong_extension972=== RUN TestIsValidCachePath/short_hash973=== RUN TestParseSingleRange/single_byte974=== PAUSE TestIsValidCachePath/short_hash975=== CONT TestGCTaskStore_PhaseUpdates976=== PAUSE TestParseSingleRange/single_byte977=== RUN TestParseSingleRange/start_past_EOF978=== CONT TestConcurrentPinUpdatesAgree979--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)980=== PAUSE TestParseSingleRange/start_past_EOF981=== RUN TestParseSingleRange/start_far_past_EOF982=== PAUSE TestParseSingleRange/start_far_past_EOF983=== CONT TestPush_SignsNarinfosOfItsPendingObjects984--- PASS: TestGenerateLandingPage (0.02s)985=== CONT TestPushWaitsForSweepHoldingRow986--- PASS: TestSkippedUploadsHandler (0.04s)987=== CONT TestMultipartCleanup988=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure989=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure990=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart991=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart992=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts993=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts994=== CONT TestGCEndsOnShutdown995=== RUN TestGCEndsOnShutdown/before_the_run996=== PAUSE TestGCEndsOnShutdown/before_the_run997=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete998=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete999=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1000=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1001=== CONT TestFailedS3DeleteKeepsTombstone1002--- PASS: TestService_Rustfstest (0.83s)1003=== CONT TestClientWithDependencies1004--- PASS: TestReadProxyInvalidPath (0.85s)1005=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded10062026/10/28 14:31:58 INFO Received push request method=POST path=/api/pushes1007--- PASS: TestReadProxyHead (0.90s)1008=== CONT TestLeadEndsOnShutdown1009=== CONT TestConnectSerialisesConcurrentMigrations1010--- PASS: TestPresentRefreshesOnlyStaleClosures (0.91s)10112026/10/28 14:31:59 INFO Received uploads request method=POST path=/api/pending_closures1012=== CONT TestPinProtectsFromGC1013--- PASS: TestReadProxyRangeRequest (1.53s)10142026-10-28 14:31:59.357 UTC [548] ERROR: duplicate key value violates unique constraint "pg_class_relname_nsp_index"10152026-10-28 14:31:59.357 UTC [548] DETAIL: Key (relname, relnamespace)=(goose_db_version_id_seq, 2200) already exists.10162026-10-28 14:31:59.357 UTC [548] STATEMENT: CREATE TABLE goose_db_version (1017 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1018 version_id bigint NOT NULL,1019 is_applied boolean NOT NULL,1020 tstamp timestamp NOT NULL DEFAULT now()1021 )10222026/10/28 14:31:59 INFO Received uploads request method=POST path=/api/pending_closures10232026/10/28 14:31:59 INFO Received uploads request method=POST path=/api/pending_closures10242026/10/28 14:31:59 INFO Received create pin request method=POST path=/api/pins/app10252026/10/28 14:31:59 INFO Received create pin request method=POST path=/api/pins/app10262026/10/28 14:31:59 INFO Received uploads request method=POST path=/api/pending_closures1027=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1028--- PASS: TestReadProxyNarStreaming (1.64s)10292026/10/28 14:31:59 INFO Received uploads request method=POST path=/api/pending_closures1030--- PASS: TestReadProxyContentNegotiation (1.71s)1031=== CONT TestClientIntegration10322026/10/28 14:31:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10332026/10/28 14:31:59 INFO Received uploads request method=POST path=/api/pending_closures1034--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.73s)1035=== CONT TestForceGCDuringPushOffersSweptObject1036=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1037=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1038=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1039=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1040=== CONT TestTombstonedObjectOfferedWithoutWaiting10412026/10/28 14:31:59 INFO Received cleanup request method=DELETE path=/api/pending_closures10422026/10/28 14:31:59 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"10432026/10/28 14:31:59 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket17/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10442026/10/28 14:31:59 INFO Aborted multipart uploads count=0 kept=110452026/10/28 14:31:59 INFO Aborted multipart uploads count=0 kept=010462026/10/28 14:31:59 INFO Received cleanup request method=DELETE path=/api/pending_closures10472026/10/28 14:31:59 INFO Aborted multipart uploads count=1 kept=010482026/10/28 14:31:59 WARN Force mode enabled - objects will be deleted immediately without grace period1049--- PASS: TestService_AuthMiddleware (1.82s)1050=== CONT TestService_ReadScope_PublicByDefault10512026/10/28 14:31:59 INFO Received uploads request method=POST path=/api/pending_closures10522026/10/28 14:31:59 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."10532026/10/28 14:31:59 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1054=== CONT TestIsValidUploadKey1055--- PASS: TestMultipartCleanup (1.79s)1056=== RUN TestIsValidUploadKey/narinfo1057=== PAUSE TestIsValidUploadKey/narinfo1058=== RUN TestIsValidUploadKey/nar_zst1059=== PAUSE TestIsValidUploadKey/nar_zst1060=== RUN TestIsValidUploadKey/nar_xz1061=== PAUSE TestIsValidUploadKey/nar_xz1062=== RUN TestIsValidUploadKey/nar_plain1063=== PAUSE TestIsValidUploadKey/nar_plain1064=== RUN TestIsValidUploadKey/listing1065=== PAUSE TestIsValidUploadKey/listing1066=== RUN TestIsValidUploadKey/build_log1067=== PAUSE TestIsValidUploadKey/build_log1068=== RUN TestIsValidUploadKey/build_log_home-manager_file1069=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1070=== RUN TestIsValidUploadKey/build_log_plus_in_name1071=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1072=== RUN TestIsValidUploadKey/build_log_question_mark1073=== PAUSE TestIsValidUploadKey/build_log_question_mark1074=== RUN TestIsValidUploadKey/build_log_equals1075=== PAUSE TestIsValidUploadKey/build_log_equals1076=== RUN TestIsValidUploadKey/realisation1077=== PAUSE TestIsValidUploadKey/realisation1078=== RUN TestIsValidUploadKey/realisation_plus_in_output1079=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1080=== RUN TestIsValidUploadKey/nix-cache-info1081=== PAUSE TestIsValidUploadKey/nix-cache-info1082=== RUN TestIsValidUploadKey/index.html1083=== PAUSE TestIsValidUploadKey/index.html1084=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1085=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1086=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1087=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1088=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1089=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1090=== RUN TestIsValidUploadKey/traversal1091=== PAUSE TestIsValidUploadKey/traversal1092=== RUN TestIsValidUploadKey/traversal_nar1093=== PAUSE TestIsValidUploadKey/traversal_nar1094=== RUN TestIsValidUploadKey/absolute1095=== PAUSE TestIsValidUploadKey/absolute1096=== RUN TestIsValidUploadKey/empty_key1097=== PAUSE TestIsValidUploadKey/empty_key1098=== RUN TestIsValidUploadKey/unknown_type1099=== PAUSE TestIsValidUploadKey/unknown_type1100=== CONT TestService_AuthMiddleware_OIDC1101--- PASS: TestObjectStatsUpdatedOncePerCommit (1.84s)1102=== CONT TestGCSweepDeliversEachKeyOnce1103--- PASS: TestFailedS3DeleteKeepsTombstone (1.42s)1104=== CONT TestReadProxyDisabled11052026/10/28 14:31:59 WARN readiness check failed error="closed pool"11062026/10/28 14:31:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11072026/10/28 14:31:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11082026/10/28 14:31:59 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LjljYmFkYWZiLTJhNmYtNDBmYS1hMzVjLTc5NDkwNTg3YzMyNngxNzkzMTk3OTE5MzgwMDY0NTI41109--- PASS: TestService_readinessHandler (1.88s)1110=== CONT TestClientPushesUseOnePush1111=== CONT TestPush_CompleteWaitsForCleanupOfThePush1112--- PASS: TestReadRedirectKeepsNarinfoProxied (1.87s)11132026/10/28 14:31:59 INFO Received push request method=POST path=/api/pushes11142026/10/28 14:31:59 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LmQwY2EwNjgyLTg1NjUtNGIxNy1hMjhlLTYxMjM3ZDJkYzIzYngxNzkzMTk3OTE4NjkyMTM1MjEy parts=1011152026/10/28 14:31:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11162026/10/28 14:31:59 INFO Received uploads request method=POST path=/api/pending_closures11172026/10/28 14:31:59 INFO Signed narinfos id=1 count=111182026/10/28 14:31:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11192026/10/28 14:31:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11202026/10/28 14:31:59 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"11212026/10/28 14:31:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11222026/10/28 14:31:59 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"11232026/10/28 14:31:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11242026/10/28 14:31:59 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=111252026/10/28 14:31:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11262026/10/28 14:31:59 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1127=== CONT TestResolveDBConnectionString1128--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.93s)1129=== RUN TestResolveDBConnectionString/flag_wins1130=== PAUSE TestResolveDBConnectionString/flag_wins1131=== RUN TestResolveDBConnectionString/file_when_flag_empty1132=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1133=== RUN TestResolveDBConnectionString/missing_file_is_an_error1134=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1135=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1136=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1137=== RUN TestResolveDBConnectionString/nothing_configured1138=== PAUSE TestResolveDBConnectionString/nothing_configured1139=== CONT TestSweepRechecksPendingAfterLocking1140--- PASS: TestService_healthCheckHandler (1.95s)1141=== CONT TestReadRedirectUsesPublicS3URL11422026/10/28 14:31:59 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LjljYmFkYWZiLTJhNmYtNDBmYS1hMzVjLTc5NDkwNTg3YzMyNngxNzkzMTk3OTE5MzgwMDY0NTI4 error="Delete \"http://localhost:34021/bucket12/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LjljYmFkYWZiLTJhNmYtNDBmYS1hMzVjLTc5NDkwNTg3YzMyNngxNzkzMTk3OTE5MzgwMDY0NTI4\": injected: abort refused"11432026/10/28 14:31:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11442026/10/28 14:31:59 INFO Received uploads request method=POST path=/api/pending_closures11452026/10/28 14:31:59 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LjljYmFkYWZiLTJhNmYtNDBmYS1hMzVjLTc5NDkwNTg3YzMyNngxNzkzMTk3OTE5MzgwMDY0NTI411462026/10/28 14:31:59 ERROR Failed to register completed object error="get pending object \"nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst\": context canceled" object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst11472026/10/28 14:31:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11482026/10/28 14:31:59 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=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LjljYmFkYWZiLTJhNmYtNDBmYS1hMzVjLTc5NDkwNTg3YzMyNngxNzkzMTk3OTE5MzgwMDY0NTI411492026/10/28 14:31:59 INFO lead: acquired remote=192.0.2.1:123411502026/10/28 14:31:59 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LjljYmFkYWZiLTJhNmYtNDBmYS1hMzVjLTc5NDkwNTg3YzMyNngxNzkzMTk3OTE5MzgwMDY0NTI4 parts=11151=== CONT TestReadProxyConditionalGet1152--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (1.18s)1153--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.04s)1154=== CONT TestReadProxyOutlastsServerWriteTimeout1155=== NAME TestClientWithDependencies1156 client_integration_test.go:722: Built derivation: /build/TestClientWithDependencies4081254562/001/store/l5kzjwnl5pzkjaisb2cbjah5783b7cci-test-script11572026/10/28 14:31:59 INFO Received uploads request method=POST path=/api/pending_closures1158 client_integration_test.go:724: Found 1 dependencies (including self)11592026/10/28 14:31:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36333/oidc11602026/10/28 14:31:59 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo11612026/10/28 14:31:59 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo11622026/10/28 14:31:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1163=== NAME TestPinProtectsFromGC1164 client_integration_test.go:854: Pinned store path: /build/TestPinProtectsFromGC3262314366/001/store/c7pkpynrcviwf2i6xs90rmvyzhbb1p77-pinned-file.txt1165 client_integration_test.go:855: Unpinned store path: /build/TestPinProtectsFromGC3262314366/001/store/s2safkvw9j1j06w2s6gn1fyvizq84sf8-unpinned-file.txt1166=== CONT TestGCAdvisoryLockBlocksConcurrentRun1167--- PASS: TestConcurrentPinUpdatesAgree (2.12s)11682026/10/28 14:31:59 INFO Received uploads request method=POST path=/api/pending_closures11692026/10/28 14:31:59 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LjhkN2NhOGJmLTExYmMtNGY2Zi1hZmI4LWE5ODczNmQ5NWUxZXgxNzkzMTk3OTE5MzUxNTA1NDUy parts=1211702026/10/28 14:31:59 INFO Received uploads request method=POST path=/api/pending_closures1171=== NAME TestClientIntegration1172 client_integration_test.go:331: Created store path: /build/TestClientIntegration3430277883/002/store/scnz88dfrii41851ki6b81yhyxl8x6xa-test-file.txt1173--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.43s)1174=== CONT TestPush_RejectsBadRequests11752026/10/28 14:31:59 INFO Received uploads request method=POST path=/api/pending_closures1176=== CONT TestReadProxyRootRedirectsToIndexHTML1177--- PASS: TestService_ReadScope_PublicByDefault (0.36s)11782026/10/28 14:32:00 INFO Received push request method=POST path=/api/pushes11792026/10/28 14:32:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11802026/10/28 14:32:00 INFO Uploading l5kzjwnl5pzkjaisb2cbjah5783b7cci-test-script (136B)11812026/10/28 14:32:00 INFO Received push request method=POST path=/api/pushes1182--- PASS: TestReadProxyDisabled (0.35s)1183=== CONT TestPush_RootsAreLockedInByteOrder11842026/10/28 14:32:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11852026/10/28 14:32:00 INFO Uploading c7pkpynrcviwf2i6xs90rmvyzhbb1p77-pinned-file.txt (128B)11862026/10/28 14:32:00 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"11872026/10/28 14:32:00 WARN Failed to register uploaded object key=log/025r9jfss5clf3lgrfqqijnci346cfxb-test-script.drv error="server returned 404: 404 page not found\n"11882026/10/28 14:32:00 WARN Failed to register uploaded object key=l5kzjwnl5pzkjaisb2cbjah5783b7cci.ls error="server returned 404: 404 page not found\n"11892026/10/28 14:32:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11902026/10/28 14:32:00 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11912026/10/28 14:32:00 INFO Signed narinfos id=1 count=111922026/10/28 14:32:00 INFO Uploading 1 narinfos11932026/10/28 14:32:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11942026/10/28 14:32:00 WARN Failed to register uploaded object key=c7pkpynrcviwf2i6xs90rmvyzhbb1p77.ls error="server returned 404: 404 page not found\n"11952026/10/28 14:32:00 INFO Received push request method=POST path=/api/pushes11962026/10/28 14:32:00 INFO Signed narinfos id=1 count=111972026/10/28 14:32:00 INFO Uploading 1 narinfos11982026/10/28 14:32:00 INFO Received complete push request method=POST path=/api/pushes/1/complete11992026/10/28 14:32:00 WARN Failed to register uploaded object key=l5kzjwnl5pzkjaisb2cbjah5783b7cci.narinfo error="server returned 404: 404 page not found\n"12002026/10/28 14:32:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12012026/10/28 14:32:00 INFO Uploading scnz88dfrii41851ki6b81yhyxl8x6xa-test-file.txt (152B)12022026/10/28 14:32:00 INFO Completed push id=1 objects=4 duration=22.369081ms12032026/10/28 14:32:00 INFO Upload complete. (133ms)12042026/10/28 14:32:00 INFO Received complete push request method=POST path=/api/pushes/1/complete12052026/10/28 14:32:00 WARN Failed to register uploaded object key=c7pkpynrcviwf2i6xs90rmvyzhbb1p77.narinfo error="server returned 404: 404 page not found\n"12062026/10/28 14:32:00 INFO Aborted multipart uploads count=0 kept=012072026/10/28 14:32:00 WARN Force mode enabled - objects will be deleted immediately without grace period12082026/10/28 14:32:00 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=012092026/10/28 14:32:00 INFO Completed push id=1 objects=3 duration=30.662195ms12102026/10/28 14:32:00 INFO Upload complete. (147ms)1211--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.67s)1212=== CONT TestPush_RepeatedRootCommitsOnce12132026/10/28 14:32:00 WARN Failed to register uploaded object key=scnz88dfrii41851ki6b81yhyxl8x6xa.ls error="server returned 404: 404 page not found\n"12142026/10/28 14:32:00 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12152026/10/28 14:32:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12162026/10/28 14:32:00 INFO Signed narinfos id=1 count=112172026/10/28 14:32:00 INFO Uploading 1 narinfos12182026/10/28 14:32:00 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>12192026/10/28 14:32:00 INFO Received complete push request method=POST path=/api/pushes/1/complete12202026/10/28 14:32:00 WARN Failed to register uploaded object key=scnz88dfrii41851ki6b81yhyxl8x6xa.narinfo error="server returned 404: 404 page not found\n"12212026/10/28 14:32:00 INFO Received push request method=POST path=/api/pushes12222026/10/28 14:32:00 INFO Vacuumed table table=pending_closures12232026/10/28 14:32:00 INFO Completed push id=1 objects=3 duration=11.433823ms12242026/10/28 14:32:00 INFO Upload complete. (259ms)12252026/10/28 14:32:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12262026/10/28 14:32:00 INFO Uploading s2safkvw9j1j06w2s6gn1fyvizq84sf8-unpinned-file.txt (128B)12272026/10/28 14:32:00 INFO Vacuumed table table=pending_objects12282026/10/28 14:32:00 INFO Vacuumed table table=multipart_uploads12292026/10/28 14:32:00 INFO Aborted multipart uploads count=0 kept=012302026/10/28 14:32:00 INFO Vacuumed table table=closures12312026/10/28 14:32:00 INFO Vacuumed table table=objects1232=== CONT TestReadProxy404And4291233--- PASS: TestReadProxyNarinfo (2.47s)12342026/10/28 14:32:00 WARN Force mode enabled - objects will be deleted immediately without grace period12352026/10/28 14:32:00 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"1236--- PASS: TestPushWaitsForSweepHoldingRow (2.45s)1237=== CONT TestPresentReportsOnlyClosureRoots12382026/10/28 14:32:00 WARN Failed to register uploaded object key=s2safkvw9j1j06w2s6gn1fyvizq84sf8.ls error="server returned 404: 404 page not found\n"1239=== NAME TestClientWithDependencies1240 client_integration_test.go:740: Skipping nix copy test - isolated store (/build/TestClientWithDependencies4081254562/001/store) requires matching store prefix12412026/10/28 14:32:00 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12422026/10/28 14:32:00 INFO Signed narinfos id=2 count=112432026/10/28 14:32:00 INFO Uploading 1 narinfos12442026/10/28 14:32:00 INFO Received complete push request method=POST path=/api/pushes/2/complete12452026/10/28 14:32:00 WARN Failed to register uploaded object key=s2safkvw9j1j06w2s6gn1fyvizq84sf8.narinfo error="server returned 404: 404 page not found\n"12462026/10/28 14:32:00 INFO Completed push id=2 objects=3 duration=2.575643ms12472026/10/28 14:32:00 INFO Upload complete. (147ms)12482026/10/28 14:32:00 INFO All 1 paths already cached1249=== NAME TestClientIntegration1250 client_integration_test.go:357: Retrieved narinfo from S3:1251 StorePath: /build/TestClientIntegration3430277883/002/store/scnz88dfrii41851ki6b81yhyxl8x6xa-test-file.txt1252 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1253 Compression: zstd1254 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11255 NarSize: 1521256 References: 1257 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11258 client_integration_test.go:358: Retrieved .ls file from S3 (compressed size: 77 bytes)1259 client_integration_test.go:358: Decompressed .ls content (64 bytes):1260 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1261--- PASS: TestClientWithDependencies (1.67s)1262=== CONT TestGetExistingObjectsLocksRows12632026/10/28 14:32:00 INFO Received push request method=POST path=/api/pushes12642026/10/28 14:32:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12652026/10/28 14:32:00 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=012662026/10/28 14:32:00 INFO Vacuumed table table=pending_closures12672026/10/28 14:32:00 INFO Vacuumed table table=pending_objects12682026/10/28 14:32:00 INFO Vacuumed table table=multipart_uploads12692026/10/28 14:32:00 INFO Vacuumed table table=closures12702026/10/28 14:32:00 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LjljMWExMzAxLTIzZDEtNDY1My04OTFhLTI2YjA5MWE5OTBiMngxNzkzMTk3OTE4NjkyNDk2MTM1 parts=1012712026/10/28 14:32:00 INFO Vacuumed table table=objects12722026/10/28 14:32:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures12732026/10/28 14:32:00 INFO Garbage collection started12742026/10/28 14:32:00 INFO Aborted multipart uploads count=0 kept=01275=== CONT TestGracefulShutdownDrainsInflight1276--- PASS: TestGCSweepDeliversEachKeyOnce (0.70s)12772026/10/28 14:32:00 INFO Starting HTTP server address=127.0.0.1:4481112782026/10/28 14:32:00 INFO Shutdown signal received, draining in-flight requests timeout=10s12792026/10/28 14:32:00 WARN Force mode enabled - objects will be deleted immediately without grace period1280--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.39s)1281=== CONT TestCreatePinRejectsBadInput1282--- PASS: TestConnectSerialisesConcurrentMigrations (1.65s)1283=== CONT TestGCTaskStore_Fail1284--- PASS: TestGCTaskStore_Fail (0.00s)1285=== CONT TestGCTaskStore_GetReturnsLatest1286--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1287=== CONT TestPresignedUploadRegisteredBeforeCommit12882026/10/28 14:32:00 INFO Aborted multipart uploads count=0 kept=012892026/10/28 14:32:00 INFO Received push request method=POST path=/api/pushes12902026/10/28 14:32:00 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=012912026/10/28 14:32:00 INFO Vacuumed table table=pending_closures12922026/10/28 14:32:00 WARN Force mode enabled - objects will be deleted immediately without grace period12932026/10/28 14:32:00 INFO Object in database but missing from S3 key=scnz88dfrii41851ki6b81yhyxl8x6xa.ls12942026/10/28 14:32:00 WARN Found objects in DB but missing from S3, will re-upload count=112952026/10/28 14:32:00 INFO Vacuumed table table=pending_objects12962026/10/28 14:32:00 INFO Vacuumed table table=multipart_uploads12972026/10/28 14:32:00 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12982026/10/28 14:32:00 INFO Vacuumed table table=closures12992026/10/28 14:32:00 INFO Vacuumed table table=objects1300=== CONT TestRegisterCompletedObjectNeedsPendingRow1301--- PASS: TestGracefulShutdownDrainsInflight (0.07s)13022026/10/28 14:32:00 INFO Received complete push request method=POST path=/api/pushes/2/complete13032026/10/28 14:32:00 WARN Failed to register uploaded object key=scnz88dfrii41851ki6b81yhyxl8x6xa.ls error="server returned 404: 404 page not found\n"13042026/10/28 14:32:00 INFO Completed push id=2 objects=3 duration=2.901086ms13052026/10/28 14:32:00 INFO Upload complete. (68ms)1306=== NAME TestClientIntegration1307 client_integration_test.go:375: Retrieved .ls file from S3 (compressed size: 62 bytes)1308 client_integration_test.go:375: Decompressed .ls content (49 bytes):1309 {"version":1,"root":{"type":"regular","size":39}}13102026/10/28 14:32:00 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=013112026/10/28 14:32:00 INFO Vacuumed table table=pending_closures13122026/10/28 14:32:00 INFO Vacuumed table table=pending_objects13132026/10/28 14:32:00 INFO Vacuumed table table=multipart_uploads13142026/10/28 14:32:00 INFO Vacuumed table table=closures13152026/10/28 14:32:00 INFO Vacuumed table table=objects1316--- PASS: TestSweepRechecksPendingAfterLocking (0.72s)1317=== CONT TestCreatePin_ReservedPins13182026/10/28 14:32:00 INFO Received push request method=POST path=/api/pushes1319=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1320=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1321=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1322=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1323=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1324=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1325=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1326=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1327=== CONT TestGCTaskStore_GetEmpty1328--- PASS: TestGCTaskStore_GetEmpty (0.00s)1329=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit13302026/10/28 14:32:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13312026/10/28 14:32:00 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13322026/10/28 14:32:00 INFO Uploading q51dwjs2mbrmcvf5cmgpmrizapqw2yhh-b (216B)13332026/10/28 14:32:00 INFO Uploading rzkq6wr36kfc202jxis7i4xjbs3g7l7k-shared-dep (136B)13342026/10/28 14:32:00 WARN Failed to register uploaded object key=8mmycgrg6wgys3s8mwj0bs2mr1pcy5dw.ls error="server returned 404: 404 page not found\n"13352026/10/28 14:32:00 WARN Failed to register uploaded object key=nar/175fck9adi52s11mfacxqpa65aqffdw5a2h412pq4si5avnm5a7b.nar.zst error="server returned 404: 404 page not found\n"13362026/10/28 14:32:00 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13372026/10/28 14:32:00 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LmZkODVhOTY1LTA0ODMtNGY4Zi1iMmExLWI3ZWMwYjkyODU3YXgxNzkzMTk3OTE5NzMxOTQ1ODA4 parts=1213382026/10/28 14:32:00 INFO Received uploads request method=POST path=/api/pending_closures13392026/10/28 14:32:00 INFO Received push request method=POST path=/api/pushes13402026/10/28 14:32:00 WARN Failed to register uploaded object key=rzkq6wr36kfc202jxis7i4xjbs3g7l7k.ls error="server returned 404: 404 page not found\n"13412026/10/28 14:32:00 WARN Failed to register uploaded object key=q51dwjs2mbrmcvf5cmgpmrizapqw2yhh.ls error="server returned 404: 404 page not found\n"13422026/10/28 14:32:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13432026/10/28 14:32:00 INFO Signed narinfos id=1 count=313442026/10/28 14:32:00 INFO Uploading 3 narinfos13452026/10/28 14:32:00 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13462026/10/28 14:32:00 INFO Received complete push request method=POST path=/api/pushes/1/complete13472026/10/28 14:32:00 WARN Failed to register uploaded object key=rzkq6wr36kfc202jxis7i4xjbs3g7l7k.narinfo error="server returned 404: 404 page not found\n"13482026/10/28 14:32:00 WARN Failed to register uploaded object key=q51dwjs2mbrmcvf5cmgpmrizapqw2yhh.narinfo error="server returned 404: 404 page not found\n"13492026/10/28 14:32:00 WARN Failed to register uploaded object key=8mmycgrg6wgys3s8mwj0bs2mr1pcy5dw.narinfo error="server returned 404: 404 page not found\n"13502026/10/28 14:32:00 INFO Received complete push request method=POST path=/api/pushes/3/complete13512026/10/28 14:32:00 WARN Failed to register uploaded object key=scnz88dfrii41851ki6b81yhyxl8x6xa.ls error="server returned 404: 404 page not found\n"13522026/10/28 14:32:00 INFO Completed push id=1 objects=8 duration=9.838168ms13532026/10/28 14:32:00 INFO Upload complete. (285ms)13542026/10/28 14:32:00 INFO Completed push id=3 objects=3 duration=3.108668ms13552026/10/28 14:32:00 INFO Upload complete. (232ms)1356=== NAME TestClientPushesUseOnePush1357 client_pushes_test.go:97: Retrieved narinfo from S3:1358 StorePath: /build/TestClientPushesUseOnePush3589925659/001/store/rzkq6wr36kfc202jxis7i4xjbs3g7l7k-shared-dep1359 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1360 Compression: zstd1361 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821362 NarSize: 1361363 References: 1364 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1365=== NAME TestClientIntegration1366 client_integration_test.go:392: Retrieved .ls file from S3 (compressed size: 62 bytes)1367 client_integration_test.go:392: Decompressed .ls content (49 bytes):1368 {"version":1,"root":{"type":"regular","size":39}}1369=== NAME TestClientPushesUseOnePush1370 client_pushes_test.go:97: Retrieved narinfo from S3:1371 StorePath: /build/TestClientPushesUseOnePush3589925659/001/store/8mmycgrg6wgys3s8mwj0bs2mr1pcy5dw-a1372 URL: nar/175fck9adi52s11mfacxqpa65aqffdw5a2h412pq4si5avnm5a7b.nar.zst1373 Compression: zstd1374 NarHash: sha256:175fck9adi52s11mfacxqpa65aqffdw5a2h412pq4si5avnm5a7b1375 NarSize: 2161376 References: /build/TestClientPushesUseOnePush3589925659/001/store/rzkq6wr36kfc202jxis7i4xjbs3g7l7k-shared-dep1377 CA: text:sha256:09rbnfj8pi1nb1b4sx3wm4pksrhj0wgcb2ibdia5552wkmfwbwci1378--- PASS: TestReadRedirectUsesPublicS3URL (0.97s)1379=== CONT TestGCTaskStore_DeduplicateSameParams1380=== CONT TestGCTaskStore_ConflictDifferentParams1381=== CONT TestOrphanedObjectsGC1382--- PASS: TestReadProxyConditionalGet (0.88s)1383=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1384=== CONT TestReadRedirectNar1385--- PASS: TestCompletedNarNotReofferedAcrossClosures (2.92s)1386--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1387--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1388=== NAME TestClientPushesUseOnePush1389 client_pushes_test.go:97: Retrieved narinfo from S3:1390 StorePath: /build/TestClientPushesUseOnePush3589925659/001/store/q51dwjs2mbrmcvf5cmgpmrizapqw2yhh-b1391 URL: nar/175fck9adi52s11mfacxqpa65aqffdw5a2h412pq4si5avnm5a7b.nar.zst1392 Compression: zstd1393 NarHash: sha256:175fck9adi52s11mfacxqpa65aqffdw5a2h412pq4si5avnm5a7b1394 NarSize: 2161395 References: /build/TestClientPushesUseOnePush3589925659/001/store/rzkq6wr36kfc202jxis7i4xjbs3g7l7k-shared-dep1396 CA: text:sha256:09rbnfj8pi1nb1b4sx3wm4pksrhj0wgcb2ibdia5552wkmfwbwci1397=== RUN TestPush_RejectsBadRequests/no_roots1398=== PAUSE TestPush_RejectsBadRequests/no_roots1399=== RUN TestPush_RejectsBadRequests/no_objects1400=== PAUSE TestPush_RejectsBadRequests/no_objects1401=== RUN TestPush_RejectsBadRequests/bad_root1402=== PAUSE TestPush_RejectsBadRequests/bad_root1403=== RUN TestPush_RejectsBadRequests/root_not_in_objects1404=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1405=== CONT TestDeletePinKeepsRowWhenS3Fails14062026/10/28 14:32:00 INFO Received push request method=POST path=/api/pushes1407--- PASS: TestClientPushesUseOnePush (1.08s)1408=== CONT TestPendingClosureFailureAbortsItsUploads14092026/10/28 14:32:00 INFO Received push request method=POST path=/api/pushes14102026/10/28 14:32:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46613/oidc14112026/10/28 14:32:00 INFO Received push request method=POST path=/api/pushes14122026/10/28 14:32:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14132026/10/28 14:32:00 INFO Uploading prlls716b5532x33nv9jcbn8bnvrsixb-lost-commit.txt (152B)1414--- PASS: TestPresentReportsOnlyClosureRoots (0.58s)1415=== CONT TestObjectStatsTrigger14162026/10/28 14:32:00 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"14172026/10/28 14:32:00 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign14182026/10/28 14:32:00 WARN Failed to register uploaded object key=prlls716b5532x33nv9jcbn8bnvrsixb.ls error="server returned 404: 404 page not found\n"14192026/10/28 14:32:00 INFO lead: released remote=192.0.2.1:123414202026/10/28 14:32:00 INFO Signed narinfos id=4 count=114212026/10/28 14:32:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14222026/10/28 14:32:00 INFO Uploading 1 narinfos14232026/10/28 14:32:00 INFO Received complete push request method=POST path=/api/pushes/4/complete14242026/10/28 14:32:00 WARN Failed to register uploaded object key=prlls716b5532x33nv9jcbn8bnvrsixb.narinfo error="server returned 404: 404 page not found\n"14252026/10/28 14:32:00 INFO Completed push id=4 objects=3 duration=2.457662ms14262026/10/28 14:32:00 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:34099/api/pushes/4/complete\": EOF" url=http://127.0.0.1:34099/api/pushes/4/complete14272026/10/28 14:32:00 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LmUzMzgwNTJlLWZiMWEtNGI1OC1hMDdjLTU3Njk0ODI0MDkzYngxNzkzMTk3OTE5OTg4MjIxMjMw error="Get \"http://127.0.0.1:1/bucket11/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"14282026/10/28 14:32:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LjlhZDVkOThlLTMyODktNDNlZi04YzgxLWNkYWZhMTIzNDc5N3gxNzkzMTk3OTE5OTY0NTQ2MDM3 parts=121429--- PASS: TestLeadEndsOnShutdown (2.19s)1430=== CONT TestOrphanedObjectsGCStressTest14312026/10/28 14:32:00 INFO Received cleanup request method=DELETE path=/api/pending_closures14322026/10/28 14:32:00 INFO Aborted multipart uploads count=1 kept=014332026/10/28 14:32:00 INFO Received create pin request method=POST path=/api/pins/deploy14342026/10/28 14:32:00 INFO Received create pin request method=POST path=/api/pins/deploy14352026/10/28 14:32:00 INFO Received create pin request method=POST path=/api/pins/deploy14362026/10/28 14:32:00 INFO Received create pin request method=POST path=/api/pins/deploy14372026/10/28 14:32:00 INFO Received create pin request method=POST path=/api/pins/deploy14382026/10/28 14:32:00 INFO Received create pin request method=POST path=/api/pins/deploy14392026/10/28 14:32:00 INFO Received create pin request method=POST path=/api/pins/deploy14402026/10/28 14:32:00 INFO Received create pin request method=POST path=/api/pins/deploy1441--- PASS: TestGetExistingObjectsLocksRows (0.61s)1442=== CONT TestPendingCleanupUsesOneCutoff1443=== CONT TestService_cleanupPendingClosuresHandler1444--- PASS: TestRedundantMultipartUpload (3.12s)14452026/10/28 14:32:00 INFO Received uploads request method=POST path=/api/pending_closures14462026/10/28 14:32:00 INFO Received create pin request method=POST path=/api/pins/deploy14472026/10/28 14:32:00 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst14482026/10/28 14:32:00 INFO Received uploads request method=POST path=/api/pending_closures1449=== CONT TestPendingClosureFailureTracksEveryUpload1450--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.57s)1451=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1452=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1453=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1454=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1455=== CONT TestCommitRacingPendingCleanupKeepsObjects14562026/10/28 14:32:00 INFO Received push request method=POST path=/api/pushes14572026/10/28 14:32:00 INFO Received complete push request method=POST path=/api/pushes/4/complete1458--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.61s)1459=== CONT TestService_NativeMTLS14602026-10-28 14:32:01.000 UTC [575] ERROR: Push does not exist: id=414612026-10-28 14:32:01.000 UTC [575] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE14622026-10-28 14:32:01.000 UTC [575] STATEMENT: -- name: CommitPush :one1463 SELECT commit_push($1::bigint)::bigint1464 14652026/10/28 14:32:01 WARN Push not found id=414662026/10/28 14:32:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14672026/10/28 14:32:01 INFO Upload complete. (196ms)1468=== NAME TestClientIntegration1469 client_integration_test.go:422: Retrieved narinfo from S3:1470 StorePath: /build/TestClientIntegration3430277883/002/store/prlls716b5532x33nv9jcbn8bnvrsixb-lost-commit.txt1471 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1472 Compression: zstd1473 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1474 NarSize: 1521475 References: 1476 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1477 client_integration_test.go:425: Testing garbage collection...14782026/10/28 14:32:01 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LmNhYjY4YTRiLWY5YjgtNGVkZS1iZTcyLWI0NGVhNDUzMDI5MHgxNzkzMTk3OTE4NjkyNjI4NDE2 parts=1014792026/10/28 14:32:01 INFO Received complete push request method=POST path=/api/pushes/1/complete14802026/10/28 14:32:01 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"14812026/10/28 14:32:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14822026/10/28 14:32:01 INFO Completed push id=1 objects=6 duration=10.705056ms14832026/10/28 14:32:01 INFO Starting cleanup of old closures method=DELETE path=/api/closures14842026/10/28 14:32:01 INFO Garbage collection started14852026/10/28 14:32:01 INFO Received push request method=POST path=/api/pushes14862026/10/28 14:32:01 INFO Aborted multipart uploads count=0 kept=014872026/10/28 14:32:01 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LmJlYmEzY2ZkLTMwMmEtNDg4MC1hMjFjLWI1YTkyYzc2ODE3OHgxNzkzMTk3OTIwMzI1Mzk1ODc3 parts=101488--- PASS: TestPush_CompleteCommitsEveryRoot (3.25s)1489=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT1490=== CONT TestReconnectLeavesObjectsUnlocked1491--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (1.12s)14922026/10/28 14:32:01 WARN Force mode enabled - objects will be deleted immediately without grace period1493=== CONT TestCompleteMultipartUnregistered1494--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.38s)14952026/10/28 14:32:01 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=014962026/10/28 14:32:01 INFO Vacuumed table table=pending_closures14972026/10/28 14:32:01 INFO Vacuumed table table=pending_objects14982026/10/28 14:32:01 INFO Vacuumed table table=multipart_uploads14992026/10/28 14:32:01 INFO Vacuumed table table=closures15002026/10/28 14:32:01 INFO Received create pin request method=POST path=/api/pins/app15012026/10/28 14:32:01 INFO Vacuumed table table=objects1502=== CONT TestDeduplicatedObjectsRecordedAsPending1503--- PASS: TestReadRedirectNar (0.42s)15042026/10/28 14:32:01 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo15052026/10/28 14:32:01 INFO Received delete pin request method=DELETE path=/api/pins/app15062026/10/28 14:32:01 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket61/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"15072026/10/28 14:32:01 INFO Received delete pin request method=DELETE path=/api/pins/app15082026/10/28 14:32:01 INFO Received uploads request method=POST path=/api/pending_closures15092026/10/28 14:32:01 WARN Rate limiter enabled after throttle name=s3-test rate=515102026/10/28 14:32:01 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."15112026/10/28 14:32:01 WARN Rate limiter backed off name=s3-test rate=515122026/10/28 14:32:01 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."1513--- PASS: TestReadProxy404And429 (0.97s)1514=== CONT TestServerTLSConfig1515=== RUN TestServerTLSConfig/no_client_CA1516=== PAUSE TestServerTLSConfig/no_client_CA1517=== RUN TestServerTLSConfig/missing_CA_file1518=== PAUSE TestServerTLSConfig/missing_CA_file1519=== RUN TestServerTLSConfig/not_a_PEM_file1520=== PAUSE TestServerTLSConfig/not_a_PEM_file1521=== CONT TestGCBugBareHashReferences15222026/10/28 14:32:01 INFO Deleted pin name=app1523=== CONT TestService_verifyS3Integrity1524--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.55s)1525=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1526--- PASS: TestPendingClosureFailureAbortsItsUploads (0.55s)15272026/10/28 14:32:01 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15282026/10/28 14:32:01 WARN Refused reserved pin name=worker-x86_64-linux15292026/10/28 14:32:01 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15302026/10/28 14:32:01 INFO Received create pin request method=POST path=/api/pins/my-app15312026/10/28 14:32:01 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1532--- PASS: TestCreatePin_ReservedPins (0.91s)1533=== CONT TestMetricsCommit15342026-10-28 14:32:01.387 UTC [1259] ERROR: Push does not exist: id=115352026-10-28 14:32:01.387 UTC [1259] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE15362026-10-28 14:32:01.387 UTC [1259] STATEMENT: SELECT commit_push($1)1537=== CONT TestDeleteClosuresRacingPins1538--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.72s)15392026/10/28 14:32:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1540--- PASS: TestObjectStatsTrigger (0.58s)1541=== CONT TestGCMetrics15422026/10/28 14:32:01 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LjRhNjU3NjU5LWQ0NDktNGEzYi04YjE0LThhZmE4YzZjZTlhMngxNzkzMTk3OTIwNzc5NjA1OTE2 parts=1015432026/10/28 14:32:01 INFO Received uploads request method=POST path=/api/pending_closures15442026/10/28 14:32:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15452026/10/28 14:32:01 INFO Received uploads request method=POST path=/api/pending_closures15462026/10/28 14:32:01 INFO Received cleanup request method=DELETE path=/api/pending_closures15472026/10/28 14:32:01 INFO Aborted multipart uploads count=0 kept=015482026/10/28 14:32:01 INFO Received uploads request method=POST path=/api/pending_closures15492026/10/28 14:32:01 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LmViOGY4MDM3LTZmOTYtNGM2My05MmY5LTZhZDEyNTk4MTcxYngxNzkzMTk3OTIwODExODA4NDQ1 parts=1015502026/10/28 14:32:01 INFO Received cleanup request method=DELETE path=/api/pending_closures15512026/10/28 14:32:01 INFO Received cleanup request method=DELETE path=/api/pending_closures15522026/10/28 14:32:01 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15532026/10/28 14:32:01 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15542026/10/28 14:32:01 INFO Aborted multipart uploads count=1 kept=015552026/10/28 14:32:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15562026-10-28 14:32:01.519 UTC [1237] ERROR: Closure does not exist: id=115572026-10-28 14:32:01.519 UTC [1237] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE15582026-10-28 14:32:01.519 UTC [1237] STATEMENT: -- name: CommitPendingClosure :one1559 SELECT commit_pending_closure($1::bigint)::bigint1560 1561--- PASS: TestService_NativeMTLS (0.54s)1562=== CONT TestMetricsInventory1563--- PASS: TestService_cleanupPendingClosuresHandler (0.60s)1564=== CONT TestLeadElectsOneAndHandsOver1565=== NAME TestOrphanedObjectsGC1566 orphaned_objects_gc_test.go:287: GC Test Summary:1567 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1568 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1569 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1570 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1571 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects15722026/10/28 14:32:01 INFO Received uploads request method=POST path=/api/pending_closures1573=== CONT TestGCTaskStore_CompletedAllowsNewTask1574--- PASS: TestOrphanedObjectsGC (0.84s)1575--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1576=== CONT TestClientSharedPathCommittedMidPush15772026/10/28 14:32:01 INFO Aborted multipart uploads count=0 kept=015782026/10/28 14:32:01 WARN Force mode enabled - objects will be deleted immediately without grace period15792026/10/28 14:32:01 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015802026/10/28 14:32:01 INFO Vacuumed table table=pending_closures15812026/10/28 14:32:01 INFO Vacuumed table table=pending_objects15822026/10/28 14:32:01 INFO Vacuumed table table=multipart_uploads15832026/10/28 14:32:01 INFO Vacuumed table table=closures15842026/10/28 14:32:01 INFO Vacuumed table table=objects1585--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.61s)1586=== CONT TestNARDeduplicationMetadataUploadBug15872026/10/28 14:32:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1588--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.70s)1589=== CONT TestConnectWaitsForAPeerMigration15902026/10/28 14:32:01 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1591=== CONT TestPushDedupSurvivesConcurrentGC1592--- PASS: TestReconnectLeavesObjectsUnlocked (0.64s)1593--- PASS: TestCompleteMultipartUnregistered (0.60s)1594=== CONT TestUploadHandlersRejectInvalidKeys1595=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1596=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1597=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1598=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1599=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1600=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1601=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1602=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1603=== CONT TestLeadIncumbentAnnouncesAtOnce16042026/10/28 14:32:01 INFO Received uploads request method=POST path=/api/pending_closures16052026/10/28 14:32:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1606--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.61s)1607=== CONT TestSweepSkipsRowsLockedByPush16082026/10/28 14:32:01 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LjdhNTA1Y2ZmLWNkNTAtNDE3MC1hOGVkLTVmZDhiMWQyNTUzM3gxNzkzMTk3OTIxMDEwMTUyMzA2 parts=1016092026/10/28 14:32:01 INFO Received uploads request method=POST path=/api/pending_closures16102026/10/28 14:32:01 INFO Received push request method=POST path=/api/pushes16112026/10/28 14:32:01 INFO Received create pin request method=POST path=/api/pins/deploy16122026/10/28 14:32:01 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo1613=== CONT TestCacheStatsHandler1614--- PASS: TestCreatePinRejectsBadInput (1.58s)16152026/10/28 14:32:01 INFO Aborted multipart uploads count=0 kept=016162026/10/28 14:32:01 WARN Force mode enabled - objects will be deleted immediately without grace period16172026/10/28 14:32:01 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016182026/10/28 14:32:01 INFO Vacuumed table table=pending_closures16192026/10/28 14:32:01 INFO Vacuumed table table=pending_objects16202026/10/28 14:32:01 INFO Vacuumed table table=multipart_uploads16212026/10/28 14:32:01 INFO Vacuumed table table=closures16222026/10/28 14:32:01 INFO Vacuumed table table=objects16232026/10/28 14:32:02 INFO lead: acquired remote=192.0.2.1:12341624--- PASS: TestGCMetrics (0.58s)1625=== CONT TestService_createPendingClosureHandler16262026/10/28 14:32:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1627--- PASS: TestGCBugBareHashReferences (0.78s)1628=== CONT TestClientMultipleUploads1629--- PASS: TestMetricsInventory (0.50s)1630=== CONT TestGCSweepSkipsPendingObjects16312026/10/28 14:32:02 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4Ljg5NTVmZTIyLWM1YjktNDgxMS1hMmZjLWYyYzU2MzdkYTU2MXgxNzkzMTk3OTIwNzc4Nzg3NTY4 parts=1016322026/10/28 14:32:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16332026/10/28 14:32:02 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LjU3OGI1YjQzLTVjMjMtNDRjZC04OTlkLWNiYjAzODQ4MjM3ZngxNzkzMTk3OTIwODEwOTM4ODc3 parts=1016342026/10/28 14:32:02 INFO Received complete push request method=POST path=/api/pushes/1/complete16352026/10/28 14:32:02 INFO Completed push id=1 objects=4 duration=8.084232ms1636--- PASS: TestPush_RepeatedRootCommitsOnce (1.97s)1637=== CONT TestClientCADerivations1638=== NAME TestNARDeduplicationMetadataUploadBug1639 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2002027252/001/store/r63ynq3v3zqw8klapigq3cvf4d9wn22d-file1.txt16402026/10/28 14:32:02 INFO Received uploads request method=POST path=/api/pending_closures16412026/10/28 14:32:02 INFO lead: acquired remote=192.0.2.1:123416422026/10/28 14:32:02 INFO lead: released remote=192.0.2.1:12341643--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.42s)1644=== CONT TestService_RequireScope_OIDC16452026/10/28 14:32:02 INFO Aborted multipart uploads count=0 kept=016462026/10/28 14:32:02 WARN Force mode enabled - objects will be deleted immediately without grace period16472026/10/28 14:32:02 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016482026/10/28 14:32:02 INFO Vacuumed table table=pending_closures16492026/10/28 14:32:02 INFO Vacuumed table table=pending_objects16502026/10/28 14:32:02 INFO Vacuumed table table=multipart_uploads16512026/10/28 14:32:02 INFO Vacuumed table table=closures16522026/10/28 14:32:02 INFO Vacuumed table table=objects16532026/10/28 14:32:02 INFO Received push request method=POST path=/api/pushes16542026/10/28 14:32:02 INFO Aborted multipart uploads count=0 kept=016552026/10/28 14:32:02 INFO Aborted multipart uploads count=0 kept=016562026/10/28 14:32:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16572026/10/28 14:32:02 INFO Uploading r63ynq3v3zqw8klapigq3cvf4d9wn22d-file1.txt (160B)16582026/10/28 14:32:02 INFO Received push request method=POST path=/api/pushes16592026/10/28 14:32:02 WARN Force mode enabled - objects will be deleted immediately without grace period1660--- PASS: TestCacheStatsHandler (0.24s)1661=== CONT TestClientErrorHandling1662=== RUN TestClientErrorHandling/InvalidStorePath1663=== PAUSE TestClientErrorHandling/InvalidStorePath1664=== RUN TestClientErrorHandling/InvalidAuthToken1665=== PAUSE TestClientErrorHandling/InvalidAuthToken1666=== RUN TestClientErrorHandling/ServerNotAvailable1667=== PAUSE TestClientErrorHandling/ServerNotAvailable1668=== CONT TestService_AuthMiddleware_MTLSProxyHeader16692026/10/28 14:32: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=016702026/10/28 14:32:02 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16712026/10/28 14:32:02 INFO Uploading l69pmmndcc2xxz2b3azlh68lc00qz9lj-shared-dep (136B)16722026/10/28 14:32:02 INFO Uploading kilncn0kwj53l3p9fkdsbxw0lssmxvxb-top (224B)16732026/10/28 14:32:02 INFO Vacuumed table table=pending_closures16742026/10/28 14:32:02 INFO Vacuumed table table=pending_objects16752026/10/28 14:32:02 INFO Vacuumed table table=multipart_uploads16762026/10/28 14:32:02 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"16772026/10/28 14:32:02 INFO Vacuumed table table=closures16782026/10/28 14:32:02 INFO Vacuumed table table=objects16792026/10/28 14:32:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16802026/10/28 14:32:02 WARN Failed to register uploaded object key=r63ynq3v3zqw8klapigq3cvf4d9wn22d.ls error="server returned 404: 404 page not found\n"16812026/10/28 14:32:02 INFO Received uploads request method=POST path=/api/pending_closures16822026/10/28 14:32:02 INFO Signed narinfos id=1 count=116832026/10/28 14:32:02 INFO Received uploads request method=POST path=/api/pending_closures16842026/10/28 14:32:02 INFO Received uploads request method=POST path=/api/pending_closures16852026/10/28 14:32:02 INFO Uploading 1 narinfos16862026/10/28 14:32:02 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16872026/10/28 14:32:02 WARN Failed to register uploaded object key=nar/01afd2yl70y8hizpvs35x2iq9d3b8jy6fdqmmrl3099m14r1kgyf.nar.zst error="server returned 404: 404 page not found\n"16882026/10/28 14:32:02 INFO Aborted multipart uploads count=0 kept=016892026/10/28 14:32:02 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=016902026/10/28 14:32:02 WARN Failed to register uploaded object key=l69pmmndcc2xxz2b3azlh68lc00qz9lj.ls error="server returned 404: 404 page not found\n"16912026/10/28 14:32:02 WARN Force mode enabled - objects will be deleted immediately without grace period16922026/10/28 14:32:02 WARN Failed to register uploaded object key=kilncn0kwj53l3p9fkdsbxw0lssmxvxb.ls error="server returned 404: 404 page not found\n"16932026/10/28 14:32:02 INFO Vacuumed table table=pending_closures16942026/10/28 14:32:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16952026/10/28 14:32:02 INFO Vacuumed table table=pending_objects16962026/10/28 14:32:02 INFO Vacuumed table table=multipart_uploads16972026/10/28 14:32:02 INFO Signed narinfos id=1 count=216982026/10/28 14:32:02 INFO Vacuumed table table=closures16992026/10/28 14:32:02 INFO Uploading 2 narinfos17002026/10/28 14:32:02 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=017012026/10/28 14:32:02 INFO Vacuumed table table=objects17022026/10/28 14:32:02 INFO Vacuumed table table=pending_closures17032026/10/28 14:32:02 INFO Received complete push request method=POST path=/api/pushes/1/complete17042026/10/28 14:32:02 WARN Failed to register uploaded object key=r63ynq3v3zqw8klapigq3cvf4d9wn22d.narinfo error="server returned 404: 404 page not found\n"17052026/10/28 14:32:02 INFO Vacuumed table table=pending_objects17062026/10/28 14:32:02 INFO Vacuumed table table=multipart_uploads17072026/10/28 14:32:02 WARN Failed to register uploaded object key=kilncn0kwj53l3p9fkdsbxw0lssmxvxb.narinfo error="server returned 404: 404 page not found\n"17082026/10/28 14:32:02 INFO Vacuumed table table=closures17092026/10/28 14:32:02 INFO Vacuumed table table=objects17102026/10/28 14:32:02 INFO Received complete push request method=POST path=/api/pushes/1/complete17112026/10/28 14:32:02 WARN Failed to register uploaded object key=l69pmmndcc2xxz2b3azlh68lc00qz9lj.narinfo error="server returned 404: 404 page not found\n"17122026/10/28 14:32:02 INFO Completed push id=1 objects=3 duration=7.098224ms17132026/10/28 14:32:02 INFO Upload complete. (89ms)1714=== NAME TestNARDeduplicationMetadataUploadBug1715 metadata_upload_test.go:54: Retrieved narinfo from S3:1716 StorePath: /build/TestNARDeduplicationMetadataUploadBug2002027252/001/store/r63ynq3v3zqw8klapigq3cvf4d9wn22d-file1.txt1717 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1718 Compression: zstd1719 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1720 NarSize: 1601721 References: 1722 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf17232026/10/28 14:32:02 INFO Completed push id=1 objects=6 duration=6.599459ms17242026/10/28 14:32:02 INFO Upload complete. (89ms)1725=== NAME TestClientSharedPathCommittedMidPush1726 client_integration_test.go:803: Retrieved narinfo from S3:1727 StorePath: /build/TestClientSharedPathCommittedMidPush4260808285/001/store/l69pmmndcc2xxz2b3azlh68lc00qz9lj-shared-dep1728 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1729 Compression: zstd1730 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821731 NarSize: 1361732 References: 1733 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1734=== NAME TestNARDeduplicationMetadataUploadBug1735 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1736 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1737 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1738--- PASS: TestSweepSkipsRowsLockedByPush (0.48s)1739=== CONT TestClientFallsBackToClosures1740=== NAME TestClientSharedPathCommittedMidPush1741 client_integration_test.go:803: Retrieved narinfo from S3:1742 StorePath: /build/TestClientSharedPathCommittedMidPush4260808285/001/store/kilncn0kwj53l3p9fkdsbxw0lssmxvxb-top1743 URL: nar/01afd2yl70y8hizpvs35x2iq9d3b8jy6fdqmmrl3099m14r1kgyf.nar.zst1744 Compression: zstd1745 NarHash: sha256:01afd2yl70y8hizpvs35x2iq9d3b8jy6fdqmmrl3099m14r1kgyf1746 NarSize: 2241747 References: /build/TestClientSharedPathCommittedMidPush4260808285/001/store/l69pmmndcc2xxz2b3azlh68lc00qz9lj-shared-dep1748 CA: text:sha256:159dkdcf4dqlwyzf9pmcq8y425j3prbvjmja7jfrwpbdc3pgkdbl1749--- PASS: TestPushDedupSurvivesConcurrentGC (0.54s)1750=== CONT TestGCTaskStore_StartNew1751--- PASS: TestGCTaskStore_StartNew (0.00s)1752=== CONT TestService_AuthMiddleware_MTLSBoundSubjects17532026/10/28 14:32:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17542026/10/28 14:32:02 INFO Received uploads request method=POST path=/api/pending_closures1755=== NAME TestNARDeduplicationMetadataUploadBug1756 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2002027252/001/store/xc07wmay4m80fs5z14jf2mzh4lgy9mv3-file2.txt17572026/10/28 14:32:02 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LmU5YzNiOTQyLTRkMjgtNDZjYy1hMDBjLTQ2OGNlMGZkYjMwY3gxNzkzMTk3OTIxMDEzMjU2Njk0 parts=101758=== CONT TestCacheConfigHandler1759=== RUN TestCacheConfigHandler/full_config,_no_issuer1760--- PASS: TestClientSharedPathCommittedMidPush (0.71s)1761=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1762=== RUN TestCacheConfigHandler/no_cache_url_configured1763=== PAUSE TestCacheConfigHandler/no_cache_url_configured1764=== RUN TestCacheConfigHandler/no_signing_keys1765=== PAUSE TestCacheConfigHandler/no_signing_keys1766=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1767=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1768=== CONT TestService_ReadAuthMiddleware17692026/10/28 14:32:02 INFO Received complete push request method=POST path=/api/pushes/1/complete17702026/10/28 14:32:02 INFO Completed push id=1 objects=4 duration=6.71886ms17712026/10/28 14:32:02 INFO Received push request method=POST path=/api/pushes1772=== NAME TestClientMultipleUploads1773 client_integration_test.go:467: Created store path 0: /build/TestClientMultipleUploads3598427470/001/store/k7vvzddm55mpy058blc0x5y1z2hnrxiq-test-file-0.txt17742026/10/28 14:32:02 INFO Aborted multipart uploads count=0 kept=017752026/10/28 14:32:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40217/oidc17762026/10/28 14:32:02 WARN Force mode enabled - objects will be deleted immediately without grace period17772026/10/28 14:32:02 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=017782026/10/28 14:32:02 INFO Vacuumed table table=pending_closures17792026/10/28 14:32:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17802026/10/28 14:32:02 INFO Vacuumed table table=pending_objects17812026/10/28 14:32:02 INFO Vacuumed table table=multipart_uploads17822026/10/28 14:32:02 INFO Vacuumed table table=closures17832026/10/28 14:32:02 INFO Vacuumed table table=objects1784 client_integration_test.go:467: Created store path 1: /build/TestClientMultipleUploads3598427470/001/store/jiqiac8yrrwgklwnxmisimkq4gn3qmwc-test-file-1.txt17852026/10/28 14:32:02 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LjM0MTVkNmFjLWYyYjItNDgyMS1hOGY4LWU2NTQ2MzYxODEwZXgxNzkzMTk3OTIxNzg5MTQzNDgx parts=1017862026/10/28 14:32:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17872026/10/28 14:32:02 INFO Completed upload id=1 objects=2 duration=4.239299ms17882026/10/28 14:32:02 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01789--- PASS: TestGCSweepSkipsPendingObjects (0.30s)1790=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline17912026/10/28 14:32:02 INFO Received create pin request method=POST path=/api/pins/myapp17922026/10/28 14:32:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17932026/10/28 14:32:02 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3262314366/001/store/c7pkpynrcviwf2i6xs90rmvyzhbb1p77-pinned-file.txt narinfo_key=c7pkpynrcviwf2i6xs90rmvyzhbb1p77.narinfo17942026/10/28 14:32:02 INFO Received uploads request method=POST path=/api/pending_closures17952026/10/28 14:32:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures17962026/10/28 14:32:02 INFO Garbage collection started17972026/10/28 14:32:02 INFO Received push request method=POST path=/api/pushes17982026/10/28 14:32:02 INFO Received uploads request method=POST path=/api/pending_closures17992026/10/28 14:32:02 INFO Aborted multipart uploads count=0 kept=01800=== NAME TestClientMultipleUploads1801 client_integration_test.go:467: Created store path 2: /build/TestClientMultipleUploads3598427470/001/store/zl6pz842b1awd7sy7an8cl2nnkpizrpb-test-file-2.txt18022026/10/28 14:32:02 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18032026/10/28 14:32:02 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo18042026/10/28 14:32:02 WARN Found objects in DB but missing from S3, will re-upload count=118052026/10/28 14:32:02 INFO Aborted multipart uploads count=0 kept=018062026/10/28 14:32:02 WARN Force mode enabled - objects will be deleted immediately without grace period18072026/10/28 14:32:02 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete18082026/10/28 14:32:02 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LjVkMTg4Njk3LTU0MWEtNDE2My1hNjlkLWI1NTEyNGFiMDE5OXgxNzkzMTk3OTIxODQ1NjY3NzQ4 parts=1018092026/10/28 14:32:02 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=018102026/10/28 14:32:02 INFO Completed upload id=3 objects=2 duration=2.26172ms18112026/10/28 14:32:02 INFO Vacuumed table table=pending_closures18122026/10/28 14:32:02 INFO Vacuumed table table=pending_objects18132026/10/28 14:32:02 INFO Vacuumed table table=multipart_uploads18142026/10/28 14:32:02 WARN Failed to register uploaded object key=xc07wmay4m80fs5z14jf2mzh4lgy9mv3.ls error="server returned 404: 404 page not found\n"18152026/10/28 14:32:02 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18162026/10/28 14:32:02 INFO Signed narinfos id=2 count=118172026/10/28 14:32:02 INFO Uploading 1 narinfos18182026/10/28 14:32:02 WARN Force mode enabled - objects will be deleted immediately without grace period18192026/10/28 14:32:02 INFO Vacuumed table table=closures1820=== NAME TestClientCADerivations1821 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2195066137/001/store/4irl62c1xakkwqk2k2jrw0l2d6i5w0rr-ca-test18222026/10/28 14:32:02 INFO Vacuumed table table=objects1823--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.21s)1824=== CONT TestPendingClosureWriteTimeout/670k_objects1825=== CONT TestPendingClosureWriteTimeout/400_objects1826=== CONT TestPendingClosureWriteTimeout/empty1827=== CONT TestProxyWriteTimeout/1_GiB_nar1828=== CONT TestProxyWriteTimeout/unknown_size18292026/10/28 14:32:02 INFO Received complete push request method=POST path=/api/pushes/2/complete1830=== CONT TestProxyWriteTimeout/10_GiB_nar1831=== CONT TestProxyWriteTimeout/narinfo1832=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh18332026/10/28 14:32:02 WARN Failed to register uploaded object key=xc07wmay4m80fs5z14jf2mzh4lgy9mv3.narinfo error="server returned 404: 404 page not found\n"1834--- PASS: TestProxyWriteTimeout (0.00s)1835 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1836 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1837 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1838 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)18392026/10/28 14:32:02 INFO Completed push id=2 objects=3 duration=5.915513ms18402026/10/28 14:32:02 INFO Upload complete. (89ms)1841--- PASS: TestService_verifyS3Integrity (1.12s)1842=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1843=== NAME TestNARDeduplicationMetadataUploadBug1844 metadata_upload_test.go:76: Retrieved narinfo from S3:1845 StorePath: /build/TestNARDeduplicationMetadataUploadBug2002027252/001/store/xc07wmay4m80fs5z14jf2mzh4lgy9mv3-file2.txt1846 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1847 Compression: zstd1848 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1849 NarSize: 1601850 References: 1851 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1852 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1853 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1854 {"version":1,"root":{"type":"regular","size":44}}18552026/10/28 14:32:02 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"18562026/10/28 14:32:02 WARN mTLS auth: bound subjects configured but subject DN unavailable18572026/10/28 14:32:02 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1858=== NAME TestClientCADerivations1859 client_ca_test.go:139: Found 1 dependencies (including self)18602026/10/28 14:32:02 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=018612026/10/28 14:32:02 INFO Vacuumed table table=pending_closures18622026/10/28 14:32:02 INFO Vacuumed table table=pending_objects18632026/10/28 14:32:02 INFO Vacuumed table table=multipart_uploads1864--- PASS: TestNARDeduplicationMetadataUploadBug (0.77s)1865=== CONT TestIsValidCachePath/narinfo1866=== CONT TestIsValidCachePath/nar_bz21867=== CONT TestIsValidCachePath/nar_xz1868=== CONT TestIsValidCachePath/realisation1869=== CONT TestIsValidCachePath/short_hash1870=== CONT TestIsValidCachePath/ls1871=== CONT TestIsValidCachePath/traversal_parent1872=== CONT TestIsValidCachePath/log1873=== CONT TestIsValidCachePath/invalid_char_e1874=== CONT TestIsValidCachePath/nar_zst1875=== CONT TestIsValidCachePath/nix-cache-info1876=== CONT TestIsValidCachePath/wrong_extension1877=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1878=== CONT TestIsValidCachePath/empty1879=== CONT TestIsValidCachePath/nar_uncompressed1880=== CONT TestIsValidCachePath/traversal_in_middle1881=== CONT TestIsValidCachePath/invalid_char_u1882=== CONT TestIsValidCachePath/index.html1883=== CONT TestIsValidCachePath/leading_slash1884=== CONT TestParseSingleRange/none1885=== CONT TestIsValidCachePath/random_path1886=== CONT TestParseSingleRange/end_clamped_to_size1887--- PASS: TestIsValidCachePath (0.01s)1888 --- PASS: TestIsValidCachePath/narinfo (0.00s)1889 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1890 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1891 --- PASS: TestIsValidCachePath/realisation (0.00s)1892 --- PASS: TestIsValidCachePath/short_hash (0.00s)1893 --- PASS: TestIsValidCachePath/ls (0.00s)1894 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1895 --- PASS: TestIsValidCachePath/log (0.00s)1896 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1897 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1898 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1899 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1900 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1901 --- PASS: TestIsValidCachePath/empty (0.00s)1902 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1903 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1904 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1905 --- PASS: TestIsValidCachePath/index.html (0.00s)1906 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1907 --- PASS: TestIsValidCachePath/random_path (0.00s)1908=== CONT TestParseSingleRange/start_far_past_EOF1909=== CONT TestParseSingleRange/single_byte1910=== CONT TestParseSingleRange/start_past_EOF1911=== CONT TestParseSingleRange/suffix_exceeds_size1912--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.20s)1913=== CONT TestParseSingleRange/open-ended1914=== CONT TestParseSingleRange/suffix1915=== CONT TestParseSingleRange/malformed_no_dash1916=== CONT TestParseSingleRange/closed1917=== CONT TestParseSingleRange/malformed_both_empty1918=== CONT TestParseSingleRange/multi-range_ignored1919=== CONT TestParseSingleRange/unknown_unit1920=== CONT TestParseSingleRange/malformed_end_before_start1921=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19222026/10/28 14:32:02 INFO Vacuumed table table=closures1923=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19242026/10/28 14:32:02 INFO Received complete multipart upload request method=POST path=/1925--- PASS: TestParseSingleRange (0.00s)1926 --- PASS: TestParseSingleRange/none (0.00s)1927 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1928 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1929 --- PASS: TestParseSingleRange/single_byte (0.00s)1930 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1931 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1932 --- PASS: TestParseSingleRange/open-ended (0.00s)1933 --- PASS: TestParseSingleRange/suffix (0.00s)1934 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1935 --- PASS: TestParseSingleRange/closed (0.00s)1936 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1937 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1938 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1939 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)19402026/10/28 14:32:02 INFO Received request for more parts method=POST path=/19412026/10/28 14:32:02 INFO Received push request method=POST path=/api/pushes19422026/10/28 14:32:02 INFO Vacuumed table table=objects19432026/10/28 14:32:02 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)19442026/10/28 14:32:02 INFO Uploading zl6pz842b1awd7sy7an8cl2nnkpizrpb-test-file-2.txt (160B)19452026/10/28 14:32:02 INFO Uploading jiqiac8yrrwgklwnxmisimkq4gn3qmwc-test-file-1.txt (160B)19462026/10/28 14:32:02 INFO Uploading k7vvzddm55mpy058blc0x5y1z2hnrxiq-test-file-0.txt (160B)19472026/10/28 14:32:02 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"19482026/10/28 14:32:02 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"19492026/10/28 14:32:02 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"19502026/10/28 14:32:02 WARN Failed to register uploaded object key=k7vvzddm55mpy058blc0x5y1z2hnrxiq.ls error="server returned 404: 404 page not found\n"19512026/10/28 14:32:02 WARN Failed to register uploaded object key=jiqiac8yrrwgklwnxmisimkq4gn3qmwc.ls error="server returned 404: 404 page not found\n"19522026/10/28 14:32:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19532026/10/28 14:32:02 WARN Failed to register uploaded object key=zl6pz842b1awd7sy7an8cl2nnkpizrpb.ls error="server returned 404: 404 page not found\n"19542026/10/28 14:32:02 INFO Signed narinfos id=1 count=319552026/10/28 14:32:02 INFO Uploading 3 narinfos19562026/10/28 14:32:02 WARN Failed to register uploaded object key=jiqiac8yrrwgklwnxmisimkq4gn3qmwc.narinfo error="server returned 404: 404 page not found\n"19572026/10/28 14:32:02 WARN Failed to register uploaded object key=k7vvzddm55mpy058blc0x5y1z2hnrxiq.narinfo error="server returned 404: 404 page not found\n"19582026/10/28 14:32:02 INFO Received complete push request method=POST path=/api/pushes/1/complete19592026/10/28 14:32:02 WARN Failed to register uploaded object key=zl6pz842b1awd7sy7an8cl2nnkpizrpb.narinfo error="server returned 404: 404 page not found\n"19602026/10/28 14:32:02 INFO Completed push id=1 objects=9 duration=6.616599ms19612026/10/28 14:32:02 INFO Upload complete. (97ms)1962=== NAME TestClientMultipleUploads1963 client_integration_test.go:478: Uploaded 3 paths in 136.006402ms19642026/10/28 14:32:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1965=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure1966--- PASS: TestService_ReadAuthMiddleware (0.26s)19672026/10/28 14:32:02 INFO Received uploads request method=POST path=/19682026/10/28 14:32:02 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LjRmNmI3ZDA3LTJmMzUtNDEzOC1hMWMyLWQ4MzU5ODlhOTQyMngxNzkzMTk3OTIwNzc5NTMxMTU1 parts=1019692026/10/28 14:32:02 INFO Received push request method=POST path=/api/pushes19702026/10/28 14:32:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19712026/10/28 14:32:02 INFO Uploading 4irl62c1xakkwqk2k2jrw0l2d6i5w0rr-ca-test (144B)19722026/10/28 14:32:02 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"19732026/10/28 14:32:02 WARN Failed to register uploaded object key=4irl62c1xakkwqk2k2jrw0l2d6i5w0rr.ls error="server returned 404: 404 page not found\n"19742026/10/28 14:32:02 WARN Failed to register uploaded object key=log/3bin8jgm5y514y0lyx3yjqbr5x38lqn2-ca-test.drv error="server returned 404: 404 page not found\n"19752026/10/28 14:32:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19762026/10/28 14:32:02 INFO Signed narinfos id=1 count=119772026/10/28 14:32:02 INFO Uploading 1 narinfos19782026/10/28 14:32:02 INFO Received uploads request method=POST path=/api/pending_closures1979--- PASS: TestClientMultipleUploads (0.54s)1980=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1981=== RUN TestService_RequireScope_OIDC/builder_may_write1982=== PAUSE TestService_RequireScope_OIDC/builder_may_write1983=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1984=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1985=== RUN TestService_RequireScope_OIDC/ops_may_admin1986=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1987=== RUN TestService_RequireScope_OIDC/ops_may_not_write1988=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1989=== RUN TestService_RequireScope_OIDC/reader_may_not_write1990=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1991=== RUN TestService_RequireScope_OIDC/static_token_may_admin1992=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1993=== RUN TestService_RequireScope_OIDC/static_token_may_write19942026/10/28 14:32:02 INFO Received complete push request method=POST path=/api/pushes/1/complete1995=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1996=== RUN TestService_RequireScope_OIDC/reader_may_read1997=== PAUSE TestService_RequireScope_OIDC/reader_may_read1998=== RUN TestService_RequireScope_OIDC/writer_implies_read1999=== PAUSE TestService_RequireScope_OIDC/writer_implies_read20002026/10/28 14:32:02 WARN Failed to register uploaded object key=4irl62c1xakkwqk2k2jrw0l2d6i5w0rr.narinfo error="server returned 404: 404 page not found\n"2001=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2002=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2003=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc2004=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc2005=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2006=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2007=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2008=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2009=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2010=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2011=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete20122026/10/28 14:32:02 INFO Completed push id=1 objects=4 duration=6.225096ms20132026/10/28 14:32:02 INFO Upload complete. (116ms)2014--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.26s)2015=== CONT TestGCEndsOnShutdown/before_the_run2016=== NAME TestClientCADerivations2017 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2195066137/001/store/4irl62c1xakkwqk2k2jrw0l2d6i5w0rr-ca-test2018 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2019 Compression: zstd2020 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2021 NarSize: 1442022 References: 2023 Deriver: /build/TestClientCADerivations2195066137/001/store/3bin8jgm5y514y0lyx3yjqbr5x38lqn2-ca-test.drv2024 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2025 client_ca_test.go:185: Checking for realisation files in S3...2026 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2027 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache20282026/10/28 14:32:02 INFO Received uploads request method=POST path=/api/pending_closures20292026/10/28 14:32:02 INFO Received uploads request method=POST path=/api/pending_closures20302026/10/28 14:32:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20312026/10/28 14:32:02 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)20322026/10/28 14:32:02 INFO Uploading nklxsgj5ah8fb01xq4gcvi85crs6g856-a (216B)20332026/10/28 14:32:02 INFO Uploading 9clh4gj2j1x87l6d30vg4j6mvk9wi5wp-shared-dep (136B)2034 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2035 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2036 error: binary cache 's3://bucket91?endpoint=http://localhost:34021®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2195066137/001/store'2037 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 120382026/10/28 14:32:02 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LjZiODNiMmQ5LWIxZjYtNDlmMi04MWFhLTZiMzg4NmMwODBhN3gxNzkzMTk3OTIyMjE4NzM2Mjk4 parts=1020392026/10/28 14:32:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20402026/10/28 14:32:02 WARN Failed to register uploaded object key=cfyg4n2mjpb0girxdkzyhqxld9wgv2xi.ls error="server returned 404: 404 page not found\n"20412026/10/28 14:32:02 INFO Completed upload id=1 objects=2 duration=3.671974ms20422026/10/28 14:32:02 WARN Failed to register uploaded object key=nar/082icbzmx03fxrn74sybl0qpv1qj0q714w1yns0927n4r4nx9dri.nar.zst error="server returned 404: 404 page not found\n"20432026/10/28 14:32:02 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20442026/10/28 14:32:02 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000020452026/10/28 14:32:02 WARN Failed to register uploaded object key=nklxsgj5ah8fb01xq4gcvi85crs6g856.ls error="server returned 404: 404 page not found\n"20462026/10/28 14:32:02 WARN Failed to register uploaded object key=9clh4gj2j1x87l6d30vg4j6mvk9wi5wp.ls error="server returned 404: 404 page not found\n"20472026/10/28 14:32:02 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign20482026/10/28 14:32:02 INFO Signed narinfos id=2 count=220492026/10/28 14:32:02 INFO Received uploads request method=POST path=/api/pending_closures20502026/10/28 14:32:02 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20512026/10/28 14:32:02 INFO Signed narinfos id=1 count=220522026/10/28 14:32:02 INFO Uploading 4 narinfos20532026/10/28 14:32:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures20542026/10/28 14:32:02 WARN Failed to register uploaded object key=9clh4gj2j1x87l6d30vg4j6mvk9wi5wp.narinfo error="server returned 404: 404 page not found\n"20552026/10/28 14:32:02 WARN Failed to register uploaded object key=cfyg4n2mjpb0girxdkzyhqxld9wgv2xi.narinfo error="server returned 404: 404 page not found\n"2056--- PASS: TestClientCADerivations (0.63s)2057=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows20582026/10/28 14:32:02 WARN Failed to register uploaded object key=nklxsgj5ah8fb01xq4gcvi85crs6g856.narinfo error="server returned 404: 404 page not found\n"20592026/10/28 14:32:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20602026/10/28 14:32:02 WARN Failed to register uploaded object key=9clh4gj2j1x87l6d30vg4j6mvk9wi5wp.narinfo error="server returned 404: 404 page not found\n"20612026/10/28 14:32:02 INFO Completed upload id=1 objects=6 duration=5.046465ms20622026/10/28 14:32:02 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20632026/10/28 14:32:02 INFO Completed upload id=2 objects=6 duration=1.138351ms20642026/10/28 14:32:02 INFO Upload complete. (109ms)20652026/10/28 14:32:02 INFO Aborted multipart uploads count=0 kept=02066=== NAME TestClientFallsBackToClosures2067 client_pushes_test.go:112: Retrieved narinfo from S3:2068 StorePath: /build/TestClientFallsBackToClosures1802539502/001/store/9clh4gj2j1x87l6d30vg4j6mvk9wi5wp-shared-dep2069 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2070 Compression: zstd2071 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822072 NarSize: 1362073 References: 2074 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2075 client_pushes_test.go:112: Retrieved narinfo from S3:2076 StorePath: /build/TestClientFallsBackToClosures1802539502/001/store/nklxsgj5ah8fb01xq4gcvi85crs6g856-a2077 URL: nar/082icbzmx03fxrn74sybl0qpv1qj0q714w1yns0927n4r4nx9dri.nar.zst2078 Compression: zstd2079 NarHash: sha256:082icbzmx03fxrn74sybl0qpv1qj0q714w1yns0927n4r4nx9dri2080 NarSize: 2162081 References: /build/TestClientFallsBackToClosures1802539502/001/store/9clh4gj2j1x87l6d30vg4j6mvk9wi5wp-shared-dep2082 CA: text:sha256:05rmlqay51bfdzy7q6zm6av5bzbgwy40690y12fr7xy0y2058p7q2083 client_pushes_test.go:112: Retrieved narinfo from S3:2084 StorePath: /build/TestClientFallsBackToClosures1802539502/001/store/cfyg4n2mjpb0girxdkzyhqxld9wgv2xi-b2085 URL: nar/082icbzmx03fxrn74sybl0qpv1qj0q714w1yns0927n4r4nx9dri.nar.zst2086 Compression: zstd2087 NarHash: sha256:082icbzmx03fxrn74sybl0qpv1qj0q714w1yns0927n4r4nx9dri2088 NarSize: 2162089 References: /build/TestClientFallsBackToClosures1802539502/001/store/9clh4gj2j1x87l6d30vg4j6mvk9wi5wp-shared-dep2090 CA: text:sha256:05rmlqay51bfdzy7q6zm6av5bzbgwy40690y12fr7xy0y2058p7q20912026/10/28 14:32: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=020922026/10/28 14:32:02 INFO Vacuumed table table=pending_closures20932026/10/28 14:32:02 INFO Vacuumed table table=pending_objects20942026/10/28 14:32:02 INFO Vacuumed table table=multipart_uploads20952026/10/28 14:32:02 INFO Vacuumed table table=closures20962026/10/28 14:32:02 INFO Vacuumed table table=objects20972026/10/28 14:32:02 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000020982026/10/28 14:32:02 INFO Aborted multipart uploads count=0 kept=02099--- PASS: TestClientFallsBackToClosures (0.53s)2100=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check21012026/10/28 14:32:02 WARN Force mode enabled - objects will be deleted immediately without grace period2102--- PASS: TestService_createPendingClosureHandler (0.76s)2103=== CONT TestIsValidUploadKey/narinfo2104=== CONT TestIsValidUploadKey/index.html2105=== CONT TestIsValidUploadKey/nix-cache-info2106=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2107=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2108=== CONT TestIsValidUploadKey/build_log_equals2109=== CONT TestIsValidUploadKey/realisation_plus_in_output2110=== CONT TestIsValidUploadKey/unknown_type2111=== CONT TestIsValidUploadKey/build_log_plus_in_name2112=== CONT TestIsValidUploadKey/absolute2113=== CONT TestIsValidUploadKey/build_log_question_mark2114=== CONT TestIsValidUploadKey/nar_zst2115=== CONT TestIsValidUploadKey/listing2116=== CONT TestIsValidUploadKey/realisation2117=== CONT TestIsValidUploadKey/nar_plain2118=== CONT TestIsValidUploadKey/nar_xz2119=== CONT TestIsValidUploadKey/traversal2120=== CONT TestIsValidUploadKey/empty_key2121=== CONT TestIsValidUploadKey/traversal_nar2122=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2123=== CONT TestIsValidUploadKey/build_log_home-manager_file2124=== CONT TestIsValidUploadKey/build_log2125=== CONT TestResolveDBConnectionString/flag_wins2126--- PASS: TestIsValidUploadKey (0.00s)2127 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2128 --- PASS: TestIsValidUploadKey/index.html (0.00s)2129 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2130 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2131 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2132 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2133 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2134 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2135 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2136 --- PASS: TestIsValidUploadKey/absolute (0.00s)2137 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2138 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2139 --- PASS: TestIsValidUploadKey/listing (0.00s)2140 --- PASS: TestIsValidUploadKey/realisation (0.00s)2141 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2142 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2143 --- PASS: TestIsValidUploadKey/traversal (0.00s)2144 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2145 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2146 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2147 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2148 --- PASS: TestIsValidUploadKey/build_log (0.00s)2149=== CONT TestResolveDBConnectionString/nothing_configured2150=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2151=== CONT TestResolveDBConnectionString/file_when_flag_empty21522026-10-28 14:32:02.791 UTC [2012] ERROR: canceling statement due to user request21532026-10-28 14:32:02.791 UTC [2012] CONTEXT: SQL statement "UPDATE object_stats s2154 SET object_count = s.object_count + n.n - o.n,2155 total_bytes = s.total_bytes + n.bytes - o.bytes2156 FROM (2157 SELECT count(*) AS n, coalesce(sum(size), 0) AS bytes2158 FROM new_rows WHERE deleted_at IS NULL2159 ) AS n,2160 (2161 SELECT count(*) AS n, coalesce(sum(size), 0) AS bytes2162 FROM old_rows WHERE deleted_at IS NULL2163 ) AS o2164 WHERE s.id AND (n.n <> o.n OR n.bytes <> o.bytes)"2165 PL/pgSQL function object_stats_update() line 3 at SQL statement21662026-10-28 14:32:02.791 UTC [2012] STATEMENT: -- name: MarkStaleObjects :execrows2167 WITH RECURSIVE ct AS (2168 SELECT timezone('UTC', now()) AS now2169 ),2170 closure_reach AS (2171 -- Start with all closure keys2172 SELECT o.key, o.refs2173 FROM objects o2174 INNER JOIN closures c ON o.key = c.key2175 UNION2176 -- Recursively add all referenced objects2177 SELECT o.key, o.refs2178 FROM objects o2179 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2180 ),2181 reachable_objects AS (2182 SELECT DISTINCT key FROM closure_reach2183 ),2184 stale_objects AS (2185 SELECT o.key2186 FROM objects AS o, ct2187 WHERE2188 NOT EXISTS (2189 SELECT 12190 FROM reachable_objects ro2191 WHERE ro.key = o.key2192 )2193 AND NOT EXISTS (2194 SELECT 12195 FROM pending_objects AS po2196 WHERE po.key = o.key2197 )2198 AND o.deleted_at IS NULL -- Only mark fresh objects2199 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2200 FOR UPDATE2201 )2202 UPDATE objects2203 SET2204 deleted_at = ct.now,2205 first_deleted_at = COALESCE(first_deleted_at, ct.now)2206 FROM stale_objects, ct2207 WHERE objects.key = stale_objects.key2208 2209=== CONT TestResolveDBConnectionString/missing_file_is_an_error2210=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2211--- PASS: TestResolveDBConnectionString (0.00s)2212 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2213 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2214 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2215 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2216 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2217=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2218=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2219=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected22202026/10/28 14:32:02 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]2221=== CONT TestPush_RejectsBadRequests/no_roots22222026/10/28 14:32:02 INFO Received push request method=POST path=/api/pushes22232026/10/28 14:32:02 WARN Authentication failed token_preview=eyJhbGciOi...wtmH1IvF_A token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2224=== CONT TestPush_RejectsBadRequests/root_not_in_objects2225=== CONT TestPush_RejectsBadRequests/bad_root22262026/10/28 14:32:02 INFO Received push request method=POST path=/api/pushes22272026/10/28 14:32:02 INFO Received push request method=POST path=/api/pushes2228=== CONT TestPush_RejectsBadRequests/no_objects2229=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false22302026/10/28 14:32:02 INFO Received push request method=POST path=/api/pushes2231=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true22322026/10/28 14:32:02 INFO Aborted multipart uploads count=0 kept=02233=== CONT TestServerTLSConfig/no_client_CA2234=== CONT TestServerTLSConfig/missing_CA_file2235=== CONT TestServerTLSConfig/not_a_PEM_file2236=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal2237--- PASS: TestServerTLSConfig (0.00s)2238 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2239 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2240 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)22412026/10/28 14:32:02 INFO Received uploads request method=POST path=/2242=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key22432026/10/28 14:32:02 INFO Received request for more parts method=POST path=/2244=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key22452026/10/28 14:32:02 INFO Received complete multipart upload request method=POST path=/2246=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info22472026/10/28 14:32:02 INFO Received uploads request method=POST path=/22482026/10/28 14:32:02 WARN Force mode enabled - objects will be deleted immediately without grace period2249=== CONT TestClientErrorHandling/InvalidAuthToken2250--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2251 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2252 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2253 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2254 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2255--- PASS: TestPush_RejectsBadRequests (0.79s)2256 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2257 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2258 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2259 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2260--- PASS: TestService_AuthMiddleware_OIDC (0.87s)2261 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2262 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2263 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2264 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)22652026/10/28 14:32:02 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:34021/bucket102/?delete=\": context canceled"2266=== CONT TestClientErrorHandling/ServerNotAvailable2267--- PASS: TestGCEndsOnShutdown (0.00s)2268 --- PASS: TestGCEndsOnShutdown/before_the_run (0.21s)2269 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.24s)2270 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.27s)22712026/10/28 14:32:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22722026/10/28 14:32:02 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LjU0YTAwNjkwLTZhMmMtNDQzMS1hMTI2LTliNzQ5MjQ3MmM1M3gxNzkzMTk3OTIxODQ0NjA4NjU5 parts=1022732026/10/28 14:32:02 INFO Received complete push request method=POST path=/api/pushes/1/complete22742026/10/28 14:32:02 INFO Completed push id=1 objects=4 duration=5.088326ms22752026/10/28 14:32:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22762026/10/28 14:32:02 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22772026/10/28 14:32:02 INFO Completed upload id=2 objects=2 duration=1.616735ms22782026/10/28 14:32:02 INFO Received uploads request method=POST path=/api/pending_closures22792026/10/28 14:32:02 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LjhlNTUyNzVmLWRhOWMtNDdhMC1iZGUyLTNjZDRmZDY3NWVhZngxNzkzMTk3OTIyMjk0Mzk4NjM3 parts=1022802026/10/28 14:32:02 INFO Received complete push request method=POST path=/api/pushes/2/complete22812026/10/28 14:32:02 INFO Aborted multipart uploads count=0 kept=022822026/10/28 14:32:02 INFO Completed push id=2 objects=4 duration=2.868326ms22832026/10/28 14:32:02 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/present22842026/10/28 14:32:02 WARN Force mode enabled - objects will be deleted immediately without grace period22852026/10/28 14:32:02 INFO Received uploads request method=POST path=/api/pending_closures2286--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.46s)2287=== CONT TestClientErrorHandling/InvalidStorePath22882026/10/28 14:32:02 INFO Aborted multipart uploads count=0 kept=02289=== CONT TestCacheConfigHandler/no_signing_keys2290--- PASS: TestMetricsCommit (1.58s)2291=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2292=== CONT TestCacheConfigHandler/full_config,_no_issuer2293=== CONT TestCacheConfigHandler/no_cache_url_configured2294--- PASS: TestCacheConfigHandler (0.00s)2295 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2296 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2297 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2298 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2299=== CONT TestService_RequireScope_OIDC/builder_may_write23002026/10/28 14:32:02 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=023012026/10/28 14:32:02 INFO Vacuumed table table=pending_closures23022026/10/28 14:32:02 WARN Force mode enabled - objects will be deleted immediately without grace period23032026/10/28 14:32:02 INFO Vacuumed table table=pending_objects23042026/10/28 14:32:02 INFO Vacuumed table table=multipart_uploads2305=== CONT TestService_RequireScope_OIDC/static_token_may_write2306=== CONT TestService_RequireScope_OIDC/reader_may_not_write23072026/10/28 14:32:02 INFO Vacuumed table table=closures2308=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2309=== CONT TestService_RequireScope_OIDC/ops_may_admin2310=== CONT TestService_RequireScope_OIDC/static_token_may_admin2311=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2312=== CONT TestService_RequireScope_OIDC/reader_may_read23132026/10/28 14:32:02 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=023142026/10/28 14:32:02 INFO Vacuumed table table=objects2315=== CONT TestService_RequireScope_OIDC/writer_implies_read2316=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2317=== CONT TestService_RequireScope_OIDC/ops_may_not_write2318=== CONT TestService_RequireScope_OIDC/builder_may_not_admin23192026-10-28 14:32:02.964 UTC [177] LOG: checkpoints are occurring too frequently (11 seconds apart)23202026-10-28 14:32:02.964 UTC [177] HINT: Consider increasing the configuration parameter "max_wal_size".2321=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read23222026-10-28 14:32:02.964 UTC [177] LOG: checkpoint starting: wal23232026/10/28 14:32:02 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]2324=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read23252026/10/28 14:32:02 INFO Vacuumed table table=pending_closures23262026/10/28 14:32:02 INFO Received uploads request method=POST path=/api/pending_closures23272026/10/28 14:32:02 INFO Vacuumed table table=pending_objects23282026/10/28 14:32:02 INFO Vacuumed table table=multipart_uploads23292026/10/28 14:32:02 INFO Vacuumed table table=closures23302026/10/28 14:32:02 INFO Vacuumed table table=objects2331--- PASS: TestService_RequireScope_OIDC (0.47s)2332 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2333 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2334 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2335 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2336 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2337 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2338 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2339 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2340 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2341 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2342 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2343 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2344 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2345 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)23462026/10/28 14:32:02 INFO Received uploads request method=POST path=/api/pending_closures23472026/10/28 14:32:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2348--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2349 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.24s)2350 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.29s)23512026/10/28 14:32:03 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LjAxN2RkNDYxLTkxYmItNDBhYi1iODFkLWJhOTliZDY1M2M4NXgxNzkzMTk3OTIwNzc5NTM5MTc1 parts=1023522026/10/28 14:32:03 WARN Request failed, retrying attempt=2 backoff=217.922393ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23532026/10/28 14:32:03 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02354=== NAME TestClientIntegration2355 client_integration_test.go:432: Objects in database after GC:2356 client_integration_test.go:432: Successfully deleted all objects with GC --force2357--- PASS: TestClientIntegration (3.56s)23582026/10/28 14:32:03 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"23592026/10/28 14:32:03 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2360--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2361 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.72s)2362 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.74s)23632026/10/28 14:32:03 WARN Request failed, retrying attempt=3 backoff=393.889902ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23642026/10/28 14:32:03 INFO lead: released remote=192.0.2.1:123423652026/10/28 14:32:03 INFO lead: acquired remote=192.0.2.1:12342366--- PASS: TestDeleteClosuresRacingPins (1.96s)2367--- PASS: TestPendingClosureWriteTimeout (0.00s)2368 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2369 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2370 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2371 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.06s)23722026/10/28 14:32:03 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LjhhNzk3MmI4LWQ2OTctNDAwOC04NjMxLTdlYzViMzJkYjAxN3gxNzkzMTk3OTIyOTgxOTU1MDMx error="Access Denied"23732026/10/28 14:32:03 WARN keeping failed pending closure for cleanup to retry the abort id=123742026/10/28 14:32:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23752026/10/28 14:32:03 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LmNhZmIwNTVlLWYyOGUtNDFiNS04MjBlLWE5ZjZiMWMyN2ViZHgxNzkzMTk3OTIwNzc5NjIyMjk2 parts=102376=== NAME TestOrphanedObjectsGCStressTest2377 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2378 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion2379--- PASS: TestPendingClosureFailureTracksEveryUpload (0.00s)2380 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (0.71s)2381 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (0.73s)23822026/10/28 14:32:03 WARN Request failed, retrying attempt=4 backoff=850.625635ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23832026/10/28 14:32:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23842026/10/28 14:32:04 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=NjNiYmM5MWYtMTczNC00MmVhLTg2N2QtYWE0NzVhZGY4MmU4LjBkOTRiNTEwLWRmMjctNDUzNC1iOTU4LTdjYjdlOTI3ZTMzZHgxNzkzMTk3OTIwNzc5NDgxMDM0 parts=1023852026-10-28 14:32:04.090 UTC [1165] ERROR: could not obtain lock on row in relation "closures"23862026-10-28 14:32:04.090 UTC [1165] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23872026-10-28 14:32:04.091 UTC [1165] ERROR: could not obtain lock on row in relation "closures"23882026-10-28 14:32:04.091 UTC [1165] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23892026-10-28 14:32:04.091 UTC [1165] ERROR: could not obtain lock on row in relation "closures"23902026-10-28 14:32:04.091 UTC [1165] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23912026-10-28 14:32:04.092 UTC [1165] ERROR: could not obtain lock on row in relation "closures"23922026-10-28 14:32:04.092 UTC [1165] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23932026-10-28 14:32:04.092 UTC [1165] ERROR: could not obtain lock on row in relation "closures"23942026-10-28 14:32:04.092 UTC [1165] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT2395--- PASS: TestPush_RootsAreLockedInByteOrder (4.11s)23962026/10/28 14:32:04 INFO lead: released remote=192.0.2.1:12342397=== NAME TestPinProtectsFromGC2398 client_integration_test.go:963: Pin successfully protected closure from garbage collection2399--- PASS: TestLeadElectsOneAndHandsOver (2.84s)2400--- PASS: TestPinProtectsFromGC (5.05s)2401=== NAME TestOrphanedObjectsGCStressTest2402 orphaned_objects_gc_test.go:503: Stress test completed successfully:2403 orphaned_objects_gc_test.go:504: - Active objects preserved: 202404 orphaned_objects_gc_test.go:505: - Objects deleted: 2102405 orphaned_objects_gc_test.go:506: - Total GC'd: 2102406--- PASS: TestOrphanedObjectsGCStressTest (3.53s)24072026/10/28 14:32:04 WARN Request failed, retrying attempt=5 backoff=1.628840008s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2408--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.08s)24092026/10/28 14:32:05 WARN Rate limiter enabled after throttle name=s3-test rate=524102026/10/28 14:32:05 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2411=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2412 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102413 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002414--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (7.32s)24152026/10/28 14:32:06 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24162026/10/28 14:32:06 WARN Request failed, retrying attempt=2 backoff=206.824697ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24172026/10/28 14:32:06 WARN Request failed, retrying attempt=3 backoff=432.297904ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2418--- PASS: TestConnectWaitsForAPeerMigration (5.15s)24192026/10/28 14:32:06 WARN Request failed, retrying attempt=4 backoff=724.697532ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24202026/10/28 14:32:07 INFO Aborted multipart uploads count=1 kept=024212026/10/28 14:32:07 INFO Received cleanup request method=DELETE path=/api/pending_closures24222026/10/28 14:32:07 INFO Aborted multipart uploads count=1 kept=02423--- PASS: TestPendingCleanupUsesOneCutoff (6.62s)24242026/10/28 14:32:07 WARN Request failed, retrying attempt=5 backoff=1.645576011s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24252026/10/28 14:32:09 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"24262026/10/28 14:32:09 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24272026/10/28 14:32:09 WARN Request failed, retrying attempt=2 backoff=208.749114ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24282026/10/28 14:32:09 WARN Request failed, retrying attempt=3 backoff=407.534807ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24292026/10/28 14:32:10 WARN Request failed, retrying attempt=4 backoff=799.879551ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24302026/10/28 14:32:10 WARN Request failed, retrying attempt=5 backoff=1.487640046s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24312026/10/28 14:32:12 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_closures24322026/10/28 14:32:12 WARN Request failed, retrying attempt=2 backoff=218.34248ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24332026/10/28 14:32:12 WARN Request failed, retrying attempt=3 backoff=418.623327ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24342026/10/28 14:32:13 WARN Request failed, retrying attempt=4 backoff=786.250995ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24352026/10/28 14:32:13 WARN Request failed, retrying attempt=5 backoff=1.514147015s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2436--- PASS: TestClientErrorHandling (0.00s)2437 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.33s)2438 --- PASS: TestClientErrorHandling/InvalidStorePath (0.23s)2439 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.51s)2440--- PASS: TestUploadHandlersRejectOversizedBody (0.43s)2441 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.82s)2442 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.84s)2443 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (13.78s)2444PASS24452026-10-28 14:32:16.577 UTC [172] LOG: received smart shutdown request24462026-10-28 14:32:16.582 UTC [172] LOG: background worker "logical replication launcher" (PID 182) exited with exit code 124472026-10-28 14:32:17.124 UTC [177] LOG: checkpoint complete: wrote 9459 buffers (57.7%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=13.820 s, sync=0.293 s, total=14.161 s; sync files=37078, longest=0.039 s, average=0.001 s; distance=533467 kB, estimate=533467 kB; lsn=0/22A9EF68, redo lsn=0/2205CAA024482026-10-28 14:32:17.129 UTC [177] LOG: shutting down24492026-10-28 14:32:17.130 UTC [177] LOG: checkpoint starting: shutdown immediate24502026-10-28 14:32:17.185 UTC [177] LOG: checkpoint complete: wrote 918 buffers (5.6%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.016 s, sync=0.038 s, total=0.056 s; sync files=339, longest=0.001 s, average=0.001 s; distance=10505 kB, estimate=481171 kB; lsn=0/22A9EFE0, redo lsn=0/22A9EFE024512026-10-28 14:32:17.265 UTC [172] LOG: database system is shut down2452Running OIDC tests...2453=== RUN TestAudienceForIssuer2454=== PAUSE TestAudienceForIssuer2455=== RUN TestHTTPClientForHasTimeouts2456=== PAUSE TestHTTPClientForHasTimeouts2457=== RUN TestGlobMatch2458=== PAUSE TestGlobMatch2459=== RUN TestValidateToken_ValidToken2460=== PAUSE TestValidateToken_ValidToken2461=== RUN TestValidateToken_WrongAudience2462=== PAUSE TestValidateToken_WrongAudience2463=== RUN TestValidateToken_Expired2464=== PAUSE TestValidateToken_Expired2465=== RUN TestValidateToken_BoundClaimsMismatch2466=== PAUSE TestValidateToken_BoundClaimsMismatch2467=== RUN TestValidateToken_BoundSubjectMismatch2468=== PAUSE TestValidateToken_BoundSubjectMismatch2469=== RUN TestValidateToken_MultipleProviders2470=== PAUSE TestValidateToken_MultipleProviders2471=== RUN TestValidateToken_NoMatchingProvider2472=== PAUSE TestValidateToken_NoMatchingProvider2473=== RUN TestValidateToken_KubernetesServiceAccount2474=== PAUSE TestValidateToken_KubernetesServiceAccount2475=== RUN TestNewValidator_KubernetesRequiresCA2476=== PAUSE TestNewValidator_KubernetesRequiresCA2477=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2478=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2479=== RUN TestPins_ReservedForMatchingRule2480=== PAUSE TestPins_ReservedForMatchingRule2481=== RUN TestPins_TopLevelShorthand2482=== PAUSE TestPins_TopLevelShorthand2483=== RUN TestPins_ConfigValidation2484=== PAUSE TestPins_ConfigValidation2485=== RUN TestScopes_LegacyProviderDefaultsToWrite2486=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2487=== RUN TestScopes_Rules2488=== PAUSE TestScopes_Rules2489=== RUN TestScopes_ConfigValidation2490=== PAUSE TestScopes_ConfigValidation2491=== CONT TestHTTPClientForHasTimeouts2492=== CONT TestPins_TopLevelShorthand2493=== CONT TestValidateToken_ValidToken2494=== CONT TestScopes_LegacyProviderDefaultsToWrite2495=== CONT TestAudienceForIssuer2496--- PASS: TestAudienceForIssuer (0.00s)2497=== CONT TestValidateToken_NoMatchingProvider2498=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2499=== CONT TestPins_ReservedForMatchingRule2500=== CONT TestValidateToken_KubernetesServiceAccount2501=== CONT TestScopes_Rules2502=== CONT TestValidateToken_WrongAudience2503=== CONT TestScopes_ConfigValidation2504=== CONT TestValidateToken_BoundSubjectMismatch2505=== CONT TestNewValidator_KubernetesRequiresCA2506=== CONT TestValidateToken_Expired2507=== CONT TestPins_ConfigValidation2508=== CONT TestGlobMatch2509=== RUN TestGlobMatch/foo_foo2510=== CONT TestValidateToken_BoundClaimsMismatch2511=== PAUSE TestGlobMatch/foo_foo2512=== CONT TestValidateToken_MultipleProviders2513--- PASS: TestScopes_ConfigValidation (0.00s)2514=== RUN TestGlobMatch/foo_bar2515=== PAUSE TestGlobMatch/foo_bar2516=== RUN TestGlobMatch/*_2517=== PAUSE TestGlobMatch/*_2518=== RUN TestGlobMatch/*_anything2519=== PAUSE TestGlobMatch/*_anything2520=== RUN TestGlobMatch/foo*_foo2521=== PAUSE TestGlobMatch/foo*_foo2522=== RUN TestGlobMatch/foo*_foobar2523--- PASS: TestPins_ConfigValidation (0.00s)2524=== PAUSE TestGlobMatch/foo*_foobar2525=== RUN TestGlobMatch/foo*_bar2526=== PAUSE TestGlobMatch/foo*_bar2527=== RUN TestGlobMatch/*bar_bar2528=== PAUSE TestGlobMatch/*bar_bar2529=== RUN TestGlobMatch/*bar_foobar2530=== PAUSE TestGlobMatch/*bar_foobar2531=== RUN TestGlobMatch/*bar_foo2532=== PAUSE TestGlobMatch/*bar_foo2533=== RUN TestGlobMatch/foo*bar_foobar2534=== PAUSE TestGlobMatch/foo*bar_foobar2535=== RUN TestGlobMatch/foo*bar_foo123bar2536=== PAUSE TestGlobMatch/foo*bar_foo123bar2537=== RUN TestGlobMatch/foo*bar_foobarbaz2538=== PAUSE TestGlobMatch/foo*bar_foobarbaz2539=== RUN TestGlobMatch/*/*_foo/bar2540=== PAUSE TestGlobMatch/*/*_foo/bar2541=== RUN TestGlobMatch/*/*_foo2542=== PAUSE TestGlobMatch/*/*_foo2543=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2544=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2545=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02546=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02547=== RUN TestGlobMatch/refs/*/main_refs/heads/main2548=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2549=== RUN TestGlobMatch/fo?_foo2550=== PAUSE TestGlobMatch/fo?_foo2551=== RUN TestGlobMatch/fo?_fo2552=== PAUSE TestGlobMatch/fo?_fo2553=== RUN TestGlobMatch/fo?_fooo2554=== PAUSE TestGlobMatch/fo?_fooo2555=== RUN TestGlobMatch/?oo_foo2556=== PAUSE TestGlobMatch/?oo_foo2557=== RUN TestGlobMatch/?oo_boo2558=== PAUSE TestGlobMatch/?oo_boo2559=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2560=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2561=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2562=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2563=== CONT TestGlobMatch/foo_foo2564=== CONT TestGlobMatch/refs/*/main_refs/heads/main2565=== CONT TestGlobMatch/*/*_foo2566=== CONT TestGlobMatch/?oo_boo2567=== CONT TestGlobMatch/foo*bar_foobarbaz2568=== CONT TestGlobMatch/*bar_foo2569=== CONT TestGlobMatch/foo*bar_foo123bar2570=== CONT TestGlobMatch/fo?_fo2571=== CONT TestGlobMatch/fo?_foo2572=== CONT TestGlobMatch/foo*_bar2573=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02574=== CONT TestGlobMatch/foo*_foo2575=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2576=== CONT TestGlobMatch/foo*bar_foobar2577=== CONT TestGlobMatch/*bar_bar2578=== CONT TestGlobMatch/fo?_fooo2579=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2580=== CONT TestGlobMatch/*/*_foo/bar2581=== CONT TestGlobMatch/?oo_foo2582=== CONT TestGlobMatch/*_anything2583=== CONT TestGlobMatch/foo_bar2584=== CONT TestGlobMatch/foo*_foobar2585=== CONT TestGlobMatch/*_2586=== CONT TestGlobMatch/*bar_foobar2587=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2588--- PASS: TestGlobMatch (0.01s)2589 --- PASS: TestGlobMatch/foo_foo (0.00s)2590 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2591 --- PASS: TestGlobMatch/*/*_foo (0.00s)2592 --- PASS: TestGlobMatch/?oo_boo (0.00s)2593 --- PASS: TestGlobMatch/*bar_foo (0.00s)2594 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2595 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2596 --- PASS: TestGlobMatch/fo?_fo (0.00s)2597 --- PASS: TestGlobMatch/fo?_foo (0.00s)2598 --- PASS: TestGlobMatch/foo*_bar (0.00s)2599 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2600 --- PASS: TestGlobMatch/foo*_foo (0.00s)2601 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2602 --- PASS: TestGlobMatch/*bar_bar (0.00s)2603 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2604 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2605 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2606 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2607 --- PASS: TestGlobMatch/?oo_foo (0.00s)2608 --- PASS: TestGlobMatch/*_anything (0.00s)2609 --- PASS: TestGlobMatch/foo_bar (0.00s)2610 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2611 --- PASS: TestGlobMatch/*_ (0.00s)2612 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2613 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)26142026/10/28 14:32:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44109/oidc26152026/10/28 14:32:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45103/oidc2616--- PASS: TestPins_TopLevelShorthand (0.07s)2617--- PASS: TestValidateToken_WrongAudience (0.07s)26182026/10/28 14:32:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36899/oidc2619--- PASS: TestPins_ReservedForMatchingRule (0.09s)26202026/10/28 14:32:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37053/oidc26212026/10/28 14:32:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43457/oidc2622--- PASS: TestValidateToken_Expired (0.12s)2623--- PASS: TestValidateToken_ValidToken (0.13s)26242026/10/28 14:32:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43613/oidc2625--- PASS: TestValidateToken_BoundSubjectMismatch (0.16s)26262026/10/28 14:32:20 http: TLS handshake error from 127.0.0.1:57140: remote error: tls: bad certificate2627--- PASS: TestNewValidator_KubernetesRequiresCA (0.17s)26282026/10/28 14:32:20 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:345932629--- PASS: TestValidateToken_KubernetesServiceAccount (0.21s)26302026/10/28 14:32:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39979/oidc2631--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.23s)26322026/10/28 14:32:20 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232633--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.38s)26342026/10/28 14:32:20 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:36729/oidc2635--- PASS: TestValidateToken_NoMatchingProvider (0.38s)26362026/10/28 14:32:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44041/oidc2637--- PASS: TestHTTPClientForHasTimeouts (0.41s)2638--- PASS: TestScopes_Rules (0.42s)26392026/10/28 14:32:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45523/oidc2640--- PASS: TestValidateToken_BoundClaimsMismatch (0.45s)26412026/10/28 14:32:21 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41539/oidc26422026/10/28 14:32:21 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:42565/oidc2643--- PASS: TestValidateToken_MultipleProviders (0.47s)2644PASS2645Running hook tests...2646=== RUN TestSendPathsEmpty2647=== PAUSE TestSendPathsEmpty2648=== RUN TestQueueEnqueueAndFetch2649=== PAUSE TestQueueEnqueueAndFetch2650=== RUN TestQueueDeduplication2651=== PAUSE TestQueueDeduplication2652=== RUN TestQueueRemove2653=== PAUSE TestQueueRemove2654=== RUN TestQueueFetchBatchLimit2655=== PAUSE TestQueueFetchBatchLimit2656=== RUN TestQueueRetryMovesToBack2657=== PAUSE TestQueueRetryMovesToBack2658=== RUN TestQueueFetchRemoveLifecycle2659=== PAUSE TestQueueFetchRemoveLifecycle2660=== RUN TestQueueConcurrentWriters2661=== PAUSE TestQueueConcurrentWriters2662=== RUN TestQueueRemoveLargeClosure2663=== PAUSE TestQueueRemoveLargeClosure2664=== RUN TestServerClientIntegration2665--- PASS: TestServerClientIntegration (0.00s)2666=== RUN TestServerQueueError26672026/10/28 14:32:22 ERROR Failed to queue paths error="permission denied" count=12668--- PASS: TestServerQueueError (0.00s)2669=== RUN TestServerRefusesOversizedAndNonStoreRequests2670=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2671=== RUN TestGetListenerSocketActivation2672 server_test.go:309: === RUN TestGetListenerSocketActivation2673 --- PASS: TestGetListenerSocketActivation (0.00s)2674 PASS2675 2676--- PASS: TestGetListenerSocketActivation (1.02s)2677=== RUN TestServerStalledClientDoesNotBlockShutdown2678=== PAUSE TestServerStalledClientDoesNotBlockShutdown2679=== RUN TestServerBacksOffOnAcceptErrors2680=== PAUSE TestServerBacksOffOnAcceptErrors2681=== RUN TestDrainIsolatesPoisonPath2682=== PAUSE TestDrainIsolatesPoisonPath2683=== RUN TestRunNotBlockedByPoisonHead2684=== PAUSE TestRunNotBlockedByPoisonHead2685=== RUN TestDrainGivesUpWhenServerDown2686=== PAUSE TestDrainGivesUpWhenServerDown2687=== RUN TestFailedPathPrunedByLaterClosure2688=== PAUSE TestFailedPathPrunedByLaterClosure2689=== RUN TestWorkerUploadsAndRemoves2690=== PAUSE TestWorkerUploadsAndRemoves2691=== RUN TestWorkerSkipsGCdPaths2692=== PAUSE TestWorkerSkipsGCdPaths2693=== RUN TestWorkerPrunesClosureDeps2694=== PAUSE TestWorkerPrunesClosureDeps2695=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2696=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2697=== RUN TestDrainTimeout2698=== PAUSE TestDrainTimeout2699=== RUN TestDrainTimeoutDuringIsolation2700=== PAUSE TestDrainTimeoutDuringIsolation2701=== RUN TestShutdownFinishesInFlightPush2702=== PAUSE TestShutdownFinishesInFlightPush2703=== RUN TestWorkerRemoveFailureIsNotProgress2704=== PAUSE TestWorkerRemoveFailureIsNotProgress2705=== RUN TestWorkerKeepsPathItCannotStat2706=== PAUSE TestWorkerKeepsPathItCannotStat2707=== CONT TestQueueEnqueueAndFetch2708=== CONT TestDrainTimeoutDuringIsolation2709=== CONT TestDrainIsolatesPoisonPath2710=== CONT TestServerStalledClientDoesNotBlockShutdown2711=== CONT TestDrainGivesUpWhenServerDown2712=== CONT TestWorkerRemoveFailureIsNotProgress2713=== CONT TestShutdownFinishesInFlightPush2714=== RUN TestShutdownFinishesInFlightPush/completes2715=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2716=== PAUSE TestShutdownFinishesInFlightPush/completes2717=== CONT TestWorkerUploadsAndRemoves2718=== CONT TestRunNotBlockedByPoisonHead2719=== CONT TestServerBacksOffOnAcceptErrors2720=== CONT TestServerRefusesOversizedAndNonStoreRequests2721=== CONT TestWorkerKeepsPathItCannotStat27222026/10/28 14:32:23 ERROR Accept failed error="too many open files"2723=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2724=== CONT TestQueueRemoveLargeClosure2725=== CONT TestQueueConcurrentWriters2726=== CONT TestQueueFetchRemoveLifecycle2727=== CONT TestQueueRemove2728=== CONT TestQueueRetryMovesToBack2729=== CONT TestWorkerSkipsGCdPaths2730=== CONT TestQueueFetchBatchLimit2731=== CONT TestQueueDeduplication2732=== CONT TestDrainTimeout2733=== CONT TestWorkerPrunesClosureDeps2734=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2735=== CONT TestFailedPathPrunedByLaterClosure2736=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout27372026/10/28 14:32:23 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2738=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2739=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2740=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2741=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2742=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch27432026/10/28 14:32:23 ERROR Refusing path outside the store path=/nix/store store=/nix/store2744=== CONT TestSendPathsEmpty2745=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline27462026/10/28 14:32:23 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store2747=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2748--- PASS: TestSendPathsEmpty (0.00s)2749=== CONT TestShutdownFinishesInFlightPush/completes2750=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout27512026/10/28 14:32:23 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store27522026/10/28 14:32:23 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store2753=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths27542026/10/28 14:32:23 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store2755=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths27562026/10/28 14:32:23 ERROR Accept failed error="too many open files"2757=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline27582026/10/28 14:32:23 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27592026/10/28 14:32:23 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store27602026/10/28 14:32:23 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store27612026/10/28 14:32:23 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store27622026/10/28 14:32:23 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store27632026/10/28 14:32:23 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store27642026/10/28 14:32:23 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store27652026/10/28 14:32:23 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store27662026/10/28 14:32:23 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store27672026/10/28 14:32:23 ERROR Failed to decode request error="unexpected EOF"2768--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2769=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short27702026/10/28 14:32:23 ERROR Accept failed error="too many open files"27712026/10/28 14:32:23 ERROR Accept failed error="too many open files"27722026/10/28 14:32:23 INFO Upload queue status pending=327732026/10/28 14:32:23 INFO Upload queue status pending=227742026/10/28 14:32:23 INFO Uploading batch count=127752026/10/28 14:32:23 ERROR Upload failed error="upload failed" count=127762026/10/28 14:32:23 INFO Upload queue status pending=227772026/10/28 14:32:23 INFO Upload queue status pending=227782026/10/28 14:32:23 INFO Uploading batch count=227792026/10/28 14:32:23 INFO Upload queue status pending=227802026/10/28 14:32:23 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3450081650/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat3450081650/002/locked/aaa: permission denied"27812026/10/28 14:32:23 INFO Upload queue status pending=327822026/10/28 14:32:23 INFO Uploading batch count=227832026/10/28 14:32:23 INFO Uploading batch count=227842026/10/28 14:32:23 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2903412843/002/nonexistent27852026/10/28 14:32:23 INFO Uploading batch count=427862026/10/28 14:32:23 ERROR Upload failed error="upload failed" count=427872026/10/28 14:32:23 INFO Uploading batch count=227882026/10/28 14:32:23 INFO Uploading batch count=227892026/10/28 14:32:23 ERROR Accept failed error="too many open files"27902026/10/28 14:32:23 INFO Upload queue status pending=227912026/10/28 14:32:23 INFO Uploading batch count=127922026/10/28 14:32:23 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3450081650/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat3450081650/002/locked/aaa: permission denied"27932026/10/28 14:32:23 INFO Uploading batch count=427942026/10/28 14:32:23 ERROR Upload failed error="upload failed" count=427952026/10/28 14:32:23 INFO Uploading batch count=227962026/10/28 14:32:23 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3639101480/002/bbb2797=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch2798--- PASS: TestQueueFetchBatchLimit (0.08s)2799=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths2800--- PASS: TestQueueRetryMovesToBack (0.08s)2801=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path2802--- PASS: TestQueueDeduplication (0.08s)28032026/10/28 14:32:23 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3450081650/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat3450081650/002/locked/aaa: permission denied"28042026/10/28 14:32:23 INFO Uploading batch count=128052026/10/28 14:32:23 ERROR Upload failed error="upload failed" count=128062026/10/28 14:32:23 INFO Uploading batch count=428072026/10/28 14:32:23 ERROR Upload failed error="upload failed" count=428082026/10/28 14:32:23 INFO Uploading batch count=228092026/10/28 14:32:23 ERROR Upload failed error="upload failed" count=228102026/10/28 14:32:23 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1665701603/002/a2811--- PASS: TestQueueRemove (0.09s)2812--- PASS: TestQueueEnqueueAndFetch (0.09s)28132026/10/28 14:32:23 ERROR Drain finished with paths left in queue remaining=128142026/10/28 14:32:23 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1665701603/002/b28152026/10/28 14:32:23 INFO Uploading batch count=12816--- PASS: TestQueueFetchRemoveLifecycle (0.09s)28172026/10/28 14:32:23 INFO Uploading batch count=128182026/10/28 14:32:23 ERROR Upload failed error="upload failed" count=128192026/10/28 14:32:23 INFO Uploading batch count=228202026/10/28 14:32:23 ERROR Upload failed error="upload failed" count=228212026/10/28 14:32:23 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1665701603/002/c28222026/10/28 14:32:23 INFO Uploading batch count=12823--- PASS: TestWorkerKeepsPathItCannotStat (0.09s)28242026/10/28 14:32:23 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1665701603/002/d28252026/10/28 14:32:23 INFO Uploading batch count=12826--- PASS: TestWorkerUploadsAndRemoves (0.10s)28272026/10/28 14:32:23 ERROR Upload failed error="upload failed" count=12828--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.10s)28292026/10/28 14:32:23 INFO Uploading batch count=228302026/10/28 14:32:23 ERROR Upload failed error="upload failed" count=228312026/10/28 14:32:23 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1665701603/002/e28322026/10/28 14:32:23 INFO Uploading batch count=128332026/10/28 14:32:23 ERROR Upload failed error="upload failed" count=12834--- PASS: TestWorkerSkipsGCdPaths (0.10s)2835--- PASS: TestWorkerPrunesClosureDeps (0.10s)28362026/10/28 14:32:23 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1665701603/002/f28372026/10/28 14:32:23 ERROR Drain finished with paths left in queue remaining=12838--- PASS: TestFailedPathPrunedByLaterClosure (0.10s)28392026/10/28 14:32:23 ERROR Drain finished with paths left in queue remaining=102840--- PASS: TestDrainIsolatesPoisonPath (0.11s)2841--- PASS: TestDrainGivesUpWhenServerDown (0.11s)28422026/10/28 14:32:23 INFO Uploading batch count=228432026/10/28 14:32:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228442026/10/28 14:32:23 INFO Uploading batch count=228452026/10/28 14:32:23 ERROR Upload failed error="upload failed" count=228462026/10/28 14:32:23 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path4025448214/001/nonexistent28472026/10/28 14:32:23 INFO Uploading batch count=228482026/10/28 14:32:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128492026/10/28 14:32:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228502026/10/28 14:32:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128512026/10/28 14:32:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128522026/10/28 14:32:23 INFO Uploading batch count=228532026/10/28 14:32:23 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path4025448214/001/nonexistent28542026/10/28 14:32:23 INFO Uploading batch count=228552026/10/28 14:32:23 ERROR Upload failed error="upload failed" count=228562026/10/28 14:32:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228572026/10/28 14:32:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128582026/10/28 14:32:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128592026/10/28 14:32:23 ERROR Drain finished with paths left in queue remaining=228602026/10/28 14:32:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128612026/10/28 14:32:23 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path4025448214/001/nonexistent28622026/10/28 14:32:23 INFO Uploading batch count=228632026/10/28 14:32:23 ERROR Upload failed error="upload failed" count=228642026/10/28 14:32:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128652026/10/28 14:32:23 ERROR Drain finished with paths left in queue remaining=128662026/10/28 14:32:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128672026/10/28 14:32:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128682026/10/28 14:32:23 ERROR Drain finished with paths left in queue remaining=22869--- PASS: TestWorkerRemoveFailureIsNotProgress (0.01s)2870 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.05s)2871 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.05s)2872 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.05s)28732026/10/28 14:32:23 ERROR Accept failed error="too many open files"28742026/10/28 14:32:23 ERROR Failed to decode request error="read unix /build/hook143403255/test.sock->@: i/o timeout"28752026/10/28 14:32:23 ERROR Failed to write response error="write unix /build/hook143403255/test.sock->@: i/o timeout"2876--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)28772026/10/28 14:32:23 ERROR Upload failed error="context canceled" count=228782026/10/28 14:32:23 ERROR Upload failed error="context canceled" count=228792026/10/28 14:32:23 ERROR Drain finished with paths left in queue remaining=228802026/10/28 14:32:23 ERROR Drain finished with paths left in queue remaining=42881--- PASS: TestShutdownFinishesInFlightPush (0.00s)2882 --- PASS: TestShutdownFinishesInFlightPush/completes (0.22s)2883 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.27s)2884--- PASS: TestDrainTimeout (0.28s)28852026/10/28 14:32:23 ERROR Drain finished with paths left in queue remaining=428862026/10/28 14:32:23 ERROR Accept failed error="too many open files"28872026/10/28 14:32:23 ERROR Drain finished with paths left in queue remaining=32888--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2889 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.27s)2890 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.38s)28912026/10/28 14:32:23 ERROR Accept failed error="too many open files"2892--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)2893--- PASS: TestQueueConcurrentWriters (0.65s)28942026/10/28 14:32:24 INFO Uploading batch count=128952026/10/28 14:32:24 INFO Uploading batch count=128962026/10/28 14:32:24 INFO Uploading batch count=128972026/10/28 14:32:24 ERROR Upload failed error="upload failed" count=128982026/10/28 14:32:24 INFO Uploading batch count=128992026/10/28 14:32:24 ERROR Upload failed error="upload failed" count=129002026/10/28 14:32:24 INFO Uploading batch count=129012026/10/28 14:32:24 ERROR Upload failed error="upload failed" count=129022026/10/28 14:32:24 INFO Uploading batch count=129032026/10/28 14:32:24 ERROR Upload failed error="upload failed" count=129042026/10/28 14:32:24 ERROR Drain finished with paths left in queue remaining=12905--- PASS: TestRunNotBlockedByPoisonHead (1.10s)2906--- PASS: TestQueueRemoveLargeClosure (2.56s)2907PASS2908Running signing tests...2909=== RUN TestExternalSigner2910=== PAUSE TestExternalSigner2911=== RUN TestExternalSignerWrongPublicKey2912=== PAUSE TestExternalSignerWrongPublicKey2913=== RUN TestExternalSignerErrors2914=== PAUSE TestExternalSignerErrors2915=== RUN TestExternalSignerRestartsAfterCrash2916=== PAUSE TestExternalSignerRestartsAfterCrash2917=== RUN TestExternalSignerProgramErrorKeepsProcess2918=== PAUSE TestExternalSignerProgramErrorKeepsProcess2919=== RUN TestExternalSignerClose2920=== PAUSE TestExternalSignerClose2921=== RUN TestExternalSignerRejectsInvalidPublicKey2922=== PAUSE TestExternalSignerRejectsInvalidPublicKey2923=== RUN TestExternalSignerCancellation2924=== PAUSE TestExternalSignerCancellation2925=== RUN TestGenerateFingerprint2926=== PAUSE TestGenerateFingerprint2927=== RUN TestParseSigningKey2928=== PAUSE TestParseSigningKey2929=== RUN TestSign2930=== PAUSE TestSign2931=== RUN TestSignBatch2932=== PAUSE TestSignBatch2933=== RUN TestNilKeyPublicKey2934=== PAUSE TestNilKeyPublicKey2935=== RUN TestSignErrors2936=== PAUSE TestSignErrors2937=== CONT TestExternalSigner2938=== CONT TestNilKeyPublicKey2939=== CONT TestParseSigningKey2940--- PASS: TestNilKeyPublicKey (0.00s)2941=== RUN TestParseSigningKey/valid_32-byte_key2942=== PAUSE TestParseSigningKey/valid_32-byte_key2943=== CONT TestExternalSignerProgramErrorKeepsProcess2944=== CONT TestExternalSignerClose2945=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2946=== CONT TestExternalSignerWrongPublicKey2947=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2948=== CONT TestExternalSignerRestartsAfterCrash2949=== CONT TestExternalSignerErrors2950=== CONT TestSignBatch2951=== CONT TestSignErrors2952=== CONT TestSign2953=== CONT TestGenerateFingerprint2954=== CONT TestExternalSignerCancellation2955=== CONT TestExternalSignerRejectsInvalidPublicKey2956=== RUN TestParseSigningKey/no_colon2957=== PAUSE TestParseSigningKey/no_colon2958=== RUN TestParseSigningKey/empty_name2959=== PAUSE TestParseSigningKey/empty_name2960=== RUN TestExternalSignerErrors/invalid_JSON2961=== RUN TestParseSigningKey/invalid_base642962=== PAUSE TestExternalSignerErrors/invalid_JSON2963=== PAUSE TestParseSigningKey/invalid_base642964=== RUN TestExternalSignerRejectsInvalidPublicKey/#002965=== RUN TestParseSigningKey/wrong_length2966=== RUN TestExternalSignerErrors/wrong_id2967=== RUN TestGenerateFingerprint/basic_with_references2968=== PAUSE TestExternalSignerErrors/wrong_id2969=== RUN TestExternalSignerErrors/invalid_signature_base642970=== PAUSE TestGenerateFingerprint/basic_with_references2971=== PAUSE TestExternalSignerErrors/invalid_signature_base642972=== RUN TestExternalSignerErrors/wrong_shape2973=== RUN TestGenerateFingerprint/no_references2974=== PAUSE TestExternalSignerErrors/wrong_shape2975=== RUN TestExternalSignerErrors/missing_signatures2976=== PAUSE TestParseSigningKey/wrong_length2977=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002978=== PAUSE TestGenerateFingerprint/no_references2979=== PAUSE TestExternalSignerErrors/missing_signatures2980=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2981=== RUN TestExternalSignerErrors/wrong_signatures_shape2982=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2983=== CONT TestParseSigningKey/invalid_base642984=== CONT TestParseSigningKey/wrong_length2985=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2986=== CONT TestParseSigningKey/empty_name2987=== CONT TestParseSigningKey/no_colon2988=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2989=== CONT TestParseSigningKey/valid_32-byte_key2990=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2991=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2992=== RUN TestExternalSignerErrors/too_few_signatures2993=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2994=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2995=== PAUSE TestExternalSignerErrors/too_few_signatures2996=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2997=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2998=== RUN TestExternalSignerErrors/unrequested_key2999=== PAUSE TestExternalSignerErrors/unrequested_key3000=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!3001=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix3002=== RUN TestExternalSignerErrors/wrong_signature_length3003=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==3004=== PAUSE TestExternalSignerErrors/wrong_signature_length3005=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==3006=== RUN TestGenerateFingerprint/invalid_nar_hash_length3007=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!3008=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon3009=== CONT TestExternalSignerRejectsInvalidPublicKey/#003010=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=3011=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==3012=== RUN TestExternalSignerErrors/program_error3013--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)3014 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)3015 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)3016 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)3017 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)3018 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)3019=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length3020=== PAUSE TestExternalSignerErrors/program_error3021=== RUN TestGenerateFingerprint/invalid_store_path_prefix3022=== RUN TestExternalSignerErrors/exit_at_startup3023=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix3024--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)3025=== PAUSE TestExternalSignerErrors/exit_at_startup3026=== RUN TestGenerateFingerprint/invalid_reference_prefix3027=== PAUSE TestGenerateFingerprint/invalid_reference_prefix3028=== RUN TestExternalSignerErrors/exit_on_request3029=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix3030=== CONT TestGenerateFingerprint/invalid_reference_prefix3031=== CONT TestGenerateFingerprint/unsorted_references_get_sorted3032=== PAUSE TestExternalSignerErrors/exit_on_request3033=== CONT TestGenerateFingerprint/no_references3034=== CONT TestGenerateFingerprint/invalid_store_path_prefix3035=== CONT TestGenerateFingerprint/basic_with_references3036=== CONT TestGenerateFingerprint/invalid_nar_hash_length3037=== RUN TestExternalSignerErrors/null3038=== PAUSE TestExternalSignerErrors/null3039=== RUN TestExternalSignerErrors/null_signatures3040--- PASS: TestGenerateFingerprint (0.00s)3041 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)3042 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)3043 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)3044 --- PASS: TestGenerateFingerprint/no_references (0.00s)3045 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)3046 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)3047 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)3048=== PAUSE TestExternalSignerErrors/null_signatures3049=== RUN TestExternalSignerErrors/missing_signature_name3050=== PAUSE TestExternalSignerErrors/missing_signature_name3051=== RUN TestExternalSignerErrors/wrong_signature_name3052=== PAUSE TestExternalSignerErrors/wrong_signature_name3053=== CONT TestExternalSignerErrors/invalid_JSON3054=== CONT TestExternalSignerErrors/missing_signatures3055=== CONT TestExternalSignerErrors/wrong_signature_length3056=== CONT TestExternalSignerErrors/unrequested_key3057=== CONT TestExternalSignerErrors/wrong_shape3058=== CONT TestExternalSignerErrors/null_signatures3059=== CONT TestExternalSignerErrors/wrong_signature_name3060=== CONT TestExternalSignerErrors/exit_on_request3061=== CONT TestExternalSignerErrors/too_few_signatures3062=== CONT TestExternalSignerErrors/exit_at_startup3063=== CONT TestExternalSignerErrors/program_error3064=== CONT TestExternalSignerErrors/null3065=== CONT TestExternalSignerErrors/wrong_signatures_shape3066=== CONT TestExternalSignerErrors/missing_signature_name3067--- PASS: TestExternalSignerClose (0.01s)3068=== CONT TestExternalSignerErrors/invalid_signature_base643069=== CONT TestExternalSignerErrors/wrong_id3070--- PASS: TestExternalSignerWrongPublicKey (0.01s)3071=== RUN TestSignErrors/nil_key3072=== PAUSE TestSignErrors/nil_key3073=== RUN TestSignErrors/nil_narinfo3074=== PAUSE TestSignErrors/nil_narinfo3075=== RUN TestSignErrors/invalid_narinfo3076=== PAUSE TestSignErrors/invalid_narinfo3077=== RUN TestSignErrors/canceled3078=== PAUSE TestSignErrors/canceled3079=== CONT TestSignErrors/nil_key3080=== CONT TestSignErrors/invalid_narinfo3081=== CONT TestSignErrors/canceled3082=== CONT TestSignErrors/nil_narinfo3083--- PASS: TestParseSigningKey (0.00s)3084 --- PASS: TestParseSigningKey/wrong_length (0.00s)3085 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)3086 --- PASS: TestParseSigningKey/empty_name (0.00s)3087 --- PASS: TestParseSigningKey/no_colon (0.00s)3088 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.01s)3089 --- PASS: TestParseSigningKey/valid_32-byte_key (0.01s)3090--- PASS: TestSignErrors (0.01s)3091 --- PASS: TestSignErrors/nil_key (0.00s)3092 --- PASS: TestSignErrors/invalid_narinfo (0.00s)3093 --- PASS: TestSignErrors/canceled (0.00s)3094 --- PASS: TestSignErrors/nil_narinfo (0.00s)3095--- PASS: TestExternalSignerErrors (0.01s)3096 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.00s)3097 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)3098 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)3099 --- PASS: TestExternalSignerErrors/program_error (0.01s)3100 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)3101 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)3102 --- PASS: TestExternalSignerErrors/null (0.01s)3103 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)3104 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)3105 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)3106 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)3107 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)3108 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)3109 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)3110 --- PASS: TestExternalSignerErrors/wrong_id (0.00s)3111 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)3112--- PASS: TestExternalSignerRestartsAfterCrash (0.02s)3113--- PASS: TestSign (0.02s)3114--- PASS: TestExternalSigner (0.02s)3115--- PASS: TestExternalSignerCancellation (0.02s)3116--- PASS: TestSignBatch (0.03s)3117PASS3118Running OpenBao signer tests...3119=== RUN TestSign3120=== PAUSE TestSign3121=== RUN TestSignErrors3122=== PAUSE TestSignErrors3123=== RUN TestServe3124=== PAUSE TestServe3125=== RUN TestServeRejectsGarbage3126=== PAUSE TestServeRejectsGarbage3127=== CONT TestSign3128=== CONT TestServe3129=== CONT TestSignErrors3130=== CONT TestServeRejectsGarbage3131=== RUN TestSignErrors/invalid_base643132=== PAUSE TestSignErrors/invalid_base643133--- PASS: TestServeRejectsGarbage (0.00s)3134=== RUN TestSignErrors/http_error3135=== PAUSE TestSignErrors/http_error3136=== RUN TestSignErrors/invalid_json3137=== PAUSE TestSignErrors/invalid_json3138--- PASS: TestServe (0.00s)3139=== RUN TestSignErrors/no_prefix3140=== PAUSE TestSignErrors/no_prefix3141=== CONT TestSignErrors/invalid_base643142=== CONT TestSignErrors/http_error3143=== CONT TestSignErrors/invalid_json3144=== CONT TestSignErrors/no_prefix3145--- PASS: TestSign (0.01s)3146--- PASS: TestSignErrors (0.00s)3147 --- PASS: TestSignErrors/invalid_json (0.01s)3148 --- PASS: TestSignErrors/no_prefix (0.01s)3149 --- PASS: TestSignErrors/invalid_base64 (0.01s)3150 --- PASS: TestSignErrors/http_error (0.01s)3151PASS3152Running niks3-hook command tests...3153=== RUN TestServeSecondSignalEndsDrain3154=== PAUSE TestServeSecondSignalEndsDrain3155=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown3156=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown3157=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown3158=== CONT TestServeSecondSignalEndsDrain3159--- PASS: TestServeSecondSignalEndsDrain (0.07s)31602026/10/28 14:32:29 INFO Upload queue status pending=131612026/10/28 14:32:29 INFO Uploading batch count=13162--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.14s)3163PASS3164Running rate limiter tests...3165=== RUN TestAdaptiveRateLimiter_ThreadSafety3166=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3167=== CONT TestAdaptiveRateLimiter_ThreadSafety31682026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=112.7357000000000731692026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=78.9149900000000531702026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=55.2404930000000331712026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=38.6683451000000231722026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=27.0678415700000131732026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=18.94748909900000631742026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=13.26324236930000431752026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=9.28426965851000231762026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=6.49898876095700131772026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=531782026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=5.12435000000000131792026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=531802026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=531812026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=531822026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=531832026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=531842026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=531852026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=531862026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=531872026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=531882026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=531892026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=531902026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=531912026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=531922026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=531932026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=531942026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=531952026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=531962026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=531972026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=531982026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=531992026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532002026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532012026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532022026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532032026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532042026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532052026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532062026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532072026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532082026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532092026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532102026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532112026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532122026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532132026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532142026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532152026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532162026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532172026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532182026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532192026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532202026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532212026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532222026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532232026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532242026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532252026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532262026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532272026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532282026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532292026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532302026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532312026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532322026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532332026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532342026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532352026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532362026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532372026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532382026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532392026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532402026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532412026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532422026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532432026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532442026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532452026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532462026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532472026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532482026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532492026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532502026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532512026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532522026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532532026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532542026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=5.12435000000000132552026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532562026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532572026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532582026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532592026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532602026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532612026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532622026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532632026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532642026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=6.200463500000001532652026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532662026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=532672026/10/28 14:32:30 WARN Rate limiter backed off name=test rate=5.6367850000000013268--- PASS: TestAdaptiveRateLimiter_ThreadSafety (2.18s)3269PASS