niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #444
· raw
1tribuchet: building on mac022Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure18=== PAUSE TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure19=== RUN TestUploadMultipart_PartsInParallel20=== PAUSE TestUploadMultipart_PartsInParallel21=== RUN TestUploadMultipart_FailedPartBufferNotReused22=== PAUSE TestUploadMultipart_FailedPartBufferNotReused23=== RUN TestUploadMultipart_ProducerErrorIsNotEOF24=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestUploadMultipart_SupersededByPeer28=== PAUSE TestUploadMultipart_SupersededByPeer29=== RUN TestDumpPathCaseHackMatchesNix30--- PASS: TestDumpPathCaseHackMatchesNix (0.16s)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.37s)46=== RUN TestEncodeNixBase3247=== PAUSE TestEncodeNixBase3248=== RUN TestEncodeNixBase32WithRealHash49=== PAUSE TestEncodeNixBase32WithRealHash50=== RUN TestConvertHashToNix3251=== PAUSE TestConvertHashToNix3252=== RUN TestGetStorePathHash53=== PAUSE TestGetStorePathHash54=== RUN TestPathInfoHashCompatibility55=== PAUSE TestPathInfoHashCompatibility56=== RUN TestParsePathInfoJSON57=== PAUSE TestParsePathInfoJSON58=== RUN TestParsePathInfoJSONMultiplePaths59=== PAUSE TestParsePathInfoJSONMultiplePaths60=== RUN TestPathInfoCACompatibility61=== PAUSE TestPathInfoCACompatibility62=== RUN TestUploadPendingObjectsStopsStartingAfterFailure63--- PASS: TestUploadPendingObjectsStopsStartingAfterFailure (0.01s)64=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent65=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent66=== RUN TestCompletePendingClosure_NotFoundWithoutKey67=== PAUSE TestCompletePendingClosure_NotFoundWithoutKey68=== RUN TestRateLimiterFeedback69=== PAUSE TestRateLimiterFeedback70=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess71=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess72=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer73=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer74=== RUN TestResolveStorePath75=== PAUSE TestResolveStorePath76=== RUN TestDoWithRetry_BodyReplayedViaGetBody77=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody78=== RUN TestRetryTimeoutOutlastsMaxRetries79=== PAUSE TestRetryTimeoutOutlastsMaxRetries80=== RUN TestDoWithRetry_FinalResponseBodyReadable81=== PAUSE TestDoWithRetry_FinalResponseBodyReadable82=== RUN TestShellSplit83=== PAUSE TestShellSplit84=== RUN TestShellSplitErrors85=== PAUSE TestShellSplitErrors86=== RUN TestStreamPushReportsEveryPath87=== PAUSE TestStreamPushReportsEveryPath88=== RUN TestStreamPushBatchesUnderLoad89=== PAUSE TestStreamPushBatchesUnderLoad90=== RUN TestStreamPushIsolatesFailures91=== PAUSE TestStreamPushIsolatesFailures92=== RUN TestStreamPushGivesUpOnDeadServer93=== PAUSE TestStreamPushGivesUpOnDeadServer94=== RUN TestStreamPushRequestLine95=== PAUSE TestStreamPushRequestLine96=== RUN TestStreamPushReportsSignatures97=== PAUSE TestStreamPushReportsSignatures98=== RUN TestStreamPushReportsSkippedPaths99=== PAUSE TestStreamPushReportsSkippedPaths100=== RUN TestClientSignaturesByStorePath101=== PAUSE TestClientSignaturesByStorePath102=== RUN TestStreamPushStopsWhenCanceled103=== PAUSE TestStreamPushStopsWhenCanceled104=== RUN TestStreamPushStopsOnCancel105=== PAUSE TestStreamPushStopsOnCancel106=== RUN TestStreamPushStartsNothingOnSlotFreedByCancel107=== PAUSE TestStreamPushStartsNothingOnSlotFreedByCancel108=== RUN TestSetClientTLS109=== PAUSE TestSetClientTLS110=== RUN TestSetClientTLSDoesNotMutateDefaultTransport111=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport112=== RUN TestSetClientTLSErrors113=== PAUSE TestSetClientTLSErrors114=== RUN TestStaticToken115=== PAUSE TestStaticToken116=== RUN TestFileTokenReadsAndCaches117=== PAUSE TestFileTokenReadsAndCaches118=== RUN TestFileTokenMissing119=== PAUSE TestFileTokenMissing120=== RUN TestFileTokenEmpty121=== PAUSE TestFileTokenEmpty122=== RUN TestScriptTokenNoExpiryRerunsEveryCall123=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall124=== RUN TestScriptTokenCachesUntilRefresh125=== PAUSE TestScriptTokenCachesUntilRefresh126=== RUN TestScriptTokenEmptyToken127=== PAUSE TestScriptTokenEmptyToken128=== RUN TestScriptTokenBadJSON129=== PAUSE TestScriptTokenBadJSON130=== RUN TestScriptTokenScriptFails131=== PAUSE TestScriptTokenScriptFails132=== RUN TestScriptTokenEmptyCommand133=== PAUSE TestScriptTokenEmptyCommand134=== RUN TestScriptTokenDoesNotWaitForItsChildren135=== PAUSE TestScriptTokenDoesNotWaitForItsChildren136=== CONT TestRegisterUploadedObjectReusesConnections137=== CONT TestScriptTokenEmptyCommand138=== CONT TestRateLimiterFeedback139--- PASS: TestScriptTokenEmptyCommand (0.00s)140=== CONT TestScriptTokenDoesNotWaitForItsChildren141=== RUN TestRateLimiterFeedback/429_enables_limiter142=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs143=== PAUSE TestRateLimiterFeedback/429_enables_limiter144=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer145=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs146=== CONT TestResolveStorePath147=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent148=== CONT TestParsePathInfoJSONMultiplePaths149=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths150=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths151=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths152=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths153=== CONT TestPathInfoCACompatibility154=== RUN TestPathInfoCACompatibility/null_ca_field155=== CONT TestFileTokenEmpty156=== CONT TestPathInfoHashCompatibility157=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)158=== CONT TestParsePathInfoJSON159=== CONT TestConvertHashToNix32160=== CONT TestEncodeNixBase32WithRealHash161=== CONT TestEncodeNixBase32162=== CONT TestGetStorePathHash163=== CONT TestDumpPathSingleFile164=== CONT TestSetClientTLS165=== CONT TestScriptTokenScriptFails166=== CONT TestScriptTokenBadJSON167=== CONT TestScriptTokenEmptyToken168=== CONT TestScriptTokenCachesUntilRefresh169=== CONT TestUploadMultipart_PartsInParallel170=== CONT TestScriptTokenNoExpiryRerunsEveryCall171=== CONT TestDumpPathWriterError172=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess173=== RUN TestRateLimiterFeedback/503_enables_limiter174=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout175=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier176=== RUN TestParsePathInfoJSON/Nix_format177=== RUN TestEncodeNixBase32/test_string_hash178=== PAUSE TestParsePathInfoJSON/Nix_format179=== PAUSE TestEncodeNixBase32/test_string_hash180=== RUN TestParsePathInfoJSON/Lix_format181=== PAUSE TestParsePathInfoJSON/Lix_format182=== RUN TestEncodeNixBase32/empty_input183--- PASS: TestResolveStorePath (0.00s)184--- PASS: TestFileTokenEmpty (0.00s)185=== RUN TestParsePathInfoJSON/empty_input186--- PASS: TestEncodeNixBase32WithRealHash (0.00s)187=== PAUSE TestParsePathInfoJSON/empty_input188=== PAUSE TestEncodeNixBase32/empty_input189=== CONT TestFileTokenMissing190=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)191=== CONT TestFileTokenReadsAndCaches192=== CONT TestPartSizeForNAR193=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier194=== CONT TestSetClientTLSErrors195=== PAUSE TestPathInfoCACompatibility/null_ca_field196=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout197=== RUN TestGetStorePathHash/valid_store_path198=== RUN TestConvertHashToNix32/SRI_format_to_Nix32199=== RUN TestParsePathInfoJSON/whitespace_only200--- PASS: TestScriptTokenScriptFails (0.01s)201=== CONT TestStaticToken202--- PASS: TestStaticToken (0.00s)203=== PAUSE TestRateLimiterFeedback/503_enables_limiter204=== CONT TestStreamPushStartsNothingOnSlotFreedByCancel205=== PAUSE TestParsePathInfoJSON/whitespace_only206=== CONT TestSetClientTLSDoesNotMutateDefaultTransport207=== PAUSE TestGetStorePathHash/valid_store_path208=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32209=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon210=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up211=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter212=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter213=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon214=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up215=== RUN TestParsePathInfoJSON/invalid_JSON216=== PAUSE TestParsePathInfoJSON/invalid_JSON217=== CONT TestStreamPushStopsOnCancel218--- PASS: TestFileTokenMissing (0.00s)219=== RUN TestPartSizeForNAR/zero_stays_at_minimum220=== RUN TestPathInfoCACompatibility/old_string_format_-_text221=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum222=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier223=== RUN TestPartSizeForNAR/small_stays_at_minimum224=== RUN TestStreamPushStopsOnCancel/waiting_for_input225=== PAUSE TestPartSizeForNAR/small_stays_at_minimum226=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier227=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client228=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client229=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter230=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter231=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum232=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum233=== RUN TestGetStorePathHash/basename_without_hyphen_should_error234=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error235=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error236=== RUN TestSetClientTLS/rejects_connection_without_client_cert237=== CONT TestUploadMultipart_FailedPartBufferNotReused238=== RUN TestSetClientTLSErrors/missing_cert_file239=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts240=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts241=== RUN TestPartSizeForNAR/1_TiB242=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text243=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive244=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error245=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error246=== RUN TestConvertHashToNix32/already_Nix32_format247=== PAUSE TestConvertHashToNix32/already_Nix32_format248=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert249--- PASS: TestScriptTokenBadJSON (0.02s)250=== PAUSE TestPartSizeForNAR/1_TiB251=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive252=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error253=== RUN TestConvertHashToNix32/invalid_format254=== PAUSE TestConvertHashToNix32/invalid_format255=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA256=== RUN TestPathInfoCACompatibility/new_structured_format_-_text257--- PASS: TestFileTokenReadsAndCaches (0.01s)258=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input259=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA260=== CONT TestUploadMultipart_ProducerErrorIsNotEOF261=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part262=== CONT TestClientSignaturesByStorePath263=== CONT TestStreamPushReportsSkippedPaths264=== CONT TestStreamPushStopsWhenCanceled265=== CONT TestStreamPushIsolatesFailures266=== PAUSE TestSetClientTLSErrors/missing_cert_file267=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI268=== RUN TestPartSizeForNAR/5_TiB_S3_max_object269=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client270=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text271=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot272=== CONT TestStreamPushReportsSignatures273=== CONT TestStreamPushBatchesUnderLoad274=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false275=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false276=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true277=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true278=== CONT TestSupersededNARStillUploadsListing279=== RUN TestSupersededNARStillUploadsListing/small_NAR280=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client281=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI282=== PAUSE TestSupersededNARStillUploadsListing/small_NAR283=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512284=== RUN TestSupersededNARStillUploadsListing/dump_cut_short285=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot286--- PASS: TestScriptTokenEmptyToken (0.03s)287=== CONT TestStreamPushRequestLine288--- PASS: TestStreamPushIsolatesFailures (0.00s)289--- PASS: TestStreamPushReportsSignatures (0.00s)290=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short291=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails292=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails293=== CONT TestRetryTimeoutOutlastsMaxRetries294=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object295=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512296=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part297=== CONT TestStreamPushGivesUpOnDeadServer298=== RUN TestSetClientTLSErrors/missing_key_file299=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica300=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method301=== CONT TestDumpPathMatchesNix302=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot303=== RUN TestPartSizeForNAR/capped_at_5_GiB304=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure305=== RUN TestSetClientTLS/preserves_debug_logging_transport306--- PASS: TestClientSignaturesByStorePath (0.00s)307=== CONT TestFilterOversizedClosures308=== CONT TestShellSplitErrors309=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary310=== PAUSE TestSetClientTLSErrors/missing_key_file311=== CONT TestShellSplit312=== PAUSE TestPartSizeForNAR/capped_at_5_GiB313=== CONT TestDoWithRetry_FinalResponseBodyReadable314=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot315=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method316--- PASS: TestStreamPushStopsWhenCanceled (0.00s)317=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot318--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)319--- PASS: TestStreamPushReportsSkippedPaths (0.00s)320--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)321--- PASS: TestShellSplitErrors (0.00s)322--- PASS: TestShellSplit (0.00s)323--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)324=== RUN TestFilterOversizedClosures/no_limit_keeps_everything325--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.02s)326=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything327=== RUN TestSetClientTLSErrors/missing_ca_file328=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped329=== PAUSE TestSetClientTLS/preserves_debug_logging_transport330=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary331=== CONT TestDoWithRetry_BodyReplayedViaGetBody332=== CONT TestTruncatedNARDumpIsNotCompleted333=== CONT TestCaseHackSuffix334=== CONT TestStreamPushReportsEveryPath335=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot336=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot337=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot338=== PAUSE TestSetClientTLSErrors/missing_ca_file339=== RUN TestSetClientTLSErrors/invalid_ca_file340--- PASS: TestDumpPathSingleFile (0.07s)341=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped342=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry343=== CONT TestUploadMultipart_SupersededByPeer344=== CONT TestDoServerRequestAttachesToken345=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken346=== CONT TestCompletePendingClosure_NotFoundWithoutKey347=== RUN TestUploadMultipart_SupersededByPeer/exists348=== PAUSE TestUploadMultipart_SupersededByPeer/exists349=== RUN TestUploadMultipart_SupersededByPeer/missing350=== PAUSE TestUploadMultipart_SupersededByPeer/missing351=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun352=== RUN TestFilterOversizedClosures/all_closures_skipped353=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken354=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths355=== PAUSE TestFilterOversizedClosures/all_closures_skipped356=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths357=== CONT TestEncodeNixBase32/test_string_hash358=== CONT TestEncodeNixBase32/empty_input359=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout360--- PASS: TestEncodeNixBase32 (0.00s)361 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)362 --- PASS: TestEncodeNixBase32/empty_input (0.00s)363--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)364 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)365 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)366=== PAUSE TestSetClientTLSErrors/invalid_ca_file367=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs368=== CONT TestParsePathInfoJSON/Lix_format369=== CONT TestParsePathInfoJSON/invalid_JSON370--- PASS: TestStreamPushReportsEveryPath (0.00s)371=== CONT TestParsePathInfoJSON/empty_input372=== CONT TestParsePathInfoJSON/Nix_format373=== CONT TestGetStorePathHash/valid_store_path374=== CONT TestParsePathInfoJSON/whitespace_only375=== CONT TestConvertHashToNix32/SRI_format_to_Nix32376=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error377=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error378=== CONT TestGetStorePathHash/basename_without_hyphen_should_error379=== CONT TestConvertHashToNix32/invalid_format380--- PASS: TestParsePathInfoJSON (0.02s)381 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)382 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)383 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)384 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)385 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)386=== CONT TestConvertHashToNix32/already_Nix32_format387=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter388=== CONT TestRateLimiterFeedback/503_enables_limiter389--- PASS: TestGetStorePathHash (0.02s)390 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)391 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)392 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)393 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)394--- PASS: TestConvertHashToNix32 (0.02s)395 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)396 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)397 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)398=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter399=== CONT TestRateLimiterFeedback/429_enables_limiter400--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.03s)401=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true402=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false403=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier404--- PASS: TestStreamPushBatchesUnderLoad (0.00s)405 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)406 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)407--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.05s)408=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client409=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client410--- PASS: TestDoServerRequestAttachesToken (0.04s)411=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up412--- PASS: TestRateLimiterFeedback (0.03s)413 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)414 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)415 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)416 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.02s)417=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier418--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.05s)419--- PASS: TestScriptTokenCachesUntilRefresh (0.12s)420--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.05s)421=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails422=== CONT TestSupersededNARStillUploadsListing/dump_cut_short423=== CONT TestSupersededNARStillUploadsListing/small_NAR424=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512425=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI426=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon427=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)428=== CONT TestPartSizeForNAR/small_stays_at_minimum429=== CONT TestPartSizeForNAR/capped_at_5_GiB430--- PASS: TestPathInfoHashCompatibility (0.03s)431 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)432 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)433 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)434 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)435=== CONT TestPartSizeForNAR/1_TiB436=== CONT TestPartSizeForNAR/5_TiB_S3_max_object437=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts438=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum439=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive440=== CONT TestPartSizeForNAR/zero_stays_at_minimum441=== CONT TestPathInfoCACompatibility/new_structured_format_-_text442--- PASS: TestPartSizeForNAR (0.02s)443 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)444 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)445 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)446 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)447 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)448 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)449 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)450=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary451=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part452=== CONT TestPathInfoCACompatibility/old_string_format_-_text453=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA454--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.03s)455 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.02s)456 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.02s)457 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.02s)458 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.02s)459 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.02s)460=== CONT TestPathInfoCACompatibility/null_ca_field461=== CONT TestSetClientTLS/preserves_debug_logging_transport462=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method463=== CONT TestSetClientTLS/rejects_connection_without_client_cert464--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.14s)465=== CONT TestUploadMultipart_SupersededByPeer/missing466--- PASS: TestPathInfoCACompatibility (0.07s)467 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)468 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)469 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)470 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)471 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)472--- PASS: TestCaseHackSuffix (0.08s)473=== CONT TestUploadMultipart_SupersededByPeer/exists474--- PASS: TestStreamPushRequestLine (0.13s)475--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.13s)476=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot477=== CONT TestFilterOversizedClosures/all_closures_skipped478=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped479=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot480=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot481=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot482=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken483--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)484 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)485 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)486=== CONT TestStreamPushStopsOnCancel/waiting_for_input487=== CONT TestFilterOversizedClosures/no_limit_keeps_everything488=== CONT TestSetClientTLSErrors/missing_cert_file489--- PASS: TestFilterOversizedClosures (0.04s)490 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)491 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)492 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)493=== CONT TestSetClientTLSErrors/invalid_ca_file494=== CONT TestSetClientTLSErrors/missing_ca_file495=== CONT TestSetClientTLSErrors/missing_key_file496--- PASS: TestSetClientTLSErrors (0.07s)497 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)498 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)499 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)500 --- PASS: TestSetClientTLSErrors/missing_key_file (0.01s)501--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.04s)502 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.05s)503 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.07s)504--- PASS: TestStreamPushStopsOnCancel (0.05s)505 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.05s)506 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)507 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.05s)508 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.05s)509 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.05s)510 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.05s)511--- PASS: TestStreamPushStartsNothingOnSlotFreedByCancel (0.20s)512--- PASS: TestDumpPathWriterError (0.22s)513--- PASS: TestSetClientTLS (0.07s)514 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)515 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)516 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.12s)517--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.24s)518--- PASS: TestRegisterUploadedObjectReusesConnections (0.29s)519--- PASS: TestDumpPathMatchesNix (0.26s)520--- PASS: TestTruncatedNARDumpIsNotCompleted (0.42s)521--- PASS: TestUploadMultipart_PartsInParallel (0.69s)522--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.71s)523--- PASS: TestSupersededNARStillUploadsListing (0.00s)524 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.04s)525 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.05s)526 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.67s)527--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)528--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.01s)529--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.01s)530 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.05s)531 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.20s)532PASS533Running server tests...534The files belonging to this database system will be owned by user "_tribuchetbld8".535This user must also own the server process.536537The database cluster will be initialized with locale "C".538The default database encoding has accordingly been set to "SQL_ASCII".539The default text search configuration will be set to "english".540541Data page checksums are enabled.542543creating directory /private/var/tb/8/scratch/0a0a303197769805/build/postgres3598294748/data ... ok544creating subdirectories ... ok545selecting dynamic shared memory implementation ... posix546selecting default "max_connections" ... 100547selecting default "shared_buffers" ... 128MB548selecting default time zone ... UTC549creating configuration files ... ok550running bootstrap script ... ok551performing post-bootstrap initialization ... ok552syncing data to disk ... ok553554initdb: warning: enabling "trust" authentication for local connections555initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.556557Success. You can now start the database server using:558559 pg_ctl -D /private/var/tb/8/scratch/0a0a303197769805/build/postgres3598294748/data -l logfile start560561/private/var/tb/8/scratch/0a0a303197769805/build/postgres3598294748:5432 - no response5622026-10-27 13:03:18.435 UTC [9250] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5632026-10-27 13:03:18.435 UTC [9250] LOG: listening on Unix socket "/private/var/tb/8/scratch/0a0a303197769805/build/postgres3598294748/.s.PGSQL.5432"5642026-10-27 13:03:18.437 UTC [9257] LOG: database system was shut down at 2026-10-27 13:03:18 UTC5652026-10-27 13:03:18.438 UTC [9250] LOG: database system is ready to accept connections566/private/var/tb/8/scratch/0a0a303197769805/build/postgres3598294748:5432 - accepting connections567{"timestamp":"2026-10-27T13:03:18.676954Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"5073c9ee-a7de-4b0c-af52-ec2bab17538c","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":8,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}568{"timestamp":"2026-10-27T13:03:18.788126Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"b96cf38a-26f4-4d47-a1cd-b2dafa75b09e","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}569=== RUN TestService_AuthMiddleware570=== PAUSE TestService_AuthMiddleware571=== RUN TestService_AuthMiddleware_MTLSProxyHeader572=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader573=== RUN TestService_AuthMiddleware_MTLSBoundSubjects574=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects575=== RUN TestService_ReadAuthMiddleware576=== PAUSE TestService_ReadAuthMiddleware577=== RUN TestService_AuthMiddleware_OIDC578=== PAUSE TestService_AuthMiddleware_OIDC579=== RUN TestService_RequireScope_OIDC580=== PAUSE TestService_RequireScope_OIDC581=== RUN TestService_ReadScope_PublicByDefault582=== PAUSE TestService_ReadScope_PublicByDefault583=== RUN TestCacheConfigHandler584=== PAUSE TestCacheConfigHandler585=== RUN TestCacheStatsHandler586=== PAUSE TestCacheStatsHandler587=== RUN TestClientCADerivations588=== PAUSE TestClientCADerivations589=== RUN TestClientErrorHandling590=== PAUSE TestClientErrorHandling591=== RUN TestClientIntegration592=== PAUSE TestClientIntegration593=== RUN TestClientMultipleUploads594=== PAUSE TestClientMultipleUploads595=== RUN TestClientWithDependencies596=== PAUSE TestClientWithDependencies597=== RUN TestClientSharedPathCommittedMidPush598=== PAUSE TestClientSharedPathCommittedMidPush599=== RUN TestPinProtectsFromGC600=== PAUSE TestPinProtectsFromGC601=== RUN TestClientPushesUseOnePush602=== PAUSE TestClientPushesUseOnePush603=== RUN TestClientFallsBackToClosures604=== PAUSE TestClientFallsBackToClosures605=== RUN TestDeleteClosuresRacingPins606=== PAUSE TestDeleteClosuresRacingPins607=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock608=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock609=== RUN TestResolveDBConnectionString610=== PAUSE TestResolveDBConnectionString611=== RUN TestConnectWaitsForAPeerMigration612=== PAUSE TestConnectWaitsForAPeerMigration613=== RUN TestConnectSerialisesConcurrentMigrations614=== PAUSE TestConnectSerialisesConcurrentMigrations615=== RUN TestLeadElectsOneAndHandsOver616=== PAUSE TestLeadElectsOneAndHandsOver617=== RUN TestLeadIncumbentWinsAfterRestart6182026/10/27 13:03:19 INFO lead: acquired remote=192.0.2.1:12346192026/10/27 13:03:19 INFO lead: released remote=192.0.2.1:12346202026/10/27 13:03:19 INFO lead: acquired remote=192.0.2.1:12346212026/10/27 13:03:20 INFO lead: released remote=192.0.2.1:1234622--- PASS: TestLeadIncumbentWinsAfterRestart (1.99s)623=== RUN TestLeadIncumbentAnnouncesAtOnce624=== PAUSE TestLeadIncumbentAnnouncesAtOnce625=== RUN TestLeadEndsOnShutdown626=== PAUSE TestLeadEndsOnShutdown627=== RUN TestLeadEndsWhenItsConnectionHangs6282026/10/27 13:03:21 INFO lead: acquired remote=192.0.2.1:12346292026-10-27 13:03:22.272 UTC [9294] FATAL: terminating connection due to administrator command6302026/10/27 13:03:22 INFO lead: acquired remote=192.0.2.1:12346312026/10/27 13:03:23 WARN lead: lock connection lost error="timeout: context deadline exceeded"6322026/10/27 13:03:23 INFO lead: released remote=192.0.2.1:12346332026/10/27 13:03:23 INFO lead: released remote=192.0.2.1:1234634--- PASS: TestLeadEndsWhenItsConnectionHangs (2.79s)635=== RUN TestGCAdvisoryLockBlocksConcurrentRun636=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun637=== RUN TestGCBugBareHashReferences638=== PAUSE TestGCBugBareHashReferences639=== RUN TestGCMetrics640=== PAUSE TestGCMetrics641=== RUN TestPushDedupSurvivesConcurrentGC642=== PAUSE TestPushDedupSurvivesConcurrentGC643=== RUN TestDeduplicatedObjectsRecordedAsPending644=== PAUSE TestDeduplicatedObjectsRecordedAsPending645=== RUN TestGCSweepSkipsPendingObjects646=== PAUSE TestGCSweepSkipsPendingObjects647=== RUN TestTombstonedObjectOfferedWithoutWaiting648=== PAUSE TestTombstonedObjectOfferedWithoutWaiting649=== RUN TestGCSweepDeliversEachKeyOnce650=== PAUSE TestGCSweepDeliversEachKeyOnce651=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection652=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection653=== RUN TestForceGCDuringPushOffersSweptObject654=== PAUSE TestForceGCDuringPushOffersSweptObject655=== RUN TestFailedS3DeleteKeepsTombstone656=== PAUSE TestFailedS3DeleteKeepsTombstone657=== RUN TestSweepSkipsRowsLockedByPush658=== PAUSE TestSweepSkipsRowsLockedByPush659=== RUN TestRegisterCompletedObjectNeedsPendingRow660=== PAUSE TestRegisterCompletedObjectNeedsPendingRow661=== RUN TestGetExistingObjectsLocksRows662=== PAUSE TestGetExistingObjectsLocksRows663=== RUN TestSweepRechecksPendingAfterLocking664=== PAUSE TestSweepRechecksPendingAfterLocking665=== RUN TestPushWaitsForSweepHoldingRow666=== PAUSE TestPushWaitsForSweepHoldingRow667=== RUN TestCommitRacingPendingCleanupKeepsObjects668=== PAUSE TestCommitRacingPendingCleanupKeepsObjects669=== RUN TestGCEndsOnShutdown670=== PAUSE TestGCEndsOnShutdown671=== RUN TestGCTaskStore_StartNew672=== PAUSE TestGCTaskStore_StartNew673=== RUN TestGCTaskStore_DeduplicateSameParams674=== PAUSE TestGCTaskStore_DeduplicateSameParams675=== RUN TestGCTaskStore_ConflictDifferentParams676=== PAUSE TestGCTaskStore_ConflictDifferentParams677=== RUN TestGCTaskStore_GetEmpty678=== PAUSE TestGCTaskStore_GetEmpty679=== RUN TestGCTaskStore_GetReturnsLatest680=== PAUSE TestGCTaskStore_GetReturnsLatest681=== RUN TestGCTaskStore_CompletedAllowsNewTask682=== PAUSE TestGCTaskStore_CompletedAllowsNewTask683=== RUN TestGCTaskStore_PhaseUpdates684=== PAUSE TestGCTaskStore_PhaseUpdates685=== RUN TestGCTaskStore_Fail686=== PAUSE TestGCTaskStore_Fail687=== RUN TestGracefulShutdownDrainsInflight688=== PAUSE TestGracefulShutdownDrainsInflight689=== RUN TestService_healthCheckHandler690=== PAUSE TestService_healthCheckHandler691=== RUN TestService_readinessHandler692=== PAUSE TestService_readinessHandler693=== RUN TestGenerateLandingPage694=== PAUSE TestGenerateLandingPage695=== RUN TestChildrenInheritRaisedFileLimit696=== PAUSE TestChildrenInheritRaisedFileLimit697=== RUN TestCacheConfigHandlerMaxNarSize698=== PAUSE TestCacheConfigHandlerMaxNarSize699=== RUN TestCreatePendingClosureRejectsOversizedNAR700=== PAUSE TestCreatePendingClosureRejectsOversizedNAR701=== RUN TestNARDeduplicationMetadataUploadBug702=== PAUSE TestNARDeduplicationMetadataUploadBug703=== RUN TestMetricsInventory704=== PAUSE TestMetricsInventory705=== RUN TestMetricsCommit706=== PAUSE TestMetricsCommit707=== RUN TestService_NativeMTLS708=== PAUSE TestService_NativeMTLS709=== RUN TestServerTLSConfig710=== PAUSE TestServerTLSConfig711=== RUN TestMultipartCleanup712=== PAUSE TestMultipartCleanup713=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded714=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded715=== RUN TestPendingCleanupUsesOneCutoff716=== PAUSE TestPendingCleanupUsesOneCutoff717=== RUN TestPendingClosureFailureTracksEveryUpload718=== PAUSE TestPendingClosureFailureTracksEveryUpload719=== RUN TestPendingClosureFailureAbortsItsUploads720=== PAUSE TestPendingClosureFailureAbortsItsUploads721=== RUN TestObjectStatsTrigger722=== PAUSE TestObjectStatsTrigger723=== RUN TestObjectStatsUpdatedOncePerCommit724=== PAUSE TestObjectStatsUpdatedOncePerCommit725=== RUN TestReconnectLeavesObjectsUnlocked726=== PAUSE TestReconnectLeavesObjectsUnlocked727=== RUN TestOrphanedObjectsGC728=== PAUSE TestOrphanedObjectsGC729=== RUN TestOrphanedObjectsGCStressTest730=== PAUSE TestOrphanedObjectsGCStressTest731=== RUN TestCreatePin_ReservedPins732=== PAUSE TestCreatePin_ReservedPins733=== RUN TestConcurrentPinUpdatesAgree734=== PAUSE TestConcurrentPinUpdatesAgree735=== RUN TestCreatePinRejectsBadInput736=== PAUSE TestCreatePinRejectsBadInput737=== RUN TestDeletePinKeepsRowWhenS3Fails738=== PAUSE TestDeletePinKeepsRowWhenS3Fails739=== RUN TestPresentReportsOnlyClosureRoots740=== PAUSE TestPresentReportsOnlyClosureRoots741=== RUN TestPresentRefreshesOnlyStaleClosures742=== PAUSE TestPresentRefreshesOnlyStaleClosures743=== RUN TestPresentNotReportedWhileGCDeletesClosure744=== PAUSE TestPresentNotReportedWhileGCDeletesClosure745=== RUN TestParseSingleRange746=== PAUSE TestParseSingleRange747=== RUN TestProxyHeadersOnlyTrustedOnSocket7482026/10/27 13:03:23 INFO Starting HTTP server address=proxy.sock7492026/10/27 13:03:23 INFO Starting HTTP server address=127.0.0.1:620907502026/10/27 13:03:23 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7512026/10/27 13:03:23 INFO Shutdown signal received, draining in-flight requests timeout=10s752--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.16s)753=== RUN TestIsValidCachePath754=== PAUSE TestIsValidCachePath755=== RUN TestReadProxyNarinfo756=== PAUSE TestReadProxyNarinfo757=== RUN TestReadProxyNarinfoAlreadyDecompressed758=== PAUSE TestReadProxyNarinfoAlreadyDecompressed759=== RUN TestReadProxyContentNegotiation760=== PAUSE TestReadProxyContentNegotiation761=== RUN TestReadProxyNarStreaming762=== PAUSE TestReadProxyNarStreaming763=== RUN TestReadProxy404And429764=== PAUSE TestReadProxy404And429765=== RUN TestReadProxyInvalidPath766=== PAUSE TestReadProxyInvalidPath767=== RUN TestReadProxyHead768=== PAUSE TestReadProxyHead769=== RUN TestReadProxyOutlastsServerWriteTimeout770=== PAUSE TestReadProxyOutlastsServerWriteTimeout771=== RUN TestReadProxyConditionalGet772=== PAUSE TestReadProxyConditionalGet773=== RUN TestReadProxyRootRedirectsToIndexHTML774=== PAUSE TestReadProxyRootRedirectsToIndexHTML775=== RUN TestReadProxyDisabled776=== PAUSE TestReadProxyDisabled777=== RUN TestReadRedirectNar778=== PAUSE TestReadRedirectNar779=== RUN TestReadRedirectKeepsNarinfoProxied780=== PAUSE TestReadRedirectKeepsNarinfoProxied781=== RUN TestReadProxyRangeRequest782=== PAUSE TestReadProxyRangeRequest783=== RUN TestReadRedirectUsesPublicS3URL784=== PAUSE TestReadRedirectUsesPublicS3URL785=== RUN TestPush_OverlappingRootsStoreOneRowPerKey786=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey787=== RUN TestPush_CompleteCommitsEveryRoot788=== PAUSE TestPush_CompleteCommitsEveryRoot789=== RUN TestPush_RepeatedRootCommitsOnce790=== PAUSE TestPush_RepeatedRootCommitsOnce791=== RUN TestPush_CompleteWaitsForCleanupOfThePush792=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush793=== RUN TestPush_RootsAreLockedInByteOrder794=== PAUSE TestPush_RootsAreLockedInByteOrder795=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit796=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit797=== RUN TestPush_RejectsBadRequests798=== PAUSE TestPush_RejectsBadRequests799=== RUN TestPush_SignsNarinfosOfItsPendingObjects800=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects801=== RUN TestRedundantMultipartUpload802=== PAUSE TestRedundantMultipartUpload803=== RUN TestCompleteMultipartUpload_ErrorButObjectExists804=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists805=== RUN TestCompletedNarNotReofferedAcrossClosures806=== PAUSE TestCompletedNarNotReofferedAcrossClosures807=== RUN TestPresignedUploadRegisteredBeforeCommit808=== PAUSE TestPresignedUploadRegisteredBeforeCommit809=== RUN TestService_Rustfstest810=== PAUSE TestService_Rustfstest811=== RUN TestParseSize812=== PAUSE TestParseSize813=== RUN TestSkippedUploadsHandler814=== PAUSE TestSkippedUploadsHandler815=== RUN TestSystemdListenerNotActivated816--- PASS: TestSystemdListenerNotActivated (0.00s)817=== RUN TestWatchdogBeatsWhenHealthy818--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)819=== RUN TestWatchdogSkipsWhenUnhealthy8202026/10/27 13:03:23 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8212026/10/27 13:03:23 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8222026/10/27 13:03:23 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8232026/10/27 13:03:23 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8242026/10/27 13:03:23 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8252026/10/27 13:03:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8262026/10/27 13:03:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8272026/10/27 13:03:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8282026/10/27 13:03:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8292026/10/27 13:03:24 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"830--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)831=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle832=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle833=== RUN TestProxyWriteTimeout834=== PAUSE TestProxyWriteTimeout835=== RUN TestPendingClosureWriteTimeout836=== PAUSE TestPendingClosureWriteTimeout837=== RUN TestIsValidUploadKey838=== PAUSE TestIsValidUploadKey839=== RUN TestUploadHandlersRejectInvalidKeys840=== PAUSE TestUploadHandlersRejectInvalidKeys841=== RUN TestUploadHandlersRejectOversizedBody842=== PAUSE TestUploadHandlersRejectOversizedBody843=== RUN TestService_cleanupPendingClosuresHandler844=== PAUSE TestService_cleanupPendingClosuresHandler845=== RUN TestService_createPendingClosureHandler846=== PAUSE TestService_createPendingClosureHandler847=== RUN TestService_verifyS3Integrity848=== PAUSE TestService_verifyS3Integrity849=== RUN TestCompleteMultipartUnregistered850=== PAUSE TestCompleteMultipartUnregistered851=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT852=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT853=== CONT TestPush_CompleteWaitsForCleanupOfThePush854=== CONT TestReadProxyNarStreaming855=== CONT TestReadRedirectNar856=== CONT TestDeletePinKeepsRowWhenS3Fails857=== CONT TestReadProxyRootRedirectsToIndexHTML858=== CONT TestIsValidCachePath859=== RUN TestIsValidCachePath/narinfo860=== CONT TestReadProxyNarinfoAlreadyDecompressed861=== CONT TestPresentReportsOnlyClosureRoots862=== CONT TestPresentRefreshesOnlyStaleClosures863=== CONT TestReadProxyConditionalGet864=== CONT TestReadProxyHead865=== CONT TestReadProxy404And429866=== CONT TestReadProxyOutlastsServerWriteTimeout867=== CONT TestReadProxyInvalidPath868=== CONT TestPush_RootsAreLockedInByteOrder869=== CONT TestService_AuthMiddleware_MTLSBoundSubjects870=== CONT TestPush_RepeatedRootCommitsOnce871=== CONT TestPush_OverlappingRootsStoreOneRowPerKey872=== CONT TestPush_CompleteCommitsEveryRoot873=== CONT TestReadRedirectUsesPublicS3URL874=== CONT TestPresentNotReportedWhileGCDeletesClosure875=== CONT TestReadRedirectKeepsNarinfoProxied876=== CONT TestReadProxyRangeRequest877=== CONT TestCreatePinRejectsBadInput878=== PAUSE TestIsValidCachePath/narinfo879=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale880=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars881=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale882=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars883=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh884=== RUN TestIsValidCachePath/nar_zst885=== PAUSE TestIsValidCachePath/nar_zst886=== RUN TestIsValidCachePath/nar_xz887=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh888=== PAUSE TestIsValidCachePath/nar_xz889=== RUN TestIsValidCachePath/nar_bz2890=== CONT TestConcurrentPinUpdatesAgree891=== PAUSE TestIsValidCachePath/nar_bz2892=== RUN TestIsValidCachePath/nar_uncompressed893=== PAUSE TestIsValidCachePath/nar_uncompressed894=== RUN TestIsValidCachePath/ls895=== PAUSE TestIsValidCachePath/ls896=== RUN TestIsValidCachePath/log897=== PAUSE TestIsValidCachePath/log898=== RUN TestIsValidCachePath/realisation899=== PAUSE TestIsValidCachePath/realisation900=== RUN TestIsValidCachePath/nix-cache-info901=== PAUSE TestIsValidCachePath/nix-cache-info902=== RUN TestIsValidCachePath/index.html903=== PAUSE TestIsValidCachePath/index.html904=== RUN TestIsValidCachePath/traversal_parent905=== PAUSE TestIsValidCachePath/traversal_parent906=== RUN TestIsValidCachePath/traversal_in_middle907=== PAUSE TestIsValidCachePath/traversal_in_middle908=== RUN TestIsValidCachePath/invalid_char_e909=== PAUSE TestIsValidCachePath/invalid_char_e910=== RUN TestIsValidCachePath/invalid_char_u911=== PAUSE TestIsValidCachePath/invalid_char_u912=== RUN TestIsValidCachePath/random_path913=== PAUSE TestIsValidCachePath/random_path914=== RUN TestIsValidCachePath/empty915=== PAUSE TestIsValidCachePath/empty916=== RUN TestIsValidCachePath/leading_slash917=== PAUSE TestIsValidCachePath/leading_slash918=== RUN TestIsValidCachePath/wrong_extension919=== PAUSE TestIsValidCachePath/wrong_extension920=== RUN TestIsValidCachePath/short_hash921=== PAUSE TestIsValidCachePath/short_hash922=== CONT TestCreatePin_ReservedPins9232026/10/27 13:03:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62094/oidc924--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.82s)925=== CONT TestParseSingleRange926=== RUN TestParseSingleRange/none927=== PAUSE TestParseSingleRange/none928=== RUN TestParseSingleRange/unknown_unit929=== PAUSE TestParseSingleRange/unknown_unit930=== RUN TestParseSingleRange/multi-range_ignored931=== PAUSE TestParseSingleRange/multi-range_ignored932=== RUN TestParseSingleRange/malformed_no_dash933=== PAUSE TestParseSingleRange/malformed_no_dash934=== RUN TestParseSingleRange/malformed_both_empty935=== PAUSE TestParseSingleRange/malformed_both_empty936=== RUN TestParseSingleRange/malformed_end_before_start937=== PAUSE TestParseSingleRange/malformed_end_before_start938=== RUN TestParseSingleRange/closed939=== PAUSE TestParseSingleRange/closed940=== RUN TestParseSingleRange/open-ended941=== PAUSE TestParseSingleRange/open-ended942=== RUN TestParseSingleRange/end_clamped_to_size943=== PAUSE TestParseSingleRange/end_clamped_to_size944=== RUN TestParseSingleRange/suffix945=== PAUSE TestParseSingleRange/suffix946=== RUN TestParseSingleRange/suffix_exceeds_size947=== PAUSE TestParseSingleRange/suffix_exceeds_size948=== RUN TestParseSingleRange/single_byte949=== PAUSE TestParseSingleRange/single_byte950=== RUN TestParseSingleRange/start_past_EOF951=== PAUSE TestParseSingleRange/start_past_EOF952=== RUN TestParseSingleRange/start_far_past_EOF953=== PAUSE TestParseSingleRange/start_far_past_EOF954=== CONT TestFailedS3DeleteKeepsTombstone955--- PASS: TestReadRedirectNar (1.03s)956=== CONT TestReconnectLeavesObjectsUnlocked957=== CONT TestObjectStatsUpdatedOncePerCommit958--- PASS: TestReadProxyNarStreaming (1.27s)959--- PASS: TestPresentReportsOnlyClosureRoots (1.59s)960=== CONT TestObjectStatsTrigger9612026/10/27 13:03:25 INFO Received create pin request method=POST path=/api/pins/app9622026/10/27 13:03:26 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo9632026/10/27 13:03:26 INFO Received delete pin request method=DELETE path=/api/pins/app9642026/10/27 13:03:26 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket8/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"9652026/10/27 13:03:26 INFO Received delete pin request method=DELETE path=/api/pins/app9662026/10/27 13:03:26 INFO Deleted pin name=app9672026/10/27 13:03:26 INFO Received push request method=POST path=/api/pushes968--- PASS: TestDeletePinKeepsRowWhenS3Fails (2.17s)969=== CONT TestReadProxyContentNegotiation970--- PASS: TestReadProxyHead (2.43s)971=== CONT TestReadProxyNarinfo972--- PASS: TestReadProxyConditionalGet (2.67s)973=== CONT TestPendingClosureFailureAbortsItsUploads974--- PASS: TestReadProxyNarinfoAlreadyDecompressed (2.89s)975=== CONT TestOrphanedObjectsGCStressTest976--- PASS: TestPresentRefreshesOnlyStaleClosures (3.12s)977=== CONT TestResolveDBConnectionString978=== RUN TestResolveDBConnectionString/flag_wins979=== PAUSE TestResolveDBConnectionString/flag_wins980=== RUN TestResolveDBConnectionString/file_when_flag_empty981=== PAUSE TestResolveDBConnectionString/file_when_flag_empty982=== RUN TestResolveDBConnectionString/missing_file_is_an_error983=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error984=== RUN TestResolveDBConnectionString/PGHOST_allows_empty985=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty986=== RUN TestResolveDBConnectionString/nothing_configured987=== PAUSE TestResolveDBConnectionString/nothing_configured988=== CONT TestPendingClosureFailureTracksEveryUpload989=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false990=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false991=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true992=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true993=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded9942026/10/27 13:03:27 INFO Received push request method=POST path=/api/pushes9952026/10/27 13:03:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9962026/10/27 13:03:27 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLjY5ZGNjYjgzLWNmNTEtNGI0YS05YTFkLTI5ZjY3M2Q3N2I0N3gxNzkzMTA2MjA2MzA2MTY0MDAw parts=109972026-10-27 13:03:27.867 UTC [9410] ERROR: Push does not exist: id=19982026-10-27 13:03:27.867 UTC [9410] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE9992026-10-27 13:03:27.867 UTC [9410] STATEMENT: SELECT commit_push($1)1000--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (3.79s)1001=== CONT TestSweepSkipsRowsLockedByPush1002--- PASS: TestReadRedirectKeepsNarinfoProxied (4.17s)1003=== CONT TestReadProxyDisabled10042026/10/27 13:03:28 WARN Rate limiter enabled after throttle name=s3-test rate=510052026/10/27 13:03:28 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."10062026/10/27 13:03:28 INFO Received push request method=POST path=/api/pushes10072026/10/27 13:03:28 WARN Rate limiter backed off name=s3-test rate=510082026/10/27 13:03:28 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."1009--- PASS: TestReadProxy404And429 (4.40s)1010=== CONT TestMultipartCleanup10112026/10/27 13:03:28 INFO Received create pin request method=POST path=/api/pins/app10122026/10/27 13:03:28 INFO Received create pin request method=POST path=/api/pins/app10132026/10/27 13:03:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10142026/10/27 13:03:28 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLjJjOTFlODlhLWIyNTMtNDZkYy04ODk3LThmNGM3MWQ1N2I3NXgxNzkzMTA2MjA3NDc4MjI5MDAw parts=1010152026/10/27 13:03:28 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"10162026/10/27 13:03:28 WARN mTLS auth: bound subjects configured but subject DN unavailable10172026/10/27 13:03:28 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1018--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (4.88s)1019=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10202026/10/27 13:03:29 INFO Received push request method=POST path=/api/pushes10212026/10/27 13:03:29 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo1022--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (5.19s)1023=== CONT TestGracefulShutdownDrainsInflight10242026/10/27 13:03:29 INFO Starting HTTP server address=127.0.0.1:6222310252026/10/27 13:03:29 INFO Shutdown signal received, draining in-flight requests timeout=10s10262026/10/27 13:03:29 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo1027--- PASS: TestConcurrentPinUpdatesAgree (5.26s)1028=== CONT TestGCTaskStore_PhaseUpdates1029--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1030=== CONT TestForceGCDuringPushOffersSweptObject1031=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1032=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1033=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1034=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1035=== CONT TestServerTLSConfig1036=== RUN TestServerTLSConfig/no_client_CA1037=== PAUSE TestServerTLSConfig/no_client_CA1038=== RUN TestServerTLSConfig/missing_CA_file1039=== PAUSE TestServerTLSConfig/missing_CA_file1040=== RUN TestServerTLSConfig/not_a_PEM_file1041=== PAUSE TestServerTLSConfig/not_a_PEM_file1042=== CONT TestGCTaskStore_CompletedAllowsNewTask1043--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1044=== CONT TestGCSweepDeliversEachKeyOnce1045--- PASS: TestGracefulShutdownDrainsInflight (0.08s)1046=== CONT TestService_NativeMTLS1047--- PASS: TestReadProxyInvalidPath (5.40s)1048=== CONT TestGCTaskStore_GetReturnsLatest1049--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1050=== CONT TestGCSweepSkipsPendingObjects10512026/10/27 13:03:29 INFO Received push request method=POST path=/api/pushes10522026/10/27 13:03:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10532026/10/27 13:03:29 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLjIwNDgyNDI1LTE3OWEtNDg2My05YzI1LWVhZDA4ODQwN2I0YngxNzkzMTA2MjA4NDk3MjIxMDAw parts=1010542026/10/27 13:03:30 INFO Received create pin request method=POST path=/api/pins/deploy10552026/10/27 13:03:30 INFO Received create pin request method=POST path=/api/pins/deploy10562026/10/27 13:03:30 INFO Received create pin request method=POST path=/api/pins/deploy10572026/10/27 13:03:30 INFO Received create pin request method=POST path=/api/pins/deploy10582026/10/27 13:03:30 INFO Received create pin request method=POST path=/api/pins/deploy10592026/10/27 13:03:30 INFO Received create pin request method=POST path=/api/pins/deploy10602026/10/27 13:03:30 INFO Received create pin request method=POST path=/api/pins/deploy10612026/10/27 13:03:30 INFO Received create pin request method=POST path=/api/pins/deploy10622026/10/27 13:03:30 INFO Received create pin request method=POST path=/api/pins/deploy10632026/10/27 13:03:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10642026/10/27 13:03:30 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLjc1ODMzMGU0LWI0YmMtNGQ2Mi05Zjk5LTlkYTA3ZDhhYTVkMngxNzkzMTA2MjA3NDc3NDMxMDAw parts=1010652026/10/27 13:03:30 INFO Received create pin request method=POST path=/api/pins/deploy1066--- PASS: TestReadProxyRangeRequest (6.27s)1067=== CONT TestPendingCleanupUsesOneCutoff10682026/10/27 13:03:30 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo1069--- PASS: TestCreatePinRejectsBadInput (6.34s)1070=== CONT TestGCTaskStore_ConflictDifferentParams1071--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1072=== CONT TestDeduplicatedObjectsRecordedAsPending1073--- PASS: TestReadRedirectUsesPublicS3URL (6.64s)1074=== CONT TestMetricsInventory10752026/10/27 13:03:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10762026/10/27 13:03:30 WARN Refused reserved pin name=worker-x86_64-linux10772026/10/27 13:03:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10782026/10/27 13:03:30 INFO Received create pin request method=POST path=/api/pins/my-app10792026/10/27 13:03:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1080=== CONT TestMetricsCommit1081--- PASS: TestCreatePin_ReservedPins (6.90s)10822026/10/27 13:03:31 INFO Received uploads request method=POST path=/api/pending_closures10832026/10/27 13:03:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10842026/10/27 13:03:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10852026/10/27 13:03:31 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLjhmNzZiZmM1LTg3YTEtNDdjZi1iNTg0LTBmZDJiZjNiMzk0ZHgxNzkzMTA2MjA4NDk3MjY2MDAw parts=1010862026/10/27 13:03:31 INFO Aborted multipart uploads count=0 kept=010872026/10/27 13:03:31 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLmU4YjRiMDU3LWQyYjYtNDYxMy1iYTgwLWJmYTk3NGM0OTQ4Y3gxNzkzMTA2MjA5NzU4NTI2MDAw parts=1010882026/10/27 13:03:31 WARN Force mode enabled - objects will be deleted immediately without grace period10892026/10/27 13:03:31 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."10902026/10/27 13:03:31 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1091--- PASS: TestFailedS3DeleteKeepsTombstone (6.83s)1092=== CONT TestGCTaskStore_DeduplicateSameParams1093=== CONT TestPushDedupSurvivesConcurrentGC1094--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)10952026/10/27 13:03:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10962026/10/27 13:03:32 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLjQ5NmI2YWRkLTcxY2ItNGZiYS04NzdlLWFmZjk5YmY5YTRhZngxNzkzMTA2MjA3NDc4MTAxMDAw parts=101097--- PASS: TestObjectStatsUpdatedOncePerCommit (6.69s)1098=== CONT TestCreatePendingClosureRejectsOversizedNAR10992026/10/27 13:03:32 INFO Received complete push request method=POST path=/api/pushes/1/complete11002026/10/27 13:03:32 INFO Received uploads request method=POST path=/api/pending_closures1101--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1102=== CONT TestGCTaskStore_StartNew1103--- PASS: TestGCTaskStore_StartNew (0.00s)1104=== CONT TestGCMetrics11052026/10/27 13:03:32 INFO Completed push id=1 objects=6 duration=18.5935ms1106--- PASS: TestReconnectLeavesObjectsUnlocked (6.98s)1107=== CONT TestCacheConfigHandlerMaxNarSize1108--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1109=== CONT TestGCTaskStore_GetEmpty1110--- PASS: TestGCTaskStore_GetEmpty (0.00s)1111=== CONT TestTombstonedObjectOfferedWithoutWaiting1112=== CONT TestNARDeduplicationMetadataUploadBug1113--- PASS: TestPush_CompleteCommitsEveryRoot (8.03s)1114--- PASS: TestReadProxyOutlastsServerWriteTimeout (8.15s)1115=== CONT TestGCEndsOnShutdown1116=== RUN TestGCEndsOnShutdown/before_the_run1117=== PAUSE TestGCEndsOnShutdown/before_the_run1118=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1119=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1120=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1121=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1122=== CONT TestGenerateLandingPage1123--- PASS: TestGenerateLandingPage (0.01s)1124=== CONT TestGCAdvisoryLockBlocksConcurrentRun1125--- PASS: TestObjectStatsTrigger (6.71s)1126=== CONT TestPushWaitsForSweepHoldingRow1127=== CONT TestChildrenInheritRaisedFileLimit1128--- PASS: TestReadProxyContentNegotiation (6.63s)1129--- PASS: TestChildrenInheritRaisedFileLimit (0.01s)1130=== CONT TestGCBugBareHashReferences11312026/10/27 13:03:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11322026/10/27 13:03:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11332026/10/27 13:03:33 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1134--- PASS: TestReadProxyNarinfo (6.74s)1135=== CONT TestCommitRacingPendingCleanupKeepsObjects11362026/10/27 13:03:33 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLmQ2ZGFmOWViLTQ1MDktNDNjNS1iYTMxLTQ1NjdjOTYyNjdjMngxNzkzMTA2MjA5NzU4OTEyMDAw parts=1011372026/10/27 13:03:33 INFO Received complete push request method=POST path=/api/pushes/1/complete11382026/10/27 13:03:33 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLjk4NGYzNDYxLTMwN2ItNGUwZC05MjU5LTE3ZjRiNmJhMDU0NngxNzkzMTA2MjA4NDk3Mjk5MDAw parts=1011392026/10/27 13:03:33 INFO Completed push id=1 objects=4 duration=34.621958ms11402026/10/27 13:03:33 INFO Received uploads request method=POST path=/api/pending_closures1141--- PASS: TestPush_RepeatedRootCommitsOnce (9.26s)1142=== CONT TestService_readinessHandler1143--- PASS: TestPendingClosureFailureAbortsItsUploads (6.67s)1144=== CONT TestLeadIncumbentAnnouncesAtOnce11452026/10/27 13:03:34 INFO Received uploads request method=POST path=/api/pending_closures1146--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (7.05s)1147=== CONT TestLeadEndsOnShutdown11482026/10/27 13:03:34 INFO Aborted multipart uploads count=0 kept=011492026/10/27 13:03:34 WARN Force mode enabled - objects will be deleted immediately without grace period11502026/10/27 13:03:34 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011512026/10/27 13:03:34 INFO Vacuumed table table=pending_closures11522026/10/27 13:03:34 INFO Vacuumed table table=pending_objects11532026/10/27 13:03:34 INFO Vacuumed table table=multipart_uploads11542026/10/27 13:03:34 INFO Vacuumed table table=closures11552026/10/27 13:03:34 INFO Vacuumed table table=objects11562026/10/27 13:03:34 INFO Aborted multipart uploads count=0 kept=011572026/10/27 13:03:34 WARN Force mode enabled - objects will be deleted immediately without grace period1158--- PASS: TestReadProxyDisabled (6.65s)1159=== CONT TestConnectSerialisesConcurrentMigrations11602026/10/27 13:03:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11612026/10/27 13:03:35 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=011622026/10/27 13:03:35 INFO Vacuumed table table=pending_closures11632026/10/27 13:03:35 INFO Vacuumed table table=pending_objects11642026/10/27 13:03:35 INFO Vacuumed table table=multipart_uploads11652026/10/27 13:03:35 INFO Vacuumed table table=closures11662026/10/27 13:03:35 INFO Vacuumed table table=objects11672026/10/27 13:03:35 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLjI0MzU2MzcwLWE4OGItNGMwYi04YjdjLTBhODZmOWE2Yjk5YngxNzkzMTA2MjA4NDk3Mzc3MDAw parts=101168--- PASS: TestSweepSkipsRowsLockedByPush (7.42s)1169=== CONT TestConnectWaitsForAPeerMigration11702026/10/27 13:03:35 INFO Received uploads request method=POST path=/api/pending_closures11712026/10/27 13:03:35 INFO Received cleanup request method=DELETE path=/api/pending_closures11722026/10/27 13:03:35 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket39/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11732026/10/27 13:03:35 INFO Aborted multipart uploads count=0 kept=111742026/10/27 13:03:35 INFO Received cleanup request method=DELETE path=/api/pending_closures11752026/10/27 13:03:35 INFO Aborted multipart uploads count=1 kept=01176--- PASS: TestMultipartCleanup (7.16s)1177=== CONT TestLeadElectsOneAndHandsOver11782026/10/27 13:03:35 INFO Received uploads request method=POST path=/api/pending_closures1179--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (7.10s)1180=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11812026/10/27 13:03:36 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11822026/10/27 13:03:36 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1183--- PASS: TestService_NativeMTLS (6.86s)1184=== CONT TestGetExistingObjectsLocksRows11852026/10/27 13:03:36 INFO Aborted multipart uploads count=0 kept=011862026/10/27 13:03:36 WARN Force mode enabled - objects will be deleted immediately without grace period11872026/10/27 13:03:36 INFO Received uploads request method=POST path=/api/pending_closures11882026/10/27 13:03:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11892026/10/27 13:03:37 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLjQ0NDBmNmFkLTBhMGMtNGM1Ni1hNTllLWEyNGEyMjdhZGI0ZXgxNzkzMTA2MjA4NDk3MzEyMDAw parts=1011902026/10/27 13:03:37 INFO Aborted multipart uploads count=0 kept=011912026/10/27 13:03:37 WARN Force mode enabled - objects will be deleted immediately without grace period11922026/10/27 13:03:37 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=011932026/10/27 13:03:37 INFO Vacuumed table table=pending_closures11942026/10/27 13:03:37 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=011952026/10/27 13:03:37 INFO Vacuumed table table=pending_closures11962026/10/27 13:03:37 INFO Vacuumed table table=pending_objects11972026/10/27 13:03:37 INFO Vacuumed table table=multipart_uploads11982026/10/27 13:03:37 INFO Vacuumed table table=closures11992026/10/27 13:03:37 INFO Vacuumed table table=pending_objects12002026/10/27 13:03:37 INFO Vacuumed table table=multipart_uploads12012026/10/27 13:03:37 INFO Vacuumed table table=closures12022026/10/27 13:03:37 INFO Received uploads request method=POST path=/api/pending_closures12032026/10/27 13:03:37 INFO Vacuumed table table=objects12042026/10/27 13:03:37 INFO Vacuumed table table=objects1205--- PASS: TestGCSweepDeliversEachKeyOnce (8.13s)1206=== CONT TestRegisterCompletedObjectNeedsPendingRow1207--- PASS: TestGCSweepSkipsPendingObjects (8.00s)1208=== CONT TestClientErrorHandling1209=== RUN TestClientErrorHandling/InvalidStorePath1210=== PAUSE TestClientErrorHandling/InvalidStorePath1211=== RUN TestClientErrorHandling/InvalidAuthToken1212=== PAUSE TestClientErrorHandling/InvalidAuthToken1213=== RUN TestClientErrorHandling/ServerNotAvailable1214=== PAUSE TestClientErrorHandling/ServerNotAvailable1215--- PASS: TestDeduplicatedObjectsRecordedAsPending (7.11s)1216=== CONT TestSweepRechecksPendingAfterLocking1217=== CONT TestDeleteClosuresRacingPins12182026/10/27 13:03:37 INFO Received uploads request method=POST path=/api/pending_closures12192026/10/27 13:03:37 INFO Received uploads request method=POST path=/api/pending_closures12202026/10/27 13:03:38 INFO Received cleanup request method=DELETE path=/api/pending_closures1221--- PASS: TestMetricsInventory (7.58s)1222=== CONT TestClientSharedPathCommittedMidPush12232026-10-27 13:03:38.365 UTC [9544] ERROR: duplicate key value violates unique constraint "pg_class_relname_nsp_index"12242026-10-27 13:03:38.365 UTC [9544] DETAIL: Key (relname, relnamespace)=(goose_db_version_id_seq, 2200) already exists.12252026-10-27 13:03:38.365 UTC [9544] STATEMENT: CREATE TABLE goose_db_version (1226 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1227 version_id bigint NOT NULL,1228 is_applied boolean NOT NULL,1229 tstamp timestamp NOT NULL DEFAULT now()1230 )12312026/10/27 13:03:38 INFO Received push request method=POST path=/api/pushes12322026/10/27 13:03:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12332026/10/27 13:03:39 INFO Received uploads request method=POST path=/api/pending_closures1234=== CONT TestClientFallsBackToClosures1235--- PASS: TestConnectSerialisesConcurrentMigrations (4.44s)12362026/10/27 13:03:39 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLmViNzdhNzNmLWIxZDctNDJmYy1iOTk4LWEyN2E0NTRiMmE4MHgxNzkzMTA2MjA4NDk2NDMyMDAw parts=1012372026/10/27 13:03:39 INFO Received uploads request method=POST path=/api/pending_closures12382026/10/27 13:03:39 INFO Aborted multipart uploads count=0 kept=012392026/10/27 13:03:39 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=01240--- PASS: TestTombstonedObjectOfferedWithoutWaiting (7.50s)1241=== CONT TestClientMultipleUploads12422026-10-27 13:03:39.665 UTC [9427] ERROR: could not obtain lock on row in relation "closures"12432026-10-27 13:03:39.665 UTC [9427] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12442026/10/27 13:03:39 INFO Vacuumed table table=pending_closures12452026-10-27 13:03:39.672 UTC [9427] ERROR: could not obtain lock on row in relation "closures"12462026-10-27 13:03:39.672 UTC [9427] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12472026-10-27 13:03:39.673 UTC [9427] ERROR: could not obtain lock on row in relation "closures"12482026-10-27 13:03:39.673 UTC [9427] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12492026-10-27 13:03:39.679 UTC [9427] ERROR: could not obtain lock on row in relation "closures"12502026-10-27 13:03:39.679 UTC [9427] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12512026-10-27 13:03:39.685 UTC [9427] ERROR: could not obtain lock on row in relation "closures"12522026-10-27 13:03:39.685 UTC [9427] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12532026/10/27 13:03:39 INFO Vacuumed table table=pending_objects12542026/10/27 13:03:39 INFO Vacuumed table table=multipart_uploads12552026/10/27 13:03:39 INFO Vacuumed table table=closures12562026/10/27 13:03:39 INFO Vacuumed table table=objects1257--- PASS: TestPush_RootsAreLockedInByteOrder (15.71s)1258=== CONT TestClientPushesUseOnePush12592026/10/27 13:03:39 INFO Aborted multipart uploads count=0 kept=012602026/10/27 13:03:39 WARN Force mode enabled - objects will be deleted immediately without grace period12612026/10/27 13:03:39 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=012622026/10/27 13:03:39 INFO Vacuumed table table=pending_closures12632026/10/27 13:03:39 INFO Vacuumed table table=pending_objects12642026/10/27 13:03:39 INFO Vacuumed table table=multipart_uploads12652026/10/27 13:03:39 INFO Aborted multipart uploads count=0 kept=012662026/10/27 13:03:39 INFO Vacuumed table table=closures12672026/10/27 13:03:39 INFO Vacuumed table table=objects12682026/10/27 13:03:39 WARN Force mode enabled - objects will be deleted immediately without grace period12692026/10/27 13:03:39 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=012702026/10/27 13:03:39 INFO Vacuumed table table=pending_closures12712026/10/27 13:03:39 INFO Vacuumed table table=pending_objects1272--- PASS: TestPushDedupSurvivesConcurrentGC (8.16s)12732026/10/27 13:03:39 INFO Vacuumed table table=multipart_uploads1274=== CONT TestClientWithDependencies12752026/10/27 13:03:39 INFO Vacuumed table table=closures12762026/10/27 13:03:39 INFO Vacuumed table table=objects1277--- PASS: TestGCMetrics (7.90s)1278=== CONT TestPinProtectsFromGC1279=== NAME TestNARDeduplicationMetadataUploadBug1280 metadata_upload_test.go:48: First store path: /private/var/tb/8/scratch/0a0a303197769805/build/TestNARDeduplicationMetadataUploadBug65147091/001/store/aj623vd7wgzg7sd6202bzlnwy3942pzc-file1.txt12812026/10/27 13:03:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12822026/10/27 13:03:40 INFO Received push request method=POST path=/api/pushes12832026/10/27 13:03:40 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12842026/10/27 13:03:40 INFO Uploading aj623vd7wgzg7sd6202bzlnwy3942pzc-file1.txt (160B)12852026/10/27 13:03:40 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLjY5Yjc2NjgwLTdiYzYtNDY3MC1hZGVlLTIxMTNmODdlNmRiZXgxNzkzMTA2MjE4NjUyMjgyMDAw parts=1012862026/10/27 13:03:40 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12872026/10/27 13:03:40 WARN Failed to register uploaded object key=aj623vd7wgzg7sd6202bzlnwy3942pzc.ls error="server returned 404: 404 page not found\n"12882026/10/27 13:03:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12892026/10/27 13:03:40 INFO Signed narinfos id=1 count=112902026/10/27 13:03:40 INFO Uploading 1 narinfos12912026/10/27 13:03:40 INFO Received uploads request method=POST path=/api/pending_closures12922026/10/27 13:03:40 INFO Received complete push request method=POST path=/api/pushes/1/complete12932026/10/27 13:03:40 WARN Failed to register uploaded object key=aj623vd7wgzg7sd6202bzlnwy3942pzc.narinfo error="server returned 404: 404 page not found\n"12942026/10/27 13:03:41 INFO Completed push id=1 objects=3 duration=38.782625ms12952026/10/27 13:03:41 INFO Upload complete. (333ms)1296 metadata_upload_test.go:54: Retrieved narinfo from S3:1297 StorePath: /private/var/tb/8/scratch/0a0a303197769805/build/TestNARDeduplicationMetadataUploadBug65147091/001/store/aj623vd7wgzg7sd6202bzlnwy3942pzc-file1.txt1298 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1299 Compression: zstd1300 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1301 NarSize: 1601302 References: 1303 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1304 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1305 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1306 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1307 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/8/scratch/0a0a303197769805/build/TestNARDeduplicationMetadataUploadBug65147091/001/store/jiq1y3zwwlgjfbs61yy061gf4fb2pbdm-file2.txt13082026/10/27 13:03:41 INFO Received push request method=POST path=/api/pushes13092026/10/27 13:03:41 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13102026/10/27 13:03:41 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13112026/10/27 13:03:41 WARN Failed to register uploaded object key=jiq1y3zwwlgjfbs61yy061gf4fb2pbdm.ls error="server returned 404: 404 page not found\n"13122026/10/27 13:03:41 INFO Signed narinfos id=2 count=113132026/10/27 13:03:41 INFO Uploading 1 narinfos13142026/10/27 13:03:41 INFO Received complete push request method=POST path=/api/pushes/2/complete13152026/10/27 13:03:41 WARN Failed to register uploaded object key=jiq1y3zwwlgjfbs61yy061gf4fb2pbdm.narinfo error="server returned 404: 404 page not found\n"13162026/10/27 13:03:41 INFO Completed push id=2 objects=3 duration=1.141417ms13172026/10/27 13:03:41 INFO Upload complete. (218ms)1318 metadata_upload_test.go:76: Retrieved narinfo from S3:1319 StorePath: /private/var/tb/8/scratch/0a0a303197769805/build/TestNARDeduplicationMetadataUploadBug65147091/001/store/jiq1y3zwwlgjfbs61yy061gf4fb2pbdm-file2.txt1320 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1321 Compression: zstd1322 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1323 NarSize: 1601324 References: 1325 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1326 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1327 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1328 {"version":1,"root":{"type":"regular","size":44}}1329--- PASS: TestPushWaitsForSweepHoldingRow (9.08s)1330=== CONT TestGCTaskStore_Fail1331--- PASS: TestGCTaskStore_Fail (0.00s)1332=== CONT TestService_AuthMiddleware_OIDC13332026/10/27 13:03:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62423/oidc1334--- PASS: TestGCBugBareHashReferences (8.66s)1335=== CONT TestClientIntegration1336--- PASS: TestNARDeduplicationMetadataUploadBug (9.45s)1337=== CONT TestCacheStatsHandler13382026/10/27 13:03:41 INFO Aborted multipart uploads count=0 kept=013392026/10/27 13:03:41 WARN Force mode enabled - objects will be deleted immediately without grace period13402026/10/27 13:03: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=013412026/10/27 13:03:41 INFO Vacuumed table table=pending_closures13422026/10/27 13:03:41 WARN readiness check failed error="closed pool"13432026/10/27 13:03:41 INFO Vacuumed table table=pending_objects13442026/10/27 13:03:41 INFO Vacuumed table table=multipart_uploads1345--- PASS: TestService_readinessHandler (8.64s)1346=== CONT TestCacheConfigHandler1347=== RUN TestCacheConfigHandler/full_config,_no_issuer1348=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1349=== RUN TestCacheConfigHandler/no_cache_url_configured1350=== PAUSE TestCacheConfigHandler/no_cache_url_configured1351=== RUN TestCacheConfigHandler/no_signing_keys1352=== PAUSE TestCacheConfigHandler/no_signing_keys1353=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1354=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1355=== CONT TestSkippedUploadsHandler13562026/10/27 13:03:42 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001357--- PASS: TestSkippedUploadsHandler (0.01s)1358=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT13592026/10/27 13:03:42 INFO Vacuumed table table=closures13602026/10/27 13:03:42 INFO Vacuumed table table=objects1361--- PASS: TestCommitRacingPendingCleanupKeepsObjects (8.78s)1362=== CONT TestCompleteMultipartUnregistered13632026/10/27 13:03:42 INFO lead: acquired remote=192.0.2.1:123413642026/10/27 13:03:42 INFO lead: released remote=192.0.2.1:12341365--- PASS: TestLeadIncumbentAnnouncesAtOnce (8.91s)1366=== CONT TestService_createPendingClosureHandler13672026/10/27 13:03:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13682026/10/27 13:03:42 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLmYzOGIwODlkLWQ3MGYtNGRkNy1hMDg2LWZhZWUwNmFkNWY2MHgxNzkzMTA2MjE4NjUzNjc4MDAw parts=1013692026/10/27 13:03:42 INFO Received complete push request method=POST path=/api/pushes/1/complete13702026/10/27 13:03:42 INFO Completed push id=1 objects=4 duration=24.018959ms13712026/10/27 13:03:42 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13722026/10/27 13:03:42 INFO Completed upload id=2 objects=2 duration=2.58025ms13732026/10/27 13:03:42 INFO lead: acquired remote=192.0.2.1:12341374--- PASS: TestMetricsCommit (11.76s)1375=== CONT TestService_cleanupPendingClosuresHandler13762026/10/27 13:03:43 INFO lead: acquired remote=192.0.2.1:12341377--- PASS: TestGetExistingObjectsLocksRows (7.51s)1378=== CONT TestService_ReadScope_PublicByDefault13792026/10/27 13:03:43 INFO lead: released remote=192.0.2.1:12341380--- PASS: TestLeadEndsOnShutdown (9.57s)1381=== CONT TestUploadHandlersRejectOversizedBody1382=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1383=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1384=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1385=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1386=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1387=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1388=== CONT TestUploadHandlersRejectInvalidKeys1389=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1390=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1391=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1392=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1393=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1394=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1395=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1396=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1397=== CONT TestClientCADerivations13982026/10/27 13:03:44 INFO Aborted multipart uploads count=1 kept=013992026/10/27 13:03:44 INFO Aborted multipart uploads count=0 kept=014002026/10/27 13:03:44 INFO Received cleanup request method=DELETE path=/api/pending_closures14012026/10/27 13:03:44 INFO Aborted multipart uploads count=1 kept=01402--- PASS: TestConnectWaitsForAPeerMigration (8.79s)1403=== CONT TestService_verifyS3Integrity14042026/10/27 13:03:44 WARN Force mode enabled - objects will be deleted immediately without grace period1405--- PASS: TestPendingCleanupUsesOneCutoff (13.78s)1406=== CONT TestProxyWriteTimeout1407=== RUN TestProxyWriteTimeout/narinfo1408=== PAUSE TestProxyWriteTimeout/narinfo1409=== RUN TestProxyWriteTimeout/1_GiB_nar1410=== PAUSE TestProxyWriteTimeout/1_GiB_nar1411=== RUN TestProxyWriteTimeout/10_GiB_nar1412=== PAUSE TestProxyWriteTimeout/10_GiB_nar1413=== RUN TestProxyWriteTimeout/unknown_size1414=== PAUSE TestProxyWriteTimeout/unknown_size1415=== CONT TestPendingClosureWriteTimeout1416=== RUN TestPendingClosureWriteTimeout/empty1417=== PAUSE TestPendingClosureWriteTimeout/empty1418=== RUN TestPendingClosureWriteTimeout/400_objects1419=== PAUSE TestPendingClosureWriteTimeout/400_objects1420=== RUN TestPendingClosureWriteTimeout/670k_objects1421=== PAUSE TestPendingClosureWriteTimeout/670k_objects1422=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1423=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1424=== CONT TestIsValidUploadKey1425=== RUN TestIsValidUploadKey/narinfo1426=== PAUSE TestIsValidUploadKey/narinfo1427=== RUN TestIsValidUploadKey/nar_zst1428=== PAUSE TestIsValidUploadKey/nar_zst1429=== RUN TestIsValidUploadKey/nar_xz1430=== PAUSE TestIsValidUploadKey/nar_xz1431=== RUN TestIsValidUploadKey/nar_plain1432=== PAUSE TestIsValidUploadKey/nar_plain1433=== RUN TestIsValidUploadKey/listing1434=== PAUSE TestIsValidUploadKey/listing1435=== RUN TestIsValidUploadKey/build_log1436=== PAUSE TestIsValidUploadKey/build_log1437=== RUN TestIsValidUploadKey/build_log_home-manager_file1438=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1439=== RUN TestIsValidUploadKey/build_log_plus_in_name1440=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1441=== RUN TestIsValidUploadKey/build_log_question_mark1442=== PAUSE TestIsValidUploadKey/build_log_question_mark1443=== RUN TestIsValidUploadKey/build_log_equals1444=== PAUSE TestIsValidUploadKey/build_log_equals1445=== RUN TestIsValidUploadKey/realisation1446=== PAUSE TestIsValidUploadKey/realisation1447=== RUN TestIsValidUploadKey/realisation_plus_in_output1448=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1449=== RUN TestIsValidUploadKey/nix-cache-info1450=== PAUSE TestIsValidUploadKey/nix-cache-info1451=== RUN TestIsValidUploadKey/index.html1452=== PAUSE TestIsValidUploadKey/index.html1453=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1454=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type14552026/10/27 13:03:44 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=01456=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1457=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1458=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1459=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1460=== RUN TestIsValidUploadKey/traversal1461=== PAUSE TestIsValidUploadKey/traversal1462=== RUN TestIsValidUploadKey/traversal_nar1463=== PAUSE TestIsValidUploadKey/traversal_nar1464=== RUN TestIsValidUploadKey/absolute1465=== PAUSE TestIsValidUploadKey/absolute1466=== RUN TestIsValidUploadKey/empty_key1467=== PAUSE TestIsValidUploadKey/empty_key1468=== RUN TestIsValidUploadKey/unknown_type1469=== PAUSE TestIsValidUploadKey/unknown_type1470=== CONT TestCompletedNarNotReofferedAcrossClosures14712026/10/27 13:03:44 INFO Vacuumed table table=pending_closures14722026/10/27 13:03:44 INFO Vacuumed table table=pending_objects14732026/10/27 13:03:44 INFO Vacuumed table table=multipart_uploads14742026/10/27 13:03:44 INFO Vacuumed table table=closures14752026/10/27 13:03:44 INFO Vacuumed table table=objects14762026/10/27 13:03:44 INFO lead: released remote=192.0.2.1:12341477--- PASS: TestSweepRechecksPendingAfterLocking (6.73s)1478=== CONT TestParseSize1479--- PASS: TestParseSize (0.00s)1480=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1481--- PASS: TestRegisterCompletedObjectNeedsPendingRow (6.84s)14822026/10/27 13:03:44 INFO lead: acquired remote=192.0.2.1:12341483=== CONT TestPresignedUploadRegisteredBeforeCommit14842026/10/27 13:03:45 INFO Received push request method=POST path=/api/pushes14852026/10/27 13:03:45 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14862026/10/27 13:03:45 INFO Uploading bsz8ag4iw3cwbhq7abpraan811jsgl9r-shared-dep (136B)14872026/10/27 13:03:45 INFO Uploading 01b6z574ymps2vc9vg24yf13b05xaixi-top (264B)14882026/10/27 13:03:45 INFO lead: released remote=192.0.2.1:12341489--- PASS: TestLeadElectsOneAndHandsOver (9.74s)14902026/10/27 13:03:45 WARN Failed to register uploaded object key=bsz8ag4iw3cwbhq7abpraan811jsgl9r.ls error="server returned 404: 404 page not found\n"1491=== CONT TestPush_SignsNarinfosOfItsPendingObjects14922026/10/27 13:03:45 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14932026/10/27 13:03:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14942026/10/27 13:03:45 WARN Failed to register uploaded object key=01b6z574ymps2vc9vg24yf13b05xaixi.ls error="server returned 404: 404 page not found\n"14952026/10/27 13:03:45 WARN Failed to register uploaded object key=nar/1scr1kpshcz0wa0mhv1zj8sh653s9arkx6vzbmswjpdv0a5skp3n.nar.zst error="server returned 404: 404 page not found\n"14962026/10/27 13:03:45 INFO Signed narinfos id=1 count=214972026/10/27 13:03:45 INFO Uploading 2 narinfos14982026/10/27 13:03:45 WARN Failed to register uploaded object key=bsz8ag4iw3cwbhq7abpraan811jsgl9r.narinfo error="server returned 404: 404 page not found\n"14992026/10/27 13:03:45 INFO Received complete push request method=POST path=/api/pushes/1/complete15002026/10/27 13:03:45 WARN Failed to register uploaded object key=01b6z574ymps2vc9vg24yf13b05xaixi.narinfo error="server returned 404: 404 page not found\n"15012026/10/27 13:03:45 INFO Completed push id=1 objects=6 duration=14.58075ms15022026/10/27 13:03:45 INFO Upload complete. (261ms)1503=== NAME TestClientSharedPathCommittedMidPush1504 client_integration_test.go:803: Retrieved narinfo from S3:1505 StorePath: /private/var/tb/8/scratch/0a0a303197769805/build/TestClientSharedPathCommittedMidPush2996175466/001/store/bsz8ag4iw3cwbhq7abpraan811jsgl9r-shared-dep1506 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1507 Compression: zstd1508 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821509 NarSize: 1361510 References: 1511 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1512 client_integration_test.go:803: Retrieved narinfo from S3:1513 StorePath: /private/var/tb/8/scratch/0a0a303197769805/build/TestClientSharedPathCommittedMidPush2996175466/001/store/01b6z574ymps2vc9vg24yf13b05xaixi-top1514 URL: nar/1scr1kpshcz0wa0mhv1zj8sh653s9arkx6vzbmswjpdv0a5skp3n.nar.zst1515 Compression: zstd1516 NarHash: sha256:1scr1kpshcz0wa0mhv1zj8sh653s9arkx6vzbmswjpdv0a5skp3n1517 NarSize: 2641518 References: /private/var/tb/8/scratch/0a0a303197769805/build/TestClientSharedPathCommittedMidPush2996175466/001/store/bsz8ag4iw3cwbhq7abpraan811jsgl9r-shared-dep1519 CA: text:sha256:19nj47wl852d7lv0awj0c5r7d4k8b0cq7r8lfjyqlyfyaizr95gx1520--- PASS: TestClientSharedPathCommittedMidPush (7.30s)1521=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1522=== NAME TestClientMultipleUploads1523 client_integration_test.go:467: Created store path 0: /private/var/tb/8/scratch/0a0a303197769805/build/TestClientMultipleUploads1673900942/001/store/cspdlrwwg0g96b51ljw8h6a81i7lqb40-test-file-0.txt1524--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (9.62s)1525=== CONT TestService_Rustfstest15262026/10/27 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures15272026/10/27 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures15282026/10/27 13:03:45 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15292026/10/27 13:03:45 INFO Uploading i43a30m5d6dk394hv7j1qf4p6ay7374i-a (256B)15302026/10/27 13:03:45 INFO Uploading c098rw81zr3cwsj4f1nbiixd90zj38c2-shared-dep (136B)15312026/10/27 13:03:45 WARN Failed to register uploaded object key=7sqqdx0rq3z2i53nrynh2aasf5pfjfpb.ls error="server returned 404: 404 page not found\n"15322026/10/27 13:03:45 WARN Failed to register uploaded object key=c098rw81zr3cwsj4f1nbiixd90zj38c2.ls error="server returned 404: 404 page not found\n"15332026/10/27 13:03:45 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15342026/10/27 13:03:45 WARN Failed to register uploaded object key=nar/02zw9y1js1q0hfisjh0mn1ic50kg9r4cj0vmqr3h23rzaj11vdan.nar.zst error="server returned 404: 404 page not found\n"1535=== NAME TestClientMultipleUploads1536 client_integration_test.go:467: Created store path 1: /private/var/tb/8/scratch/0a0a303197769805/build/TestClientMultipleUploads1673900942/001/store/lgh0jrml8f49sjmnhz0m1p0a0wf3a3bl-test-file-1.txt15372026/10/27 13:03:45 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15382026/10/27 13:03:45 WARN Failed to register uploaded object key=i43a30m5d6dk394hv7j1qf4p6ay7374i.ls error="server returned 404: 404 page not found\n"15392026/10/27 13:03:45 INFO Signed narinfos id=1 count=215402026/10/27 13:03:45 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15412026/10/27 13:03:45 INFO Signed narinfos id=2 count=215422026/10/27 13:03:45 INFO Uploading 4 narinfos15432026/10/27 13:03:45 WARN Failed to register uploaded object key=c098rw81zr3cwsj4f1nbiixd90zj38c2.narinfo error="server returned 404: 404 page not found\n"15442026/10/27 13:03:45 WARN Failed to register uploaded object key=7sqqdx0rq3z2i53nrynh2aasf5pfjfpb.narinfo error="server returned 404: 404 page not found\n"15452026/10/27 13:03:45 WARN Failed to register uploaded object key=i43a30m5d6dk394hv7j1qf4p6ay7374i.narinfo error="server returned 404: 404 page not found\n"15462026/10/27 13:03:46 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15472026/10/27 13:03:46 WARN Failed to register uploaded object key=c098rw81zr3cwsj4f1nbiixd90zj38c2.narinfo error="server returned 404: 404 page not found\n"1548 client_integration_test.go:467: Created store path 2: /private/var/tb/8/scratch/0a0a303197769805/build/TestClientMultipleUploads1673900942/001/store/16fyamm5gbpq49plh7fw9a707d143h5r-test-file-2.txt15492026/10/27 13:03:46 INFO Completed upload id=1 objects=6 duration=4.639083ms15502026/10/27 13:03:46 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15512026/10/27 13:03:46 INFO Completed upload id=2 objects=6 duration=1.004292ms15522026/10/27 13:03:46 INFO Upload complete. (384ms)1553=== NAME TestClientFallsBackToClosures1554 client_pushes_test.go:112: Retrieved narinfo from S3:1555 StorePath: /private/var/tb/8/scratch/0a0a303197769805/build/TestClientFallsBackToClosures4112998877/001/store/c098rw81zr3cwsj4f1nbiixd90zj38c2-shared-dep1556 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1557 Compression: zstd1558 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821559 NarSize: 1361560 References: 1561 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1562 client_pushes_test.go:112: Retrieved narinfo from S3:1563 StorePath: /private/var/tb/8/scratch/0a0a303197769805/build/TestClientFallsBackToClosures4112998877/001/store/i43a30m5d6dk394hv7j1qf4p6ay7374i-a1564 URL: nar/02zw9y1js1q0hfisjh0mn1ic50kg9r4cj0vmqr3h23rzaj11vdan.nar.zst1565 Compression: zstd1566 NarHash: sha256:02zw9y1js1q0hfisjh0mn1ic50kg9r4cj0vmqr3h23rzaj11vdan1567 NarSize: 2561568 References: /private/var/tb/8/scratch/0a0a303197769805/build/TestClientFallsBackToClosures4112998877/001/store/c098rw81zr3cwsj4f1nbiixd90zj38c2-shared-dep1569 CA: text:sha256:1mygkxh0zdchvqzrprrzwaxrrmyvmmj38g6mvbkni6q9i2wp6y7r1570 client_pushes_test.go:112: Retrieved narinfo from S3:1571 StorePath: /private/var/tb/8/scratch/0a0a303197769805/build/TestClientFallsBackToClosures4112998877/001/store/7sqqdx0rq3z2i53nrynh2aasf5pfjfpb-b1572 URL: nar/02zw9y1js1q0hfisjh0mn1ic50kg9r4cj0vmqr3h23rzaj11vdan.nar.zst1573 Compression: zstd1574 NarHash: sha256:02zw9y1js1q0hfisjh0mn1ic50kg9r4cj0vmqr3h23rzaj11vdan1575 NarSize: 2561576 References: /private/var/tb/8/scratch/0a0a303197769805/build/TestClientFallsBackToClosures4112998877/001/store/c098rw81zr3cwsj4f1nbiixd90zj38c2-shared-dep1577 CA: text:sha256:1mygkxh0zdchvqzrprrzwaxrrmyvmmj38g6mvbkni6q9i2wp6y7r15782026/10/27 13:03:46 INFO Received push request method=POST path=/api/pushes15792026/10/27 13:03:46 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15802026/10/27 13:03:46 INFO Uploading cspdlrwwg0g96b51ljw8h6a81i7lqb40-test-file-0.txt (160B)15812026/10/27 13:03:46 INFO Uploading 16fyamm5gbpq49plh7fw9a707d143h5r-test-file-2.txt (160B)15822026/10/27 13:03:46 INFO Uploading lgh0jrml8f49sjmnhz0m1p0a0wf3a3bl-test-file-1.txt (160B)1583--- PASS: TestClientFallsBackToClosures (6.82s)1584=== CONT TestCompleteMultipartUpload_ErrorButObjectExists15852026/10/27 13:03:46 WARN Failed to register uploaded object key=lgh0jrml8f49sjmnhz0m1p0a0wf3a3bl.ls error="server returned 404: 404 page not found\n"15862026/10/27 13:03:46 WARN Failed to register uploaded object key=cspdlrwwg0g96b51ljw8h6a81i7lqb40.ls error="server returned 404: 404 page not found\n"15872026/10/27 13:03:46 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15882026/10/27 13:03:46 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15892026/10/27 13:03:46 WARN Failed to register uploaded object key=16fyamm5gbpq49plh7fw9a707d143h5r.ls error="server returned 404: 404 page not found\n"15902026/10/27 13:03:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15912026/10/27 13:03:46 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15922026/10/27 13:03:46 INFO Signed narinfos id=1 count=315932026/10/27 13:03:46 INFO Uploading 3 narinfos15942026/10/27 13:03:46 WARN Failed to register uploaded object key=16fyamm5gbpq49plh7fw9a707d143h5r.narinfo error="server returned 404: 404 page not found\n"15952026/10/27 13:03:46 WARN Failed to register uploaded object key=cspdlrwwg0g96b51ljw8h6a81i7lqb40.narinfo error="server returned 404: 404 page not found\n"15962026/10/27 13:03:46 INFO Received complete push request method=POST path=/api/pushes/1/complete15972026/10/27 13:03:46 WARN Failed to register uploaded object key=lgh0jrml8f49sjmnhz0m1p0a0wf3a3bl.narinfo error="server returned 404: 404 page not found\n"15982026/10/27 13:03:46 INFO Received push request method=POST path=/api/pushes15992026/10/27 13:03:46 INFO Completed push id=1 objects=9 duration=30.700958ms16002026/10/27 13:03:46 INFO Upload complete. (355ms)1601=== NAME TestClientMultipleUploads1602 client_integration_test.go:478: Uploaded 3 paths in 401.418833ms16032026/10/27 13:03:46 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16042026/10/27 13:03:46 INFO Uploading shzrfmbzy49m6wbhdz7qhxp0f37hj5lq-shared-dep (136B)16052026/10/27 13:03:46 INFO Uploading d83m2d60mn5a8vhvfq3dpikncf1q8i51-a (256B)16062026/10/27 13:03:46 WARN Failed to register uploaded object key=shzrfmbzy49m6wbhdz7qhxp0f37hj5lq.ls error="server returned 404: 404 page not found\n"16072026/10/27 13:03:46 WARN Failed to register uploaded object key=08dj4jr0chgr11l53nnkakylyzkvrws6.ls error="server returned 404: 404 page not found\n"16082026/10/27 13:03:46 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16092026/10/27 13:03:46 WARN Failed to register uploaded object key=d83m2d60mn5a8vhvfq3dpikncf1q8i51.ls error="server returned 404: 404 page not found\n"16102026/10/27 13:03:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16112026/10/27 13:03:46 WARN Failed to register uploaded object key=nar/09myd7bjgkl60rgr20dw2kfj8kipmchg6jsxd2adc0fhfvga5fr0.nar.zst error="server returned 404: 404 page not found\n"16122026/10/27 13:03:46 INFO Signed narinfos id=1 count=316132026/10/27 13:03:46 INFO Uploading 3 narinfos1614--- PASS: TestClientMultipleUploads (6.97s)1615=== CONT TestRedundantMultipartUpload16162026/10/27 13:03:46 WARN Failed to register uploaded object key=08dj4jr0chgr11l53nnkakylyzkvrws6.narinfo error="server returned 404: 404 page not found\n"16172026/10/27 13:03:46 WARN Failed to register uploaded object key=d83m2d60mn5a8vhvfq3dpikncf1q8i51.narinfo error="server returned 404: 404 page not found\n"16182026/10/27 13:03:46 INFO Received complete push request method=POST path=/api/pushes/1/complete16192026/10/27 13:03:46 WARN Failed to register uploaded object key=shzrfmbzy49m6wbhdz7qhxp0f37hj5lq.narinfo error="server returned 404: 404 page not found\n"16202026/10/27 13:03:46 INFO Completed push id=1 objects=8 duration=23.168167ms16212026/10/27 13:03:46 INFO Upload complete. (321ms)1622=== NAME TestClientPushesUseOnePush1623 client_pushes_test.go:97: Retrieved narinfo from S3:1624 StorePath: /private/var/tb/8/scratch/0a0a303197769805/build/TestClientPushesUseOnePush3830377293/001/store/shzrfmbzy49m6wbhdz7qhxp0f37hj5lq-shared-dep1625 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1626 Compression: zstd1627 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821628 NarSize: 1361629 References: 1630 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1631 client_pushes_test.go:97: Retrieved narinfo from S3:1632 StorePath: /private/var/tb/8/scratch/0a0a303197769805/build/TestClientPushesUseOnePush3830377293/001/store/d83m2d60mn5a8vhvfq3dpikncf1q8i51-a1633 URL: nar/09myd7bjgkl60rgr20dw2kfj8kipmchg6jsxd2adc0fhfvga5fr0.nar.zst1634 Compression: zstd1635 NarHash: sha256:09myd7bjgkl60rgr20dw2kfj8kipmchg6jsxd2adc0fhfvga5fr01636 NarSize: 2561637 References: /private/var/tb/8/scratch/0a0a303197769805/build/TestClientPushesUseOnePush3830377293/001/store/shzrfmbzy49m6wbhdz7qhxp0f37hj5lq-shared-dep1638 CA: text:sha256:122gzcyn872r586fqjvkp8fm799xm5fsdw2wc901a982y80qzwi91639 client_pushes_test.go:97: Retrieved narinfo from S3:1640 StorePath: /private/var/tb/8/scratch/0a0a303197769805/build/TestClientPushesUseOnePush3830377293/001/store/08dj4jr0chgr11l53nnkakylyzkvrws6-b1641 URL: nar/09myd7bjgkl60rgr20dw2kfj8kipmchg6jsxd2adc0fhfvga5fr0.nar.zst1642 Compression: zstd1643 NarHash: sha256:09myd7bjgkl60rgr20dw2kfj8kipmchg6jsxd2adc0fhfvga5fr01644 NarSize: 2561645 References: /private/var/tb/8/scratch/0a0a303197769805/build/TestClientPushesUseOnePush3830377293/001/store/shzrfmbzy49m6wbhdz7qhxp0f37hj5lq-shared-dep1646 CA: text:sha256:122gzcyn872r586fqjvkp8fm799xm5fsdw2wc901a982y80qzwi91647=== NAME TestClientWithDependencies1648 client_integration_test.go:722: Built derivation: /private/var/tb/8/scratch/0a0a303197769805/build/TestClientWithDependencies3487120635/001/store/04mjarcav81m0gcqdfwnd8il2imlh2l1-test-script1649 client_integration_test.go:724: Found 1 dependencies (including self)1650--- PASS: TestClientPushesUseOnePush (6.98s)1651=== CONT TestService_ReadAuthMiddleware16522026/10/27 13:03:46 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld8 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1653=== NAME TestPinProtectsFromGC1654 client_integration_test.go:854: Pinned store path: /private/var/tb/8/scratch/0a0a303197769805/build/TestPinProtectsFromGC3813760050/001/store/ispljw7yylwb7ybd846i0s6ihlj51r7d-pinned-file.txt1655 client_integration_test.go:855: Unpinned store path: /private/var/tb/8/scratch/0a0a303197769805/build/TestPinProtectsFromGC3813760050/001/store/vgrbgvqp9mp9kmza47nk8hahmgnx7x7m-unpinned-file.txt16562026/10/27 13:03:46 INFO Received push request method=POST path=/api/pushes1657--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (14.62s)1658=== CONT TestService_RequireScope_OIDC16592026/10/27 13:03:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16602026/10/27 13:03:46 INFO Uploading 04mjarcav81m0gcqdfwnd8il2imlh2l1-test-script (136B)16612026/10/27 13:03:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62564/oidc16622026/10/27 13:03:46 WARN Failed to register uploaded object key=log/b6yl2jpqsw8zq8mx02aiivhd13sgw9cq-test-script.drv error="server returned 404: 404 page not found\n"16632026/10/27 13:03:46 WARN Failed to register uploaded object key=04mjarcav81m0gcqdfwnd8il2imlh2l1.ls error="server returned 404: 404 page not found\n"16642026/10/27 13:03:46 INFO Received push request method=POST path=/api/pushes16652026/10/27 13:03:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16662026/10/27 13:03:46 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16672026/10/27 13:03:46 INFO Signed narinfos id=1 count=116682026/10/27 13:03:46 INFO Uploading 1 narinfos16692026/10/27 13:03:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16702026/10/27 13:03:47 INFO Uploading ispljw7yylwb7ybd846i0s6ihlj51r7d-pinned-file.txt (128B)16712026/10/27 13:03:47 INFO Received complete push request method=POST path=/api/pushes/1/complete16722026/10/27 13:03:47 WARN Failed to register uploaded object key=04mjarcav81m0gcqdfwnd8il2imlh2l1.narinfo error="server returned 404: 404 page not found\n"16732026/10/27 13:03:47 WARN Failed to register uploaded object key=ispljw7yylwb7ybd846i0s6ihlj51r7d.ls error="server returned 404: 404 page not found\n"16742026/10/27 13:03:47 INFO Completed push id=1 objects=4 duration=27.93175ms16752026/10/27 13:03:47 INFO Upload complete. (273ms)16762026/10/27 13:03:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16772026/10/27 13:03:47 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16782026/10/27 13:03:47 INFO Signed narinfos id=1 count=116792026/10/27 13:03:47 INFO Uploading 1 narinfos1680=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1681=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1682=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1683=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1684=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1685=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1686=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1687=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1688=== CONT TestPush_RejectsBadRequests16892026/10/27 13:03:47 INFO Aborted multipart uploads count=0 kept=016902026/10/27 13:03:47 WARN Force mode enabled - objects will be deleted immediately without grace period16912026/10/27 13:03:47 INFO Received complete push request method=POST path=/api/pushes/1/complete16922026/10/27 13:03:47 WARN Failed to register uploaded object key=ispljw7yylwb7ybd846i0s6ihlj51r7d.narinfo error="server returned 404: 404 page not found\n"16932026/10/27 13:03: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=016942026/10/27 13:03:47 INFO Completed push id=1 objects=3 duration=21.415ms16952026/10/27 13:03:47 INFO Upload complete. (243ms)16962026/10/27 13:03:47 INFO Vacuumed table table=pending_closures16972026/10/27 13:03:47 INFO Vacuumed table table=pending_objects16982026/10/27 13:03:47 INFO Vacuumed table table=multipart_uploads16992026/10/27 13:03:47 INFO Vacuumed table table=closures17002026/10/27 13:03:47 INFO Vacuumed table table=objects1701=== NAME TestClientWithDependencies1702 client_integration_test.go:740: Skipping nix copy test - isolated store (/private/var/tb/8/scratch/0a0a303197769805/build/TestClientWithDependencies3487120635/001/store) requires matching store prefix17032026/10/27 13:03:47 INFO Received push request method=POST path=/api/pushes17042026/10/27 13:03:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17052026/10/27 13:03:47 INFO Uploading vgrbgvqp9mp9kmza47nk8hahmgnx7x7m-unpinned-file.txt (128B)1706--- PASS: TestClientWithDependencies (7.34s)1707=== CONT TestService_AuthMiddleware_MTLSProxyHeader17082026/10/27 13:03:47 WARN Failed to register uploaded object key=vgrbgvqp9mp9kmza47nk8hahmgnx7x7m.ls error="server returned 404: 404 page not found\n"17092026/10/27 13:03:47 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17102026/10/27 13:03:47 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17112026/10/27 13:03:47 INFO Signed narinfos id=2 count=117122026/10/27 13:03:47 INFO Uploading 1 narinfos17132026/10/27 13:03:47 INFO Received complete push request method=POST path=/api/pushes/2/complete17142026/10/27 13:03:47 WARN Failed to register uploaded object key=vgrbgvqp9mp9kmza47nk8hahmgnx7x7m.narinfo error="server returned 404: 404 page not found\n"17152026/10/27 13:03:47 INFO Completed push id=2 objects=3 duration=649.209µs17162026/10/27 13:03:47 INFO Upload complete. (180ms)1717=== NAME TestOrphanedObjectsGCStressTest1718 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains17192026/10/27 13:03:47 INFO Starting cleanup of old closures method=DELETE path=/api/closures17202026/10/27 13:03:47 INFO Garbage collection started17212026/10/27 13:03:47 INFO Aborted multipart uploads count=0 kept=017222026/10/27 13:03:47 WARN Force mode enabled - objects will be deleted immediately without grace period1723 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion1724=== NAME TestClientIntegration1725 client_integration_test.go:331: Created store path: /private/var/tb/8/scratch/0a0a303197769805/build/TestClientIntegration3511856681/002/store/c2ln4qpwfl55nfvxwmch3dv59qikg51v-test-file.txt17262026/10/27 13:03:47 INFO Received push request method=POST path=/api/pushes1727--- PASS: TestCacheStatsHandler (6.19s)1728=== CONT TestService_AuthMiddleware17292026/10/27 13:03:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17302026/10/27 13:03:47 INFO Uploading c2ln4qpwfl55nfvxwmch3dv59qikg51v-test-file.txt (152B)17312026/10/27 13:03:47 WARN Failed to register uploaded object key=c2ln4qpwfl55nfvxwmch3dv59qikg51v.ls error="server returned 404: 404 page not found\n"17322026/10/27 13:03:47 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17332026/10/27 13:03:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17342026/10/27 13:03:47 INFO Signed narinfos id=1 count=117352026/10/27 13:03:47 INFO Uploading 1 narinfos17362026/10/27 13:03:47 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=017372026/10/27 13:03:47 INFO Vacuumed table table=pending_closures17382026/10/27 13:03:47 INFO Received complete push request method=POST path=/api/pushes/1/complete17392026/10/27 13:03:47 WARN Failed to register uploaded object key=c2ln4qpwfl55nfvxwmch3dv59qikg51v.narinfo error="server returned 404: 404 page not found\n"17402026/10/27 13:03:47 INFO Vacuumed table table=pending_objects17412026/10/27 13:03:47 INFO Completed push id=1 objects=3 duration=39.016584ms17422026/10/27 13:03:47 INFO Vacuumed table table=multipart_uploads17432026/10/27 13:03:47 INFO Upload complete. (367ms)17442026/10/27 13:03:48 INFO Vacuumed table table=closures17452026/10/27 13:03:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17462026/10/27 13:03:48 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst17472026/10/27 13:03:48 INFO Vacuumed table table=objects17482026/10/27 13:03:48 INFO All 1 paths already cached1749=== NAME TestClientIntegration1750 client_integration_test.go:357: Retrieved narinfo from S3:1751 StorePath: /private/var/tb/8/scratch/0a0a303197769805/build/TestClientIntegration3511856681/002/store/c2ln4qpwfl55nfvxwmch3dv59qikg51v-test-file.txt1752 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1753 Compression: zstd1754 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11755 NarSize: 1521756 References: 1757 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11758 client_integration_test.go:358: Retrieved .ls file from S3 (compressed size: 77 bytes)1759 client_integration_test.go:358: Decompressed .ls content (64 bytes):1760 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1761--- PASS: TestCompleteMultipartUnregistered (6.02s)1762=== CONT TestService_healthCheckHandler17632026/10/27 13:03:48 INFO Received uploads request method=POST path=/api/pending_closures17642026/10/27 13:03:48 INFO Received push request method=POST path=/api/pushes17652026/10/27 13:03:48 INFO Object in database but missing from S3 key=c2ln4qpwfl55nfvxwmch3dv59qikg51v.ls17662026/10/27 13:03:48 WARN Found objects in DB but missing from S3, will re-upload count=117672026/10/27 13:03:48 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17682026/10/27 13:03:48 WARN Failed to register uploaded object key=c2ln4qpwfl55nfvxwmch3dv59qikg51v.ls error="server returned 404: 404 page not found\n"17692026/10/27 13:03:48 INFO Received complete push request method=POST path=/api/pushes/2/complete17702026/10/27 13:03:48 INFO Completed push id=2 objects=3 duration=1.168208ms17712026/10/27 13:03:48 INFO Upload complete. (117ms)1772=== NAME TestClientIntegration1773 client_integration_test.go:375: Retrieved .ls file from S3 (compressed size: 62 bytes)1774 client_integration_test.go:375: Decompressed .ls content (49 bytes):1775 {"version":1,"root":{"type":"regular","size":39}}1776--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (6.53s)1777=== CONT TestOrphanedObjectsGC17782026/10/27 13:03:48 INFO Received uploads request method=POST path=/api/pending_closures17792026/10/27 13:03:48 INFO Received uploads request method=POST path=/api/pending_closures17802026/10/27 13:03:48 INFO Received uploads request method=POST path=/api/pending_closures17812026/10/27 13:03:48 INFO Received push request method=POST path=/api/pushes17822026/10/27 13:03:48 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17832026/10/27 13:03:48 INFO Received complete push request method=POST path=/api/pushes/3/complete17842026/10/27 13:03:48 WARN Failed to register uploaded object key=c2ln4qpwfl55nfvxwmch3dv59qikg51v.ls error="server returned 404: 404 page not found\n"17852026/10/27 13:03:48 INFO Completed push id=3 objects=3 duration=1.165875ms17862026/10/27 13:03:49 INFO Upload complete. (136ms)1787=== NAME TestClientIntegration1788 client_integration_test.go:392: Retrieved .ls file from S3 (compressed size: 62 bytes)1789 client_integration_test.go:392: Decompressed .ls content (49 bytes):1790 {"version":1,"root":{"type":"regular","size":39}}17912026/10/27 13:03:49 INFO Received cleanup request method=DELETE path=/api/pending_closures17922026/10/27 13:03:49 INFO Aborted multipart uploads count=0 kept=017932026/10/27 13:03:49 INFO Received uploads request method=POST path=/api/pending_closures17942026/10/27 13:03:49 INFO Received cleanup request method=DELETE path=/api/pending_closures17952026/10/27 13:03:49 INFO Aborted multipart uploads count=1 kept=017962026/10/27 13:03:49 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17972026-10-27 13:03:49.242 UTC [9644] ERROR: Closure does not exist: id=117982026-10-27 13:03:49.242 UTC [9644] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE17992026-10-27 13:03:49.242 UTC [9644] STATEMENT: -- name: CommitPendingClosure :one1800 SELECT commit_pending_closure($1::bigint)::bigint1801 18022026/10/27 13:03:49 INFO Received push request method=POST path=/api/pushes1803--- PASS: TestService_cleanupPendingClosuresHandler (6.47s)18042026/10/27 13:03:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18052026/10/27 13:03:49 INFO Uploading 5zp36pz8xmx1yd9wixm6ab4fllhsaj26-lost-commit.txt (152B)1806=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1807--- PASS: TestDeleteClosuresRacingPins (11.71s)1808=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale18092026/10/27 13:03:49 WARN Failed to register uploaded object key=5zp36pz8xmx1yd9wixm6ab4fllhsaj26.ls error="server returned 404: 404 page not found\n"18102026/10/27 13:03:49 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"18112026/10/27 13:03:49 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign18122026/10/27 13:03:49 INFO Signed narinfos id=4 count=118132026/10/27 13:03:49 INFO Uploading 1 narinfos18142026/10/27 13:03:49 INFO Received complete push request method=POST path=/api/pushes/4/complete18152026/10/27 13:03:49 WARN Failed to register uploaded object key=5zp36pz8xmx1yd9wixm6ab4fllhsaj26.narinfo error="server returned 404: 404 page not found\n"18162026/10/27 13:03:49 INFO Completed push id=4 objects=3 duration=1.10525ms18172026/10/27 13:03:49 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:62584/api/pushes/4/complete\": EOF" url=http://127.0.0.1:62584/api/pushes/4/complete18182026/10/27 13:03:49 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=018192026/10/27 13:03:49 INFO Received create pin request method=POST path=/api/pins/myapp18202026/10/27 13:03:49 INFO Created/updated pin name=myapp store_path=/private/var/tb/8/scratch/0a0a303197769805/build/TestPinProtectsFromGC3813760050/001/store/ispljw7yylwb7ybd846i0s6ihlj51r7d-pinned-file.txt narinfo_key=ispljw7yylwb7ybd846i0s6ihlj51r7d.narinfo18212026/10/27 13:03:49 INFO Starting cleanup of old closures method=DELETE path=/api/closures18222026/10/27 13:03:49 INFO Garbage collection started18232026/10/27 13:03:49 INFO Aborted multipart uploads count=0 kept=018242026/10/27 13:03:49 WARN Force mode enabled - objects will be deleted immediately without grace period1825--- PASS: TestService_ReadScope_PublicByDefault (5.77s)1826=== CONT TestIsValidCachePath/narinfo1827=== CONT TestIsValidCachePath/nix-cache-info18282026/10/27 13:03:49 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=01829=== CONT TestIsValidCachePath/short_hash18302026/10/27 13:03:49 INFO Received complete push request method=POST path=/api/pushes/4/complete18312026/10/27 13:03:49 INFO Vacuumed table table=pending_closures1832=== CONT TestIsValidCachePath/wrong_extension18332026-10-27 13:03:49.532 UTC [9618] ERROR: Push does not exist: id=418342026-10-27 13:03:49.532 UTC [9618] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE18352026-10-27 13:03:49.532 UTC [9618] STATEMENT: -- name: CommitPush :one1836 SELECT commit_push($1::bigint)::bigint1837 18382026/10/27 13:03:49 INFO Vacuumed table table=pending_objects1839=== CONT TestIsValidCachePath/leading_slash1840=== CONT TestIsValidCachePath/empty18412026/10/27 13:03:49 WARN Push not found id=41842=== CONT TestIsValidCachePath/invalid_char_u18432026/10/27 13:03:49 INFO Vacuumed table table=multipart_uploads1844=== CONT TestIsValidCachePath/invalid_char_e18452026/10/27 13:03:49 INFO Upload complete. (373ms)1846=== CONT TestIsValidCachePath/random_path18472026/10/27 13:03:49 INFO Vacuumed table table=closures1848=== CONT TestIsValidCachePath/traversal_in_middle1849=== NAME TestClientIntegration18502026/10/27 13:03:49 INFO Vacuumed table table=objects1851 client_integration_test.go:422: Retrieved narinfo from S3:1852 StorePath: /private/var/tb/8/scratch/0a0a303197769805/build/TestClientIntegration3511856681/002/store/5zp36pz8xmx1yd9wixm6ab4fllhsaj26-lost-commit.txt1853 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1854 Compression: zstd1855 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1856 NarSize: 1521857 References: 1858 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1859=== CONT TestIsValidCachePath/index.html1860=== NAME TestClientIntegration1861 client_integration_test.go:425: Testing garbage collection...1862=== CONT TestIsValidCachePath/nar_bz21863=== CONT TestIsValidCachePath/realisation1864=== CONT TestIsValidCachePath/log1865=== CONT TestIsValidCachePath/ls1866=== CONT TestIsValidCachePath/nar_uncompressed1867=== CONT TestIsValidCachePath/traversal_parent1868=== CONT TestIsValidCachePath/nar_xz1869=== CONT TestIsValidCachePath/nar_zst1870=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1871=== CONT TestParseSingleRange/none1872=== CONT TestParseSingleRange/closed1873=== CONT TestParseSingleRange/start_far_past_EOF1874--- PASS: TestIsValidCachePath (0.02s)1875 --- PASS: TestIsValidCachePath/narinfo (0.00s)1876 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1877 --- PASS: TestIsValidCachePath/short_hash (0.00s)1878 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1879 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1880 --- PASS: TestIsValidCachePath/empty (0.00s)1881 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1882 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1883 --- PASS: TestIsValidCachePath/random_path (0.00s)1884 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1885 --- PASS: TestIsValidCachePath/index.html (0.00s)1886 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1887 --- PASS: TestIsValidCachePath/realisation (0.00s)1888 --- PASS: TestIsValidCachePath/log (0.00s)1889 --- PASS: TestIsValidCachePath/ls (0.00s)1890 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1891 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1892 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1893 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1894 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1895=== CONT TestParseSingleRange/start_past_EOF1896=== CONT TestParseSingleRange/suffix_exceeds_size1897=== CONT TestParseSingleRange/single_byte1898=== CONT TestParseSingleRange/suffix1899=== CONT TestParseSingleRange/malformed_no_dash1900=== CONT TestParseSingleRange/end_clamped_to_size1901=== CONT TestParseSingleRange/open-ended1902=== CONT TestParseSingleRange/malformed_both_empty1903=== CONT TestParseSingleRange/multi-range_ignored19042026/10/27 13:03:49 INFO Starting cleanup of old closures method=DELETE path=/api/closures1905=== CONT TestParseSingleRange/unknown_unit19062026/10/27 13:03:49 INFO Garbage collection started1907=== CONT TestParseSingleRange/malformed_end_before_start1908=== CONT TestResolveDBConnectionString/flag_wins1909--- PASS: TestParseSingleRange (0.00s)1910 --- PASS: TestParseSingleRange/none (0.00s)1911 --- PASS: TestParseSingleRange/closed (0.00s)1912 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1913 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1914 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1915 --- PASS: TestParseSingleRange/single_byte (0.00s)1916 --- PASS: TestParseSingleRange/suffix (0.00s)1917 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1918 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1919 --- PASS: TestParseSingleRange/open-ended (0.00s)1920 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1921 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1922 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1923 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1924=== CONT TestResolveDBConnectionString/nothing_configured1925=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1926=== CONT TestResolveDBConnectionString/file_when_flag_empty1927=== CONT TestResolveDBConnectionString/missing_file_is_an_error1928=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1929--- PASS: TestResolveDBConnectionString (0.03s)1930 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1931 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1932 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1933 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1934 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)19352026/10/27 13:03:49 INFO Aborted multipart uploads count=0 kept=019362026/10/27 13:03:49 WARN Force mode enabled - objects will be deleted immediately without grace period19372026/10/27 13:03:50 INFO Received uploads request method=POST path=/api/pending_closures19382026/10/27 13:03:50 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=019392026/10/27 13:03:50 INFO Vacuumed table table=pending_closures19402026/10/27 13:03:50 INFO Vacuumed table table=pending_objects19412026/10/27 13:03:50 INFO Vacuumed table table=multipart_uploads19422026/10/27 13:03:50 INFO Vacuumed table table=closures19432026/10/27 13:03:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19442026/10/27 13:03:50 INFO Vacuumed table table=objects19452026/10/27 13:03:50 INFO Received uploads request method=POST path=/api/pending_closures19462026/10/27 13:03:50 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLjYxNTU1NDI0LTRjYjUtNDBhMy1hODkxLTI3ODA4YjNjY2RkYXgxNzkzMTA2MjI4ODIyMDc4MDAw parts=1019472026/10/27 13:03:50 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19482026/10/27 13:03:51 INFO Completed upload id=1 objects=2 duration=37.458875ms19492026/10/27 13:03:51 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000019502026/10/27 13:03:51 INFO Received uploads request method=POST path=/api/pending_closures19512026/10/27 13:03:51 INFO Starting cleanup of old closures method=DELETE path=/api/closures19522026/10/27 13:03:51 INFO Aborted multipart uploads count=0 kept=019532026/10/27 13:03:51 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=01954=== NAME TestClientCADerivations1955 client_ca_test.go:136: Built CA derivation: /private/var/tb/8/scratch/0a0a303197769805/build/TestClientCADerivations2095175107/001/store/y5sfmba458zvvfhj9pry4k1r3y3mhz17-ca-test1956 client_ca_test.go:139: Found 1 dependencies (including self)19572026/10/27 13:03:51 INFO Vacuumed table table=pending_closures19582026/10/27 13:03:51 INFO Vacuumed table table=pending_objects19592026/10/27 13:03:51 INFO Vacuumed table table=multipart_uploads19602026/10/27 13:03:51 INFO Received uploads request method=POST path=/api/pending_closures19612026/10/27 13:03:51 INFO Vacuumed table table=closures19622026/10/27 13:03:51 INFO Received push request method=POST path=/api/pushes19632026/10/27 13:03:51 INFO Vacuumed table table=objects19642026/10/27 13:03:51 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001965--- PASS: TestService_createPendingClosureHandler (9.06s)1966=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false19672026/10/27 13:03:51 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19682026/10/27 13:03:51 INFO Uploading y5sfmba458zvvfhj9pry4k1r3y3mhz17-ca-test (144B)1969=== NAME TestPinProtectsFromGC1970 client_integration_test.go:963: Pin successfully protected closure from garbage collection19712026/10/27 13:03:51 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"19722026/10/27 13:03:51 WARN Failed to register uploaded object key=y5sfmba458zvvfhj9pry4k1r3y3mhz17.ls error="server returned 404: 404 page not found\n"19732026/10/27 13:03:51 WARN Failed to register uploaded object key=log/a2dvzpxy8qx75wzz1xc3q656qn6d396h-ca-test.drv error="server returned 404: 404 page not found\n"19742026/10/27 13:03:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19752026/10/27 13:03:51 INFO Signed narinfos id=1 count=119762026/10/27 13:03:51 INFO Uploading 1 narinfos19772026/10/27 13:03:51 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=01978=== NAME TestClientIntegration1979 client_integration_test.go:432: Objects in database after GC:1980 client_integration_test.go:432: Successfully deleted all objects with GC --force19812026/10/27 13:03:51 INFO Received complete push request method=POST path=/api/pushes/1/complete19822026/10/27 13:03:51 WARN Failed to register uploaded object key=y5sfmba458zvvfhj9pry4k1r3y3mhz17.narinfo error="server returned 404: 404 page not found\n"19832026/10/27 13:03:51 INFO Completed push id=1 objects=4 duration=56.043708ms19842026/10/27 13:03:51 INFO Upload complete. (483ms)1985=== NAME TestClientCADerivations1986 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/8/scratch/0a0a303197769805/build/TestClientCADerivations2095175107/001/store/y5sfmba458zvvfhj9pry4k1r3y3mhz17-ca-test1987 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1988 Compression: zstd1989 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1990 NarSize: 1441991 References: 1992 Deriver: /private/var/tb/8/scratch/0a0a303197769805/build/TestClientCADerivations2095175107/001/store/a2dvzpxy8qx75wzz1xc3q656qn6d396h-ca-test.drv1993 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1994 client_ca_test.go:185: Checking for realisation files in S3...1995--- PASS: TestPinProtectsFromGC (11.80s)1996=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1997=== NAME TestClientCADerivations1998 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1999 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache20002026/10/27 13:03:51 INFO Received uploads request method=POST path=/api/pending_closures2001--- PASS: TestClientIntegration (10.26s)2002=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check20032026/10/27 13:03:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20042026/10/27 13:03:51 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst20052026/10/27 13:03:51 INFO Received uploads request method=POST path=/api/pending_closures2006--- PASS: TestPresignedUploadRegisteredBeforeCommit (7.66s)2007=== CONT TestServerTLSConfig/missing_CA_file2008=== CONT TestServerTLSConfig/not_a_PEM_file2009=== CONT TestServerTLSConfig/no_client_CA2010=== NAME TestClientCADerivations2011 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket80?endpoint=http://localhost:62064®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/8/scratch/0a0a303197769805/build/TestClientCADerivations2095175107/001/store'2012=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete2013--- PASS: TestServerTLSConfig (0.00s)2014 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2015 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)2016 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2017=== NAME TestClientCADerivations2018 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 120192026/10/27 13:03:52 INFO Received push request method=POST path=/api/pushes2020--- PASS: TestClientCADerivations (8.28s)2021=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark20222026/10/27 13:03:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20232026/10/27 13:03:52 INFO Signed narinfos id=1 count=120242026/10/27 13:03:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20252026/10/27 13:03:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20262026/10/27 13:03:52 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"20272026/10/27 13:03:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20282026/10/27 13:03:52 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"20292026/10/27 13:03:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20302026/10/27 13:03:52 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=120312026/10/27 13:03:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20322026/10/27 13:03:52 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo2033--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (7.00s)2034=== CONT TestGCEndsOnShutdown/before_the_run2035--- PASS: TestService_Rustfstest (6.91s)2036=== CONT TestClientErrorHandling/InvalidAuthToken20372026/10/27 13:03:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20382026/10/27 13:03:53 INFO Received push request method=POST path=/api/pushes20392026/10/27 13:03:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20402026/10/27 13:03:53 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLjk2MDE4ZjMwLTgyNjYtNDE0Yi04NjZjLTMwNDllZTQxYzNkNngxNzkzMTA2MjMwNDk0NDE5MDAw parts=1220412026/10/27 13:03:53 INFO Received uploads request method=POST path=/api/pending_closures2042--- PASS: TestCompletedNarNotReofferedAcrossClosures (9.09s)20432026/10/27 13:03:53 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLjhlYThlYWI3LTRkNjAtNDYyZC05ZTkxLWIyYWI0MTFkNTQ4Y3gxNzkzMTA2MjMwOTk5NDExMDAw parts=102044=== CONT TestClientErrorHandling/ServerNotAvailable20452026/10/27 13:03:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20462026/10/27 13:03:53 INFO Completed upload id=1 objects=2 duration=39.965167ms20472026/10/27 13:03:53 INFO Received uploads request method=POST path=/api/pending_closures20482026/10/27 13:03:53 INFO Received uploads request method=POST path=/api/pending_closures20492026/10/27 13:03:53 INFO Received uploads request method=POST path=/api/pending_closures20502026/10/27 13:03:53 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo20512026/10/27 13:03:53 WARN Found objects in DB but missing from S3, will re-upload count=120522026/10/27 13:03:53 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete20532026/10/27 13:03:53 INFO Completed upload id=3 objects=2 duration=1.008ms2054--- PASS: TestService_verifyS3Integrity (9.73s)2055=== CONT TestClientErrorHandling/InvalidStorePath20562026/10/27 13:03:53 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20572026/10/27 13:03:53 INFO Received uploads request method=POST path=/api/pending_closures20582026/10/27 13:03:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20592026/10/27 13:03:53 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLmM4MGYyY2Y0LTQ2ZjUtNDZlMC1iZTQzLWY3MDA4NmIzMGE3M3gxNzkzMTA2MjMzNTk3OTc3MDAw20602026/10/27 13:03:53 WARN Request failed, retrying attempt=2 backoff=217.98142ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20612026/10/27 13:03:54 INFO Received uploads request method=POST path=/api/pending_closures20622026/10/27 13:03:54 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLmM4MGYyY2Y0LTQ2ZjUtNDZlMC1iZTQzLWY3MDA4NmIzMGE3M3gxNzkzMTA2MjMzNTk3OTc3MDAw error="Delete \"http://localhost:62064/bucket88/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLmM4MGYyY2Y0LTQ2ZjUtNDZlMC1iZTQzLWY3MDA4NmIzMGE3M3gxNzkzMTA2MjMzNTk3OTc3MDAw\": injected: abort refused"20632026/10/27 13:03:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20642026/10/27 13:03:54 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLmM4MGYyY2Y0LTQ2ZjUtNDZlMC1iZTQzLWY3MDA4NmIzMGE3M3gxNzkzMTA2MjMzNTk3OTc3MDAw20652026/10/27 13:03:54 ERROR Failed to register completed object error="get pending object \"nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst\": context canceled" object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst20662026/10/27 13:03:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20672026/10/27 13:03:54 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified multipart upload does not exist. The upload ID may be invalid, or the upload may have been aborted or completed." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLmM4MGYyY2Y0LTQ2ZjUtNDZlMC1iZTQzLWY3MDA4NmIzMGE3M3gxNzkzMTA2MjMzNTk3OTc3MDAw20682026/10/27 13:03:54 WARN Request failed, retrying attempt=3 backoff=418.337923ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20692026/10/27 13:03:54 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLmM4MGYyY2Y0LTQ2ZjUtNDZlMC1iZTQzLWY3MDA4NmIzMGE3M3gxNzkzMTA2MjMzNTk3OTc3MDAw parts=12070--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (8.01s)2071=== CONT TestCacheConfigHandler/no_signing_keys2072=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2073=== CONT TestCacheConfigHandler/no_cache_url_configured2074=== CONT TestCacheConfigHandler/full_config,_no_issuer2075=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart2076--- PASS: TestCacheConfigHandler (0.00s)2077 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2078 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2079 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2080 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)20812026/10/27 13:03:54 INFO Received complete multipart upload request method=POST path=/20822026-10-27 13:03:54.347 UTC [9255] LOG: checkpoint starting: wal2083--- PASS: TestService_ReadAuthMiddleware (7.57s)2084=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts20852026/10/27 13:03:54 INFO Received request for more parts method=POST path=/2086=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure20872026/10/27 13:03:54 INFO Received uploads request method=POST path=/20882026/10/27 13:03:54 WARN Request failed, retrying attempt=4 backoff=843.152805ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2089=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal20902026/10/27 13:03:54 INFO Received uploads request method=POST path=/2091=== RUN TestService_RequireScope_OIDC/builder_may_write2092=== PAUSE TestService_RequireScope_OIDC/builder_may_write2093=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key2094=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2095=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin20962026/10/27 13:03:54 INFO Received complete multipart upload request method=POST path=/2097=== RUN TestService_RequireScope_OIDC/ops_may_admin2098=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2099=== RUN TestService_RequireScope_OIDC/ops_may_not_write2100=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key2101=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2102=== RUN TestService_RequireScope_OIDC/reader_may_not_write21032026/10/27 13:03:54 INFO Received request for more parts method=POST path=/2104=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2105=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info2106=== RUN TestService_RequireScope_OIDC/static_token_may_admin21072026/10/27 13:03:54 INFO Received uploads request method=POST path=/2108=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2109=== CONT TestProxyWriteTimeout/narinfo2110--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2111 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.01s)2112 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2113 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2114 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.01s)2115=== RUN TestService_RequireScope_OIDC/static_token_may_write2116=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2117=== RUN TestService_RequireScope_OIDC/reader_may_read2118=== PAUSE TestService_RequireScope_OIDC/reader_may_read2119=== RUN TestService_RequireScope_OIDC/writer_implies_read2120=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2121=== CONT TestProxyWriteTimeout/unknown_size2122=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2123=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2124=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc2125=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc2126=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2127=== CONT TestProxyWriteTimeout/10_GiB_nar2128=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2129=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2130=== CONT TestProxyWriteTimeout/1_GiB_nar2131--- PASS: TestProxyWriteTimeout (0.00s)2132 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2133 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2134 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2135 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2136=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2137=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2138=== CONT TestPendingClosureWriteTimeout/670k_objects2139=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2140=== CONT TestPendingClosureWriteTimeout/400_objects2141=== CONT TestPendingClosureWriteTimeout/empty2142=== CONT TestIsValidUploadKey/listing2143=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline2144=== CONT TestIsValidUploadKey/realisation_plus_in_output2145=== CONT TestIsValidUploadKey/unknown_type2146=== CONT TestIsValidUploadKey/empty_key2147=== CONT TestIsValidUploadKey/absolute2148=== CONT TestIsValidUploadKey/traversal_nar2149=== CONT TestIsValidUploadKey/traversal2150=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2151=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2152=== CONT TestIsValidUploadKey/index.html2153=== CONT TestIsValidUploadKey/nix-cache-info2154=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2155=== CONT TestIsValidUploadKey/build_log_home-manager_file2156=== CONT TestIsValidUploadKey/build_log_equals2157=== CONT TestIsValidUploadKey/build_log_question_mark2158=== CONT TestIsValidUploadKey/build_log_plus_in_name2159=== CONT TestIsValidUploadKey/realisation2160=== CONT TestIsValidUploadKey/nar_xz2161=== CONT TestIsValidUploadKey/build_log2162=== CONT TestIsValidUploadKey/nar_plain2163=== CONT TestIsValidUploadKey/nar_zst2164=== CONT TestIsValidUploadKey/narinfo2165=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2166--- PASS: TestIsValidUploadKey (0.03s)2167 --- PASS: TestIsValidUploadKey/listing (0.00s)2168 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2169 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2170 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2171 --- PASS: TestIsValidUploadKey/absolute (0.00s)2172 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2173 --- PASS: TestIsValidUploadKey/traversal (0.00s)2174 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2175 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2176 --- PASS: TestIsValidUploadKey/index.html (0.00s)2177 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2178 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2179 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2180 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2181 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2182 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2183 --- PASS: TestIsValidUploadKey/realisation (0.00s)2184 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2185 --- PASS: TestIsValidUploadKey/build_log (0.00s)2186 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2187 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2188 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2189=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2190=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected21912026/10/27 13:03:54 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]2192=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected21932026/10/27 13:03:54 WARN Authentication failed token_preview=eyJhbGciOi...BoNGIqbreQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2194=== CONT TestService_RequireScope_OIDC/ops_may_admin2195=== CONT TestService_RequireScope_OIDC/reader_may_read2196=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2197=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2198=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2199--- PASS: TestService_AuthMiddleware_OIDC (5.63s)2200 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2201 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2202 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.01s)2203 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)2204=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read22052026/10/27 13:03:54 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]2206=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2207=== CONT TestService_RequireScope_OIDC/reader_may_not_write2208=== CONT TestService_RequireScope_OIDC/static_token_may_write2209=== CONT TestService_RequireScope_OIDC/static_token_may_admin2210=== CONT TestService_RequireScope_OIDC/writer_implies_read2211=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2212=== CONT TestService_RequireScope_OIDC/ops_may_not_write2213=== CONT TestService_RequireScope_OIDC/builder_may_write2214--- PASS: TestService_RequireScope_OIDC (7.82s)2215 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2216 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2217 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2218 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2219 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2220 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2221 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2222 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2223 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2224 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2225 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2226 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2227 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2228 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2229=== RUN TestPush_RejectsBadRequests/no_roots2230=== PAUSE TestPush_RejectsBadRequests/no_roots2231=== RUN TestPush_RejectsBadRequests/no_objects2232=== PAUSE TestPush_RejectsBadRequests/no_objects2233=== RUN TestPush_RejectsBadRequests/bad_root2234=== PAUSE TestPush_RejectsBadRequests/bad_root2235=== RUN TestPush_RejectsBadRequests/root_not_in_objects2236=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects2237=== CONT TestPush_RejectsBadRequests/no_roots2238=== CONT TestPush_RejectsBadRequests/bad_root22392026/10/27 13:03:55 INFO Received push request method=POST path=/api/pushes22402026/10/27 13:03:55 INFO Received push request method=POST path=/api/pushes2241=== CONT TestPush_RejectsBadRequests/root_not_in_objects2242=== CONT TestPush_RejectsBadRequests/no_objects22432026/10/27 13:03:55 INFO Received push request method=POST path=/api/pushes22442026/10/27 13:03:55 INFO Received push request method=POST path=/api/pushes2245--- PASS: TestPush_RejectsBadRequests (8.04s)2246 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2247 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2248 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2249 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)22502026/10/27 13:03:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22512026/10/27 13:03:55 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLjllOGVhN2QyLWNhN2ItNGZmMy05YTIzLWJiNDZmMDU4MDBkN3gxNzkzMTA2MjMzMTk4MjM4MDAw parts=1022522026/10/27 13:03:55 WARN Request failed, retrying attempt=5 backoff=1.650319385s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2253--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (8.19s)22542026/10/27 13:03:55 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"2255--- PASS: TestService_AuthMiddleware (8.07s)2256--- PASS: TestService_healthCheckHandler (8.13s)22572026/10/27 13:03:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22582026/10/27 13:03:56 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLjQ1M2FkNjI0LWU5NTYtNGYwNi04Nzc3LWFiOTc5ZTRkMDI2NHgxNzkzMTA2MjM0MDEwMTMyMDAw parts=1222592026/10/27 13:03:56 INFO Received uploads request method=POST path=/api/pending_closures22602026/10/27 13:03:56 INFO Received uploads request method=POST path=/api/pending_closures22612026/10/27 13:03:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22622026/10/27 13:03:57 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLjVhMGFmNDJkLTcyM2UtNDJlOS1iMzBlLTQ3MDZkZjJiMTg4N3gxNzkzMTA2MjMzMTk4NzI2MDAw parts=1022632026/10/27 13:03:57 INFO Received complete push request method=POST path=/api/pushes/1/complete22642026/10/27 13:03:57 INFO Completed push id=1 objects=4 duration=10.154417ms22652026/10/27 13:03:57 INFO Received push request method=POST path=/api/pushes22662026/10/27 13:03:57 INFO Aborted multipart uploads count=0 kept=022672026/10/27 13:03:57 WARN Force mode enabled - objects will be deleted immediately without grace period22682026/10/27 13:03:57 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22692026/10/27 13:03:57 WARN Request failed, retrying attempt=2 backoff=182.700838ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22702026/10/27 13:03:57 WARN Request failed, retrying attempt=3 backoff=408.169281ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22712026/10/27 13:03:57 WARN Rate limiter enabled after throttle name=s3-test rate=522722026/10/27 13:03:57 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2273=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2274 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102275 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002276--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (13.20s)22772026/10/27 13:03:57 INFO Received uploads request method=POST path=/api/pending_closures22782026/10/27 13:03:57 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=02279--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2280 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (8.10s)2281 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (8.43s)22822026/10/27 13:03:57 INFO Vacuumed table table=pending_closures22832026/10/27 13:03:57 INFO Vacuumed table table=pending_objects22842026/10/27 13:03:57 INFO Vacuumed table table=multipart_uploads22852026/10/27 13:03:57 INFO Vacuumed table table=closures22862026/10/27 13:03:57 INFO Vacuumed table table=objects22872026/10/27 13:03:57 INFO Received uploads request method=POST path=/api/pending_closures22882026/10/27 13:03:57 WARN Request failed, retrying attempt=4 backoff=774.042771ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22892026/10/27 13:03:58 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLjc0YTAwZjdjLThkNWUtNDA2MS04Nzk4LTM0YjUyYmE1NTExMXgxNzkzMTA2MjM3NTY2MDY3MDAw error="Access Denied"22902026/10/27 13:03:58 WARN keeping failed pending closure for cleanup to retry the abort id=12291=== NAME TestOrphanedObjectsGC2292 orphaned_objects_gc_test.go:287: GC Test Summary:2293 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A2294 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B2295 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)2296 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)2297 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects2298--- PASS: TestOrphanedObjectsGC (9.88s)22992026/10/27 13:03:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23002026/10/27 13:03:58 INFO Received uploads request method=POST path=/api/pending_closures23012026/10/27 13:03:58 INFO Aborted multipart uploads count=0 kept=023022026/10/27 13:03:58 WARN Force mode enabled - objects will be deleted immediately without grace period23032026/10/27 13:03:58 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=02304--- PASS: TestPendingClosureFailureTracksEveryUpload (0.00s)2305 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (8.46s)2306 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (7.06s)23072026/10/27 13:03:58 INFO Vacuumed table table=pending_closures23082026/10/27 13:03:58 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLjNjZDlmNDAwLWVlMDMtNDU0ZS1iOWNhLTAwYjYyYzg2MTQ4Y3gxNzkzMTA2MjM2NDIwMDgxMDAw error="Get \"http://127.0.0.1:1/bucket89/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"23092026/10/27 13:03:58 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLjUzMmRmZTg2LWZhZWMtNGJhOS1hMjBkLWFlM2JjMjQ4MWJhYXgxNzkzMTA2MjM2Mzc0OTI1MDAw parts=1223102026/10/27 13:03:58 INFO Received cleanup request method=DELETE path=/api/pending_closures23112026/10/27 13:03:58 INFO Vacuumed table table=pending_objects23122026/10/27 13:03:58 INFO Vacuumed table table=multipart_uploads23132026/10/27 13:03:58 INFO Vacuumed table table=closures23142026/10/27 13:03:58 INFO Aborted multipart uploads count=1 kept=02315--- PASS: TestRedundantMultipartUpload (12.00s)23162026/10/27 13:03:58 INFO Vacuumed table table=objects23172026/10/27 13:03:58 WARN Request failed, retrying attempt=5 backoff=1.652946155s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23182026/10/27 13:03:58 INFO Received uploads request method=POST path=/api/pending_closures23192026/10/27 13:03:58 INFO Aborted multipart uploads count=0 kept=023202026/10/27 13:03:58 WARN Force mode enabled - objects will be deleted immediately without grace period2321--- PASS: TestUploadHandlersRejectOversizedBody (0.09s)2322 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.29s)2323 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.30s)2324 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (4.36s)23252026/10/27 13:03:58 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=023262026/10/27 13:03:58 INFO Vacuumed table table=pending_closures23272026/10/27 13:03:58 INFO Vacuumed table table=pending_objects23282026/10/27 13:03:58 INFO Vacuumed table table=multipart_uploads23292026/10/27 13:03:58 INFO Vacuumed table table=closures23302026/10/27 13:03:59 INFO Vacuumed table table=objects23312026/10/27 13:03:59 INFO Aborted multipart uploads count=0 kept=023322026/10/27 13:03:59 WARN Force mode enabled - objects will be deleted immediately without grace period23332026/10/27 13:03:59 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:62064/bucket103/?delete=\": context canceled"2334--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2335 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (6.83s)2336 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (7.37s)23372026/10/27 13:03:59 INFO Aborted multipart uploads count=0 kept=023382026/10/27 13:03:59 WARN Force mode enabled - objects will be deleted immediately without grace period23392026-10-27 13:03:59.294 UTC [9844] ERROR: canceling statement due to user request23402026-10-27 13:03:59.294 UTC [9844] STATEMENT: -- name: MarkStaleObjects :execrows2341 WITH RECURSIVE ct AS (2342 SELECT timezone('UTC', now()) AS now2343 ),2344 closure_reach AS (2345 -- Start with all closure keys2346 SELECT o.key, o.refs2347 FROM objects o2348 INNER JOIN closures c ON o.key = c.key2349 UNION2350 -- Recursively add all referenced objects2351 SELECT o.key, o.refs2352 FROM objects o2353 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2354 ),2355 reachable_objects AS (2356 SELECT DISTINCT key FROM closure_reach2357 ),2358 stale_objects AS (2359 SELECT o.key2360 FROM objects AS o, ct2361 WHERE2362 NOT EXISTS (2363 SELECT 12364 FROM reachable_objects ro2365 WHERE ro.key = o.key2366 )2367 AND NOT EXISTS (2368 SELECT 12369 FROM pending_objects AS po2370 WHERE po.key = o.key2371 )2372 AND o.deleted_at IS NULL -- Only mark fresh objects2373 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2374 FOR UPDATE2375 )2376 UPDATE objects2377 SET2378 deleted_at = ct.now,2379 first_deleted_at = COALESCE(first_deleted_at, ct.now)2380 FROM stale_objects, ct2381 WHERE objects.key = stale_objects.key2382 23832026/10/27 13:03:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23842026/10/27 13:03:59 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=YmY1NzEyZTktZmFhYi00OTJlLWJlODMtMWFhNjIyYzE5MzIzLjhmNTk4NzJmLTBkMmUtNGI1OS1hMzcxLWRmY2M1MTFlZjg2ZngxNzkzMTA2MjM3MDY5Nzc2MDAw parts=1023852026/10/27 13:03:59 INFO Received complete push request method=POST path=/api/pushes/2/complete23862026/10/27 13:03:59 INFO Completed push id=2 objects=4 duration=7.55125ms2387--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (13.81s)2388--- PASS: TestGCEndsOnShutdown (0.01s)2389 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (7.00s)2390 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (7.07s)2391 --- PASS: TestGCEndsOnShutdown/before_the_run (7.11s)23922026/10/27 13:03:59 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"23932026/10/27 13:03:59 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"23942026/10/27 13:04:00 INFO Received uploads request method=POST path=/api/pending_closures23952026/10/27 13:04:00 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"23962026/10/27 13:04:00 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23972026/10/27 13:04:00 WARN Request failed, retrying attempt=2 backoff=203.553952ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23982026/10/27 13:04:00 WARN Request failed, retrying attempt=3 backoff=362.063865ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2399--- PASS: TestPendingClosureWriteTimeout (0.00s)2400 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2401 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2402 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2403 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (6.26s)24042026/10/27 13:04:01 WARN Request failed, retrying attempt=4 backoff=758.776385ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24052026/10/27 13:04:01 WARN Request failed, retrying attempt=5 backoff=1.711977066s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24062026/10/27 13:04:03 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24072026/10/27 13:04:03 WARN Request failed, retrying attempt=2 backoff=211.437843ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24082026/10/27 13:04:03 WARN Request failed, retrying attempt=3 backoff=385.754578ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24092026/10/27 13:04:04 WARN Request failed, retrying attempt=4 backoff=860.601439ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24102026/10/27 13:04:05 WARN Request failed, retrying attempt=5 backoff=1.620731862s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2411=== NAME TestOrphanedObjectsGCStressTest2412 orphaned_objects_gc_test.go:503: Stress test completed successfully:2413 orphaned_objects_gc_test.go:504: - Active objects preserved: 202414 orphaned_objects_gc_test.go:505: - Objects deleted: 2102415 orphaned_objects_gc_test.go:506: - Total GC'd: 2102416--- PASS: TestOrphanedObjectsGCStressTest (38.52s)2417--- PASS: TestClientErrorHandling (0.03s)2418 --- PASS: TestClientErrorHandling/InvalidStorePath (6.10s)2419 --- PASS: TestClientErrorHandling/InvalidAuthToken (7.45s)2420 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.44s)2421PASS2422{"timestamp":"2026-10-27T13:04:06.738318Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:62607","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}24232026-10-27 13:04:06.906 UTC [9250] LOG: received smart shutdown request24242026-10-27 13:04:06.907 UTC [9250] LOG: background worker "logical replication launcher" (PID 9260) exited with exit code 124252026-10-27 13:04:08.176 UTC [9255] LOG: checkpoint complete: wrote 8459 buffers (51.6%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=13.038 s, sync=0.721 s, total=13.830 s; sync files=37078, longest=0.001 s, average=0.001 s; distance=533723 kB, estimate=533723 kB; lsn=0/233D6D08, redo lsn=0/220C3EE024262026-10-27 13:04:08.177 UTC [9255] LOG: shutting down24272026-10-27 13:04:08.177 UTC [9255] LOG: checkpoint starting: shutdown immediate24282026-10-27 13:04:08.339 UTC [9255] LOG: checkpoint complete: wrote 3498 buffers (21.4%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 1 recycled; write=0.115 s, sync=0.046 s, total=0.162 s; sync files=1144, longest=0.010 s, average=0.001 s; distance=19531 kB, estimate=482304 kB; lsn=0/233D6D80, redo lsn=0/233D6D8024292026-10-27 13:04:08.347 UTC [9250] LOG: database system is shut down2430Running OIDC tests...2431=== RUN TestAudienceForIssuer2432=== PAUSE TestAudienceForIssuer2433=== RUN TestHTTPClientForHasTimeouts2434=== PAUSE TestHTTPClientForHasTimeouts2435=== RUN TestGlobMatch2436=== PAUSE TestGlobMatch2437=== RUN TestValidateToken_ValidToken2438=== PAUSE TestValidateToken_ValidToken2439=== RUN TestValidateToken_WrongAudience2440=== PAUSE TestValidateToken_WrongAudience2441=== RUN TestValidateToken_Expired2442=== PAUSE TestValidateToken_Expired2443=== RUN TestValidateToken_BoundClaimsMismatch2444=== PAUSE TestValidateToken_BoundClaimsMismatch2445=== RUN TestValidateToken_BoundSubjectMismatch2446=== PAUSE TestValidateToken_BoundSubjectMismatch2447=== RUN TestValidateToken_MultipleProviders2448=== PAUSE TestValidateToken_MultipleProviders2449=== RUN TestValidateToken_NoMatchingProvider2450=== PAUSE TestValidateToken_NoMatchingProvider2451=== RUN TestValidateToken_KubernetesServiceAccount2452=== PAUSE TestValidateToken_KubernetesServiceAccount2453=== RUN TestNewValidator_KubernetesRequiresCA2454=== PAUSE TestNewValidator_KubernetesRequiresCA2455=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2456=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2457=== RUN TestPins_ReservedForMatchingRule2458=== PAUSE TestPins_ReservedForMatchingRule2459=== RUN TestPins_TopLevelShorthand2460=== PAUSE TestPins_TopLevelShorthand2461=== RUN TestPins_ConfigValidation2462=== PAUSE TestPins_ConfigValidation2463=== RUN TestScopes_LegacyProviderDefaultsToWrite2464=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2465=== RUN TestScopes_Rules2466=== PAUSE TestScopes_Rules2467=== RUN TestScopes_ConfigValidation2468=== PAUSE TestScopes_ConfigValidation2469=== CONT TestAudienceForIssuer2470=== CONT TestValidateToken_NoMatchingProvider2471=== CONT TestGlobMatch2472=== CONT TestValidateToken_WrongAudience2473=== CONT TestNewValidator_KubernetesRequiresCA2474=== CONT TestValidateToken_BoundSubjectMismatch2475=== CONT TestValidateToken_MultipleProviders2476=== CONT TestValidateToken_Expired2477=== CONT TestValidateToken_ValidToken2478=== CONT TestHTTPClientForHasTimeouts2479=== CONT TestPins_ConfigValidation2480=== CONT TestScopes_Rules2481=== CONT TestScopes_LegacyProviderDefaultsToWrite2482=== CONT TestScopes_ConfigValidation2483--- PASS: TestAudienceForIssuer (0.00s)2484=== CONT TestValidateToken_BoundClaimsMismatch2485--- PASS: TestScopes_ConfigValidation (0.00s)2486--- PASS: TestPins_ConfigValidation (0.00s)2487=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2488=== CONT TestPins_TopLevelShorthand2489=== CONT TestPins_ReservedForMatchingRule2490=== CONT TestValidateToken_KubernetesServiceAccount2491=== RUN TestGlobMatch/foo_foo2492=== PAUSE TestGlobMatch/foo_foo2493=== RUN TestGlobMatch/foo_bar2494=== PAUSE TestGlobMatch/foo_bar2495=== RUN TestGlobMatch/*_2496=== PAUSE TestGlobMatch/*_2497=== RUN TestGlobMatch/*_anything2498=== PAUSE TestGlobMatch/*_anything2499=== RUN TestGlobMatch/foo*_foo2500=== PAUSE TestGlobMatch/foo*_foo2501=== RUN TestGlobMatch/foo*_foobar2502=== PAUSE TestGlobMatch/foo*_foobar2503=== RUN TestGlobMatch/foo*_bar2504=== PAUSE TestGlobMatch/foo*_bar2505=== RUN TestGlobMatch/*bar_bar2506=== PAUSE TestGlobMatch/*bar_bar2507=== RUN TestGlobMatch/*bar_foobar2508=== PAUSE TestGlobMatch/*bar_foobar2509=== RUN TestGlobMatch/*bar_foo2510=== PAUSE TestGlobMatch/*bar_foo2511=== RUN TestGlobMatch/foo*bar_foobar2512=== PAUSE TestGlobMatch/foo*bar_foobar2513=== RUN TestGlobMatch/foo*bar_foo123bar2514=== PAUSE TestGlobMatch/foo*bar_foo123bar2515=== RUN TestGlobMatch/foo*bar_foobarbaz2516=== PAUSE TestGlobMatch/foo*bar_foobarbaz2517=== RUN TestGlobMatch/*/*_foo/bar2518=== PAUSE TestGlobMatch/*/*_foo/bar2519=== RUN TestGlobMatch/*/*_foo2520=== PAUSE TestGlobMatch/*/*_foo2521=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2522=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2523=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02524=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02525=== RUN TestGlobMatch/refs/*/main_refs/heads/main2526=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2527=== RUN TestGlobMatch/fo?_foo2528=== PAUSE TestGlobMatch/fo?_foo2529=== RUN TestGlobMatch/fo?_fo2530=== PAUSE TestGlobMatch/fo?_fo2531=== RUN TestGlobMatch/fo?_fooo2532=== PAUSE TestGlobMatch/fo?_fooo2533=== RUN TestGlobMatch/?oo_foo2534=== PAUSE TestGlobMatch/?oo_foo2535=== RUN TestGlobMatch/?oo_boo2536=== PAUSE TestGlobMatch/?oo_boo2537=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2538=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2539=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2540=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2541=== CONT TestGlobMatch/foo_bar2542=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2543=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2544=== CONT TestGlobMatch/?oo_foo2545=== CONT TestGlobMatch/fo?_fooo2546=== CONT TestGlobMatch/?oo_boo2547=== CONT TestGlobMatch/fo?_foo2548=== CONT TestGlobMatch/fo?_fo2549=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02550=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2551=== CONT TestGlobMatch/refs/*/main_refs/heads/main2552=== CONT TestGlobMatch/*/*_foo2553=== CONT TestGlobMatch/foo*bar_foobarbaz2554=== CONT TestGlobMatch/*/*_foo/bar2555=== CONT TestGlobMatch/foo*bar_foo123bar2556=== CONT TestGlobMatch/*bar_foo2557=== CONT TestGlobMatch/foo*bar_foobar2558=== CONT TestGlobMatch/*bar_bar2559=== CONT TestGlobMatch/foo*_bar2560=== CONT TestGlobMatch/*bar_foobar2561=== CONT TestGlobMatch/foo*_foobar2562=== CONT TestGlobMatch/*_anything2563=== CONT TestGlobMatch/foo*_foo2564=== CONT TestGlobMatch/*_2565=== CONT TestGlobMatch/foo_foo2566--- PASS: TestGlobMatch (0.05s)2567 --- PASS: TestGlobMatch/foo_bar (0.00s)2568 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2569 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2570 --- PASS: TestGlobMatch/?oo_foo (0.00s)2571 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2572 --- PASS: TestGlobMatch/?oo_boo (0.00s)2573 --- PASS: TestGlobMatch/fo?_foo (0.00s)2574 --- PASS: TestGlobMatch/fo?_fo (0.00s)2575 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2576 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2577 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2578 --- PASS: TestGlobMatch/*/*_foo (0.00s)2579 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2580 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2581 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2582 --- PASS: TestGlobMatch/*bar_foo (0.00s)2583 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2584 --- PASS: TestGlobMatch/*bar_bar (0.00s)2585 --- PASS: TestGlobMatch/foo*_bar (0.00s)2586 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2587 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2588 --- PASS: TestGlobMatch/*_anything (0.00s)2589 --- PASS: TestGlobMatch/foo*_foo (0.00s)2590 --- PASS: TestGlobMatch/*_ (0.00s)2591 --- PASS: TestGlobMatch/foo_foo (0.00s)25922026/10/27 13:04:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62875/oidc2593--- PASS: TestValidateToken_Expired (0.06s)25942026/10/27 13:04:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62880/oidc25952026/10/27 13:04:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62878/oidc2596--- PASS: TestPins_TopLevelShorthand (0.07s)25972026/10/27 13:04:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62879/oidc2598--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.07s)2599--- PASS: TestValidateToken_BoundSubjectMismatch (0.09s)26002026/10/27 13:04:11 http: TLS handshake error from 127.0.0.1:62885: remote error: tls: bad certificate2601--- PASS: TestNewValidator_KubernetesRequiresCA (0.11s)26022026/10/27 13:04:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62889/oidc26032026/10/27 13:04:11 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:628872604--- PASS: TestScopes_Rules (0.13s)26052026/10/27 13:04:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62891/oidc2606--- PASS: TestValidateToken_KubernetesServiceAccount (0.11s)2607--- PASS: TestValidateToken_BoundClaimsMismatch (0.13s)26082026/10/27 13:04:11 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:62877/oidc2609--- PASS: TestValidateToken_NoMatchingProvider (0.15s)26102026/10/27 13:04:11 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12326112026/10/27 13:04:11 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:62886/oidc26122026/10/27 13:04:11 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:62897/oidc2613--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.15s)2614--- PASS: TestValidateToken_MultipleProviders (0.17s)26152026/10/27 13:04:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62900/oidc2616--- PASS: TestValidateToken_WrongAudience (0.17s)26172026/10/27 13:04:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62902/oidc2618--- PASS: TestPins_ReservedForMatchingRule (0.18s)26192026/10/27 13:04:11 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:62904/oidc2620--- PASS: TestValidateToken_ValidToken (0.20s)2621--- PASS: TestHTTPClientForHasTimeouts (0.41s)2622PASS2623Running hook tests...2624=== RUN TestSendPathsEmpty2625=== PAUSE TestSendPathsEmpty2626=== RUN TestQueueEnqueueAndFetch2627=== PAUSE TestQueueEnqueueAndFetch2628=== RUN TestQueueDeduplication2629=== PAUSE TestQueueDeduplication2630=== RUN TestQueueRemove2631=== PAUSE TestQueueRemove2632=== RUN TestQueueFetchBatchLimit2633=== PAUSE TestQueueFetchBatchLimit2634=== RUN TestQueueRetryMovesToBack2635=== PAUSE TestQueueRetryMovesToBack2636=== RUN TestQueueFetchRemoveLifecycle2637=== PAUSE TestQueueFetchRemoveLifecycle2638=== RUN TestQueueConcurrentWriters2639=== PAUSE TestQueueConcurrentWriters2640=== RUN TestQueueRemoveLargeClosure2641=== PAUSE TestQueueRemoveLargeClosure2642=== RUN TestServerClientIntegration2643--- PASS: TestServerClientIntegration (0.00s)2644=== RUN TestServerQueueError26452026/10/27 13:04:13 ERROR Failed to queue paths error="permission denied" count=12646--- PASS: TestServerQueueError (0.00s)2647=== RUN TestServerRefusesOversizedAndNonStoreRequests2648=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2649=== RUN TestGetListenerSocketActivation2650 server_test.go:236: systemd socket activation does not exist on darwin2651--- SKIP: TestGetListenerSocketActivation (0.00s)2652=== RUN TestServerStalledClientDoesNotBlockShutdown2653=== PAUSE TestServerStalledClientDoesNotBlockShutdown2654=== RUN TestServerBacksOffOnAcceptErrors2655=== PAUSE TestServerBacksOffOnAcceptErrors2656=== RUN TestDrainIsolatesPoisonPath2657=== PAUSE TestDrainIsolatesPoisonPath2658=== RUN TestRunNotBlockedByPoisonHead2659=== PAUSE TestRunNotBlockedByPoisonHead2660=== RUN TestDrainGivesUpWhenServerDown2661=== PAUSE TestDrainGivesUpWhenServerDown2662=== RUN TestFailedPathPrunedByLaterClosure2663=== PAUSE TestFailedPathPrunedByLaterClosure2664=== RUN TestWorkerUploadsAndRemoves2665=== PAUSE TestWorkerUploadsAndRemoves2666=== RUN TestWorkerSkipsGCdPaths2667=== PAUSE TestWorkerSkipsGCdPaths2668=== RUN TestWorkerPrunesClosureDeps2669=== PAUSE TestWorkerPrunesClosureDeps2670=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2671=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2672=== RUN TestDrainTimeout2673=== PAUSE TestDrainTimeout2674=== RUN TestDrainTimeoutDuringIsolation2675=== PAUSE TestDrainTimeoutDuringIsolation2676=== RUN TestShutdownFinishesInFlightPush2677=== PAUSE TestShutdownFinishesInFlightPush2678=== RUN TestWorkerRemoveFailureIsNotProgress2679=== PAUSE TestWorkerRemoveFailureIsNotProgress2680=== RUN TestWorkerKeepsPathItCannotStat2681=== PAUSE TestWorkerKeepsPathItCannotStat2682=== CONT TestSendPathsEmpty2683=== CONT TestWorkerUploadsAndRemoves2684=== CONT TestWorkerSkipsGCdPaths2685=== CONT TestWorkerKeepsPathItCannotStat2686=== CONT TestWorkerRemoveFailureIsNotProgress2687=== CONT TestShutdownFinishesInFlightPush2688=== CONT TestDrainTimeout2689=== RUN TestShutdownFinishesInFlightPush/completes2690=== PAUSE TestShutdownFinishesInFlightPush/completes2691=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2692=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2693=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2694=== CONT TestWorkerPrunesClosureDeps2695=== CONT TestDrainTimeoutDuringIsolation2696=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2697=== CONT TestFailedPathPrunedByLaterClosure2698=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2699=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2700=== CONT TestServerStalledClientDoesNotBlockShutdown2701=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2702=== CONT TestShutdownFinishesInFlightPush/completes2703=== CONT TestServerRefusesOversizedAndNonStoreRequests2704=== CONT TestServerBacksOffOnAcceptErrors27052026/10/27 13:04:13 ERROR Accept failed error="too many open files"2706=== CONT TestRunNotBlockedByPoisonHead2707=== CONT TestQueueConcurrentWriters2708=== CONT TestQueueDeduplication27092026/10/27 13:04:13 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2710=== CONT TestQueueRemoveLargeClosure2711=== CONT TestDrainIsolatesPoisonPath2712=== CONT TestQueueFetchBatchLimit2713=== CONT TestQueueEnqueueAndFetch2714=== CONT TestDrainGivesUpWhenServerDown27152026/10/27 13:04:13 ERROR Refusing path outside the store path=/nix/store store=/nix/store2716=== CONT TestQueueRetryMovesToBack2717=== CONT TestQueueRemove2718--- PASS: TestSendPathsEmpty (0.00s)2719=== CONT TestQueueFetchRemoveLifecycle2720=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2721=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2722=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2723=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2724=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2725=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2726=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2727=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short27282026/10/27 13:04:13 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store27292026/10/27 13:04:13 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store27302026/10/27 13:04:13 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store27312026/10/27 13:04:13 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27322026/10/27 13:04:13 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27332026/10/27 13:04:13 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store27342026/10/27 13:04:13 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store27352026/10/27 13:04:13 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store27362026/10/27 13:04:13 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store27372026/10/27 13:04:13 ERROR Accept failed error="too many open files"27382026/10/27 13:04:13 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store27392026/10/27 13:04:13 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store27402026/10/27 13:04:13 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store27412026/10/27 13:04:13 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store27422026/10/27 13:04:13 ERROR Failed to decode request error="unexpected EOF"2743--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2744=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline27452026/10/27 13:04:13 ERROR Accept failed error="too many open files"27462026/10/27 13:04:13 INFO Upload queue status pending=327472026/10/27 13:04:13 INFO Uploading batch count=127482026/10/27 13:04:13 ERROR Upload failed error="upload failed" count=127492026/10/27 13:04:13 INFO Upload queue status pending=227502026/10/27 13:04:13 INFO Upload queue status pending=327512026/10/27 13:04:13 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/8/scratch/0a0a303197769805/build/TestWorkerSkipsGCdPaths1993096056/002/nonexistent27522026/10/27 13:04:13 INFO Uploading batch count=227532026/10/27 13:04:13 INFO Upload queue status pending=22754--- PASS: TestQueueDeduplication (0.03s)2755=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths27562026/10/27 13:04:13 INFO Uploading batch count=227572026/10/27 13:04:13 INFO Uploading batch count=427582026/10/27 13:04:13 ERROR Upload failed error="upload failed" count=427592026/10/27 13:04:13 INFO Uploading batch count=127602026/10/27 13:04:13 ERROR Upload failed error="upload failed" count=127612026/10/27 13:04:13 INFO Uploading batch count=227622026/10/27 13:04:13 INFO Uploading batch count=227632026/10/27 13:04:13 INFO Upload queue status pending=227642026/10/27 13:04:13 WARN Cannot stat store path, will retry later path=/private/var/tb/8/scratch/0a0a303197769805/build/TestWorkerKeepsPathItCannotStat909696933/002/locked/aaa error="lstat /private/var/tb/8/scratch/0a0a303197769805/build/TestWorkerKeepsPathItCannotStat909696933/002/locked/aaa: permission denied"27652026/10/27 13:04:13 INFO Uploading batch count=227662026/10/27 13:04:13 INFO Upload queue status pending=227672026/10/27 13:04:13 ERROR Upload failed error="upload failed" count=227682026/10/27 13:04:13 INFO Uploading batch count=227692026/10/27 13:04:13 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/0a0a303197769805/build/TestDrainGivesUpWhenServerDown610575044/002/a2770--- PASS: TestQueueEnqueueAndFetch (0.03s)2771=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch27722026/10/27 13:04:13 INFO Uploading batch count=12773--- PASS: TestQueueFetchBatchLimit (0.03s)2774=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27752026/10/27 13:04:13 INFO Uploading batch count=227762026/10/27 13:04:13 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/0a0a303197769805/build/TestDrainGivesUpWhenServerDown610575044/002/b27772026/10/27 13:04:13 INFO Upload queue status pending=227782026/10/27 13:04:13 INFO Uploading batch count=427792026/10/27 13:04:13 ERROR Upload failed error="upload failed" count=42780--- PASS: TestQueueRetryMovesToBack (0.03s)27812026/10/27 13:04:13 WARN Cannot stat store path, will retry later path=/private/var/tb/8/scratch/0a0a303197769805/build/TestWorkerKeepsPathItCannotStat909696933/002/locked/aaa error="lstat /private/var/tb/8/scratch/0a0a303197769805/build/TestWorkerKeepsPathItCannotStat909696933/002/locked/aaa: permission denied"27822026/10/27 13:04:13 INFO Uploading batch count=127832026/10/27 13:04:13 INFO Uploading batch count=427842026/10/27 13:04:13 ERROR Upload failed error="upload failed" count=427852026/10/27 13:04:13 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/0a0a303197769805/build/TestDrainIsolatesPoisonPath3455046774/002/bbb27862026/10/27 13:04:13 INFO Uploading batch count=227872026/10/27 13:04:13 ERROR Upload failed error="upload failed" count=227882026/10/27 13:04:13 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/0a0a303197769805/build/TestDrainGivesUpWhenServerDown610575044/002/c27892026/10/27 13:04:13 INFO Uploading batch count=127902026/10/27 13:04:13 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/0a0a303197769805/build/TestDrainGivesUpWhenServerDown610575044/002/d27912026/10/27 13:04:13 WARN Cannot stat store path, will retry later path=/private/var/tb/8/scratch/0a0a303197769805/build/TestWorkerKeepsPathItCannotStat909696933/002/locked/aaa error="lstat /private/var/tb/8/scratch/0a0a303197769805/build/TestWorkerKeepsPathItCannotStat909696933/002/locked/aaa: permission denied"2792--- PASS: TestQueueFetchRemoveLifecycle (0.03s)2793--- PASS: TestQueueRemove (0.03s)27942026/10/27 13:04:13 ERROR Accept failed error="too many open files"27952026/10/27 13:04:13 INFO Uploading batch count=227962026/10/27 13:04:13 ERROR Upload failed error="upload failed" count=227972026/10/27 13:04:13 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/0a0a303197769805/build/TestDrainGivesUpWhenServerDown610575044/002/e27982026/10/27 13:04:13 ERROR Drain finished with paths left in queue remaining=127992026/10/27 13:04:13 INFO Uploading batch count=128002026/10/27 13:04:13 ERROR Upload failed error="upload failed" count=128012026/10/27 13:04:13 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/0a0a303197769805/build/TestDrainGivesUpWhenServerDown610575044/002/f28022026/10/27 13:04:13 INFO Uploading batch count=128032026/10/27 13:04:13 ERROR Upload failed error="upload failed" count=128042026/10/27 13:04:13 ERROR Drain finished with paths left in queue remaining=1028052026/10/27 13:04:13 INFO Uploading batch count=128062026/10/27 13:04:13 ERROR Upload failed error="upload failed" count=12807--- PASS: TestFailedPathPrunedByLaterClosure (0.04s)2808--- PASS: TestWorkerKeepsPathItCannotStat (0.04s)28092026/10/27 13:04:13 ERROR Drain finished with paths left in queue remaining=12810--- PASS: TestDrainGivesUpWhenServerDown (0.04s)2811--- PASS: TestDrainIsolatesPoisonPath (0.04s)28122026/10/27 13:04:13 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/8/scratch/0a0a303197769805/build/TestWorkerRemoveFailureIsNotProgresscollected_path4163094544/001/nonexistent28132026/10/27 13:04:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128142026/10/27 13:04:13 INFO Uploading batch count=228152026/10/27 13:04:13 INFO Uploading batch count=228162026/10/27 13:04:13 ERROR Upload failed error="upload failed" count=228172026/10/27 13:04:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228182026/10/27 13:04:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128192026/10/27 13:04:13 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/8/scratch/0a0a303197769805/build/TestWorkerRemoveFailureIsNotProgresscollected_path4163094544/001/nonexistent28202026/10/27 13:04:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128212026/10/27 13:04:13 INFO Uploading batch count=228222026/10/27 13:04:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128232026/10/27 13:04:13 INFO Uploading batch count=228242026/10/27 13:04:13 ERROR Upload failed error="upload failed" count=228252026/10/27 13:04:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228262026/10/27 13:04:13 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/8/scratch/0a0a303197769805/build/TestWorkerRemoveFailureIsNotProgresscollected_path4163094544/001/nonexistent28272026/10/27 13:04:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128282026/10/27 13:04:13 INFO Uploading batch count=228292026/10/27 13:04:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128302026/10/27 13:04:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128312026/10/27 13:04:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228322026/10/27 13:04:13 INFO Uploading batch count=228332026/10/27 13:04:13 ERROR Upload failed error="upload failed" count=228342026/10/27 13:04:13 ERROR Drain finished with paths left in queue remaining=128352026/10/27 13:04:13 ERROR Drain finished with paths left in queue remaining=228362026/10/27 13:04:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128372026/10/27 13:04:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128382026/10/27 13:04:13 ERROR Drain finished with paths left in queue remaining=22839--- PASS: TestWorkerSkipsGCdPaths (0.05s)2840--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.05s)2841--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2842 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.02s)2843 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.02s)2844 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.02s)2845--- PASS: TestWorkerUploadsAndRemoves (0.05s)2846--- PASS: TestWorkerPrunesClosureDeps (0.05s)28472026/10/27 13:04:13 ERROR Accept failed error="too many open files"28482026/10/27 13:04:13 ERROR Accept failed error="too many open files"2849--- PASS: TestQueueConcurrentWriters (0.16s)28502026/10/27 13:04:13 ERROR Failed to decode request error="read unix /private/var/tb/8/scratch/0a0a303197769805/build/hook2828718160/test.sock->: i/o timeout"28512026/10/27 13:04:13 ERROR Failed to write response error="write unix /private/var/tb/8/scratch/0a0a303197769805/build/hook2828718160/test.sock->: i/o timeout"2852--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)28532026/10/27 13:04:13 ERROR Upload failed error="context canceled" count=228542026/10/27 13:04:13 ERROR Upload failed error="context canceled" count=228552026/10/27 13:04:13 ERROR Drain finished with paths left in queue remaining=428562026/10/27 13:04:13 ERROR Drain finished with paths left in queue remaining=428572026/10/27 13:04:13 ERROR Drain finished with paths left in queue remaining=22858--- PASS: TestShutdownFinishesInFlightPush (0.00s)2859 --- PASS: TestShutdownFinishesInFlightPush/completes (0.13s)2860 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.23s)2861--- PASS: TestDrainTimeout (0.23s)28622026/10/27 13:04:13 ERROR Accept failed error="too many open files"28632026/10/27 13:04:13 ERROR Drain finished with paths left in queue remaining=32864--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2865 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.23s)2866 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.33s)28672026/10/27 13:04:14 ERROR Accept failed error="too many open files"2868--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)2869--- PASS: TestQueueRemoveLargeClosure (0.79s)28702026/10/27 13:04:14 INFO Uploading batch count=128712026/10/27 13:04:14 INFO Uploading batch count=128722026/10/27 13:04:14 INFO Uploading batch count=128732026/10/27 13:04:14 ERROR Upload failed error="upload failed" count=128742026/10/27 13:04:14 INFO Uploading batch count=128752026/10/27 13:04:14 ERROR Upload failed error="upload failed" count=128762026/10/27 13:04:14 INFO Uploading batch count=128772026/10/27 13:04:14 ERROR Upload failed error="upload failed" count=128782026/10/27 13:04:14 INFO Uploading batch count=128792026/10/27 13:04:14 ERROR Upload failed error="upload failed" count=128802026/10/27 13:04:14 ERROR Drain finished with paths left in queue remaining=12881--- PASS: TestRunNotBlockedByPoisonHead (1.06s)2882PASS2883Running signing tests...2884=== RUN TestExternalSigner2885=== PAUSE TestExternalSigner2886=== RUN TestExternalSignerWrongPublicKey2887=== PAUSE TestExternalSignerWrongPublicKey2888=== RUN TestExternalSignerErrors2889=== PAUSE TestExternalSignerErrors2890=== RUN TestExternalSignerRestartsAfterCrash2891=== PAUSE TestExternalSignerRestartsAfterCrash2892=== RUN TestExternalSignerProgramErrorKeepsProcess2893=== PAUSE TestExternalSignerProgramErrorKeepsProcess2894=== RUN TestExternalSignerClose2895=== PAUSE TestExternalSignerClose2896=== RUN TestExternalSignerRejectsInvalidPublicKey2897=== PAUSE TestExternalSignerRejectsInvalidPublicKey2898=== RUN TestExternalSignerCancellation2899=== PAUSE TestExternalSignerCancellation2900=== RUN TestGenerateFingerprint2901=== PAUSE TestGenerateFingerprint2902=== RUN TestParseSigningKey2903=== PAUSE TestParseSigningKey2904=== RUN TestSign2905=== PAUSE TestSign2906=== RUN TestSignBatch2907=== PAUSE TestSignBatch2908=== RUN TestNilKeyPublicKey2909=== PAUSE TestNilKeyPublicKey2910=== RUN TestSignErrors2911=== PAUSE TestSignErrors2912=== CONT TestExternalSigner2913=== CONT TestSign2914=== CONT TestExternalSignerClose2915=== CONT TestExternalSignerWrongPublicKey2916=== CONT TestParseSigningKey2917=== RUN TestParseSigningKey/valid_32-byte_key2918=== PAUSE TestParseSigningKey/valid_32-byte_key2919=== CONT TestExternalSignerRejectsInvalidPublicKey2920=== RUN TestExternalSignerRejectsInvalidPublicKey/#002921=== CONT TestNilKeyPublicKey2922--- PASS: TestNilKeyPublicKey (0.00s)2923=== CONT TestGenerateFingerprint2924=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002925=== CONT TestExternalSignerCancellation2926=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2927=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2928=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2929=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2930=== RUN TestParseSigningKey/no_colon2931=== CONT TestExternalSignerProgramErrorKeepsProcess2932=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2933=== CONT TestExternalSignerErrors2934=== CONT TestSignErrors2935=== CONT TestExternalSignerRestartsAfterCrash2936=== RUN TestGenerateFingerprint/basic_with_references2937=== PAUSE TestParseSigningKey/no_colon2938=== CONT TestSignBatch2939=== PAUSE TestGenerateFingerprint/basic_with_references2940=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2941=== RUN TestParseSigningKey/empty_name2942=== RUN TestGenerateFingerprint/no_references2943=== PAUSE TestGenerateFingerprint/no_references2944=== PAUSE TestParseSigningKey/empty_name2945=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2946=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2947=== RUN TestExternalSignerErrors/wrong_signature_length2948=== RUN TestParseSigningKey/invalid_base642949=== PAUSE TestExternalSignerErrors/wrong_signature_length2950=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2951=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2952=== RUN TestExternalSignerErrors/exit_on_request2953=== PAUSE TestParseSigningKey/invalid_base642954=== PAUSE TestExternalSignerErrors/exit_on_request2955=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2956=== RUN TestParseSigningKey/wrong_length2957=== PAUSE TestParseSigningKey/wrong_length2958=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2959=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2960=== RUN TestExternalSignerErrors/invalid_signature_base642961=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2962=== CONT TestParseSigningKey/invalid_base642963=== CONT TestParseSigningKey/no_colon2964=== CONT TestParseSigningKey/wrong_length2965=== PAUSE TestExternalSignerErrors/invalid_signature_base642966=== RUN TestGenerateFingerprint/invalid_nar_hash_length2967=== RUN TestExternalSignerErrors/exit_at_startup2968=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2969=== CONT TestParseSigningKey/valid_32-byte_key2970=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2971=== PAUSE TestExternalSignerErrors/exit_at_startup2972=== CONT TestExternalSignerRejectsInvalidPublicKey/#002973=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2974=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2975=== RUN TestGenerateFingerprint/invalid_store_path_prefix2976=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2977=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2978=== CONT TestParseSigningKey/empty_name2979=== RUN TestExternalSignerErrors/missing_signatures2980=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2981=== RUN TestGenerateFingerprint/invalid_reference_prefix2982=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2983--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.01s)2984 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2985 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2986 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2987 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2988 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2989=== PAUSE TestExternalSignerErrors/missing_signatures2990=== CONT TestGenerateFingerprint/basic_with_references2991=== CONT TestGenerateFingerprint/invalid_reference_prefix2992=== RUN TestExternalSignerErrors/too_few_signatures2993=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2994=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2995=== CONT TestGenerateFingerprint/no_references2996=== CONT TestGenerateFingerprint/invalid_store_path_prefix2997=== CONT TestGenerateFingerprint/invalid_nar_hash_length2998=== PAUSE TestExternalSignerErrors/too_few_signatures2999=== RUN TestExternalSignerErrors/unrequested_key3000=== PAUSE TestExternalSignerErrors/unrequested_key3001--- PASS: TestGenerateFingerprint (0.01s)3002 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)3003 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)3004 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)3005 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)3006 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)3007 --- PASS: TestGenerateFingerprint/no_references (0.00s)3008 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)3009=== RUN TestExternalSignerErrors/program_error3010=== PAUSE TestExternalSignerErrors/program_error3011=== RUN TestExternalSignerErrors/invalid_JSON3012=== PAUSE TestExternalSignerErrors/invalid_JSON3013=== RUN TestExternalSignerErrors/wrong_shape3014=== PAUSE TestExternalSignerErrors/wrong_shape3015=== RUN TestExternalSignerErrors/wrong_signatures_shape3016=== PAUSE TestExternalSignerErrors/wrong_signatures_shape3017=== RUN TestExternalSignerErrors/wrong_signature_name3018=== RUN TestSignErrors/nil_key3019--- PASS: TestSign (0.01s)3020=== PAUSE TestExternalSignerErrors/wrong_signature_name3021--- PASS: TestParseSigningKey (0.00s)3022 --- PASS: TestParseSigningKey/no_colon (0.00s)3023 --- PASS: TestParseSigningKey/wrong_length (0.00s)3024 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)3025 --- PASS: TestParseSigningKey/empty_name (0.00s)3026 --- PASS: TestParseSigningKey/valid_32-byte_key (0.01s)3027 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.01s)3028=== PAUSE TestSignErrors/nil_key3029=== RUN TestSignErrors/nil_narinfo3030=== RUN TestExternalSignerErrors/null3031=== PAUSE TestSignErrors/nil_narinfo3032=== RUN TestSignErrors/invalid_narinfo3033=== PAUSE TestSignErrors/invalid_narinfo3034=== RUN TestSignErrors/canceled3035=== PAUSE TestSignErrors/canceled3036=== PAUSE TestExternalSignerErrors/null3037=== CONT TestSignErrors/canceled3038=== CONT TestSignErrors/nil_narinfo3039=== CONT TestSignErrors/invalid_narinfo3040=== RUN TestExternalSignerErrors/wrong_id3041=== PAUSE TestExternalSignerErrors/wrong_id3042=== CONT TestSignErrors/nil_key3043=== RUN TestExternalSignerErrors/null_signatures3044=== PAUSE TestExternalSignerErrors/null_signatures3045=== RUN TestExternalSignerErrors/missing_signature_name3046=== PAUSE TestExternalSignerErrors/missing_signature_name3047=== CONT TestExternalSignerErrors/wrong_signature_length3048=== CONT TestExternalSignerErrors/program_error3049=== CONT TestExternalSignerErrors/wrong_shape3050=== CONT TestExternalSignerErrors/wrong_signature_name3051=== CONT TestExternalSignerErrors/unrequested_key3052=== CONT TestExternalSignerErrors/null_signatures3053=== CONT TestExternalSignerErrors/wrong_id3054=== CONT TestExternalSignerErrors/wrong_signatures_shape3055=== CONT TestExternalSignerErrors/null3056=== CONT TestExternalSignerErrors/too_few_signatures3057=== CONT TestExternalSignerErrors/invalid_JSON3058--- PASS: TestSignErrors (0.01s)3059 --- PASS: TestSignErrors/canceled (0.00s)3060 --- PASS: TestSignErrors/nil_narinfo (0.00s)3061 --- PASS: TestSignErrors/invalid_narinfo (0.00s)3062 --- PASS: TestSignErrors/nil_key (0.00s)3063=== CONT TestExternalSignerErrors/missing_signatures3064=== CONT TestExternalSignerErrors/invalid_signature_base643065=== CONT TestExternalSignerErrors/exit_on_request3066=== CONT TestExternalSignerErrors/exit_at_startup3067=== CONT TestExternalSignerErrors/missing_signature_name3068--- PASS: TestSignBatch (0.02s)3069--- PASS: TestExternalSigner (0.24s)3070--- PASS: TestExternalSignerWrongPublicKey (0.41s)3071--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.60s)3072--- PASS: TestExternalSignerCancellation (0.81s)3073--- PASS: TestExternalSignerClose (1.01s)3074--- PASS: TestExternalSignerRestartsAfterCrash (1.19s)3075--- PASS: TestExternalSignerErrors (0.01s)3076 --- PASS: TestExternalSignerErrors/wrong_signature_length (1.34s)3077 --- PASS: TestExternalSignerErrors/invalid_JSON (1.53s)3078 --- PASS: TestExternalSignerErrors/wrong_shape (1.72s)3079 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (1.91s)3080 --- PASS: TestExternalSignerErrors/wrong_signature_name (2.11s)3081 --- PASS: TestExternalSignerErrors/too_few_signatures (2.30s)3082 --- PASS: TestExternalSignerErrors/missing_signatures (2.49s)3083 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (2.69s)3084 --- PASS: TestExternalSignerErrors/unrequested_key (2.88s)3085 --- PASS: TestExternalSignerErrors/exit_on_request (3.08s)3086 --- PASS: TestExternalSignerErrors/missing_signature_name (3.27s)3087 --- PASS: TestExternalSignerErrors/program_error (3.47s)3088 --- PASS: TestExternalSignerErrors/exit_at_startup (3.66s)3089 --- PASS: TestExternalSignerErrors/null (3.85s)3090 --- PASS: TestExternalSignerErrors/null_signatures (4.04s)3091 --- PASS: TestExternalSignerErrors/wrong_id (4.23s)3092PASS3093Running OpenBao signer tests...3094=== RUN TestSign3095=== PAUSE TestSign3096=== RUN TestSignErrors3097=== PAUSE TestSignErrors3098=== RUN TestServe3099=== PAUSE TestServe3100=== RUN TestServeRejectsGarbage3101=== PAUSE TestServeRejectsGarbage3102=== CONT TestSign3103=== CONT TestServe3104=== CONT TestSignErrors3105=== CONT TestServeRejectsGarbage3106=== RUN TestSignErrors/http_error3107--- PASS: TestServeRejectsGarbage (0.00s)3108=== PAUSE TestSignErrors/http_error3109=== RUN TestSignErrors/invalid_json3110=== PAUSE TestSignErrors/invalid_json3111=== RUN TestSignErrors/no_prefix3112=== PAUSE TestSignErrors/no_prefix3113=== RUN TestSignErrors/invalid_base643114=== PAUSE TestSignErrors/invalid_base643115=== CONT TestSignErrors/no_prefix3116=== CONT TestSignErrors/invalid_base643117=== CONT TestSignErrors/http_error3118=== CONT TestSignErrors/invalid_json3119--- PASS: TestServe (0.00s)3120--- PASS: TestSign (0.00s)3121--- PASS: TestSignErrors (0.00s)3122 --- PASS: TestSignErrors/invalid_json (0.00s)3123 --- PASS: TestSignErrors/no_prefix (0.00s)3124 --- PASS: TestSignErrors/http_error (0.00s)3125 --- PASS: TestSignErrors/invalid_base64 (0.00s)3126PASS3127Running niks3-hook command tests...3128=== RUN TestServeSecondSignalEndsDrain3129=== PAUSE TestServeSecondSignalEndsDrain3130=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown3131=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown3132=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown3133=== CONT TestServeSecondSignalEndsDrain3134--- PASS: TestServeSecondSignalEndsDrain (0.05s)31352026/10/27 13:04:23 INFO Upload queue status pending=131362026/10/27 13:04:23 INFO Uploading batch count=13137--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.12s)3138PASS3139Running rate limiter tests...3140=== RUN TestAdaptiveRateLimiter_ThreadSafety3141=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3142=== CONT TestAdaptiveRateLimiter_ThreadSafety31432026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=112.7357000000000731442026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=78.9149900000000531452026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=55.2404930000000331462026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=38.6683451000000231472026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=27.0678415700000131482026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=18.94748909900000631492026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=13.26324236930000431502026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=9.28426965851000231512026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=6.49898876095700131522026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531532026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531542026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531552026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531562026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531572026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531582026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531592026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531602026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531612026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531622026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531632026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=6.200463500000001531642026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531652026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531662026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531672026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531682026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531692026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531702026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531712026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531722026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531732026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531742026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531752026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531762026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531772026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531782026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531792026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531802026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531812026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531822026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531832026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531842026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531852026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531862026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531872026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531882026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531892026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=5.12435000000000131902026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531912026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531922026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531932026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531942026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531952026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531962026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531972026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=531982026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=8.25281691850000431992026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=5.77697184295000332002026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532012026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532022026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532032026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532042026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532052026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532062026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532072026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532082026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532092026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532102026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532112026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532122026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532132026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532142026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532152026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532162026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532172026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532182026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532192026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532202026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532212026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532222026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532232026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532242026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532252026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532262026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532272026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532282026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532292026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532302026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532312026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532322026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532332026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532342026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532352026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532362026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532372026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=6.82050985000000232382026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532392026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532402026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532412026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=532422026/10/27 13:04:24 WARN Rate limiter backed off name=test rate=53243--- PASS: TestAdaptiveRateLimiter_ThreadSafety (3.71s)3244PASS