niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #448
· raw
1tribuchet: building on mac022Running 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.19s)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:280: no /proc/self/io: open /proc/self/io: no such file or directory45--- SKIP: TestDumpPathWriterErrorStopsReading (0.46s)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.01s)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 TestStreamPushReportsEveryPath137=== CONT TestDoServerRequestAttachesToken138=== CONT TestScriptTokenCachesUntilRefresh139=== CONT TestResolveStorePath140=== CONT TestStreamPushStartsNothingOnSlotFreedByCancel141=== CONT TestStreamPushStopsOnCancel142=== CONT TestStaticToken143=== CONT TestFileTokenMissing144--- PASS: TestStaticToken (0.00s)145=== CONT TestStreamPushReportsSkippedPaths146=== RUN TestStreamPushStopsOnCancel/waiting_for_input147=== CONT TestFileTokenEmpty148=== CONT TestSetClientTLSErrors149=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input150=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot151=== CONT TestScriptTokenDoesNotWaitForItsChildren152=== CONT TestScriptTokenScriptFails153=== CONT TestFileTokenReadsAndCaches154=== CONT TestScriptTokenEmptyCommand155=== CONT TestClientSignaturesByStorePath156=== CONT TestScriptTokenBadJSON157=== CONT TestScriptTokenEmptyToken158=== CONT TestDumpPathSingleFile159=== CONT TestDoWithRetry_FinalResponseBodyReadable160=== CONT TestRetryTimeoutOutlastsMaxRetries161=== CONT TestDoWithRetry_BodyReplayedViaGetBody162=== CONT TestSetClientTLSDoesNotMutateDefaultTransport163=== CONT TestSetClientTLS164=== CONT TestStreamPushGivesUpOnDeadServer165=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer166=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot167=== CONT TestScriptTokenNoExpiryRerunsEveryCall168--- PASS: TestFileTokenMissing (0.00s)169=== CONT TestStreamPushReportsSignatures170--- PASS: TestStreamPushReportsSkippedPaths (0.00s)171=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs172--- PASS: TestFileTokenEmpty (0.00s)173=== CONT TestStreamPushBatchesUnderLoad174--- PASS: TestStreamPushReportsEveryPath (0.00s)175--- PASS: TestScriptTokenEmptyCommand (0.00s)176=== CONT TestStreamPushRequestLine177--- PASS: TestClientSignaturesByStorePath (0.00s)178=== CONT TestStreamPushIsolatesFailures179--- PASS: TestStreamPushIsolatesFailures (0.00s)180=== CONT TestShellSplitErrors181--- PASS: TestShellSplitErrors (0.00s)182=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot183=== CONT TestShellSplit184=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs185--- PASS: TestFileTokenReadsAndCaches (0.01s)186=== CONT TestRateLimiterFeedback187--- PASS: TestResolveStorePath (0.01s)188=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout189=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure190=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess191=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout192=== CONT TestFilterOversizedClosures193=== RUN TestFilterOversizedClosures/no_limit_keeps_everything194=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything195=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false196=== CONT TestPathInfoCACompatibility197=== RUN TestRateLimiterFeedback/429_enables_limiter198=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot199=== CONT TestCompletePendingClosure_NotFoundWithoutKey200=== CONT TestParsePathInfoJSONMultiplePaths201--- PASS: TestShellSplit (0.00s)202=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent203=== CONT TestStreamPushStopsWhenCanceled204=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped205=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped206=== RUN TestSetClientTLSErrors/missing_cert_file207=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false208=== RUN TestPathInfoCACompatibility/null_ca_field209=== PAUSE TestRateLimiterFeedback/429_enables_limiter210=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot211=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths212--- PASS: TestScriptTokenScriptFails (0.01s)213=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths214--- PASS: TestDoServerRequestAttachesToken (0.01s)215=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun216=== RUN TestFilterOversizedClosures/all_closures_skipped217=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true218=== PAUSE TestSetClientTLSErrors/missing_cert_file219=== RUN TestRateLimiterFeedback/503_enables_limiter220=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot221=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier222=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths223=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths224--- PASS: TestStreamPushReportsSignatures (0.01s)225=== PAUSE TestFilterOversizedClosures/all_closures_skipped226=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica227=== RUN TestSetClientTLSErrors/missing_key_file228=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier229=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up230=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up231=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier232=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier233=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client234=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot235--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)236=== PAUSE TestSetClientTLSErrors/missing_key_file237=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot238--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)239=== CONT TestDumpPathMatchesNix240=== CONT TestRegisterUploadedObjectReusesConnections241=== CONT TestEncodeNixBase32242=== RUN TestEncodeNixBase32/test_string_hash243=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client244=== RUN TestSetClientTLS/rejects_connection_without_client_cert245=== CONT TestCaseHackSuffix246=== PAUSE TestPathInfoCACompatibility/null_ca_field247=== RUN TestSetClientTLSErrors/missing_ca_file248=== PAUSE TestRateLimiterFeedback/503_enables_limiter249--- PASS: TestStreamPushStopsWhenCanceled (0.00s)250=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken251=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true252=== CONT TestTruncatedNARDumpIsNotCompleted253=== PAUSE TestEncodeNixBase32/test_string_hash254=== CONT TestGetStorePathHash255=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client256=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert257--- PASS: TestScriptTokenEmptyToken (0.02s)258=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken259=== PAUSE TestSetClientTLSErrors/missing_ca_file260=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry261=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter262=== RUN TestPathInfoCACompatibility/old_string_format_-_text263=== RUN TestEncodeNixBase32/empty_input264=== RUN TestSetClientTLSErrors/invalid_ca_file265=== PAUSE TestEncodeNixBase32/empty_input266=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text267=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client268=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA269=== CONT TestPathInfoHashCompatibility270=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA271=== CONT TestPartSizeForNAR272=== RUN TestPartSizeForNAR/zero_stays_at_minimum273=== RUN TestSetClientTLS/preserves_debug_logging_transport274=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum275=== RUN TestPartSizeForNAR/small_stays_at_minimum276--- PASS: TestScriptTokenBadJSON (0.02s)277--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)278=== RUN TestGetStorePathHash/valid_store_path279=== PAUSE TestGetStorePathHash/valid_store_path280--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.01s)281=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter282=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter283=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter284=== RUN TestGetStorePathHash/basename_without_hyphen_should_error285=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive286=== CONT TestSupersededNARStillUploadsListing287=== PAUSE TestSetClientTLSErrors/invalid_ca_file288=== CONT TestParsePathInfoJSON289=== CONT TestUploadMultipart_SupersededByPeer290--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.02s)291=== RUN TestUploadMultipart_SupersededByPeer/exists292=== CONT TestUploadMultipart_ProducerErrorIsNotEOF293=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part294=== PAUSE TestUploadMultipart_SupersededByPeer/exists295=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part296=== RUN TestUploadMultipart_SupersededByPeer/missing297=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary298=== PAUSE TestUploadMultipart_SupersededByPeer/missing299=== CONT TestUploadMultipart_PartsInParallel300=== PAUSE TestPartSizeForNAR/small_stays_at_minimum301=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum302=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum303=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts304=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts305=== RUN TestPartSizeForNAR/1_TiB306=== PAUSE TestPartSizeForNAR/1_TiB307=== RUN TestPartSizeForNAR/5_TiB_S3_max_object308=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error309=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive310=== RUN TestPathInfoCACompatibility/new_structured_format_-_text311=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text312=== RUN TestSupersededNARStillUploadsListing/small_NAR313=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object314--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.02s)315=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method316=== PAUSE TestSupersededNARStillUploadsListing/small_NAR317=== RUN TestPartSizeForNAR/capped_at_5_GiB318=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error319=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error320=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error321=== RUN TestSupersededNARStillUploadsListing/dump_cut_short322=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short323=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails324=== PAUSE TestPartSizeForNAR/capped_at_5_GiB325=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails326=== CONT TestUploadMultipart_FailedPartBufferNotReused327=== CONT TestEncodeNixBase32WithRealHash328=== PAUSE TestSetClientTLS/preserves_debug_logging_transport329=== CONT TestDumpPathWriterError330--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.02s)331=== CONT TestConvertHashToNix32332--- PASS: TestEncodeNixBase32WithRealHash (0.00s)333=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout334=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method335=== RUN TestConvertHashToNix32/SRI_format_to_Nix32336=== RUN TestParsePathInfoJSON/Nix_format337=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32338=== RUN TestConvertHashToNix32/already_Nix32_format339=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs340=== PAUSE TestConvertHashToNix32/already_Nix32_format341=== RUN TestConvertHashToNix32/invalid_format342=== PAUSE TestConvertHashToNix32/invalid_format343=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths344=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)345=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error346=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)347=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary348=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths349=== PAUSE TestParsePathInfoJSON/Nix_format350=== RUN TestParsePathInfoJSON/Lix_format351=== PAUSE TestParsePathInfoJSON/Lix_format352=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon353=== CONT TestFilterOversizedClosures/no_limit_keeps_everything354=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped355=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon356=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI357=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI358=== CONT TestFilterOversizedClosures/all_closures_skipped359=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true360=== RUN TestParsePathInfoJSON/empty_input361--- PASS: TestFilterOversizedClosures (0.01s)362 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)363 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)364 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)365=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512366=== PAUSE TestParsePathInfoJSON/empty_input367=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512368=== RUN TestParsePathInfoJSON/whitespace_only369=== CONT TestStreamPushStopsOnCancel/waiting_for_input370=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false371=== PAUSE TestParsePathInfoJSON/whitespace_only372=== RUN TestParsePathInfoJSON/invalid_JSON373=== PAUSE TestParsePathInfoJSON/invalid_JSON374=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken375=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot376--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)377=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot378--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)379 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)380 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)381=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot382--- PASS: TestScriptTokenCachesUntilRefresh (0.05s)383--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.01s)384=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot385=== CONT TestEncodeNixBase32/test_string_hash386=== CONT TestEncodeNixBase32/empty_input387=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up388--- PASS: TestEncodeNixBase32 (0.01s)389 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)390 --- PASS: TestEncodeNixBase32/empty_input (0.00s)391=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client392--- PASS: TestStreamPushBatchesUnderLoad (0.03s)393 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.01s)394 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.02s)395--- PASS: TestDumpPathSingleFile (0.07s)396=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client397=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier398=== CONT TestRateLimiterFeedback/429_enables_limiter399=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier400=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter401=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter402=== CONT TestRateLimiterFeedback/503_enables_limiter403=== CONT TestSetClientTLSErrors/missing_cert_file404=== CONT TestSetClientTLSErrors/missing_ca_file405=== CONT TestSetClientTLSErrors/invalid_ca_file406=== CONT TestUploadMultipart_SupersededByPeer/missing407=== CONT TestPartSizeForNAR/zero_stays_at_minimum408=== CONT TestPartSizeForNAR/capped_at_5_GiB409=== CONT TestPartSizeForNAR/5_TiB_S3_max_object410=== CONT TestUploadMultipart_SupersededByPeer/exists411=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts412=== CONT TestSetClientTLSErrors/missing_key_file413--- PASS: TestRateLimiterFeedback (0.03s)414 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)415 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)416 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)417 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)418=== CONT TestPartSizeForNAR/small_stays_at_minimum419=== CONT TestPartSizeForNAR/1_TiB420=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum421--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.02s)422 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.01s)423 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.02s)424 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.03s)425 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.01s)426 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.01s)427=== CONT TestSetClientTLS/rejects_connection_without_client_cert428=== CONT TestSetClientTLS/preserves_debug_logging_transport429=== CONT TestSupersededNARStillUploadsListing/dump_cut_short430=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails431=== CONT TestSupersededNARStillUploadsListing/small_NAR432--- PASS: TestPartSizeForNAR (0.00s)433 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)434 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)435 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)436 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)437 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)438 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)439 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)440--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.10s)441=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA442--- PASS: TestSetClientTLSErrors (0.06s)443 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)444 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)445 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)446 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)447--- PASS: TestCaseHackSuffix (0.10s)448=== CONT TestPathInfoCACompatibility/null_ca_field449=== CONT TestPathInfoCACompatibility/new_structured_format_-_text450=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive451=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method452=== CONT TestPathInfoCACompatibility/old_string_format_-_text453=== CONT TestConvertHashToNix32/SRI_format_to_Nix32454=== CONT TestConvertHashToNix32/already_Nix32_format455=== CONT TestGetStorePathHash/valid_store_path456=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error457=== CONT TestGetStorePathHash/basename_without_hyphen_should_error458--- PASS: TestStreamPushStopsOnCancel (0.04s)459 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.05s)460 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.05s)461 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)462 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.06s)463 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.09s)464 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.09s)465=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error466--- PASS: TestGetStorePathHash (0.01s)467 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)468 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)469 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)470 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)471=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary472--- PASS: TestPathInfoCACompatibility (0.03s)473 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)474 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)475 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)476 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)477 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)478=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part479=== CONT TestConvertHashToNix32/invalid_format480=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)481=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI482--- PASS: TestConvertHashToNix32 (0.00s)483 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)484 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)485 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)486=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512487=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon488=== CONT TestParsePathInfoJSON/Nix_format489--- PASS: TestPathInfoHashCompatibility (0.00s)490 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)491 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)492 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)493 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)494=== CONT TestParsePathInfoJSON/invalid_JSON495=== CONT TestParsePathInfoJSON/empty_input496=== CONT TestParsePathInfoJSON/whitespace_only497=== CONT TestParsePathInfoJSON/Lix_format498--- PASS: TestParsePathInfoJSON (0.00s)499 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)500 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)501 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)502 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)503 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)504--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)505 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.05s)506 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.05s)507--- PASS: TestSetClientTLS (0.04s)508 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.06s)509 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.05s)510 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.15s)511--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.25s)512--- PASS: TestDumpPathWriterError (0.26s)513--- PASS: TestStreamPushStartsNothingOnSlotFreedByCancel (0.34s)514--- PASS: TestStreamPushRequestLine (0.81s)515--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.00s)516 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.47s)517 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.71s)518--- PASS: TestDumpPathMatchesNix (0.98s)519--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.01s)520--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.01s)521--- PASS: TestRegisterUploadedObjectReusesConnections (1.01s)522--- PASS: TestTruncatedNARDumpIsNotCompleted (1.25s)523--- PASS: TestUploadMultipart_PartsInParallel (1.45s)524--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.49s)525--- PASS: TestSupersededNARStillUploadsListing (0.00s)526 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.05s)527 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.06s)528 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.45s)529--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.02s)530 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.03s)531 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.21s)532PASS533Running server tests...534The files belonging to this database system will be owned by user "_tribuchetbld4".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 /private/var/tb/4/scratch/99e362236db6695a/build/postgres1859659393/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 /private/var/tb/4/scratch/99e362236db6695a/build/postgres1859659393/data -l logfile start560561/private/var/tb/4/scratch/99e362236db6695a/build/postgres1859659393:5432 - no response5622026-10-29 01:20:58.771 UTC [43591] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5632026-10-29 01:20:58.771 UTC [43591] LOG: listening on Unix socket "/private/var/tb/4/scratch/99e362236db6695a/build/postgres1859659393/.s.PGSQL.5432"5642026-10-29 01:20:58.774 UTC [43598] LOG: database system was shut down at 2026-10-29 01:20:58 UTC5652026-10-29 01:20:58.775 UTC [43591] LOG: database system is ready to accept connections566/private/var/tb/4/scratch/99e362236db6695a/build/postgres1859659393:5432 - accepting connections567{"timestamp":"2026-10-29T01:20:59.020716Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"7d652f70-aa29-4d24-8aa9-9256b398cde1","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":8,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(7)"}568{"timestamp":"2026-10-29T01:20:59.131087Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"23136eb2-f953-4f75-9d32-eafffdbfdf54","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(5)"}569=== RUN TestService_AuthMiddleware570=== PAUSE TestService_AuthMiddleware571=== RUN TestService_AuthMiddleware_MTLSProxyHeader572=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader573=== RUN TestService_AuthMiddleware_MTLSBoundSubjects574=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects575=== RUN TestService_ReadAuthMiddleware576=== PAUSE TestService_ReadAuthMiddleware577=== RUN TestService_AuthMiddleware_OIDC578=== PAUSE TestService_AuthMiddleware_OIDC579=== RUN TestService_RequireScope_OIDC580=== PAUSE TestService_RequireScope_OIDC581=== RUN TestService_ReadScope_PublicByDefault582=== PAUSE TestService_ReadScope_PublicByDefault583=== RUN TestCacheConfigHandler584=== PAUSE TestCacheConfigHandler585=== RUN TestCacheStatsHandler586=== PAUSE TestCacheStatsHandler587=== RUN TestClientCADerivations588=== PAUSE TestClientCADerivations589=== RUN TestClientErrorHandling590=== PAUSE TestClientErrorHandling591=== RUN TestClientIntegration592=== PAUSE TestClientIntegration593=== RUN TestClientMultipleUploads594=== PAUSE TestClientMultipleUploads595=== RUN TestClientWithDependencies596=== PAUSE TestClientWithDependencies597=== RUN TestClientSharedPathCommittedMidPush598=== PAUSE TestClientSharedPathCommittedMidPush599=== RUN TestPinProtectsFromGC600=== PAUSE TestPinProtectsFromGC601=== RUN TestClientPushesUseOnePush602=== PAUSE TestClientPushesUseOnePush603=== RUN TestClientFallsBackToClosures604=== PAUSE TestClientFallsBackToClosures605=== RUN TestDeleteClosuresRacingPins606=== PAUSE TestDeleteClosuresRacingPins607=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock608=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock609=== RUN TestResolveDBConnectionString610=== PAUSE TestResolveDBConnectionString611=== RUN TestConnectWaitsForAPeerMigration612=== PAUSE TestConnectWaitsForAPeerMigration613=== RUN TestConnectSerialisesConcurrentMigrations614=== PAUSE TestConnectSerialisesConcurrentMigrations615=== RUN TestLeadElectsOneAndHandsOver616=== PAUSE TestLeadElectsOneAndHandsOver617=== RUN TestLeadIncumbentWinsAfterRestart6182026/10/29 01:20:59 INFO lead: acquired remote=192.0.2.1:12346192026/10/29 01:21:00 INFO lead: released remote=192.0.2.1:12346202026/10/29 01:21:00 INFO lead: acquired remote=192.0.2.1:12346212026/10/29 01:21:01 INFO lead: released remote=192.0.2.1:1234622--- PASS: TestLeadIncumbentWinsAfterRestart (2.05s)623=== RUN TestLeadIncumbentAnnouncesAtOnce624=== PAUSE TestLeadIncumbentAnnouncesAtOnce625=== RUN TestLeadEndsOnShutdown626=== PAUSE TestLeadEndsOnShutdown627=== RUN TestLeadEndsWhenItsConnectionHangs6282026/10/29 01:21:01 INFO lead: acquired remote=192.0.2.1:12346292026-10-29 01:21:02.653 UTC [43644] FATAL: terminating connection due to administrator command6302026/10/29 01:21:02 INFO lead: acquired remote=192.0.2.1:12346312026/10/29 01:21:03 WARN lead: lock connection lost error="timeout: context deadline exceeded"6322026/10/29 01:21:03 INFO lead: released remote=192.0.2.1:12346332026/10/29 01:21:04 INFO lead: released remote=192.0.2.1:1234634--- PASS: TestLeadEndsWhenItsConnectionHangs (2.77s)635=== RUN TestGCAdvisoryLockBlocksConcurrentRun636=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun637=== RUN TestGCBugBareHashReferences638=== PAUSE TestGCBugBareHashReferences639=== RUN TestGCMetrics640=== PAUSE TestGCMetrics641=== RUN TestPushDedupSurvivesConcurrentGC642=== PAUSE TestPushDedupSurvivesConcurrentGC643=== RUN TestDeduplicatedObjectsRecordedAsPending644=== PAUSE TestDeduplicatedObjectsRecordedAsPending645=== RUN TestGCSweepSkipsPendingObjects646=== PAUSE TestGCSweepSkipsPendingObjects647=== RUN TestTombstonedObjectOfferedWithoutWaiting648=== PAUSE TestTombstonedObjectOfferedWithoutWaiting649=== RUN TestGCSweepDeliversEachKeyOnce650=== PAUSE TestGCSweepDeliversEachKeyOnce651=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection652=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection653=== RUN TestForceGCDuringPushOffersSweptObject654=== PAUSE TestForceGCDuringPushOffersSweptObject655=== RUN TestFailedS3DeleteKeepsTombstone656=== PAUSE TestFailedS3DeleteKeepsTombstone657=== RUN TestSweepSkipsRowsLockedByPush658=== PAUSE TestSweepSkipsRowsLockedByPush659=== RUN TestRegisterCompletedObjectNeedsPendingRow660=== PAUSE TestRegisterCompletedObjectNeedsPendingRow661=== RUN TestGetExistingObjectsLocksRows662=== PAUSE TestGetExistingObjectsLocksRows663=== RUN TestSweepRechecksPendingAfterLocking664=== PAUSE TestSweepRechecksPendingAfterLocking665=== RUN TestPushWaitsForSweepHoldingRow666=== PAUSE TestPushWaitsForSweepHoldingRow667=== RUN TestCommitRacingPendingCleanupKeepsObjects668=== PAUSE TestCommitRacingPendingCleanupKeepsObjects669=== RUN TestGCEndsOnShutdown670=== PAUSE TestGCEndsOnShutdown671=== RUN TestGCTaskStore_StartNew672=== PAUSE TestGCTaskStore_StartNew673=== RUN TestGCTaskStore_DeduplicateSameParams674=== PAUSE TestGCTaskStore_DeduplicateSameParams675=== RUN TestGCTaskStore_ConflictDifferentParams676=== PAUSE TestGCTaskStore_ConflictDifferentParams677=== RUN TestGCTaskStore_GetEmpty678=== PAUSE TestGCTaskStore_GetEmpty679=== RUN TestGCTaskStore_GetReturnsLatest680=== PAUSE TestGCTaskStore_GetReturnsLatest681=== RUN TestGCTaskStore_CompletedAllowsNewTask682=== PAUSE TestGCTaskStore_CompletedAllowsNewTask683=== RUN TestGCTaskStore_PhaseUpdates684=== PAUSE TestGCTaskStore_PhaseUpdates685=== RUN TestGCTaskStore_Fail686=== PAUSE TestGCTaskStore_Fail687=== RUN TestGracefulShutdownDrainsInflight688=== PAUSE TestGracefulShutdownDrainsInflight689=== RUN TestService_healthCheckHandler690=== PAUSE TestService_healthCheckHandler691=== RUN TestService_readinessHandler692=== PAUSE TestService_readinessHandler693=== RUN TestGenerateLandingPage694=== PAUSE TestGenerateLandingPage695=== RUN TestChildrenInheritRaisedFileLimit696=== PAUSE TestChildrenInheritRaisedFileLimit697=== RUN TestCacheConfigHandlerMaxNarSize698=== PAUSE TestCacheConfigHandlerMaxNarSize699=== RUN TestCreatePendingClosureRejectsOversizedNAR700=== PAUSE TestCreatePendingClosureRejectsOversizedNAR701=== RUN TestNARDeduplicationMetadataUploadBug702=== PAUSE TestNARDeduplicationMetadataUploadBug703=== RUN TestMetricsInventory704=== PAUSE TestMetricsInventory705=== RUN TestMetricsCommit706=== PAUSE TestMetricsCommit707=== RUN TestService_NativeMTLS708=== PAUSE TestService_NativeMTLS709=== RUN TestServerTLSConfig710=== PAUSE TestServerTLSConfig711=== RUN TestMultipartCleanup712=== PAUSE TestMultipartCleanup713=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded714=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded715=== RUN TestPendingCleanupUsesOneCutoff716=== PAUSE TestPendingCleanupUsesOneCutoff717=== RUN TestPendingClosureFailureTracksEveryUpload718=== PAUSE TestPendingClosureFailureTracksEveryUpload719=== RUN TestPendingClosureFailureAbortsItsUploads720=== PAUSE TestPendingClosureFailureAbortsItsUploads721=== RUN TestObjectStatsTrigger722=== PAUSE TestObjectStatsTrigger723=== RUN TestObjectStatsUpdatedOncePerCommit724=== PAUSE TestObjectStatsUpdatedOncePerCommit725=== RUN TestReconnectLeavesObjectsUnlocked726=== PAUSE TestReconnectLeavesObjectsUnlocked727=== RUN TestOrphanedObjectsGC728=== PAUSE TestOrphanedObjectsGC729=== RUN TestOrphanedObjectsGCStressTest730=== PAUSE TestOrphanedObjectsGCStressTest731=== RUN TestCreatePin_ReservedPins732=== PAUSE TestCreatePin_ReservedPins733=== RUN TestConcurrentPinUpdatesAgree734=== PAUSE TestConcurrentPinUpdatesAgree735=== RUN TestCreatePinRejectsBadInput736=== PAUSE TestCreatePinRejectsBadInput737=== RUN TestDeletePinKeepsRowWhenS3Fails738=== PAUSE TestDeletePinKeepsRowWhenS3Fails739=== RUN TestPresentReportsOnlyClosureRoots740=== PAUSE TestPresentReportsOnlyClosureRoots741=== RUN TestPresentRefreshesOnlyStaleClosures742=== PAUSE TestPresentRefreshesOnlyStaleClosures743=== RUN TestPresentNotReportedWhileGCDeletesClosure744=== PAUSE TestPresentNotReportedWhileGCDeletesClosure745=== RUN TestParseSingleRange746=== PAUSE TestParseSingleRange747=== RUN TestProxyHeadersOnlyTrustedOnSocket7482026/10/29 01:21:04 INFO Starting HTTP server address=proxy.sock7492026/10/29 01:21:04 INFO Starting HTTP server address=127.0.0.1:620007502026/10/29 01:21:04 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7512026/10/29 01:21:04 INFO Shutdown signal received, draining in-flight requests timeout=10s752--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.17s)753=== RUN TestIsValidCachePath754=== PAUSE TestIsValidCachePath755=== RUN TestReadProxyNarinfo756=== PAUSE TestReadProxyNarinfo757=== RUN TestReadProxyNarinfoAlreadyDecompressed758=== PAUSE TestReadProxyNarinfoAlreadyDecompressed759=== RUN TestReadProxyContentNegotiation760=== PAUSE TestReadProxyContentNegotiation761=== RUN TestReadProxyNarStreaming762=== PAUSE TestReadProxyNarStreaming763=== RUN TestReadProxy404And429764=== PAUSE TestReadProxy404And429765=== RUN TestReadProxyInvalidPath766=== PAUSE TestReadProxyInvalidPath767=== RUN TestReadProxyHead768=== PAUSE TestReadProxyHead769=== RUN TestReadProxyOutlastsServerWriteTimeout770=== PAUSE TestReadProxyOutlastsServerWriteTimeout771=== RUN TestReadProxyConditionalGet772=== PAUSE TestReadProxyConditionalGet773=== RUN TestReadProxyRootRedirectsToIndexHTML774=== PAUSE TestReadProxyRootRedirectsToIndexHTML775=== RUN TestReadProxyDisabled776=== PAUSE TestReadProxyDisabled777=== RUN TestReadRedirectNar778=== PAUSE TestReadRedirectNar779=== RUN TestReadRedirectKeepsNarinfoProxied780=== PAUSE TestReadRedirectKeepsNarinfoProxied781=== RUN TestReadProxyRangeRequest782=== PAUSE TestReadProxyRangeRequest783=== RUN TestReadRedirectUsesPublicS3URL784=== PAUSE TestReadRedirectUsesPublicS3URL785=== RUN TestPush_OverlappingRootsStoreOneRowPerKey786=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey787=== RUN TestPush_CompleteCommitsEveryRoot788=== PAUSE TestPush_CompleteCommitsEveryRoot789=== RUN TestPush_RepeatedRootCommitsOnce790=== PAUSE TestPush_RepeatedRootCommitsOnce791=== RUN TestPush_CompleteWaitsForCleanupOfThePush792=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush793=== RUN TestPush_RootsAreLockedInByteOrder794=== PAUSE TestPush_RootsAreLockedInByteOrder795=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit796=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit797=== RUN TestPush_RejectsBadRequests798=== PAUSE TestPush_RejectsBadRequests799=== RUN TestPush_SignsNarinfosOfItsPendingObjects800=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects801=== RUN TestRedundantMultipartUpload802=== PAUSE TestRedundantMultipartUpload803=== RUN TestCompleteMultipartUpload_ErrorButObjectExists804=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists805=== RUN TestCompletedNarNotReofferedAcrossClosures806=== PAUSE TestCompletedNarNotReofferedAcrossClosures807=== RUN TestPresignedUploadRegisteredBeforeCommit808=== PAUSE TestPresignedUploadRegisteredBeforeCommit809=== RUN TestService_Rustfstest810=== PAUSE TestService_Rustfstest811=== RUN TestParseSize812=== PAUSE TestParseSize813=== RUN TestSkippedUploadsHandler814=== PAUSE TestSkippedUploadsHandler815=== RUN TestSystemdListenerNotActivated816--- PASS: TestSystemdListenerNotActivated (0.00s)817=== RUN TestWatchdogBeatsWhenHealthy818--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)819=== RUN TestWatchdogSkipsWhenUnhealthy8202026/10/29 01:21:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8212026/10/29 01:21:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8222026/10/29 01:21:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8232026/10/29 01:21:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8242026/10/29 01:21:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8252026/10/29 01:21:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8262026/10/29 01:21:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8272026/10/29 01:21:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8282026/10/29 01:21:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8292026/10/29 01:21:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"830--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)831=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle832=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle833=== RUN TestProxyWriteTimeout834=== PAUSE TestProxyWriteTimeout835=== RUN TestPendingClosureWriteTimeout836=== PAUSE TestPendingClosureWriteTimeout837=== RUN TestIsValidUploadKey838=== PAUSE TestIsValidUploadKey839=== RUN TestUploadHandlersRejectInvalidKeys840=== PAUSE TestUploadHandlersRejectInvalidKeys841=== RUN TestUploadHandlersRejectOversizedBody842=== PAUSE TestUploadHandlersRejectOversizedBody843=== RUN TestService_cleanupPendingClosuresHandler844=== PAUSE TestService_cleanupPendingClosuresHandler845=== RUN TestService_createPendingClosureHandler846=== PAUSE TestService_createPendingClosureHandler847=== RUN TestService_verifyS3Integrity848=== PAUSE TestService_verifyS3Integrity849=== RUN TestCompleteMultipartUnregistered850=== PAUSE TestCompleteMultipartUnregistered851=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT852=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT853=== CONT TestPush_SignsNarinfosOfItsPendingObjects854=== CONT TestService_createPendingClosureHandler855=== CONT TestPush_RepeatedRootCommitsOnce856=== CONT TestLeadElectsOneAndHandsOver857=== CONT TestGCTaskStore_PhaseUpdates858--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)859=== CONT TestGCTaskStore_ConflictDifferentParams860=== CONT TestForceGCDuringPushOffersSweptObject861=== CONT TestGCTaskStore_Fail862=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows863=== CONT TestTombstonedObjectOfferedWithoutWaiting864=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows865--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)866--- PASS: TestGCTaskStore_Fail (0.00s)867=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT868=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check869=== CONT TestLeadEndsOnShutdown870=== CONT TestGCTaskStore_GetReturnsLatest871=== CONT TestCompleteMultipartUnregistered872=== CONT TestRedundantMultipartUpload873=== CONT TestService_verifyS3Integrity874=== CONT TestUploadHandlersRejectOversizedBody875=== CONT TestPush_RejectsBadRequests876=== CONT TestIsValidUploadKey877=== CONT TestService_cleanupPendingClosuresHandler878=== CONT TestGracefulShutdownDrainsInflight879=== CONT TestPush_RootsAreLockedInByteOrder880=== CONT TestGCAdvisoryLockBlocksConcurrentRun881=== CONT TestGCTaskStore_CompletedAllowsNewTask882=== CONT TestSweepSkipsRowsLockedByPush883=== CONT TestGCSweepDeliversEachKeyOnce884=== CONT TestProxyWriteTimeout885=== CONT TestService_AuthMiddleware8862026/10/29 01:21:04 INFO Starting HTTP server address=127.0.0.1:62004887=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check888--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)889=== CONT TestGCSweepSkipsPendingObjects890=== RUN TestIsValidUploadKey/narinfo891=== RUN TestProxyWriteTimeout/narinfo892=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection893--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)894=== CONT TestDeduplicatedObjectsRecordedAsPending895=== PAUSE TestProxyWriteTimeout/narinfo896=== PAUSE TestIsValidUploadKey/narinfo897=== RUN TestIsValidUploadKey/nar_zst898=== RUN TestProxyWriteTimeout/1_GiB_nar899=== PAUSE TestProxyWriteTimeout/1_GiB_nar900=== PAUSE TestIsValidUploadKey/nar_zst901=== RUN TestIsValidUploadKey/nar_xz902=== RUN TestProxyWriteTimeout/10_GiB_nar903=== PAUSE TestProxyWriteTimeout/10_GiB_nar904=== PAUSE TestIsValidUploadKey/nar_xz905=== RUN TestProxyWriteTimeout/unknown_size906=== RUN TestIsValidUploadKey/nar_plain907=== PAUSE TestProxyWriteTimeout/unknown_size908=== PAUSE TestIsValidUploadKey/nar_plain909=== RUN TestIsValidUploadKey/listing910=== CONT TestGCMetrics911=== PAUSE TestIsValidUploadKey/listing912=== RUN TestIsValidUploadKey/build_log9132026/10/29 01:21:04 INFO Shutdown signal received, draining in-flight requests timeout=10s914=== PAUSE TestIsValidUploadKey/build_log915=== RUN TestIsValidUploadKey/build_log_home-manager_file916=== PAUSE TestIsValidUploadKey/build_log_home-manager_file917=== RUN TestIsValidUploadKey/build_log_plus_in_name918=== PAUSE TestIsValidUploadKey/build_log_plus_in_name919=== RUN TestIsValidUploadKey/build_log_question_mark920=== PAUSE TestIsValidUploadKey/build_log_question_mark921=== RUN TestIsValidUploadKey/build_log_equals922=== PAUSE TestIsValidUploadKey/build_log_equals923=== RUN TestIsValidUploadKey/realisation924=== PAUSE TestIsValidUploadKey/realisation925=== RUN TestIsValidUploadKey/realisation_plus_in_output926=== PAUSE TestIsValidUploadKey/realisation_plus_in_output927=== RUN TestIsValidUploadKey/nix-cache-info928=== PAUSE TestIsValidUploadKey/nix-cache-info929=== RUN TestIsValidUploadKey/index.html930=== PAUSE TestIsValidUploadKey/index.html931=== RUN TestIsValidUploadKey/narinfo_key,_nar_type932=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type933=== RUN TestIsValidUploadKey/nar_key,_narinfo_type934=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type935=== RUN TestIsValidUploadKey/listing_key,_narinfo_type936=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type937=== RUN TestIsValidUploadKey/traversal938=== PAUSE TestIsValidUploadKey/traversal939=== RUN TestIsValidUploadKey/traversal_nar940=== PAUSE TestIsValidUploadKey/traversal_nar941=== RUN TestIsValidUploadKey/absolute942=== PAUSE TestIsValidUploadKey/absolute943=== RUN TestIsValidUploadKey/empty_key944=== PAUSE TestIsValidUploadKey/empty_key945=== RUN TestIsValidUploadKey/unknown_type946=== PAUSE TestIsValidUploadKey/unknown_type947=== CONT TestPushDedupSurvivesConcurrentGC948--- PASS: TestGracefulShutdownDrainsInflight (0.08s)949=== CONT TestGCBugBareHashReferences950=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure951=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure952=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart953=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart954=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts955=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts956=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit9572026/10/29 01:21:05 INFO Received uploads request method=POST path=/api/pending_closures9582026/10/29 01:21:05 INFO lead: acquired remote=192.0.2.1:12349592026/10/29 01:21:05 INFO Aborted multipart uploads count=0 kept=09602026/10/29 01:21:05 WARN Force mode enabled - objects will be deleted immediately without grace period9612026/10/29 01:21:05 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=09622026/10/29 01:21:05 INFO Vacuumed table table=pending_closures9632026/10/29 01:21:05 INFO Vacuumed table table=pending_objects9642026/10/29 01:21:05 INFO Vacuumed table table=multipart_uploads9652026/10/29 01:21:05 INFO Vacuumed table table=closures9662026/10/29 01:21:05 INFO Vacuumed table table=objects9672026/10/29 01:21:05 INFO Received push request method=POST path=/api/pushes968--- PASS: TestGCSweepSkipsPendingObjects (0.97s)969=== CONT TestPush_CompleteWaitsForCleanupOfThePush9702026/10/29 01:21:05 INFO Received uploads request method=POST path=/api/pending_closures9712026/10/29 01:21:05 INFO Received uploads request method=POST path=/api/pending_closures9722026/10/29 01:21:05 INFO Received uploads request method=POST path=/api/pending_closures9732026/10/29 01:21:06 INFO Received push request method=POST path=/api/pushes9742026/10/29 01:21:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9752026/10/29 01:21:06 INFO Signed narinfos id=1 count=19762026/10/29 01:21:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9772026/10/29 01:21:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9782026/10/29 01:21:06 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9792026/10/29 01:21:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9802026/10/29 01:21:06 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9812026/10/29 01:21:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9822026/10/29 01:21:06 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19832026/10/29 01:21:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9842026/10/29 01:21:06 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo985--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.72s)986=== CONT TestClientIntegration9872026/10/29 01:21:06 INFO lead: released remote=192.0.2.1:12349882026/10/29 01:21:06 INFO lead: acquired remote=192.0.2.1:12349892026/10/29 01:21:06 INFO Received uploads request method=POST path=/api/pending_closures9902026/10/29 01:21:07 INFO Received uploads request method=POST path=/api/pending_closures9912026/10/29 01:21:07 INFO Received uploads request method=POST path=/api/pending_closures9922026/10/29 01:21:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9932026/10/29 01:21:07 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLjM3N2M2YTgwLWE2NTgtNDA1MC1iZTVlLTExMTJiZWY2MmE5NHgxNzkzMjM2ODY1NTEyNzc3MDAw parts=109942026/10/29 01:21:07 INFO Received uploads request method=POST path=/api/pending_closures995--- PASS: TestTombstonedObjectOfferedWithoutWaiting (2.96s)996=== CONT TestPush_CompleteCommitsEveryRoot9972026/10/29 01:21:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9982026/10/29 01:21:07 INFO lead: released remote=192.0.2.1:1234999--- PASS: TestLeadElectsOneAndHandsOver (3.10s)1000=== CONT TestReadProxyRangeRequest10012026/10/29 01:21:07 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLmU1NjJlZmI4LTU1MzktNDY4NS04Y2JmLTgwYmY5YzkwM2RiNXgxNzkzMjM2ODY1ODM4MTEyMDAw parts=1010022026/10/29 01:21:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10032026/10/29 01:21:07 INFO Completed upload id=1 objects=2 duration=16.716ms10042026/10/29 01:21:07 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010052026/10/29 01:21:07 INFO Received uploads request method=POST path=/api/pending_closures10062026/10/29 01:21:07 INFO Starting cleanup of old closures method=DELETE path=/api/closures10072026/10/29 01:21:07 INFO Aborted multipart uploads count=0 kept=010082026/10/29 01:21:07 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=010092026/10/29 01:21:07 INFO Received uploads request method=POST path=/api/pending_closures10102026/10/29 01:21:07 INFO Vacuumed table table=pending_closures10112026/10/29 01:21:07 INFO Vacuumed table table=pending_objects10122026/10/29 01:21:07 INFO Vacuumed table table=multipart_uploads1013--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (3.39s)1014=== CONT TestReadRedirectKeepsNarinfoProxied10152026/10/29 01:21:07 INFO Vacuumed table table=closures10162026/10/29 01:21:07 INFO Vacuumed table table=objects10172026/10/29 01:21:07 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001018--- PASS: TestService_createPendingClosureHandler (3.45s)1019=== CONT TestLeadIncumbentAnnouncesAtOnce10202026/10/29 01:21:08 INFO Aborted multipart uploads count=0 kept=010212026/10/29 01:21:08 WARN Force mode enabled - objects will be deleted immediately without grace period10222026/10/29 01:21:08 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=010232026/10/29 01:21:08 INFO Vacuumed table table=pending_closures10242026/10/29 01:21:08 INFO Vacuumed table table=pending_objects10252026/10/29 01:21:08 INFO Vacuumed table table=multipart_uploads10262026/10/29 01:21:08 INFO Vacuumed table table=closures10272026/10/29 01:21:08 INFO Vacuumed table table=objects10282026/10/29 01:21:08 INFO Aborted multipart uploads count=0 kept=010292026/10/29 01:21:08 WARN Force mode enabled - objects will be deleted immediately without grace period10302026/10/29 01:21:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10312026/10/29 01:21:08 INFO lead: acquired remote=192.0.2.1:123410322026/10/29 01:21:08 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLmZmYmNlMzBjLTIxZWEtNDZjMS1hMjMzLWJkMDY5ZmU2ODk0YXgxNzkzMjM2ODY2NzE1MzM2MDAw parts=1010332026/10/29 01:21:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10342026/10/29 01:21:08 INFO Completed upload id=1 objects=2 duration=19.153792ms10352026/10/29 01:21:08 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=010362026/10/29 01:21:08 INFO Vacuumed table table=pending_closures10372026/10/29 01:21:08 INFO Vacuumed table table=pending_objects10382026/10/29 01:21:08 INFO Vacuumed table table=multipart_uploads10392026/10/29 01:21:08 INFO Vacuumed table table=closures10402026/10/29 01:21:08 INFO Vacuumed table table=objects1041--- PASS: TestSweepSkipsRowsLockedByPush (4.12s)1042=== CONT TestReadRedirectNar10432026/10/29 01:21:08 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1044--- PASS: TestService_AuthMiddleware (4.25s)1045=== CONT TestReadRedirectUsesPublicS3URL10462026/10/29 01:21:08 INFO Received uploads request method=POST path=/api/pending_closures10472026/10/29 01:21:08 INFO Received uploads request method=POST path=/api/pending_closures10482026/10/29 01:21:08 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10492026/10/29 01:21:08 WARN Found objects in DB but missing from S3, will re-upload count=110502026/10/29 01:21:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10512026/10/29 01:21:08 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete10522026/10/29 01:21:08 INFO Completed upload id=3 objects=2 duration=916.5µs1053--- PASS: TestService_verifyS3Integrity (4.40s)1054=== CONT TestReadProxyRootRedirectsToIndexHTML10552026/10/29 01:21:08 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLjA5YmMyOWYwLTUzM2YtNDE0Mi04NzgxLWM1YzdlNWVhODJkMXgxNzkzMjM2ODY1NTEyNzc3MDAw parts=1010562026/10/29 01:21:08 INFO Received complete push request method=POST path=/api/pushes/1/complete10572026/10/29 01:21:08 INFO Completed push id=1 objects=4 duration=25.38075ms1058--- PASS: TestPush_RepeatedRootCommitsOnce (4.50s)1059=== CONT TestReadProxyConditionalGet10602026/10/29 01:21:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10612026/10/29 01:21:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10622026/10/29 01:21:09 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1063--- PASS: TestCompleteMultipartUnregistered (4.57s)1064=== CONT TestConnectSerialisesConcurrentMigrations10652026/10/29 01:21:09 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLmM0MGJjM2JkLWU0ZTAtNDZkMC1iY2E1LTE3YjBkNGJmNGUzZXgxNzkzMjM2ODY3MDc3NTMwMDAw parts=1210662026/10/29 01:21:09 INFO Received uploads request method=POST path=/api/pending_closures10672026/10/29 01:21:09 INFO Received uploads request method=POST path=/api/pending_closures1068=== RUN TestPush_RejectsBadRequests/no_roots1069=== PAUSE TestPush_RejectsBadRequests/no_roots1070=== RUN TestPush_RejectsBadRequests/no_objects1071=== PAUSE TestPush_RejectsBadRequests/no_objects1072=== RUN TestPush_RejectsBadRequests/bad_root1073=== PAUSE TestPush_RejectsBadRequests/bad_root1074=== RUN TestPush_RejectsBadRequests/root_not_in_objects1075=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1076=== CONT TestReadProxyOutlastsServerWriteTimeout10772026/10/29 01:21:09 INFO lead: released remote=192.0.2.1:12341078=== CONT TestReadProxyDisabled1079--- PASS: TestLeadEndsOnShutdown (5.01s)10802026/10/29 01:21:09 INFO Aborted multipart uploads count=0 kept=010812026/10/29 01:21:09 WARN Force mode enabled - objects will be deleted immediately without grace period10822026/10/29 01:21:09 INFO Received push request method=POST path=/api/pushes10832026/10/29 01:21:10 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=010842026/10/29 01:21:10 INFO Vacuumed table table=pending_closures10852026/10/29 01:21:10 INFO Vacuumed table table=pending_objects10862026/10/29 01:21:10 INFO Vacuumed table table=multipart_uploads10872026/10/29 01:21:10 INFO Vacuumed table table=closures10882026/10/29 01:21:10 INFO Vacuumed table table=objects1089--- PASS: TestGCSweepDeliversEachKeyOnce (6.07s)1090=== CONT TestReadProxyInvalidPath10912026/10/29 01:21:10 INFO Received uploads request method=POST path=/api/pending_closures10922026/10/29 01:21:10 INFO Received uploads request method=POST path=/api/pending_closures10932026/10/29 01:21:10 INFO Aborted multipart uploads count=0 kept=010942026/10/29 01:21:10 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=010952026/10/29 01:21:10 INFO Vacuumed table table=pending_closures10962026/10/29 01:21:10 INFO Vacuumed table table=pending_objects10972026/10/29 01:21:10 INFO Vacuumed table table=multipart_uploads10982026/10/29 01:21:10 INFO Vacuumed table table=closures10992026/10/29 01:21:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11002026/10/29 01:21:10 INFO Vacuumed table table=objects11012026/10/29 01:21:11 INFO Aborted multipart uploads count=0 kept=011022026/10/29 01:21:11 WARN Force mode enabled - objects will be deleted immediately without grace period11032026/10/29 01:21:11 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=01104--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (6.58s)1105=== CONT TestReadProxy404And42911062026/10/29 01:21:11 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLjcyZDQ2MmJmLTE0ZDktNGU0MC1iMGFmLWRiMGI5YTBiNzA2YngxNzkzMjM2ODY5MTIwNTg5MDAw error="Get \"http://127.0.0.1:1/bucket10/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11072026/10/29 01:21:11 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLjVjMTk3ZmI4LTg4YzYtNGRhNC1hYjAwLWUxNGVlODMxMjMxM3gxNzkzMjM2ODY5MDk2NDEyMDAw parts=1211082026/10/29 01:21:11 INFO Vacuumed table table=pending_closures11092026/10/29 01:21:11 INFO Received cleanup request method=DELETE path=/api/pending_closures11102026/10/29 01:21:11 INFO Aborted multipart uploads count=0 kept=011112026/10/29 01:21:11 INFO Vacuumed table table=pending_objects11122026/10/29 01:21:11 INFO Vacuumed table table=multipart_uploads11132026/10/29 01:21:11 INFO Aborted multipart uploads count=1 kept=011142026/10/29 01:21:11 WARN Force mode enabled - objects will be deleted immediately without grace period11152026/10/29 01:21:11 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=011162026/10/29 01:21:11 INFO Vacuumed table table=closures11172026/10/29 01:21:11 INFO Vacuumed table table=objects11182026/10/29 01:21:11 INFO Vacuumed table table=pending_closures11192026/10/29 01:21:11 INFO Vacuumed table table=pending_objects11202026/10/29 01:21:11 INFO Vacuumed table table=multipart_uploads11212026/10/29 01:21:11 INFO Vacuumed table table=closures1122--- PASS: TestPushDedupSurvivesConcurrentGC (6.72s)1123=== CONT TestReadProxyNarStreaming11242026/10/29 01:21:11 INFO Vacuumed table table=objects1125--- PASS: TestGCMetrics (6.76s)1126--- PASS: TestRedundantMultipartUpload (6.78s)1127=== CONT TestReadProxyContentNegotiation1128=== CONT TestReadProxyHead11292026-10-29 01:21:11.388 UTC [43801] ERROR: duplicate key value violates unique constraint "pg_class_relname_nsp_index"11302026-10-29 01:21:11.388 UTC [43801] DETAIL: Key (relname, relnamespace)=(goose_db_version_id_seq, 2200) already exists.11312026-10-29 01:21:11.388 UTC [43801] STATEMENT: CREATE TABLE goose_db_version (1132 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1133 version_id bigint NOT NULL,1134 is_applied boolean NOT NULL,1135 tstamp timestamp NOT NULL DEFAULT now()1136 )11372026/10/29 01:21:11 INFO Received uploads request method=POST path=/api/pending_closures1138--- PASS: TestDeduplicatedObjectsRecordedAsPending (7.03s)1139=== CONT TestReadProxyNarinfoAlreadyDecompressed11402026/10/29 01:21:11 INFO Received push request method=POST path=/api/pushes11412026/10/29 01:21:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1142=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1143--- PASS: TestGCBugBareHashReferences (7.44s)11442026/10/29 01:21:12 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLjE1M2NlNjZmLTQ4OTUtNGU0My1hZGZiLThmYTJlNjA3MDkxM3gxNzkzMjM2ODcwMDM2MjczMDAw parts=1011452026/10/29 01:21:12 INFO Received cleanup request method=DELETE path=/api/pending_closures11462026/10/29 01:21:12 INFO Aborted multipart uploads count=0 kept=011472026/10/29 01:21:12 INFO Received uploads request method=POST path=/api/pending_closures11482026/10/29 01:21:12 INFO Received cleanup request method=DELETE path=/api/pending_closures11492026/10/29 01:21:12 INFO Aborted multipart uploads count=1 kept=011502026/10/29 01:21:12 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11512026-10-29 01:21:12.267 UTC [43729] ERROR: Closure does not exist: id=111522026-10-29 01:21:12.267 UTC [43729] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE11532026-10-29 01:21:12.267 UTC [43729] STATEMENT: -- name: CommitPendingClosure :one1154 SELECT commit_pending_closure($1::bigint)::bigint1155 1156--- PASS: TestService_cleanupPendingClosuresHandler (7.85s)1157=== CONT TestIsValidCachePath1158=== RUN TestIsValidCachePath/narinfo1159=== PAUSE TestIsValidCachePath/narinfo1160=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1161=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1162=== RUN TestIsValidCachePath/nar_zst1163=== PAUSE TestIsValidCachePath/nar_zst1164=== RUN TestIsValidCachePath/nar_xz1165=== PAUSE TestIsValidCachePath/nar_xz1166=== RUN TestIsValidCachePath/nar_bz21167=== PAUSE TestIsValidCachePath/nar_bz21168=== RUN TestIsValidCachePath/nar_uncompressed1169=== PAUSE TestIsValidCachePath/nar_uncompressed1170=== RUN TestIsValidCachePath/ls1171=== PAUSE TestIsValidCachePath/ls1172=== RUN TestIsValidCachePath/log1173=== PAUSE TestIsValidCachePath/log1174=== RUN TestIsValidCachePath/realisation1175=== PAUSE TestIsValidCachePath/realisation1176=== RUN TestIsValidCachePath/nix-cache-info1177=== PAUSE TestIsValidCachePath/nix-cache-info1178=== RUN TestIsValidCachePath/index.html1179=== PAUSE TestIsValidCachePath/index.html1180=== RUN TestIsValidCachePath/traversal_parent1181=== PAUSE TestIsValidCachePath/traversal_parent1182=== RUN TestIsValidCachePath/traversal_in_middle1183=== PAUSE TestIsValidCachePath/traversal_in_middle1184=== RUN TestIsValidCachePath/invalid_char_e1185=== PAUSE TestIsValidCachePath/invalid_char_e1186=== RUN TestIsValidCachePath/invalid_char_u1187=== PAUSE TestIsValidCachePath/invalid_char_u1188=== RUN TestIsValidCachePath/random_path1189=== PAUSE TestIsValidCachePath/random_path1190=== RUN TestIsValidCachePath/empty1191=== PAUSE TestIsValidCachePath/empty1192=== RUN TestIsValidCachePath/leading_slash1193=== PAUSE TestIsValidCachePath/leading_slash1194=== RUN TestIsValidCachePath/wrong_extension1195=== PAUSE TestIsValidCachePath/wrong_extension1196=== RUN TestIsValidCachePath/short_hash1197=== PAUSE TestIsValidCachePath/short_hash1198=== CONT TestReadProxyNarinfo1199--- PASS: TestConnectSerialisesConcurrentMigrations (3.35s)1200=== CONT TestParseSingleRange1201=== RUN TestParseSingleRange/none1202=== PAUSE TestParseSingleRange/none1203=== RUN TestParseSingleRange/unknown_unit1204=== PAUSE TestParseSingleRange/unknown_unit1205=== RUN TestParseSingleRange/multi-range_ignored1206=== PAUSE TestParseSingleRange/multi-range_ignored1207=== RUN TestParseSingleRange/malformed_no_dash1208=== PAUSE TestParseSingleRange/malformed_no_dash1209=== RUN TestParseSingleRange/malformed_both_empty1210=== PAUSE TestParseSingleRange/malformed_both_empty1211=== RUN TestParseSingleRange/malformed_end_before_start1212=== PAUSE TestParseSingleRange/malformed_end_before_start1213=== RUN TestParseSingleRange/closed12142026/10/29 01:21:12 INFO Received push request method=POST path=/api/pushes1215=== PAUSE TestParseSingleRange/closed1216=== RUN TestParseSingleRange/open-ended1217=== PAUSE TestParseSingleRange/open-ended1218=== RUN TestParseSingleRange/end_clamped_to_size1219=== PAUSE TestParseSingleRange/end_clamped_to_size1220=== RUN TestParseSingleRange/suffix1221=== PAUSE TestParseSingleRange/suffix1222=== RUN TestParseSingleRange/suffix_exceeds_size1223=== PAUSE TestParseSingleRange/suffix_exceeds_size1224=== RUN TestParseSingleRange/single_byte1225=== PAUSE TestParseSingleRange/single_byte1226=== RUN TestParseSingleRange/start_past_EOF1227=== PAUSE TestParseSingleRange/start_past_EOF1228=== RUN TestParseSingleRange/start_far_past_EOF1229=== PAUSE TestParseSingleRange/start_far_past_EOF1230=== CONT TestResolveDBConnectionString1231=== RUN TestResolveDBConnectionString/flag_wins1232=== PAUSE TestResolveDBConnectionString/flag_wins1233=== RUN TestResolveDBConnectionString/file_when_flag_empty1234=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1235=== RUN TestResolveDBConnectionString/missing_file_is_an_error1236=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1237=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1238=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1239=== RUN TestResolveDBConnectionString/nothing_configured1240=== PAUSE TestResolveDBConnectionString/nothing_configured1241=== CONT TestPresentNotReportedWhileGCDeletesClosure1242=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1243=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1244=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1245=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1246=== CONT TestDeleteClosuresRacingPins12472026/10/29 01:21:13 INFO Received push request method=POST path=/api/pushes1248=== NAME TestClientIntegration1249 client_integration_test.go:331: Created store path: /private/var/tb/4/scratch/99e362236db6695a/build/TestClientIntegration58090642/002/store/v842p9rycpdj3i42hmc8z48vf2k6cshw-test-file.txt12502026/10/29 01:21:13 INFO Received push request method=POST path=/api/pushes12512026/10/29 01:21:13 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12522026/10/29 01:21:13 INFO Uploading v842p9rycpdj3i42hmc8z48vf2k6cshw-test-file.txt (152B)12532026/10/29 01:21:13 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"1254--- PASS: TestReadProxyRangeRequest (6.05s)1255=== CONT TestPresentReportsOnlyClosureRoots12562026/10/29 01:21:13 WARN Failed to register uploaded object key=v842p9rycpdj3i42hmc8z48vf2k6cshw.ls error="server returned 404: 404 page not found\n"12572026/10/29 01:21:13 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12582026/10/29 01:21:13 INFO Signed narinfos id=1 count=112592026/10/29 01:21:13 INFO Uploading 1 narinfos12602026/10/29 01:21:13 INFO Received complete push request method=POST path=/api/pushes/1/complete12612026/10/29 01:21:13 WARN Failed to register uploaded object key=v842p9rycpdj3i42hmc8z48vf2k6cshw.narinfo error="server returned 404: 404 page not found\n"12622026/10/29 01:21:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12632026/10/29 01:21:13 INFO Completed push id=1 objects=3 duration=44.630625ms12642026/10/29 01:21:13 INFO Upload complete. (337ms)12652026/10/29 01:21:13 INFO All 1 paths already cached1266=== NAME TestClientIntegration1267 client_integration_test.go:357: Retrieved narinfo from S3:1268 StorePath: /private/var/tb/4/scratch/99e362236db6695a/build/TestClientIntegration58090642/002/store/v842p9rycpdj3i42hmc8z48vf2k6cshw-test-file.txt1269 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1270 Compression: zstd1271 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11272 NarSize: 1521273 References: 1274 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11275 client_integration_test.go:358: Retrieved .ls file from S3 (compressed size: 77 bytes)1276 client_integration_test.go:358: Decompressed .ls content (64 bytes):1277 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}12782026/10/29 01:21:13 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLmJmYjY4ZTQwLTgxZGQtNGIxZi1iNDljLWVjOGE2ZjRlOGUzZHgxNzkzMjM2ODcwMDM2MjQyMDAw parts=1012792026/10/29 01:21:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12802026/10/29 01:21:13 INFO lead: acquired remote=192.0.2.1:123412812026/10/29 01:21:13 INFO lead: released remote=192.0.2.1:12341282--- PASS: TestLeadIncumbentAnnouncesAtOnce (6.04s)1283=== CONT TestPresentRefreshesOnlyStaleClosures12842026/10/29 01:21:14 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLjg2MDE1OTNmLWYwNzktNGQ4MS1hM2NiLTY0YmM2YjVlY2JkNHgxNzkzMjM2ODcyMDQ2MjAyMDAw parts=1012852026/10/29 01:21:14 INFO Received push request method=POST path=/api/pushes12862026/10/29 01:21:14 INFO Object in database but missing from S3 key=v842p9rycpdj3i42hmc8z48vf2k6cshw.ls12872026/10/29 01:21:14 WARN Found objects in DB but missing from S3, will re-upload count=112882026/10/29 01:21:14 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12892026/10/29 01:21:14 INFO Received complete push request method=POST path=/api/pushes/2/complete12902026/10/29 01:21:14 WARN Failed to register uploaded object key=v842p9rycpdj3i42hmc8z48vf2k6cshw.ls error="server returned 404: 404 page not found\n"12912026/10/29 01:21:14 INFO Completed push id=2 objects=3 duration=7.263208ms12922026/10/29 01:21:14 INFO Upload complete. (159ms)1293=== NAME TestClientIntegration1294 client_integration_test.go:375: Retrieved .ls file from S3 (compressed size: 62 bytes)1295 client_integration_test.go:375: Decompressed .ls content (49 bytes):1296 {"version":1,"root":{"type":"regular","size":39}}12972026/10/29 01:21:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1298--- PASS: TestReadRedirectKeepsNarinfoProxied (6.66s)1299=== CONT TestClientPushesUseOnePush13002026/10/29 01:21:14 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLjI1N2U3YmUxLWQxODAtNGRiOC1iOWI3LTBhYWEwZGMyYjZhZngxNzkzMjM2ODcyNDg3MzcxMDAw parts=1013012026/10/29 01:21:14 INFO Received push request method=POST path=/api/pushes13022026/10/29 01:21:14 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13032026/10/29 01:21:14 INFO Received complete push request method=POST path=/api/pushes/3/complete13042026/10/29 01:21:14 WARN Failed to register uploaded object key=v842p9rycpdj3i42hmc8z48vf2k6cshw.ls error="server returned 404: 404 page not found\n"13052026/10/29 01:21:14 INFO Completed push id=3 objects=3 duration=1.038041ms13062026/10/29 01:21:14 INFO Upload complete. (150ms)1307=== NAME TestClientIntegration1308 client_integration_test.go:392: Retrieved .ls file from S3 (compressed size: 62 bytes)1309 client_integration_test.go:392: Decompressed .ls content (49 bytes):1310 {"version":1,"root":{"type":"regular","size":39}}13112026-10-29 01:21:14.959 UTC [43840] ERROR: Push does not exist: id=113122026-10-29 01:21:14.959 UTC [43840] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE13132026-10-29 01:21:14.959 UTC [43840] STATEMENT: SELECT commit_push($1)1314--- PASS: TestReadRedirectUsesPublicS3URL (6.24s)1315=== CONT TestPinProtectsFromGC1316--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (9.54s)1317=== CONT TestCreatePinRejectsBadInput13182026/10/29 01:21:15 INFO Received push request method=POST path=/api/pushes13192026/10/29 01:21:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13202026/10/29 01:21:15 INFO Uploading p103jiwy1zrwa0559ylv17bgqqlx7k67-lost-commit.txt (152B)13212026/10/29 01:21:15 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"13222026/10/29 01:21:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13232026/10/29 01:21:15 WARN Failed to register uploaded object key=p103jiwy1zrwa0559ylv17bgqqlx7k67.ls error="server returned 404: 404 page not found\n"13242026/10/29 01:21:15 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign13252026/10/29 01:21:15 INFO Signed narinfos id=4 count=113262026/10/29 01:21:15 INFO Uploading 1 narinfos1327--- PASS: TestReadRedirectNar (6.77s)1328=== CONT TestClientFallsBackToClosures13292026/10/29 01:21:15 INFO Received complete push request method=POST path=/api/pushes/4/complete13302026/10/29 01:21:15 WARN Failed to register uploaded object key=p103jiwy1zrwa0559ylv17bgqqlx7k67.narinfo error="server returned 404: 404 page not found\n"13312026/10/29 01:21:15 INFO Completed push id=4 objects=3 duration=1.379958ms13322026/10/29 01:21:15 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:62131/api/pushes/4/complete\": EOF" url=http://127.0.0.1:62131/api/pushes/4/complete13332026/10/29 01:21:15 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLjRiOTg0ODAzLTA3NDgtNGUyMS05YzYyLTc5YzAzODI5ZDE0NXgxNzkzMjM2ODczMTgwMjQyMDAw parts=1013342026/10/29 01:21:15 INFO Received complete push request method=POST path=/api/pushes/4/complete13352026-10-29 01:21:15.554 UTC [43749] ERROR: Push does not exist: id=413362026-10-29 01:21:15.554 UTC [43749] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE13372026-10-29 01:21:15.554 UTC [43749] STATEMENT: -- name: CommitPush :one1338 SELECT commit_push($1::bigint)::bigint1339 13402026/10/29 01:21:15 WARN Push not found id=413412026/10/29 01:21:15 INFO Upload complete. (407ms)1342=== NAME TestClientIntegration1343 client_integration_test.go:422: Retrieved narinfo from S3:1344 StorePath: /private/var/tb/4/scratch/99e362236db6695a/build/TestClientIntegration58090642/002/store/p103jiwy1zrwa0559ylv17bgqqlx7k67-lost-commit.txt1345 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1346 Compression: zstd1347 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1348 NarSize: 1521349 References: 1350 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1351 client_integration_test.go:425: Testing garbage collection...13522026/10/29 01:21:15 INFO Starting cleanup of old closures method=DELETE path=/api/closures13532026/10/29 01:21:15 INFO Garbage collection started13542026/10/29 01:21:15 INFO Aborted multipart uploads count=0 kept=013552026/10/29 01:21:15 WARN Force mode enabled - objects will be deleted immediately without grace period13562026/10/29 01:21:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1357--- PASS: TestReadProxyRootRedirectsToIndexHTML (6.89s)1358=== CONT TestDeletePinKeepsRowWhenS3Fails13592026/10/29 01:21:15 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLjk0YjkyNjBlLTE3OWEtNGYwZS1hMWYxLTg4Y2YwMTFhMmQ0OXgxNzkzMjM2ODcwMDM2MTUyMDAw parts=1013602026/10/29 01:21:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13612026/10/29 01:21:16 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLjQ0Yzg1OGMzLTFiOTUtNGY5Zi1hN2M3LTVjZDc2ZTdlOTE3Y3gxNzkzMjM2ODcyMDQ2NjY1MDAw parts=1013622026/10/29 01:21:16 INFO Received complete push request method=POST path=/api/pushes/1/complete13632026/10/29 01:21:16 INFO Completed push id=1 objects=4 duration=54.717ms13642026/10/29 01:21:16 INFO Received push request method=POST path=/api/pushes13652026/10/29 01:21:16 INFO Aborted multipart uploads count=0 kept=013662026/10/29 01:21:16 WARN Force mode enabled - objects will be deleted immediately without grace period1367=== CONT TestConcurrentPinUpdatesAgree1368--- PASS: TestReadProxyConditionalGet (7.35s)13692026/10/29 01:21:16 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=013702026/10/29 01:21:16 INFO Vacuumed table table=pending_closures13712026/10/29 01:21:16 INFO Vacuumed table table=pending_objects13722026/10/29 01:21:16 INFO Vacuumed table table=multipart_uploads13732026/10/29 01:21:16 INFO Vacuumed table table=closures13742026/10/29 01:21:16 INFO Vacuumed table table=objects13752026/10/29 01:21:17 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=013762026/10/29 01:21:17 INFO Vacuumed table table=pending_closures13772026/10/29 01:21:17 INFO Vacuumed table table=pending_objects13782026/10/29 01:21:17 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld4 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"13792026/10/29 01:21:17 INFO Vacuumed table table=multipart_uploads1380--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (12.71s)1381=== CONT TestClientSharedPathCommittedMidPush13822026/10/29 01:21:17 INFO Vacuumed table table=closures13832026/10/29 01:21:17 INFO Vacuumed table table=objects13842026/10/29 01:21:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1385--- PASS: TestReadProxyDisabled (8.02s)1386=== CONT TestCreatePin_ReservedPins13872026/10/29 01:21:17 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLmRjMTdlY2UxLTc1YjktNDA3MS1iY2E0LTE5NjAzODJiMzE0OHgxNzkzMjM2ODczMTc5OTEzMDAw parts=1013882026/10/29 01:21:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62243/oidc13892026/10/29 01:21:17 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=01390=== NAME TestClientIntegration1391 client_integration_test.go:432: Objects in database after GC:1392 client_integration_test.go:432: Successfully deleted all objects with GC --force1393--- PASS: TestClientIntegration (11.58s)1394=== CONT TestOrphanedObjectsGC1395--- PASS: TestReadProxyInvalidPath (7.30s)1396=== CONT TestClientMultipleUploads13972026/10/29 01:21:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13982026/10/29 01:21:17 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLjk1MjM3Yjk2LTlhYjItNDcxMi1hMTVkLTc1ODY1YzdhODM1MHgxNzkzMjM2ODcwMDM2MTgzMDAw parts=101399--- PASS: TestReadProxyHead (7.49s)1400=== CONT TestPush_OverlappingRootsStoreOneRowPerKey14012026/10/29 01:21:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14022026/10/29 01:21:19 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLjhhMzIyZTdjLTg3ODctNDMxNC1iNGU5LWI2NDM4MDQ2YzEyZHgxNzkzMjM2ODc2MTA2NzE2MDAw parts=1014032026/10/29 01:21:19 INFO Received complete push request method=POST path=/api/pushes/2/complete14042026/10/29 01:21:19 INFO Completed push id=2 objects=4 duration=6.502417ms1405--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (14.52s)1406=== CONT TestReconnectLeavesObjectsUnlocked1407--- PASS: TestReadProxyNarStreaming (7.96s)1408=== CONT TestObjectStatsUpdatedOncePerCommit14092026/10/29 01:21:19 WARN Rate limiter enabled after throttle name=s3-test rate=514102026/10/29 01:21:19 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."14112026/10/29 01:21:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14122026/10/29 01:21:19 WARN Rate limiter backed off name=s3-test rate=514132026/10/29 01:21:19 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."14142026/10/29 01:21:19 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLjc1ODk4NWE5LWQ5NTktNDQwNS1iZDNhLWRlZDVhYmFkNDNlOHgxNzkzMjM2ODczMTgwMjg1MDAw parts=101415--- PASS: TestReadProxy404And429 (8.30s)1416=== CONT TestObjectStatsTrigger14172026/10/29 01:21:19 INFO Received complete push request method=POST path=/api/pushes/1/complete14182026/10/29 01:21:19 INFO Completed push id=1 objects=6 duration=14.602417ms1419--- PASS: TestPush_CompleteCommitsEveryRoot (12.03s)1420=== CONT TestClientWithDependencies14212026/10/29 01:21:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14222026/10/29 01:21:19 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLjhmMTMxYWMwLTRkN2EtNGNhNC1hODRiLTVkYzk2ZjdmMDFiM3gxNzkzMjM2ODcwMDM0Mzk0MDAw parts=101423--- PASS: TestReadProxyContentNegotiation (8.53s)1424=== CONT TestPendingClosureFailureAbortsItsUploads1425--- PASS: TestReadProxyNarinfoAlreadyDecompressed (8.38s)1426=== CONT TestOrphanedObjectsGCStressTest14272026/10/29 01:21:20 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1428--- PASS: TestReadProxyNarinfo (8.48s)1429=== CONT TestClientErrorHandling1430=== RUN TestClientErrorHandling/InvalidStorePath1431=== PAUSE TestClientErrorHandling/InvalidStorePath1432=== RUN TestClientErrorHandling/InvalidAuthToken1433=== PAUSE TestClientErrorHandling/InvalidAuthToken1434=== RUN TestClientErrorHandling/ServerNotAvailable1435=== PAUSE TestClientErrorHandling/ServerNotAvailable1436=== CONT TestClientCADerivations1437--- PASS: TestReadProxyOutlastsServerWriteTimeout (11.93s)1438=== CONT TestPendingClosureFailureTracksEveryUpload1439=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1440=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1441=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1442=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1443=== CONT TestCacheStatsHandler14442026/10/29 01:21:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1445--- PASS: TestPresentReportsOnlyClosureRoots (7.62s)1446=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded14472026/10/29 01:21:21 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLmNmOTdmODkxLTVhYmQtNDExMy05OGE4LTU2NjhmY2I0NDE5NngxNzkzMjM2ODcwMDM3MjE4MDAw parts=1014482026-10-29 01:21:21.427 UTC [43724] ERROR: could not obtain lock on row in relation "closures"14492026-10-29 01:21:21.427 UTC [43724] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14502026-10-29 01:21:21.433 UTC [43724] ERROR: could not obtain lock on row in relation "closures"14512026-10-29 01:21:21.433 UTC [43724] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14522026-10-29 01:21:21.435 UTC [43724] ERROR: could not obtain lock on row in relation "closures"14532026-10-29 01:21:21.435 UTC [43724] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14542026-10-29 01:21:21.438 UTC [43724] ERROR: could not obtain lock on row in relation "closures"14552026-10-29 01:21:21.438 UTC [43724] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14562026-10-29 01:21:21.444 UTC [43724] ERROR: could not obtain lock on row in relation "closures"14572026-10-29 01:21:21.444 UTC [43724] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1458--- PASS: TestPush_RootsAreLockedInByteOrder (17.00s)1459=== CONT TestCacheConfigHandler1460=== RUN TestCacheConfigHandler/full_config,_no_issuer1461=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1462=== RUN TestCacheConfigHandler/no_cache_url_configured1463=== PAUSE TestCacheConfigHandler/no_cache_url_configured1464=== RUN TestCacheConfigHandler/no_signing_keys1465=== PAUSE TestCacheConfigHandler/no_signing_keys1466=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1467=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1468=== CONT TestMultipartCleanup1469--- PASS: TestPresentRefreshesOnlyStaleClosures (7.55s)1470=== CONT TestGCTaskStore_GetEmpty1471=== CONT TestService_ReadScope_PublicByDefault1472--- PASS: TestGCTaskStore_GetEmpty (0.00s)14732026/10/29 01:21:21 INFO Received create pin request method=POST path=/api/pins/deploy14742026/10/29 01:21:21 INFO Received create pin request method=POST path=/api/pins/deploy14752026/10/29 01:21:21 INFO Received create pin request method=POST path=/api/pins/deploy14762026/10/29 01:21:21 INFO Received create pin request method=POST path=/api/pins/deploy14772026/10/29 01:21:21 INFO Received create pin request method=POST path=/api/pins/deploy14782026/10/29 01:21:21 INFO Received create pin request method=POST path=/api/pins/deploy14792026/10/29 01:21:21 INFO Received create pin request method=POST path=/api/pins/deploy14802026/10/29 01:21:21 INFO Received create pin request method=POST path=/api/pins/deploy14812026/10/29 01:21:21 INFO Received create pin request method=POST path=/api/pins/deploy1482--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (10.13s)1483=== CONT TestService_Rustfstest14842026/10/29 01:21:22 INFO Received push request method=POST path=/api/pushes14852026/10/29 01:21:22 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14862026/10/29 01:21:22 INFO Uploading v7w52k0f61l8dzfi66llvsgq77jpq5y1-a (256B)14872026/10/29 01:21:22 INFO Uploading imkn1j967jsgwy35pqcyf1mlllf5cy9a-shared-dep (136B)14882026/10/29 01:21:22 WARN Failed to register uploaded object key=v7w52k0f61l8dzfi66llvsgq77jpq5y1.ls error="server returned 404: 404 page not found\n"14892026/10/29 01:21:22 WARN Failed to register uploaded object key=nar/1ys5pklxs7lnf28b2qcfw9m8x4ivwiclm39js285ypl402xn6imm.nar.zst error="server returned 404: 404 page not found\n"14902026/10/29 01:21:22 WARN Failed to register uploaded object key=ahs364s5a4ljpvk1byjwq2vv1wjcp66i.ls error="server returned 404: 404 page not found\n"14912026/10/29 01:21:22 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14922026/10/29 01:21:22 WARN Failed to register uploaded object key=imkn1j967jsgwy35pqcyf1mlllf5cy9a.ls error="server returned 404: 404 page not found\n"14932026/10/29 01:21:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14942026/10/29 01:21:22 INFO Signed narinfos id=1 count=314952026/10/29 01:21:22 INFO Uploading 3 narinfos14962026/10/29 01:21:22 INFO Received create pin request method=POST path=/api/pins/deploy14972026/10/29 01:21:22 WARN Failed to register uploaded object key=ahs364s5a4ljpvk1byjwq2vv1wjcp66i.narinfo error="server returned 404: 404 page not found\n"14982026/10/29 01:21:22 WARN Failed to register uploaded object key=imkn1j967jsgwy35pqcyf1mlllf5cy9a.narinfo error="server returned 404: 404 page not found\n"14992026/10/29 01:21:22 INFO Received complete push request method=POST path=/api/pushes/1/complete15002026/10/29 01:21:22 WARN Failed to register uploaded object key=v7w52k0f61l8dzfi66llvsgq77jpq5y1.narinfo error="server returned 404: 404 page not found\n"15012026/10/29 01:21:22 INFO Completed push id=1 objects=8 duration=36.026625ms15022026/10/29 01:21:22 INFO Upload complete. (266ms)15032026/10/29 01:21:22 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo1504=== NAME TestClientPushesUseOnePush1505 client_pushes_test.go:97: Retrieved narinfo from S3:1506 StorePath: /private/var/tb/4/scratch/99e362236db6695a/build/TestClientPushesUseOnePush2263355018/001/store/imkn1j967jsgwy35pqcyf1mlllf5cy9a-shared-dep1507 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1508 Compression: zstd1509 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821510 NarSize: 1361511 References: 1512 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1513 client_pushes_test.go:97: Retrieved narinfo from S3:1514 StorePath: /private/var/tb/4/scratch/99e362236db6695a/build/TestClientPushesUseOnePush2263355018/001/store/v7w52k0f61l8dzfi66llvsgq77jpq5y1-a1515 URL: nar/1ys5pklxs7lnf28b2qcfw9m8x4ivwiclm39js285ypl402xn6imm.nar.zst1516 Compression: zstd1517 NarHash: sha256:1ys5pklxs7lnf28b2qcfw9m8x4ivwiclm39js285ypl402xn6imm1518 NarSize: 2561519 References: /private/var/tb/4/scratch/99e362236db6695a/build/TestClientPushesUseOnePush2263355018/001/store/imkn1j967jsgwy35pqcyf1mlllf5cy9a-shared-dep1520 CA: text:sha256:09i8k72brr5niwx91n05n9gpar5k7da36f5b3d57fqaxkcq7rd1n1521 client_pushes_test.go:97: Retrieved narinfo from S3:1522 StorePath: /private/var/tb/4/scratch/99e362236db6695a/build/TestClientPushesUseOnePush2263355018/001/store/ahs364s5a4ljpvk1byjwq2vv1wjcp66i-b1523 URL: nar/1ys5pklxs7lnf28b2qcfw9m8x4ivwiclm39js285ypl402xn6imm.nar.zst1524 Compression: zstd1525 NarHash: sha256:1ys5pklxs7lnf28b2qcfw9m8x4ivwiclm39js285ypl402xn6imm1526 NarSize: 2561527 References: /private/var/tb/4/scratch/99e362236db6695a/build/TestClientPushesUseOnePush2263355018/001/store/imkn1j967jsgwy35pqcyf1mlllf5cy9a-shared-dep1528 CA: text:sha256:09i8k72brr5niwx91n05n9gpar5k7da36f5b3d57fqaxkcq7rd1n1529--- PASS: TestCreatePinRejectsBadInput (7.38s)1530=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1531--- PASS: TestClientPushesUseOnePush (7.90s)1532=== CONT TestGCTaskStore_StartNew1533=== NAME TestPinProtectsFromGC1534 client_integration_test.go:854: Pinned store path: /private/var/tb/4/scratch/99e362236db6695a/build/TestPinProtectsFromGC1873272396/001/store/20iqxjlvgk7jkl2h3mz7lx6rc6wv96rb-pinned-file.txt1535 client_integration_test.go:855: Unpinned store path: /private/var/tb/4/scratch/99e362236db6695a/build/TestPinProtectsFromGC1873272396/001/store/mrmvz924f9f7m4v47k5jc1mkcf60x5qz-unpinned-file.txt1536--- PASS: TestGCTaskStore_StartNew (0.00s)1537=== CONT TestParseSize1538--- PASS: TestParseSize (0.00s)1539=== CONT TestPendingCleanupUsesOneCutoff15402026/10/29 01:21:22 INFO Received push request method=POST path=/api/pushes15412026/10/29 01:21:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15422026/10/29 01:21:22 INFO Uploading 20iqxjlvgk7jkl2h3mz7lx6rc6wv96rb-pinned-file.txt (128B)15432026/10/29 01:21:22 WARN Failed to register uploaded object key=20iqxjlvgk7jkl2h3mz7lx6rc6wv96rb.ls error="server returned 404: 404 page not found\n"15442026/10/29 01:21:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15452026/10/29 01:21:22 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15462026/10/29 01:21:22 INFO Signed narinfos id=1 count=115472026/10/29 01:21:22 INFO Received create pin request method=POST path=/api/pins/app15482026/10/29 01:21:22 INFO Uploading 1 narinfos15492026/10/29 01:21:22 INFO Received complete push request method=POST path=/api/pushes/1/complete15502026/10/29 01:21:22 WARN Failed to register uploaded object key=20iqxjlvgk7jkl2h3mz7lx6rc6wv96rb.narinfo error="server returned 404: 404 page not found\n"15512026/10/29 01:21:22 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo15522026/10/29 01:21:22 INFO Received delete pin request method=DELETE path=/api/pins/app15532026/10/29 01:21:22 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket56/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"15542026/10/29 01:21:22 INFO Completed push id=1 objects=3 duration=25.541833ms15552026/10/29 01:21:22 INFO Upload complete. (195ms)15562026/10/29 01:21:22 INFO Received delete pin request method=DELETE path=/api/pins/app15572026/10/29 01:21:22 INFO Received push request method=POST path=/api/pushes15582026/10/29 01:21:22 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15592026/10/29 01:21:22 INFO Uploading mrmvz924f9f7m4v47k5jc1mkcf60x5qz-unpinned-file.txt (128B)15602026/10/29 01:21:22 INFO Received uploads request method=POST path=/api/pending_closures15612026/10/29 01:21:22 INFO Received uploads request method=POST path=/api/pending_closures15622026/10/29 01:21:22 WARN Failed to register uploaded object key=mrmvz924f9f7m4v47k5jc1mkcf60x5qz.ls error="server returned 404: 404 page not found\n"15632026/10/29 01:21:22 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15642026/10/29 01:21:22 INFO Uploading diyjj69w6kc4sfh5kw72p6w594xfwlg4-b (256B)15652026/10/29 01:21:22 INFO Uploading h7ywjd67s33n8rki44b6w102s9l25kbv-shared-dep (136B)15662026/10/29 01:21:22 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15672026/10/29 01:21:22 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15682026/10/29 01:21:22 INFO Signed narinfos id=2 count=115692026/10/29 01:21:22 INFO Uploading 1 narinfos15702026/10/29 01:21:22 WARN Failed to register uploaded object key=j6ihai8v69hwhhiql3iipk0dwzvyssdm.ls error="server returned 404: 404 page not found\n"15712026/10/29 01:21:22 INFO Deleted pin name=app15722026/10/29 01:21:22 INFO Received create pin request method=POST path=/api/pins/app15732026/10/29 01:21:22 WARN Failed to register uploaded object key=diyjj69w6kc4sfh5kw72p6w594xfwlg4.ls error="server returned 404: 404 page not found\n"15742026/10/29 01:21:22 WARN Failed to register uploaded object key=h7ywjd67s33n8rki44b6w102s9l25kbv.ls error="server returned 404: 404 page not found\n"15752026/10/29 01:21:22 WARN Failed to register uploaded object key=nar/09p7mgmhsvhdqjmq6wnjpq0qdxizpylcn9szn96iyr56kcmrxmic.nar.zst error="server returned 404: 404 page not found\n"15762026/10/29 01:21:22 INFO Received complete push request method=POST path=/api/pushes/2/complete15772026/10/29 01:21:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1578--- PASS: TestDeletePinKeepsRowWhenS3Fails (7.13s)1579=== CONT TestServerTLSConfig1580=== RUN TestServerTLSConfig/no_client_CA15812026/10/29 01:21:22 WARN Failed to register uploaded object key=mrmvz924f9f7m4v47k5jc1mkcf60x5qz.narinfo error="server returned 404: 404 page not found\n"15822026/10/29 01:21:22 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1583=== PAUSE TestServerTLSConfig/no_client_CA1584=== RUN TestServerTLSConfig/missing_CA_file1585=== PAUSE TestServerTLSConfig/missing_CA_file1586=== RUN TestServerTLSConfig/not_a_PEM_file1587=== PAUSE TestServerTLSConfig/not_a_PEM_file15882026/10/29 01:21:22 INFO Completed push id=2 objects=3 duration=615.917µs1589=== CONT TestGCEndsOnShutdown1590=== RUN TestGCEndsOnShutdown/before_the_run1591=== PAUSE TestGCEndsOnShutdown/before_the_run1592=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete15932026/10/29 01:21:22 INFO Signed narinfos id=1 count=21594=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1595=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark15962026/10/29 01:21:22 INFO Upload complete. (206ms)1597=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1598=== CONT TestService_NativeMTLS15992026/10/29 01:21:22 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16002026/10/29 01:21:22 INFO Signed narinfos id=2 count=216012026/10/29 01:21:22 INFO Uploading 4 narinfos16022026/10/29 01:21:22 INFO Received create pin request method=POST path=/api/pins/app16032026/10/29 01:21:22 INFO Starting cleanup of old closures method=DELETE path=/api/closures16042026/10/29 01:21:22 INFO Garbage collection started16052026/10/29 01:21:22 INFO Aborted multipart uploads count=0 kept=016062026/10/29 01:21:22 WARN Failed to register uploaded object key=h7ywjd67s33n8rki44b6w102s9l25kbv.narinfo error="server returned 404: 404 page not found\n"16072026/10/29 01:21:22 WARN Failed to register uploaded object key=diyjj69w6kc4sfh5kw72p6w594xfwlg4.narinfo error="server returned 404: 404 page not found\n"16082026/10/29 01:21:22 WARN Force mode enabled - objects will be deleted immediately without grace period16092026/10/29 01:21:22 WARN Failed to register uploaded object key=j6ihai8v69hwhhiql3iipk0dwzvyssdm.narinfo error="server returned 404: 404 page not found\n"16102026/10/29 01:21:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16112026/10/29 01:21:23 WARN Failed to register uploaded object key=h7ywjd67s33n8rki44b6w102s9l25kbv.narinfo error="server returned 404: 404 page not found\n"16122026/10/29 01:21:23 INFO Completed upload id=1 objects=6 duration=27.260583ms16132026/10/29 01:21:23 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16142026/10/29 01:21:23 INFO Completed upload id=2 objects=6 duration=570.958µs16152026/10/29 01:21:23 INFO Upload complete. (349ms)1616=== NAME TestClientFallsBackToClosures1617 client_pushes_test.go:112: Retrieved narinfo from S3:1618 StorePath: /private/var/tb/4/scratch/99e362236db6695a/build/TestClientFallsBackToClosures2657328651/001/store/h7ywjd67s33n8rki44b6w102s9l25kbv-shared-dep1619 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1620 Compression: zstd1621 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821622 NarSize: 1361623 References: 1624 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1625 client_pushes_test.go:112: Retrieved narinfo from S3:1626 StorePath: /private/var/tb/4/scratch/99e362236db6695a/build/TestClientFallsBackToClosures2657328651/001/store/j6ihai8v69hwhhiql3iipk0dwzvyssdm-a1627 URL: nar/09p7mgmhsvhdqjmq6wnjpq0qdxizpylcn9szn96iyr56kcmrxmic.nar.zst1628 Compression: zstd1629 NarHash: sha256:09p7mgmhsvhdqjmq6wnjpq0qdxizpylcn9szn96iyr56kcmrxmic1630 NarSize: 2561631 References: /private/var/tb/4/scratch/99e362236db6695a/build/TestClientFallsBackToClosures2657328651/001/store/h7ywjd67s33n8rki44b6w102s9l25kbv-shared-dep1632 CA: text:sha256:0mnb8s3kd3lpf720n3j6y2qhwyhicxy2xw0kl6qiz4n9wlrbwf3i1633 client_pushes_test.go:112: Retrieved narinfo from S3:1634 StorePath: /private/var/tb/4/scratch/99e362236db6695a/build/TestClientFallsBackToClosures2657328651/001/store/diyjj69w6kc4sfh5kw72p6w594xfwlg4-b1635 URL: nar/09p7mgmhsvhdqjmq6wnjpq0qdxizpylcn9szn96iyr56kcmrxmic.nar.zst1636 Compression: zstd1637 NarHash: sha256:09p7mgmhsvhdqjmq6wnjpq0qdxizpylcn9szn96iyr56kcmrxmic1638 NarSize: 2561639 References: /private/var/tb/4/scratch/99e362236db6695a/build/TestClientFallsBackToClosures2657328651/001/store/h7ywjd67s33n8rki44b6w102s9l25kbv-shared-dep1640 CA: text:sha256:0mnb8s3kd3lpf720n3j6y2qhwyhicxy2xw0kl6qiz4n9wlrbwf3i1641=== CONT TestRegisterCompletedObjectNeedsPendingRow1642--- PASS: TestClientFallsBackToClosures (7.85s)16432026/10/29 01:21:23 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=016442026/10/29 01:21:23 INFO Vacuumed table table=pending_closures16452026/10/29 01:21:23 INFO Vacuumed table table=pending_objects16462026/10/29 01:21:23 INFO Vacuumed table table=multipart_uploads16472026/10/29 01:21:23 INFO Vacuumed table table=closures16482026/10/29 01:21:23 INFO Vacuumed table table=objects16492026/10/29 01:21:23 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux16502026/10/29 01:21:23 WARN Refused reserved pin name=worker-x86_64-linux16512026/10/29 01:21:23 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux16522026/10/29 01:21:23 INFO Received create pin request method=POST path=/api/pins/my-app16532026/10/29 01:21:23 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1654--- PASS: TestCreatePin_ReservedPins (5.93s)1655=== CONT TestGetExistingObjectsLocksRows16562026/10/29 01:21:23 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo16572026/10/29 01:21:23 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo1658--- PASS: TestConcurrentPinUpdatesAgree (7.19s)1659=== CONT TestMetricsInventory16602026/10/29 01:21:23 INFO Received push request method=POST path=/api/pushes16612026/10/29 01:21:23 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16622026/10/29 01:21:23 INFO Uploading s2dgp7r5hq4l7mxwvrcn82mclih1m8km-top (264B)16632026/10/29 01:21:23 INFO Uploading sga9lbhlldk71aidl4nnc4hr1qjrsrjz-shared-dep (136B)16642026/10/29 01:21:23 WARN Failed to register uploaded object key=s2dgp7r5hq4l7mxwvrcn82mclih1m8km.ls error="server returned 404: 404 page not found\n"16652026/10/29 01:21:23 WARN Failed to register uploaded object key=nar/0vn4s83l4lw9grmks6sq1zmlnm9s9lcqcrlj97i6z6wpw6qbjbqg.nar.zst error="server returned 404: 404 page not found\n"16662026/10/29 01:21:23 WARN Failed to register uploaded object key=sga9lbhlldk71aidl4nnc4hr1qjrsrjz.ls error="server returned 404: 404 page not found\n"16672026/10/29 01:21:23 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16682026/10/29 01:21:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16692026/10/29 01:21:23 INFO Signed narinfos id=1 count=216702026/10/29 01:21:23 INFO Uploading 2 narinfos16712026/10/29 01:21:23 WARN Failed to register uploaded object key=sga9lbhlldk71aidl4nnc4hr1qjrsrjz.narinfo error="server returned 404: 404 page not found\n"16722026/10/29 01:21:23 INFO Received complete push request method=POST path=/api/pushes/1/complete16732026/10/29 01:21:23 WARN Failed to register uploaded object key=s2dgp7r5hq4l7mxwvrcn82mclih1m8km.narinfo error="server returned 404: 404 page not found\n"16742026/10/29 01:21:23 INFO Completed push id=1 objects=6 duration=25.705708ms16752026/10/29 01:21:23 INFO Upload complete. (271ms)1676=== NAME TestClientSharedPathCommittedMidPush1677 client_integration_test.go:803: Retrieved narinfo from S3:1678 StorePath: /private/var/tb/4/scratch/99e362236db6695a/build/TestClientSharedPathCommittedMidPush3708690721/001/store/sga9lbhlldk71aidl4nnc4hr1qjrsrjz-shared-dep1679 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1680 Compression: zstd1681 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821682 NarSize: 1361683 References: 1684 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1685 client_integration_test.go:803: Retrieved narinfo from S3:1686 StorePath: /private/var/tb/4/scratch/99e362236db6695a/build/TestClientSharedPathCommittedMidPush3708690721/001/store/s2dgp7r5hq4l7mxwvrcn82mclih1m8km-top1687 URL: nar/0vn4s83l4lw9grmks6sq1zmlnm9s9lcqcrlj97i6z6wpw6qbjbqg.nar.zst1688 Compression: zstd1689 NarHash: sha256:0vn4s83l4lw9grmks6sq1zmlnm9s9lcqcrlj97i6z6wpw6qbjbqg1690 NarSize: 2641691 References: /private/var/tb/4/scratch/99e362236db6695a/build/TestClientSharedPathCommittedMidPush3708690721/001/store/sga9lbhlldk71aidl4nnc4hr1qjrsrjz-shared-dep1692 CA: text:sha256:1d6vpidw2jg40cnb90f2ck805n32m4hxaicyq8l0chphngymzx1a1693--- PASS: TestClientSharedPathCommittedMidPush (6.62s)1694=== CONT TestGCTaskStore_DeduplicateSameParams1695--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1696=== CONT TestCommitRacingPendingCleanupKeepsObjects1697--- PASS: TestDeleteClosuresRacingPins (11.50s)1698=== CONT TestFailedS3DeleteKeepsTombstone1699=== NAME TestClientMultipleUploads1700 client_integration_test.go:467: Created store path 0: /private/var/tb/4/scratch/99e362236db6695a/build/TestClientMultipleUploads2842530315/001/store/2p6xs5jqxrizi85a5vxsh9vi5hhqswpd-test-file-0.txt1701 client_integration_test.go:467: Created store path 1: /private/var/tb/4/scratch/99e362236db6695a/build/TestClientMultipleUploads2842530315/001/store/qf9wf9w7dwsz4pii16y4lckmvyrw60i9-test-file-1.txt17022026/10/29 01:21:24 INFO Received push request method=POST path=/api/pushes1703 client_integration_test.go:467: Created store path 2: /private/var/tb/4/scratch/99e362236db6695a/build/TestClientMultipleUploads2842530315/001/store/sbgmjpws3kqlsd5d2v73xz0hvaamli05-test-file-2.txt1704--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (5.46s)1705=== CONT TestMetricsCommit17062026/10/29 01:21:24 INFO Received push request method=POST path=/api/pushes17072026/10/29 01:21:24 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)17082026/10/29 01:21:24 INFO Uploading 2p6xs5jqxrizi85a5vxsh9vi5hhqswpd-test-file-0.txt (160B)17092026/10/29 01:21:24 INFO Uploading sbgmjpws3kqlsd5d2v73xz0hvaamli05-test-file-2.txt (160B)17102026/10/29 01:21:24 INFO Uploading qf9wf9w7dwsz4pii16y4lckmvyrw60i9-test-file-1.txt (160B)17112026/10/29 01:21:24 WARN Failed to register uploaded object key=2p6xs5jqxrizi85a5vxsh9vi5hhqswpd.ls error="server returned 404: 404 page not found\n"17122026/10/29 01:21:24 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"17132026/10/29 01:21:24 WARN Failed to register uploaded object key=qf9wf9w7dwsz4pii16y4lckmvyrw60i9.ls error="server returned 404: 404 page not found\n"17142026/10/29 01:21:24 WARN Failed to register uploaded object key=sbgmjpws3kqlsd5d2v73xz0hvaamli05.ls error="server returned 404: 404 page not found\n"17152026/10/29 01:21:24 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17162026/10/29 01:21:24 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"17172026/10/29 01:21:24 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"17182026/10/29 01:21:24 INFO Signed narinfos id=1 count=317192026/10/29 01:21:24 INFO Uploading 3 narinfos17202026/10/29 01:21:24 WARN Failed to register uploaded object key=qf9wf9w7dwsz4pii16y4lckmvyrw60i9.narinfo error="server returned 404: 404 page not found\n"17212026/10/29 01:21:24 WARN Failed to register uploaded object key=sbgmjpws3kqlsd5d2v73xz0hvaamli05.narinfo error="server returned 404: 404 page not found\n"17222026/10/29 01:21:24 INFO Received complete push request method=POST path=/api/pushes/1/complete17232026/10/29 01:21:24 WARN Failed to register uploaded object key=2p6xs5jqxrizi85a5vxsh9vi5hhqswpd.narinfo error="server returned 404: 404 page not found\n"17242026/10/29 01:21:24 INFO Completed push id=1 objects=9 duration=42.916875ms17252026/10/29 01:21:24 INFO Upload complete. (309ms)1726=== NAME TestClientMultipleUploads1727 client_integration_test.go:478: Uploaded 3 paths in 346.782625ms1728--- PASS: TestObjectStatsTrigger (5.18s)1729=== CONT TestPushWaitsForSweepHoldingRow1730--- PASS: TestClientMultipleUploads (6.81s)1731=== CONT TestCreatePendingClosureRejectsOversizedNAR17322026/10/29 01:21:24 INFO Received uploads request method=POST path=/api/pending_closures1733--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1734=== CONT TestSweepRechecksPendingAfterLocking1735--- PASS: TestReconnectLeavesObjectsUnlocked (5.59s)1736=== CONT TestCacheConfigHandlerMaxNarSize1737--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1738=== CONT TestService_RequireScope_OIDC17392026/10/29 01:21:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62469/oidc17402026/10/29 01:21:24 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=017412026/10/29 01:21:24 INFO Received create pin request method=POST path=/api/pins/myapp17422026/10/29 01:21:25 INFO Created/updated pin name=myapp store_path=/private/var/tb/4/scratch/99e362236db6695a/build/TestPinProtectsFromGC1873272396/001/store/20iqxjlvgk7jkl2h3mz7lx6rc6wv96rb-pinned-file.txt narinfo_key=20iqxjlvgk7jkl2h3mz7lx6rc6wv96rb.narinfo17432026/10/29 01:21:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures17442026/10/29 01:21:25 INFO Garbage collection started17452026/10/29 01:21:25 INFO Aborted multipart uploads count=0 kept=017462026/10/29 01:21:25 WARN Force mode enabled - objects will be deleted immediately without grace period17472026/10/29 01:21:25 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=017482026/10/29 01:21:25 INFO Vacuumed table table=pending_closures17492026/10/29 01:21:25 INFO Vacuumed table table=pending_objects17502026/10/29 01:21:25 INFO Vacuumed table table=multipart_uploads17512026/10/29 01:21:25 INFO Vacuumed table table=closures17522026/10/29 01:21:25 INFO Vacuumed table table=objects1753--- PASS: TestObjectStatsUpdatedOncePerCommit (6.18s)1754=== CONT TestChildrenInheritRaisedFileLimit1755=== CONT TestService_AuthMiddleware_OIDC1756--- PASS: TestChildrenInheritRaisedFileLimit (0.03s)1757=== NAME TestOrphanedObjectsGC1758 orphaned_objects_gc_test.go:287: GC Test Summary:1759 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1760 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1761 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1762 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1763 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects17642026/10/29 01:21:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62477/oidc1765--- PASS: TestOrphanedObjectsGC (7.75s)1766=== CONT TestNARDeduplicationMetadataUploadBug17672026/10/29 01:21:25 INFO Received uploads request method=POST path=/api/pending_closures1768--- PASS: TestPendingClosureFailureAbortsItsUploads (6.02s)1769=== CONT TestGenerateLandingPage1770--- PASS: TestGenerateLandingPage (0.00s)1771=== CONT TestService_ReadAuthMiddleware1772=== NAME TestClientWithDependencies1773 client_integration_test.go:722: Built derivation: /private/var/tb/4/scratch/99e362236db6695a/build/TestClientWithDependencies2578144370/001/store/x2x2nf553kzzcyb1pznvkaa9p7kydp1i-test-script1774 client_integration_test.go:724: Found 1 dependencies (including self)17752026/10/29 01:21:26 INFO Received push request method=POST path=/api/pushes17762026/10/29 01:21:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17772026/10/29 01:21:26 INFO Uploading x2x2nf553kzzcyb1pznvkaa9p7kydp1i-test-script (136B)17782026/10/29 01:21:26 WARN Failed to register uploaded object key=x2x2nf553kzzcyb1pznvkaa9p7kydp1i.ls error="server returned 404: 404 page not found\n"17792026/10/29 01:21:26 WARN Failed to register uploaded object key=log/x9m3iqkqgnk9ml0kyxv8gcjqj2izjzs6-test-script.drv error="server returned 404: 404 page not found\n"17802026/10/29 01:21:26 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"17812026/10/29 01:21:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17822026/10/29 01:21:26 INFO Signed narinfos id=1 count=117832026/10/29 01:21:26 INFO Uploading 1 narinfos17842026/10/29 01:21:26 INFO Received complete push request method=POST path=/api/pushes/1/complete17852026/10/29 01:21:26 WARN Failed to register uploaded object key=x2x2nf553kzzcyb1pznvkaa9p7kydp1i.narinfo error="server returned 404: 404 page not found\n"17862026/10/29 01:21:26 INFO Completed push id=1 objects=4 duration=20.659792ms17872026/10/29 01:21:26 INFO Upload complete. (259ms)17882026/10/29 01:21:26 INFO Aborted multipart uploads count=0 kept=017892026/10/29 01:21:26 WARN Force mode enabled - objects will be deleted immediately without grace period17902026/10/29 01:21:26 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=017912026/10/29 01:21:26 INFO Vacuumed table table=pending_closures17922026/10/29 01:21:26 INFO Vacuumed table table=pending_objects17932026/10/29 01:21:26 INFO Vacuumed table table=multipart_uploads17942026/10/29 01:21:26 INFO Vacuumed table table=closures17952026/10/29 01:21:26 INFO Vacuumed table table=objects1796 client_integration_test.go:740: Skipping nix copy test - isolated store (/private/var/tb/4/scratch/99e362236db6695a/build/TestClientWithDependencies2578144370/001/store) requires matching store prefix1797--- PASS: TestClientWithDependencies (6.95s)1798=== CONT TestSkippedUploadsHandler17992026/10/29 01:21:26 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001800--- PASS: TestSkippedUploadsHandler (0.01s)1801=== CONT TestService_readinessHandler18022026/10/29 01:21:26 INFO Received uploads request method=POST path=/api/pending_closures1803--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (5.27s)1804=== CONT TestService_healthCheckHandler1805=== NAME TestClientCADerivations1806 client_ca_test.go:136: Built CA derivation: /private/var/tb/4/scratch/99e362236db6695a/build/TestClientCADerivations2933004826/001/store/mvgjqk0hpf94ajbg71ymg89h01g1kncw-ca-test1807 client_ca_test.go:139: Found 1 dependencies (including self)1808--- PASS: TestCacheStatsHandler (5.57s)1809=== CONT TestConnectWaitsForAPeerMigration18102026/10/29 01:21:26 INFO Received push request method=POST path=/api/pushes18112026/10/29 01:21:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18122026/10/29 01:21:26 INFO Uploading mvgjqk0hpf94ajbg71ymg89h01g1kncw-ca-test (144B)18132026/10/29 01:21:26 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18142026/10/29 01:21:26 WARN Failed to register uploaded object key=mvgjqk0hpf94ajbg71ymg89h01g1kncw.ls error="server returned 404: 404 page not found\n"18152026/10/29 01:21:26 WARN Failed to register uploaded object key=log/5zh0kng8zsm4w4598dzj5yys7d7y8m61-ca-test.drv error="server returned 404: 404 page not found\n"18162026/10/29 01:21:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18172026/10/29 01:21:26 INFO Signed narinfos id=1 count=118182026/10/29 01:21:26 INFO Uploading 1 narinfos18192026/10/29 01:21:26 INFO Received uploads request method=POST path=/api/pending_closures18202026/10/29 01:21:26 INFO Received complete push request method=POST path=/api/pushes/1/complete18212026/10/29 01:21:26 WARN Failed to register uploaded object key=mvgjqk0hpf94ajbg71ymg89h01g1kncw.narinfo error="server returned 404: 404 page not found\n"18222026/10/29 01:21:27 INFO Completed push id=1 objects=4 duration=24.48525ms18232026/10/29 01:21:27 INFO Upload complete. (339ms)1824=== NAME TestClientCADerivations1825 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/4/scratch/99e362236db6695a/build/TestClientCADerivations2933004826/001/store/mvgjqk0hpf94ajbg71ymg89h01g1kncw-ca-test1826 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1827 Compression: zstd1828 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1829 NarSize: 1441830 References: 1831 Deriver: /private/var/tb/4/scratch/99e362236db6695a/build/TestClientCADerivations2933004826/001/store/5zh0kng8zsm4w4598dzj5yys7d7y8m61-ca-test.drv1832 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1833 client_ca_test.go:185: Checking for realisation files in S3...1834 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1835 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1836=== NAME TestPinProtectsFromGC1837 client_integration_test.go:963: Pin successfully protected closure from garbage collection18382026/10/29 01:21:27 INFO Received cleanup request method=DELETE path=/api/pending_closures18392026/10/29 01:21:27 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket72/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""18402026/10/29 01:21:27 INFO Aborted multipart uploads count=0 kept=11841--- PASS: TestPinProtectsFromGC (12.15s)1842=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1843=== NAME TestClientCADerivations1844 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket69?endpoint=http://localhost:61974®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/4/scratch/99e362236db6695a/build/TestClientCADerivations2933004826/001/store'1845 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 118462026/10/29 01:21:27 INFO Received cleanup request method=DELETE path=/api/pending_closures18472026/10/29 01:21:27 INFO Aborted multipart uploads count=1 kept=01848--- PASS: TestMultipartCleanup (5.73s)1849=== CONT TestPresignedUploadRegisteredBeforeCommit1850--- PASS: TestService_ReadScope_PublicByDefault (5.69s)1851=== CONT TestCompletedNarNotReofferedAcrossClosures1852--- PASS: TestClientCADerivations (6.44s)1853=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1854--- PASS: TestService_Rustfstest (5.36s)1855=== CONT TestService_AuthMiddleware_MTLSProxyHeader18562026/10/29 01:21:27 INFO Received uploads request method=POST path=/api/pending_closures18572026/10/29 01:21:28 INFO Received uploads request method=POST path=/api/pending_closures18582026/10/29 01:21:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18592026/10/29 01:21:28 INFO Received uploads request method=POST path=/api/pending_closures18602026/10/29 01:21:28 INFO Received cleanup request method=DELETE path=/api/pending_closures18612026/10/29 01:21:28 WARN mTLS auth: subject not in bound subjects subject="CN=reader"18622026/10/29 01:21:28 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1863--- PASS: TestService_NativeMTLS (5.45s)1864=== CONT TestUploadHandlersRejectInvalidKeys1865=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1866=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1867=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1868=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1869=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1870=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1871=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1872=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1873=== CONT TestPendingClosureWriteTimeout1874=== RUN TestPendingClosureWriteTimeout/empty1875=== PAUSE TestPendingClosureWriteTimeout/empty1876=== RUN TestPendingClosureWriteTimeout/400_objects1877=== PAUSE TestPendingClosureWriteTimeout/400_objects1878=== RUN TestPendingClosureWriteTimeout/670k_objects1879=== PAUSE TestPendingClosureWriteTimeout/670k_objects1880=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1881=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1882=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1883--- PASS: TestRegisterCompletedObjectNeedsPendingRow (5.43s)1884=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1885--- PASS: TestGetExistingObjectsLocksRows (5.54s)1886=== CONT TestProxyWriteTimeout/1_GiB_nar1887=== CONT TestProxyWriteTimeout/unknown_size1888=== CONT TestProxyWriteTimeout/10_GiB_nar1889=== CONT TestProxyWriteTimeout/narinfo1890=== CONT TestIsValidUploadKey/nar_xz1891--- PASS: TestProxyWriteTimeout (0.01s)1892 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1893 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1894 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1895 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1896=== CONT TestIsValidUploadKey/build_log_equals1897=== CONT TestIsValidUploadKey/realisation_plus_in_output1898=== CONT TestIsValidUploadKey/build_log_question_mark1899=== CONT TestIsValidUploadKey/build_log_home-manager_file1900=== CONT TestIsValidUploadKey/build_log1901=== CONT TestIsValidUploadKey/listing1902=== CONT TestIsValidUploadKey/build_log_plus_in_name1903=== CONT TestIsValidUploadKey/nar_plain1904=== CONT TestIsValidUploadKey/nar_zst1905=== CONT TestIsValidUploadKey/narinfo1906=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1907=== CONT TestIsValidUploadKey/unknown_type1908=== CONT TestIsValidUploadKey/empty_key1909=== CONT TestIsValidUploadKey/traversal_nar1910=== CONT TestIsValidUploadKey/traversal1911=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1912=== CONT TestIsValidUploadKey/absolute1913=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1914=== CONT TestIsValidUploadKey/nix-cache-info1915=== CONT TestIsValidUploadKey/realisation1916=== CONT TestIsValidUploadKey/index.html1917--- PASS: TestIsValidUploadKey (0.03s)1918 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1919 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1920 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1921 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1922 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1923 --- PASS: TestIsValidUploadKey/build_log (0.00s)1924 --- PASS: TestIsValidUploadKey/listing (0.00s)1925 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1926 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1927 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1928 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1929 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1930 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1931 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1932 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1933 --- PASS: TestIsValidUploadKey/traversal (0.00s)1934 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1935 --- PASS: TestIsValidUploadKey/absolute (0.00s)1936 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1937 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1938 --- PASS: TestIsValidUploadKey/realisation (0.00s)1939 --- PASS: TestIsValidUploadKey/index.html (0.00s)1940=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19412026/10/29 01:21:29 INFO Received complete multipart upload request method=POST path=/1942--- PASS: TestMetricsInventory (5.70s)1943=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19442026/10/29 01:21:29 INFO Received request for more parts method=POST path=/1945=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19462026/10/29 01:21:29 INFO Received uploads request method=POST path=/19472026/10/29 01:21:29 INFO Aborted multipart uploads count=0 kept=019482026/10/29 01:21:29 WARN Force mode enabled - objects will be deleted immediately without grace period19492026/10/29 01:21:29 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=01950=== CONT TestPush_RejectsBadRequests/no_roots19512026/10/29 01:21:29 INFO Received push request method=POST path=/api/pushes1952=== CONT TestPush_RejectsBadRequests/root_not_in_objects19532026/10/29 01:21:29 INFO Received push request method=POST path=/api/pushes19542026/10/29 01:21:29 INFO Vacuumed table table=pending_closures1955=== CONT TestPush_RejectsBadRequests/bad_root19562026/10/29 01:21:29 INFO Received push request method=POST path=/api/pushes1957=== CONT TestPush_RejectsBadRequests/no_objects19582026/10/29 01:21:29 INFO Received push request method=POST path=/api/pushes1959=== CONT TestIsValidCachePath/narinfo1960=== CONT TestIsValidCachePath/index.html1961=== CONT TestIsValidCachePath/short_hash1962=== CONT TestIsValidCachePath/leading_slash1963=== CONT TestIsValidCachePath/empty19642026/10/29 01:21:29 INFO Vacuumed table table=pending_objects1965=== CONT TestIsValidCachePath/random_path1966=== CONT TestIsValidCachePath/wrong_extension19672026/10/29 01:21:29 INFO Vacuumed table table=multipart_uploads1968=== CONT TestIsValidCachePath/invalid_char_u1969=== CONT TestIsValidCachePath/traversal_in_middle1970=== CONT TestIsValidCachePath/invalid_char_e1971=== CONT TestIsValidCachePath/traversal_parent1972=== CONT TestIsValidCachePath/nar_bz21973=== CONT TestIsValidCachePath/realisation1974=== CONT TestIsValidCachePath/log1975=== CONT TestIsValidCachePath/nix-cache-info1976=== CONT TestIsValidCachePath/nar_uncompressed1977=== CONT TestIsValidCachePath/nar_zst1978=== CONT TestIsValidCachePath/ls1979=== CONT TestIsValidCachePath/nar_xz1980=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars19812026/10/29 01:21:29 INFO Vacuumed table table=closures1982--- PASS: TestIsValidCachePath (0.01s)1983 --- PASS: TestIsValidCachePath/narinfo (0.00s)1984 --- PASS: TestIsValidCachePath/index.html (0.00s)1985 --- PASS: TestIsValidCachePath/short_hash (0.00s)1986 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1987 --- PASS: TestIsValidCachePath/empty (0.00s)1988 --- PASS: TestIsValidCachePath/random_path (0.00s)1989 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1990 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1991 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1992 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1993 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1994 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1995 --- PASS: TestIsValidCachePath/realisation (0.00s)1996 --- PASS: TestIsValidCachePath/log (0.00s)1997 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1998 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1999 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2000 --- PASS: TestIsValidCachePath/ls (0.00s)2001 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2002 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2003=== CONT TestParseSingleRange/none2004=== CONT TestParseSingleRange/start_far_past_EOF2005=== CONT TestParseSingleRange/single_byte2006=== CONT TestParseSingleRange/start_past_EOF2007=== CONT TestParseSingleRange/malformed_both_empty2008=== CONT TestParseSingleRange/end_clamped_to_size20092026/10/29 01:21:29 INFO Vacuumed table table=objects2010=== CONT TestParseSingleRange/open-ended2011=== CONT TestParseSingleRange/suffix_exceeds_size2012=== CONT TestParseSingleRange/closed2013=== CONT TestParseSingleRange/multi-range_ignored2014=== CONT TestParseSingleRange/malformed_end_before_start2015=== CONT TestParseSingleRange/malformed_no_dash2016=== CONT TestParseSingleRange/unknown_unit2017=== CONT TestParseSingleRange/suffix2018--- PASS: TestParseSingleRange (0.06s)2019 --- PASS: TestParseSingleRange/none (0.00s)2020 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2021 --- PASS: TestParseSingleRange/single_byte (0.00s)2022 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2023 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2024 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2025 --- PASS: TestParseSingleRange/open-ended (0.00s)2026 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2027 --- PASS: TestParseSingleRange/closed (0.00s)2028 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2029 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2030 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2031 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2032 --- PASS: TestParseSingleRange/suffix (0.00s)2033=== CONT TestResolveDBConnectionString/flag_wins2034=== CONT TestResolveDBConnectionString/nothing_configured2035=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2036=== CONT TestResolveDBConnectionString/missing_file_is_an_error2037=== CONT TestResolveDBConnectionString/file_when_flag_empty2038--- PASS: TestCommitRacingPendingCleanupKeepsObjects (5.76s)2039=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh2040--- PASS: TestPush_RejectsBadRequests (4.79s)2041 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2042 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2043 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2044 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)20452026/10/29 01:21:29 INFO Received uploads request method=POST path=/api/pending_closures2046=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale2047--- PASS: TestResolveDBConnectionString (0.04s)2048 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2049 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2050 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2051 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2052 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)20532026/10/29 01:21:29 INFO Aborted multipart uploads count=0 kept=020542026/10/29 01:21:29 WARN Force mode enabled - objects will be deleted immediately without grace period20552026/10/29 01:21:29 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."20562026/10/29 01:21:29 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."2057--- PASS: TestFailedS3DeleteKeepsTombstone (5.81s)2058=== CONT TestClientErrorHandling/InvalidStorePath20592026/10/29 01:21:29 INFO Received push request method=POST path=/api/pushes20602026/10/29 01:21:30 INFO Received uploads request method=POST path=/api/pending_closures20612026/10/29 01:21:30 INFO Aborted multipart uploads count=0 kept=020622026/10/29 01:21:30 WARN Force mode enabled - objects will be deleted immediately without grace period20632026/10/29 01:21:30 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=020642026/10/29 01:21:30 INFO Vacuumed table table=pending_closures20652026/10/29 01:21:30 INFO Vacuumed table table=pending_objects20662026/10/29 01:21:30 INFO Vacuumed table table=multipart_uploads20672026/10/29 01:21:30 INFO Vacuumed table table=closures20682026/10/29 01:21:30 INFO Vacuumed table table=objects2069--- PASS: TestSweepRechecksPendingAfterLocking (5.78s)2070=== CONT TestClientErrorHandling/ServerNotAvailable2071=== RUN TestService_RequireScope_OIDC/builder_may_write2072=== PAUSE TestService_RequireScope_OIDC/builder_may_write2073=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2074=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2075=== RUN TestService_RequireScope_OIDC/ops_may_admin2076=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2077=== RUN TestService_RequireScope_OIDC/ops_may_not_write2078=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2079=== RUN TestService_RequireScope_OIDC/reader_may_not_write2080=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2081=== RUN TestService_RequireScope_OIDC/static_token_may_admin2082=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2083=== RUN TestService_RequireScope_OIDC/static_token_may_write2084=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2085=== RUN TestService_RequireScope_OIDC/reader_may_read2086=== PAUSE TestService_RequireScope_OIDC/reader_may_read2087=== RUN TestService_RequireScope_OIDC/writer_implies_read2088=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2089=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2090=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2091=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc2092=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc2093=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2094=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2095=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2096=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2097=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2098=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2099=== CONT TestClientErrorHandling/InvalidAuthToken2100--- PASS: TestPushWaitsForSweepHoldingRow (6.05s)2101=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false21022026/10/29 01:21:30 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/present2103=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2104=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2105=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2106=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2107=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2108=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2109=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2110=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2111=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true21122026/10/29 01:21:30 WARN Request failed, retrying attempt=2 backoff=208.923324ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21132026/10/29 01:21:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21142026/10/29 01:21:31 WARN Request failed, retrying attempt=3 backoff=383.156253ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21152026/10/29 01:21:31 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLjBlNzI2ZjQwLTkwYjMtNGIyYy1iM2U4LTc2NjM1YmY2NTNkMHgxNzkzMjM2ODg5ODY4MzIwMDAw parts=1021162026/10/29 01:21:31 WARN Request failed, retrying attempt=4 backoff=846.195498ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2117--- PASS: TestService_ReadAuthMiddleware (5.70s)2118=== CONT TestCacheConfigHandler/full_config,_no_issuer2119=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2120=== CONT TestCacheConfigHandler/no_signing_keys2121=== CONT TestCacheConfigHandler/no_cache_url_configured2122=== CONT TestServerTLSConfig/no_client_CA2123--- PASS: TestCacheConfigHandler (0.00s)2124 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2125 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2126 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2127 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2128=== CONT TestServerTLSConfig/not_a_PEM_file2129=== CONT TestServerTLSConfig/missing_CA_file2130--- PASS: TestServerTLSConfig (0.01s)2131 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2132 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.03s)2133 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2134=== CONT TestGCEndsOnShutdown/before_the_run2135=== NAME TestNARDeduplicationMetadataUploadBug2136 metadata_upload_test.go:48: First store path: /private/var/tb/4/scratch/99e362236db6695a/build/TestNARDeduplicationMetadataUploadBug1130270060/001/store/vas9ghdfdwcqcrj043kgy764bncbvyzr-file1.txt21372026/10/29 01:21:31 INFO Received push request method=POST path=/api/pushes21382026/10/29 01:21:31 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21392026/10/29 01:21:31 INFO Uploading vas9ghdfdwcqcrj043kgy764bncbvyzr-file1.txt (160B)21402026/10/29 01:21:31 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"21412026/10/29 01:21:31 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21422026/10/29 01:21:31 WARN Failed to register uploaded object key=vas9ghdfdwcqcrj043kgy764bncbvyzr.ls error="server returned 404: 404 page not found\n"21432026/10/29 01:21:31 INFO Signed narinfos id=1 count=121442026/10/29 01:21:31 INFO Uploading 1 narinfos21452026/10/29 01:21:31 WARN readiness check failed error="closed pool"21462026/10/29 01:21:31 INFO Received complete push request method=POST path=/api/pushes/1/complete21472026/10/29 01:21:31 WARN Failed to register uploaded object key=vas9ghdfdwcqcrj043kgy764bncbvyzr.narinfo error="server returned 404: 404 page not found\n"2148=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark2149--- PASS: TestService_readinessHandler (5.46s)21502026/10/29 01:21:31 INFO Completed push id=1 objects=3 duration=23.078083ms21512026/10/29 01:21:31 INFO Upload complete. (280ms)2152=== NAME TestNARDeduplicationMetadataUploadBug2153 metadata_upload_test.go:54: Retrieved narinfo from S3:2154 StorePath: /private/var/tb/4/scratch/99e362236db6695a/build/TestNARDeduplicationMetadataUploadBug1130270060/001/store/vas9ghdfdwcqcrj043kgy764bncbvyzr-file1.txt2155 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2156 Compression: zstd2157 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2158 NarSize: 1602159 References: 2160 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2161 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2162 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2163 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}2164 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/4/scratch/99e362236db6695a/build/TestNARDeduplicationMetadataUploadBug1130270060/001/store/z7pd2rxa04ky45hq9kihjs5s0nn6s1zh-file2.txt21652026/10/29 01:21:32 INFO Received push request method=POST path=/api/pushes21662026/10/29 01:21:32 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)2167--- PASS: TestService_healthCheckHandler (5.65s)2168=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete21692026/10/29 01:21:32 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign21702026/10/29 01:21:32 WARN Failed to register uploaded object key=z7pd2rxa04ky45hq9kihjs5s0nn6s1zh.ls error="server returned 404: 404 page not found\n"21712026/10/29 01:21:32 INFO Signed narinfos id=2 count=121722026/10/29 01:21:32 INFO Uploading 1 narinfos21732026/10/29 01:21:32 INFO Received complete push request method=POST path=/api/pushes/2/complete21742026/10/29 01:21:32 WARN Failed to register uploaded object key=z7pd2rxa04ky45hq9kihjs5s0nn6s1zh.narinfo error="server returned 404: 404 page not found\n"21752026/10/29 01:21:32 INFO Completed push id=2 objects=3 duration=813.542µs21762026/10/29 01:21:32 INFO Upload complete. (214ms)21772026/10/29 01:21:32 WARN Request failed, retrying attempt=5 backoff=1.681179491s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2178=== NAME TestNARDeduplicationMetadataUploadBug2179 metadata_upload_test.go:76: Retrieved narinfo from S3:2180 StorePath: /private/var/tb/4/scratch/99e362236db6695a/build/TestNARDeduplicationMetadataUploadBug1130270060/001/store/z7pd2rxa04ky45hq9kihjs5s0nn6s1zh-file2.txt2181 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2182 Compression: zstd2183 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2184 NarSize: 1602185 References: 2186 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2187 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2188 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2189 {"version":1,"root":{"type":"regular","size":44}}21902026-10-29 01:21:32.432 UTC [43596] LOG: checkpoint starting: wal2191--- PASS: TestNARDeduplicationMetadataUploadBug (6.97s)2192=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info21932026/10/29 01:21:32 INFO Received uploads request method=POST path=/2194=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key21952026/10/29 01:21:32 INFO Received request for more parts method=POST path=/2196=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key21972026/10/29 01:21:32 INFO Received complete multipart upload request method=POST path=/2198=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal21992026/10/29 01:21:32 INFO Received uploads request method=POST path=/2200=== CONT TestPendingClosureWriteTimeout/400_objects22012026/10/29 01:21:32 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"2202--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)2203 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.01s)2204 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2205 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2206 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2207=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline22082026/10/29 01:21:32 WARN mTLS auth: bound subjects configured but subject DN unavailable22092026/10/29 01:21:32 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2210--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (5.43s)2211=== CONT TestPendingClosureWriteTimeout/670k_objects2212=== CONT TestPendingClosureWriteTimeout/empty2213=== CONT TestService_RequireScope_OIDC/ops_may_not_write2214=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2215=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read22162026/10/29 01:21:32 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]2217=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2218=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2219=== CONT TestService_RequireScope_OIDC/static_token_may_admin2220=== CONT TestService_RequireScope_OIDC/ops_may_admin2221=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2222=== CONT TestService_RequireScope_OIDC/builder_may_write2223=== CONT TestService_RequireScope_OIDC/reader_may_read2224=== CONT TestService_RequireScope_OIDC/writer_implies_read2225=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2226=== CONT TestService_RequireScope_OIDC/static_token_may_write2227=== CONT TestService_RequireScope_OIDC/reader_may_not_write2228=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2229=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected22302026/10/29 01:21:32 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]2231=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2232=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected22332026/10/29 01:21:32 WARN Authentication failed token_preview=eyJhbGciOi...ZqQajW8nLQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2234--- PASS: TestService_AuthMiddleware_OIDC (5.43s)2235 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2236 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.01s)2237 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2238 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)2239--- PASS: TestService_RequireScope_OIDC (5.88s)2240 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2241 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2242 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2243 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2244 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2245 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2246 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2247 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2248 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2249 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2250 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2251 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2252 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2253 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)22542026/10/29 01:21:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22552026/10/29 01:21:32 INFO Received uploads request method=POST path=/api/pending_closures22562026/10/29 01:21:32 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLjNhOTI0ZjVlLWU1Y2MtNGUyNy1iMmRhLTUxNWIzNTBiMmM2MHgxNzkzMjM2ODg5ODY4NjYxMDAw parts=1022572026/10/29 01:21:32 INFO Received complete push request method=POST path=/api/pushes/1/complete22582026/10/29 01:21:32 INFO Completed push id=1 objects=4 duration=23.678125ms22592026/10/29 01:21:32 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22602026/10/29 01:21:32 INFO Completed upload id=2 objects=2 duration=575.292µs22612026/10/29 01:21:32 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst22622026/10/29 01:21:32 INFO Received uploads request method=POST path=/api/pending_closures2263--- PASS: TestMetricsCommit (8.77s)2264--- PASS: TestPresignedUploadRegisteredBeforeCommit (5.79s)22652026/10/29 01:21:33 INFO Received uploads request method=POST path=/api/pending_closures22662026/10/29 01:21:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22672026/10/29 01:21:33 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLjliYTlmZmMxLWFiYzktNDRkNC1iZjM4LTQ4MGVlNzg3YTlmM3gxNzkzMjM2ODkzMTg1NTY0MDAw22682026/10/29 01:21:33 INFO Received uploads request method=POST path=/api/pending_closures22692026/10/29 01:21:33 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLjliYTlmZmMxLWFiYzktNDRkNC1iZjM4LTQ4MGVlNzg3YTlmM3gxNzkzMjM2ODkzMTg1NTY0MDAw error="Delete \"http://localhost:61974/bucket94/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLjliYTlmZmMxLWFiYzktNDRkNC1iZjM4LTQ4MGVlNzg3YTlmM3gxNzkzMjM2ODkzMTg1NTY0MDAw\": injected: abort refused"22702026/10/29 01:21:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22712026/10/29 01:21:33 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLjliYTlmZmMxLWFiYzktNDRkNC1iZjM4LTQ4MGVlNzg3YTlmM3gxNzkzMjM2ODkzMTg1NTY0MDAw22722026/10/29 01:21:33 ERROR Failed to register completed object error="get pending object \"nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst\": context canceled" object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst22732026/10/29 01:21:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22742026/10/29 01:21:33 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=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLjliYTlmZmMxLWFiYzktNDRkNC1iZjM4LTQ4MGVlNzg3YTlmM3gxNzkzMjM2ODkzMTg1NTY0MDAw22752026/10/29 01:21:33 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLjliYTlmZmMxLWFiYzktNDRkNC1iZjM4LTQ4MGVlNzg3YTlmM3gxNzkzMjM2ODkzMTg1NTY0MDAw parts=12276--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (6.32s)2277--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (6.26s)22782026/10/29 01:21:33 WARN Rate limiter enabled after throttle name=s3-test rate=522792026/10/29 01:21:33 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2280=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2281 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102282 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002283--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (11.45s)2284--- PASS: TestConnectWaitsForAPeerMigration (7.14s)22852026/10/29 01:21:34 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-config22862026/10/29 01:21:34 INFO Received uploads request method=POST path=/api/pending_closures22872026/10/29 01:21:34 INFO Aborted multipart uploads count=0 kept=022882026/10/29 01:21:34 WARN Force mode enabled - objects will be deleted immediately without grace period22892026/10/29 01:21:34 WARN Request failed, retrying attempt=2 backoff=218.602391ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22902026/10/29 01:21:34 INFO Aborted multipart uploads count=1 kept=022912026/10/29 01:21:34 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=022922026/10/29 01:21:34 INFO Received cleanup request method=DELETE path=/api/pending_closures22932026/10/29 01:21:34 INFO Aborted multipart uploads count=1 kept=022942026/10/29 01:21:34 INFO Vacuumed table table=pending_closures22952026/10/29 01:21:34 INFO Vacuumed table table=pending_objects22962026/10/29 01:21:34 INFO Vacuumed table table=multipart_uploads22972026/10/29 01:21:34 INFO Vacuumed table table=closures22982026/10/29 01:21:34 INFO Vacuumed table table=objects22992026/10/29 01:21:34 WARN Request failed, retrying attempt=3 backoff=419.179704ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23002026/10/29 01:21:34 INFO Received uploads request method=POST path=/api/pending_closures2301--- PASS: TestPendingCleanupUsesOneCutoff (12.00s)23022026/10/29 01:21:34 INFO Aborted multipart uploads count=0 kept=02303--- PASS: TestUploadHandlersRejectOversizedBody (0.18s)2304 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.31s)2305 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.29s)2306 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (5.19s)23072026/10/29 01:21:34 WARN Force mode enabled - objects will be deleted immediately without grace period23082026/10/29 01:21:34 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=023092026/10/29 01:21:34 INFO Vacuumed table table=pending_closures23102026/10/29 01:21:34 INFO Vacuumed table table=pending_objects23112026/10/29 01:21:34 INFO Vacuumed table table=multipart_uploads23122026/10/29 01:21:34 INFO Vacuumed table table=closures23132026/10/29 01:21:34 INFO Vacuumed table table=objects2314--- PASS: TestForceGCDuringPushOffersSweptObject (0.01s)2315 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (6.24s)2316 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (6.06s)23172026/10/29 01:21:34 WARN Request failed, retrying attempt=4 backoff=784.289966ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23182026/10/29 01:21:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23192026/10/29 01:21:35 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLmNiYzMxNzg1LTJmMDYtNGI4Zi1hN2M1LWJhNGJhNDljNWQzMHgxNzkzMjM2ODkzNTA5NTk3MDAw parts=1223202026/10/29 01:21:35 INFO Received uploads request method=POST path=/api/pending_closures2321--- PASS: TestCompletedNarNotReofferedAcrossClosures (8.02s)2322--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2323 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (5.66s)2324 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (5.93s)23252026/10/29 01:21:35 WARN Request failed, retrying attempt=5 backoff=1.747447641s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23262026/10/29 01:21:35 INFO Received uploads request method=POST path=/api/pending_closures23272026/10/29 01:21:35 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"23282026/10/29 01:21:35 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"23292026/10/29 01:21:35 INFO Received uploads request method=POST path=/api/pending_closures2330=== NAME TestOrphanedObjectsGCStressTest2331 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2332 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion23332026/10/29 01:21:36 INFO Aborted multipart uploads count=0 kept=023342026/10/29 01:21:36 WARN Force mode enabled - objects will be deleted immediately without grace period23352026-10-29 01:21:36.369 UTC [44193] ERROR: canceling statement due to user request23362026-10-29 01:21:36.369 UTC [44193] STATEMENT: -- name: MarkStaleObjects :execrows2337 WITH RECURSIVE ct AS (2338 SELECT timezone('UTC', now()) AS now2339 ),2340 closure_reach AS (2341 -- Start with all closure keys2342 SELECT o.key, o.refs2343 FROM objects o2344 INNER JOIN closures c ON o.key = c.key2345 UNION2346 -- Recursively add all referenced objects2347 SELECT o.key, o.refs2348 FROM objects o2349 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2350 ),2351 reachable_objects AS (2352 SELECT DISTINCT key FROM closure_reach2353 ),2354 stale_objects AS (2355 SELECT o.key2356 FROM objects AS o, ct2357 WHERE2358 NOT EXISTS (2359 SELECT 12360 FROM reachable_objects ro2361 WHERE ro.key = o.key2362 )2363 AND NOT EXISTS (2364 SELECT 12365 FROM pending_objects AS po2366 WHERE po.key = o.key2367 )2368 AND o.deleted_at IS NULL -- Only mark fresh objects2369 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2370 FOR UPDATE2371 )2372 UPDATE objects2373 SET2374 deleted_at = ct.now,2375 first_deleted_at = COALESCE(first_deleted_at, ct.now)2376 FROM stale_objects, ct2377 WHERE objects.key = stale_objects.key2378 23792026/10/29 01:21:36 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=NjhjODU1YzQtNDkwZS00MjFjLTgxNTItZDkyMDhiMmFlNTdjLjgyZTlkODIyLTk4NGMtNDg2MC1iNDU5LTQ2MzIzMGE1YTA2Y3gxNzkzMjM2ODk1ODYzNTc0MDAw error="Access Denied"23802026/10/29 01:21:36 WARN keeping failed pending closure for cleanup to retry the abort id=12381--- PASS: TestPendingClosureFailureTracksEveryUpload (0.00s)2382 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (5.63s)2383 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (5.59s)23842026/10/29 01:21:36 INFO Aborted multipart uploads count=0 kept=023852026/10/29 01:21:36 WARN Force mode enabled - objects will be deleted immediately without grace period23862026/10/29 01:21:36 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:61974/bucket107/?delete=\": context canceled"2387--- PASS: TestGCEndsOnShutdown (0.00s)2388 --- PASS: TestGCEndsOnShutdown/before_the_run (4.55s)2389 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (4.48s)2390 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (4.37s)23912026/10/29 01:21:36 INFO Received uploads request method=POST path=/api/pending_closures23922026/10/29 01:21:37 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"23932026/10/29 01:21:37 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-config2394--- PASS: TestPendingClosureWriteTimeout (0.01s)2395 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2396 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2397 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2398 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (4.96s)23992026/10/29 01:21:37 WARN Request failed, retrying attempt=2 backoff=207.362709ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24002026/10/29 01:21:37 WARN Request failed, retrying attempt=3 backoff=379.521523ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24012026/10/29 01:21:38 WARN Request failed, retrying attempt=4 backoff=794.249627ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24022026/10/29 01:21:38 WARN Request failed, retrying attempt=5 backoff=1.670650583s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24032026/10/29 01:21:40 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_closures24042026/10/29 01:21:40 WARN Request failed, retrying attempt=2 backoff=190.811334ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24052026/10/29 01:21:40 WARN Request failed, retrying attempt=3 backoff=408.667733ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24062026/10/29 01:21:41 WARN Request failed, retrying attempt=4 backoff=867.64254ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24072026/10/29 01:21:42 WARN Request failed, retrying attempt=5 backoff=1.757492798s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2408--- PASS: TestClientErrorHandling (0.00s)2409 --- PASS: TestClientErrorHandling/InvalidStorePath (5.56s)2410 --- PASS: TestClientErrorHandling/InvalidAuthToken (5.19s)2411 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.61s)2412=== NAME TestOrphanedObjectsGCStressTest2413 orphaned_objects_gc_test.go:503: Stress test completed successfully:2414 orphaned_objects_gc_test.go:504: - Active objects preserved: 202415 orphaned_objects_gc_test.go:505: - Objects deleted: 2102416 orphaned_objects_gc_test.go:506: - Total GC'd: 2102417--- PASS: TestOrphanedObjectsGCStressTest (25.13s)2418PASS2419{"timestamp":"2026-10-29T01:21:45.06403Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:62163","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}2420{"timestamp":"2026-10-29T01:21:45.063956Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:62162","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}24212026-10-29 01:21:45.228 UTC [43591] LOG: received smart shutdown request24222026-10-29 01:21:45.229 UTC [43591] LOG: background worker "logical replication launcher" (PID 43601) exited with exit code 124232026-10-29 01:21:46.413 UTC [43596] LOG: checkpoint complete: wrote 8297 buffers (50.6%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=13.141 s, sync=0.716 s, total=13.981 s; sync files=37078, longest=0.001 s, average=0.001 s; distance=533107 kB, estimate=533107 kB; lsn=0/2332D290, redo lsn=0/22029BE024242026-10-29 01:21:46.414 UTC [43596] LOG: shutting down24252026-10-29 01:21:46.414 UTC [43596] LOG: checkpoint starting: shutdown immediate24262026-10-29 01:21:46.648 UTC [43596] LOG: checkpoint complete: wrote 3582 buffers (21.9%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 1 recycled; write=0.206 s, sync=0.028 s, total=0.235 s; sync files=1130, longest=0.001 s, average=0.001 s; distance=19469 kB, estimate=481743 kB; lsn=0/2332D308, redo lsn=0/2332D30824272026-10-29 01:21:46.658 UTC [43591] LOG: database system is shut down2428Running OIDC tests...2429=== RUN TestAudienceForIssuer2430=== PAUSE TestAudienceForIssuer2431=== RUN TestHTTPClientForHasTimeouts2432=== PAUSE TestHTTPClientForHasTimeouts2433=== RUN TestGlobMatch2434=== PAUSE TestGlobMatch2435=== RUN TestValidateToken_ValidToken2436=== PAUSE TestValidateToken_ValidToken2437=== RUN TestValidateToken_WrongAudience2438=== PAUSE TestValidateToken_WrongAudience2439=== RUN TestValidateToken_Expired2440=== PAUSE TestValidateToken_Expired2441=== RUN TestValidateToken_BoundClaimsMismatch2442=== PAUSE TestValidateToken_BoundClaimsMismatch2443=== RUN TestValidateToken_BoundSubjectMismatch2444=== PAUSE TestValidateToken_BoundSubjectMismatch2445=== RUN TestValidateToken_MultipleProviders2446=== PAUSE TestValidateToken_MultipleProviders2447=== RUN TestValidateToken_NoMatchingProvider2448=== PAUSE TestValidateToken_NoMatchingProvider2449=== RUN TestValidateToken_KubernetesServiceAccount2450=== PAUSE TestValidateToken_KubernetesServiceAccount2451=== RUN TestNewValidator_KubernetesRequiresCA2452=== PAUSE TestNewValidator_KubernetesRequiresCA2453=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2454=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2455=== RUN TestPins_ReservedForMatchingRule2456=== PAUSE TestPins_ReservedForMatchingRule2457=== RUN TestPins_TopLevelShorthand2458=== PAUSE TestPins_TopLevelShorthand2459=== RUN TestPins_ConfigValidation2460=== PAUSE TestPins_ConfigValidation2461=== RUN TestScopes_LegacyProviderDefaultsToWrite2462=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2463=== RUN TestScopes_Rules2464=== PAUSE TestScopes_Rules2465=== RUN TestScopes_ConfigValidation2466=== PAUSE TestScopes_ConfigValidation2467=== CONT TestAudienceForIssuer2468=== CONT TestNewValidator_KubernetesRequiresCA2469=== CONT TestValidateToken_WrongAudience2470=== CONT TestValidateToken_MultipleProviders2471=== CONT TestValidateToken_BoundSubjectMismatch2472=== CONT TestValidateToken_NoMatchingProvider2473=== CONT TestValidateToken_BoundClaimsMismatch2474=== CONT TestPins_TopLevelShorthand2475=== CONT TestScopes_ConfigValidation2476=== CONT TestScopes_LegacyProviderDefaultsToWrite2477=== CONT TestScopes_Rules2478=== CONT TestValidateToken_ValidToken2479--- PASS: TestAudienceForIssuer (0.00s)2480=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2481--- PASS: TestScopes_ConfigValidation (0.00s)2482=== CONT TestPins_ReservedForMatchingRule2483=== CONT TestPins_ConfigValidation2484=== CONT TestHTTPClientForHasTimeouts2485--- PASS: TestPins_ConfigValidation (0.00s)2486=== CONT TestValidateToken_KubernetesServiceAccount2487=== CONT TestValidateToken_Expired2488=== CONT TestGlobMatch2489=== RUN TestGlobMatch/foo_foo2490=== PAUSE TestGlobMatch/foo_foo2491=== RUN TestGlobMatch/foo_bar2492=== PAUSE TestGlobMatch/foo_bar2493=== RUN TestGlobMatch/*_2494=== PAUSE TestGlobMatch/*_2495=== RUN TestGlobMatch/*_anything2496=== PAUSE TestGlobMatch/*_anything2497=== RUN TestGlobMatch/foo*_foo2498=== PAUSE TestGlobMatch/foo*_foo2499=== RUN TestGlobMatch/foo*_foobar2500=== PAUSE TestGlobMatch/foo*_foobar2501=== RUN TestGlobMatch/foo*_bar2502=== PAUSE TestGlobMatch/foo*_bar2503=== RUN TestGlobMatch/*bar_bar2504=== PAUSE TestGlobMatch/*bar_bar2505=== RUN TestGlobMatch/*bar_foobar2506=== PAUSE TestGlobMatch/*bar_foobar2507=== RUN TestGlobMatch/*bar_foo2508=== PAUSE TestGlobMatch/*bar_foo2509=== RUN TestGlobMatch/foo*bar_foobar2510=== PAUSE TestGlobMatch/foo*bar_foobar2511=== RUN TestGlobMatch/foo*bar_foo123bar2512=== PAUSE TestGlobMatch/foo*bar_foo123bar2513=== RUN TestGlobMatch/foo*bar_foobarbaz2514=== PAUSE TestGlobMatch/foo*bar_foobarbaz2515=== RUN TestGlobMatch/*/*_foo/bar2516=== PAUSE TestGlobMatch/*/*_foo/bar2517=== RUN TestGlobMatch/*/*_foo2518=== PAUSE TestGlobMatch/*/*_foo2519=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2520=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2521=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02522=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02523=== RUN TestGlobMatch/refs/*/main_refs/heads/main2524=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2525=== RUN TestGlobMatch/fo?_foo2526=== PAUSE TestGlobMatch/fo?_foo2527=== RUN TestGlobMatch/fo?_fo2528=== PAUSE TestGlobMatch/fo?_fo2529=== RUN TestGlobMatch/fo?_fooo2530=== PAUSE TestGlobMatch/fo?_fooo2531=== RUN TestGlobMatch/?oo_foo2532=== PAUSE TestGlobMatch/?oo_foo2533=== RUN TestGlobMatch/?oo_boo2534=== PAUSE TestGlobMatch/?oo_boo2535=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2536=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2537=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2538=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2539=== CONT TestGlobMatch/foo*_foo2540=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2541=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2542=== CONT TestGlobMatch/?oo_boo2543=== CONT TestGlobMatch/?oo_foo2544=== CONT TestGlobMatch/fo?_fooo2545=== CONT TestGlobMatch/fo?_foo2546=== CONT TestGlobMatch/refs/*/main_refs/heads/main2547=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02548=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2549=== CONT TestGlobMatch/*/*_foo2550=== CONT TestGlobMatch/*/*_foo/bar2551=== CONT TestGlobMatch/fo?_fo2552=== CONT TestGlobMatch/foo*bar_foo123bar2553=== CONT TestGlobMatch/foo*bar_foobarbaz2554=== CONT TestGlobMatch/foo*bar_foobar2555=== CONT TestGlobMatch/*bar_foobar2556=== CONT TestGlobMatch/*bar_foo2557=== CONT TestGlobMatch/foo*_bar2558=== CONT TestGlobMatch/*bar_bar2559=== CONT TestGlobMatch/foo*_foobar2560=== CONT TestGlobMatch/*_anything2561=== CONT TestGlobMatch/*_2562=== CONT TestGlobMatch/foo_bar2563=== CONT TestGlobMatch/foo_foo2564--- PASS: TestGlobMatch (0.00s)2565 --- PASS: TestGlobMatch/foo*_foo (0.00s)2566 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2567 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2568 --- PASS: TestGlobMatch/?oo_boo (0.00s)2569 --- PASS: TestGlobMatch/?oo_foo (0.00s)2570 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2571 --- PASS: TestGlobMatch/fo?_foo (0.00s)2572 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2573 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2574 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2575 --- PASS: TestGlobMatch/*/*_foo (0.00s)2576 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2577 --- PASS: TestGlobMatch/fo?_fo (0.00s)2578 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2579 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2580 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2581 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2582 --- PASS: TestGlobMatch/*bar_foo (0.00s)2583 --- PASS: TestGlobMatch/foo*_bar (0.00s)2584 --- PASS: TestGlobMatch/*bar_bar (0.00s)2585 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2586 --- PASS: TestGlobMatch/*_anything (0.00s)2587 --- PASS: TestGlobMatch/*_ (0.00s)2588 --- PASS: TestGlobMatch/foo_bar (0.00s)2589 --- PASS: TestGlobMatch/foo_foo (0.00s)25902026/10/29 01:21:49 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232591--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.08s)25922026/10/29 01:21:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62788/oidc2593--- PASS: TestValidateToken_ValidToken (0.10s)25942026/10/29 01:21:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62791/oidc2595--- PASS: TestValidateToken_Expired (0.10s)25962026/10/29 01:21:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62793/oidc2597--- PASS: TestValidateToken_BoundClaimsMismatch (0.13s)25982026/10/29 01:21:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62795/oidc2599--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.13s)26002026/10/29 01:21:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62801/oidc26012026/10/29 01:21:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62803/oidc26022026/10/29 01:21:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62805/oidc26032026/10/29 01:21:49 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:6279926042026/10/29 01:21:49 http: TLS handshake error from 127.0.0.1:62798: remote error: tls: bad certificate2605--- PASS: TestNewValidator_KubernetesRequiresCA (0.16s)2606--- PASS: TestPins_TopLevelShorthand (0.16s)2607--- PASS: TestValidateToken_WrongAudience (0.16s)2608--- PASS: TestValidateToken_KubernetesServiceAccount (0.15s)2609--- PASS: TestScopes_Rules (0.16s)26102026/10/29 01:21:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62808/oidc2611--- PASS: TestValidateToken_BoundSubjectMismatch (0.18s)26122026/10/29 01:21:49 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:62789/oidc26132026/10/29 01:21:49 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:62810/oidc2614--- PASS: TestValidateToken_MultipleProviders (0.18s)26152026/10/29 01:21:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62813/oidc2616--- PASS: TestPins_ReservedForMatchingRule (0.19s)26172026/10/29 01:21:49 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:62807/oidc2618--- PASS: TestValidateToken_NoMatchingProvider (0.21s)2619--- PASS: TestHTTPClientForHasTimeouts (0.41s)2620PASS2621Running hook tests...2622=== RUN TestSendPathsEmpty2623=== PAUSE TestSendPathsEmpty2624=== RUN TestQueueEnqueueAndFetch2625=== PAUSE TestQueueEnqueueAndFetch2626=== RUN TestQueueDeduplication2627=== PAUSE TestQueueDeduplication2628=== RUN TestQueueRemove2629=== PAUSE TestQueueRemove2630=== RUN TestQueueFetchBatchLimit2631=== PAUSE TestQueueFetchBatchLimit2632=== RUN TestQueueRetryMovesToBack2633=== PAUSE TestQueueRetryMovesToBack2634=== RUN TestQueueFetchRemoveLifecycle2635=== PAUSE TestQueueFetchRemoveLifecycle2636=== RUN TestQueueConcurrentWriters2637=== PAUSE TestQueueConcurrentWriters2638=== RUN TestQueueRemoveLargeClosure2639=== PAUSE TestQueueRemoveLargeClosure2640=== RUN TestServerClientIntegration2641--- PASS: TestServerClientIntegration (0.00s)2642=== RUN TestServerQueueError26432026/10/29 01:21:51 ERROR Failed to queue paths error="permission denied" count=12644--- PASS: TestServerQueueError (0.00s)2645=== RUN TestServerRefusesOversizedAndNonStoreRequests2646=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2647=== RUN TestGetListenerSocketActivation2648 server_test.go:236: systemd socket activation does not exist on darwin2649--- SKIP: TestGetListenerSocketActivation (0.00s)2650=== RUN TestServerStalledClientDoesNotBlockShutdown2651=== PAUSE TestServerStalledClientDoesNotBlockShutdown2652=== RUN TestServerBacksOffOnAcceptErrors2653=== PAUSE TestServerBacksOffOnAcceptErrors2654=== RUN TestDrainIsolatesPoisonPath2655=== PAUSE TestDrainIsolatesPoisonPath2656=== RUN TestRunNotBlockedByPoisonHead2657=== PAUSE TestRunNotBlockedByPoisonHead2658=== RUN TestDrainGivesUpWhenServerDown2659=== PAUSE TestDrainGivesUpWhenServerDown2660=== RUN TestFailedPathPrunedByLaterClosure2661=== PAUSE TestFailedPathPrunedByLaterClosure2662=== RUN TestWorkerUploadsAndRemoves2663=== PAUSE TestWorkerUploadsAndRemoves2664=== RUN TestWorkerSkipsGCdPaths2665=== PAUSE TestWorkerSkipsGCdPaths2666=== RUN TestWorkerPrunesClosureDeps2667=== PAUSE TestWorkerPrunesClosureDeps2668=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2669=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2670=== RUN TestDrainTimeout2671=== PAUSE TestDrainTimeout2672=== RUN TestDrainTimeoutDuringIsolation2673=== PAUSE TestDrainTimeoutDuringIsolation2674=== RUN TestShutdownFinishesInFlightPush2675=== PAUSE TestShutdownFinishesInFlightPush2676=== RUN TestWorkerRemoveFailureIsNotProgress2677=== PAUSE TestWorkerRemoveFailureIsNotProgress2678=== RUN TestWorkerKeepsPathItCannotStat2679=== PAUSE TestWorkerKeepsPathItCannotStat2680=== CONT TestSendPathsEmpty2681=== CONT TestShutdownFinishesInFlightPush2682=== CONT TestQueueFetchRemoveLifecycle2683=== CONT TestWorkerSkipsGCdPaths2684=== CONT TestQueueRemove2685=== CONT TestWorkerKeepsPathItCannotStat2686=== CONT TestWorkerRemoveFailureIsNotProgress2687=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2688=== CONT TestDrainTimeoutDuringIsolation2689=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2690=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2691=== CONT TestDrainTimeout2692=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2693=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2694=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2695=== CONT TestWorkerPrunesClosureDeps2696=== CONT TestQueueConcurrentWriters2697=== CONT TestDrainGivesUpWhenServerDown2698=== CONT TestWorkerUploadsAndRemoves2699=== CONT TestQueueFetchBatchLimit2700=== CONT TestServerRefusesOversizedAndNonStoreRequests2701=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2702=== CONT TestServerStalledClientDoesNotBlockShutdown2703=== CONT TestQueueRemoveLargeClosure27042026/10/29 01:21:51 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2705=== CONT TestFailedPathPrunedByLaterClosure2706=== CONT TestDrainIsolatesPoisonPath2707=== CONT TestQueueDeduplication2708=== CONT TestQueueEnqueueAndFetch2709=== CONT TestRunNotBlockedByPoisonHead2710=== CONT TestQueueRetryMovesToBack2711--- PASS: TestSendPathsEmpty (0.00s)2712=== CONT TestServerBacksOffOnAcceptErrors2713=== RUN TestShutdownFinishesInFlightPush/completes2714=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2715=== PAUSE TestShutdownFinishesInFlightPush/completes27162026/10/29 01:21:51 ERROR Refusing path outside the store path=/nix/store store=/nix/store2717=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2718=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch27192026/10/29 01:21:51 ERROR Accept failed error="too many open files"2720=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2721=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2722=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short2723=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2724=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2725=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout27262026/10/29 01:21:51 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store27272026/10/29 01:21:51 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store27282026/10/29 01:21:51 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store27292026/10/29 01:21:51 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27302026/10/29 01:21:51 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27312026/10/29 01:21:51 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store27322026/10/29 01:21:51 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store27332026/10/29 01:21:51 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store27342026/10/29 01:21:51 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store27352026/10/29 01:21:51 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store27362026/10/29 01:21:51 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store27372026/10/29 01:21:51 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store27382026/10/29 01:21:51 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store27392026/10/29 01:21:51 ERROR Accept failed error="too many open files"27402026/10/29 01:21:51 ERROR Failed to decode request error="unexpected EOF"2741--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2742=== CONT TestShutdownFinishesInFlightPush/completes27432026/10/29 01:21:51 ERROR Accept failed error="too many open files"2744=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path2745--- PASS: TestQueueEnqueueAndFetch (0.03s)27462026/10/29 01:21:51 INFO Upload queue status pending=227472026/10/29 01:21:51 INFO Uploading batch count=127482026/10/29 01:21:51 ERROR Upload failed error="upload failed" count=127492026/10/29 01:21:51 INFO Uploading batch count=427502026/10/29 01:21:51 ERROR Upload failed error="upload failed" count=427512026/10/29 01:21:51 INFO Upload queue status pending=327522026/10/29 01:21:51 INFO Uploading batch count=227532026/10/29 01:21:51 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/4/scratch/99e362236db6695a/build/TestWorkerSkipsGCdPaths3085390064/002/nonexistent27542026/10/29 01:21:51 INFO Upload queue status pending=227552026/10/29 01:21:51 WARN Cannot stat store path, will retry later path=/private/var/tb/4/scratch/99e362236db6695a/build/TestWorkerKeepsPathItCannotStat762007698/002/locked/aaa error="lstat /private/var/tb/4/scratch/99e362236db6695a/build/TestWorkerKeepsPathItCannotStat762007698/002/locked/aaa: permission denied"27562026/10/29 01:21:51 INFO Uploading batch count=227572026/10/29 01:21:51 INFO Upload queue status pending=227582026/10/29 01:21:51 INFO Uploading batch count=427592026/10/29 01:21:51 ERROR Upload failed error="upload failed" count=427602026/10/29 01:21:51 INFO Uploading batch count=227612026/10/29 01:21:51 INFO Uploading batch count=127622026/10/29 01:21:51 INFO Uploading batch count=127632026/10/29 01:21:51 INFO Upload queue status pending=327642026/10/29 01:21:51 INFO Uploading batch count=227652026/10/29 01:21:51 ERROR Upload failed error="upload failed" count=227662026/10/29 01:21:51 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/4/scratch/99e362236db6695a/build/TestDrainGivesUpWhenServerDown2131025850/002/a27672026/10/29 01:21:51 INFO Uploading batch count=227682026/10/29 01:21:51 INFO Uploading batch count=427692026/10/29 01:21:51 ERROR Upload failed error="upload failed" count=427702026/10/29 01:21:51 INFO Uploading batch count=127712026/10/29 01:21:51 ERROR Upload failed error="upload failed" count=127722026/10/29 01:21:51 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/4/scratch/99e362236db6695a/build/TestDrainIsolatesPoisonPath1473442403/002/bbb2773--- PASS: TestQueueFetchRemoveLifecycle (0.03s)2774=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths27752026/10/29 01:21:51 WARN Cannot stat store path, will retry later path=/private/var/tb/4/scratch/99e362236db6695a/build/TestWorkerKeepsPathItCannotStat762007698/002/locked/aaa error="lstat /private/var/tb/4/scratch/99e362236db6695a/build/TestWorkerKeepsPathItCannotStat762007698/002/locked/aaa: permission denied"27762026/10/29 01:21:51 INFO Upload queue status pending=227772026/10/29 01:21:51 INFO Upload queue status pending=227782026/10/29 01:21:51 INFO Uploading batch count=22779--- PASS: TestQueueFetchBatchLimit (0.03s)2780=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch27812026/10/29 01:21:51 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/4/scratch/99e362236db6695a/build/TestDrainGivesUpWhenServerDown2131025850/002/b2782--- PASS: TestQueueDeduplication (0.03s)2783--- PASS: TestQueueRemove (0.03s)27842026/10/29 01:21:51 INFO Uploading batch count=22785--- PASS: TestQueueRetryMovesToBack (0.03s)27862026/10/29 01:21:51 INFO Uploading batch count=127872026/10/29 01:21:51 WARN Cannot stat store path, will retry later path=/private/var/tb/4/scratch/99e362236db6695a/build/TestWorkerKeepsPathItCannotStat762007698/002/locked/aaa error="lstat /private/var/tb/4/scratch/99e362236db6695a/build/TestWorkerKeepsPathItCannotStat762007698/002/locked/aaa: permission denied"27882026/10/29 01:21:51 INFO Uploading batch count=227892026/10/29 01:21:51 ERROR Upload failed error="upload failed" count=227902026/10/29 01:21:51 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/4/scratch/99e362236db6695a/build/TestDrainGivesUpWhenServerDown2131025850/002/c27912026/10/29 01:21:51 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/4/scratch/99e362236db6695a/build/TestDrainGivesUpWhenServerDown2131025850/002/d27922026/10/29 01:21:51 INFO Uploading batch count=127932026/10/29 01:21:51 ERROR Drain finished with paths left in queue remaining=127942026/10/29 01:21:51 ERROR Upload failed error="upload failed" count=127952026/10/29 01:21:51 ERROR Accept failed error="too many open files"27962026/10/29 01:21:51 INFO Uploading batch count=227972026/10/29 01:21:51 ERROR Upload failed error="upload failed" count=227982026/10/29 01:21:51 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/4/scratch/99e362236db6695a/build/TestDrainGivesUpWhenServerDown2131025850/002/e27992026/10/29 01:21:51 INFO Uploading batch count=128002026/10/29 01:21:51 ERROR Upload failed error="upload failed" count=12801--- PASS: TestFailedPathPrunedByLaterClosure (0.04s)28022026/10/29 01:21:51 INFO Uploading batch count=128032026/10/29 01:21:51 ERROR Upload failed error="upload failed" count=128042026/10/29 01:21:51 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/4/scratch/99e362236db6695a/build/TestDrainGivesUpWhenServerDown2131025850/002/f2805--- PASS: TestWorkerKeepsPathItCannotStat (0.04s)28062026/10/29 01:21:51 ERROR Drain finished with paths left in queue remaining=128072026/10/29 01:21:51 ERROR Drain finished with paths left in queue remaining=102808--- PASS: TestDrainIsolatesPoisonPath (0.04s)2809--- PASS: TestDrainGivesUpWhenServerDown (0.04s)28102026/10/29 01:21:51 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/4/scratch/99e362236db6695a/build/TestWorkerRemoveFailureIsNotProgresscollected_path3484504733/001/nonexistent28112026/10/29 01:21:51 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128122026/10/29 01:21:51 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/4/scratch/99e362236db6695a/build/TestWorkerRemoveFailureIsNotProgresscollected_path3484504733/001/nonexistent28132026/10/29 01:21:51 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128142026/10/29 01:21:51 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/4/scratch/99e362236db6695a/build/TestWorkerRemoveFailureIsNotProgresscollected_path3484504733/001/nonexistent28152026/10/29 01:21:51 INFO Uploading batch count=228162026/10/29 01:21:51 INFO Uploading batch count=228172026/10/29 01:21:51 ERROR Upload failed error="upload failed" count=228182026/10/29 01:21:51 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128192026/10/29 01:21:51 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228202026/10/29 01:21:51 ERROR Drain finished with paths left in queue remaining=128212026/10/29 01:21:51 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128222026/10/29 01:21:51 INFO Uploading batch count=228232026/10/29 01:21:51 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128242026/10/29 01:21:51 INFO Uploading batch count=228252026/10/29 01:21:51 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228262026/10/29 01:21:51 ERROR Upload failed error="upload failed" count=228272026/10/29 01:21:51 INFO Uploading batch count=228282026/10/29 01:21:51 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128292026/10/29 01:21:51 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128302026/10/29 01:21:51 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228312026/10/29 01:21:51 ERROR Drain finished with paths left in queue remaining=228322026/10/29 01:21:51 INFO Uploading batch count=228332026/10/29 01:21:51 ERROR Upload failed error="upload failed" count=228342026/10/29 01:21:51 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128352026/10/29 01:21:51 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128362026/10/29 01:21:51 ERROR Drain finished with paths left in queue remaining=22837--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.05s)2838--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2839 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.02s)2840 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.02s)2841 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.02s)2842--- PASS: TestWorkerSkipsGCdPaths (0.05s)2843--- PASS: TestWorkerUploadsAndRemoves (0.05s)2844--- PASS: TestWorkerPrunesClosureDeps (0.05s)28452026/10/29 01:21:51 ERROR Accept failed error="too many open files"28462026/10/29 01:21:51 ERROR Accept failed error="too many open files"2847--- PASS: TestQueueConcurrentWriters (0.16s)28482026/10/29 01:21:51 ERROR Failed to decode request error="read unix /private/var/tb/4/scratch/99e362236db6695a/build/hook1958393400/test.sock->: i/o timeout"28492026/10/29 01:21:51 ERROR Failed to write response error="write unix /private/var/tb/4/scratch/99e362236db6695a/build/hook1958393400/test.sock->: i/o timeout"2850--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)28512026/10/29 01:21:51 ERROR Upload failed error="context canceled" count=228522026/10/29 01:21:51 ERROR Drain finished with paths left in queue remaining=428532026/10/29 01:21:51 ERROR Drain finished with paths left in queue remaining=42854--- PASS: TestDrainTimeout (0.23s)28552026/10/29 01:21:51 ERROR Upload failed error="context canceled" count=228562026/10/29 01:21:51 ERROR Drain finished with paths left in queue remaining=22857--- PASS: TestShutdownFinishesInFlightPush (0.00s)2858 --- PASS: TestShutdownFinishesInFlightPush/completes (0.13s)2859 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.23s)28602026/10/29 01:21:52 ERROR Accept failed error="too many open files"28612026/10/29 01:21:52 ERROR Drain finished with paths left in queue remaining=32862--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2863 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.23s)2864 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.33s)28652026/10/29 01:21:52 ERROR Accept failed error="too many open files"2866--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)2867--- PASS: TestQueueRemoveLargeClosure (0.79s)28682026/10/29 01:21:52 INFO Uploading batch count=128692026/10/29 01:21:52 INFO Uploading batch count=128702026/10/29 01:21:52 INFO Uploading batch count=128712026/10/29 01:21:52 ERROR Upload failed error="upload failed" count=128722026/10/29 01:21:52 INFO Uploading batch count=128732026/10/29 01:21:52 ERROR Upload failed error="upload failed" count=128742026/10/29 01:21:52 INFO Uploading batch count=128752026/10/29 01:21:52 ERROR Upload failed error="upload failed" count=128762026/10/29 01:21:52 INFO Uploading batch count=128772026/10/29 01:21:52 ERROR Upload failed error="upload failed" count=128782026/10/29 01:21:52 ERROR Drain finished with paths left in queue remaining=12879--- PASS: TestRunNotBlockedByPoisonHead (1.06s)2880PASS2881Running signing tests...2882=== RUN TestExternalSigner2883=== PAUSE TestExternalSigner2884=== RUN TestExternalSignerWrongPublicKey2885=== PAUSE TestExternalSignerWrongPublicKey2886=== RUN TestExternalSignerErrors2887=== PAUSE TestExternalSignerErrors2888=== RUN TestExternalSignerRestartsAfterCrash2889=== PAUSE TestExternalSignerRestartsAfterCrash2890=== RUN TestExternalSignerProgramErrorKeepsProcess2891=== PAUSE TestExternalSignerProgramErrorKeepsProcess2892=== RUN TestExternalSignerClose2893=== PAUSE TestExternalSignerClose2894=== RUN TestExternalSignerRejectsInvalidPublicKey2895=== PAUSE TestExternalSignerRejectsInvalidPublicKey2896=== RUN TestExternalSignerCancellation2897=== PAUSE TestExternalSignerCancellation2898=== RUN TestGenerateFingerprint2899=== PAUSE TestGenerateFingerprint2900=== RUN TestParseSigningKey2901=== PAUSE TestParseSigningKey2902=== RUN TestSign2903=== PAUSE TestSign2904=== RUN TestSignBatch2905=== PAUSE TestSignBatch2906=== RUN TestNilKeyPublicKey2907=== PAUSE TestNilKeyPublicKey2908=== RUN TestSignErrors2909=== PAUSE TestSignErrors2910=== CONT TestExternalSignerWrongPublicKey2911=== CONT TestParseSigningKey2912=== CONT TestExternalSignerCancellation2913=== RUN TestParseSigningKey/valid_32-byte_key2914=== CONT TestExternalSignerRestartsAfterCrash2915=== CONT TestSignErrors2916=== PAUSE TestParseSigningKey/valid_32-byte_key2917=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2918=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2919=== RUN TestParseSigningKey/no_colon2920=== CONT TestExternalSignerClose2921=== PAUSE TestParseSigningKey/no_colon2922=== CONT TestExternalSignerProgramErrorKeepsProcess2923=== CONT TestExternalSignerRejectsInvalidPublicKey2924=== CONT TestExternalSignerErrors2925=== CONT TestExternalSigner2926=== CONT TestSignBatch2927=== CONT TestNilKeyPublicKey2928=== CONT TestGenerateFingerprint2929=== CONT TestSign2930=== RUN TestParseSigningKey/empty_name2931=== RUN TestExternalSignerRejectsInvalidPublicKey/#002932=== RUN TestExternalSignerErrors/invalid_JSON2933--- PASS: TestNilKeyPublicKey (0.00s)2934=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002935=== PAUSE TestParseSigningKey/empty_name2936=== PAUSE TestExternalSignerErrors/invalid_JSON2937=== RUN TestGenerateFingerprint/basic_with_references2938=== RUN TestParseSigningKey/invalid_base642939=== RUN TestExternalSignerErrors/wrong_shape2940=== PAUSE TestExternalSignerErrors/wrong_shape2941=== PAUSE TestGenerateFingerprint/basic_with_references2942=== PAUSE TestParseSigningKey/invalid_base642943=== RUN TestExternalSignerErrors/missing_signature_name2944=== RUN TestGenerateFingerprint/no_references2945=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2946=== PAUSE TestExternalSignerErrors/missing_signature_name2947=== RUN TestParseSigningKey/wrong_length2948=== RUN TestExternalSignerErrors/invalid_signature_base642949=== PAUSE TestGenerateFingerprint/no_references2950=== PAUSE TestParseSigningKey/wrong_length2951=== PAUSE TestExternalSignerErrors/invalid_signature_base642952=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2953=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2954=== CONT TestParseSigningKey/no_colon2955=== CONT TestParseSigningKey/valid_32-byte_key2956=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2957=== CONT TestParseSigningKey/empty_name2958=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2959=== CONT TestParseSigningKey/invalid_base642960=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2961=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2962=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2963=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2964=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2965=== CONT TestParseSigningKey/wrong_length2966=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2967=== RUN TestExternalSignerErrors/wrong_id2968=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2969=== PAUSE TestExternalSignerErrors/wrong_id2970=== CONT TestExternalSignerRejectsInvalidPublicKey/#002971=== RUN TestExternalSignerErrors/wrong_signatures_shape2972=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2973=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2974=== RUN TestGenerateFingerprint/invalid_nar_hash_length2975=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2976=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2977=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2978=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2979=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2980=== RUN TestExternalSignerErrors/unrequested_key2981=== RUN TestGenerateFingerprint/invalid_store_path_prefix2982--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2983 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2984 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2985 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2986 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2987 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2988=== PAUSE TestExternalSignerErrors/unrequested_key2989=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2990=== RUN TestExternalSignerErrors/program_error2991=== RUN TestGenerateFingerprint/invalid_reference_prefix2992=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2993=== PAUSE TestExternalSignerErrors/program_error2994=== CONT TestGenerateFingerprint/invalid_nar_hash_length2995=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2996=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2997=== RUN TestExternalSignerErrors/null2998=== CONT TestGenerateFingerprint/invalid_reference_prefix2999=== CONT TestGenerateFingerprint/no_references3000=== CONT TestGenerateFingerprint/invalid_store_path_prefix3001=== CONT TestGenerateFingerprint/basic_with_references3002=== PAUSE TestExternalSignerErrors/null3003=== RUN TestExternalSignerErrors/missing_signatures3004--- PASS: TestGenerateFingerprint (0.01s)3005 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)3006 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)3007 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)3008 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)3009 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)3010 --- PASS: TestGenerateFingerprint/no_references (0.00s)3011 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)3012=== PAUSE TestExternalSignerErrors/missing_signatures3013=== RUN TestExternalSignerErrors/null_signatures3014=== PAUSE TestExternalSignerErrors/null_signatures3015=== RUN TestExternalSignerErrors/too_few_signatures3016=== PAUSE TestExternalSignerErrors/too_few_signatures3017=== RUN TestExternalSignerErrors/wrong_signature_name3018=== PAUSE TestExternalSignerErrors/wrong_signature_name3019=== RUN TestExternalSignerErrors/wrong_signature_length3020=== PAUSE TestExternalSignerErrors/wrong_signature_length3021=== RUN TestExternalSignerErrors/exit_on_request3022=== RUN TestSignErrors/nil_key3023=== PAUSE TestExternalSignerErrors/exit_on_request3024=== RUN TestExternalSignerErrors/exit_at_startup3025=== PAUSE TestExternalSignerErrors/exit_at_startup3026=== PAUSE TestSignErrors/nil_key3027=== RUN TestSignErrors/nil_narinfo3028=== CONT TestExternalSignerErrors/null3029=== CONT TestExternalSignerErrors/wrong_id3030=== CONT TestExternalSignerErrors/unrequested_key3031=== CONT TestExternalSignerErrors/missing_signatures3032=== CONT TestExternalSignerErrors/wrong_signatures_shape3033=== PAUSE TestSignErrors/nil_narinfo3034=== RUN TestSignErrors/invalid_narinfo3035=== CONT TestExternalSignerErrors/exit_at_startup3036=== CONT TestExternalSignerErrors/missing_signature_name3037--- PASS: TestParseSigningKey (0.00s)3038 --- PASS: TestParseSigningKey/no_colon (0.00s)3039 --- PASS: TestParseSigningKey/empty_name (0.00s)3040 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)3041 --- PASS: TestParseSigningKey/wrong_length (0.00s)3042 --- PASS: TestParseSigningKey/valid_32-byte_key (0.01s)3043 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.01s)3044--- PASS: TestSign (0.01s)3045=== CONT TestExternalSignerErrors/exit_on_request3046=== CONT TestExternalSignerErrors/invalid_signature_base643047=== CONT TestExternalSignerErrors/program_error3048=== PAUSE TestSignErrors/invalid_narinfo3049=== RUN TestSignErrors/canceled3050=== PAUSE TestSignErrors/canceled3051=== CONT TestSignErrors/invalid_narinfo3052=== CONT TestSignErrors/canceled3053=== CONT TestSignErrors/nil_narinfo3054=== CONT TestSignErrors/nil_key3055=== CONT TestExternalSignerErrors/invalid_JSON3056--- PASS: TestSignErrors (0.01s)3057 --- PASS: TestSignErrors/invalid_narinfo (0.00s)3058 --- PASS: TestSignErrors/canceled (0.00s)3059 --- PASS: TestSignErrors/nil_narinfo (0.00s)3060 --- PASS: TestSignErrors/nil_key (0.00s)3061=== CONT TestExternalSignerErrors/wrong_signature_length3062=== CONT TestExternalSignerErrors/wrong_signature_name3063=== CONT TestExternalSignerErrors/too_few_signatures3064=== CONT TestExternalSignerErrors/null_signatures3065=== CONT TestExternalSignerErrors/wrong_shape3066--- PASS: TestSignBatch (0.02s)3067--- PASS: TestExternalSignerWrongPublicKey (0.22s)3068--- PASS: TestExternalSignerClose (0.40s)3069--- PASS: TestExternalSignerCancellation (0.61s)3070--- PASS: TestExternalSignerRestartsAfterCrash (0.80s)3071--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.97s)3072--- PASS: TestExternalSigner (3.79s)3073--- PASS: TestExternalSignerErrors (0.01s)3074 --- PASS: TestExternalSignerErrors/exit_at_startup (1.14s)3075 --- PASS: TestExternalSignerErrors/unrequested_key (1.34s)3076 --- PASS: TestExternalSignerErrors/missing_signature_name (2.07s)3077 --- PASS: TestExternalSignerErrors/exit_on_request (2.26s)3078 --- PASS: TestExternalSignerErrors/invalid_JSON (2.44s)3079 --- PASS: TestExternalSignerErrors/wrong_signature_length (2.63s)3080 --- PASS: TestExternalSignerErrors/wrong_signature_name (2.82s)3081 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (3.01s)3082 --- PASS: TestExternalSignerErrors/null (3.20s)3083 --- PASS: TestExternalSignerErrors/wrong_id (3.38s)3084 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (3.57s)3085 --- PASS: TestExternalSignerErrors/wrong_shape (3.94s)3086 --- PASS: TestExternalSignerErrors/missing_signatures (4.14s)3087 --- PASS: TestExternalSignerErrors/program_error (4.32s)3088 --- PASS: TestExternalSignerErrors/too_few_signatures (4.51s)3089 --- PASS: TestExternalSignerErrors/null_signatures (4.70s)3090PASS3091Running OpenBao signer tests...3092=== RUN TestSign3093=== PAUSE TestSign3094=== RUN TestSignErrors3095=== PAUSE TestSignErrors3096=== RUN TestServe3097=== PAUSE TestServe3098=== RUN TestServeRejectsGarbage3099=== PAUSE TestServeRejectsGarbage3100=== CONT TestSign3101=== CONT TestServe3102=== CONT TestSignErrors3103=== RUN TestSignErrors/http_error3104=== CONT TestServeRejectsGarbage3105--- PASS: TestServeRejectsGarbage (0.00s)3106=== PAUSE TestSignErrors/http_error3107--- PASS: TestServe (0.00s)3108=== RUN TestSignErrors/invalid_json3109=== PAUSE TestSignErrors/invalid_json3110=== RUN TestSignErrors/no_prefix3111=== PAUSE TestSignErrors/no_prefix3112=== RUN TestSignErrors/invalid_base643113=== PAUSE TestSignErrors/invalid_base643114=== CONT TestSignErrors/http_error3115=== CONT TestSignErrors/invalid_base643116=== CONT TestSignErrors/invalid_json3117=== CONT TestSignErrors/no_prefix3118--- PASS: TestSign (0.01s)3119--- PASS: TestSignErrors (0.00s)3120 --- PASS: TestSignErrors/http_error (0.00s)3121 --- PASS: TestSignErrors/invalid_base64 (0.00s)3122 --- PASS: TestSignErrors/no_prefix (0.00s)3123 --- PASS: TestSignErrors/invalid_json (0.00s)3124PASS3125Running niks3-hook command tests...3126=== RUN TestServeSecondSignalEndsDrain3127=== PAUSE TestServeSecondSignalEndsDrain3128=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown3129=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown3130=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown3131=== CONT TestServeSecondSignalEndsDrain3132--- PASS: TestServeSecondSignalEndsDrain (0.05s)31332026/10/29 01:22:02 INFO Upload queue status pending=131342026/10/29 01:22:02 INFO Uploading batch count=13135--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.12s)3136PASS3137Running rate limiter tests...3138=== RUN TestAdaptiveRateLimiter_ThreadSafety3139=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3140=== CONT TestAdaptiveRateLimiter_ThreadSafety31412026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=112.7357000000000731422026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=78.9149900000000531432026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=55.2404930000000331442026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=38.6683451000000231452026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=27.0678415700000131462026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=18.94748909900000631472026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=13.26324236930000431482026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=9.28426965851000231492026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=6.49898876095700131502026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531512026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=9.07809861035000631522026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=6.35466902724500431532026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531542026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531552026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531562026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531572026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531582026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531592026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531602026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531612026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=5.63678500000000131622026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531632026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531642026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531652026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531662026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531672026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531682026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531692026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531702026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531712026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531722026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531732026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531742026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531752026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531762026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531772026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531782026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531792026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531802026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531812026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531822026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531832026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531842026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531852026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531862026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531872026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=5.12435000000000131882026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531892026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531902026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531912026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531922026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531932026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531942026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531952026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=531962026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=16.08240545225027431972026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=11.25768381657519231982026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=7.88037867160263331992026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=5.51626507012184332002026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532012026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532022026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532032026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532042026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532052026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532062026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532072026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532082026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532092026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532102026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532112026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532122026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532132026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532142026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532152026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532162026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532172026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532182026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532192026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532202026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532212026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532222026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532232026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532242026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532252026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532262026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532272026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532282026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532292026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532302026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532312026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532322026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532332026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532342026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532352026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532362026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532372026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532382026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532392026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=532402026/10/29 01:22:03 WARN Rate limiter backed off name=test rate=53241--- PASS: TestAdaptiveRateLimiter_ThreadSafety (0.07s)3242PASS