niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #404
· 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_ProducerErrorIsNotEOF22=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF23=== RUN TestUploadMultipart_FailedPartBufferNotReused24=== PAUSE TestUploadMultipart_FailedPartBufferNotReused25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestUploadMultipart_SupersededByPeer28=== PAUSE TestUploadMultipart_SupersededByPeer29=== RUN TestDumpPathCaseHackMatchesNix30--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)31=== RUN TestDumpPathCaseHackCollision32--- PASS: TestDumpPathCaseHackCollision (0.00s)33=== RUN TestSupersededNARStillUploadsListing34=== PAUSE TestSupersededNARStillUploadsListing35=== RUN TestTruncatedNARDumpIsNotCompleted36=== PAUSE TestTruncatedNARDumpIsNotCompleted37=== RUN TestDumpPathMatchesNix38=== PAUSE TestDumpPathMatchesNix39=== RUN TestDumpPathSingleFile40=== PAUSE TestDumpPathSingleFile41=== RUN TestDumpPathWriterError42=== PAUSE TestDumpPathWriterError43=== RUN TestDumpPathWriterErrorStopsReading44 nar_test.go:280: no /proc/self/io: open /proc/self/io: no such file or directory45--- SKIP: TestDumpPathWriterErrorStopsReading (0.36s)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 TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade79=== PAUSE TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade80=== RUN TestRetryTimeoutOutlastsMaxRetries81=== PAUSE TestRetryTimeoutOutlastsMaxRetries82=== RUN TestDoWithRetry_FinalResponseBodyReadable83=== PAUSE TestDoWithRetry_FinalResponseBodyReadable84=== RUN TestShellSplit85=== PAUSE TestShellSplit86=== RUN TestShellSplitErrors87=== PAUSE TestShellSplitErrors88=== RUN TestStreamPushReportsEveryPath89=== PAUSE TestStreamPushReportsEveryPath90=== RUN TestStreamPushBatchesUnderLoad91=== PAUSE TestStreamPushBatchesUnderLoad92=== RUN TestStreamPushIsolatesFailures93=== PAUSE TestStreamPushIsolatesFailures94=== RUN TestStreamPushGivesUpOnDeadServer95=== PAUSE TestStreamPushGivesUpOnDeadServer96=== RUN TestStreamPushRequestLine97=== PAUSE TestStreamPushRequestLine98=== RUN TestStreamPushReportsSignatures99=== PAUSE TestStreamPushReportsSignatures100=== RUN TestStreamPushReportsSkippedPaths101=== PAUSE TestStreamPushReportsSkippedPaths102=== RUN TestClientSignaturesByStorePath103=== PAUSE TestClientSignaturesByStorePath104=== RUN TestStreamPushStopsWhenCanceled105=== PAUSE TestStreamPushStopsWhenCanceled106=== RUN TestStreamPushStopsOnCancel107=== PAUSE TestStreamPushStopsOnCancel108=== RUN TestSetClientTLS109=== PAUSE TestSetClientTLS110=== RUN TestSetClientTLSDoesNotMutateDefaultTransport111=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport112=== RUN TestSetClientTLSErrors113=== PAUSE TestSetClientTLSErrors114=== RUN TestStaticToken115=== PAUSE TestStaticToken116=== RUN TestFileTokenReadsAndCaches117=== PAUSE TestFileTokenReadsAndCaches118=== RUN TestFileTokenMissing119=== PAUSE TestFileTokenMissing120=== RUN TestFileTokenEmpty121=== PAUSE TestFileTokenEmpty122=== RUN TestScriptTokenNoExpiryRerunsEveryCall123=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall124=== RUN TestScriptTokenCachesUntilRefresh125=== PAUSE TestScriptTokenCachesUntilRefresh126=== RUN TestScriptTokenEmptyToken127=== PAUSE TestScriptTokenEmptyToken128=== RUN TestScriptTokenBadJSON129=== PAUSE TestScriptTokenBadJSON130=== RUN TestScriptTokenScriptFails131=== PAUSE TestScriptTokenScriptFails132=== RUN TestScriptTokenEmptyCommand133=== PAUSE TestScriptTokenEmptyCommand134=== RUN TestScriptTokenDoesNotWaitForItsChildren135=== PAUSE TestScriptTokenDoesNotWaitForItsChildren136=== CONT TestDoServerRequestAttachesToken137=== CONT TestStreamPushReportsSkippedPaths138=== CONT TestStreamPushStopsWhenCanceled139=== CONT TestScriptTokenDoesNotWaitForItsChildren140=== CONT TestScriptTokenScriptFails141=== CONT TestClientSignaturesByStorePath142=== CONT TestFileTokenMissing143=== CONT TestStreamPushReportsSignatures144=== CONT TestCompletePendingClosure_NotFoundWithoutKey145=== CONT TestScriptTokenBadJSON146=== CONT TestScriptTokenEmptyCommand147=== CONT TestScriptTokenCachesUntilRefresh148=== CONT TestPathInfoHashCompatibility149=== CONT TestScriptTokenEmptyToken150=== CONT TestFileTokenEmpty151=== CONT TestScriptTokenNoExpiryRerunsEveryCall152=== CONT TestStaticToken153=== CONT TestDumpPathWriterError154=== CONT TestEncodeNixBase32WithRealHash155=== CONT TestFileTokenReadsAndCaches156=== CONT TestParsePathInfoJSONMultiplePaths157=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess158=== CONT TestSetClientTLSErrors159=== CONT TestDumpPathSingleFile160=== CONT TestRateLimiterFeedback161=== CONT TestSetClientTLSDoesNotMutateDefaultTransport162=== CONT TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade163=== CONT TestSetClientTLS164=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent165=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer166=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs167--- PASS: TestStreamPushStopsWhenCanceled (0.00s)168=== CONT TestStreamPushStopsOnCancel169=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)170=== CONT TestParsePathInfoJSON171=== CONT TestEncodeNixBase32172=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths173=== RUN TestRateLimiterFeedback/429_enables_limiter174=== CONT TestGetStorePathHash175=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier176=== CONT TestConvertHashToNix32177=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs178--- PASS: TestClientSignaturesByStorePath (0.00s)179=== CONT TestStreamPushIsolatesFailures180=== RUN TestParsePathInfoJSON/Nix_format181=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)182=== RUN TestStreamPushStopsOnCancel/waiting_for_input183=== RUN TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0184=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths185=== RUN TestEncodeNixBase32/test_string_hash186=== PAUSE TestEncodeNixBase32/test_string_hash187=== RUN TestSetClientTLSErrors/missing_cert_file188=== PAUSE TestRateLimiterFeedback/429_enables_limiter189=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon190=== CONT TestPathInfoCACompatibility191=== RUN TestGetStorePathHash/valid_store_path192=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon193=== PAUSE TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0194=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout195=== CONT TestStreamPushGivesUpOnDeadServer196--- PASS: TestStreamPushReportsSkippedPaths (0.00s)197=== CONT TestStreamPushReportsEveryPath198--- PASS: TestScriptTokenEmptyCommand (0.00s)199=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier200=== PAUSE TestParsePathInfoJSON/Nix_format201=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up202=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths203=== RUN TestRateLimiterFeedback/503_enables_limiter204=== RUN TestParsePathInfoJSON/Lix_format205=== RUN TestEncodeNixBase32/empty_input206=== PAUSE TestSetClientTLSErrors/missing_cert_file207=== PAUSE TestRateLimiterFeedback/503_enables_limiter208=== RUN TestSetClientTLSErrors/missing_key_file209=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter210=== CONT TestStreamPushBatchesUnderLoad211=== RUN TestStreamPushBatchesUnderLoad/together212=== PAUSE TestStreamPushBatchesUnderLoad/together213=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time214=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up215=== RUN TestSetClientTLS/rejects_connection_without_client_cert216=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert217=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA218=== RUN TestConvertHashToNix32/SRI_format_to_Nix32219=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA220=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32221=== RUN TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=5222=== RUN TestSetClientTLS/preserves_debug_logging_transport223=== PAUSE TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=5224=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout225=== PAUSE TestGetStorePathHash/valid_store_path226=== CONT TestRetryTimeoutOutlastsMaxRetries227=== RUN TestGetStorePathHash/basename_without_hyphen_should_error228=== CONT TestShellSplit229=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error230=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error231=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths232=== PAUSE TestEncodeNixBase32/empty_input233=== CONT TestDoWithRetry_BodyReplayedViaGetBody234=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input235=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun236=== PAUSE TestParsePathInfoJSON/Lix_format237=== PAUSE TestSetClientTLSErrors/missing_key_file238=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter239=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time240=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier241=== CONT TestTruncatedNARDumpIsNotCompleted242=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot243=== RUN TestParsePathInfoJSON/empty_input244=== RUN TestSetClientTLSErrors/missing_ca_file245=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI246=== RUN TestConvertHashToNix32/already_Nix32_format247=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI248=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512249=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512250=== RUN TestPathInfoCACompatibility/null_ca_field251=== PAUSE TestSetClientTLS/preserves_debug_logging_transport252=== PAUSE TestPathInfoCACompatibility/null_ca_field253=== RUN TestPathInfoCACompatibility/old_string_format_-_text254=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text255=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive256=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive257=== RUN TestPathInfoCACompatibility/new_structured_format_-_text258=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text259=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method260=== PAUSE TestParsePathInfoJSON/empty_input261=== PAUSE TestConvertHashToNix32/already_Nix32_format262=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error263=== CONT TestShellSplitErrors264=== CONT TestUploadMultipart_PartsInParallel265=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter266=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter267=== CONT TestUploadMultipart_ProducerErrorIsNotEOF268=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part269=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier270=== CONT TestStreamPushRequestLine271--- PASS: TestStreamPushReportsSignatures (0.00s)272=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure273=== PAUSE TestSetClientTLSErrors/missing_ca_file274=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot275=== RUN TestParsePathInfoJSON/whitespace_only276=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot277=== RUN TestSetClientTLSErrors/invalid_ca_file278=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot279=== PAUSE TestParsePathInfoJSON/whitespace_only280=== PAUSE TestSetClientTLSErrors/invalid_ca_file281=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error282=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot283=== RUN TestParsePathInfoJSON/invalid_JSON284=== CONT TestFilterOversizedClosures285=== PAUSE TestParsePathInfoJSON/invalid_JSON286=== RUN TestFilterOversizedClosures/no_limit_keeps_everything287=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything288=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped289=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped290=== CONT TestCaseHackSuffix291=== CONT TestResolveStorePath292=== RUN TestFilterOversizedClosures/all_closures_skipped293=== PAUSE TestFilterOversizedClosures/all_closures_skipped294=== CONT TestSupersededNARStillUploadsListing295=== RUN TestSupersededNARStillUploadsListing/small_NAR296=== PAUSE TestSupersededNARStillUploadsListing/small_NAR297=== RUN TestSupersededNARStillUploadsListing/dump_cut_short298=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short299=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails300=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails301=== CONT TestUploadMultipart_SupersededByPeer302=== RUN TestUploadMultipart_SupersededByPeer/exists303=== PAUSE TestUploadMultipart_SupersededByPeer/exists304=== RUN TestUploadMultipart_SupersededByPeer/missing305=== PAUSE TestUploadMultipart_SupersededByPeer/missing306=== CONT TestDoWithRetry_FinalResponseBodyReadable307=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client308=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client309=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client310--- PASS: TestStaticToken (0.00s)311=== CONT TestUploadMultipart_FailedPartBufferNotReused312--- PASS: TestFileTokenMissing (0.00s)313--- PASS: TestEncodeNixBase32WithRealHash (0.00s)314--- PASS: TestDoServerRequestAttachesToken (0.00s)315--- PASS: TestFileTokenReadsAndCaches (0.00s)316--- PASS: TestFileTokenEmpty (0.00s)317--- PASS: TestScriptTokenScriptFails (0.01s)318--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.01s)319--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)320--- PASS: TestScriptTokenEmptyToken (0.01s)321--- PASS: TestStreamPushIsolatesFailures (0.00s)322=== RUN TestConvertHashToNix32/invalid_format323=== PAUSE TestConvertHashToNix32/invalid_format324=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error325=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part326=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica327=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method328=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot329=== CONT TestDumpPathMatchesNix330=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client331--- PASS: TestStreamPushReportsEveryPath (0.00s)332=== CONT TestPartSizeForNAR333=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry334--- PASS: TestShellSplit (0.00s)335=== RUN TestPartSizeForNAR/zero_stays_at_minimum336=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot337=== CONT TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0338=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot339--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)340=== CONT TestRegisterUploadedObjectReusesConnections341=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken342=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary343--- PASS: TestShellSplitErrors (0.00s)344=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum345=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken346=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary347--- PASS: TestScriptTokenBadJSON (0.02s)348--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)349=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs350=== CONT TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=5351=== RUN TestPartSizeForNAR/small_stays_at_minimum352=== PAUSE TestPartSizeForNAR/small_stays_at_minimum353=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum354=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum355=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts356=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts357=== RUN TestPartSizeForNAR/1_TiB358=== PAUSE TestPartSizeForNAR/1_TiB359=== RUN TestPartSizeForNAR/5_TiB_S3_max_object360--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)361=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout362=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object363=== RUN TestPartSizeForNAR/capped_at_5_GiB364=== PAUSE TestPartSizeForNAR/capped_at_5_GiB365=== CONT TestEncodeNixBase32/empty_input366=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths367=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths368--- PASS: TestResolveStorePath (0.00s)369--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)370 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)371 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)372=== CONT TestEncodeNixBase32/test_string_hash373=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon374=== CONT TestStreamPushBatchesUnderLoad/together375--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)376--- PASS: TestEncodeNixBase32 (0.01s)377 --- PASS: TestEncodeNixBase32/empty_input (0.00s)378 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)379=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI380=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time381=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512382=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)383=== CONT TestSetClientTLS/preserves_debug_logging_transport384=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA385=== CONT TestSetClientTLS/rejects_connection_without_client_cert386--- PASS: TestPathInfoHashCompatibility (0.01s)387 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)388 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)389 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)390 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)391=== CONT TestRateLimiterFeedback/503_enables_limiter392--- PASS: TestStreamPushBatchesUnderLoad (0.00s)393 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)394 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)395=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter396--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.02s)397=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter398--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.02s)399=== CONT TestRateLimiterFeedback/429_enables_limiter400--- PASS: TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade (0.02s)401 --- PASS: TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0 (0.00s)402 --- PASS: TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=5 (0.01s)403--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)404=== CONT TestSetClientTLSErrors/missing_ca_file405=== CONT TestSetClientTLSErrors/invalid_ca_file406=== CONT TestSetClientTLSErrors/missing_key_file407=== CONT TestSetClientTLSErrors/missing_cert_file408=== CONT TestParsePathInfoJSON/Nix_format409=== CONT TestParsePathInfoJSON/Lix_format410=== CONT TestParsePathInfoJSON/whitespace_only411=== CONT TestParsePathInfoJSON/empty_input412=== CONT TestParsePathInfoJSON/invalid_JSON413--- PASS: TestParsePathInfoJSON (0.01s)414 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)415 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)416 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)417 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)418 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)419=== CONT TestFilterOversizedClosures/all_closures_skipped420=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped421=== CONT TestFilterOversizedClosures/no_limit_keeps_everything422=== CONT TestSupersededNARStillUploadsListing/small_NAR423=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails424=== CONT TestSupersededNARStillUploadsListing/dump_cut_short425--- PASS: TestFilterOversizedClosures (0.00s)426 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)427 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)428 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)429--- PASS: TestSetClientTLSErrors (0.04s)430 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)431 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)432 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)433 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)434=== CONT TestUploadMultipart_SupersededByPeer/missing435--- PASS: TestDumpPathSingleFile (0.07s)436=== CONT TestUploadMultipart_SupersededByPeer/exists437=== CONT TestConvertHashToNix32/invalid_format438=== CONT TestConvertHashToNix32/already_Nix32_format439=== CONT TestConvertHashToNix32/SRI_format_to_Nix32440=== CONT TestGetStorePathHash/basename_without_hyphen_should_error441--- PASS: TestConvertHashToNix32 (0.01s)442 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)443 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)444 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)445=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error446=== CONT TestGetStorePathHash/valid_store_path447=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error448--- PASS: TestGetStorePathHash (0.01s)449 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)450 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)451 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)452 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)453=== CONT TestPathInfoCACompatibility/old_string_format_-_text454=== CONT TestPathInfoCACompatibility/new_structured_format_-_text455=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method456=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive457=== CONT TestPathInfoCACompatibility/null_ca_field458=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier459--- PASS: TestScriptTokenCachesUntilRefresh (0.07s)460=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client461--- PASS: TestPathInfoCACompatibility (0.01s)462 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)463 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)464 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)465 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)466 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)467=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client468=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up469=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier470=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part471=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary472=== CONT TestPartSizeForNAR/1_TiB473--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)474 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)475 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)476=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot477=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot478=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot479=== CONT TestPartSizeForNAR/capped_at_5_GiB480=== CONT TestPartSizeForNAR/5_TiB_S3_max_object481=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum482=== CONT TestPartSizeForNAR/zero_stays_at_minimum483=== CONT TestPartSizeForNAR/small_stays_at_minimum484=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts485=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot486=== CONT TestStreamPushStopsOnCancel/waiting_for_input487--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.07s)488=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken489--- PASS: TestSetClientTLS (0.01s)490 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.03s)491 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.05s)492 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.06s)493--- PASS: TestCaseHackSuffix (0.08s)494--- PASS: TestPartSizeForNAR (0.00s)495 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)496 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)497 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)498 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)499 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)500 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)501 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)502--- PASS: TestRateLimiterFeedback (0.01s)503 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.03s)504 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.02s)505 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.04s)506 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.04s)507--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.02s)508 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.01s)509 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.01s)510 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.00s)511 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.01s)512 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.01s)513--- PASS: TestStreamPushRequestLine (0.10s)514--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.00s)515 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.04s)516 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.05s)517--- PASS: TestStreamPushStopsOnCancel (0.01s)518 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)519 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.05s)520 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.06s)521 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.05s)522 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.05s)523 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.06s)524--- PASS: TestDumpPathWriterError (0.17s)525--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.17s)526--- PASS: TestDumpPathMatchesNix (0.22s)527--- PASS: TestRegisterUploadedObjectReusesConnections (0.23s)528--- PASS: TestTruncatedNARDumpIsNotCompleted (0.41s)529--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.66s)530--- PASS: TestUploadMultipart_PartsInParallel (0.67s)531--- PASS: TestSupersededNARStillUploadsListing (0.00s)532 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.04s)533 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.04s)534 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.67s)535--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.01s)536--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (2.00s)537--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.01s)538 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.07s)539 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.21s)540PASS541Running server tests...542The files belonging to this database system will be owned by user "_tribuchetbld7".543This user must also own the server process.544545The database cluster will be initialized with locale "C".546The default database encoding has accordingly been set to "SQL_ASCII".547The default text search configuration will be set to "english".548549Data page checksums are enabled.550551creating directory /private/var/tb/7/scratch/be18d57bca741e73/build/postgres4036276622/data ... ok552creating subdirectories ... ok553selecting dynamic shared memory implementation ... posix554selecting default "max_connections" ... 100555selecting default "shared_buffers" ... 128MB556selecting default time zone ... UTC557creating configuration files ... ok558running bootstrap script ... ok559performing post-bootstrap initialization ... ok560syncing data to disk ... ok561562initdb: warning: enabling "trust" authentication for local connections563initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.564565Success. You can now start the database server using:566567 pg_ctl -D /private/var/tb/7/scratch/be18d57bca741e73/build/postgres4036276622/data -l logfile start568569/private/var/tb/7/scratch/be18d57bca741e73/build/postgres4036276622:5432 - no response5702026-10-09 18:06:26.586 UTC [64684] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5712026-10-09 18:06:26.586 UTC [64684] LOG: listening on Unix socket "/private/var/tb/7/scratch/be18d57bca741e73/build/postgres4036276622/.s.PGSQL.5432"5722026-10-09 18:06:26.588 UTC [64691] LOG: database system was shut down at 2026-10-09 18:06:26 UTC5732026-10-09 18:06:26.589 UTC [64684] LOG: database system is ready to accept connections574/private/var/tb/7/scratch/be18d57bca741e73/build/postgres4036276622:5432 - accepting connections575{"timestamp":"2026-10-09T18:06:26.805594Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"a2ba28ae-2840-497f-b09c-58de7fc4b47b","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(3)"}576=== RUN TestService_AuthMiddleware577=== PAUSE TestService_AuthMiddleware578=== RUN TestService_AuthMiddleware_MTLSProxyHeader579=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader580=== RUN TestService_AuthMiddleware_MTLSBoundSubjects581=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects582=== RUN TestService_ReadAuthMiddleware583=== PAUSE TestService_ReadAuthMiddleware584=== RUN TestService_AuthMiddleware_OIDC585=== PAUSE TestService_AuthMiddleware_OIDC586=== RUN TestService_RequireScope_OIDC587=== PAUSE TestService_RequireScope_OIDC588=== RUN TestService_ReadScope_PublicByDefault589=== PAUSE TestService_ReadScope_PublicByDefault590=== RUN TestCacheConfigHandler591=== PAUSE TestCacheConfigHandler592=== RUN TestCacheStatsHandler593=== PAUSE TestCacheStatsHandler594=== RUN TestClientCADerivations595=== PAUSE TestClientCADerivations596=== RUN TestClientErrorHandling597=== PAUSE TestClientErrorHandling598=== RUN TestClientIntegration599=== PAUSE TestClientIntegration600=== RUN TestClientMultipleUploads601=== PAUSE TestClientMultipleUploads602=== RUN TestClientWithDependencies603=== PAUSE TestClientWithDependencies604=== RUN TestClientSharedPathCommittedMidPush605=== PAUSE TestClientSharedPathCommittedMidPush606=== RUN TestPinProtectsFromGC607=== PAUSE TestPinProtectsFromGC608=== RUN TestClientPushesUseOnePush609=== PAUSE TestClientPushesUseOnePush610=== RUN TestClientFallsBackToClosures611=== PAUSE TestClientFallsBackToClosures612=== RUN TestDeleteClosuresRacingPins613=== PAUSE TestDeleteClosuresRacingPins614=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock615=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock616=== RUN TestResolveDBConnectionString617=== PAUSE TestResolveDBConnectionString618=== RUN TestConnectWaitsForAPeerMigration619=== PAUSE TestConnectWaitsForAPeerMigration620=== RUN TestConnectSerialisesConcurrentMigrations621=== PAUSE TestConnectSerialisesConcurrentMigrations622=== RUN TestLeadElectsOneAndHandsOver623=== PAUSE TestLeadElectsOneAndHandsOver624=== RUN TestLeadIncumbentWinsAfterRestart6252026/10/09 18:06:27 INFO lead: acquired remote=192.0.2.1:12346262026/10/09 18:06:27 INFO lead: released remote=192.0.2.1:12346272026/10/09 18:06:27 INFO lead: acquired remote=192.0.2.1:12346282026/10/09 18:06:28 INFO lead: released remote=192.0.2.1:1234629--- PASS: TestLeadIncumbentWinsAfterRestart (1.93s)630=== RUN TestLeadIncumbentAnnouncesAtOnce631=== PAUSE TestLeadIncumbentAnnouncesAtOnce632=== RUN TestLeadEndsOnShutdown633=== PAUSE TestLeadEndsOnShutdown634=== RUN TestLeadEndsWhenItsConnectionHangs6352026/10/09 18:06:29 INFO lead: acquired remote=192.0.2.1:12346362026-10-09 18:06:30.205 UTC [64727] FATAL: terminating connection due to administrator command6372026/10/09 18:06:30 INFO lead: acquired remote=192.0.2.1:12346382026/10/09 18:06:31 WARN lead: lock connection lost error="timeout: context deadline exceeded"6392026/10/09 18:06:31 INFO lead: released remote=192.0.2.1:12346402026/10/09 18:06:31 INFO lead: released remote=192.0.2.1:1234641--- PASS: TestLeadEndsWhenItsConnectionHangs (2.78s)642=== RUN TestGCAdvisoryLockBlocksConcurrentRun643=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun644=== RUN TestGCBugBareHashReferences645=== PAUSE TestGCBugBareHashReferences646=== RUN TestGCMetrics647=== PAUSE TestGCMetrics648=== RUN TestPushDedupSurvivesConcurrentGC649=== PAUSE TestPushDedupSurvivesConcurrentGC650=== RUN TestDeduplicatedObjectsRecordedAsPending651=== PAUSE TestDeduplicatedObjectsRecordedAsPending652=== RUN TestGCSweepSkipsPendingObjects653=== PAUSE TestGCSweepSkipsPendingObjects654=== RUN TestTombstonedObjectOfferedWithoutWaiting655=== PAUSE TestTombstonedObjectOfferedWithoutWaiting656=== RUN TestGCSweepDeliversEachKeyOnce657=== PAUSE TestGCSweepDeliversEachKeyOnce658=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection659=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection660=== RUN TestForceGCDuringPushOffersSweptObject661=== PAUSE TestForceGCDuringPushOffersSweptObject662=== RUN TestFailedS3DeleteKeepsTombstone663=== PAUSE TestFailedS3DeleteKeepsTombstone664=== RUN TestSweepSkipsRowsLockedByPush665=== PAUSE TestSweepSkipsRowsLockedByPush666=== RUN TestRegisterCompletedObjectNeedsPendingRow667=== PAUSE TestRegisterCompletedObjectNeedsPendingRow668=== RUN TestGetExistingObjectsLocksRows669=== PAUSE TestGetExistingObjectsLocksRows670=== RUN TestSweepRechecksPendingAfterLocking671=== PAUSE TestSweepRechecksPendingAfterLocking672=== RUN TestPushWaitsForSweepHoldingRow673=== PAUSE TestPushWaitsForSweepHoldingRow674=== RUN TestCommitRacingPendingCleanupKeepsObjects675=== PAUSE TestCommitRacingPendingCleanupKeepsObjects676=== RUN TestGCEndsOnShutdown677=== PAUSE TestGCEndsOnShutdown678=== RUN TestGCTaskStore_StartNew679=== PAUSE TestGCTaskStore_StartNew680=== RUN TestGCTaskStore_DeduplicateSameParams681=== PAUSE TestGCTaskStore_DeduplicateSameParams682=== RUN TestGCTaskStore_ConflictDifferentParams683=== PAUSE TestGCTaskStore_ConflictDifferentParams684=== RUN TestGCTaskStore_GetEmpty685=== PAUSE TestGCTaskStore_GetEmpty686=== RUN TestGCTaskStore_GetReturnsLatest687=== PAUSE TestGCTaskStore_GetReturnsLatest688=== RUN TestGCTaskStore_CompletedAllowsNewTask689=== PAUSE TestGCTaskStore_CompletedAllowsNewTask690=== RUN TestGCTaskStore_PhaseUpdates691=== PAUSE TestGCTaskStore_PhaseUpdates692=== RUN TestGCTaskStore_Fail693=== PAUSE TestGCTaskStore_Fail694=== RUN TestGracefulShutdownDrainsInflight695=== PAUSE TestGracefulShutdownDrainsInflight696=== RUN TestService_healthCheckHandler697=== PAUSE TestService_healthCheckHandler698=== RUN TestService_readinessHandler699=== PAUSE TestService_readinessHandler700=== RUN TestGenerateLandingPage701=== PAUSE TestGenerateLandingPage702=== RUN TestChildrenInheritRaisedFileLimit703=== PAUSE TestChildrenInheritRaisedFileLimit704=== RUN TestCacheConfigHandlerMaxNarSize705=== PAUSE TestCacheConfigHandlerMaxNarSize706=== RUN TestCreatePendingClosureRejectsOversizedNAR707=== PAUSE TestCreatePendingClosureRejectsOversizedNAR708=== RUN TestNARDeduplicationMetadataUploadBug709=== PAUSE TestNARDeduplicationMetadataUploadBug710=== RUN TestMetricsInventory711=== PAUSE TestMetricsInventory712=== RUN TestMetricsCommit713=== PAUSE TestMetricsCommit714=== RUN TestService_NativeMTLS715=== PAUSE TestService_NativeMTLS716=== RUN TestServerTLSConfig717=== PAUSE TestServerTLSConfig718=== RUN TestMultipartCleanup719=== PAUSE TestMultipartCleanup720=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded721=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded722=== RUN TestPendingCleanupUsesOneCutoff723=== PAUSE TestPendingCleanupUsesOneCutoff724=== RUN TestPendingClosureFailureTracksEveryUpload725=== PAUSE TestPendingClosureFailureTracksEveryUpload726=== RUN TestPendingClosureFailureAbortsItsUploads727=== PAUSE TestPendingClosureFailureAbortsItsUploads728=== RUN TestObjectStatsTrigger729=== PAUSE TestObjectStatsTrigger730=== RUN TestObjectStatsLargeCommit731=== PAUSE TestObjectStatsLargeCommit732=== RUN TestReconnectLeavesObjectsUnlocked733=== PAUSE TestReconnectLeavesObjectsUnlocked734=== RUN TestOrphanedObjectsGC735=== PAUSE TestOrphanedObjectsGC736=== RUN TestOrphanedObjectsGCStressTest737=== PAUSE TestOrphanedObjectsGCStressTest738=== RUN TestCreatePin_ReservedPins739=== PAUSE TestCreatePin_ReservedPins740=== RUN TestConcurrentPinUpdatesAgree741=== PAUSE TestConcurrentPinUpdatesAgree742=== RUN TestCreatePinRejectsBadInput743=== PAUSE TestCreatePinRejectsBadInput744=== RUN TestDeletePinKeepsRowWhenS3Fails745=== PAUSE TestDeletePinKeepsRowWhenS3Fails746=== RUN TestPresentReportsOnlyClosureRoots747=== PAUSE TestPresentReportsOnlyClosureRoots748=== RUN TestPresentRefreshesOnlyStaleClosures749=== PAUSE TestPresentRefreshesOnlyStaleClosures750=== RUN TestPresentNotReportedWhileGCDeletesClosure751=== PAUSE TestPresentNotReportedWhileGCDeletesClosure752=== RUN TestParseSingleRange753=== PAUSE TestParseSingleRange754=== RUN TestProxyHeadersOnlyTrustedOnSocket7552026/10/09 18:06:31 INFO Starting HTTP server address=proxy.sock7562026/10/09 18:06:31 INFO Starting HTTP server address=127.0.0.1:649667572026/10/09 18:06:31 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7582026/10/09 18:06:31 INFO Shutdown signal received, draining in-flight requests timeout=10s759--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.15s)760=== RUN TestIsValidCachePath761=== PAUSE TestIsValidCachePath762=== RUN TestReadProxyNarinfo763=== PAUSE TestReadProxyNarinfo764=== RUN TestReadProxyNarinfoAlreadyDecompressed765=== PAUSE TestReadProxyNarinfoAlreadyDecompressed766=== RUN TestReadProxyContentNegotiation767=== PAUSE TestReadProxyContentNegotiation768=== RUN TestReadProxyNarStreaming769=== PAUSE TestReadProxyNarStreaming770=== RUN TestReadProxy404771=== PAUSE TestReadProxy404772=== RUN TestReadProxyInvalidPath773=== PAUSE TestReadProxyInvalidPath774=== RUN TestReadProxyHead775=== PAUSE TestReadProxyHead776=== RUN TestReadProxyOutlastsServerWriteTimeout777=== PAUSE TestReadProxyOutlastsServerWriteTimeout778=== RUN TestReadProxyConditionalGet779=== PAUSE TestReadProxyConditionalGet780=== RUN TestReadProxyRootRedirectsToIndexHTML781=== PAUSE TestReadProxyRootRedirectsToIndexHTML782=== RUN TestReadProxyDisabled783=== PAUSE TestReadProxyDisabled784=== RUN TestReadRedirectNar785=== PAUSE TestReadRedirectNar786=== RUN TestReadRedirectKeepsNarinfoProxied787=== PAUSE TestReadRedirectKeepsNarinfoProxied788=== RUN TestReadProxyRangeRequest789=== PAUSE TestReadProxyRangeRequest790=== RUN TestReadRedirectUsesPublicS3URL791=== PAUSE TestReadRedirectUsesPublicS3URL792=== RUN TestPush_OverlappingRootsStoreOneRowPerKey793=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey794=== RUN TestPush_CompleteCommitsEveryRoot795=== PAUSE TestPush_CompleteCommitsEveryRoot796=== RUN TestPush_RepeatedRootCommitsOnce797=== PAUSE TestPush_RepeatedRootCommitsOnce798=== RUN TestPush_CompleteWaitsForCleanupOfThePush799=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush800=== RUN TestPush_RootsAreLockedInByteOrder801=== PAUSE TestPush_RootsAreLockedInByteOrder802=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit803=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit804=== RUN TestPush_RejectsBadRequests805=== PAUSE TestPush_RejectsBadRequests806=== RUN TestPush_SignsNarinfosOfItsPendingObjects807=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects808=== RUN TestRedundantMultipartUpload809=== PAUSE TestRedundantMultipartUpload810=== RUN TestCompleteMultipartUpload_ErrorButObjectExists811=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists812=== RUN TestCompletedNarNotReofferedAcrossClosures813=== PAUSE TestCompletedNarNotReofferedAcrossClosures814=== RUN TestPresignedUploadRegisteredBeforeCommit815=== PAUSE TestPresignedUploadRegisteredBeforeCommit816=== RUN TestService_Rustfstest817=== PAUSE TestService_Rustfstest818=== RUN TestParseSize819=== PAUSE TestParseSize820=== RUN TestSkippedUploadsHandler821=== PAUSE TestSkippedUploadsHandler822=== RUN TestSystemdListenerNotActivated823--- PASS: TestSystemdListenerNotActivated (0.00s)824=== RUN TestWatchdogBeatsWhenHealthy825--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)826=== RUN TestWatchdogSkipsWhenUnhealthy8272026/10/09 18:06:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8282026/10/09 18:06:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8292026/10/09 18:06:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8302026/10/09 18:06:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8312026/10/09 18:06:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8322026/10/09 18:06:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8332026/10/09 18:06:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8342026/10/09 18:06:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8352026/10/09 18:06:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8362026/10/09 18:06:32 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"837--- PASS: TestWatchdogSkipsWhenUnhealthy (0.21s)838=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle839=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle840=== RUN TestProxyWriteTimeout841=== PAUSE TestProxyWriteTimeout842=== RUN TestPendingClosureWriteTimeout843=== PAUSE TestPendingClosureWriteTimeout844=== RUN TestIsValidUploadKey845=== PAUSE TestIsValidUploadKey846=== RUN TestUploadHandlersRejectInvalidKeys847=== PAUSE TestUploadHandlersRejectInvalidKeys848=== RUN TestUploadHandlersRejectOversizedBody849=== PAUSE TestUploadHandlersRejectOversizedBody850=== RUN TestService_cleanupPendingClosuresHandler851=== PAUSE TestService_cleanupPendingClosuresHandler852=== RUN TestService_createPendingClosureHandler853=== PAUSE TestService_createPendingClosureHandler854=== RUN TestService_verifyS3Integrity855=== PAUSE TestService_verifyS3Integrity856=== RUN TestCompleteMultipartUnregistered857=== PAUSE TestCompleteMultipartUnregistered858=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT859=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT860=== CONT TestReadProxy404861=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT862=== CONT TestIsValidUploadKey863=== RUN TestIsValidUploadKey/narinfo864=== PAUSE TestIsValidUploadKey/narinfo865=== RUN TestIsValidUploadKey/nar_zst866=== PAUSE TestIsValidUploadKey/nar_zst867=== CONT TestPresentNotReportedWhileGCDeletesClosure868=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale869=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale870=== CONT TestService_AuthMiddleware871=== CONT TestCompleteMultipartUnregistered872=== CONT TestService_Rustfstest873=== CONT TestParseSingleRange874=== CONT TestProxyWriteTimeout875=== CONT TestSkippedUploadsHandler876=== CONT TestCompletedNarNotReofferedAcrossClosures877=== CONT TestRedundantMultipartUpload878=== CONT TestUploadHandlersRejectInvalidKeys879=== CONT TestCompleteMultipartUpload_ErrorButObjectExists880=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info881=== CONT TestReadProxyNarinfo882=== CONT TestService_createPendingClosureHandler883=== CONT TestPresentRefreshesOnlyStaleClosures884=== CONT TestService_verifyS3Integrity885=== CONT TestService_cleanupPendingClosuresHandler886=== CONT TestIsValidCachePath887=== RUN TestIsValidCachePath/narinfo888=== CONT TestPush_SignsNarinfosOfItsPendingObjects889=== CONT TestUploadHandlersRejectOversizedBody890=== CONT TestDeletePinKeepsRowWhenS3Fails891=== RUN TestIsValidUploadKey/nar_xz892=== CONT TestPush_RejectsBadRequests893=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh894=== RUN TestParseSingleRange/none895=== RUN TestProxyWriteTimeout/narinfo896=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info897=== PAUSE TestIsValidCachePath/narinfo898=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh899=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars900=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars901=== RUN TestIsValidCachePath/nar_zst902=== PAUSE TestIsValidCachePath/nar_zst903=== RUN TestIsValidCachePath/nar_xz904=== CONT TestRegisterCompletedObjectNeedsPendingRow905=== PAUSE TestIsValidUploadKey/nar_xz906=== PAUSE TestProxyWriteTimeout/narinfo907=== PAUSE TestParseSingleRange/none908=== RUN TestProxyWriteTimeout/1_GiB_nar909=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal910=== RUN TestParseSingleRange/unknown_unit911=== PAUSE TestProxyWriteTimeout/1_GiB_nar912=== RUN TestProxyWriteTimeout/10_GiB_nar913=== PAUSE TestParseSingleRange/unknown_unit914=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal915=== RUN TestIsValidUploadKey/nar_plain916=== PAUSE TestIsValidUploadKey/nar_plain917=== RUN TestIsValidUploadKey/listing9182026/10/09 18:06:32 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000919=== PAUSE TestProxyWriteTimeout/10_GiB_nar920=== RUN TestProxyWriteTimeout/unknown_size921=== PAUSE TestIsValidCachePath/nar_xz922=== RUN TestParseSingleRange/multi-range_ignored923=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key924=== PAUSE TestIsValidUploadKey/listing925=== PAUSE TestProxyWriteTimeout/unknown_size926=== PAUSE TestParseSingleRange/multi-range_ignored927=== RUN TestIsValidCachePath/nar_bz2928=== RUN TestParseSingleRange/malformed_no_dash929=== PAUSE TestIsValidCachePath/nar_bz2930=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key931=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key932=== CONT TestCreatePinRejectsBadInput933=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key934=== PAUSE TestParseSingleRange/malformed_no_dash935=== RUN TestParseSingleRange/malformed_both_empty936=== PAUSE TestParseSingleRange/malformed_both_empty937=== RUN TestParseSingleRange/malformed_end_before_start938=== RUN TestIsValidCachePath/nar_uncompressed939=== RUN TestIsValidUploadKey/build_log940=== PAUSE TestParseSingleRange/malformed_end_before_start941=== PAUSE TestIsValidCachePath/nar_uncompressed942=== RUN TestParseSingleRange/closed943=== RUN TestIsValidCachePath/ls944=== CONT TestDeleteClosuresRacingPins945=== PAUSE TestParseSingleRange/closed946=== PAUSE TestIsValidUploadKey/build_log947=== RUN TestIsValidUploadKey/build_log_home-manager_file948=== PAUSE TestIsValidUploadKey/build_log_home-manager_file949=== PAUSE TestIsValidCachePath/ls950=== RUN TestParseSingleRange/open-ended951=== RUN TestIsValidUploadKey/build_log_plus_in_name952=== PAUSE TestParseSingleRange/open-ended953=== RUN TestParseSingleRange/end_clamped_to_size954=== RUN TestIsValidCachePath/log955=== PAUSE TestParseSingleRange/end_clamped_to_size956=== RUN TestParseSingleRange/suffix957=== PAUSE TestIsValidCachePath/log958=== PAUSE TestParseSingleRange/suffix959=== RUN TestParseSingleRange/suffix_exceeds_size960=== RUN TestIsValidCachePath/realisation961=== PAUSE TestIsValidCachePath/realisation962=== RUN TestIsValidCachePath/nix-cache-info963=== PAUSE TestParseSingleRange/suffix_exceeds_size964=== PAUSE TestIsValidCachePath/nix-cache-info965=== RUN TestParseSingleRange/single_byte966=== PAUSE TestParseSingleRange/single_byte967=== RUN TestParseSingleRange/start_past_EOF968=== RUN TestIsValidCachePath/index.html969=== PAUSE TestParseSingleRange/start_past_EOF970=== PAUSE TestIsValidCachePath/index.html971=== RUN TestParseSingleRange/start_far_past_EOF972=== PAUSE TestIsValidUploadKey/build_log_plus_in_name973=== RUN TestIsValidCachePath/traversal_parent974=== RUN TestIsValidUploadKey/build_log_question_mark975=== PAUSE TestParseSingleRange/start_far_past_EOF976=== PAUSE TestIsValidCachePath/traversal_parent977=== PAUSE TestIsValidUploadKey/build_log_question_mark978=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock979=== RUN TestIsValidUploadKey/build_log_equals980=== RUN TestIsValidCachePath/traversal_in_middle981=== PAUSE TestIsValidCachePath/traversal_in_middle982=== PAUSE TestIsValidUploadKey/build_log_equals983=== RUN TestIsValidCachePath/invalid_char_e984=== RUN TestIsValidUploadKey/realisation985=== PAUSE TestIsValidCachePath/invalid_char_e986=== PAUSE TestIsValidUploadKey/realisation987=== RUN TestIsValidCachePath/invalid_char_u988=== RUN TestIsValidUploadKey/realisation_plus_in_output989=== PAUSE TestIsValidCachePath/invalid_char_u990=== PAUSE TestIsValidUploadKey/realisation_plus_in_output991=== RUN TestIsValidCachePath/random_path992=== PAUSE TestIsValidCachePath/random_path993=== RUN TestIsValidUploadKey/nix-cache-info994=== RUN TestIsValidCachePath/empty995=== PAUSE TestIsValidUploadKey/nix-cache-info996=== PAUSE TestIsValidCachePath/empty997=== RUN TestIsValidCachePath/leading_slash998=== PAUSE TestIsValidCachePath/leading_slash999=== RUN TestIsValidCachePath/wrong_extension1000=== PAUSE TestIsValidCachePath/wrong_extension1001=== RUN TestIsValidCachePath/short_hash1002=== PAUSE TestIsValidCachePath/short_hash1003=== CONT TestClientFallsBackToClosures1004=== RUN TestIsValidUploadKey/index.html1005--- PASS: TestSkippedUploadsHandler (0.04s)1006=== PAUSE TestIsValidUploadKey/index.html1007=== CONT TestGetExistingObjectsLocksRows1008=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1009=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1010=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1011=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1012=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1013=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1014=== RUN TestIsValidUploadKey/traversal1015=== PAUSE TestIsValidUploadKey/traversal1016=== RUN TestIsValidUploadKey/traversal_nar1017=== PAUSE TestIsValidUploadKey/traversal_nar1018=== RUN TestIsValidUploadKey/absolute1019=== PAUSE TestIsValidUploadKey/absolute1020=== RUN TestIsValidUploadKey/empty_key1021=== PAUSE TestIsValidUploadKey/empty_key1022=== RUN TestIsValidUploadKey/unknown_type1023=== PAUSE TestIsValidUploadKey/unknown_type1024=== CONT TestCreatePin_ReservedPins1025=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1026=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1027=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1028=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1029=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1030=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1031=== CONT TestOrphanedObjectsGCStressTest10322026/10/09 18:06:32 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:64969/oidc10332026/10/09 18:06:32 INFO Received uploads request method=POST path=/api/pending_closures1034--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.77s)1035=== CONT TestPresentReportsOnlyClosureRoots10362026/10/09 18:06:33 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1037--- PASS: TestService_AuthMiddleware (1.13s)1038=== CONT TestPinProtectsFromGC10392026/10/09 18:06:33 WARN Rate limiter enabled after throttle name=s3-test rate=510402026/10/09 18:06:33 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."10412026/10/09 18:06:33 WARN Rate limiter backed off name=s3-test rate=510422026/10/09 18:06:33 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."1043--- PASS: TestReadProxy404 (1.29s)1044=== CONT TestFailedS3DeleteKeepsTombstone10452026/10/09 18:06:33 INFO Received push request method=POST path=/api/pushes10462026/10/09 18:06:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10472026/10/09 18:06:33 INFO Signed narinfos id=1 count=110482026/10/09 18:06:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10492026/10/09 18:06:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10502026/10/09 18:06:33 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10512026/10/09 18:06:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10522026/10/09 18:06:33 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10532026/10/09 18:06:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10542026/10/09 18:06:33 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110552026/10/09 18:06:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10562026/10/09 18:06:33 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1057--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.48s)1058=== CONT TestForceGCDuringPushOffersSweptObject1059=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1060=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1061=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1062=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1063=== CONT TestReconnectLeavesObjectsUnlocked1064--- PASS: TestService_Rustfstest (1.93s)1065=== CONT TestClientSharedPathCommittedMidPush10662026/10/09 18:06:34 INFO Received create pin request method=POST path=/api/pins/app10672026/10/09 18:06:34 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo10682026/10/09 18:06:34 INFO Received delete pin request method=DELETE path=/api/pins/app10692026/10/09 18:06:34 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket9/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"10702026/10/09 18:06:34 INFO Received delete pin request method=DELETE path=/api/pins/app10712026/10/09 18:06:34 INFO Deleted pin name=app1072--- PASS: TestDeletePinKeepsRowWhenS3Fails (2.21s)1073=== CONT TestObjectStatsLargeCommit10742026/10/09 18:06:34 INFO Received cleanup request method=DELETE path=/api/pending_closures10752026/10/09 18:06:34 INFO Aborted multipart uploads count=0 kept=010762026/10/09 18:06:34 INFO Received uploads request method=POST path=/api/pending_closures10772026/10/09 18:06:34 INFO Received cleanup request method=DELETE path=/api/pending_closures10782026/10/09 18:06:34 INFO Aborted multipart uploads count=1 kept=010792026/10/09 18:06:34 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10802026-10-09 18:06:34.743 UTC [64802] ERROR: Closure does not exist: id=110812026-10-09 18:06:34.743 UTC [64802] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE10822026-10-09 18:06:34.743 UTC [64802] STATEMENT: -- name: CommitPendingClosure :one1083 SELECT commit_pending_closure($1::bigint)::bigint1084 1085--- PASS: TestService_cleanupPendingClosuresHandler (2.72s)1086=== CONT TestSweepSkipsRowsLockedByPush1087--- PASS: TestRegisterCompletedObjectNeedsPendingRow (2.84s)1088=== CONT TestClientWithDependencies10892026/10/09 18:06:35 INFO Received uploads request method=POST path=/api/pending_closures10902026/10/09 18:06:35 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1091--- PASS: TestReadProxyNarinfo (3.26s)1092=== CONT TestObjectStatsTrigger10932026/10/09 18:06:35 INFO Received uploads request method=POST path=/api/pending_closures10942026/10/09 18:06:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10952026/10/09 18:06:35 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1096--- PASS: TestCompleteMultipartUnregistered (3.69s)1097=== CONT TestOrphanedObjectsGC10982026/10/09 18:06:36 INFO Received uploads request method=POST path=/api/pending_closures10992026/10/09 18:06:36 INFO Received uploads request method=POST path=/api/pending_closures11002026/10/09 18:06:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11012026/10/09 18:06:36 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LmYzOTY4NGY2LWFkNmUtNDVkOC1hMGFmLWVmMTdmYTNlZGVlYXgxNzkxNTY5MTk2MjY2ODYwMDAw11022026/10/09 18:06:36 INFO Received uploads request method=POST path=/api/pending_closures11032026/10/09 18:06:36 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11042026/10/09 18:06:36 INFO Received create pin request method=POST path=/api/pins/deploy11052026/10/09 18:06:36 INFO Uploading a541yzna9fllpnmb6i4bcp0iry8iikf6-shared-dep (136B)11062026/10/09 18:06:36 INFO Uploading pn02jpkxzgzwdxpglvgcswf22x15z6g0-a (256B)11072026/10/09 18:06:36 INFO Received create pin request method=POST path=/api/pins/deploy11082026/10/09 18:06:36 INFO Received create pin request method=POST path=/api/pins/deploy11092026/10/09 18:06:36 INFO Received create pin request method=POST path=/api/pins/deploy11102026/10/09 18:06:36 INFO Received create pin request method=POST path=/api/pins/deploy11112026/10/09 18:06:36 INFO Received create pin request method=POST path=/api/pins/deploy11122026/10/09 18:06:36 WARN Failed to register uploaded object key=22phbmwylclm8r1yyg5rjjij38j8ldiq.ls error="server returned 404: 404 page not found\n"11132026/10/09 18:06:36 INFO Received create pin request method=POST path=/api/pins/deploy11142026/10/09 18:06:36 INFO Received create pin request method=POST path=/api/pins/deploy11152026/10/09 18:06:36 INFO Received create pin request method=POST path=/api/pins/deploy11162026/10/09 18:06:36 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11172026/10/09 18:06:36 WARN Failed to register uploaded object key=nar/1dmpaykrgaknal2yl67pg3qgfgwyifv6iv27vsxzyd13h67vc5jd.nar.zst error="server returned 404: 404 page not found\n"11182026/10/09 18:06:36 WARN Failed to register uploaded object key=a541yzna9fllpnmb6i4bcp0iry8iikf6.ls error="server returned 404: 404 page not found\n"11192026/10/09 18:06:36 WARN Failed to register uploaded object key=pn02jpkxzgzwdxpglvgcswf22x15z6g0.ls error="server returned 404: 404 page not found\n"11202026/10/09 18:06:36 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11212026/10/09 18:06:36 INFO Signed narinfos id=1 count=211222026/10/09 18:06:36 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11232026/10/09 18:06:36 INFO Signed narinfos id=2 count=211242026/10/09 18:06:36 INFO Uploading 4 narinfos11252026/10/09 18:06:36 WARN Failed to register uploaded object key=pn02jpkxzgzwdxpglvgcswf22x15z6g0.narinfo error="server returned 404: 404 page not found\n"11262026/10/09 18:06:36 WARN Failed to register uploaded object key=a541yzna9fllpnmb6i4bcp0iry8iikf6.narinfo error="server returned 404: 404 page not found\n"11272026/10/09 18:06:36 WARN Failed to register uploaded object key=22phbmwylclm8r1yyg5rjjij38j8ldiq.narinfo error="server returned 404: 404 page not found\n"11282026/10/09 18:06:36 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11292026/10/09 18:06:36 WARN Failed to register uploaded object key=a541yzna9fllpnmb6i4bcp0iry8iikf6.narinfo error="server returned 404: 404 page not found\n"11302026/10/09 18:06:36 INFO Completed upload id=1 objects=6 duration=10.845458ms11312026/10/09 18:06:36 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11322026/10/09 18:06:36 INFO Completed upload id=2 objects=6 duration=503.166µs11332026/10/09 18:06:36 INFO Upload complete. (246ms)1134=== NAME TestClientFallsBackToClosures1135 client_pushes_test.go:112: Retrieved narinfo from S3:1136 StorePath: /private/var/tb/7/scratch/be18d57bca741e73/build/TestClientFallsBackToClosures3870975579/001/store/a541yzna9fllpnmb6i4bcp0iry8iikf6-shared-dep1137 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1138 Compression: zstd1139 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821140 NarSize: 1361141 References: 1142 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n11432026/10/09 18:06:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1144 client_pushes_test.go:112: Retrieved narinfo from S3:1145 StorePath: /private/var/tb/7/scratch/be18d57bca741e73/build/TestClientFallsBackToClosures3870975579/001/store/pn02jpkxzgzwdxpglvgcswf22x15z6g0-a1146 URL: nar/1dmpaykrgaknal2yl67pg3qgfgwyifv6iv27vsxzyd13h67vc5jd.nar.zst1147 Compression: zstd1148 NarHash: sha256:1dmpaykrgaknal2yl67pg3qgfgwyifv6iv27vsxzyd13h67vc5jd1149 NarSize: 2561150 References: /private/var/tb/7/scratch/be18d57bca741e73/build/TestClientFallsBackToClosures3870975579/001/store/a541yzna9fllpnmb6i4bcp0iry8iikf6-shared-dep1151 CA: text:sha256:0czp17p1f12f90sabhfq1667dfkjf09rdrf9a0c0bfsx3pnv6rvb11522026/10/09 18:06:36 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LmYzOTY4NGY2LWFkNmUtNDVkOC1hMGFmLWVmMTdmYTNlZGVlYXgxNzkxNTY5MTk2MjY2ODYwMDAw error="Delete \"http://localhost:64949/bucket18/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LmYzOTY4NGY2LWFkNmUtNDVkOC1hMGFmLWVmMTdmYTNlZGVlYXgxNzkxNTY5MTk2MjY2ODYwMDAw\": injected: abort refused"1153 client_pushes_test.go:112: Retrieved narinfo from S3:11542026/10/09 18:06:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1155 StorePath: /private/var/tb/7/scratch/be18d57bca741e73/build/TestClientFallsBackToClosures3870975579/001/store/22phbmwylclm8r1yyg5rjjij38j8ldiq-b1156 URL: nar/1dmpaykrgaknal2yl67pg3qgfgwyifv6iv27vsxzyd13h67vc5jd.nar.zst11572026/10/09 18:06:36 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LmYzOTY4NGY2LWFkNmUtNDVkOC1hMGFmLWVmMTdmYTNlZGVlYXgxNzkxNTY5MTk2MjY2ODYwMDAw1158 Compression: zstd1159 NarHash: sha256:1dmpaykrgaknal2yl67pg3qgfgwyifv6iv27vsxzyd13h67vc5jd1160 NarSize: 2561161 References: /private/var/tb/7/scratch/be18d57bca741e73/build/TestClientFallsBackToClosures3870975579/001/store/a541yzna9fllpnmb6i4bcp0iry8iikf6-shared-dep1162 CA: text:sha256:0czp17p1f12f90sabhfq1667dfkjf09rdrf9a0c0bfsx3pnv6rvb11632026/10/09 18:06:36 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LmYzOTY4NGY2LWFkNmUtNDVkOC1hMGFmLWVmMTdmYTNlZGVlYXgxNzkxNTY5MTk2MjY2ODYwMDAw parts=111642026/10/09 18:06:36 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LjFjMjZhNTAwLTA5YjMtNGU4NC1iZjcwLTg3ZGZjZDVhZjdjOXgxNzkxNTY5MTk1MjU0MTE4MDAw parts=121165--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (4.76s)1166=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection11672026/10/09 18:06:36 INFO Received uploads request method=POST path=/api/pending_closures11682026/10/09 18:06:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11692026/10/09 18:06:36 INFO Received create pin request method=POST path=/api/pins/deploy1170--- PASS: TestPresentRefreshesOnlyStaleClosures (4.84s)1171=== CONT TestClientMultipleUploads1172--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.85s)1173=== CONT TestGCSweepDeliversEachKeyOnce11742026/10/09 18:06:36 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LmFjM2MwM2QxLTMyYzItNGI1MC1hMjU3LTFkMjJkOWQ3NTAxNngxNzkxNTY5MTk1NDY2MTQ4MDAw parts=1011752026/10/09 18:06:36 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo1176--- PASS: TestClientFallsBackToClosures (4.82s)1177=== CONT TestPendingClosureFailureTracksEveryUpload11782026/10/09 18:06:36 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1179=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1180=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1181=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1182=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1183=== CONT TestTombstonedObjectOfferedWithoutWaiting11842026/10/09 18:06:36 INFO Completed upload id=1 objects=2 duration=15.82675ms11852026/10/09 18:06:36 INFO Received uploads request method=POST path=/api/pending_closures11862026/10/09 18:06:36 INFO Received uploads request method=POST path=/api/pending_closures1187--- PASS: TestCreatePinRejectsBadInput (4.89s)1188=== CONT TestClientPushesUseOnePush11892026/10/09 18:06:36 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11902026/10/09 18:06:36 WARN Found objects in DB but missing from S3, will re-upload count=111912026/10/09 18:06:36 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete11922026/10/09 18:06:36 INFO Completed upload id=3 objects=2 duration=715.875µs1193--- PASS: TestService_verifyS3Integrity (4.97s)1194=== CONT TestPendingClosureFailureAbortsItsUploads1195--- PASS: TestGetExistingObjectsLocksRows (5.05s)1196=== CONT TestClientIntegration11972026/10/09 18:06:37 INFO Received uploads request method=POST path=/api/pending_closures11982026/10/09 18:06:37 INFO Received uploads request method=POST path=/api/pending_closures1199--- PASS: TestDeleteClosuresRacingPins (5.46s)1200=== CONT TestGCSweepSkipsPendingObjects1201=== RUN TestPush_RejectsBadRequests/no_roots1202=== PAUSE TestPush_RejectsBadRequests/no_roots1203=== RUN TestPush_RejectsBadRequests/no_objects1204=== PAUSE TestPush_RejectsBadRequests/no_objects1205=== RUN TestPush_RejectsBadRequests/bad_root1206=== PAUSE TestPush_RejectsBadRequests/bad_root1207=== RUN TestPush_RejectsBadRequests/root_not_in_objects1208=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1209=== CONT TestClientCADerivations12102026/10/09 18:06:37 INFO Received uploads request method=POST path=/api/pending_closures12112026/10/09 18:06:37 INFO Received uploads request method=POST path=/api/pending_closures12122026/10/09 18:06:37 INFO Received uploads request method=POST path=/api/pending_closures12132026/10/09 18:06:38 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12142026/10/09 18:06:38 WARN Refused reserved pin name=worker-x86_64-linux12152026/10/09 18:06:38 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12162026/10/09 18:06:38 INFO Received create pin request method=POST path=/api/pins/my-app12172026/10/09 18:06:38 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1218--- PASS: TestCreatePin_ReservedPins (6.16s)1219=== CONT TestDeduplicatedObjectsRecordedAsPending12202026/10/09 18:06:39 INFO Received uploads request method=POST path=/api/pending_closures12212026/10/09 18:06:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12222026/10/09 18:06:39 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LmVjZTg5M2E3LWY3NDgtNGJjMi04MGM2LWFhZjdiODJiNzU2N3gxNzkxNTY5MTk3NDYyNjY1MDAw parts=1212232026/10/09 18:06:39 INFO Received uploads request method=POST path=/api/pending_closures12242026/10/09 18:06:39 INFO Aborted multipart uploads count=0 kept=012252026/10/09 18:06:39 INFO Received uploads request method=POST path=/api/pending_closures12262026/10/09 18:06:39 WARN Force mode enabled - objects will be deleted immediately without grace period12272026/10/09 18:06:39 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12282026/10/09 18:06:39 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1229--- PASS: TestFailedS3DeleteKeepsTombstone (6.47s)1230=== CONT TestClientErrorHandling1231=== RUN TestClientErrorHandling/InvalidStorePath1232=== PAUSE TestClientErrorHandling/InvalidStorePath1233=== RUN TestClientErrorHandling/InvalidAuthToken1234=== PAUSE TestClientErrorHandling/InvalidAuthToken1235=== RUN TestClientErrorHandling/ServerNotAvailable1236=== PAUSE TestClientErrorHandling/ServerNotAvailable1237=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1238=== NAME TestPinProtectsFromGC1239 client_integration_test.go:867: Pinned store path: /private/var/tb/7/scratch/be18d57bca741e73/build/TestPinProtectsFromGC472297162/001/store/xy4g0g06chvpi0a8f3apif6pm8kj720m-pinned-file.txt1240 client_integration_test.go:868: Unpinned store path: /private/var/tb/7/scratch/be18d57bca741e73/build/TestPinProtectsFromGC472297162/001/store/z3l2qdy21q4m629fpdv54955p1n138cw-unpinned-file.txt12412026/10/09 18:06:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12422026/10/09 18:06:39 INFO Received push request method=POST path=/api/pushes1243--- PASS: TestReconnectLeavesObjectsUnlocked (6.51s)1244=== CONT TestGCMetrics12452026/10/09 18:06:40 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LmVhMDg4ODc5LTE1YzktNGM0MS05ODY2LTEyZTgxNzY2ZDk2M3gxNzkxNTY5MTk3OTM1NTQwMDAw parts=1012462026/10/09 18:06:40 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12472026/10/09 18:06:40 INFO Uploading xy4g0g06chvpi0a8f3apif6pm8kj720m-pinned-file.txt (128B)12482026/10/09 18:06:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12492026/10/09 18:06:40 INFO Completed upload id=1 objects=2 duration=18.144458ms12502026/10/09 18:06:40 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012512026/10/09 18:06:40 INFO Received uploads request method=POST path=/api/pending_closures12522026/10/09 18:06:40 WARN Failed to register uploaded object key=xy4g0g06chvpi0a8f3apif6pm8kj720m.ls error="server returned 404: 404 page not found\n"12532026/10/09 18:06:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12542026/10/09 18:06:40 INFO Starting cleanup of old closures method=DELETE path=/api/closures12552026/10/09 18:06:40 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"12562026/10/09 18:06:40 INFO Signed narinfos id=1 count=112572026/10/09 18:06:40 INFO Uploading 1 narinfos12582026/10/09 18:06:40 INFO Aborted multipart uploads count=0 kept=01259--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (8.07s)1260=== CONT TestCacheConfigHandler1261=== RUN TestCacheConfigHandler/full_config,_no_issuer1262=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1263=== RUN TestCacheConfigHandler/no_cache_url_configured1264=== PAUSE TestCacheConfigHandler/no_cache_url_configured1265=== RUN TestCacheConfigHandler/no_signing_keys1266=== PAUSE TestCacheConfigHandler/no_signing_keys1267=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1268=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1269=== CONT TestPushDedupSurvivesConcurrentGC12702026/10/09 18:06:40 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=012712026/10/09 18:06:40 INFO Received complete push request method=POST path=/api/pushes/1/complete12722026/10/09 18:06:40 WARN Failed to register uploaded object key=xy4g0g06chvpi0a8f3apif6pm8kj720m.narinfo error="server returned 404: 404 page not found\n"12732026/10/09 18:06:40 INFO Completed push id=1 objects=3 duration=55.11475ms12742026/10/09 18:06:40 INFO Upload complete. (345ms)12752026/10/09 18:06:40 INFO Vacuumed table table=pending_closures12762026/10/09 18:06:40 INFO Vacuumed table table=pending_objects12772026/10/09 18:06:40 INFO Vacuumed table table=multipart_uploads12782026/10/09 18:06:40 INFO Received push request method=POST path=/api/pushes12792026/10/09 18:06:40 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12802026/10/09 18:06:40 INFO Uploading z3l2qdy21q4m629fpdv54955p1n138cw-unpinned-file.txt (128B)12812026/10/09 18:06:40 INFO Vacuumed table table=closures12822026/10/09 18:06:40 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"12832026/10/09 18:06:40 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12842026/10/09 18:06:40 WARN Failed to register uploaded object key=z3l2qdy21q4m629fpdv54955p1n138cw.ls error="server returned 404: 404 page not found\n"12852026/10/09 18:06:40 INFO Signed narinfos id=2 count=112862026/10/09 18:06:40 INFO Uploading 1 narinfos1287--- PASS: TestPresentReportsOnlyClosureRoots (7.57s)1288=== CONT TestServerTLSConfig1289=== RUN TestServerTLSConfig/no_client_CA1290=== PAUSE TestServerTLSConfig/no_client_CA1291=== RUN TestServerTLSConfig/missing_CA_file1292=== PAUSE TestServerTLSConfig/missing_CA_file1293=== RUN TestServerTLSConfig/not_a_PEM_file1294=== PAUSE TestServerTLSConfig/not_a_PEM_file1295=== CONT TestCacheStatsHandler12962026/10/09 18:06:40 INFO Vacuumed table table=objects12972026/10/09 18:06:40 INFO Received complete push request method=POST path=/api/pushes/2/complete12982026/10/09 18:06:40 WARN Failed to register uploaded object key=z3l2qdy21q4m629fpdv54955p1n138cw.narinfo error="server returned 404: 404 page not found\n"12992026/10/09 18:06:40 INFO Completed push id=2 objects=3 duration=1.029583ms13002026/10/09 18:06:40 INFO Upload complete. (155ms)13012026/10/09 18:06:40 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001302--- PASS: TestService_createPendingClosureHandler (8.40s)1303=== CONT TestService_NativeMTLS13042026/10/09 18:06:40 INFO Starting cleanup of old closures method=DELETE path=/api/closures13052026/10/09 18:06:40 INFO Garbage collection started13062026/10/09 18:06:40 INFO Aborted multipart uploads count=0 kept=013072026/10/09 18:06:40 WARN Force mode enabled - objects will be deleted immediately without grace period13082026/10/09 18:06:40 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=013092026/10/09 18:06:40 INFO Vacuumed table table=pending_closures13102026/10/09 18:06:40 INFO Vacuumed table table=pending_objects13112026/10/09 18:06:40 INFO Vacuumed table table=multipart_uploads13122026/10/09 18:06:40 INFO Vacuumed table table=closures13132026/10/09 18:06:40 INFO Vacuumed table table=objects13142026/10/09 18:06:41 INFO Received push request method=POST path=/api/pushes13152026/10/09 18:06:41 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)13162026/10/09 18:06:41 INFO Uploading 1i7b133sjlvsw5h5yc75lig039zf2b4g-top (264B)13172026/10/09 18:06:41 INFO Uploading c1m8613z2d3xr9p4k9pp0n8v0cwyl27m-shared-dep (136B)13182026/10/09 18:06:41 WARN Failed to register uploaded object key=nar/0wd82jig690fasqhj11hrkw3zzmim93kad19ndqfglnz5a3m7frg.nar.zst error="server returned 404: 404 page not found\n"13192026/10/09 18:06:41 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13202026/10/09 18:06:41 WARN Failed to register uploaded object key=1i7b133sjlvsw5h5yc75lig039zf2b4g.ls error="server returned 404: 404 page not found\n"13212026/10/09 18:06:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13222026/10/09 18:06:41 WARN Failed to register uploaded object key=c1m8613z2d3xr9p4k9pp0n8v0cwyl27m.ls error="server returned 404: 404 page not found\n"13232026/10/09 18:06:41 INFO Signed narinfos id=1 count=213242026/10/09 18:06:41 INFO Uploading 2 narinfos13252026/10/09 18:06:41 WARN Failed to register uploaded object key=c1m8613z2d3xr9p4k9pp0n8v0cwyl27m.narinfo error="server returned 404: 404 page not found\n"13262026/10/09 18:06:41 INFO Received complete push request method=POST path=/api/pushes/1/complete13272026/10/09 18:06:41 WARN Failed to register uploaded object key=1i7b133sjlvsw5h5yc75lig039zf2b4g.narinfo error="server returned 404: 404 page not found\n"13282026/10/09 18:06:41 INFO Aborted multipart uploads count=0 kept=013292026/10/09 18:06:41 WARN Force mode enabled - objects will be deleted immediately without grace period13302026/10/09 18:06:41 INFO Completed push id=1 objects=6 duration=32.994708ms13312026/10/09 18:06:41 INFO Upload complete. (200ms)13322026/10/09 18:06:41 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=01333=== NAME TestClientSharedPathCommittedMidPush1334 client_integration_test.go:816: Retrieved narinfo from S3:1335 StorePath: /private/var/tb/7/scratch/be18d57bca741e73/build/TestClientSharedPathCommittedMidPush3425764160/001/store/c1m8613z2d3xr9p4k9pp0n8v0cwyl27m-shared-dep1336 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1337 Compression: zstd1338 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y8213392026/10/09 18:06:41 INFO Vacuumed table table=pending_closures1340 NarSize: 13613412026/10/09 18:06:41 INFO Vacuumed table table=pending_objects1342 References: 1343 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13442026/10/09 18:06:41 INFO Vacuumed table table=multipart_uploads1345 client_integration_test.go:816: Retrieved narinfo from S3:13462026/10/09 18:06:41 INFO Vacuumed table table=closures1347 StorePath: /private/var/tb/7/scratch/be18d57bca741e73/build/TestClientSharedPathCommittedMidPush3425764160/001/store/1i7b133sjlvsw5h5yc75lig039zf2b4g-top1348 URL: nar/0wd82jig690fasqhj11hrkw3zzmim93kad19ndqfglnz5a3m7frg.nar.zst1349 Compression: zstd1350 NarHash: sha256:0wd82jig690fasqhj11hrkw3zzmim93kad19ndqfglnz5a3m7frg1351 NarSize: 2641352 References: /private/var/tb/7/scratch/be18d57bca741e73/build/TestClientSharedPathCommittedMidPush3425764160/001/store/c1m8613z2d3xr9p4k9pp0n8v0cwyl27m-shared-dep1353 CA: text:sha256:0y2x2p4cx81sa0kyx5hzjs8vvch9b618cv3rjqwvplngi53sydgc13542026/10/09 18:06:41 INFO Vacuumed table table=objects1355--- PASS: TestClientSharedPathCommittedMidPush (7.73s)1356=== CONT TestGCAdvisoryLockBlocksConcurrentRun13572026/10/09 18:06:41 INFO Aborted multipart uploads count=0 kept=013582026/10/09 18:06:41 WARN Force mode enabled - objects will be deleted immediately without grace period13592026/10/09 18:06:41 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=013602026/10/09 18:06:41 INFO Vacuumed table table=pending_closures13612026/10/09 18:06:41 INFO Vacuumed table table=pending_objects13622026/10/09 18:06:41 INFO Vacuumed table table=multipart_uploads13632026/10/09 18:06:41 INFO Vacuumed table table=closures13642026/10/09 18:06:41 INFO Vacuumed table table=objects1365--- PASS: TestSweepSkipsRowsLockedByPush (7.05s)1366=== CONT TestService_ReadScope_PublicByDefault13672026/10/09 18:06:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13682026/10/09 18:06:41 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LmQ1Nzc1NDAyLTdmNjQtNDRiOC1hYTBiLWJkMjc3M2M2YzA3N3gxNzkxNTY5MTk5NzQ1NTU0MDAw error="Get \"http://127.0.0.1:1/bucket23/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"13692026/10/09 18:06:41 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LmRmNzEyMDJhLTJkMzktNDkxMi05YzhiLWVhOWJjZjEzYzNjNHgxNzkxNTY5MTk5NjgwNjQ2MDAw parts=1213702026/10/09 18:06:41 INFO Received cleanup request method=DELETE path=/api/pending_closures13712026/10/09 18:06:42 INFO Aborted multipart uploads count=1 kept=01372--- PASS: TestRedundantMultipartUpload (10.03s)1373=== CONT TestGCBugBareHashReferences1374--- PASS: TestObjectStatsTrigger (6.98s)1375=== CONT TestMetricsCommit1376=== NAME TestClientWithDependencies1377 client_integration_test.go:735: Built derivation: /private/var/tb/7/scratch/be18d57bca741e73/build/TestClientWithDependencies3969228308/001/store/i66z0gl4i286gixy4i9nmx0b442xn6pv-test-script1378 client_integration_test.go:737: Found 1 dependencies (including self)13792026/10/09 18:06:42 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=013802026/10/09 18:06:42 INFO Received push request method=POST path=/api/pushes13812026/10/09 18:06:42 INFO Received create pin request method=POST path=/api/pins/myapp13822026/10/09 18:06:42 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13832026/10/09 18:06:42 INFO Uploading i66z0gl4i286gixy4i9nmx0b442xn6pv-test-script (136B)13842026/10/09 18:06:42 INFO Created/updated pin name=myapp store_path=/private/var/tb/7/scratch/be18d57bca741e73/build/TestPinProtectsFromGC472297162/001/store/xy4g0g06chvpi0a8f3apif6pm8kj720m-pinned-file.txt narinfo_key=xy4g0g06chvpi0a8f3apif6pm8kj720m.narinfo13852026/10/09 18:06:42 INFO Starting cleanup of old closures method=DELETE path=/api/closures13862026/10/09 18:06:42 INFO Garbage collection started13872026/10/09 18:06:42 INFO Aborted multipart uploads count=0 kept=013882026/10/09 18:06:42 WARN Force mode enabled - objects will be deleted immediately without grace period13892026/10/09 18:06:42 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=013902026/10/09 18:06:42 INFO Vacuumed table table=pending_closures13912026/10/09 18:06:42 INFO Vacuumed table table=pending_objects13922026/10/09 18:06:42 WARN Failed to register uploaded object key=i66z0gl4i286gixy4i9nmx0b442xn6pv.ls error="server returned 404: 404 page not found\n"13932026/10/09 18:06:42 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13942026/10/09 18:06:42 INFO Vacuumed table table=multipart_uploads13952026/10/09 18:06:42 INFO Vacuumed table table=closures13962026/10/09 18:06:42 WARN Failed to register uploaded object key=log/q4yvygaknpd90rwjnm6p1y9hvyfsz1s5-test-script.drv error="server returned 404: 404 page not found\n"13972026/10/09 18:06:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13982026/10/09 18:06:42 INFO Vacuumed table table=objects13992026/10/09 18:06:42 INFO Signed narinfos id=1 count=114002026/10/09 18:06:42 INFO Uploading 1 narinfos14012026/10/09 18:06:42 INFO Received complete push request method=POST path=/api/pushes/1/complete14022026/10/09 18:06:42 WARN Failed to register uploaded object key=i66z0gl4i286gixy4i9nmx0b442xn6pv.narinfo error="server returned 404: 404 page not found\n"14032026/10/09 18:06:42 INFO Completed push id=1 objects=4 duration=31.040708ms14042026/10/09 18:06:42 INFO Upload complete. (285ms)14052026/10/09 18:06:42 INFO Aborted multipart uploads count=0 kept=014062026/10/09 18:06:42 WARN Force mode enabled - objects will be deleted immediately without grace period14072026/10/09 18:06:42 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=014082026/10/09 18:06:42 INFO Vacuumed table table=pending_closures14092026/10/09 18:06:42 INFO Vacuumed table table=pending_objects14102026/10/09 18:06:42 INFO Vacuumed table table=multipart_uploads14112026/10/09 18:06:42 INFO Vacuumed table table=closures14122026/10/09 18:06:42 INFO Vacuumed table table=objects1413 client_integration_test.go:753: Skipping nix copy test - isolated store (/private/var/tb/7/scratch/be18d57bca741e73/build/TestClientWithDependencies3969228308/001/store) requires matching store prefix1414--- PASS: TestClientWithDependencies (8.21s)1415=== CONT TestLeadIncumbentAnnouncesAtOnce14162026/10/09 18:06:43 INFO Aborted multipart uploads count=0 kept=014172026/10/09 18:06:43 WARN Force mode enabled - objects will be deleted immediately without grace period14182026/10/09 18:06:43 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=014192026/10/09 18:06:43 INFO Vacuumed table table=pending_closures14202026/10/09 18:06:43 INFO Vacuumed table table=pending_objects14212026/10/09 18:06:43 INFO Vacuumed table table=multipart_uploads14222026/10/09 18:06:43 INFO Vacuumed table table=closures14232026/10/09 18:06:43 INFO Vacuumed table table=objects14242026/10/09 18:06:43 INFO Received uploads request method=POST path=/api/pending_closures1425--- PASS: TestGCSweepDeliversEachKeyOnce (6.48s)1426=== CONT TestService_ReadAuthMiddleware1427=== NAME TestOrphanedObjectsGC1428 orphaned_objects_gc_test.go:287: GC Test Summary:1429 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1430 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1431 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1432 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1433 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1434=== CONT TestMultipartCleanup1435--- PASS: TestOrphanedObjectsGC (7.85s)1436--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (6.84s)1437=== CONT TestLeadElectsOneAndHandsOver1438=== NAME TestClientMultipleUploads1439 client_integration_test.go:480: Created store path 0: /private/var/tb/7/scratch/be18d57bca741e73/build/TestClientMultipleUploads3630840752/001/store/0sisk1pv1i66kb9c81wyk1di991yq9aw-test-file-0.txt14402026/10/09 18:06:43 INFO Received uploads request method=POST path=/api/pending_closures1441--- PASS: TestTombstonedObjectOfferedWithoutWaiting (7.15s)1442=== CONT TestService_AuthMiddleware_OIDC1443=== NAME TestClientMultipleUploads1444 client_integration_test.go:480: Created store path 1: /private/var/tb/7/scratch/be18d57bca741e73/build/TestClientMultipleUploads3630840752/001/store/f60zspnwr3nzfhynqd9b0c02xcm3gi43-test-file-1.txt14452026/10/09 18:06:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65098/oidc1446 client_integration_test.go:480: Created store path 2: /private/var/tb/7/scratch/be18d57bca741e73/build/TestClientMultipleUploads3630840752/001/store/iagdzlvf56m9arx6czc7imhwr12pbnk4-test-file-2.txt14472026/10/09 18:06:44 INFO Received push request method=POST path=/api/pushes14482026/10/09 18:06:44 INFO Received uploads request method=POST path=/api/pending_closures14492026/10/09 18:06:44 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14502026/10/09 18:06:44 INFO Uploading 0sisk1pv1i66kb9c81wyk1di991yq9aw-test-file-0.txt (160B)14512026/10/09 18:06:44 INFO Uploading iagdzlvf56m9arx6czc7imhwr12pbnk4-test-file-2.txt (160B)14522026/10/09 18:06:44 INFO Uploading f60zspnwr3nzfhynqd9b0c02xcm3gi43-test-file-1.txt (160B)14532026/10/09 18:06:44 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"14542026/10/09 18:06:44 WARN Failed to register uploaded object key=iagdzlvf56m9arx6czc7imhwr12pbnk4.ls error="server returned 404: 404 page not found\n"14552026/10/09 18:06:44 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14562026/10/09 18:06:44 WARN Failed to register uploaded object key=0sisk1pv1i66kb9c81wyk1di991yq9aw.ls error="server returned 404: 404 page not found\n"14572026/10/09 18:06:44 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14582026/10/09 18:06:44 WARN Failed to register uploaded object key=f60zspnwr3nzfhynqd9b0c02xcm3gi43.ls error="server returned 404: 404 page not found\n"14592026/10/09 18:06:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14602026/10/09 18:06:44 INFO Signed narinfos id=1 count=314612026/10/09 18:06:44 INFO Uploading 3 narinfos1462--- PASS: TestPendingClosureFailureAbortsItsUploads (7.42s)1463=== CONT TestMetricsInventory14642026/10/09 18:06:44 WARN Failed to register uploaded object key=0sisk1pv1i66kb9c81wyk1di991yq9aw.narinfo error="server returned 404: 404 page not found\n"14652026/10/09 18:06:44 INFO Received complete push request method=POST path=/api/pushes/1/complete14662026/10/09 18:06:44 WARN Failed to register uploaded object key=f60zspnwr3nzfhynqd9b0c02xcm3gi43.narinfo error="server returned 404: 404 page not found\n"14672026/10/09 18:06:44 WARN Failed to register uploaded object key=iagdzlvf56m9arx6czc7imhwr12pbnk4.narinfo error="server returned 404: 404 page not found\n"14682026/10/09 18:06:44 INFO Completed push id=1 objects=9 duration=40.000916ms14692026/10/09 18:06:44 INFO Upload complete. (305ms)1470=== NAME TestClientMultipleUploads1471 client_integration_test.go:491: Uploaded 3 paths in 344.080041ms1472=== NAME TestPinProtectsFromGC1473 client_integration_test.go:976: Pin successfully protected closure from garbage collection1474--- PASS: TestClientMultipleUploads (7.82s)1475=== CONT TestService_AuthMiddleware_MTLSProxyHeader1476--- PASS: TestPinProtectsFromGC (11.56s)1477=== CONT TestLeadEndsOnShutdown1478=== NAME TestClientIntegration1479 client_integration_test.go:334: Created store path: /private/var/tb/7/scratch/be18d57bca741e73/build/TestClientIntegration2429472955/002/store/lmgagfn3yc1nyndczyh7nk38qfazcbr3-test-file.txt14802026/10/09 18:06:45 INFO Received uploads request method=POST path=/api/pending_closures14812026/10/09 18:06:45 INFO Received push request method=POST path=/api/pushes14822026/10/09 18:06:45 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14832026/10/09 18:06:45 INFO Uploading 4dncxk2is4z8apdqvkadp0b2dr7vnvrr-shared-dep (136B)14842026/10/09 18:06:45 INFO Uploading d8hf09g5jxzd0p70mscf9niawvj5hqyl-a (256B)14852026/10/09 18:06:45 WARN Failed to register uploaded object key=4dncxk2is4z8apdqvkadp0b2dr7vnvrr.ls error="server returned 404: 404 page not found\n"14862026/10/09 18:06:45 WARN Failed to register uploaded object key=bl3mwwbl10ngfi1z7zvyvh2didwfw8sx.ls error="server returned 404: 404 page not found\n"14872026/10/09 18:06:45 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14882026/10/09 18:06:45 WARN Failed to register uploaded object key=d8hf09g5jxzd0p70mscf9niawvj5hqyl.ls error="server returned 404: 404 page not found\n"14892026/10/09 18:06:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14902026/10/09 18:06:45 WARN Failed to register uploaded object key=nar/0kq6j9ipbpiv2wc2mh6r2sxfmifh8xfkcg9rkwf2li78d9v5iahc.nar.zst error="server returned 404: 404 page not found\n"14912026/10/09 18:06:45 INFO Signed narinfos id=1 count=314922026/10/09 18:06:45 INFO Received push request method=POST path=/api/pushes14932026/10/09 18:06:45 INFO Uploading 3 narinfos14942026/10/09 18:06:45 INFO Aborted multipart uploads count=0 kept=014952026/10/09 18:06:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14962026/10/09 18:06:45 INFO Uploading lmgagfn3yc1nyndczyh7nk38qfazcbr3-test-file.txt (152B)14972026/10/09 18:06:45 WARN Failed to register uploaded object key=d8hf09g5jxzd0p70mscf9niawvj5hqyl.narinfo error="server returned 404: 404 page not found\n"14982026/10/09 18:06:45 INFO Received complete push request method=POST path=/api/pushes/1/complete14992026/10/09 18:06:45 WARN Failed to register uploaded object key=bl3mwwbl10ngfi1z7zvyvh2didwfw8sx.narinfo error="server returned 404: 404 page not found\n"15002026/10/09 18:06:45 WARN Failed to register uploaded object key=4dncxk2is4z8apdqvkadp0b2dr7vnvrr.narinfo error="server returned 404: 404 page not found\n"15012026/10/09 18:06:45 WARN Force mode enabled - objects will be deleted immediately without grace period15022026/10/09 18:06:45 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=015032026/10/09 18:06:45 WARN Failed to register uploaded object key=lmgagfn3yc1nyndczyh7nk38qfazcbr3.ls error="server returned 404: 404 page not found\n"15042026/10/09 18:06:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15052026/10/09 18:06:45 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15062026/10/09 18:06:45 INFO Signed narinfos id=1 count=115072026/10/09 18:06:45 INFO Uploading 1 narinfos15082026/10/09 18:06:45 INFO Completed push id=1 objects=8 duration=38.825708ms15092026/10/09 18:06:45 INFO Upload complete. (249ms)15102026/10/09 18:06:45 INFO Vacuumed table table=pending_closures1511=== NAME TestClientPushesUseOnePush1512 client_pushes_test.go:97: Retrieved narinfo from S3:1513 StorePath: /private/var/tb/7/scratch/be18d57bca741e73/build/TestClientPushesUseOnePush1531381040/001/store/4dncxk2is4z8apdqvkadp0b2dr7vnvrr-shared-dep1514 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1515 Compression: zstd1516 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821517 NarSize: 1361518 References: 1519 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1520 client_pushes_test.go:97: Retrieved narinfo from S3:1521 StorePath: /private/var/tb/7/scratch/be18d57bca741e73/build/TestClientPushesUseOnePush1531381040/001/store/d8hf09g5jxzd0p70mscf9niawvj5hqyl-a1522 URL: nar/0kq6j9ipbpiv2wc2mh6r2sxfmifh8xfkcg9rkwf2li78d9v5iahc.nar.zst1523 Compression: zstd1524 NarHash: sha256:0kq6j9ipbpiv2wc2mh6r2sxfmifh8xfkcg9rkwf2li78d9v5iahc1525 NarSize: 2561526 References: /private/var/tb/7/scratch/be18d57bca741e73/build/TestClientPushesUseOnePush1531381040/001/store/4dncxk2is4z8apdqvkadp0b2dr7vnvrr-shared-dep1527 CA: text:sha256:1d3gafrxkgrq2nifmbg4sfvx7376qsf4zlmg4sh957rph1hkjgn215282026/10/09 18:06:45 INFO Received complete push request method=POST path=/api/pushes/1/complete15292026/10/09 18:06:45 INFO Vacuumed table table=pending_objects1530 client_pushes_test.go:97: Retrieved narinfo from S3:1531 StorePath: /private/var/tb/7/scratch/be18d57bca741e73/build/TestClientPushesUseOnePush1531381040/001/store/bl3mwwbl10ngfi1z7zvyvh2didwfw8sx-b1532 URL: nar/0kq6j9ipbpiv2wc2mh6r2sxfmifh8xfkcg9rkwf2li78d9v5iahc.nar.zst1533 Compression: zstd1534 NarHash: sha256:0kq6j9ipbpiv2wc2mh6r2sxfmifh8xfkcg9rkwf2li78d9v5iahc15352026/10/09 18:06:45 WARN Failed to register uploaded object key=lmgagfn3yc1nyndczyh7nk38qfazcbr3.narinfo error="server returned 404: 404 page not found\n"1536 NarSize: 25615372026/10/09 18:06:45 INFO Vacuumed table table=multipart_uploads1538 References: /private/var/tb/7/scratch/be18d57bca741e73/build/TestClientPushesUseOnePush1531381040/001/store/4dncxk2is4z8apdqvkadp0b2dr7vnvrr-shared-dep1539 CA: text:sha256:1d3gafrxkgrq2nifmbg4sfvx7376qsf4zlmg4sh957rph1hkjgn215402026/10/09 18:06:45 INFO Vacuumed table table=closures15412026/10/09 18:06:45 INFO Completed push id=1 objects=3 duration=63.267333ms15422026/10/09 18:06:45 INFO Upload complete. (312ms)15432026/10/09 18:06:45 INFO Vacuumed table table=objects1544--- PASS: TestGCSweepSkipsPendingObjects (8.16s)1545=== CONT TestNARDeduplicationMetadataUploadBug15462026/10/09 18:06:45 INFO All 1 paths already cached1547=== NAME TestClientIntegration1548 client_integration_test.go:360: Retrieved narinfo from S3:1549 StorePath: /private/var/tb/7/scratch/be18d57bca741e73/build/TestClientIntegration2429472955/002/store/lmgagfn3yc1nyndczyh7nk38qfazcbr3-test-file.txt1550 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1551 Compression: zstd1552 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11553 NarSize: 1521554 References: 1555 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11556 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)1557 client_integration_test.go:361: Decompressed .ls content (64 bytes):1558 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1559--- PASS: TestClientPushesUseOnePush (8.80s)1560=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15612026/10/09 18:06:45 INFO Received push request method=POST path=/api/pushes15622026/10/09 18:06:45 INFO Object in database but missing from S3 key=lmgagfn3yc1nyndczyh7nk38qfazcbr3.ls15632026/10/09 18:06:45 WARN Found objects in DB but missing from S3, will re-upload count=115642026/10/09 18:06:45 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)15652026/10/09 18:06:45 INFO Received complete push request method=POST path=/api/pushes/2/complete15662026/10/09 18:06:45 WARN Failed to register uploaded object key=lmgagfn3yc1nyndczyh7nk38qfazcbr3.ls error="server returned 404: 404 page not found\n"15672026/10/09 18:06:45 INFO Completed push id=2 objects=3 duration=875.5µs15682026/10/09 18:06:45 INFO Upload complete. (125ms)1569=== NAME TestClientIntegration1570 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)1571 client_integration_test.go:389: Decompressed .ls content (49 bytes):1572 {"version":1,"root":{"type":"regular","size":39}}15732026/10/09 18:06:46 INFO Received uploads request method=POST path=/api/pending_closures15742026/10/09 18:06:46 INFO Received push request method=POST path=/api/pushes1575=== NAME TestOrphanedObjectsGCStressTest15762026/10/09 18:06:46 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1577 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains15782026/10/09 18:06:46 WARN Failed to register uploaded object key=lmgagfn3yc1nyndczyh7nk38qfazcbr3.ls error="server returned 404: 404 page not found\n"15792026/10/09 18:06:46 INFO Received complete push request method=POST path=/api/pushes/3/complete15802026/10/09 18:06:46 INFO Completed push id=3 objects=3 duration=42.105916ms15812026/10/09 18:06:46 INFO Upload complete. (142ms)1582=== NAME TestClientIntegration1583 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)1584=== NAME TestOrphanedObjectsGCStressTest1585 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion1586=== NAME TestClientIntegration1587 client_integration_test.go:405: Decompressed .ls content (49 bytes):1588 {"version":1,"root":{"type":"regular","size":39}}1589=== NAME TestClientCADerivations1590 client_ca_test.go:136: Built CA derivation: /private/var/tb/7/scratch/be18d57bca741e73/build/TestClientCADerivations3081612081/001/store/ws1nfn1p3aij7cclphwc5gs8xh8m7nr2-ca-test1591--- PASS: TestDeduplicatedObjectsRecordedAsPending (7.92s)1592=== CONT TestConnectWaitsForAPeerMigration1593=== NAME TestClientCADerivations1594 client_ca_test.go:139: Found 1 dependencies (including self)15952026/10/09 18:06:46 INFO Received uploads request method=POST path=/api/pending_closures15962026/10/09 18:06:46 INFO Received push request method=POST path=/api/pushes15972026/10/09 18:06:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15982026/10/09 18:06:46 INFO Uploading d4nzqj5z80r4yhhvih1phhxk5ca5c8a3-lost-commit.txt (152B)15992026/10/09 18:06:46 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"16002026/10/09 18:06:46 WARN Failed to register uploaded object key=d4nzqj5z80r4yhhvih1phhxk5ca5c8a3.ls error="server returned 404: 404 page not found\n"16012026/10/09 18:06:46 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign16022026/10/09 18:06:46 INFO Signed narinfos id=4 count=116032026/10/09 18:06:46 INFO Uploading 1 narinfos16042026/10/09 18:06:46 INFO Received complete push request method=POST path=/api/pushes/4/complete16052026/10/09 18:06:46 WARN Failed to register uploaded object key=d4nzqj5z80r4yhhvih1phhxk5ca5c8a3.narinfo error="server returned 404: 404 page not found\n"16062026/10/09 18:06:46 INFO Completed push id=4 objects=3 duration=882.875µs16072026/10/09 18:06:46 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:65119/api/pushes/4/complete\": EOF" url=http://127.0.0.1:65119/api/pushes/4/complete16082026/10/09 18:06:46 INFO Received push request method=POST path=/api/pushes1609--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (6.61s)16102026/10/09 18:06:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16112026/10/09 18:06:46 INFO Uploading ws1nfn1p3aij7cclphwc5gs8xh8m7nr2-ca-test (144B)1612=== CONT TestConcurrentPinUpdatesAgree16132026/10/09 18:06:46 WARN Failed to register uploaded object key=ws1nfn1p3aij7cclphwc5gs8xh8m7nr2.ls error="server returned 404: 404 page not found\n"16142026/10/09 18:06:46 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16152026/10/09 18:06:46 INFO Received complete push request method=POST path=/api/pushes/4/complete16162026-10-09 18:06:46.467 UTC [64915] ERROR: Push does not exist: id=416172026-10-09 18:06:46.467 UTC [64915] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE16182026-10-09 18:06:46.467 UTC [64915] STATEMENT: -- name: CommitPush :one1619 SELECT commit_push($1::bigint)::bigint1620 16212026/10/09 18:06:46 WARN Failed to register uploaded object key=log/r30m00v7b5nmal9szdr73im3ga0rrs6b-ca-test.drv error="server returned 404: 404 page not found\n"16222026/10/09 18:06:46 WARN Push not found id=416232026/10/09 18:06:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16242026/10/09 18:06:46 INFO Signed narinfos id=1 count=116252026/10/09 18:06:46 INFO Upload complete. (223ms)16262026/10/09 18:06:46 INFO Uploading 1 narinfos1627=== NAME TestClientIntegration1628 client_integration_test.go:435: Retrieved narinfo from S3:1629 StorePath: /private/var/tb/7/scratch/be18d57bca741e73/build/TestClientIntegration2429472955/002/store/d4nzqj5z80r4yhhvih1phhxk5ca5c8a3-lost-commit.txt1630 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1631 Compression: zstd1632 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1633 NarSize: 1521634 References: 1635 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1636 client_integration_test.go:438: Testing garbage collection...16372026/10/09 18:06:46 INFO Received complete push request method=POST path=/api/pushes/1/complete16382026/10/09 18:06:46 WARN Failed to register uploaded object key=ws1nfn1p3aij7cclphwc5gs8xh8m7nr2.narinfo error="server returned 404: 404 page not found\n"16392026/10/09 18:06:46 INFO Starting cleanup of old closures method=DELETE path=/api/closures16402026/10/09 18:06:46 INFO Garbage collection started16412026/10/09 18:06:46 INFO Completed push id=1 objects=4 duration=33.399916ms16422026/10/09 18:06:46 INFO Upload complete. (295ms)16432026/10/09 18:06:46 INFO Aborted multipart uploads count=0 kept=01644=== NAME TestClientCADerivations1645 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/7/scratch/be18d57bca741e73/build/TestClientCADerivations3081612081/001/store/ws1nfn1p3aij7cclphwc5gs8xh8m7nr2-ca-test1646 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1647 Compression: zstd1648 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1649 NarSize: 1441650 References: 1651 Deriver: /private/var/tb/7/scratch/be18d57bca741e73/build/TestClientCADerivations3081612081/001/store/r30m00v7b5nmal9szdr73im3ga0rrs6b-ca-test.drv16522026/10/09 18:06:46 WARN Force mode enabled - objects will be deleted immediately without grace period1653 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1654 client_ca_test.go:185: Checking for realisation files in S3...1655 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1656 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache16572026/10/09 18:06:46 INFO Aborted multipart uploads count=0 kept=016582026/10/09 18:06:46 WARN Force mode enabled - objects will be deleted immediately without grace period1659 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket46?endpoint=http://localhost:64949®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/7/scratch/be18d57bca741e73/build/TestClientCADerivations3081612081/001/store'1660 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 116612026/10/09 18:06:46 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=016622026/10/09 18:06:46 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=016632026/10/09 18:06:46 INFO Vacuumed table table=pending_closures16642026/10/09 18:06:46 INFO Vacuumed table table=pending_objects16652026/10/09 18:06:46 INFO Vacuumed table table=multipart_uploads16662026/10/09 18:06:46 INFO Vacuumed table table=pending_closures16672026/10/09 18:06:46 INFO Vacuumed table table=closures16682026/10/09 18:06:46 INFO Vacuumed table table=objects16692026/10/09 18:06:46 INFO Vacuumed table table=pending_objects16702026/10/09 18:06:46 INFO Vacuumed table table=multipart_uploads1671--- PASS: TestGCMetrics (6.69s)1672=== CONT TestPendingCleanupUsesOneCutoff16732026/10/09 18:06:46 INFO Vacuumed table table=closures16742026/10/09 18:06:46 INFO Vacuumed table table=objects1675--- PASS: TestClientCADerivations (9.15s)1676=== CONT TestCacheConfigHandlerMaxNarSize1677--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1678=== CONT TestParseSize1679=== CONT TestConnectSerialisesConcurrentMigrations1680--- PASS: TestParseSize (0.00s)16812026/10/09 18:06:46 INFO Received uploads request method=POST path=/api/pending_closures16822026/10/09 18:06:47 INFO Aborted multipart uploads count=0 kept=016832026/10/09 18:06:47 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=016842026/10/09 18:06:47 INFO Vacuumed table table=pending_closures16852026/10/09 18:06:47 INFO Vacuumed table table=pending_objects16862026/10/09 18:06:47 INFO Vacuumed table table=multipart_uploads16872026/10/09 18:06:47 INFO Vacuumed table table=closures16882026/10/09 18:06:47 INFO Vacuumed table table=objects16892026/10/09 18:06:47 INFO Aborted multipart uploads count=0 kept=016902026/10/09 18:06:47 WARN Force mode enabled - objects will be deleted immediately without grace period16912026/10/09 18:06:47 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=016922026/10/09 18:06:47 INFO Vacuumed table table=pending_closures16932026/10/09 18:06:47 INFO Vacuumed table table=pending_objects1694--- PASS: TestCacheStatsHandler (6.89s)1695=== CONT TestResolveDBConnectionString16962026/10/09 18:06:47 INFO Vacuumed table table=multipart_uploads1697=== RUN TestResolveDBConnectionString/flag_wins1698=== PAUSE TestResolveDBConnectionString/flag_wins1699=== RUN TestResolveDBConnectionString/file_when_flag_empty1700=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1701=== RUN TestResolveDBConnectionString/missing_file_is_an_error1702=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1703=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1704=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1705=== RUN TestResolveDBConnectionString/nothing_configured1706=== PAUSE TestResolveDBConnectionString/nothing_configured1707=== CONT TestCreatePendingClosureRejectsOversizedNAR17082026/10/09 18:06:47 INFO Vacuumed table table=closures17092026/10/09 18:06:47 INFO Received uploads request method=POST path=/api/pending_closures1710--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1711=== CONT TestCommitRacingPendingCleanupKeepsObjects17122026/10/09 18:06:47 INFO Vacuumed table table=objects1713--- PASS: TestPushDedupSurvivesConcurrentGC (7.16s)1714=== CONT TestGCTaskStore_GetReturnsLatest1715--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1716=== CONT TestGCTaskStore_ConflictDifferentParams1717--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1718=== CONT TestChildrenInheritRaisedFileLimit1719--- PASS: TestChildrenInheritRaisedFileLimit (0.02s)1720=== CONT TestGCTaskStore_StartNew1721--- PASS: TestGCTaskStore_StartNew (0.00s)1722=== CONT TestSweepRechecksPendingAfterLocking17232026/10/09 18:06:47 WARN mTLS auth: subject not in bound subjects subject="CN=reader"17242026/10/09 18:06:47 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1725--- PASS: TestService_NativeMTLS (7.01s)1726=== CONT TestGCTaskStore_DeduplicateSameParams1727--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1728=== CONT TestGenerateLandingPage1729--- PASS: TestGenerateLandingPage (0.00s)1730=== CONT TestGCTaskStore_GetEmpty1731--- PASS: TestGCTaskStore_GetEmpty (0.00s)1732=== CONT TestService_RequireScope_OIDC17332026/10/09 18:06:47 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65174/oidc1734--- PASS: TestService_ReadScope_PublicByDefault (6.07s)1735=== CONT TestPushWaitsForSweepHoldingRow17362026-10-09 18:06:48.054 UTC [65123] ERROR: duplicate key value violates unique constraint "pg_class_relname_nsp_index"17372026-10-09 18:06:48.054 UTC [65123] DETAIL: Key (relname, relnamespace)=(goose_db_version_id_seq, 2200) already exists.17382026-10-09 18:06:48.054 UTC [65123] STATEMENT: CREATE TABLE goose_db_version (1739 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1740 version_id bigint NOT NULL,1741 is_applied boolean NOT NULL,1742 tstamp timestamp NOT NULL DEFAULT now()1743 )17442026/10/09 18:06:48 INFO Received push request method=POST path=/api/pushes1745--- PASS: TestGCBugBareHashReferences (6.28s)1746=== CONT TestService_readinessHandler17472026/10/09 18:06:48 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=01748=== NAME TestClientIntegration1749 client_integration_test.go:445: Objects in database after GC:1750 client_integration_test.go:445: Successfully deleted all objects with GC --force17512026/10/09 18:06:48 INFO lead: acquired remote=192.0.2.1:123417522026/10/09 18:06:48 INFO lead: released remote=192.0.2.1:12341753--- PASS: TestClientIntegration (11.61s)1754=== CONT TestReadProxyDisabled1755--- PASS: TestLeadIncumbentAnnouncesAtOnce (5.64s)1756=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1757=== NAME TestOrphanedObjectsGCStressTest1758 orphaned_objects_gc_test.go:503: Stress test completed successfully:1759 orphaned_objects_gc_test.go:504: - Active objects preserved: 201760 orphaned_objects_gc_test.go:505: - Objects deleted: 2101761 orphaned_objects_gc_test.go:506: - Total GC'd: 2101762--- PASS: TestOrphanedObjectsGCStressTest (16.64s)1763=== CONT TestReadRedirectUsesPublicS3URL1764--- PASS: TestConnectSerialisesConcurrentMigrations (2.30s)1765=== CONT TestGracefulShutdownDrainsInflight17662026/10/09 18:06:49 INFO Starting HTTP server address=127.0.0.1:6519217672026/10/09 18:06:49 INFO Shutdown signal received, draining in-flight requests timeout=10s1768--- PASS: TestService_ReadAuthMiddleware (5.75s)1769=== CONT TestPush_RootsAreLockedInByteOrder1770=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1771--- PASS: TestObjectStatsLargeCommit (14.90s)1772=== CONT TestReadProxyRangeRequest1773--- PASS: TestGracefulShutdownDrainsInflight (0.09s)17742026/10/09 18:06:49 INFO Received uploads request method=POST path=/api/pending_closures17752026/10/09 18:06:49 INFO Received cleanup request method=DELETE path=/api/pending_closures17762026/10/09 18:06:49 INFO lead: acquired remote=192.0.2.1:123417772026/10/09 18:06:49 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket59/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""17782026/10/09 18:06:49 INFO Aborted multipart uploads count=0 kept=117792026/10/09 18:06:49 INFO Received cleanup request method=DELETE path=/api/pending_closures17802026/10/09 18:06:49 INFO Aborted multipart uploads count=1 kept=01781--- PASS: TestMultipartCleanup (6.24s)1782=== CONT TestPush_CompleteWaitsForCleanupOfThePush1783=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1784=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1785=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1786=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1787=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1788=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1789=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1790=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1791=== CONT TestPush_RepeatedRootCommitsOnce17922026/10/09 18:06:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17932026/10/09 18:06:50 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LmE1N2RkNTMwLTk4MGEtNDc1NS05OTJkLWE4NmNmZDk0Yzc3MngxNzkxNTY5MjA4MzM0MDA5MDAw parts=101794--- PASS: TestMetricsInventory (6.01s)1795=== CONT TestPush_CompleteCommitsEveryRoot1796--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (5.96s)1797=== CONT TestGCTaskStore_CompletedAllowsNewTask1798--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1799=== CONT TestReadProxyInvalidPath18002026/10/09 18:06:50 INFO lead: released remote=192.0.2.1:123418012026/10/09 18:06:50 INFO lead: acquired remote=192.0.2.1:123418022026/10/09 18:06:51 INFO lead: acquired remote=192.0.2.1:123418032026/10/09 18:06:51 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"18042026/10/09 18:06:51 WARN mTLS auth: bound subjects configured but subject DN unavailable18052026/10/09 18:06:51 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1806--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (5.73s)1807=== CONT TestReadProxyRootRedirectsToIndexHTML18082026/10/09 18:06:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18092026/10/09 18:06:51 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LjQ2YTliN2ExLThjMWQtNDU3Yi05ZWQzLTUyMjY1ZmE1MDY1MngxNzkxNTY5MjA4MzMzNjU3MDAw parts=1018102026/10/09 18:06:51 INFO Received complete push request method=POST path=/api/pushes/1/complete18112026/10/09 18:06:51 INFO Completed push id=1 objects=4 duration=64.831375ms18122026/10/09 18:06:51 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18132026/10/09 18:06:51 INFO Completed upload id=2 objects=2 duration=2.403292ms1814--- PASS: TestMetricsCommit (9.63s)1815=== CONT TestReadProxyConditionalGet18162026/10/09 18:06:52 INFO lead: released remote=192.0.2.1:12341817--- PASS: TestLeadElectsOneAndHandsOver (8.46s)1818=== CONT TestReadProxyHead18192026/10/09 18:06:52 INFO lead: released remote=192.0.2.1:12341820=== NAME TestNARDeduplicationMetadataUploadBug1821 metadata_upload_test.go:48: First store path: /private/var/tb/7/scratch/be18d57bca741e73/build/TestNARDeduplicationMetadataUploadBug422712672/001/store/x4b8wiardkc6nxy3zpy5n92ysvah8n6h-file1.txt1822--- PASS: TestLeadEndsOnShutdown (7.42s)1823=== CONT TestReadRedirectNar18242026/10/09 18:06:52 INFO Received create pin request method=POST path=/api/pins/app18252026/10/09 18:06:52 INFO Received push request method=POST path=/api/pushes18262026/10/09 18:06:52 INFO Received create pin request method=POST path=/api/pins/app18272026/10/09 18:06:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18282026/10/09 18:06:52 INFO Uploading x4b8wiardkc6nxy3zpy5n92ysvah8n6h-file1.txt (160B)18292026/10/09 18:06:52 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"18302026/10/09 18:06:52 WARN Failed to register uploaded object key=x4b8wiardkc6nxy3zpy5n92ysvah8n6h.ls error="server returned 404: 404 page not found\n"18312026/10/09 18:06:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18322026/10/09 18:06:52 INFO Signed narinfos id=1 count=118332026/10/09 18:06:52 INFO Uploading 1 narinfos18342026/10/09 18:06:52 INFO Received complete push request method=POST path=/api/pushes/1/complete18352026/10/09 18:06:52 WARN Failed to register uploaded object key=x4b8wiardkc6nxy3zpy5n92ysvah8n6h.narinfo error="server returned 404: 404 page not found\n"18362026/10/09 18:06:52 INFO Completed push id=1 objects=3 duration=30.018ms18372026/10/09 18:06:52 INFO Upload complete. (239ms)1838=== NAME TestNARDeduplicationMetadataUploadBug1839 metadata_upload_test.go:54: Retrieved narinfo from S3:1840 StorePath: /private/var/tb/7/scratch/be18d57bca741e73/build/TestNARDeduplicationMetadataUploadBug422712672/001/store/x4b8wiardkc6nxy3zpy5n92ysvah8n6h-file1.txt1841 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1842 Compression: zstd1843 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1844 NarSize: 1601845 References: 1846 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1847 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1848 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1849 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}18502026/10/09 18:06:52 INFO Received uploads request method=POST path=/api/pending_closures1851 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/7/scratch/be18d57bca741e73/build/TestNARDeduplicationMetadataUploadBug422712672/001/store/7dvnjshvcv4b9b817hr7xd05kkbd37kc-file2.txt18522026/10/09 18:06:52 INFO Received uploads request method=POST path=/api/pending_closures18532026/10/09 18:06:52 INFO Received cleanup request method=DELETE path=/api/pending_closures18542026/10/09 18:06:52 INFO Received push request method=POST path=/api/pushes18552026/10/09 18:06:52 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18562026/10/09 18:06:52 WARN Failed to register uploaded object key=7dvnjshvcv4b9b817hr7xd05kkbd37kc.ls error="server returned 404: 404 page not found\n"18572026/10/09 18:06:52 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18582026/10/09 18:06:52 INFO Signed narinfos id=2 count=118592026/10/09 18:06:52 INFO Uploading 1 narinfos18602026/10/09 18:06:52 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo18612026/10/09 18:06:52 INFO Received complete push request method=POST path=/api/pushes/2/complete18622026/10/09 18:06:52 WARN Failed to register uploaded object key=7dvnjshvcv4b9b817hr7xd05kkbd37kc.narinfo error="server returned 404: 404 page not found\n"18632026/10/09 18:06:52 INFO Completed push id=2 objects=3 duration=931.917µs18642026/10/09 18:06:52 INFO Upload complete. (185ms)1865 metadata_upload_test.go:76: Retrieved narinfo from S3:1866 StorePath: /private/var/tb/7/scratch/be18d57bca741e73/build/TestNARDeduplicationMetadataUploadBug422712672/001/store/7dvnjshvcv4b9b817hr7xd05kkbd37kc-file2.txt1867 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1868 Compression: zstd1869 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1870 NarSize: 1601871 References: 1872 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf18732026/10/09 18:06:52 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo1874 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1875 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1876 {"version":1,"root":{"type":"regular","size":44}}1877--- PASS: TestConcurrentPinUpdatesAgree (6.46s)1878=== CONT TestPendingClosureWriteTimeout1879=== RUN TestPendingClosureWriteTimeout/empty1880=== PAUSE TestPendingClosureWriteTimeout/empty1881=== RUN TestPendingClosureWriteTimeout/400_objects1882=== PAUSE TestPendingClosureWriteTimeout/400_objects1883=== RUN TestPendingClosureWriteTimeout/670k_objects1884=== PAUSE TestPendingClosureWriteTimeout/670k_objects1885=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1886=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1887=== CONT TestService_healthCheckHandler1888--- PASS: TestNARDeduplicationMetadataUploadBug (7.40s)1889=== CONT TestGCTaskStore_Fail1890--- PASS: TestGCTaskStore_Fail (0.00s)1891=== CONT TestReadProxyContentNegotiation1892--- PASS: TestConnectWaitsForAPeerMigration (6.95s)1893=== CONT TestGCEndsOnShutdown1894=== RUN TestGCEndsOnShutdown/before_the_run1895=== PAUSE TestGCEndsOnShutdown/before_the_run1896=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1897=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1898=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1899=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1900=== CONT TestReadProxyNarinfoAlreadyDecompressed19012026/10/09 18:06:53 INFO Aborted multipart uploads count=0 kept=019022026/10/09 18:06:53 WARN Force mode enabled - objects will be deleted immediately without grace period19032026/10/09 18:06:53 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=019042026/10/09 18:06:53 INFO Vacuumed table table=pending_closures19052026/10/09 18:06:53 INFO Vacuumed table table=pending_objects19062026/10/09 18:06:53 INFO Vacuumed table table=multipart_uploads19072026/10/09 18:06:53 INFO Vacuumed table table=closures19082026/10/09 18:06:53 INFO Vacuumed table table=objects19092026/10/09 18:06:53 INFO Aborted multipart uploads count=0 kept=01910--- PASS: TestCommitRacingPendingCleanupKeepsObjects (6.07s)1911=== CONT TestReadRedirectKeepsNarinfoProxied19122026/10/09 18:06:53 WARN Force mode enabled - objects will be deleted immediately without grace period19132026/10/09 18:06:53 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=019142026/10/09 18:06:53 INFO Vacuumed table table=pending_closures19152026/10/09 18:06:53 INFO Vacuumed table table=pending_objects19162026/10/09 18:06:53 INFO Vacuumed table table=multipart_uploads19172026/10/09 18:06:53 INFO Vacuumed table table=closures19182026/10/09 18:06:53 INFO Vacuumed table table=objects1919--- PASS: TestSweepRechecksPendingAfterLocking (6.20s)1920=== CONT TestGCTaskStore_PhaseUpdates1921--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1922=== CONT TestReadProxyNarStreaming1923=== RUN TestService_RequireScope_OIDC/builder_may_write1924=== PAUSE TestService_RequireScope_OIDC/builder_may_write1925=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1926=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1927=== RUN TestService_RequireScope_OIDC/ops_may_admin1928=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1929=== RUN TestService_RequireScope_OIDC/ops_may_not_write1930=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1931=== RUN TestService_RequireScope_OIDC/reader_may_not_write1932=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1933=== RUN TestService_RequireScope_OIDC/static_token_may_admin1934=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1935=== RUN TestService_RequireScope_OIDC/static_token_may_write1936=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1937=== RUN TestService_RequireScope_OIDC/reader_may_read1938=== PAUSE TestService_RequireScope_OIDC/reader_may_read1939=== RUN TestService_RequireScope_OIDC/writer_implies_read1940=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1941=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1942=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1943=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1944=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1945=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1946=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1947=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1948=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1949=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1950=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1951=== CONT TestReadProxyOutlastsServerWriteTimeout19522026/10/09 18:06:53 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld7 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1953--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (12.24s)1954=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle19552026/10/09 18:06:54 INFO Received uploads request method=POST path=/api/pending_closures19562026/10/09 18:06:54 WARN readiness check failed error="closed pool"1957--- PASS: TestService_readinessHandler (6.07s)1958=== CONT TestPresignedUploadRegisteredBeforeCommit1959--- PASS: TestPushWaitsForSweepHoldingRow (6.85s)1960=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1961--- PASS: TestReadProxyDisabled (6.05s)1962=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh19632026/10/09 18:06:55 INFO Received push request method=POST path=/api/pushes1964--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (6.51s)1965=== CONT TestProxyWriteTimeout/narinfo1966=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19672026/10/09 18:06:55 INFO Received uploads request method=POST path=/1968=== CONT TestProxyWriteTimeout/10_GiB_nar1969=== CONT TestProxyWriteTimeout/unknown_size1970=== CONT TestProxyWriteTimeout/1_GiB_nar1971--- PASS: TestProxyWriteTimeout (0.02s)1972 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1973 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1974 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1975 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1976=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19772026/10/09 18:06:55 INFO Received request for more parts method=POST path=/1978=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19792026/10/09 18:06:55 INFO Received complete multipart upload request method=POST path=/1980=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19812026/10/09 18:06:55 INFO Received uploads request method=POST path=/1982--- PASS: TestUploadHandlersRejectInvalidKeys (0.02s)1983 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1984 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1985 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1986 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1987=== CONT TestParseSingleRange/end_clamped_to_size1988=== CONT TestParseSingleRange/start_far_past_EOF1989=== CONT TestParseSingleRange/malformed_no_dash1990=== CONT TestParseSingleRange/start_past_EOF1991=== CONT TestParseSingleRange/malformed_end_before_start1992=== CONT TestParseSingleRange/single_byte1993=== CONT TestParseSingleRange/malformed_both_empty1994=== CONT TestParseSingleRange/suffix1995=== CONT TestParseSingleRange/closed1996=== CONT TestParseSingleRange/suffix_exceeds_size1997=== CONT TestParseSingleRange/open-ended1998=== CONT TestParseSingleRange/multi-range_ignored1999=== CONT TestParseSingleRange/unknown_unit2000=== CONT TestParseSingleRange/none2001=== CONT TestIsValidCachePath/nar_xz2002--- PASS: TestParseSingleRange (0.02s)2003 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2004 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2005 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2006 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2007 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2008 --- PASS: TestParseSingleRange/single_byte (0.00s)2009 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2010 --- PASS: TestParseSingleRange/suffix (0.00s)2011 --- PASS: TestParseSingleRange/closed (0.00s)2012 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2013 --- PASS: TestParseSingleRange/open-ended (0.00s)2014 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2015 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2016 --- PASS: TestParseSingleRange/none (0.00s)2017=== CONT TestIsValidCachePath/short_hash2018=== CONT TestIsValidCachePath/leading_slash2019=== CONT TestIsValidCachePath/empty2020=== CONT TestIsValidCachePath/random_path2021=== CONT TestIsValidCachePath/wrong_extension2022=== CONT TestIsValidCachePath/invalid_char_e2023=== CONT TestIsValidCachePath/invalid_char_u2024=== CONT TestIsValidCachePath/traversal_parent2025=== CONT TestIsValidCachePath/index.html2026=== CONT TestIsValidCachePath/nix-cache-info2027=== CONT TestIsValidCachePath/realisation2028=== CONT TestIsValidCachePath/log2029=== CONT TestIsValidCachePath/ls2030=== CONT TestIsValidCachePath/nar_uncompressed2031=== CONT TestIsValidCachePath/nar_bz22032=== CONT TestIsValidCachePath/traversal_in_middle2033=== CONT TestIsValidCachePath/nar_zst2034=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2035=== CONT TestIsValidCachePath/narinfo2036=== CONT TestIsValidUploadKey/listing2037--- PASS: TestIsValidCachePath (0.04s)2038 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2039 --- PASS: TestIsValidCachePath/short_hash (0.00s)2040 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2041 --- PASS: TestIsValidCachePath/empty (0.00s)2042 --- PASS: TestIsValidCachePath/random_path (0.00s)2043 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2044 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2045 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2046 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2047 --- PASS: TestIsValidCachePath/index.html (0.00s)2048 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2049 --- PASS: TestIsValidCachePath/realisation (0.00s)2050 --- PASS: TestIsValidCachePath/log (0.00s)2051 --- PASS: TestIsValidCachePath/ls (0.00s)2052 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2053 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2054 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2055 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2056 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2057 --- PASS: TestIsValidCachePath/narinfo (0.00s)2058=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2059=== CONT TestIsValidUploadKey/empty_key2060=== CONT TestIsValidUploadKey/unknown_type2061=== CONT TestIsValidUploadKey/absolute2062=== CONT TestIsValidUploadKey/traversal2063=== CONT TestIsValidUploadKey/traversal_nar2064=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2065=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2066=== CONT TestIsValidUploadKey/index.html2067=== CONT TestIsValidUploadKey/nix-cache-info2068=== CONT TestIsValidUploadKey/realisation_plus_in_output2069=== CONT TestIsValidUploadKey/build_log_plus_in_name2070=== CONT TestIsValidUploadKey/realisation2071=== CONT TestIsValidUploadKey/build_log_equals2072=== CONT TestIsValidUploadKey/build_log_question_mark2073=== CONT TestIsValidUploadKey/build_log_home-manager_file2074=== CONT TestIsValidUploadKey/nar_xz2075=== CONT TestIsValidUploadKey/build_log2076=== CONT TestIsValidUploadKey/nar_plain2077=== CONT TestIsValidUploadKey/nar_zst2078=== CONT TestIsValidUploadKey/narinfo2079=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure2080--- PASS: TestIsValidUploadKey (0.05s)2081 --- PASS: TestIsValidUploadKey/listing (0.00s)2082 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2083 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2084 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2085 --- PASS: TestIsValidUploadKey/absolute (0.00s)2086 --- PASS: TestIsValidUploadKey/traversal (0.00s)2087 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2088 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2089 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2090 --- PASS: TestIsValidUploadKey/index.html (0.00s)2091 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2092 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2093 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2094 --- PASS: TestIsValidUploadKey/realisation (0.00s)2095 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2096 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2097 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2098 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2099 --- PASS: TestIsValidUploadKey/build_log (0.00s)2100 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2101 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2102 --- PASS: TestIsValidUploadKey/narinfo (0.00s)21032026/10/09 18:06:55 INFO Received uploads request method=POST path=/21042026/10/09 18:06:55 INFO Received push request method=POST path=/api/pushes21052026-10-09 18:06:55.501 UTC [64689] LOG: checkpoints are occurring too frequently (29 seconds apart)21062026-10-09 18:06:55.501 UTC [64689] HINT: Consider increasing the configuration parameter "max_wal_size".21072026-10-09 18:06:55.507 UTC [64689] LOG: checkpoint starting: wal2108--- PASS: TestReadRedirectUsesPublicS3URL (6.97s)2109=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts21102026/10/09 18:06:55 INFO Received request for more parts method=POST path=/2111=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart21122026/10/09 18:06:56 INFO Received complete multipart upload request method=POST path=/2113--- PASS: TestReadProxyRangeRequest (6.96s)2114=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows21152026/10/09 18:06:56 INFO Received push request method=POST path=/api/pushes2116=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check21172026/10/09 18:06:56 INFO Received push request method=POST path=/api/pushes21182026/10/09 18:06:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21192026/10/09 18:06:56 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LjJmOTFjMDZkLTNjMTctNDdkOC1iMmM3LTNkNWJmZmU1Mjg0OHgxNzkxNTY5MjE1NDM1NTQ2MDAw parts=1021202026/10/09 18:06:56 INFO Received push request method=POST path=/api/pushes21212026/10/09 18:06:57 INFO Received push request method=POST path=/api/pushes2122--- PASS: TestReadProxyInvalidPath (7.07s)2123=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false21242026/10/09 18:06:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2125--- PASS: TestReadProxyRootRedirectsToIndexHTML (6.73s)2126=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true21272026/10/09 18:06:58 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LjkxYTQxNmRkLWE4NTctNDVlOS1hYmMxLWM4MzQxNjY0NWM4NHgxNzkxNTY5MjE2Mzg1ODM0MDAw parts=1021282026/10/09 18:06:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21292026/10/09 18:06:58 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LjhkMzRlZTUzLTYwYTItNGI4MC04ZTA3LTcwMjc5ZThiNTQ5NngxNzkxNTY5MjE2NzI1OTg0MDAw parts=102130--- PASS: TestReadProxyConditionalGet (6.71s)2131=== CONT TestPush_RejectsBadRequests/no_roots21322026/10/09 18:06:58 INFO Received push request method=POST path=/api/pushes2133=== CONT TestPush_RejectsBadRequests/no_objects21342026/10/09 18:06:58 INFO Received push request method=POST path=/api/pushes2135=== CONT TestPush_RejectsBadRequests/root_not_in_objects21362026/10/09 18:06:58 INFO Received push request method=POST path=/api/pushes2137=== CONT TestPush_RejectsBadRequests/bad_root21382026/10/09 18:06:58 INFO Received push request method=POST path=/api/pushes2139=== CONT TestClientErrorHandling/InvalidStorePath21402026/10/09 18:06:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21412026/10/09 18:06:58 INFO Aborted multipart uploads count=1 kept=021422026/10/09 18:06:58 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LmIxMDY0NWI3LWM2OWYtNGEzYS04MjM1LWJhMjFkODkwNjllYXgxNzkxNTY5MjE1NDM1MzA3MDAw parts=102143--- PASS: TestPush_RejectsBadRequests (5.70s)2144 --- PASS: TestPush_RejectsBadRequests/no_roots (0.01s)2145 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2146 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2147 --- PASS: TestPush_RejectsBadRequests/bad_root (0.01s)21482026/10/09 18:06:58 INFO Received cleanup request method=DELETE path=/api/pending_closures21492026/10/09 18:06:58 INFO Aborted multipart uploads count=1 kept=021502026/10/09 18:06:58 INFO Received complete push request method=POST path=/api/pushes/1/complete21512026/10/09 18:06:58 INFO Completed push id=1 objects=4 duration=25.13925ms2152--- PASS: TestPendingCleanupUsesOneCutoff (12.15s)21532026/10/09 18:06:58 INFO Received push request method=POST path=/api/pushes2154=== CONT TestClientErrorHandling/ServerNotAvailable21552026-10-09 18:06:58.923 UTC [65272] ERROR: Push does not exist: id=121562026-10-09 18:06:58.923 UTC [65272] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE21572026-10-09 18:06:58.923 UTC [65272] STATEMENT: SELECT commit_push($1)2158--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (9.11s)2159=== CONT TestClientErrorHandling/InvalidAuthToken21602026/10/09 18:06:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21612026/10/09 18:06:58 INFO Aborted multipart uploads count=0 kept=021622026/10/09 18:06:58 WARN Force mode enabled - objects will be deleted immediately without grace period2163--- PASS: TestReadRedirectNar (6.88s)2164=== CONT TestCacheConfigHandler/full_config,_no_issuer2165=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2166=== CONT TestCacheConfigHandler/no_signing_keys2167=== CONT TestCacheConfigHandler/no_cache_url_configured2168=== CONT TestServerTLSConfig/missing_CA_file2169--- PASS: TestCacheConfigHandler (0.00s)2170 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2171 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2172 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2173 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2174=== CONT TestServerTLSConfig/not_a_PEM_file21752026/10/09 18:06:59 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LjVhMzk3ODVjLWI2YWEtNDI4NC1hMDNmLWQ2NWVmOGU5NTNlMXgxNzkxNTY5MjE3MDQ0NTQ2MDAw parts=1021762026/10/09 18:06:59 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=02177=== CONT TestServerTLSConfig/no_client_CA2178=== CONT TestResolveDBConnectionString/missing_file_is_an_error2179--- PASS: TestServerTLSConfig (0.00s)2180 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2181 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.04s)2182 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2183=== CONT TestResolveDBConnectionString/nothing_configured2184=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2185=== CONT TestResolveDBConnectionString/file_when_flag_empty2186=== CONT TestResolveDBConnectionString/flag_wins2187=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2188=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2189=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected21902026/10/09 18:06:59 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]2191--- PASS: TestResolveDBConnectionString (0.02s)2192 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2193 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2194 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2195 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2196 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2197=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected21982026/10/09 18:06:59 INFO Vacuumed table table=pending_closures21992026/10/09 18:06:59 WARN Authentication failed token_preview=eyJhbGciOi...UAHpaLT9lA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2200=== CONT TestPendingClosureWriteTimeout/empty2201=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline22022026/10/09 18:06:59 INFO Vacuumed table table=pending_objects22032026/10/09 18:06:59 INFO Vacuumed table table=multipart_uploads22042026/10/09 18:06:59 INFO Vacuumed table table=closures2205--- PASS: TestService_AuthMiddleware_OIDC (6.04s)2206 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2207 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2208 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2209 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)22102026/10/09 18:06:59 INFO Vacuumed table table=objects22112026/10/09 18:06:59 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2212--- PASS: TestReadProxyHead (7.36s)2213=== CONT TestPendingClosureWriteTimeout/670k_objects2214=== CONT TestPendingClosureWriteTimeout/400_objects2215=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark22162026/10/09 18:06:59 WARN Request failed, retrying attempt=2 backoff=202.961337ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22172026/10/09 18:06:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2218=== CONT TestGCEndsOnShutdown/before_the_run2219--- PASS: TestUploadHandlersRejectOversizedBody (0.19s)2220 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.28s)2221 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.29s)2222 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (4.41s)22232026/10/09 18:06:59 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1Ljc5NGJkMTdkLTg3OTUtNGRlMi1hNDk5LWM1N2JiZjRkYTNjZHgxNzkxNTY5MjE3MzgxNTMwMDAw parts=1022242026/10/09 18:06:59 WARN Request failed, retrying attempt=3 backoff=432.233324ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2225--- PASS: TestReadProxyContentNegotiation (6.88s)2226=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete22272026/10/09 18:07:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22282026/10/09 18:07:00 WARN Request failed, retrying attempt=4 backoff=837.662906ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2229--- PASS: TestService_healthCheckHandler (7.37s)2230=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2231=== CONT TestService_RequireScope_OIDC/static_token_may_write2232=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2233=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read22342026/10/09 18:07:00 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]2235=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2236=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2237=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2238=== CONT TestService_RequireScope_OIDC/writer_implies_read22392026/10/09 18:07:00 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LmQzODE2YWE2LTQwYWItNDA3Yy04ZmIyLWU4ZGVhYTdmMjM2OHgxNzkxNTY5MjE2Mzg1Njk0MDAw parts=102240=== CONT TestService_RequireScope_OIDC/ops_may_not_write2241=== CONT TestService_RequireScope_OIDC/static_token_may_admin2242=== CONT TestService_RequireScope_OIDC/reader_may_read2243=== CONT TestService_RequireScope_OIDC/ops_may_admin2244=== CONT TestService_RequireScope_OIDC/reader_may_not_write2245=== CONT TestService_RequireScope_OIDC/builder_may_write2246--- PASS: TestService_RequireScope_OIDC (6.23s)2247 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2248 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2249 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2250 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2251 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2252 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2253 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2254 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2255 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2256 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2257 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2258 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2259 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2260 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2261--- PASS: TestReadProxyNarinfoAlreadyDecompressed (7.53s)22622026/10/09 18:07:01 WARN Request failed, retrying attempt=5 backoff=1.533315044s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2263--- PASS: TestReadRedirectKeepsNarinfoProxied (7.85s)22642026/10/09 18:07:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22652026/10/09 18:07:01 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LjM2MzczMzg5LTExODgtNDc2NS1hMTQ2LTVlMzUwN2RjYmI4ZHgxNzkxNTY5MjE3MDQ0Mjc4MDAw parts=1022662026/10/09 18:07:01 INFO Received complete push request method=POST path=/api/pushes/1/complete22672026/10/09 18:07:01 INFO Completed push id=1 objects=4 duration=48.359417ms2268--- PASS: TestPush_RepeatedRootCommitsOnce (11.44s)22692026/10/09 18:07:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22702026/10/09 18:07:01 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LmMyYWUwYjRiLWEzNTQtNDI2ZC1hY2U5LWI2YTc4OGEzMmQ2MngxNzkxNTY5MjE4ODg3ODE2MDAw parts=1022712026/10/09 18:07:01 INFO Received complete push request method=POST path=/api/pushes/2/complete22722026/10/09 18:07:01 INFO Completed push id=2 objects=4 duration=6.676291ms2273--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (12.42s)22742026/10/09 18:07:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22752026/10/09 18:07:01 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LjM4NWM2YjNmLTA0YzAtNDcyZS05OGI2LTJhMzZhNDdhOWFhY3gxNzkxNTY5MjE3MzgxNzg0MDAw parts=102276--- PASS: TestReadProxyNarStreaming (8.46s)22772026/10/09 18:07:02 INFO Received uploads request method=POST path=/api/pending_closures22782026/10/09 18:07:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22792026/10/09 18:07:02 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LjZmNzU2ZWQzLTQ1YzYtNGZmMy05ZjM3LTQ3ZGVlODM3NjJjZXgxNzkxNTY5MjE2Mzg1NzQyMDAw parts=1022802026/10/09 18:07:02 INFO Received uploads request method=POST path=/api/pending_closures22812026/10/09 18:07:02 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22822026/10/09 18:07:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22832026/10/09 18:07:02 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst22842026/10/09 18:07:02 INFO Received uploads request method=POST path=/api/pending_closures2285--- PASS: TestPresignedUploadRegisteredBeforeCommit (8.35s)22862026/10/09 18:07:02 WARN Request failed, retrying attempt=2 backoff=211.302621ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22872026/10/09 18:07:03 WARN Request failed, retrying attempt=3 backoff=390.555108ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22882026/10/09 18:07:03 WARN Request failed, retrying attempt=4 backoff=780.738354ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22892026/10/09 18:07:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22902026/10/09 18:07:03 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LjMwZjI3NzE3LTEyMmItNGM1ZS1hMTA5LWJiNWI1OWIxMjhjNngxNzkxNTY5MjE3MzgxNzc4MDAw parts=1022912026/10/09 18:07:03 INFO Received complete push request method=POST path=/api/pushes/1/complete22922026/10/09 18:07:03 INFO Completed push id=1 objects=6 duration=14.291666ms2293--- PASS: TestPush_CompleteCommitsEveryRoot (13.28s)22942026/10/09 18:07:03 INFO Received uploads request method=POST path=/api/pending_closures22952026/10/09 18:07:03 INFO Aborted multipart uploads count=0 kept=022962026/10/09 18:07:03 WARN Force mode enabled - objects will be deleted immediately without grace period22972026/10/09 18:07:03 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=022982026/10/09 18:07:03 INFO Vacuumed table table=pending_closures22992026/10/09 18:07:03 INFO Vacuumed table table=pending_objects23002026/10/09 18:07:03 INFO Vacuumed table table=multipart_uploads23012026/10/09 18:07:03 INFO Vacuumed table table=closures23022026/10/09 18:07:03 INFO Vacuumed table table=objects2303--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.02s)2304 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (8.77s)2305 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (9.18s)23062026/10/09 18:07:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23072026/10/09 18:07:04 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LmMwN2JiNzA1LWQ4NDItNGMxYi04ZjY4LWE2NDdmOTMyYTg3MXgxNzkxNTY5MjE2Mzg1OTAwMDAw parts=1023082026/10/09 18:07:04 INFO Received uploads request method=POST path=/api/pending_closures23092026/10/09 18:07:04 INFO Aborted multipart uploads count=0 kept=023102026/10/09 18:07:04 WARN Force mode enabled - objects will be deleted immediately without grace period23112026/10/09 18:07:04 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=023122026/10/09 18:07:04 INFO Vacuumed table table=pending_closures23132026/10/09 18:07:04 INFO Vacuumed table table=pending_objects23142026/10/09 18:07:04 INFO Vacuumed table table=multipart_uploads23152026/10/09 18:07:04 INFO Vacuumed table table=closures23162026/10/09 18:07:04 INFO Vacuumed table table=objects23172026/10/09 18:07:04 WARN Request failed, retrying attempt=5 backoff=1.51278253s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2318--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2319 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (7.90s)2320 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (7.83s)23212026/10/09 18:07:04 INFO Received uploads request method=POST path=/api/pending_closures23222026/10/09 18:07:04 INFO Received uploads request method=POST path=/api/pending_closures23232026/10/09 18:07:04 INFO Received uploads request method=POST path=/api/pending_closures23242026/10/09 18:07:04 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"23252026/10/09 18:07:05 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"23262026/10/09 18:07:05 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LjI1MGNlNTRhLTAzZWMtNDNkOC05ZGQzLTY1MWRiNDliZWRmZngxNzkxNTY5MjI0NDk3NDY0MDAw error="Access Denied"23272026/10/09 18:07:05 WARN keeping failed pending closure for cleanup to retry the abort id=12328--- PASS: TestPendingClosureFailureTracksEveryUpload (0.01s)2329 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (7.10s)2330 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (6.82s)23312026/10/09 18:07:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23322026/10/09 18:07:05 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LmQ2YTRlMGYwLTAxYzItNGI2Ni04YzlkLTBhNzdkYjU0MTc0MHgxNzkxNTY5MjE2Mzg1MzE1MDAw parts=1023332026/10/09 18:07:05 INFO Aborted multipart uploads count=0 kept=023342026/10/09 18:07:05 WARN Force mode enabled - objects will be deleted immediately without grace period23352026-10-09 18:07:05.185 UTC [65343] ERROR: canceling statement due to user request23362026-10-09 18:07:05.185 UTC [65343] 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/09 18:07:05 INFO Aborted multipart uploads count=0 kept=023802026/10/09 18:07:05 WARN Force mode enabled - objects will be deleted immediately without grace period23812026/10/09 18:07:05 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:64949/bucket107/?delete=\": context canceled"2382--- PASS: TestGCEndsOnShutdown (0.02s)2383 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (5.71s)2384 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (5.37s)2385 --- PASS: TestGCEndsOnShutdown/before_the_run (5.82s)23862026/10/09 18:07:05 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 127.0.0.1:19999: connect: connection refused"23872026/10/09 18:07:05 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23882026/10/09 18:07:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2389--- PASS: TestPendingClosureWriteTimeout (0.02s)2390 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2391 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2392 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2393 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (6.59s)23942026/10/09 18:07:05 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=ZTFlMjg5ZGYtZTQ4Yy00MjY0LTlmNGQtYTkzODgxMzgyNzY1LjViNGNjOGVlLTZkYTUtNGE3Ni1iNjY5LTgwYTVkMTBjYjQ0NXgxNzkxNTY5MjE2Mzg1ODkwMDAw parts=1023952026-10-09 18:07:05.816 UTC [65257] ERROR: could not obtain lock on row in relation "closures"23962026-10-09 18:07:05.816 UTC [65257] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23972026-10-09 18:07:05.817 UTC [65257] ERROR: could not obtain lock on row in relation "closures"23982026-10-09 18:07:05.817 UTC [65257] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23992026-10-09 18:07:05.818 UTC [65257] ERROR: could not obtain lock on row in relation "closures"24002026-10-09 18:07:05.818 UTC [65257] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT24012026-10-09 18:07:05.818 UTC [65257] ERROR: could not obtain lock on row in relation "closures"24022026-10-09 18:07:05.818 UTC [65257] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT24032026-10-09 18:07:05.822 UTC [65257] ERROR: could not obtain lock on row in relation "closures"24042026-10-09 18:07:05.822 UTC [65257] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT2405--- PASS: TestReadProxyOutlastsServerWriteTimeout (12.17s)24062026/10/09 18:07:05 WARN Request failed, retrying attempt=2 backoff=208.539404ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2407--- PASS: TestPush_RootsAreLockedInByteOrder (16.72s)24082026/10/09 18:07:06 WARN Request failed, retrying attempt=3 backoff=394.083418ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24092026/10/09 18:07:06 WARN Request failed, retrying attempt=4 backoff=775.19685ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24102026/10/09 18:07:07 WARN Rate limiter enabled after throttle name=s3-test rate=524112026/10/09 18:07:07 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2412=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2413 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102414 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002415--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (13.15s)24162026/10/09 18:07:07 WARN Request failed, retrying attempt=5 backoff=1.639786774s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24172026/10/09 18:07:08 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24182026/10/09 18:07:08 WARN Request failed, retrying attempt=2 backoff=204.222926ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24192026/10/09 18:07:09 WARN Request failed, retrying attempt=3 backoff=389.508636ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24202026/10/09 18:07:09 WARN Request failed, retrying attempt=4 backoff=817.254502ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24212026/10/09 18:07:10 WARN Request failed, retrying attempt=5 backoff=1.714197168s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2422--- PASS: TestClientErrorHandling (0.00s)2423 --- PASS: TestClientErrorHandling/InvalidStorePath (6.03s)2424 --- PASS: TestClientErrorHandling/InvalidAuthToken (6.13s)2425 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.25s)2426PASS2427{"timestamp":"2026-10-09T18:07:12.136806Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:65140","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}24282026-10-09 18:07:12.371 UTC [64684] LOG: received smart shutdown request24292026-10-09 18:07:12.371 UTC [64684] LOG: background worker "logical replication launcher" (PID 64694) exited with exit code 124302026-10-09 18:07:13.249 UTC [64689] LOG: checkpoint complete: wrote 4628 buffers (28.2%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=16.923 s, sync=0.702 s, total=17.742 s; sync files=37078, longest=0.001 s, average=0.001 s; distance=533055 kB, estimate=533055 kB; lsn=0/258BBF18, redo lsn=0/2201CB7024312026-10-09 18:07:13.250 UTC [64689] LOG: shutting down24322026-10-09 18:07:13.250 UTC [64689] LOG: checkpoint starting: shutdown immediate24332026-10-09 18:07:13.743 UTC [64689] LOG: checkpoint complete: wrote 7973 buffers (48.7%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 3 recycled; write=0.411 s, sync=0.080 s, total=0.494 s; sync files=2381, longest=0.033 s, average=0.001 s; distance=57981 kB, estimate=485547 kB; lsn=0/258BBF90, redo lsn=0/258BBF9024342026-10-09 18:07:13.750 UTC [64684] LOG: database system is shut down2435Running OIDC tests...2436=== RUN TestAudienceForIssuer2437=== PAUSE TestAudienceForIssuer2438=== RUN TestHTTPClientForHasTimeouts2439=== PAUSE TestHTTPClientForHasTimeouts2440=== RUN TestGlobMatch2441=== PAUSE TestGlobMatch2442=== RUN TestValidateToken_ValidToken2443=== PAUSE TestValidateToken_ValidToken2444=== RUN TestValidateToken_WrongAudience2445=== PAUSE TestValidateToken_WrongAudience2446=== RUN TestValidateToken_Expired2447=== PAUSE TestValidateToken_Expired2448=== RUN TestValidateToken_BoundClaimsMismatch2449=== PAUSE TestValidateToken_BoundClaimsMismatch2450=== RUN TestValidateToken_BoundSubjectMismatch2451=== PAUSE TestValidateToken_BoundSubjectMismatch2452=== RUN TestValidateToken_MultipleProviders2453=== PAUSE TestValidateToken_MultipleProviders2454=== RUN TestValidateToken_NoMatchingProvider2455=== PAUSE TestValidateToken_NoMatchingProvider2456=== RUN TestValidateToken_KubernetesServiceAccount2457=== PAUSE TestValidateToken_KubernetesServiceAccount2458=== RUN TestNewValidator_KubernetesRequiresCA2459=== PAUSE TestNewValidator_KubernetesRequiresCA2460=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2461=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2462=== RUN TestPins_ReservedForMatchingRule2463=== PAUSE TestPins_ReservedForMatchingRule2464=== RUN TestPins_TopLevelShorthand2465=== PAUSE TestPins_TopLevelShorthand2466=== RUN TestPins_ConfigValidation2467=== PAUSE TestPins_ConfigValidation2468=== RUN TestScopes_LegacyProviderDefaultsToWrite2469=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2470=== RUN TestScopes_Rules2471=== PAUSE TestScopes_Rules2472=== RUN TestScopes_ConfigValidation2473=== PAUSE TestScopes_ConfigValidation2474=== CONT TestAudienceForIssuer2475=== CONT TestValidateToken_BoundSubjectMismatch2476=== CONT TestValidateToken_KubernetesServiceAccount2477=== CONT TestValidateToken_NoMatchingProvider2478=== CONT TestScopes_Rules2479--- PASS: TestAudienceForIssuer (0.00s)2480=== CONT TestScopes_LegacyProviderDefaultsToWrite2481=== CONT TestValidateToken_ValidToken2482=== CONT TestPins_ConfigValidation2483=== CONT TestValidateToken_WrongAudience2484=== CONT TestScopes_ConfigValidation2485=== CONT TestHTTPClientForHasTimeouts2486=== CONT TestPins_TopLevelShorthand2487=== CONT TestGlobMatch2488=== RUN TestGlobMatch/foo_foo2489=== CONT TestPins_ReservedForMatchingRule2490=== 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--- PASS: TestPins_ConfigValidation (0.00s)2519=== CONT TestNewValidator_KubernetesRequiresCA2520=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2521--- PASS: TestScopes_ConfigValidation (0.00s)2522=== PAUSE TestGlobMatch/*/*_foo2523=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2524=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2525=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02526=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02527=== RUN TestGlobMatch/refs/*/main_refs/heads/main2528=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2529=== RUN TestGlobMatch/fo?_foo2530=== PAUSE TestGlobMatch/fo?_foo2531=== RUN TestGlobMatch/fo?_fo2532=== PAUSE TestGlobMatch/fo?_fo2533=== RUN TestGlobMatch/fo?_fooo2534=== PAUSE TestGlobMatch/fo?_fooo2535=== RUN TestGlobMatch/?oo_foo2536=== PAUSE TestGlobMatch/?oo_foo2537=== RUN TestGlobMatch/?oo_boo2538=== PAUSE TestGlobMatch/?oo_boo2539=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2540=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2541=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2542=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2543=== CONT TestGlobMatch/foo_foo2544=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2545=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2546=== CONT TestGlobMatch/?oo_boo2547=== CONT TestGlobMatch/fo?_fooo2548=== CONT TestGlobMatch/?oo_foo2549=== CONT TestGlobMatch/fo?_foo2550=== CONT TestGlobMatch/fo?_fo2551=== CONT TestGlobMatch/refs/*/main_refs/heads/main2552=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2553=== CONT TestGlobMatch/*/*_foo2554=== CONT TestGlobMatch/*/*_foo/bar2555=== CONT TestGlobMatch/foo*bar_foobarbaz2556=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02557=== CONT TestGlobMatch/foo*bar_foo123bar2558=== CONT TestGlobMatch/foo*bar_foobar2559=== CONT TestGlobMatch/*bar_foobar2560=== CONT TestGlobMatch/*bar_foo2561=== CONT TestGlobMatch/foo*_bar2562=== CONT TestGlobMatch/foo*_foobar2563=== CONT TestGlobMatch/*bar_bar2564=== CONT TestGlobMatch/*_anything2565=== CONT TestGlobMatch/*_2566=== CONT TestGlobMatch/foo_bar2567=== CONT TestGlobMatch/foo*_foo2568--- PASS: TestGlobMatch (0.00s)2569 --- PASS: TestGlobMatch/foo_foo (0.00s)2570 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2571 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2572 --- PASS: TestGlobMatch/?oo_boo (0.00s)2573 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2574 --- PASS: TestGlobMatch/?oo_foo (0.00s)2575 --- PASS: TestGlobMatch/fo?_foo (0.00s)2576 --- PASS: TestGlobMatch/fo?_fo (0.00s)2577 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2578 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2579 --- PASS: TestGlobMatch/*/*_foo (0.00s)2580 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2581 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2582 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2583 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2584 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2585 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2586 --- PASS: TestGlobMatch/*bar_foo (0.00s)2587 --- PASS: TestGlobMatch/foo*_bar (0.00s)2588 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2589 --- PASS: TestGlobMatch/*bar_bar (0.00s)2590 --- PASS: TestGlobMatch/*_anything (0.00s)2591 --- PASS: TestGlobMatch/*_ (0.00s)2592 --- PASS: TestGlobMatch/foo_bar (0.00s)2593 --- PASS: TestGlobMatch/foo*_foo (0.00s)2594=== CONT TestValidateToken_Expired2595=== CONT TestValidateToken_BoundClaimsMismatch2596=== CONT TestValidateToken_MultipleProviders25972026/10/09 18:07:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65447/oidc25982026/10/09 18:07:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65445/oidc2599--- PASS: TestValidateToken_WrongAudience (0.06s)26002026/10/09 18:07:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65448/oidc2601--- PASS: TestValidateToken_ValidToken (0.07s)2602--- PASS: TestPins_TopLevelShorthand (0.07s)26032026/10/09 18:07:16 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:65446/oidc26042026/10/09 18:07:16 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:654522605--- PASS: TestValidateToken_NoMatchingProvider (0.09s)2606--- PASS: TestValidateToken_KubernetesServiceAccount (0.09s)26072026/10/09 18:07:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65456/oidc2608--- PASS: TestValidateToken_BoundClaimsMismatch (0.11s)26092026/10/09 18:07:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65458/oidc26102026/10/09 18:07:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65460/oidc2611--- PASS: TestScopes_Rules (0.13s)2612--- PASS: TestValidateToken_Expired (0.12s)26132026/10/09 18:07:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65462/oidc2614--- PASS: TestValidateToken_BoundSubjectMismatch (0.14s)26152026/10/09 18:07:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65464/oidc2616--- PASS: TestPins_ReservedForMatchingRule (0.15s)26172026/10/09 18:07:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:65466/oidc2618--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.16s)26192026/10/09 18:07:16 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232620--- PASS: TestHTTPClientForHasTimeouts (0.20s)2621--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.20s)26222026/10/09 18:07:16 http: TLS handshake error from 127.0.0.1:65471: remote error: tls: bad certificate2623--- PASS: TestNewValidator_KubernetesRequiresCA (0.27s)26242026/10/09 18:07:17 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:65472/oidc26252026/10/09 18:07:17 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:65473/oidc2626--- PASS: TestValidateToken_MultipleProviders (0.37s)2627PASS2628Running hook tests...2629=== RUN TestSendPathsEmpty2630=== PAUSE TestSendPathsEmpty2631=== RUN TestQueueEnqueueAndFetch2632=== PAUSE TestQueueEnqueueAndFetch2633=== RUN TestQueueDeduplication2634=== PAUSE TestQueueDeduplication2635=== RUN TestQueueRemove2636=== PAUSE TestQueueRemove2637=== RUN TestQueueFetchBatchLimit2638=== PAUSE TestQueueFetchBatchLimit2639=== RUN TestQueueRetryMovesToBack2640=== PAUSE TestQueueRetryMovesToBack2641=== RUN TestQueueFetchRemoveLifecycle2642=== PAUSE TestQueueFetchRemoveLifecycle2643=== RUN TestQueueConcurrentWriters2644=== PAUSE TestQueueConcurrentWriters2645=== RUN TestQueueEnqueueWaitsOutSlowWriter2646=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2647=== RUN TestQueueRemoveLargeClosure2648=== PAUSE TestQueueRemoveLargeClosure2649=== RUN TestServerClientIntegration2650--- PASS: TestServerClientIntegration (0.00s)2651=== RUN TestServerQueueError26522026/10/09 18:07:18 ERROR Failed to queue paths error="permission denied" count=12653--- PASS: TestServerQueueError (0.00s)2654=== RUN TestServerRefusesOversizedAndNonStoreRequests2655=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2656=== RUN TestGetListenerSocketActivation2657 server_test.go:256: systemd socket activation does not exist on darwin2658--- SKIP: TestGetListenerSocketActivation (0.00s)2659=== RUN TestServerStalledClientDoesNotBlockShutdown2660=== PAUSE TestServerStalledClientDoesNotBlockShutdown2661=== RUN TestServerBacksOffOnAcceptErrors2662=== PAUSE TestServerBacksOffOnAcceptErrors2663=== RUN TestDrainIsolatesPoisonPath2664=== PAUSE TestDrainIsolatesPoisonPath2665=== RUN TestRunNotBlockedByPoisonHead2666=== PAUSE TestRunNotBlockedByPoisonHead2667=== RUN TestDrainGivesUpWhenServerDown2668=== PAUSE TestDrainGivesUpWhenServerDown2669=== RUN TestFailedPathPrunedByLaterClosure2670=== PAUSE TestFailedPathPrunedByLaterClosure2671=== RUN TestWorkerUploadsAndRemoves2672=== PAUSE TestWorkerUploadsAndRemoves2673=== RUN TestWorkerSkipsGCdPaths2674=== PAUSE TestWorkerSkipsGCdPaths2675=== RUN TestWorkerPrunesClosureDeps2676=== PAUSE TestWorkerPrunesClosureDeps2677=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2678=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2679=== RUN TestDrainTimeout2680=== PAUSE TestDrainTimeout2681=== RUN TestDrainTimeoutDuringIsolation2682=== PAUSE TestDrainTimeoutDuringIsolation2683=== RUN TestShutdownFinishesInFlightPush2684=== PAUSE TestShutdownFinishesInFlightPush2685=== RUN TestWorkerRemoveFailureIsNotProgress2686=== PAUSE TestWorkerRemoveFailureIsNotProgress2687=== RUN TestWorkerKeepsPathItCannotStat2688=== PAUSE TestWorkerKeepsPathItCannotStat2689=== CONT TestSendPathsEmpty2690=== CONT TestDrainGivesUpWhenServerDown2691=== CONT TestWorkerSkipsGCdPaths2692=== CONT TestQueueFetchBatchLimit2693=== CONT TestWorkerPrunesClosureDeps2694=== CONT TestQueueDeduplication2695=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2696=== CONT TestWorkerRemoveFailureIsNotProgress2697=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2698=== CONT TestShutdownFinishesInFlightPush2699=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2700=== RUN TestShutdownFinishesInFlightPush/completes2701=== PAUSE TestShutdownFinishesInFlightPush/completes2702=== CONT TestFailedPathPrunedByLaterClosure2703=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2704=== CONT TestDrainTimeoutDuringIsolation2705=== CONT TestQueueRetryMovesToBack2706=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2707=== CONT TestServerBacksOffOnAcceptErrors2708=== CONT TestDrainTimeout2709=== CONT TestServerStalledClientDoesNotBlockShutdown27102026/10/09 18:07:18 ERROR Accept failed error="too many open files"2711=== CONT TestQueueEnqueueWaitsOutSlowWriter2712--- PASS: TestSendPathsEmpty (0.00s)2713=== CONT TestServerRefusesOversizedAndNonStoreRequests2714=== CONT TestQueueConcurrentWriters2715=== CONT TestQueueRemoveLargeClosure2716=== CONT TestQueueFetchRemoveLifecycle2717=== CONT TestDrainIsolatesPoisonPath2718=== CONT TestQueueEnqueueAndFetch2719=== CONT TestQueueRemove2720=== CONT TestWorkerUploadsAndRemoves27212026/10/09 18:07:18 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2722=== CONT TestWorkerKeepsPathItCannotStat2723=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2724=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2725=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2726=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2727=== CONT TestRunNotBlockedByPoisonHead2728=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2729=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2730=== CONT TestShutdownFinishesInFlightPush/completes2731=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2732=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths27332026/10/09 18:07:18 ERROR Refusing path outside the store path=/nix/store store=/nix/store2734=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout27352026/10/09 18:07:18 ERROR Accept failed error="too many open files"27362026/10/09 18:07:18 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store27372026/10/09 18:07:18 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store27382026/10/09 18:07:18 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store27392026/10/09 18:07:18 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27402026/10/09 18:07:18 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27412026/10/09 18:07:18 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store27422026/10/09 18:07:18 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store27432026/10/09 18:07:18 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store27442026/10/09 18:07:18 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store27452026/10/09 18:07:18 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store27462026/10/09 18:07:18 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store27472026/10/09 18:07:18 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store27482026/10/09 18:07:18 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store27492026/10/09 18:07:18 ERROR Failed to decode request error="unexpected EOF"2750--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2751=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline27522026/10/09 18:07:18 ERROR Accept failed error="too many open files"27532026/10/09 18:07:18 INFO Uploading batch count=127542026/10/09 18:07:18 ERROR Upload failed error="upload failed" count=127552026/10/09 18:07:18 INFO Upload queue status pending=227562026/10/09 18:07:18 INFO Uploading batch count=227572026/10/09 18:07:18 INFO Upload queue status pending=227582026/10/09 18:07:18 INFO Uploading batch count=227592026/10/09 18:07:18 INFO Uploading batch count=227602026/10/09 18:07:18 INFO Uploading batch count=12761--- PASS: TestQueueEnqueueAndFetch (0.03s)2762=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short27632026/10/09 18:07:18 INFO Uploading batch count=427642026/10/09 18:07:18 ERROR Upload failed error="upload failed" count=427652026/10/09 18:07:18 INFO Upload queue status pending=227662026/10/09 18:07:18 INFO Uploading batch count=227672026/10/09 18:07:18 ERROR Upload failed error="upload failed" count=227682026/10/09 18:07:18 WARN Cannot stat store path, will retry later path=/private/var/tb/7/scratch/be18d57bca741e73/build/TestWorkerKeepsPathItCannotStat719981998/002/locked/aaa error="lstat /private/var/tb/7/scratch/be18d57bca741e73/build/TestWorkerKeepsPathItCannotStat719981998/002/locked/aaa: permission denied"27692026/10/09 18:07:18 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/be18d57bca741e73/build/TestDrainGivesUpWhenServerDown1581367807/002/a27702026/10/09 18:07:18 INFO Uploading batch count=227712026/10/09 18:07:18 INFO Upload queue status pending=227722026/10/09 18:07:18 INFO Upload queue status pending=227732026/10/09 18:07:18 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/be18d57bca741e73/build/TestDrainIsolatesPoisonPath3386284812/002/bbb27742026/10/09 18:07:18 INFO Uploading batch count=127752026/10/09 18:07:18 INFO Uploading batch count=427762026/10/09 18:07:18 ERROR Upload failed error="upload failed" count=427772026/10/09 18:07:18 INFO Upload queue status pending=32778--- PASS: TestQueueFetchBatchLimit (0.03s)2779=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27802026/10/09 18:07:18 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/be18d57bca741e73/build/TestDrainGivesUpWhenServerDown1581367807/002/b27812026/10/09 18:07:18 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/7/scratch/be18d57bca741e73/build/TestWorkerSkipsGCdPaths783063764/002/nonexistent27822026/10/09 18:07:18 INFO Uploading batch count=227832026/10/09 18:07:18 INFO Uploading batch count=127842026/10/09 18:07:18 WARN Cannot stat store path, will retry later path=/private/var/tb/7/scratch/be18d57bca741e73/build/TestWorkerKeepsPathItCannotStat719981998/002/locked/aaa error="lstat /private/var/tb/7/scratch/be18d57bca741e73/build/TestWorkerKeepsPathItCannotStat719981998/002/locked/aaa: permission denied"27852026/10/09 18:07:18 INFO Upload queue status pending=32786--- PASS: TestQueueRemove (0.03s)2787=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths27882026/10/09 18:07:18 INFO Uploading batch count=227892026/10/09 18:07:18 ERROR Upload failed error="upload failed" count=227902026/10/09 18:07:18 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/be18d57bca741e73/build/TestDrainGivesUpWhenServerDown1581367807/002/c27912026/10/09 18:07:18 INFO Uploading batch count=127922026/10/09 18:07:18 ERROR Upload failed error="upload failed" count=127932026/10/09 18:07:18 INFO Uploading batch count=227942026/10/09 18:07:18 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/be18d57bca741e73/build/TestDrainGivesUpWhenServerDown1581367807/002/d27952026/10/09 18:07:18 WARN Cannot stat store path, will retry later path=/private/var/tb/7/scratch/be18d57bca741e73/build/TestWorkerKeepsPathItCannotStat719981998/002/locked/aaa error="lstat /private/var/tb/7/scratch/be18d57bca741e73/build/TestWorkerKeepsPathItCannotStat719981998/002/locked/aaa: permission denied"2796=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch2797--- PASS: TestQueueDeduplication (0.03s)27982026/10/09 18:07:18 INFO Uploading batch count=127992026/10/09 18:07:18 ERROR Upload failed error="upload failed" count=128002026/10/09 18:07:18 ERROR Accept failed error="too many open files"2801--- PASS: TestQueueRetryMovesToBack (0.04s)28022026/10/09 18:07:18 INFO Uploading batch count=228032026/10/09 18:07:18 ERROR Drain finished with paths left in queue remaining=128042026/10/09 18:07:18 ERROR Upload failed error="upload failed" count=228052026/10/09 18:07:18 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/be18d57bca741e73/build/TestDrainGivesUpWhenServerDown1581367807/002/e2806--- PASS: TestQueueFetchRemoveLifecycle (0.04s)28072026/10/09 18:07:18 INFO Uploading batch count=128082026/10/09 18:07:18 ERROR Upload failed error="upload failed" count=12809--- PASS: TestFailedPathPrunedByLaterClosure (0.04s)28102026/10/09 18:07:18 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/7/scratch/be18d57bca741e73/build/TestDrainGivesUpWhenServerDown1581367807/002/f28112026/10/09 18:07:18 INFO Uploading batch count=128122026/10/09 18:07:18 ERROR Upload failed error="upload failed" count=128132026/10/09 18:07:18 INFO Uploading batch count=428142026/10/09 18:07:18 ERROR Upload failed error="upload failed" count=42815--- PASS: TestWorkerKeepsPathItCannotStat (0.04s)28162026/10/09 18:07:18 ERROR Drain finished with paths left in queue remaining=1028172026/10/09 18:07:18 ERROR Drain finished with paths left in queue remaining=12818--- PASS: TestDrainIsolatesPoisonPath (0.04s)2819--- PASS: TestDrainGivesUpWhenServerDown (0.04s)28202026/10/09 18:07:18 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/7/scratch/be18d57bca741e73/build/TestWorkerRemoveFailureIsNotProgresscollected_path2976877382/001/nonexistent28212026/10/09 18:07:18 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128222026/10/09 18:07:18 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/7/scratch/be18d57bca741e73/build/TestWorkerRemoveFailureIsNotProgresscollected_path2976877382/001/nonexistent28232026/10/09 18:07:18 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128242026/10/09 18:07:18 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/7/scratch/be18d57bca741e73/build/TestWorkerRemoveFailureIsNotProgresscollected_path2976877382/001/nonexistent28252026/10/09 18:07:18 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128262026/10/09 18:07:18 INFO Uploading batch count=228272026/10/09 18:07:18 ERROR Upload failed error="upload failed" count=228282026/10/09 18:07:18 ERROR Drain finished with paths left in queue remaining=128292026/10/09 18:07:18 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128302026/10/09 18:07:18 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128312026/10/09 18:07:18 INFO Uploading batch count=228322026/10/09 18:07:18 ERROR Upload failed error="upload failed" count=228332026/10/09 18:07:18 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128342026/10/09 18:07:18 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128352026/10/09 18:07:18 INFO Uploading batch count=228362026/10/09 18:07:18 INFO Uploading batch count=228372026/10/09 18:07:18 ERROR Upload failed error="upload failed" count=228382026/10/09 18:07:18 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228392026/10/09 18:07:18 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128402026/10/09 18:07:18 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128412026/10/09 18:07:18 INFO Uploading batch count=228422026/10/09 18:07:18 ERROR Drain finished with paths left in queue remaining=228432026/10/09 18:07:18 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228442026/10/09 18:07:18 INFO Uploading batch count=228452026/10/09 18:07:18 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228462026/10/09 18:07:18 ERROR Drain finished with paths left in queue remaining=22847--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2848 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.01s)2849 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.01s)2850 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.01s)2851--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.05s)2852--- PASS: TestWorkerUploadsAndRemoves (0.05s)2853--- PASS: TestWorkerPrunesClosureDeps (0.05s)2854--- PASS: TestWorkerSkipsGCdPaths (0.05s)28552026/10/09 18:07:18 ERROR Accept failed error="too many open files"28562026/10/09 18:07:18 ERROR Accept failed error="too many open files"2857--- PASS: TestQueueConcurrentWriters (0.16s)28582026/10/09 18:07:18 ERROR Failed to decode request error="read unix /private/var/tb/7/scratch/be18d57bca741e73/build/hook905468741/test.sock->: i/o timeout"28592026/10/09 18:07:18 ERROR Failed to write response error="write unix /private/var/tb/7/scratch/be18d57bca741e73/build/hook905468741/test.sock->: i/o timeout"2860--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)28612026/10/09 18:07:18 ERROR Upload failed error="context canceled" count=228622026/10/09 18:07:18 ERROR Drain finished with paths left in queue remaining=42863--- PASS: TestDrainTimeout (0.23s)28642026/10/09 18:07:18 ERROR Upload failed error="context canceled" count=228652026/10/09 18:07:18 ERROR Drain finished with paths left in queue remaining=22866--- PASS: TestShutdownFinishesInFlightPush (0.00s)2867 --- PASS: TestShutdownFinishesInFlightPush/completes (0.12s)2868 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.22s)28692026/10/09 18:07:18 ERROR Drain finished with paths left in queue remaining=428702026/10/09 18:07:18 ERROR Accept failed error="too many open files"28712026/10/09 18:07:18 ERROR Drain finished with paths left in queue remaining=32872--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2873 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.21s)2874 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.32s)28752026/10/09 18:07:19 ERROR Accept failed error="too many open files"2876--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)2877--- PASS: TestQueueRemoveLargeClosure (0.82s)28782026/10/09 18:07:19 INFO Uploading batch count=128792026/10/09 18:07:19 INFO Uploading batch count=128802026/10/09 18:07:19 INFO Uploading batch count=128812026/10/09 18:07:19 ERROR Upload failed error="upload failed" count=128822026/10/09 18:07:19 INFO Uploading batch count=128832026/10/09 18:07:19 ERROR Upload failed error="upload failed" count=128842026/10/09 18:07:19 INFO Uploading batch count=128852026/10/09 18:07:19 ERROR Upload failed error="upload failed" count=128862026/10/09 18:07:19 INFO Uploading batch count=128872026/10/09 18:07:19 ERROR Upload failed error="upload failed" count=128882026/10/09 18:07:19 ERROR Drain finished with paths left in queue remaining=12889--- PASS: TestRunNotBlockedByPoisonHead (1.07s)2890--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.03s)2891PASS2892Running signing tests...2893=== RUN TestExternalSigner2894=== PAUSE TestExternalSigner2895=== RUN TestExternalSignerWrongPublicKey2896=== PAUSE TestExternalSignerWrongPublicKey2897=== RUN TestExternalSignerErrors2898=== PAUSE TestExternalSignerErrors2899=== RUN TestExternalSignerRestartsAfterCrash2900=== PAUSE TestExternalSignerRestartsAfterCrash2901=== RUN TestExternalSignerProgramErrorKeepsProcess2902=== PAUSE TestExternalSignerProgramErrorKeepsProcess2903=== RUN TestExternalSignerClose2904=== PAUSE TestExternalSignerClose2905=== RUN TestExternalSignerRejectsInvalidPublicKey2906=== PAUSE TestExternalSignerRejectsInvalidPublicKey2907=== RUN TestExternalSignerCancellation2908=== PAUSE TestExternalSignerCancellation2909=== RUN TestGenerateFingerprint2910=== PAUSE TestGenerateFingerprint2911=== RUN TestParseSigningKey2912=== PAUSE TestParseSigningKey2913=== RUN TestSign2914=== PAUSE TestSign2915=== RUN TestSignBatch2916=== PAUSE TestSignBatch2917=== RUN TestNilKeyPublicKey2918=== PAUSE TestNilKeyPublicKey2919=== RUN TestSignErrors2920=== PAUSE TestSignErrors2921=== CONT TestExternalSignerWrongPublicKey2922=== CONT TestExternalSignerRejectsInvalidPublicKey2923=== CONT TestSignBatch2924=== RUN TestExternalSignerRejectsInvalidPublicKey/#002925=== CONT TestExternalSignerClose2926=== CONT TestExternalSignerProgramErrorKeepsProcess2927=== CONT TestGenerateFingerprint2928=== RUN TestGenerateFingerprint/basic_with_references2929=== CONT TestSign2930=== CONT TestSignErrors2931=== CONT TestExternalSignerErrors2932=== RUN TestExternalSignerErrors/exit_on_request2933=== PAUSE TestExternalSignerErrors/exit_on_request2934=== PAUSE TestGenerateFingerprint/basic_with_references2935=== RUN TestExternalSignerErrors/invalid_JSON2936=== RUN TestGenerateFingerprint/no_references2937=== CONT TestParseSigningKey2938=== RUN TestParseSigningKey/valid_32-byte_key2939=== PAUSE TestParseSigningKey/valid_32-byte_key2940=== CONT TestExternalSigner2941=== CONT TestNilKeyPublicKey2942=== CONT TestExternalSignerCancellation2943=== CONT TestExternalSignerRestartsAfterCrash2944=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002945=== PAUSE TestGenerateFingerprint/no_references2946--- PASS: TestNilKeyPublicKey (0.00s)2947=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2948=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2949=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2950=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2951=== PAUSE TestExternalSignerErrors/invalid_JSON2952=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2953=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2954=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2955=== RUN TestGenerateFingerprint/invalid_nar_hash_length2956=== RUN TestExternalSignerErrors/null2957=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2958=== PAUSE TestExternalSignerErrors/null2959=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2960=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2961=== RUN TestGenerateFingerprint/invalid_store_path_prefix2962=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2963=== RUN TestGenerateFingerprint/invalid_reference_prefix2964=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2965=== RUN TestParseSigningKey/no_colon2966=== PAUSE TestParseSigningKey/no_colon2967=== RUN TestParseSigningKey/empty_name2968=== PAUSE TestParseSigningKey/empty_name2969=== RUN TestParseSigningKey/invalid_base642970=== PAUSE TestParseSigningKey/invalid_base642971=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2972=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2973=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2974=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2975=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2976=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2977=== CONT TestGenerateFingerprint/no_references2978=== CONT TestGenerateFingerprint/basic_with_references2979=== CONT TestExternalSignerRejectsInvalidPublicKey/#002980=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2981=== CONT TestGenerateFingerprint/invalid_store_path_prefix2982=== CONT TestGenerateFingerprint/invalid_nar_hash_length2983=== RUN TestParseSigningKey/wrong_length2984=== RUN TestExternalSignerErrors/wrong_id2985=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2986=== PAUSE TestExternalSignerErrors/wrong_id2987=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2988=== CONT TestGenerateFingerprint/invalid_reference_prefix2989=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2990=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2991=== PAUSE TestParseSigningKey/wrong_length2992=== RUN TestExternalSignerErrors/null_signatures2993=== PAUSE TestExternalSignerErrors/null_signatures2994=== RUN TestExternalSignerErrors/too_few_signatures2995=== PAUSE TestExternalSignerErrors/too_few_signatures2996--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2997 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2998 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2999 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)3000 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)3001 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)3002=== RUN TestExternalSignerErrors/missing_signature_name3003--- PASS: TestGenerateFingerprint (0.00s)3004 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)3005 --- PASS: TestGenerateFingerprint/no_references (0.00s)3006 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)3007 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)3008 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)3009 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)3010 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)3011=== PAUSE TestExternalSignerErrors/missing_signature_name3012=== RUN TestExternalSignerErrors/wrong_signature_name3013=== PAUSE TestExternalSignerErrors/wrong_signature_name3014=== RUN TestExternalSignerErrors/program_error3015=== CONT TestParseSigningKey/invalid_base643016=== PAUSE TestExternalSignerErrors/program_error3017=== CONT TestParseSigningKey/valid_32-byte_key3018=== CONT TestParseSigningKey/no_colon3019=== RUN TestExternalSignerErrors/missing_signatures3020=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name3021=== PAUSE TestExternalSignerErrors/missing_signatures3022=== CONT TestParseSigningKey/empty_name3023=== CONT TestParseSigningKey/wrong_length3024=== RUN TestExternalSignerErrors/wrong_signatures_shape3025=== PAUSE TestExternalSignerErrors/wrong_signatures_shape3026=== RUN TestExternalSignerErrors/unrequested_key3027=== PAUSE TestExternalSignerErrors/unrequested_key3028=== RUN TestExternalSignerErrors/invalid_signature_base643029=== PAUSE TestExternalSignerErrors/invalid_signature_base643030=== RUN TestExternalSignerErrors/wrong_signature_length3031=== PAUSE TestExternalSignerErrors/wrong_signature_length3032=== RUN TestExternalSignerErrors/exit_at_startup3033=== PAUSE TestExternalSignerErrors/exit_at_startup3034=== RUN TestExternalSignerErrors/wrong_shape3035=== PAUSE TestExternalSignerErrors/wrong_shape3036=== CONT TestExternalSignerErrors/null3037=== CONT TestExternalSignerErrors/wrong_signature_name3038=== CONT TestExternalSignerErrors/missing_signature_name3039=== CONT TestExternalSignerErrors/wrong_id3040=== RUN TestSignErrors/nil_key3041=== CONT TestExternalSignerErrors/program_error3042=== CONT TestExternalSignerErrors/null_signatures3043=== CONT TestExternalSignerErrors/missing_signatures3044--- PASS: TestParseSigningKey (0.01s)3045 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)3046 --- PASS: TestParseSigningKey/no_colon (0.00s)3047 --- PASS: TestParseSigningKey/empty_name (0.00s)3048 --- PASS: TestParseSigningKey/wrong_length (0.00s)3049 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)3050 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)3051=== CONT TestExternalSignerErrors/wrong_signatures_shape3052--- PASS: TestSign (0.01s)3053=== PAUSE TestSignErrors/nil_key3054=== CONT TestExternalSignerErrors/wrong_signature_length3055=== CONT TestExternalSignerErrors/wrong_shape3056=== CONT TestExternalSignerErrors/too_few_signatures3057=== CONT TestExternalSignerErrors/exit_at_startup3058=== CONT TestExternalSignerErrors/invalid_signature_base643059=== CONT TestExternalSignerErrors/invalid_JSON3060=== CONT TestExternalSignerErrors/unrequested_key3061=== CONT TestExternalSignerErrors/exit_on_request3062=== RUN TestSignErrors/nil_narinfo3063=== PAUSE TestSignErrors/nil_narinfo3064=== RUN TestSignErrors/invalid_narinfo3065=== PAUSE TestSignErrors/invalid_narinfo3066=== RUN TestSignErrors/canceled3067=== PAUSE TestSignErrors/canceled3068=== CONT TestSignErrors/nil_key3069=== CONT TestSignErrors/invalid_narinfo3070=== CONT TestSignErrors/canceled3071=== CONT TestSignErrors/nil_narinfo3072--- PASS: TestSignErrors (0.01s)3073 --- PASS: TestSignErrors/nil_key (0.00s)3074 --- PASS: TestSignErrors/invalid_narinfo (0.00s)3075 --- PASS: TestSignErrors/canceled (0.00s)3076 --- PASS: TestSignErrors/nil_narinfo (0.00s)3077--- PASS: TestSignBatch (0.02s)3078--- PASS: TestExternalSignerClose (0.23s)3079--- PASS: TestExternalSignerWrongPublicKey (0.42s)3080--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.60s)3081--- PASS: TestExternalSignerRestartsAfterCrash (0.81s)3082--- PASS: TestExternalSigner (1.00s)3083--- PASS: TestExternalSignerCancellation (1.19s)3084--- PASS: TestExternalSignerErrors (0.01s)3085 --- PASS: TestExternalSignerErrors/wrong_signature_name (1.36s)3086 --- PASS: TestExternalSignerErrors/null (1.55s)3087 --- PASS: TestExternalSignerErrors/missing_signature_name (1.74s)3088 --- PASS: TestExternalSignerErrors/missing_signatures (1.93s)3089 --- PASS: TestExternalSignerErrors/program_error (2.12s)3090 --- PASS: TestExternalSignerErrors/null_signatures (2.36s)3091 --- PASS: TestExternalSignerErrors/too_few_signatures (2.55s)3092 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (2.74s)3093 --- PASS: TestExternalSignerErrors/wrong_id (2.94s)3094 --- PASS: TestExternalSignerErrors/wrong_signature_length (3.13s)3095 --- PASS: TestExternalSignerErrors/exit_at_startup (3.32s)3096 --- PASS: TestExternalSignerErrors/unrequested_key (3.51s)3097 --- PASS: TestExternalSignerErrors/wrong_shape (3.70s)3098 --- PASS: TestExternalSignerErrors/invalid_JSON (3.89s)3099 --- PASS: TestExternalSignerErrors/exit_on_request (4.07s)3100 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (4.27s)3101PASS3102Running OpenBao signer tests...3103=== RUN TestSign3104=== PAUSE TestSign3105=== RUN TestSignErrors3106=== PAUSE TestSignErrors3107=== RUN TestServe3108=== PAUSE TestServe3109=== RUN TestServeRejectsGarbage3110=== PAUSE TestServeRejectsGarbage3111=== CONT TestServeRejectsGarbage3112=== CONT TestServe3113=== CONT TestSign3114=== CONT TestSignErrors3115=== RUN TestSignErrors/invalid_base643116--- PASS: TestServeRejectsGarbage (0.00s)3117=== PAUSE TestSignErrors/invalid_base643118=== RUN TestSignErrors/http_error3119=== PAUSE TestSignErrors/http_error3120=== RUN TestSignErrors/invalid_json3121=== PAUSE TestSignErrors/invalid_json3122=== RUN TestSignErrors/no_prefix3123=== PAUSE TestSignErrors/no_prefix3124=== CONT TestSignErrors/invalid_base643125=== CONT TestSignErrors/http_error3126=== CONT TestSignErrors/no_prefix3127=== CONT TestSignErrors/invalid_json3128--- PASS: TestServe (0.00s)3129--- PASS: TestSign (0.00s)3130--- PASS: TestSignErrors (0.00s)3131 --- PASS: TestSignErrors/no_prefix (0.00s)3132 --- PASS: TestSignErrors/invalid_json (0.00s)3133 --- PASS: TestSignErrors/invalid_base64 (0.00s)3134 --- PASS: TestSignErrors/http_error (0.00s)3135PASS3136Running niks3-hook command tests...3137=== RUN TestServeSecondSignalEndsDrain3138=== PAUSE TestServeSecondSignalEndsDrain3139=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown3140=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown3141=== CONT TestServeSecondSignalEndsDrain3142=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown3143--- PASS: TestServeSecondSignalEndsDrain (0.07s)31442026/10/09 18:07:33 INFO Uploading batch count=13145--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.12s)3146PASS3147Running rate limiter tests...3148=== RUN TestAdaptiveRateLimiter_ThreadSafety3149=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3150=== CONT TestAdaptiveRateLimiter_ThreadSafety31512026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=7031522026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=4931532026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=34.331542026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=24.00999999999999831552026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=16.80731562026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=11.76489999999999931572026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=8.2354331582026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=5.76480099999999931592026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531602026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531612026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531622026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531632026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531642026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531652026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531662026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531672026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531682026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531692026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531702026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531712026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531722026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531732026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531742026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531752026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531762026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531772026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531782026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531792026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531802026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531812026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531822026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531832026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531842026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531852026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531862026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531872026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531882026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531892026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531902026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531912026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531922026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531932026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531942026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531952026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531962026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531972026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531982026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=531992026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532002026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532012026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532022026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532032026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532042026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532052026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532062026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=6.82050985000000232072026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532082026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532092026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532102026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532112026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532122026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532132026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532142026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532152026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532162026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532172026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532182026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532192026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532202026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532212026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532222026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532232026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532242026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532252026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=5.12435000000000132262026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532272026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532282026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532292026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532302026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532312026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532322026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532332026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=6.200463500000001532342026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532352026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532362026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532372026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532382026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532392026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532402026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532412026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532422026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532432026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532442026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=532452026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=21.40568165694512432462026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=14.98397715986158532472026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=10.48878401190310932482026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=7.34214880833217532492026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=5.139504165832522532502026/10/09 18:07:34 WARN Rate limiter backed off name=test rate=53251--- PASS: TestAdaptiveRateLimiter_ThreadSafety (0.11s)3252PASS