niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #273
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure18=== PAUSE TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure19=== RUN TestUploadMultipart_PartsInParallel20=== PAUSE TestUploadMultipart_PartsInParallel21=== RUN TestUploadMultipart_ProducerErrorIsNotEOF22=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF23=== RUN TestUploadMultipart_FailedPartBufferNotReused24=== PAUSE TestUploadMultipart_FailedPartBufferNotReused25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestUploadMultipart_SupersededByPeer28=== PAUSE TestUploadMultipart_SupersededByPeer29=== RUN TestDumpPathCaseHackMatchesNix30--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)31=== RUN TestDumpPathCaseHackCollision32--- PASS: TestDumpPathCaseHackCollision (0.00s)33=== RUN TestSupersededNARStillUploadsListing34=== PAUSE TestSupersededNARStillUploadsListing35=== RUN TestTruncatedNARDumpIsNotCompleted36=== PAUSE TestTruncatedNARDumpIsNotCompleted37=== RUN TestDumpPathMatchesNix38=== PAUSE TestDumpPathMatchesNix39=== RUN TestDumpPathSingleFile40=== PAUSE TestDumpPathSingleFile41=== RUN TestDumpPathWriterError42=== PAUSE TestDumpPathWriterError43=== RUN TestDumpPathWriterErrorStopsReading44 nar_test.go:289: read 114 of 32768000 bytes45--- PASS: TestDumpPathWriterErrorStopsReading (0.62s)46=== RUN TestEncodeNixBase3247=== PAUSE TestEncodeNixBase3248=== RUN TestEncodeNixBase32WithRealHash49=== PAUSE TestEncodeNixBase32WithRealHash50=== RUN TestConvertHashToNix3251=== PAUSE TestConvertHashToNix3252=== RUN TestGetStorePathHash53=== PAUSE TestGetStorePathHash54=== RUN TestPathInfoHashCompatibility55=== PAUSE TestPathInfoHashCompatibility56=== RUN TestParsePathInfoJSON57=== PAUSE TestParsePathInfoJSON58=== RUN TestParsePathInfoJSONMultiplePaths59=== PAUSE TestParsePathInfoJSONMultiplePaths60=== RUN TestPathInfoCACompatibility61=== PAUSE TestPathInfoCACompatibility62=== RUN TestUploadPendingObjectsStopsStartingAfterFailure63--- PASS: TestUploadPendingObjectsStopsStartingAfterFailure (0.02s)64=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent65=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent66=== RUN TestCompletePendingClosure_NotFoundWithoutKey67=== PAUSE TestCompletePendingClosure_NotFoundWithoutKey68=== RUN TestRateLimiterFeedback69=== PAUSE TestRateLimiterFeedback70=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess71=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess72=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer73=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer74=== RUN TestResolveStorePath75=== PAUSE TestResolveStorePath76=== RUN TestDoWithRetry_BodyReplayedViaGetBody77=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody78=== RUN TestDoWithRetry_FinalResponseBodyReadable79=== PAUSE TestDoWithRetry_FinalResponseBodyReadable80=== RUN TestShellSplit81=== PAUSE TestShellSplit82=== RUN TestShellSplitErrors83=== PAUSE TestShellSplitErrors84=== RUN TestStreamPushReportsEveryPath85=== PAUSE TestStreamPushReportsEveryPath86=== RUN TestStreamPushBatchesUnderLoad87=== PAUSE TestStreamPushBatchesUnderLoad88=== RUN TestStreamPushIsolatesFailures89=== PAUSE TestStreamPushIsolatesFailures90=== RUN TestStreamPushGivesUpOnDeadServer91=== PAUSE TestStreamPushGivesUpOnDeadServer92=== RUN TestStreamPushRequestLine93=== PAUSE TestStreamPushRequestLine94=== RUN TestStreamPushReportsSignatures95=== PAUSE TestStreamPushReportsSignatures96=== RUN TestClientSignaturesByStorePath97=== PAUSE TestClientSignaturesByStorePath98=== RUN TestStreamPushStopsOnCancel99=== PAUSE TestStreamPushStopsOnCancel100=== RUN TestSetClientTLS101=== PAUSE TestSetClientTLS102=== RUN TestSetClientTLSDoesNotMutateDefaultTransport103=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport104=== RUN TestSetClientTLSErrors105=== PAUSE TestSetClientTLSErrors106=== RUN TestStaticToken107=== PAUSE TestStaticToken108=== RUN TestFileTokenReadsAndCaches109=== PAUSE TestFileTokenReadsAndCaches110=== RUN TestFileTokenMissing111=== PAUSE TestFileTokenMissing112=== RUN TestFileTokenEmpty113=== PAUSE TestFileTokenEmpty114=== RUN TestScriptTokenNoExpiryRerunsEveryCall115=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall116=== RUN TestScriptTokenCachesUntilRefresh117=== PAUSE TestScriptTokenCachesUntilRefresh118=== RUN TestScriptTokenEmptyToken119=== PAUSE TestScriptTokenEmptyToken120=== RUN TestScriptTokenBadJSON121=== PAUSE TestScriptTokenBadJSON122=== RUN TestScriptTokenScriptFails123=== PAUSE TestScriptTokenScriptFails124=== RUN TestScriptTokenEmptyCommand125=== PAUSE TestScriptTokenEmptyCommand126=== RUN TestScriptTokenDoesNotWaitForItsChildren127=== PAUSE TestScriptTokenDoesNotWaitForItsChildren128=== CONT TestDoServerRequestAttachesToken129=== CONT TestScriptTokenCachesUntilRefresh130=== CONT TestDoWithRetry_BodyReplayedViaGetBody131=== CONT TestScriptTokenDoesNotWaitForItsChildren132=== CONT TestScriptTokenScriptFails133=== CONT TestScriptTokenEmptyCommand134=== CONT TestEncodeNixBase32WithRealHash135=== CONT TestScriptTokenEmptyToken136=== CONT TestParsePathInfoJSONMultiplePaths137=== CONT TestUploadMultipart_SupersededByPeer138=== CONT TestPathInfoHashCompatibility139=== RUN TestUploadMultipart_SupersededByPeer/exists140=== CONT TestConvertHashToNix32141=== CONT TestPathInfoCACompatibility142=== CONT TestGetStorePathHash143=== CONT TestParsePathInfoJSON144=== CONT TestEncodeNixBase32145=== CONT TestResolveStorePath146=== CONT TestDumpPathWriterError147=== CONT TestDoWithRetry_FinalResponseBodyReadable148=== CONT TestUploadMultipart_ProducerErrorIsNotEOF149=== CONT TestCompletePendingClosure_NotFoundWithoutKey150=== CONT TestDumpPathSingleFile151=== CONT TestRateLimiterFeedback152=== CONT TestSupersededNARStillUploadsListing153=== CONT TestStaticToken154=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs155=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess156--- PASS: TestScriptTokenEmptyCommand (0.00s)157=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths158=== PAUSE TestUploadMultipart_SupersededByPeer/exists159=== RUN TestPathInfoCACompatibility/null_ca_field160=== RUN TestGetStorePathHash/valid_store_path161=== RUN TestConvertHashToNix32/SRI_format_to_Nix32162=== RUN TestEncodeNixBase32/test_string_hash163=== RUN TestParsePathInfoJSON/Nix_format164=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)165=== PAUSE TestParsePathInfoJSON/Nix_format166=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part167=== PAUSE TestEncodeNixBase32/test_string_hash168=== RUN TestRateLimiterFeedback/429_enables_limiter169=== RUN TestSupersededNARStillUploadsListing/small_NAR170=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer171=== CONT TestFileTokenMissing172=== PAUSE TestSupersededNARStillUploadsListing/small_NAR173=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs174--- PASS: TestEncodeNixBase32WithRealHash (0.00s)175=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths176=== PAUSE TestPathInfoCACompatibility/null_ca_field177=== RUN TestUploadMultipart_SupersededByPeer/missing178=== PAUSE TestGetStorePathHash/valid_store_path179=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32180=== CONT TestFileTokenReadsAndCaches181=== CONT TestScriptTokenNoExpiryRerunsEveryCall182=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)183=== RUN TestConvertHashToNix32/already_Nix32_format184=== RUN TestEncodeNixBase32/empty_input185=== CONT TestStreamPushRequestLine186=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon187=== PAUSE TestRateLimiterFeedback/429_enables_limiter188=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout189--- PASS: TestScriptTokenScriptFails (0.00s)190=== PAUSE TestUploadMultipart_SupersededByPeer/missing191=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths192=== RUN TestPathInfoCACompatibility/old_string_format_-_text193=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text194=== CONT TestStreamPushReportsSignatures195=== RUN TestParsePathInfoJSON/Lix_format196=== RUN TestGetStorePathHash/basename_without_hyphen_should_error197=== RUN TestSupersededNARStillUploadsListing/dump_cut_short198=== CONT TestShellSplit199=== PAUSE TestConvertHashToNix32/already_Nix32_format200=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part201=== PAUSE TestEncodeNixBase32/empty_input202=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon203=== RUN TestRateLimiterFeedback/503_enables_limiter204--- PASS: TestStaticToken (0.00s)205=== CONT TestStreamPushIsolatesFailures206--- PASS: TestDoServerRequestAttachesToken (0.01s)207=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent208=== PAUSE TestRateLimiterFeedback/503_enables_limiter209=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure210=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive211=== PAUSE TestParsePathInfoJSON/Lix_format212=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths213=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error214=== CONT TestPartSizeForNAR215=== RUN TestConvertHashToNix32/invalid_format216=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short217=== CONT TestClientSignaturesByStorePath218=== CONT TestShellSplitErrors219=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary220=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout221=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI222--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.02s)223=== CONT TestScriptTokenBadJSON224=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier225=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive226=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter227=== RUN TestParsePathInfoJSON/empty_input228=== CONT TestFileTokenEmpty229=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error230=== RUN TestPartSizeForNAR/zero_stays_at_minimum231=== PAUSE TestConvertHashToNix32/invalid_format232=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails233=== CONT TestStreamPushBatchesUnderLoad234=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary235=== CONT TestSetClientTLSErrors236=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI237--- PASS: TestResolveStorePath (0.00s)238=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error239=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter240=== CONT TestSetClientTLS241=== RUN TestPathInfoCACompatibility/new_structured_format_-_text242=== RUN TestStreamPushBatchesUnderLoad/together243=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512244=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum245=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512246=== CONT TestTruncatedNARDumpIsNotCompleted247=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails248=== PAUSE TestParsePathInfoJSON/empty_input249=== RUN TestParsePathInfoJSON/whitespace_only250=== CONT TestDumpPathMatchesNix251=== CONT TestSetClientTLSDoesNotMutateDefaultTransport252=== CONT TestUploadMultipart_FailedPartBufferNotReused253=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier254--- PASS: TestScriptTokenEmptyToken (0.01s)255=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error256=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter257=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text258=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter259=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method260=== PAUSE TestStreamPushBatchesUnderLoad/together261=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun262=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time263=== RUN TestPartSizeForNAR/small_stays_at_minimum264=== CONT TestUploadMultipart_PartsInParallel265=== PAUSE TestParsePathInfoJSON/whitespace_only266=== CONT TestStreamPushGivesUpOnDeadServer267=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up268--- PASS: TestFileTokenMissing (0.00s)269=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error270=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method271=== CONT TestStreamPushReportsEveryPath272=== CONT TestFilterOversizedClosures273=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time274=== PAUSE TestPartSizeForNAR/small_stays_at_minimum275--- PASS: TestFileTokenReadsAndCaches (0.00s)276=== CONT TestRegisterUploadedObjectReusesConnections277=== RUN TestParsePathInfoJSON/invalid_JSON278=== RUN TestSetClientTLS/rejects_connection_without_client_cert279=== CONT TestStreamPushStopsOnCancel280=== PAUSE TestParsePathInfoJSON/invalid_JSON281=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert282=== RUN TestStreamPushStopsOnCancel/waiting_for_input283=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA284=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA285=== RUN TestSetClientTLS/preserves_debug_logging_transport286=== CONT TestUploadMultipart_SupersededByPeer/exists287=== CONT TestUploadMultipart_SupersededByPeer/missing288=== CONT TestEncodeNixBase32/test_string_hash289=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry290=== CONT TestEncodeNixBase32/empty_input291=== RUN TestSetClientTLSErrors/missing_cert_file292=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths293=== PAUSE TestSetClientTLSErrors/missing_cert_file294=== RUN TestSetClientTLSErrors/missing_key_file295=== PAUSE TestSetClientTLSErrors/missing_key_file296=== RUN TestSetClientTLSErrors/missing_ca_file297=== CONT TestCaseHackSuffix298=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout299=== PAUSE TestSetClientTLSErrors/missing_ca_file300=== RUN TestFilterOversizedClosures/no_limit_keeps_everything301=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs302--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.01s)303--- PASS: TestShellSplit (0.00s)304--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)305=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum306=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum307=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts308=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts309=== RUN TestPartSizeForNAR/1_TiB310--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)311--- PASS: TestShellSplitErrors (0.00s)312=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up313=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica314=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything315=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths316=== PAUSE TestPartSizeForNAR/1_TiB317--- PASS: TestStreamPushIsolatesFailures (0.00s)318--- PASS: TestClientSignaturesByStorePath (0.01s)319=== CONT TestConvertHashToNix32/already_Nix32_format320=== CONT TestConvertHashToNix32/SRI_format_to_Nix32321=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input322=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped323=== CONT TestConvertHashToNix32/invalid_format324--- PASS: TestConvertHashToNix32 (0.02s)325 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)326 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)327 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)328=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot329=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped330=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon331=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot332=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot333=== RUN TestPartSizeForNAR/5_TiB_S3_max_object334=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512335=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)336=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part337--- PASS: TestStreamPushReportsSignatures (0.01s)338=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary339=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI340=== RUN TestFilterOversizedClosures/all_closures_skipped341=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot342=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object343=== RUN TestPartSizeForNAR/capped_at_5_GiB344=== PAUSE TestSetClientTLS/preserves_debug_logging_transport345=== RUN TestSetClientTLSErrors/invalid_ca_file346--- PASS: TestScriptTokenBadJSON (0.01s)347=== CONT TestSupersededNARStillUploadsListing/small_NAR348=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot349=== PAUSE TestFilterOversizedClosures/all_closures_skipped350=== CONT TestSupersededNARStillUploadsListing/dump_cut_short351=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails352=== PAUSE TestPartSizeForNAR/capped_at_5_GiB353--- PASS: TestFileTokenEmpty (0.00s)354=== CONT TestRateLimiterFeedback/503_enables_limiter355=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot356=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter357=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot358=== PAUSE TestSetClientTLSErrors/invalid_ca_file359--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)360--- PASS: TestDumpPathSingleFile (0.23s)361=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot362--- PASS: TestStreamPushReportsEveryPath (0.00s)363--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.21s)364=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken365=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken366--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)367=== CONT TestRateLimiterFeedback/429_enables_limiter368=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error369=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter370=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error371=== CONT TestGetStorePathHash/valid_store_path372--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.20s)373=== CONT TestPathInfoCACompatibility/null_ca_field374=== CONT TestPathInfoCACompatibility/old_string_format_-_text375--- PASS: TestCaseHackSuffix (0.32s)376=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method377=== CONT TestStreamPushBatchesUnderLoad/together378--- PASS: TestEncodeNixBase32 (0.02s)379 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)380 --- PASS: TestEncodeNixBase32/empty_input (0.00s)381=== CONT TestGetStorePathHash/basename_without_hyphen_should_error382=== CONT TestPathInfoCACompatibility/new_structured_format_-_text383=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive384=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time385--- PASS: TestParsePathInfoJSONMultiplePaths (0.02s)386 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)387 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)388=== CONT TestParsePathInfoJSON/whitespace_only389=== CONT TestParsePathInfoJSON/Lix_format390=== CONT TestParsePathInfoJSON/invalid_JSON391=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier392--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.32s)393=== CONT TestParsePathInfoJSON/empty_input394=== CONT TestParsePathInfoJSON/Nix_format395=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up396=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA397=== CONT TestSetClientTLS/rejects_connection_without_client_cert398=== CONT TestSetClientTLS/preserves_debug_logging_transport399=== CONT TestFilterOversizedClosures/all_closures_skipped400=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped401--- PASS: TestUploadMultipart_SupersededByPeer (0.02s)402 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)403 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)404=== CONT TestFilterOversizedClosures/no_limit_keeps_everything405=== CONT TestPartSizeForNAR/capped_at_5_GiB406--- PASS: TestPathInfoHashCompatibility (0.03s)407 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)408 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)409 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)410 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)411=== CONT TestPartSizeForNAR/5_TiB_S3_max_object412=== CONT TestPartSizeForNAR/small_stays_at_minimum413=== CONT TestPartSizeForNAR/zero_stays_at_minimum414=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum415=== CONT TestPartSizeForNAR/1_TiB416=== CONT TestSetClientTLSErrors/missing_key_file417=== CONT TestSetClientTLSErrors/invalid_ca_file418=== CONT TestSetClientTLSErrors/missing_ca_file419=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts420=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken421=== CONT TestStreamPushStopsOnCancel/waiting_for_input422=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot423=== CONT TestSetClientTLSErrors/missing_cert_file424=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot425=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot426--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.33s)427--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.55s)428--- PASS: TestGetStorePathHash (0.23s)429 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)430 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)431 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)432 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)433--- PASS: TestRateLimiterFeedback (0.03s)434 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)435 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)436 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)437 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)438--- PASS: TestPathInfoCACompatibility (0.23s)439 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)440 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)441 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)442 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)443 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)444--- PASS: TestStreamPushBatchesUnderLoad (0.20s)445 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)446 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)447--- PASS: TestParsePathInfoJSON (0.23s)448 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)449 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)450 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)451 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)452 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)453--- PASS: TestFilterOversizedClosures (0.07s)454 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)455 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)456 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)457--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.22s)458 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.01s)459 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.01s)460--- PASS: TestPartSizeForNAR (0.53s)461 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)462 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)463 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)464 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)465 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)466 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)467 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)468--- PASS: TestSetClientTLSErrors (0.53s)469 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)470 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)471 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)472 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)473=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot474--- PASS: TestStreamPushStopsOnCancel (0.33s)475 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.13s)476 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.15s)477 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.15s)478 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.16s)479 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.16s)480 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.16s)481--- PASS: TestDumpPathWriterError (0.75s)482--- PASS: TestSetClientTLS (0.26s)483 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)484 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.03s)485 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.23s)486--- PASS: TestStreamPushRequestLine (0.88s)487--- PASS: TestRegisterUploadedObjectReusesConnections (0.68s)488--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.02s)489 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.51s)490 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.70s)491--- PASS: TestDumpPathMatchesNix (0.93s)492--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)493--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.49s)494--- PASS: TestUploadMultipart_PartsInParallel (1.35s)495--- PASS: TestSupersededNARStillUploadsListing (0.03s)496 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.18s)497 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.44s)498 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.17s)499--- PASS: TestTruncatedNARDumpIsNotCompleted (1.70s)500--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (2.00s)501--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.02s)502 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.01s)503 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.32s)504PASS505Running server tests...506The files belonging to this database system will be owned by user "nixbld".507This user must also own the server process.508509The database cluster will be initialized with locale "C".510The default database encoding has accordingly been set to "SQL_ASCII".511The default text search configuration will be set to "english".512513Data page checksums are enabled.514515creating directory /build/postgres171205510/data ... ok516creating subdirectories ... ok517selecting dynamic shared memory implementation ... posix518selecting default "max_connections" ... 100519selecting default "shared_buffers" ... 128MB520selecting default time zone ... UTC521creating configuration files ... ok522running bootstrap script ... ok523performing post-bootstrap initialization ... ok524syncing data to disk ... ok525526initdb: warning: enabling "trust" authentication for local connections527initdb: 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.528529Success. You can now start the database server using:530531 pg_ctl -D /build/postgres171205510/data -l logfile start532533/build/postgres171205510:5432 - no response5342026-09-24 18:05:11.120 UTC [170] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit5352026-09-24 18:05:11.121 UTC [170] LOG: listening on Unix socket "/build/postgres171205510/.s.PGSQL.5432"5362026-09-24 18:05:11.126 UTC [177] LOG: database system was shut down at 2026-09-24 18:05:10 UTC5372026-09-24 18:05:11.130 UTC [170] LOG: database system is ready to accept connections538/build/postgres171205510:5432 - accepting connections539{"timestamp":"2026-09-24T18:05:11.432703626Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"1336a463-35eb-4028-87c0-45f96778f273","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":463,"threadName":"rustfs-worker","threadId":"ThreadId(386)"}540=== RUN TestService_AuthMiddleware541=== PAUSE TestService_AuthMiddleware542=== RUN TestService_AuthMiddleware_MTLSProxyHeader543=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader544=== RUN TestService_AuthMiddleware_MTLSBoundSubjects545=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects546=== RUN TestService_ReadAuthMiddleware547=== PAUSE TestService_ReadAuthMiddleware548=== RUN TestService_AuthMiddleware_OIDC549=== PAUSE TestService_AuthMiddleware_OIDC550=== RUN TestService_RequireScope_OIDC551=== PAUSE TestService_RequireScope_OIDC552=== RUN TestService_ReadScope_PublicByDefault553=== PAUSE TestService_ReadScope_PublicByDefault554=== RUN TestCacheConfigHandler555=== PAUSE TestCacheConfigHandler556=== RUN TestCacheStatsHandler557=== PAUSE TestCacheStatsHandler558=== RUN TestClientCADerivations559=== PAUSE TestClientCADerivations560=== RUN TestClientErrorHandling561=== PAUSE TestClientErrorHandling562=== RUN TestClientIntegration563=== PAUSE TestClientIntegration564=== RUN TestClientMultipleUploads565=== PAUSE TestClientMultipleUploads566=== RUN TestClientWithDependencies567=== PAUSE TestClientWithDependencies568=== RUN TestClientSharedPathCommittedMidPush569=== PAUSE TestClientSharedPathCommittedMidPush570=== RUN TestPinProtectsFromGC571=== PAUSE TestPinProtectsFromGC572=== RUN TestClientPushesUseOnePush573=== PAUSE TestClientPushesUseOnePush574=== RUN TestClientFallsBackToClosures575=== PAUSE TestClientFallsBackToClosures576=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock577=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock578=== RUN TestResolveDBConnectionString579=== PAUSE TestResolveDBConnectionString580=== RUN TestConnectWaitsForAPeerMigration581=== PAUSE TestConnectWaitsForAPeerMigration582=== RUN TestConnectSerialisesConcurrentMigrations583=== PAUSE TestConnectSerialisesConcurrentMigrations584=== RUN TestLeadElectsOneAndHandsOver585=== PAUSE TestLeadElectsOneAndHandsOver586=== RUN TestLeadIncumbentWinsAfterRestart5872026/09/24 18:05:11 INFO lead: acquired remote=192.0.2.1:12345882026/09/24 18:05:12 INFO lead: released remote=192.0.2.1:12345892026/09/24 18:05:12 INFO lead: acquired remote=192.0.2.1:12345902026/09/24 18:05:13 INFO lead: released remote=192.0.2.1:1234591--- PASS: TestLeadIncumbentWinsAfterRestart (2.32s)592=== RUN TestLeadEndsOnShutdown593=== PAUSE TestLeadEndsOnShutdown594=== RUN TestLeadEndsWhenItsConnectionHangs5952026/09/24 18:05:14 INFO lead: acquired remote=192.0.2.1:12345962026-09-24 18:05:15.208 UTC [621] FATAL: terminating connection due to administrator command5972026/09/24 18:05:15 INFO lead: acquired remote=192.0.2.1:12345982026/09/24 18:05:16 WARN lead: lock connection lost error="timeout: context deadline exceeded"5992026/09/24 18:05:16 INFO lead: released remote=192.0.2.1:12346002026/09/24 18:05:16 INFO lead: released remote=192.0.2.1:1234601--- PASS: TestLeadEndsWhenItsConnectionHangs (2.77s)602=== RUN TestGCAdvisoryLockBlocksConcurrentRun603=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun604=== RUN TestGCBugBareHashReferences605=== PAUSE TestGCBugBareHashReferences606=== RUN TestGCMetrics607=== PAUSE TestGCMetrics608=== RUN TestPushDedupSurvivesConcurrentGC609=== PAUSE TestPushDedupSurvivesConcurrentGC610=== RUN TestDeduplicatedObjectsRecordedAsPending611=== PAUSE TestDeduplicatedObjectsRecordedAsPending612=== RUN TestGCSweepSkipsPendingObjects613=== PAUSE TestGCSweepSkipsPendingObjects614=== RUN TestTombstonedObjectOfferedWithoutWaiting615=== PAUSE TestTombstonedObjectOfferedWithoutWaiting616=== RUN TestGCSweepDeliversEachKeyOnce617=== PAUSE TestGCSweepDeliversEachKeyOnce618=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection619=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection620=== RUN TestForceGCDuringPushOffersSweptObject621=== PAUSE TestForceGCDuringPushOffersSweptObject622=== RUN TestSweepRowDeleteSparesResurrectedObject623=== PAUSE TestSweepRowDeleteSparesResurrectedObject624=== RUN TestSweepSparesObjectReuploadedMidSweep625=== PAUSE TestSweepSparesObjectReuploadedMidSweep626=== RUN TestCommitRacingPendingCleanupKeepsObjects627=== PAUSE TestCommitRacingPendingCleanupKeepsObjects628=== RUN TestGCEndsOnShutdown629=== PAUSE TestGCEndsOnShutdown630=== RUN TestGCTaskStore_StartNew631=== PAUSE TestGCTaskStore_StartNew632=== RUN TestGCTaskStore_DeduplicateSameParams633=== PAUSE TestGCTaskStore_DeduplicateSameParams634=== RUN TestGCTaskStore_ConflictDifferentParams635=== PAUSE TestGCTaskStore_ConflictDifferentParams636=== RUN TestGCTaskStore_GetEmpty637=== PAUSE TestGCTaskStore_GetEmpty638=== RUN TestGCTaskStore_GetReturnsLatest639=== PAUSE TestGCTaskStore_GetReturnsLatest640=== RUN TestGCTaskStore_CompletedAllowsNewTask641=== PAUSE TestGCTaskStore_CompletedAllowsNewTask642=== RUN TestGCTaskStore_PhaseUpdates643=== PAUSE TestGCTaskStore_PhaseUpdates644=== RUN TestGCTaskStore_Fail645=== PAUSE TestGCTaskStore_Fail646=== RUN TestGracefulShutdownDrainsInflight647=== PAUSE TestGracefulShutdownDrainsInflight648=== RUN TestService_healthCheckHandler649=== PAUSE TestService_healthCheckHandler650=== RUN TestService_readinessHandler651=== PAUSE TestService_readinessHandler652=== RUN TestGenerateLandingPage653=== PAUSE TestGenerateLandingPage654=== RUN TestCacheConfigHandlerMaxNarSize655=== PAUSE TestCacheConfigHandlerMaxNarSize656=== RUN TestCreatePendingClosureRejectsOversizedNAR657=== PAUSE TestCreatePendingClosureRejectsOversizedNAR658=== RUN TestNARDeduplicationMetadataUploadBug659=== PAUSE TestNARDeduplicationMetadataUploadBug660=== RUN TestMetricsInventory661=== PAUSE TestMetricsInventory662=== RUN TestService_NativeMTLS663=== PAUSE TestService_NativeMTLS664=== RUN TestServerTLSConfig665=== PAUSE TestServerTLSConfig666=== RUN TestMultipartCleanup667=== PAUSE TestMultipartCleanup668=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded669=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded670=== RUN TestPendingCleanupUsesOneCutoff671=== PAUSE TestPendingCleanupUsesOneCutoff672=== RUN TestPendingClosureFailureTracksEveryUpload673=== PAUSE TestPendingClosureFailureTracksEveryUpload674=== RUN TestPendingClosureFailureAbortsItsUploads675=== PAUSE TestPendingClosureFailureAbortsItsUploads676=== RUN TestObjectStatsTrigger677=== PAUSE TestObjectStatsTrigger678=== RUN TestReconnectLeavesObjectsUnlocked679=== PAUSE TestReconnectLeavesObjectsUnlocked680=== RUN TestValidateS3Concurrency681=== PAUSE TestValidateS3Concurrency682=== RUN TestOrphanedObjectsGC683=== PAUSE TestOrphanedObjectsGC684=== RUN TestOrphanedObjectsGCStressTest685=== PAUSE TestOrphanedObjectsGCStressTest686=== RUN TestResurrectedObjectNotDeleted687=== PAUSE TestResurrectedObjectNotDeleted688=== RUN TestSweepKeepsTombstoneWhenDeleteOutcomeUnknown689=== PAUSE TestSweepKeepsTombstoneWhenDeleteOutcomeUnknown690=== RUN TestCreatePin_ReservedPins691=== PAUSE TestCreatePin_ReservedPins692=== RUN TestConcurrentPinUpdatesAgree693=== PAUSE TestConcurrentPinUpdatesAgree694=== RUN TestCreatePinRejectsBadInput695=== PAUSE TestCreatePinRejectsBadInput696=== RUN TestDeletePinKeepsRowWhenS3Fails697=== PAUSE TestDeletePinKeepsRowWhenS3Fails698=== RUN TestPresentReportsOnlyClosureRoots699=== PAUSE TestPresentReportsOnlyClosureRoots700=== RUN TestPresentNotReportedWhileGCDeletesClosure701=== PAUSE TestPresentNotReportedWhileGCDeletesClosure702=== RUN TestParseSingleRange703=== PAUSE TestParseSingleRange704=== RUN TestProxyHeadersOnlyTrustedOnSocket705=== PAUSE TestProxyHeadersOnlyTrustedOnSocket706=== RUN TestIsValidCachePath707=== PAUSE TestIsValidCachePath708=== RUN TestReadProxyNarinfo709=== PAUSE TestReadProxyNarinfo710=== RUN TestReadProxyNarinfoAlreadyDecompressed711=== PAUSE TestReadProxyNarinfoAlreadyDecompressed712=== RUN TestReadProxyNarStreaming713=== PAUSE TestReadProxyNarStreaming714=== RUN TestReadProxy404715=== PAUSE TestReadProxy404716=== RUN TestReadProxyInvalidPath717=== PAUSE TestReadProxyInvalidPath718=== RUN TestReadProxyHead719=== PAUSE TestReadProxyHead720=== RUN TestReadProxyOutlastsServerWriteTimeout721=== PAUSE TestReadProxyOutlastsServerWriteTimeout722=== RUN TestReadProxyConditionalGet723=== PAUSE TestReadProxyConditionalGet724=== RUN TestReadProxyRootRedirectsToIndexHTML725=== PAUSE TestReadProxyRootRedirectsToIndexHTML726=== RUN TestReadProxyDisabled727=== PAUSE TestReadProxyDisabled728=== RUN TestReadRedirectNar729=== PAUSE TestReadRedirectNar730=== RUN TestReadRedirectKeepsNarinfoProxied731=== PAUSE TestReadRedirectKeepsNarinfoProxied732=== RUN TestReadProxyRangeRequest733=== PAUSE TestReadProxyRangeRequest734=== RUN TestReadRedirectUsesPublicS3URL735=== PAUSE TestReadRedirectUsesPublicS3URL736=== RUN TestPush_OverlappingRootsStoreOneRowPerKey737=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey738=== RUN TestPush_CompleteCommitsEveryRoot739=== PAUSE TestPush_CompleteCommitsEveryRoot740=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit741=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit742=== RUN TestPush_RejectsBadRequests743=== PAUSE TestPush_RejectsBadRequests744=== RUN TestPush_SignsNarinfosOfItsPendingObjects745=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects746=== RUN TestRedundantMultipartUpload747=== PAUSE TestRedundantMultipartUpload748=== RUN TestCompleteMultipartUpload_ErrorButObjectExists749=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists750=== RUN TestCompletedNarNotReofferedAcrossClosures751=== PAUSE TestCompletedNarNotReofferedAcrossClosures752=== RUN TestPresignedUploadRegisteredBeforeCommit753=== PAUSE TestPresignedUploadRegisteredBeforeCommit754=== RUN TestService_Rustfstest755=== PAUSE TestService_Rustfstest756=== RUN TestParseSize757=== PAUSE TestParseSize758=== RUN TestSkippedUploadsHandler759=== PAUSE TestSkippedUploadsHandler760=== RUN TestSystemdListenerNotActivated761--- PASS: TestSystemdListenerNotActivated (0.00s)762=== RUN TestWatchdogBeatsWhenHealthy763--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)764=== RUN TestWatchdogSkipsWhenUnhealthy7652026/09/24 18:05:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7662026/09/24 18:05:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7672026/09/24 18:05:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7682026/09/24 18:05:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/09/24 18:05:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/09/24 18:05:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/09/24 18:05:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/09/24 18:05:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/09/24 18:05:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/09/24 18:05:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"775--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)776=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle777=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle778=== RUN TestProxyWriteTimeout779=== PAUSE TestProxyWriteTimeout780=== RUN TestPendingClosureWriteTimeout781=== PAUSE TestPendingClosureWriteTimeout782=== RUN TestIsValidUploadKey783=== PAUSE TestIsValidUploadKey784=== RUN TestUploadHandlersRejectInvalidKeys785=== PAUSE TestUploadHandlersRejectInvalidKeys786=== RUN TestUploadHandlersRejectOversizedBody787=== PAUSE TestUploadHandlersRejectOversizedBody788=== RUN TestService_cleanupPendingClosuresHandler789=== PAUSE TestService_cleanupPendingClosuresHandler790=== RUN TestService_createPendingClosureHandler791=== PAUSE TestService_createPendingClosureHandler792=== RUN TestService_verifyS3Integrity793=== PAUSE TestService_verifyS3Integrity794=== RUN TestCompleteMultipartUnregistered795=== PAUSE TestCompleteMultipartUnregistered796=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT797=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT798=== CONT TestService_AuthMiddleware_MTLSProxyHeader799=== CONT TestSkippedUploadsHandler800=== CONT TestReadProxyNarinfoAlreadyDecompressed801=== CONT TestGCTaskStore_DeduplicateSameParams802=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT803=== CONT TestCompleteMultipartUnregistered804=== CONT TestService_verifyS3Integrity805=== CONT TestService_createPendingClosureHandler806=== CONT TestService_cleanupPendingClosuresHandler807=== CONT TestUploadHandlersRejectOversizedBody808=== CONT TestUploadHandlersRejectInvalidKeys809=== CONT TestPendingClosureWriteTimeout810=== CONT TestProxyWriteTimeout811=== CONT TestIsValidUploadKey812=== CONT TestReadProxyNarinfo813=== CONT TestReadProxyNarStreaming814=== CONT TestIsValidCachePath815=== RUN TestIsValidCachePath/narinfo816=== PAUSE TestIsValidCachePath/narinfo817=== CONT TestParseSingleRange818=== CONT TestProxyHeadersOnlyTrustedOnSocket819=== CONT TestPresentReportsOnlyClosureRoots820=== CONT TestPresentNotReportedWhileGCDeletesClosure821=== CONT TestDeletePinKeepsRowWhenS3Fails822=== CONT TestConcurrentPinUpdatesAgree823=== CONT TestCreatePinRejectsBadInput824--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)825=== CONT TestCreatePin_ReservedPins826=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info827=== RUN TestIsValidUploadKey/narinfo828=== RUN TestProxyWriteTimeout/narinfo829=== RUN TestPendingClosureWriteTimeout/empty830=== RUN TestParseSingleRange/none831=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars832=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info833=== PAUSE TestProxyWriteTimeout/narinfo834=== RUN TestProxyWriteTimeout/1_GiB_nar8352026/09/24 18:05:16 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000836=== PAUSE TestProxyWriteTimeout/1_GiB_nar837=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars838=== RUN TestProxyWriteTimeout/10_GiB_nar839=== RUN TestIsValidCachePath/nar_zst840=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal841=== PAUSE TestParseSingleRange/none842=== PAUSE TestPendingClosureWriteTimeout/empty843=== PAUSE TestIsValidUploadKey/narinfo844=== PAUSE TestProxyWriteTimeout/10_GiB_nar845=== PAUSE TestIsValidCachePath/nar_zst846=== RUN TestParseSingleRange/unknown_unit847=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal848=== RUN TestPendingClosureWriteTimeout/negative849=== RUN TestIsValidUploadKey/nar_zst850=== PAUSE TestPendingClosureWriteTimeout/negative851=== PAUSE TestIsValidUploadKey/nar_zst852=== RUN TestProxyWriteTimeout/unknown_size853=== RUN TestIsValidCachePath/nar_xz854=== PAUSE TestParseSingleRange/unknown_unit855=== PAUSE TestIsValidCachePath/nar_xz856=== RUN TestParseSingleRange/multi-range_ignored857=== PAUSE TestParseSingleRange/multi-range_ignored858=== RUN TestPendingClosureWriteTimeout/400_objects859=== RUN TestIsValidUploadKey/nar_xz860=== PAUSE TestProxyWriteTimeout/unknown_size861=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key862=== PAUSE TestIsValidUploadKey/nar_xz863=== RUN TestIsValidCachePath/nar_bz2864=== RUN TestParseSingleRange/malformed_no_dash865=== PAUSE TestPendingClosureWriteTimeout/400_objects866=== RUN TestPendingClosureWriteTimeout/670k_objects867=== PAUSE TestPendingClosureWriteTimeout/670k_objects868=== CONT TestSweepKeepsTombstoneWhenDeleteOutcomeUnknown869=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline870=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key871=== RUN TestIsValidUploadKey/nar_plain872=== PAUSE TestIsValidCachePath/nar_bz2873=== PAUSE TestParseSingleRange/malformed_no_dash874=== RUN TestIsValidCachePath/nar_uncompressed875=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline876=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key877=== PAUSE TestIsValidUploadKey/nar_plain878=== RUN TestParseSingleRange/malformed_both_empty879=== PAUSE TestIsValidCachePath/nar_uncompressed880=== RUN TestIsValidCachePath/ls881=== CONT TestNARDeduplicationMetadataUploadBug882=== PAUSE TestIsValidCachePath/ls883=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key884=== RUN TestIsValidUploadKey/listing885=== CONT TestMetricsInventory886=== PAUSE TestParseSingleRange/malformed_both_empty887=== RUN TestIsValidCachePath/log888=== PAUSE TestIsValidUploadKey/listing889=== PAUSE TestIsValidCachePath/log890=== RUN TestIsValidUploadKey/build_log891=== RUN TestIsValidCachePath/realisation892=== RUN TestParseSingleRange/malformed_end_before_start893=== PAUSE TestIsValidUploadKey/build_log894=== PAUSE TestIsValidCachePath/realisation895=== PAUSE TestParseSingleRange/malformed_end_before_start896=== RUN TestIsValidUploadKey/build_log_home-manager_file897=== PAUSE TestIsValidUploadKey/build_log_home-manager_file898=== RUN TestIsValidCachePath/nix-cache-info899=== RUN TestParseSingleRange/closed900=== PAUSE TestIsValidCachePath/nix-cache-info901=== RUN TestIsValidUploadKey/build_log_plus_in_name902=== PAUSE TestParseSingleRange/closed903=== PAUSE TestIsValidUploadKey/build_log_plus_in_name904=== RUN TestParseSingleRange/open-ended905=== RUN TestIsValidCachePath/index.html906=== RUN TestIsValidUploadKey/build_log_question_mark907=== PAUSE TestParseSingleRange/open-ended908=== PAUSE TestIsValidCachePath/index.html909=== PAUSE TestIsValidUploadKey/build_log_question_mark910=== RUN TestParseSingleRange/end_clamped_to_size911=== RUN TestIsValidUploadKey/build_log_equals912=== RUN TestIsValidCachePath/traversal_parent913=== PAUSE TestIsValidUploadKey/build_log_equals914=== PAUSE TestParseSingleRange/end_clamped_to_size915=== PAUSE TestIsValidCachePath/traversal_parent916=== RUN TestIsValidUploadKey/realisation917=== RUN TestParseSingleRange/suffix918=== PAUSE TestIsValidUploadKey/realisation919=== RUN TestIsValidCachePath/traversal_in_middle920=== PAUSE TestParseSingleRange/suffix921=== PAUSE TestIsValidCachePath/traversal_in_middle922=== RUN TestIsValidUploadKey/realisation_plus_in_output923=== RUN TestParseSingleRange/suffix_exceeds_size924=== PAUSE TestIsValidUploadKey/realisation_plus_in_output925=== RUN TestIsValidCachePath/invalid_char_e926=== PAUSE TestIsValidCachePath/invalid_char_e927=== RUN TestIsValidCachePath/invalid_char_u928=== PAUSE TestIsValidCachePath/invalid_char_u929=== PAUSE TestParseSingleRange/suffix_exceeds_size930=== RUN TestIsValidUploadKey/nix-cache-info931=== RUN TestIsValidCachePath/random_path932=== PAUSE TestIsValidUploadKey/nix-cache-info933=== RUN TestParseSingleRange/single_byte934=== PAUSE TestIsValidCachePath/random_path935=== RUN TestIsValidUploadKey/index.html936=== PAUSE TestIsValidUploadKey/index.html937=== PAUSE TestParseSingleRange/single_byte938=== RUN TestIsValidCachePath/empty939=== RUN TestIsValidUploadKey/narinfo_key,_nar_type940=== RUN TestParseSingleRange/start_past_EOF941=== PAUSE TestIsValidCachePath/empty942=== RUN TestIsValidCachePath/leading_slash943=== PAUSE TestIsValidCachePath/leading_slash944=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type945=== PAUSE TestParseSingleRange/start_past_EOF946=== RUN TestIsValidCachePath/wrong_extension947=== RUN TestIsValidUploadKey/nar_key,_narinfo_type948=== RUN TestParseSingleRange/start_far_past_EOF949=== PAUSE TestParseSingleRange/start_far_past_EOF950=== PAUSE TestIsValidCachePath/wrong_extension951=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type952=== CONT TestCacheConfigHandlerMaxNarSize953=== RUN TestIsValidUploadKey/listing_key,_narinfo_type954=== RUN TestIsValidCachePath/short_hash955=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type956=== PAUSE TestIsValidCachePath/short_hash957=== RUN TestIsValidUploadKey/traversal958=== CONT TestService_readinessHandler959=== PAUSE TestIsValidUploadKey/traversal960=== CONT TestGenerateLandingPage961--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)962=== RUN TestIsValidUploadKey/traversal_nar963=== PAUSE TestIsValidUploadKey/traversal_nar964=== RUN TestIsValidUploadKey/absolute965=== PAUSE TestIsValidUploadKey/absolute966=== RUN TestIsValidUploadKey/empty_key967=== PAUSE TestIsValidUploadKey/empty_key968=== RUN TestIsValidUploadKey/unknown_type969=== PAUSE TestIsValidUploadKey/unknown_type970=== CONT TestService_healthCheckHandler971=== CONT TestMultipartCleanup972--- PASS: TestGenerateLandingPage (0.01s)973--- PASS: TestSkippedUploadsHandler (0.04s)974=== CONT TestGracefulShutdownDrainsInflight9752026/09/24 18:05:16 INFO Starting HTTP server address=127.0.0.1:416799762026/09/24 18:05:16 INFO Shutdown signal received, draining in-flight requests timeout=10s9772026/09/24 18:05:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44515/oidc978--- PASS: TestGracefulShutdownDrainsInflight (0.07s)979=== CONT TestResurrectedObjectNotDeleted980=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure981=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure982=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart983=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart984=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts985=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts986=== CONT TestGCTaskStore_CompletedAllowsNewTask987--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)988=== CONT TestOrphanedObjectsGCStressTest9892026/09/24 18:05:17 INFO Received uploads request method=POST path=/api/pending_closures9902026/09/24 18:05:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9912026/09/24 18:05:17 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst992--- PASS: TestCompleteMultipartUnregistered (0.60s)993=== CONT TestGCTaskStore_GetReturnsLatest994--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)995=== CONT TestValidateS3Concurrency996--- PASS: TestValidateS3Concurrency (0.00s)997=== CONT TestGCTaskStore_PhaseUpdates998--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)999=== CONT TestReconnectLeavesObjectsUnlocked1000=== CONT TestGCTaskStore_ConflictDifferentParams1001=== CONT TestObjectStatsTrigger1002--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.64s)1003--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)10042026/09/24 18:05:17 INFO Received uploads request method=POST path=/api/pending_closures1005--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.68s)1006=== CONT TestPush_OverlappingRootsStoreOneRowPerKey10072026/09/24 18:05:17 INFO Received cleanup request method=DELETE path=/api/pending_closures10082026/09/24 18:05:17 INFO Aborted multipart uploads count=0 kept=010092026/09/24 18:05:17 INFO Received uploads request method=POST path=/api/pending_closures1010=== CONT TestPendingClosureFailureAbortsItsUploads1011--- PASS: TestReadProxyNarStreaming (0.70s)10122026/09/24 18:05:17 INFO Received cleanup request method=DELETE path=/api/pending_closures10132026/09/24 18:05:17 INFO Aborted multipart uploads count=1 kept=010142026/09/24 18:05:17 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10152026/09/24 18:05:17 WARN Refused reserved pin name=worker-x86_64-linux10162026/09/24 18:05:17 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10172026/09/24 18:05:17 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10182026-09-24 18:05:17.601 UTC [701] ERROR: Closure does not exist: id=110192026-09-24 18:05:17.601 UTC [701] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 19 at RAISE10202026-09-24 18:05:17.601 UTC [701] STATEMENT: -- name: CommitPendingClosure :exec1021 SELECT commit_pending_closure($1::bigint)1022 10232026/09/24 18:05:17 INFO Received create pin request method=POST path=/api/pins/my-app10242026/09/24 18:05:17 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1025=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1026--- PASS: TestService_cleanupPendingClosuresHandler (0.75s)1027--- PASS: TestCreatePin_ReservedPins (0.75s)1028=== CONT TestPendingClosureFailureTracksEveryUpload1029--- PASS: TestService_healthCheckHandler (0.75s)1030=== CONT TestParseSize1031--- PASS: TestParseSize (0.00s)1032=== CONT TestPendingCleanupUsesOneCutoff10332026/09/24 18:05:17 INFO Received create pin request method=POST path=/api/pins/app1034--- PASS: TestPresentReportsOnlyClosureRoots (0.85s)1035=== CONT TestPresignedUploadRegisteredBeforeCommit10362026/09/24 18:05:17 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo10372026/09/24 18:05:17 INFO Received delete pin request method=DELETE path=/api/pins/app10382026/09/24 18:05:17 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket13/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"10392026/09/24 18:05:17 INFO Received delete pin request method=DELETE path=/api/pins/app10402026/09/24 18:05:17 INFO Deleted pin name=app10412026/09/24 18:05:17 INFO Received create pin request method=POST path=/api/pins/app10422026/09/24 18:05:17 INFO Received create pin request method=POST path=/api/pins/app1043=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1044--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.90s)10452026/09/24 18:05:17 INFO Received uploads request method=POST path=/api/pending_closures10462026/09/24 18:05:17 INFO Received uploads request method=POST path=/api/pending_closures10472026/09/24 18:05:17 INFO Received uploads request method=POST path=/api/pending_closures10482026/09/24 18:05:17 INFO Received uploads request method=POST path=/api/pending_closures10492026/09/24 18:05:17 WARN readiness check failed error="closed pool"1050--- PASS: TestService_readinessHandler (0.96s)1051=== CONT TestService_Rustfstest10522026/09/24 18:05:17 INFO Received cleanup request method=DELETE path=/api/pending_closures10532026/09/24 18:05:17 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket16/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10542026/09/24 18:05:17 INFO Aborted multipart uploads count=0 kept=110552026/09/24 18:05:17 INFO Received cleanup request method=DELETE path=/api/pending_closures10562026/09/24 18:05:17 INFO Received create pin request method=POST path=/api/pins/deploy10572026/09/24 18:05:17 INFO Received create pin request method=POST path=/api/pins/deploy10582026/09/24 18:05:17 INFO Received create pin request method=POST path=/api/pins/deploy10592026/09/24 18:05:17 INFO Received create pin request method=POST path=/api/pins/deploy10602026/09/24 18:05:17 INFO Received create pin request method=POST path=/api/pins/deploy10612026/09/24 18:05:17 INFO Received create pin request method=POST path=/api/pins/deploy10622026/09/24 18:05:17 INFO Received create pin request method=POST path=/api/pins/deploy10632026/09/24 18:05:17 INFO Received create pin request method=POST path=/api/pins/deploy10642026/09/24 18:05:17 INFO Aborted multipart uploads count=1 kept=01065--- PASS: TestMultipartCleanup (1.09s)1066=== CONT TestOrphanedObjectsGC1067--- PASS: TestResurrectedObjectNotDeleted (1.02s)1068=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1069--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.13s)1070=== CONT TestServerTLSConfig1071=== RUN TestServerTLSConfig/no_client_CA1072=== PAUSE TestServerTLSConfig/no_client_CA1073=== RUN TestServerTLSConfig/missing_CA_file1074=== PAUSE TestServerTLSConfig/missing_CA_file1075=== RUN TestServerTLSConfig/not_a_PEM_file1076=== PAUSE TestServerTLSConfig/not_a_PEM_file1077=== CONT TestRedundantMultipartUpload1078=== CONT TestService_NativeMTLS1079--- PASS: TestMetricsInventory (1.12s)10802026/09/24 18:05:18 INFO Received create pin request method=POST path=/api/pins/deploy10812026/09/24 18:05:18 INFO Starting HTTP server address=127.0.0.1:3920110822026/09/24 18:05:18 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket3768816681/001/proxy.sock10832026/09/24 18:05:18 WARN mTLS auth: subject not in bound subjects subject="CN=someone"10842026/09/24 18:05:18 INFO Shutdown signal received, draining in-flight requests timeout=10s1085=== NAME TestNARDeduplicationMetadataUploadBug1086 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2554976049/001/store/l7nj22p5g238v3vkgc78aanra14na5ms-file1.txt10872026/09/24 18:05:18 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"1088--- PASS: TestProxyHeadersOnlyTrustedOnSocket (1.20s)1089=== CONT TestCompletedNarNotReofferedAcrossClosures10902026/09/24 18:05:18 INFO Aborted multipart uploads count=0 kept=010912026/09/24 18:05:18 WARN Force mode enabled - objects will be deleted immediately without grace period10922026/09/24 18:05:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10932026/09/24 18:05:18 INFO Received push request method=POST path=/api/pushes10942026/09/24 18:05:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10952026/09/24 18:05:18 INFO Uploading l7nj22p5g238v3vkgc78aanra14na5ms-file1.txt (160B)10962026/09/24 18:05:18 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NWYyN2U0NDUtMTMyNi00NGMzLWI1ZDktNmUyMmViMzY1OTJiLmZiZThmYmJiLTczYzEtNDI0ZS04NTczLTBmMWMxODBhZmY5NngxNzkwMjczMTE3NDYzMTEyODIw parts=1010972026/09/24 18:05:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10982026/09/24 18:05:18 INFO Completed upload id=110992026/09/24 18:05:18 ERROR failed to remove object object=nar/nnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnn.nar.zst error="We encountered an internal error."11002026/09/24 18:05:18 INFO Received uploads request method=POST path=/api/pending_closures11012026/09/24 18:05:18 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11022026/09/24 18:05:18 INFO Received uploads request method=POST path=/api/pending_closures1103--- PASS: TestReconnectLeavesObjectsUnlocked (0.70s)1104=== CONT TestGCTaskStore_Fail1105--- PASS: TestGCTaskStore_Fail (0.00s)1106=== CONT TestPush_SignsNarinfosOfItsPendingObjects11072026/09/24 18:05:18 INFO Received uploads request method=POST path=/api/pending_closures11082026/09/24 18:05:18 WARN Failed to register uploaded object key=l7nj22p5g238v3vkgc78aanra14na5ms.ls error="server returned 404: 404 page not found\n"11092026/09/24 18:05:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11102026/09/24 18:05:18 INFO Aborted multipart uploads count=0 kept=011112026/09/24 18:05:18 INFO Received push request method=POST path=/api/pushes11122026/09/24 18:05:18 INFO Signed narinfos id=1 count=111132026/09/24 18:05:18 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11142026/09/24 18:05:18 WARN Found objects in DB but missing from S3, will re-upload count=111152026/09/24 18:05:18 INFO Uploading 1 narinfos11162026/09/24 18:05:18 WARN Force mode enabled - objects will be deleted immediately without grace period11172026/09/24 18:05:18 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete1118--- PASS: TestObjectStatsTrigger (0.68s)1119=== CONT TestCreatePendingClosureRejectsOversizedNAR11202026/09/24 18:05:18 INFO Received uploads request method=POST path=/api/pending_closures11212026/09/24 18:05:18 INFO Completed upload id=31122--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1123=== CONT TestPush_CompleteCommitsEveryRoot11242026/09/24 18:05:18 INFO Garbage collection completed failed-uploads-deleted=1 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=2 objects-failed-to-delete=011252026/09/24 18:05:18 INFO Received complete push request method=POST path=/api/pushes/1/complete11262026/09/24 18:05:18 WARN Failed to register uploaded object key=l7nj22p5g238v3vkgc78aanra14na5ms.narinfo error="server returned 404: 404 page not found\n"11272026/09/24 18:05:18 INFO Vacuumed table table=pending_closures11282026/09/24 18:05:18 INFO Vacuumed table table=pending_objects11292026/09/24 18:05:18 INFO Vacuumed table table=multipart_uploads11302026/09/24 18:05:18 INFO Vacuumed table table=closures1131--- PASS: TestService_verifyS3Integrity (1.34s)1132=== CONT TestPush_RejectsBadRequests11332026/09/24 18:05:18 INFO Received uploads request method=POST path=/api/pending_closures11342026/09/24 18:05:18 INFO Upload complete. (120ms)1135=== NAME TestNARDeduplicationMetadataUploadBug1136 metadata_upload_test.go:54: Retrieved narinfo from S3:1137 StorePath: /build/TestNARDeduplicationMetadataUploadBug2554976049/001/store/l7nj22p5g238v3vkgc78aanra14na5ms-file1.txt1138 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1139 Compression: zstd1140 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1141 NarSize: 1601142 References: 1143 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf11442026/09/24 18:05:18 INFO Vacuumed table table=objects1145 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1146 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1147 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1148=== CONT TestReadProxyRootRedirectsToIndexHTML1149--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.68s)11502026/09/24 18:05:18 INFO Received uploads request method=POST path=/api/pending_closures1151=== CONT TestReadRedirectUsesPublicS3URL1152--- PASS: TestSweepKeepsTombstoneWhenDeleteOutcomeUnknown (1.36s)1153=== NAME TestNARDeduplicationMetadataUploadBug1154 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2554976049/001/store/b5r39gr65c2klwxjrkcdghc5inzjh529-file2.txt1155--- PASS: TestPendingClosureFailureAbortsItsUploads (0.70s)11562026/09/24 18:05:18 INFO Received uploads request method=POST path=/api/pending_closures1157=== CONT TestReadProxyHead11582026/09/24 18:05:18 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo11592026/09/24 18:05:18 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo11602026/09/24 18:05:18 INFO Received uploads request method=POST path=/api/pending_closures1161--- PASS: TestConcurrentPinUpdatesAgree (1.44s)1162=== CONT TestReadRedirectKeepsNarinfoProxied11632026/09/24 18:05:18 INFO Received uploads request method=POST path=/api/pending_closures11642026/09/24 18:05:18 INFO Received push request method=POST path=/api/pushes11652026/09/24 18:05:18 INFO Received uploads request method=POST path=/api/pending_closures11662026/09/24 18:05:18 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11672026/09/24 18:05:18 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11682026/09/24 18:05:18 WARN Failed to register uploaded object key=b5r39gr65c2klwxjrkcdghc5inzjh529.ls error="server returned 404: 404 page not found\n"11692026/09/24 18:05:18 INFO Signed narinfos id=2 count=111702026/09/24 18:05:18 INFO Uploading 1 narinfos11712026/09/24 18:05:18 INFO Received cleanup request method=DELETE path=/api/pending_closures11722026/09/24 18:05:18 INFO Received uploads request method=POST path=/api/pending_closures11732026/09/24 18:05:18 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11742026/09/24 18:05:18 INFO Received uploads request method=POST path=/api/pending_closures11752026/09/24 18:05:18 INFO Received complete push request method=POST path=/api/pushes/2/complete11762026/09/24 18:05:18 INFO Upload complete. (99ms)1177=== NAME TestNARDeduplicationMetadataUploadBug1178 metadata_upload_test.go:76: Retrieved narinfo from S3:1179 StorePath: /build/TestNARDeduplicationMetadataUploadBug2554976049/001/store/b5r39gr65c2klwxjrkcdghc5inzjh529-file2.txt1180 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1181 Compression: zstd1182 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1183 NarSize: 1601184 References: 1185 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf11862026/09/24 18:05:18 WARN Failed to register uploaded object key=b5r39gr65c2klwxjrkcdghc5inzjh529.narinfo error="server returned 404: 404 page not found\n"1187 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1188 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1189 {"version":1,"root":{"type":"regular","size":44}}11902026/09/24 18:05:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1191=== CONT TestReadProxyConditionalGet1192--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.73s)1193--- PASS: TestService_Rustfstest (0.60s)1194=== CONT TestReadRedirectNar1195=== CONT TestReadProxyOutlastsServerWriteTimeout1196--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.69s)1197=== CONT TestReadProxyRangeRequest1198--- PASS: TestNARDeduplicationMetadataUploadBug (1.59s)11992026/09/24 18:05:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12002026/09/24 18:05:18 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NWYyN2U0NDUtMTMyNi00NGMzLWI1ZDktNmUyMmViMzY1OTJiLjMzYjUzMGRmLWIzMmUtNDAwNS1hMDZmLWY0YjkyNDgxODQyM3gxNzkwMjczMTE3NzkxMDU1NzYw parts=1012012026/09/24 18:05:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12022026/09/24 18:05:18 INFO Received uploads request method=POST path=/api/pending_closures12032026/09/24 18:05:18 INFO Completed upload id=112042026/09/24 18:05:18 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012052026/09/24 18:05:18 INFO Received uploads request method=POST path=/api/pending_closures12062026/09/24 18:05:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures12072026/09/24 18:05:18 INFO Received uploads request method=POST path=/api/pending_closures12082026/09/24 18:05:18 INFO Aborted multipart uploads count=0 kept=012092026/09/24 18:05:18 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=012102026/09/24 18:05:18 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=1677721612112026/09/24 18:05:18 INFO Vacuumed table table=pending_closures12122026/09/24 18:05:18 INFO Vacuumed table table=pending_objects12132026/09/24 18:05:18 INFO Vacuumed table table=multipart_uploads12142026/09/24 18:05:18 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12152026/09/24 18:05:18 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12162026/09/24 18:05:18 INFO Vacuumed table table=closures12172026/09/24 18:05:18 INFO Received uploads request method=POST path=/api/pending_closures12182026/09/24 18:05:18 INFO Vacuumed table table=objects12192026/09/24 18:05:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1220--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.75s)1221=== CONT TestReadProxyDisabled1222--- PASS: TestReadProxyNarinfo (1.76s)1223=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit12242026/09/24 18:05:18 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NWYyN2U0NDUtMTMyNi00NGMzLWI1ZDktNmUyMmViMzY1OTJiLmE5YjFkZjU0LThhZjMtNGMxZi1hZmY5LWI1YmM1NjBhNzA2YXgxNzkwMjczMTE4NTUwMTYwMDY01225=== CONT TestReadProxy4041226--- PASS: TestService_NativeMTLS (0.64s)12272026/09/24 18:05:18 INFO Received uploads request method=POST path=/api/pending_closures12282026/09/24 18:05:18 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012292026/09/24 18:05:18 INFO Received push request method=POST path=/api/pushes1230--- PASS: TestService_createPendingClosureHandler (1.82s)1231=== CONT TestGCTaskStore_StartNew1232=== CONT TestReadProxyInvalidPath1233--- PASS: TestGCTaskStore_StartNew (0.00s)12342026/09/24 18:05:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12352026/09/24 18:05:18 INFO Signed narinfos id=1 count=112362026/09/24 18:05:18 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NWYyN2U0NDUtMTMyNi00NGMzLWI1ZDktNmUyMmViMzY1OTJiLmE5YjFkZjU0LThhZjMtNGMxZi1hZmY5LWI1YmM1NjBhNzA2YXgxNzkwMjczMTE4NTUwMTYwMDY0 error="Delete \"http://localhost:45357/bucket38/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=NWYyN2U0NDUtMTMyNi00NGMzLWI1ZDktNmUyMmViMzY1OTJiLmE5YjFkZjU0LThhZjMtNGMxZi1hZmY5LWI1YmM1NjBhNzA2YXgxNzkwMjczMTE4NTUwMTYwMDY0\": injected: abort refused"12372026/09/24 18:05:18 INFO Received push request method=POST path=/api/pushes12382026/09/24 18:05:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12392026/09/24 18:05:18 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NWYyN2U0NDUtMTMyNi00NGMzLWI1ZDktNmUyMmViMzY1OTJiLmE5YjFkZjU0LThhZjMtNGMxZi1hZmY5LWI1YmM1NjBhNzA2YXgxNzkwMjczMTE4NTUwMTYwMDY01240--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.57s)1241=== CONT TestPushDedupSurvivesConcurrentGC1242=== RUN TestPush_RejectsBadRequests/no_roots1243=== PAUSE TestPush_RejectsBadRequests/no_roots1244=== RUN TestPush_RejectsBadRequests/no_objects1245=== PAUSE TestPush_RejectsBadRequests/no_objects1246=== RUN TestPush_RejectsBadRequests/bad_root1247=== PAUSE TestPush_RejectsBadRequests/bad_root1248=== RUN TestPush_RejectsBadRequests/root_not_in_objects1249=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1250=== CONT TestSweepSparesObjectReuploadedMidSweep12512026/09/24 18:05:18 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NWYyN2U0NDUtMTMyNi00NGMzLWI1ZDktNmUyMmViMzY1OTJiLmE5YjFkZjU0LThhZjMtNGMxZi1hZmY5LWI1YmM1NjBhNzA2YXgxNzkwMjczMTE4NTUwMTYwMDY0 parts=11252--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.80s)1253=== CONT TestGCMetrics1254--- PASS: TestPendingClosureFailureTracksEveryUpload (1.17s)1255=== CONT TestTombstonedObjectOfferedWithoutWaiting1256--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.57s)1257=== CONT TestGCAdvisoryLockBlocksConcurrentRun12582026/09/24 18:05:18 INFO Received create pin request method=POST path=/api/pins/deploy12592026/09/24 18:05:18 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo1260=== CONT TestGCBugBareHashReferences1261--- PASS: TestCreatePinRejectsBadInput (2.05s)1262=== NAME TestOrphanedObjectsGC1263 orphaned_objects_gc_test.go:296: GC Test Summary:1264 orphaned_objects_gc_test.go:297: - Kept: 2 objects from closure A1265 orphaned_objects_gc_test.go:298: - Deleted: 2 objects from closure B1266 orphaned_objects_gc_test.go:299: - Deleted: 6 orphaned chain objects (X1->X2->X3)1267 orphaned_objects_gc_test.go:300: - Deleted: 2 orphaned single objects (Y)1268 orphaned_objects_gc_test.go:301: - Total deleted: 10 objects1269=== CONT TestGCTaskStore_GetEmpty1270--- PASS: TestOrphanedObjectsGC (0.96s)1271=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1272--- PASS: TestGCTaskStore_GetEmpty (0.00s)1273--- PASS: TestReadRedirectUsesPublicS3URL (0.75s)1274=== CONT TestCommitRacingPendingCleanupKeepsObjects1275=== CONT TestPinProtectsFromGC1276--- PASS: TestReadRedirectNar (0.55s)1277=== CONT TestDeduplicatedObjectsRecordedAsPending1278--- PASS: TestReadProxyHead (0.78s)1279--- PASS: TestReadProxyRangeRequest (0.60s)1280=== CONT TestClientWithDependencies1281--- PASS: TestReadProxyDisabled (0.44s)1282=== CONT TestService_ReadScope_PublicByDefault1283--- PASS: TestReadRedirectKeepsNarinfoProxied (0.78s)1284=== CONT TestClientErrorHandling1285=== RUN TestClientErrorHandling/InvalidStorePath1286=== PAUSE TestClientErrorHandling/InvalidStorePath1287=== RUN TestClientErrorHandling/InvalidAuthToken1288=== PAUSE TestClientErrorHandling/InvalidAuthToken1289=== RUN TestClientErrorHandling/ServerNotAvailable1290=== PAUSE TestClientErrorHandling/ServerNotAvailable1291=== CONT TestGCEndsOnShutdown12922026/09/24 18:05:19 INFO Received push request method=POST path=/api/pushes1293=== RUN TestGCEndsOnShutdown/before_the_run1294=== PAUSE TestGCEndsOnShutdown/before_the_run1295=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1296=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1297=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1298=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1299=== CONT TestCacheConfigHandler1300=== RUN TestCacheConfigHandler/full_config,_no_issuer1301=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1302=== RUN TestCacheConfigHandler/no_cache_url_configured1303=== PAUSE TestCacheConfigHandler/no_cache_url_configured1304=== RUN TestCacheConfigHandler/no_signing_keys1305=== PAUSE TestCacheConfigHandler/no_signing_keys1306=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1307=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1308=== CONT TestService_RequireScope_OIDC1309=== CONT TestService_AuthMiddleware_OIDC1310--- PASS: TestReadProxyConditionalGet (0.68s)1311--- PASS: TestReadProxyInvalidPath (0.49s)1312=== CONT TestService_AuthMiddleware_MTLSBoundSubjects13132026/09/24 18:05:19 INFO Aborted multipart uploads count=0 kept=013142026/09/24 18:05:19 INFO Received uploads request method=POST path=/api/pending_closures13152026/09/24 18:05:19 INFO Received uploads request method=POST path=/api/pending_closures13162026/09/24 18:05:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35859/oidc13172026/09/24 18:05:19 INFO Received uploads request method=POST path=/api/pending_closures1318--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.52s)1319=== CONT TestService_AuthMiddleware13202026/09/24 18:05:19 INFO Aborted multipart uploads count=0 kept=013212026/09/24 18:05:19 INFO Aborted multipart uploads count=0 kept=013222026/09/24 18:05:19 WARN Force mode enabled - objects will be deleted immediately without grace period13232026/09/24 18:05:19 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=013242026/09/24 18:05:19 INFO Vacuumed table table=pending_closures13252026/09/24 18:05:19 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=013262026/09/24 18:05:19 INFO Vacuumed table table=pending_objects13272026/09/24 18:05:19 INFO Vacuumed table table=multipart_uploads13282026/09/24 18:05:19 INFO Vacuumed table table=closures13292026/09/24 18:05:19 INFO Vacuumed table table=objects13302026/09/24 18:05:19 INFO Vacuumed table table=pending_closures13312026/09/24 18:05:19 INFO Vacuumed table table=pending_objects13322026/09/24 18:05:19 INFO Vacuumed table table=multipart_uploads13332026/09/24 18:05:19 INFO Vacuumed table table=closures13342026/09/24 18:05:19 INFO Vacuumed table table=objects13352026/09/24 18:05:19 INFO Aborted multipart uploads count=0 kept=013362026/09/24 18:05:19 WARN Force mode enabled - objects will be deleted immediately without grace period13372026/09/24 18:05:19 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=013382026/09/24 18:05:19 INFO Vacuumed table table=pending_closures13392026/09/24 18:05:19 INFO Vacuumed table table=pending_objects13402026/09/24 18:05:19 INFO Vacuumed table table=multipart_uploads13412026/09/24 18:05:19 INFO Vacuumed table table=closures13422026/09/24 18:05:19 INFO Vacuumed table table=objects1343--- PASS: TestGCMetrics (0.58s)1344=== CONT TestForceGCDuringPushOffersSweptObject1345=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1346=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1347=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1348=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1349=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1350--- PASS: TestPushDedupSurvivesConcurrentGC (0.65s)1351=== CONT TestGCSweepSkipsPendingObjects13522026/09/24 18:05:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13532026/09/24 18:05:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13542026/09/24 18:05:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13552026/09/24 18:05:19 INFO Aborted multipart uploads count=0 kept=013562026/09/24 18:05:19 WARN Force mode enabled - objects will be deleted immediately without grace period13572026/09/24 18:05:19 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=013582026/09/24 18:05:19 INFO Received uploads request method=POST path=/api/pending_closures13592026/09/24 18:05:19 INFO Vacuumed table table=pending_closures13602026/09/24 18:05:19 INFO Vacuumed table table=pending_objects13612026/09/24 18:05:19 INFO Vacuumed table table=multipart_uploads13622026/09/24 18:05:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36153/oidc13632026/09/24 18:05:19 INFO Vacuumed table table=closures13642026/09/24 18:05:19 INFO Vacuumed table table=objects13652026/09/24 18:05:19 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NWYyN2U0NDUtMTMyNi00NGMzLWI1ZDktNmUyMmViMzY1OTJiLjM1ZjNkZDQ5LTY1OGQtNGQ3NS1iN2M5LWNiMDVlZGM1ODg1N3gxNzkwMjczMTE4NzI5MjI3NjU3 parts=1013662026/09/24 18:05:19 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NWYyN2U0NDUtMTMyNi00NGMzLWI1ZDktNmUyMmViMzY1OTJiLjNhYzI0ZDcyLTQ5M2MtNDM5MC05OGIxLWYyMDQ4ZmMxODg5OHgxNzkwMjczMTE4NjEwNzUyMDc5 parts=1213672026/09/24 18:05:19 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NWYyN2U0NDUtMTMyNi00NGMzLWI1ZDktNmUyMmViMzY1OTJiLmI3NmJlMjUzLTk5ODQtNGVlOC1hMGZiLTRmZmU4NWJjNWJlMHgxNzkwMjczMTE4NjY2NTEyOTYy parts=1213682026/09/24 18:05:19 INFO Received uploads request method=POST path=/api/pending_closures13692026/09/24 18:05:19 INFO Received uploads request method=POST path=/api/pending_closures1370=== CONT TestSweepRowDeleteSparesResurrectedObject1371--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.46s)13722026/09/24 18:05:19 INFO Received uploads request method=POST path=/api/pending_closures1373--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.52s)1374=== CONT TestClientCADerivations1375--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.45s)1376=== CONT TestLeadEndsOnShutdown1377=== NAME TestPinProtectsFromGC1378 client_integration_test.go:867: Pinned store path: /build/TestPinProtectsFromGC2317796160/001/store/llwfp546l76j075kjfzbllmq3rnk6k04-pinned-file.txt1379 client_integration_test.go:868: Unpinned store path: /build/TestPinProtectsFromGC2317796160/001/store/m19iz66nbx0yvl70hj0rahhwrxi3z8fc-unpinned-file.txt1380=== CONT TestClientPushesUseOnePush1381--- PASS: TestService_ReadScope_PublicByDefault (0.48s)13822026/09/24 18:05:19 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"13832026/09/24 18:05:19 WARN mTLS auth: bound subjects configured but subject DN unavailable13842026/09/24 18:05:19 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1385--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.41s)1386=== CONT TestLeadElectsOneAndHandsOver1387=== NAME TestClientWithDependencies1388 client_integration_test.go:735: Built derivation: /build/TestClientWithDependencies2342689798/001/store/7ydly23inw9bjpfb6w80nb2il0qf7jb6-test-script1389=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1390=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1391=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1392=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1393=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1394=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1395=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1396=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1397=== CONT TestClientSharedPathCommittedMidPush13982026/09/24 18:05:19 INFO Received push request method=POST path=/api/pushes13992026/09/24 18:05:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14002026/09/24 18:05:19 INFO Uploading llwfp546l76j075kjfzbllmq3rnk6k04-pinned-file.txt (128B)1401=== NAME TestClientWithDependencies1402 client_integration_test.go:737: Found 1 dependencies (including self)1403--- PASS: TestGCBugBareHashReferences (0.70s)1404=== CONT TestConnectSerialisesConcurrentMigrations14052026/09/24 18:05:19 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"14062026/09/24 18:05:19 WARN Rate limiter enabled after throttle name=s3-test rate=514072026/09/24 18:05:19 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."14082026/09/24 18:05:19 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14092026/09/24 18:05:19 WARN Failed to register uploaded object key=llwfp546l76j075kjfzbllmq3rnk6k04.ls error="server returned 404: 404 page not found\n"14102026/09/24 18:05:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14112026/09/24 18:05:19 INFO Signed narinfos id=1 count=114122026/09/24 18:05:19 INFO Uploading 1 narinfos14132026/09/24 18:05:19 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1414=== CONT TestClientFallsBackToClosures1415--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.87s)14162026/09/24 18:05:19 INFO Received complete push request method=POST path=/api/pushes/1/complete14172026/09/24 18:05:19 WARN Failed to register uploaded object key=llwfp546l76j075kjfzbllmq3rnk6k04.narinfo error="server returned 404: 404 page not found\n"1418=== CONT TestConnectWaitsForAPeerMigration1419--- PASS: TestService_AuthMiddleware (0.36s)14202026/09/24 18:05:19 INFO Upload complete. (117ms)14212026/09/24 18:05:19 WARN Rate limiter backed off name=s3-test rate=514222026/09/24 18:05:19 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."14232026/09/24 18:05:19 INFO Received uploads request method=POST path=/api/pending_closures14242026/09/24 18:05:19 INFO Received push request method=POST path=/api/pushes1425=== CONT TestResolveDBConnectionString1426--- PASS: TestReadProxy404 (1.08s)1427=== RUN TestResolveDBConnectionString/flag_wins1428=== PAUSE TestResolveDBConnectionString/flag_wins1429=== RUN TestResolveDBConnectionString/file_when_flag_empty1430=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1431=== RUN TestResolveDBConnectionString/missing_file_is_an_error1432=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1433=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1434=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1435=== RUN TestResolveDBConnectionString/nothing_configured1436=== PAUSE TestResolveDBConnectionString/nothing_configured1437=== CONT TestClientMultipleUploads14382026/09/24 18:05:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14392026/09/24 18:05:19 INFO Uploading 7ydly23inw9bjpfb6w80nb2il0qf7jb6-test-script (136B)14402026/09/24 18:05:19 INFO Received uploads request method=POST path=/api/pending_closures14412026/09/24 18:05:19 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"14422026/09/24 18:05:19 WARN Failed to register uploaded object key=log/l0f7h1zb9pj7k7a2mfplkv95l18v2wx0-test-script.drv error="server returned 404: 404 page not found\n"14432026/09/24 18:05:19 WARN Failed to register uploaded object key=7ydly23inw9bjpfb6w80nb2il0qf7jb6.ls error="server returned 404: 404 page not found\n"14442026/09/24 18:05:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14452026/09/24 18:05:19 INFO Signed narinfos id=1 count=114462026/09/24 18:05:19 INFO Uploading 1 narinfos14472026/09/24 18:05:19 INFO Aborted multipart uploads count=0 kept=014482026/09/24 18:05:19 WARN Force mode enabled - objects will be deleted immediately without grace period14492026/09/24 18:05:19 INFO Received complete push request method=POST path=/api/pushes/1/complete14502026/09/24 18:05:19 WARN Failed to register uploaded object key=7ydly23inw9bjpfb6w80nb2il0qf7jb6.narinfo error="server returned 404: 404 page not found\n"14512026/09/24 18:05:19 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=014522026/09/24 18:05:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14532026-09-24 18:05:19.770 UTC [1277] ERROR: duplicate key value violates unique constraint "pg_class_relname_nsp_index"14542026-09-24 18:05:19.770 UTC [1277] DETAIL: Key (relname, relnamespace)=(goose_db_version_id_seq, 2200) already exists.14552026-09-24 18:05:19.770 UTC [1277] STATEMENT: CREATE TABLE goose_db_version (1456 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1457 version_id bigint NOT NULL,1458 is_applied boolean NOT NULL,1459 tstamp timestamp NOT NULL DEFAULT now()1460 )14612026/09/24 18:05:19 INFO Vacuumed table table=pending_closures14622026/09/24 18:05:19 INFO Received push request method=POST path=/api/pushes14632026/09/24 18:05:19 INFO Vacuumed table table=pending_objects14642026/09/24 18:05:19 INFO Vacuumed table table=multipart_uploads14652026/09/24 18:05:19 INFO Vacuumed table table=closures14662026/09/24 18:05:19 INFO Upload complete. (107ms)14672026/09/24 18:05:19 INFO Vacuumed table table=objects14682026/09/24 18:05:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14692026/09/24 18:05:19 INFO Uploading m19iz66nbx0yvl70hj0rahhwrxi3z8fc-unpinned-file.txt (128B)1470=== RUN TestService_RequireScope_OIDC/builder_may_write1471=== PAUSE TestService_RequireScope_OIDC/builder_may_write1472=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1473=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1474=== RUN TestService_RequireScope_OIDC/ops_may_admin1475=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1476=== RUN TestService_RequireScope_OIDC/ops_may_not_write1477=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1478=== RUN TestService_RequireScope_OIDC/reader_may_not_write1479=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1480=== RUN TestService_RequireScope_OIDC/static_token_may_admin1481=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1482=== RUN TestService_RequireScope_OIDC/static_token_may_write1483=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1484=== RUN TestService_RequireScope_OIDC/reader_may_read1485=== PAUSE TestService_RequireScope_OIDC/reader_may_read1486=== RUN TestService_RequireScope_OIDC/writer_implies_read1487=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1488=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1489=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1490=== CONT TestCacheStatsHandler14912026/09/24 18:05:19 INFO Aborted multipart uploads count=0 kept=014922026/09/24 18:05:19 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14932026/09/24 18:05:19 WARN Force mode enabled - objects will be deleted immediately without grace period14942026/09/24 18:05:19 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NWYyN2U0NDUtMTMyNi00NGMzLWI1ZDktNmUyMmViMzY1OTJiLjdjNTFjNDZiLWEzODctNDg4Yi1iY2E5LTMxMWYzNTE5ODVjYXgxNzkwMjczMTE5MTAwNzM5MTA3 parts=1014952026/09/24 18:05:19 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=014962026/09/24 18:05:19 WARN Failed to register uploaded object key=m19iz66nbx0yvl70hj0rahhwrxi3z8fc.ls error="server returned 404: 404 page not found\n"14972026/09/24 18:05:19 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14982026/09/24 18:05:19 INFO Signed narinfos id=2 count=114992026/09/24 18:05:19 INFO Uploading 1 narinfos15002026/09/24 18:05:19 INFO Vacuumed table table=pending_closures1501--- PASS: TestGCSweepSkipsPendingObjects (0.42s)1502=== CONT TestClientIntegration15032026/09/24 18:05:19 INFO Received complete push request method=POST path=/api/pushes/2/complete15042026/09/24 18:05:19 INFO Vacuumed table table=pending_objects15052026/09/24 18:05:19 WARN Failed to register uploaded object key=m19iz66nbx0yvl70hj0rahhwrxi3z8fc.narinfo error="server returned 404: 404 page not found\n"15062026/09/24 18:05:19 INFO Vacuumed table table=multipart_uploads15072026/09/24 18:05:19 INFO Upload complete. (93ms)15082026/09/24 18:05:19 INFO Vacuumed table table=closures1509=== CONT TestService_ReadAuthMiddleware1510--- PASS: TestSweepRowDeleteSparesResurrectedObject (0.31s)15112026/09/24 18:05:19 INFO Vacuumed table table=objects1512=== NAME TestClientWithDependencies1513 client_integration_test.go:753: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2342689798/001/store) requires matching store prefix15142026/09/24 18:05:19 INFO lead: acquired remote=192.0.2.1:123415152026/09/24 18:05:19 INFO Starting cleanup of old closures method=DELETE path=/api/closures15162026/09/24 18:05:19 INFO Garbage collection started1517--- PASS: TestClientWithDependencies (0.79s)1518=== CONT TestGCSweepDeliversEachKeyOnce15192026/09/24 18:05:19 INFO Aborted multipart uploads count=0 kept=015202026/09/24 18:05:19 WARN Force mode enabled - objects will be deleted immediately without grace period15212026/09/24 18:05:19 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=015222026/09/24 18:05:19 INFO Vacuumed table table=pending_closures15232026/09/24 18:05:19 INFO Vacuumed table table=pending_objects15242026/09/24 18:05:19 INFO Vacuumed table table=multipart_uploads15252026/09/24 18:05:19 INFO Vacuumed table table=closures15262026/09/24 18:05:19 INFO Vacuumed table table=objects15272026/09/24 18:05:19 INFO lead: acquired remote=192.0.2.1:12341528--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.55s)1529=== CONT TestProxyWriteTimeout/narinfo1530=== CONT TestProxyWriteTimeout/unknown_size1531=== CONT TestProxyWriteTimeout/10_GiB_nar1532=== CONT TestProxyWriteTimeout/1_GiB_nar1533=== CONT TestPendingClosureWriteTimeout/negative1534=== CONT TestPendingClosureWriteTimeout/400_objects1535--- PASS: TestProxyWriteTimeout (0.01s)1536 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1537 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1538 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1539 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1540=== CONT TestPendingClosureWriteTimeout/empty1541=== CONT TestPendingClosureWriteTimeout/670k_objects1542=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1543=== NAME TestClientCADerivations1544 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1636015882/001/store/qwwbr5wvfzw4gvi85rr4dzycy4zxss63-ca-test1545 client_ca_test.go:139: Found 1 dependencies (including self)1546=== NAME TestClientMultipleUploads1547 client_integration_test.go:480: Created store path 0: /build/TestClientMultipleUploads226568981/001/store/4bbl5l6j7ff7hd48fal7ap1pi6lxvrhc-test-file-0.txt1548--- PASS: TestCacheStatsHandler (0.31s)1549=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15502026/09/24 18:05:20 INFO Received uploads request method=POST path=/1551=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15522026/09/24 18:05:20 INFO Received complete multipart upload request method=POST path=/1553=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15542026/09/24 18:05:20 INFO Received uploads request method=POST path=/1555=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15562026/09/24 18:05:20 INFO Received request for more parts method=POST path=/1557--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)1558 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1559 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1560 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1561 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1562=== CONT TestParseSingleRange/multi-range_ignored1563=== CONT TestParseSingleRange/closed1564=== CONT TestParseSingleRange/malformed_end_before_start1565=== CONT TestParseSingleRange/suffix_exceeds_size1566=== CONT TestParseSingleRange/none1567=== CONT TestParseSingleRange/unknown_unit1568=== CONT TestParseSingleRange/suffix1569=== CONT TestParseSingleRange/single_byte1570=== CONT TestParseSingleRange/start_far_past_EOF1571=== CONT TestParseSingleRange/malformed_no_dash1572=== CONT TestParseSingleRange/start_past_EOF1573=== CONT TestParseSingleRange/malformed_both_empty1574=== CONT TestParseSingleRange/open-ended1575=== CONT TestParseSingleRange/end_clamped_to_size1576=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1577--- PASS: TestParseSingleRange (0.02s)1578 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1579 --- PASS: TestParseSingleRange/closed (0.00s)1580 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1581 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1582 --- PASS: TestParseSingleRange/none (0.00s)1583 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1584 --- PASS: TestParseSingleRange/suffix (0.00s)1585 --- PASS: TestParseSingleRange/single_byte (0.00s)1586 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1587 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1588 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1589 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1590 --- PASS: TestParseSingleRange/open-ended (0.00s)1591 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1592=== CONT TestIsValidCachePath/short_hash1593=== CONT TestIsValidCachePath/wrong_extension1594=== CONT TestIsValidCachePath/leading_slash1595=== CONT TestIsValidCachePath/empty1596=== CONT TestIsValidCachePath/random_path1597=== CONT TestIsValidCachePath/invalid_char_u1598=== CONT TestIsValidCachePath/traversal_in_middle1599=== CONT TestIsValidCachePath/ls1600=== CONT TestIsValidCachePath/nar_bz21601=== CONT TestIsValidCachePath/nix-cache-info1602=== CONT TestIsValidCachePath/log1603=== CONT TestIsValidCachePath/index.html1604=== CONT TestIsValidCachePath/narinfo1605=== CONT TestIsValidCachePath/nar_uncompressed1606=== CONT TestIsValidCachePath/nar_zst1607=== CONT TestIsValidCachePath/invalid_char_e1608=== CONT TestIsValidCachePath/traversal_parent1609=== CONT TestIsValidCachePath/realisation1610=== CONT TestIsValidCachePath/nar_xz1611=== CONT TestIsValidUploadKey/narinfo1612--- PASS: TestIsValidCachePath (0.02s)1613 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1614 --- PASS: TestIsValidCachePath/short_hash (0.00s)1615 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1616 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1617 --- PASS: TestIsValidCachePath/empty (0.00s)1618 --- PASS: TestIsValidCachePath/random_path (0.00s)1619 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1620 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1621 --- PASS: TestIsValidCachePath/ls (0.00s)1622 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1623 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1624 --- PASS: TestIsValidCachePath/log (0.00s)1625 --- PASS: TestIsValidCachePath/index.html (0.00s)1626 --- PASS: TestIsValidCachePath/narinfo (0.00s)1627 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1628 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1629 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1630 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1631 --- PASS: TestIsValidCachePath/realisation (0.00s)1632 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1633=== CONT TestIsValidUploadKey/unknown_type1634=== CONT TestIsValidUploadKey/absolute1635=== CONT TestIsValidUploadKey/traversal_nar1636=== CONT TestIsValidUploadKey/traversal1637=== CONT TestIsValidUploadKey/build_log_plus_in_name1638=== CONT TestIsValidUploadKey/nix-cache-info1639=== CONT TestIsValidUploadKey/build_log_home-manager_file1640=== CONT TestIsValidUploadKey/listing1641=== CONT TestIsValidUploadKey/nar_plain1642=== CONT TestIsValidUploadKey/nar_xz1643=== CONT TestIsValidUploadKey/build_log_question_mark1644=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1645=== CONT TestIsValidUploadKey/index.html1646=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1647=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1648=== CONT TestIsValidUploadKey/build_log_equals1649=== CONT TestIsValidUploadKey/build_log1650=== CONT TestIsValidUploadKey/empty_key1651=== CONT TestIsValidUploadKey/nar_zst1652=== CONT TestIsValidUploadKey/realisation_plus_in_output1653=== CONT TestIsValidUploadKey/realisation1654=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure1655--- PASS: TestIsValidUploadKey (0.02s)1656 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1657 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1658 --- PASS: TestIsValidUploadKey/absolute (0.00s)1659 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1660 --- PASS: TestIsValidUploadKey/traversal (0.00s)1661 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1662 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1663 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1664 --- PASS: TestIsValidUploadKey/listing (0.00s)1665 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1666 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1667 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1668 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1669 --- PASS: TestIsValidUploadKey/index.html (0.00s)1670 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1671 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1672 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1673 --- PASS: TestIsValidUploadKey/build_log (0.00s)1674 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1675 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1676 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1677 --- PASS: TestIsValidUploadKey/realisation (0.00s)16782026/09/24 18:05:20 INFO Received uploads request method=POST path=/16792026/09/24 18:05:20 INFO Received push request method=POST path=/api/pushes1680=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart1681--- PASS: TestService_ReadAuthMiddleware (0.30s)16822026/09/24 18:05:20 INFO Received complete multipart upload request method=POST path=/1683=== NAME TestClientIntegration1684 client_integration_test.go:334: Created store path: /build/TestClientIntegration3421633959/002/store/wj9x9n1sbb8knid0b5rax1ibf9nm2mwy-test-file.txt16852026/09/24 18:05:20 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16862026/09/24 18:05:20 INFO Uploading xwq9clbm5dvjjxn6sjfs15z3053vavgh-b (208B)16872026/09/24 18:05:20 INFO Uploading x4qjf7bpi1l86agbyxakmdy6yin90487-shared-dep (136B)1688=== NAME TestClientMultipleUploads1689 client_integration_test.go:480: Created store path 1: /build/TestClientMultipleUploads226568981/001/store/7y22dy11wqjsmx4xrlmlmbgiyhs58zjl-test-file-1.txt16902026/09/24 18:05:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16912026/09/24 18:05:20 WARN Failed to register uploaded object key=nar/08pjaynwr419i5sxmy2hs7c4apgq5i9r243hvgp0xgin89brvsbl.nar.zst error="server returned 404: 404 page not found\n"16922026/09/24 18:05:20 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16932026/09/24 18:05:20 WARN Failed to register uploaded object key=8r9cbmxpp3qs938219rh6hdm3p057h3r.ls error="server returned 404: 404 page not found\n"16942026/09/24 18:05:20 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NWYyN2U0NDUtMTMyNi00NGMzLWI1ZDktNmUyMmViMzY1OTJiLmQ5MmYwOTg2LTk5YzYtNDI5Ny05MWVhLTdhZDAzYWU0MzY2YXgxNzkwMjczMTE4NzI3NDg4OTY3 parts=1016952026/09/24 18:05:20 INFO Received uploads request method=POST path=/api/pending_closures16962026/09/24 18:05:20 INFO Received push request method=POST path=/api/pushes16972026/09/24 18:05:20 WARN Failed to register uploaded object key=x4qjf7bpi1l86agbyxakmdy6yin90487.ls error="server returned 404: 404 page not found\n"16982026/09/24 18:05:20 INFO Aborted multipart uploads count=0 kept=016992026/09/24 18:05:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17002026/09/24 18:05:20 WARN Failed to register uploaded object key=xwq9clbm5dvjjxn6sjfs15z3053vavgh.ls error="server returned 404: 404 page not found\n"17012026/09/24 18:05:20 INFO Signed narinfos id=1 count=317022026/09/24 18:05:20 INFO Uploading 3 narinfos17032026/09/24 18:05:20 WARN Force mode enabled - objects will be deleted immediately without grace period17042026/09/24 18:05:20 INFO Received push request method=POST path=/api/pushes17052026/09/24 18:05:20 WARN Failed to register uploaded object key=x4qjf7bpi1l86agbyxakmdy6yin90487.narinfo error="server returned 404: 404 page not found\n"17062026/09/24 18:05:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17072026/09/24 18:05:20 INFO Uploading qwwbr5wvfzw4gvi85rr4dzycy4zxss63-ca-test (144B)1708 client_integration_test.go:480: Created store path 2: /build/TestClientMultipleUploads226568981/001/store/pry264w81166kprmwij4wdjz50kxqg4f-test-file-2.txt17092026/09/24 18:05:20 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)17102026/09/24 18:05:20 INFO Uploading ajspgvlri2ywshslnj3g22wkrn1lci3k-top (224B)17112026/09/24 18:05:20 INFO Uploading 1yqlsc87gb8i8whm2vi0w0ljb30q7mqq-shared-dep (136B)17122026/09/24 18:05:20 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=017132026/09/24 18:05:20 INFO Vacuumed table table=pending_closures17142026/09/24 18:05:20 INFO Vacuumed table table=pending_objects17152026/09/24 18:05:20 WARN Failed to register uploaded object key=xwq9clbm5dvjjxn6sjfs15z3053vavgh.narinfo error="server returned 404: 404 page not found\n"17162026/09/24 18:05:20 WARN Failed to register uploaded object key=8r9cbmxpp3qs938219rh6hdm3p057h3r.narinfo error="server returned 404: 404 page not found\n"17172026/09/24 18:05:20 INFO Received complete push request method=POST path=/api/pushes/1/complete17182026/09/24 18:05:20 INFO Vacuumed table table=multipart_uploads17192026/09/24 18:05:20 INFO Vacuumed table table=closures17202026/09/24 18:05:20 INFO Vacuumed table table=objects17212026/09/24 18:05:20 INFO Upload complete. (132ms)1722=== NAME TestClientPushesUseOnePush1723 client_pushes_test.go:97: Retrieved narinfo from S3:1724 StorePath: /build/TestClientPushesUseOnePush657037740/001/store/x4qjf7bpi1l86agbyxakmdy6yin90487-shared-dep1725 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1726 Compression: zstd1727 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821728 NarSize: 1361729 References: 1730 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17312026/09/24 18:05:20 WARN Failed to register uploaded object key=log/ihxmz1b3ssv3l36j1kknz32ywsfrip0c-ca-test.drv error="server returned 404: 404 page not found\n"17322026/09/24 18:05:20 WARN Failed to register uploaded object key=nar/061ddi7yxk1z85jb3b83z5y52n7zq7nllwhng8qvl7sgmy78w4wx.nar.zst error="server returned 404: 404 page not found\n"17332026/09/24 18:05:20 INFO Received push request method=POST path=/api/pushes17342026/09/24 18:05:20 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"17352026/09/24 18:05:20 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1736 client_pushes_test.go:97: Retrieved narinfo from S3:1737 StorePath: /build/TestClientPushesUseOnePush657037740/001/store/8r9cbmxpp3qs938219rh6hdm3p057h3r-a1738 URL: nar/08pjaynwr419i5sxmy2hs7c4apgq5i9r243hvgp0xgin89brvsbl.nar.zst1739 Compression: zstd17402026/09/24 18:05:20 INFO Received uploads request method=POST path=/api/pending_closures1741 NarHash: sha256:08pjaynwr419i5sxmy2hs7c4apgq5i9r243hvgp0xgin89brvsbl1742 NarSize: 2081743 References: /build/TestClientPushesUseOnePush657037740/001/store/x4qjf7bpi1l86agbyxakmdy6yin90487-shared-dep1744 CA: text:sha256:1jc4mijbxgc68xnnjhmynlyvr86m2nklp7s5z0njqki9ddywsh2y1745--- PASS: TestGCSweepDeliversEachKeyOnce (0.33s)17462026/09/24 18:05:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1747=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17482026/09/24 18:05:20 INFO Uploading wj9x9n1sbb8knid0b5rax1ibf9nm2mwy-test-file.txt (152B)17492026/09/24 18:05:20 INFO Received request for more parts method=POST path=/17502026/09/24 18:05:20 WARN Failed to register uploaded object key=ajspgvlri2ywshslnj3g22wkrn1lci3k.ls error="server returned 404: 404 page not found\n"1751=== NAME TestClientPushesUseOnePush1752 client_pushes_test.go:97: Retrieved narinfo from S3:1753 StorePath: /build/TestClientPushesUseOnePush657037740/001/store/xwq9clbm5dvjjxn6sjfs15z3053vavgh-b1754 URL: nar/08pjaynwr419i5sxmy2hs7c4apgq5i9r243hvgp0xgin89brvsbl.nar.zst1755 Compression: zstd1756 NarHash: sha256:08pjaynwr419i5sxmy2hs7c4apgq5i9r243hvgp0xgin89brvsbl1757 NarSize: 2081758 References: /build/TestClientPushesUseOnePush657037740/001/store/x4qjf7bpi1l86agbyxakmdy6yin90487-shared-dep1759 CA: text:sha256:1jc4mijbxgc68xnnjhmynlyvr86m2nklp7s5z0njqki9ddywsh2y17602026/09/24 18:05:20 WARN Failed to register uploaded object key=1yqlsc87gb8i8whm2vi0w0ljb30q7mqq.ls error="server returned 404: 404 page not found\n"17612026/09/24 18:05:20 WARN Failed to register uploaded object key=qwwbr5wvfzw4gvi85rr4dzycy4zxss63.ls error="server returned 404: 404 page not found\n"17622026/09/24 18:05:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17632026/09/24 18:05:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17642026/09/24 18:05:20 INFO Received uploads request method=POST path=/api/pending_closures17652026/09/24 18:05:20 INFO Signed narinfos id=1 count=117662026/09/24 18:05:20 INFO Signed narinfos id=1 count=217672026/09/24 18:05:20 INFO Uploading 1 narinfos17682026/09/24 18:05:20 INFO Uploading 2 narinfos1769=== NAME TestOrphanedObjectsGCStressTest1770 orphaned_objects_gc_test.go:431: Created 10 active closures, 5 to-delete closures, 20 orphaned chains17712026/09/24 18:05:20 INFO Received complete push request method=POST path=/api/pushes/1/complete17722026/09/24 18:05:20 WARN Failed to register uploaded object key=qwwbr5wvfzw4gvi85rr4dzycy4zxss63.narinfo error="server returned 404: 404 page not found\n"17732026/09/24 18:05:20 WARN Failed to register uploaded object key=1yqlsc87gb8i8whm2vi0w0ljb30q7mqq.narinfo error="server returned 404: 404 page not found\n"17742026/09/24 18:05:20 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17752026/09/24 18:05:20 INFO Uploading 72h4dg95xfa3ibbsvgscxfym6c7ah6hj-shared-dep (136B)17762026/09/24 18:05:20 INFO Uploading r2lmjlkfy0kz1nrqjrb43c9jx2rhs3fx-a (216B)17772026/09/24 18:05:20 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=017782026/09/24 18:05:20 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17792026/09/24 18:05:20 INFO Received complete push request method=POST path=/api/pushes/1/complete17802026/09/24 18:05:20 INFO Upload complete. (194ms)17812026/09/24 18:05:20 WARN Failed to register uploaded object key=ajspgvlri2ywshslnj3g22wkrn1lci3k.narinfo error="server returned 404: 404 page not found\n"17822026/09/24 18:05:20 INFO Vacuumed table table=pending_closures17832026/09/24 18:05:20 WARN Failed to register uploaded object key=nar/0x19vy5j736swmv95wi0fmc6rff95aspyrc3pczbjnzl78b8irk6.nar.zst error="server returned 404: 404 page not found\n"17842026/09/24 18:05:20 WARN Failed to register uploaded object key=r2lmjlkfy0kz1nrqjrb43c9jx2rhs3fx.ls error="server returned 404: 404 page not found\n"17852026/09/24 18:05:20 INFO Vacuumed table table=pending_objects17862026/09/24 18:05:20 INFO Vacuumed table table=multipart_uploads17872026/09/24 18:05:20 INFO Vacuumed table table=closures17882026/09/24 18:05:20 WARN Failed to register uploaded object key=wj9x9n1sbb8knid0b5rax1ibf9nm2mwy.ls error="server returned 404: 404 page not found\n"17892026/09/24 18:05:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1790=== NAME TestClientCADerivations1791 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1636015882/001/store/qwwbr5wvfzw4gvi85rr4dzycy4zxss63-ca-test1792 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1793 Compression: zstd1794 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1795 NarSize: 1441796 References: 1797 Deriver: /build/TestClientCADerivations1636015882/001/store/ihxmz1b3ssv3l36j1kknz32ywsfrip0c-ca-test.drv1798 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1799 client_ca_test.go:185: Checking for realisation files in S3...18002026/09/24 18:05:20 INFO Upload complete. (117ms)18012026/09/24 18:05:20 INFO Vacuumed table table=objects18022026/09/24 18:05:20 INFO Signed narinfos id=1 count=118032026/09/24 18:05:20 INFO Uploading 1 narinfos1804 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1805 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache18062026/09/24 18:05:20 WARN Failed to register uploaded object key=8hxhyrd2r6km473vdd52a3mq68gpj0mr.ls error="server returned 404: 404 page not found\n"1807=== NAME TestClientSharedPathCommittedMidPush1808 client_integration_test.go:816: Retrieved narinfo from S3:1809 StorePath: /build/TestClientSharedPathCommittedMidPush2075835820/001/store/1yqlsc87gb8i8whm2vi0w0ljb30q7mqq-shared-dep1810 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1811 Compression: zstd1812 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821813 NarSize: 1361814 References: 1815 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n18162026/09/24 18:05:20 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18172026/09/24 18:05:20 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18182026/09/24 18:05:20 WARN Failed to register uploaded object key=72h4dg95xfa3ibbsvgscxfym6c7ah6hj.ls error="server returned 404: 404 page not found\n"18192026/09/24 18:05:20 INFO Signed narinfos id=2 count=218202026/09/24 18:05:20 INFO Received complete push request method=POST path=/api/pushes/1/complete18212026/09/24 18:05:20 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18222026/09/24 18:05:20 WARN Failed to register uploaded object key=wj9x9n1sbb8knid0b5rax1ibf9nm2mwy.narinfo error="server returned 404: 404 page not found\n"18232026/09/24 18:05:20 INFO Signed narinfos id=1 count=218242026/09/24 18:05:20 INFO Uploading 4 narinfos18252026/09/24 18:05:20 INFO Received push request method=POST path=/api/pushes1826 client_integration_test.go:816: Retrieved narinfo from S3:1827 StorePath: /build/TestClientSharedPathCommittedMidPush2075835820/001/store/ajspgvlri2ywshslnj3g22wkrn1lci3k-top1828 URL: nar/061ddi7yxk1z85jb3b83z5y52n7zq7nllwhng8qvl7sgmy78w4wx.nar.zst1829 Compression: zstd1830 NarHash: sha256:061ddi7yxk1z85jb3b83z5y52n7zq7nllwhng8qvl7sgmy78w4wx1831 NarSize: 2241832 References: /build/TestClientSharedPathCommittedMidPush2075835820/001/store/1yqlsc87gb8i8whm2vi0w0ljb30q7mqq-shared-dep1833 CA: text:sha256:1hqknr9inm2qm1dkx49di3zgscqzzxvvawrddwwns4grn6xi8xax1834=== CONT TestServerTLSConfig/no_client_CA1835--- PASS: TestClientPushesUseOnePush (0.68s)1836=== CONT TestServerTLSConfig/missing_CA_file1837=== CONT TestServerTLSConfig/not_a_PEM_file1838=== CONT TestPush_RejectsBadRequests/no_objects1839--- PASS: TestServerTLSConfig (0.00s)1840 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1841 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1842 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)18432026/09/24 18:05:20 INFO Received push request method=POST path=/api/pushes1844=== CONT TestPush_RejectsBadRequests/root_not_in_objects18452026/09/24 18:05:20 INFO Received push request method=POST path=/api/pushes18462026/09/24 18:05:20 INFO Upload complete. (95ms)1847=== CONT TestPush_RejectsBadRequests/bad_root18482026/09/24 18:05:20 INFO Received push request method=POST path=/api/pushes1849=== CONT TestPush_RejectsBadRequests/no_roots18502026/09/24 18:05:20 WARN Failed to register uploaded object key=r2lmjlkfy0kz1nrqjrb43c9jx2rhs3fx.narinfo error="server returned 404: 404 page not found\n"18512026/09/24 18:05:20 WARN Failed to register uploaded object key=72h4dg95xfa3ibbsvgscxfym6c7ah6hj.narinfo error="server returned 404: 404 page not found\n"18522026/09/24 18:05:20 INFO Received push request method=POST path=/api/pushes1853=== CONT TestClientErrorHandling/InvalidAuthToken18542026/09/24 18:05:20 WARN Failed to register uploaded object key=8hxhyrd2r6km473vdd52a3mq68gpj0mr.narinfo error="server returned 404: 404 page not found\n"18552026/09/24 18:05:20 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18562026/09/24 18:05:20 INFO Uploading 4bbl5l6j7ff7hd48fal7ap1pi6lxvrhc-test-file-0.txt (160B)18572026/09/24 18:05:20 INFO Uploading 7y22dy11wqjsmx4xrlmlmbgiyhs58zjl-test-file-1.txt (160B)18582026/09/24 18:05:20 INFO Uploading pry264w81166kprmwij4wdjz50kxqg4f-test-file-2.txt (160B)18592026/09/24 18:05:20 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18602026/09/24 18:05:20 WARN Failed to register uploaded object key=72h4dg95xfa3ibbsvgscxfym6c7ah6hj.narinfo error="server returned 404: 404 page not found\n"1861=== NAME TestOrphanedObjectsGCStressTest1862 orphaned_objects_gc_test.go:452: Marked 210 objects for deletion18632026/09/24 18:05:20 WARN Failed to register uploaded object key=7y22dy11wqjsmx4xrlmlmbgiyhs58zjl.ls error="server returned 404: 404 page not found\n"18642026/09/24 18:05:20 INFO Completed upload id=118652026/09/24 18:05:20 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18662026/09/24 18:05:20 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18672026/09/24 18:05:20 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18682026/09/24 18:05:20 INFO Completed upload id=218692026/09/24 18:05:20 INFO Upload complete. (109ms)18702026/09/24 18:05:20 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"1871=== NAME TestClientFallsBackToClosures1872 client_pushes_test.go:112: Retrieved narinfo from S3:1873 StorePath: /build/TestClientFallsBackToClosures2103047738/001/store/72h4dg95xfa3ibbsvgscxfym6c7ah6hj-shared-dep1874 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1875 Compression: zstd1876 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821877 NarSize: 1361878 References: 1879 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1880 client_pushes_test.go:112: Retrieved narinfo from S3:1881 StorePath: /build/TestClientFallsBackToClosures2103047738/001/store/r2lmjlkfy0kz1nrqjrb43c9jx2rhs3fx-a1882 URL: nar/0x19vy5j736swmv95wi0fmc6rff95aspyrc3pczbjnzl78b8irk6.nar.zst1883 Compression: zstd1884 NarHash: sha256:0x19vy5j736swmv95wi0fmc6rff95aspyrc3pczbjnzl78b8irk61885 NarSize: 2161886 References: /build/TestClientFallsBackToClosures2103047738/001/store/72h4dg95xfa3ibbsvgscxfym6c7ah6hj-shared-dep1887 CA: text:sha256:1wcfck19a2f4n5a61crkgs3fjrf7fij4a2abw8qshvqvf1m7l81c18882026/09/24 18:05:20 WARN Failed to register uploaded object key=pry264w81166kprmwij4wdjz50kxqg4f.ls error="server returned 404: 404 page not found\n"18892026/09/24 18:05:20 WARN Failed to register uploaded object key=4bbl5l6j7ff7hd48fal7ap1pi6lxvrhc.ls error="server returned 404: 404 page not found\n"18902026/09/24 18:05:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1891--- PASS: TestSweepSparesObjectReuploadedMidSweep (1.53s)1892=== CONT TestClientErrorHandling/ServerNotAvailable18932026/09/24 18:05:20 INFO Signed narinfos id=1 count=31894--- PASS: TestClientSharedPathCommittedMidPush (0.67s)1895=== CONT TestClientErrorHandling/InvalidStorePath18962026/09/24 18:05:20 INFO Uploading 3 narinfos1897--- PASS: TestPush_RejectsBadRequests (0.57s)1898 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1899 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1900 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1901 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1902=== NAME TestClientFallsBackToClosures1903 client_pushes_test.go:112: Retrieved narinfo from S3:1904 StorePath: /build/TestClientFallsBackToClosures2103047738/001/store/8hxhyrd2r6km473vdd52a3mq68gpj0mr-b1905 URL: nar/0x19vy5j736swmv95wi0fmc6rff95aspyrc3pczbjnzl78b8irk6.nar.zst1906 Compression: zstd1907 NarHash: sha256:0x19vy5j736swmv95wi0fmc6rff95aspyrc3pczbjnzl78b8irk61908 NarSize: 2161909 References: /build/TestClientFallsBackToClosures2103047738/001/store/72h4dg95xfa3ibbsvgscxfym6c7ah6hj-shared-dep1910 CA: text:sha256:1wcfck19a2f4n5a61crkgs3fjrf7fij4a2abw8qshvqvf1m7l81c19112026/09/24 18:05:20 WARN Failed to register uploaded object key=7y22dy11wqjsmx4xrlmlmbgiyhs58zjl.narinfo error="server returned 404: 404 page not found\n"19122026/09/24 18:05:20 WARN Failed to register uploaded object key=4bbl5l6j7ff7hd48fal7ap1pi6lxvrhc.narinfo error="server returned 404: 404 page not found\n"19132026/09/24 18:05:20 INFO All 1 paths already cached1914=== NAME TestClientIntegration1915 client_integration_test.go:360: Retrieved narinfo from S3:1916 StorePath: /build/TestClientIntegration3421633959/002/store/wj9x9n1sbb8knid0b5rax1ibf9nm2mwy-test-file.txt19172026/09/24 18:05:20 INFO Received complete push request method=POST path=/api/pushes/1/complete1918 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1919 Compression: zstd1920 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11921 NarSize: 1521922 References: 1923 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk119242026/09/24 18:05:20 WARN Failed to register uploaded object key=pry264w81166kprmwij4wdjz50kxqg4f.narinfo error="server returned 404: 404 page not found\n"19252026/09/24 18:05:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1926 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)1927 client_integration_test.go:361: Decompressed .ls content (64 bytes):1928 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}19292026/09/24 18:05:20 INFO Upload complete. (101ms)1930=== NAME TestClientMultipleUploads1931 client_integration_test.go:491: Uploaded 3 paths in 136.567943ms19322026/09/24 18:05:20 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NWYyN2U0NDUtMTMyNi00NGMzLWI1ZDktNmUyMmViMzY1OTJiLjViZjRmZWVjLTdhOGMtNGM0NS05YzAwLTY4MjEyMWU1MWI0YXgxNzkwMjczMTE5NTE4OTY0MDk5 error="Get \"http://127.0.0.1:1/bucket39/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"19332026/09/24 18:05:20 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NWYyN2U0NDUtMTMyNi00NGMzLWI1ZDktNmUyMmViMzY1OTJiLmMxZjJhZjVhLTVhNWQtNDZiNi05NGNhLWE3YTFhYTA3NDcwOHgxNzkwMjczMTE5NDk5NDcwODg0 parts=121934--- PASS: TestClientFallsBackToClosures (0.64s)1935=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete19362026/09/24 18:05:20 INFO Received cleanup request method=DELETE path=/api/pending_closures19372026/09/24 18:05:20 INFO Aborted multipart uploads count=1 kept=01938=== NAME TestClientCADerivations1939 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1940 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1941 error: binary cache 's3://bucket78?endpoint=http://localhost:45357®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1636015882/001/store'1942 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11943--- PASS: TestClientMultipleUploads (0.62s)1944=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark19452026/09/24 18:05:20 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1946--- PASS: TestRedundantMultipartUpload (2.35s)1947=== CONT TestGCEndsOnShutdown/before_the_run1948--- PASS: TestClientCADerivations (0.83s)1949=== CONT TestCacheConfigHandler/no_cache_url_configured1950=== CONT TestCacheConfigHandler/full_config,_no_issuer1951=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1952=== CONT TestCacheConfigHandler/no_signing_keys1953=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1954--- PASS: TestCacheConfigHandler (0.00s)1955 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1956 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1957 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1958 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)19592026/09/24 18:05:20 INFO Received push request method=POST path=/api/pushes19602026/09/24 18:05:20 INFO Object in database but missing from S3 key=wj9x9n1sbb8knid0b5rax1ibf9nm2mwy.ls19612026/09/24 18:05:20 WARN Found objects in DB but missing from S3, will re-upload count=119622026/09/24 18:05:20 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19632026/09/24 18:05:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19642026/09/24 18:05:20 INFO Received complete push request method=POST path=/api/pushes/2/complete19652026/09/24 18:05:20 WARN Failed to register uploaded object key=wj9x9n1sbb8knid0b5rax1ibf9nm2mwy.ls error="server returned 404: 404 page not found\n"19662026/09/24 18:05:20 INFO Upload complete. (64ms)1967=== NAME TestClientIntegration1968 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)1969 client_integration_test.go:389: Decompressed .ls content (49 bytes):1970 {"version":1,"root":{"type":"regular","size":39}}19712026/09/24 18:05:20 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NWYyN2U0NDUtMTMyNi00NGMzLWI1ZDktNmUyMmViMzY1OTJiLmMwZWU3ZmEwLTA2MWYtNDQzOC05MGE0LTFhODZhMzQ4OTE1OXgxNzkwMjczMTE5MTAzNDE3MjY4 parts=1019722026/09/24 18:05:20 INFO Received complete push request method=POST path=/api/pushes/1/complete19732026/09/24 18:05:20 INFO Received push request method=POST path=/api/pushes19742026/09/24 18:05:20 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.835527ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19752026/09/24 18:05:20 INFO Received push request method=POST path=/api/pushes19762026/09/24 18:05:20 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19772026/09/24 18:05:20 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19782026/09/24 18:05:20 INFO Received complete push request method=POST path=/api/pushes/3/complete19792026/09/24 18:05:20 WARN Failed to register uploaded object key=wj9x9n1sbb8knid0b5rax1ibf9nm2mwy.ls error="server returned 404: 404 page not found\n"19802026/09/24 18:05:20 INFO Aborted multipart uploads count=0 kept=019812026/09/24 18:05:20 INFO Upload complete. (64ms)1982 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)19832026/09/24 18:05:20 INFO Aborted multipart uploads count=0 kept=01984 client_integration_test.go:405: Decompressed .ls content (49 bytes):1985 {"version":1,"root":{"type":"regular","size":39}}19862026/09/24 18:05:20 WARN Force mode enabled - objects will be deleted immediately without grace period19872026/09/24 18:05:20 WARN Force mode enabled - objects will be deleted immediately without grace period1988=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows19892026/09/24 18:05:20 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:45357/bucket91/?delete=\": context canceled"19902026/09/24 18:05:20 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=019912026/09/24 18:05:20 INFO Vacuumed table table=pending_closures19922026/09/24 18:05:20 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19932026/09/24 18:05:20 INFO Vacuumed table table=pending_objects19942026/09/24 18:05:20 INFO Vacuumed table table=multipart_uploads19952026/09/24 18:05:20 INFO Vacuumed table table=closures1996=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured19972026/09/24 18:05:20 INFO Vacuumed table table=objects1998=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19992026/09/24 18:05:20 INFO Aborted multipart uploads count=0 kept=020002026/09/24 18:05:20 WARN Authentication failed token_preview=eyJhbGciOi...kGeYwdUUYw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2001=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20022026/09/24 18:05:20 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]2003=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token20042026/09/24 18:05:20 WARN Force mode enabled - objects will be deleted immediately without grace period2005=== CONT TestResolveDBConnectionString/file_when_flag_empty2006=== CONT TestResolveDBConnectionString/nothing_configured20072026-09-24 18:05:20.558 UTC [2298] ERROR: canceling statement due to user request20082026-09-24 18:05:20.558 UTC [2298] CONTEXT: PL/pgSQL function object_stats_apply() line 12 at assignment20092026-09-24 18:05:20.558 UTC [2298] STATEMENT: -- name: MarkStaleObjects :execrows2010 WITH RECURSIVE ct AS (2011 SELECT timezone('UTC', now()) AS now2012 ),2013 closure_reach AS (2014 -- Start with all closure keys2015 SELECT o.key, o.refs2016 FROM objects o2017 INNER JOIN closures c ON o.key = c.key2018 UNION2019 -- Recursively add all referenced objects2020 SELECT o.key, o.refs2021 FROM objects o2022 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2023 ),2024 reachable_objects AS (2025 SELECT DISTINCT key FROM closure_reach2026 ),2027 stale_objects AS (2028 SELECT o.key2029 FROM objects AS o, ct2030 WHERE2031 NOT EXISTS (2032 SELECT 12033 FROM reachable_objects ro2034 WHERE ro.key = o.key2035 )2036 AND NOT EXISTS (2037 SELECT 12038 FROM pending_objects AS po2039 WHERE po.key = o.key2040 )2041 AND o.deleted_at IS NULL -- Only mark fresh objects2042 ORDER BY o.key -- lock in key order, like commit_pending_closure2043 FOR UPDATE2044 )2045 UPDATE objects2046 SET2047 deleted_at = ct.now,2048 first_deleted_at = COALESCE(first_deleted_at, ct.now)2049 FROM stale_objects, ct2050 WHERE objects.key = stale_objects.key2051 2052=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2053=== CONT TestResolveDBConnectionString/missing_file_is_an_error2054=== CONT TestResolveDBConnectionString/flag_wins2055=== CONT TestService_RequireScope_OIDC/ops_may_admin2056--- PASS: TestResolveDBConnectionString (0.00s)2057 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2058 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2059 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2060 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2061 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2062=== CONT TestService_RequireScope_OIDC/reader_may_not_write2063=== CONT TestService_RequireScope_OIDC/writer_implies_read2064=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2065=== CONT TestService_RequireScope_OIDC/static_token_may_write2066=== CONT TestService_RequireScope_OIDC/static_token_may_admin2067=== CONT TestService_RequireScope_OIDC/ops_may_not_write2068=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2069=== CONT TestService_RequireScope_OIDC/reader_may_read2070=== CONT TestService_RequireScope_OIDC/builder_may_write2071--- PASS: TestService_AuthMiddleware_OIDC (0.49s)2072 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2073 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2074 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2075 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2076--- PASS: TestGCEndsOnShutdown (0.00s)2077 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.23s)2078 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.24s)2079 --- PASS: TestGCEndsOnShutdown/before_the_run (0.24s)2080--- PASS: TestService_RequireScope_OIDC (0.72s)2081 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2082 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2083 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2084 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2085 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2086 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2087 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2088 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2089 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2090 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)20912026/09/24 18:05:20 INFO Received uploads request method=POST path=/api/pending_closures20922026/09/24 18:05:20 INFO Aborted multipart uploads count=0 kept=020932026/09/24 18:05:20 WARN Force mode enabled - objects will be deleted immediately without grace period20942026/09/24 18:05:20 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=020952026/09/24 18:05:20 INFO Vacuumed table table=pending_closures20962026/09/24 18:05:20 INFO Received push request method=POST path=/api/pushes20972026/09/24 18:05:20 INFO Vacuumed table table=pending_objects20982026/09/24 18:05:20 INFO Vacuumed table table=multipart_uploads20992026/09/24 18:05:20 INFO Vacuumed table table=closures21002026/09/24 18:05:20 INFO Vacuumed table table=objects2101--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.68s)21022026/09/24 18:05:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21032026/09/24 18:05:20 INFO Uploading h5mp75cwa27m8hzyqsphsvnnmk4rhwzb-lost-commit.txt (152B)21042026/09/24 18:05:20 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"21052026/09/24 18:05:20 WARN Failed to register uploaded object key=h5mp75cwa27m8hzyqsphsvnnmk4rhwzb.ls error="server returned 404: 404 page not found\n"21062026/09/24 18:05:20 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign21072026/09/24 18:05:20 INFO Signed narinfos id=4 count=121082026/09/24 18:05:20 INFO Uploading 1 narinfos21092026/09/24 18:05:20 INFO Received complete push request method=POST path=/api/pushes/4/complete21102026/09/24 18:05:20 WARN Failed to register uploaded object key=h5mp75cwa27m8hzyqsphsvnnmk4rhwzb.narinfo error="server returned 404: 404 page not found\n"21112026/09/24 18:05:20 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=436.182889ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21122026/09/24 18:05:20 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://127.0.0.1:39295/api/pushes/4/complete\": EOF" url=http://127.0.0.1:39295/api/pushes/4/complete2113=== NAME TestOrphanedObjectsGCStressTest2114 orphaned_objects_gc_test.go:515: Stress test completed successfully:2115 orphaned_objects_gc_test.go:516: - Active objects preserved: 202116 orphaned_objects_gc_test.go:517: - Objects deleted: 2102117 orphaned_objects_gc_test.go:518: - Total GC'd: 21021182026/09/24 18:05:20 INFO Received uploads request method=POST path=/api/pending_closures21192026/09/24 18:05:20 INFO Aborted multipart uploads count=0 kept=021202026/09/24 18:05:20 WARN Force mode enabled - objects will be deleted immediately without grace period2121--- PASS: TestOrphanedObjectsGCStressTest (3.36s)21222026/09/24 18:05:20 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=021232026/09/24 18:05:20 INFO Vacuumed table table=pending_closures21242026/09/24 18:05:20 INFO Vacuumed table table=pending_objects21252026/09/24 18:05:20 INFO Vacuumed table table=multipart_uploads21262026/09/24 18:05:20 INFO Vacuumed table table=closures21272026/09/24 18:05:20 INFO Vacuumed table table=objects21282026/09/24 18:05:20 INFO Received complete push request method=POST path=/api/pushes/4/complete21292026-09-24 18:05:20.767 UTC [1352] ERROR: Push does not exist: id=421302026-09-24 18:05:20.767 UTC [1352] CONTEXT: PL/pgSQL function commit_push(bigint) line 9 at RAISE21312026-09-24 18:05:20.767 UTC [1352] STATEMENT: -- name: CommitPush :exec2132 SELECT commit_push($1::bigint)2133 2134--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2135 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.31s)2136 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.24s)21372026/09/24 18:05:20 INFO Upload complete. (183ms)2138=== NAME TestClientIntegration2139 client_integration_test.go:435: Retrieved narinfo from S3:2140 StorePath: /build/TestClientIntegration3421633959/002/store/h5mp75cwa27m8hzyqsphsvnnmk4rhwzb-lost-commit.txt2141 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst2142 Compression: zstd2143 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2144 NarSize: 1522145 References: 2146 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2147 client_integration_test.go:438: Testing garbage collection...2148--- PASS: TestConnectSerialisesConcurrentMigrations (1.17s)21492026/09/24 18:05:20 INFO Starting cleanup of old closures method=DELETE path=/api/closures21502026/09/24 18:05:20 INFO Garbage collection started21512026/09/24 18:05:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21522026/09/24 18:05:20 INFO Aborted multipart uploads count=0 kept=021532026/09/24 18:05:20 WARN Force mode enabled - objects will be deleted immediately without grace period21542026/09/24 18:05:20 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NWYyN2U0NDUtMTMyNi00NGMzLWI1ZDktNmUyMmViMzY1OTJiLjA3MjE5ZmJlLWNiYTctNDdhMy1hMDVjLTM3OTdmZTM1MTgzY3gxNzkwMjczMTE4NzI5NjYxNzI3 parts=1021552026/09/24 18:05:20 INFO Received complete push request method=POST path=/api/pushes/1/complete21562026/09/24 18:05:20 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=021572026/09/24 18:05:20 INFO Vacuumed table table=pending_closures21582026/09/24 18:05:20 INFO Vacuumed table table=pending_objects21592026/09/24 18:05:20 INFO Vacuumed table table=multipart_uploads21602026/09/24 18:05:20 INFO lead: released remote=192.0.2.1:123421612026/09/24 18:05:20 INFO Vacuumed table table=closures21622026/09/24 18:05:20 INFO Vacuumed table table=objects2163--- PASS: TestPush_CompleteCommitsEveryRoot (2.71s)2164--- PASS: TestLeadEndsOnShutdown (1.38s)2165--- PASS: TestPendingClosureWriteTimeout (0.01s)2166 --- PASS: TestPendingClosureWriteTimeout/negative (0.00s)2167 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2168 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2169 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2170 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.06s)21712026/09/24 18:05:21 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=734.051175ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21722026/09/24 18:05:21 INFO lead: released remote=192.0.2.1:123421732026/09/24 18:05:21 INFO lead: acquired remote=192.0.2.1:123421742026/09/24 18:05:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21752026/09/24 18:05:21 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NWYyN2U0NDUtMTMyNi00NGMzLWI1ZDktNmUyMmViMzY1OTJiLjliZDExOGZlLWE1NTMtNGIzYS1hYzY0LWQwMzEyNWNjOGIyZXgxNzkwMjczMTIwNDQzNzkzNjYz parts=1021762026/09/24 18:05:21 INFO Received complete push request method=POST path=/api/pushes/2/complete2177--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.59s)21782026/09/24 18:05:21 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.478927943s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21792026/09/24 18:05:21 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021802026/09/24 18:05:21 INFO Received create pin request method=POST path=/api/pins/myapp21812026/09/24 18:05:21 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2317796160/001/store/llwfp546l76j075kjfzbllmq3rnk6k04-pinned-file.txt narinfo_key=llwfp546l76j075kjfzbllmq3rnk6k04.narinfo21822026/09/24 18:05:21 INFO Starting cleanup of old closures method=DELETE path=/api/closures21832026/09/24 18:05:21 INFO Garbage collection started21842026/09/24 18:05:21 INFO Aborted multipart uploads count=0 kept=021852026/09/24 18:05:21 WARN Force mode enabled - objects will be deleted immediately without grace period21862026/09/24 18:05:21 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=021872026/09/24 18:05:21 INFO Vacuumed table table=pending_closures21882026/09/24 18:05:21 INFO Vacuumed table table=pending_objects21892026/09/24 18:05:21 INFO Vacuumed table table=multipart_uploads21902026/09/24 18:05:21 INFO Vacuumed table table=closures21912026/09/24 18:05:21 INFO Vacuumed table table=objects21922026/09/24 18:05:22 INFO lead: released remote=192.0.2.1:12342193--- PASS: TestLeadElectsOneAndHandsOver (2.66s)21942026/09/24 18:05:22 WARN Rate limiter enabled after throttle name=s3-test rate=521952026/09/24 18:05:22 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2196=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2197 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102198 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002199--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.89s)22002026/09/24 18:05:22 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02201=== NAME TestClientIntegration2202 client_integration_test.go:445: Objects in database after GC:2203 client_integration_test.go:445: Successfully deleted all objects with GC --force2204--- PASS: TestClientIntegration (3.06s)22052026/09/24 18:05:23 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2206--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.92s)22072026/09/24 18:05:23 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=181.447894ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22082026/09/24 18:05:23 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=390.08599ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2209=== NAME TestPinProtectsFromGC2210 client_integration_test.go:981: Pin successfully protected closure from garbage collection2211--- PASS: TestPinProtectsFromGC (4.93s)22122026/09/24 18:05:24 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=828.222536ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22132026/09/24 18:05:24 INFO Aborted multipart uploads count=1 kept=022142026/09/24 18:05:24 INFO Received cleanup request method=DELETE path=/api/pending_closures22152026/09/24 18:05:24 INFO Aborted multipart uploads count=1 kept=02216--- PASS: TestPendingCleanupUsesOneCutoff (6.79s)22172026/09/24 18:05:24 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.744164547s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2218--- PASS: TestConnectWaitsForAPeerMigration (5.21s)22192026/09/24 18:05:26 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"22202026/09/24 18:05:26 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22212026/09/24 18:05:26 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=198.148529ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22222026/09/24 18:05:26 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=406.278269ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2223--- PASS: TestUploadHandlersRejectOversizedBody (0.48s)2224 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.61s)2225 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.59s)2226 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (7.09s)22272026/09/24 18:05:27 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=866.783628ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22282026/09/24 18:05:28 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.634422722s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22292026/09/24 18:05:29 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22302026/09/24 18:05:29 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=189.757012ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22312026/09/24 18:05:30 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=424.000062ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22322026/09/24 18:05:30 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=779.267636ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22332026/09/24 18:05:31 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.512961183s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2234--- PASS: TestClientErrorHandling (0.00s)2235 --- PASS: TestClientErrorHandling/InvalidStorePath (0.25s)2236 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.32s)2237 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.61s)2238PASS2239{"timestamp":"2026-09-24T18:05:32.88219546Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:46712","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2260,"threadName":"rustfs-worker","threadId":"ThreadId(401)"}2240{"timestamp":"2026-09-24T18:05:32.88359612Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:47174","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2260,"threadName":"rustfs-worker","threadId":"ThreadId(392)"}2241{"timestamp":"2026-09-24T18:05:32.88360623Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:46952","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2260,"threadName":"rustfs-worker","threadId":"ThreadId(400)"}22422026-09-24 18:05:33.327 UTC [170] LOG: received smart shutdown request22432026-09-24 18:05:33.331 UTC [170] LOG: background worker "logical replication launcher" (PID 180) exited with exit code 122442026-09-24 18:05:33.343 UTC [175] LOG: shutting down22452026-09-24 18:05:33.344 UTC [175] LOG: checkpoint starting: shutdown immediate22462026-09-24 18:05:34.155 UTC [175] LOG: checkpoint complete: wrote 10359 buffers (63.2%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 28 recycled; write=0.241 s, sync=0.517 s, total=0.812 s; sync files=32693, longest=0.068 s, average=0.001 s; distance=463508 kB, estimate=463508 kB; lsn=0/1DC0AEE0, redo lsn=0/1DC0AEE022472026-09-24 18:05:34.234 UTC [170] LOG: database system is shut down2248Running OIDC tests...2249=== RUN TestAudienceForIssuer2250=== PAUSE TestAudienceForIssuer2251=== RUN TestHTTPClientForHasTimeouts2252=== PAUSE TestHTTPClientForHasTimeouts2253=== RUN TestGlobMatch2254=== PAUSE TestGlobMatch2255=== RUN TestValidateToken_ValidToken2256=== PAUSE TestValidateToken_ValidToken2257=== RUN TestValidateToken_WrongAudience2258=== PAUSE TestValidateToken_WrongAudience2259=== RUN TestValidateToken_Expired2260=== PAUSE TestValidateToken_Expired2261=== RUN TestValidateToken_BoundClaimsMismatch2262=== PAUSE TestValidateToken_BoundClaimsMismatch2263=== RUN TestValidateToken_BoundSubjectMismatch2264=== PAUSE TestValidateToken_BoundSubjectMismatch2265=== RUN TestValidateToken_MultipleProviders2266=== PAUSE TestValidateToken_MultipleProviders2267=== RUN TestValidateToken_NoMatchingProvider2268=== PAUSE TestValidateToken_NoMatchingProvider2269=== RUN TestValidateToken_KubernetesServiceAccount2270=== PAUSE TestValidateToken_KubernetesServiceAccount2271=== RUN TestNewValidator_KubernetesRequiresCA2272=== PAUSE TestNewValidator_KubernetesRequiresCA2273=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2274=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2275=== RUN TestPins_ReservedForMatchingRule2276=== PAUSE TestPins_ReservedForMatchingRule2277=== RUN TestPins_TopLevelShorthand2278=== PAUSE TestPins_TopLevelShorthand2279=== RUN TestPins_ConfigValidation2280=== PAUSE TestPins_ConfigValidation2281=== RUN TestScopes_LegacyProviderDefaultsToWrite2282=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2283=== RUN TestScopes_Rules2284=== PAUSE TestScopes_Rules2285=== RUN TestScopes_ConfigValidation2286=== PAUSE TestScopes_ConfigValidation2287=== CONT TestGlobMatch2288=== CONT TestValidateToken_NoMatchingProvider2289=== CONT TestValidateToken_WrongAudience2290=== CONT TestValidateToken_MultipleProviders2291=== CONT TestValidateToken_KubernetesServiceAccount2292=== RUN TestGlobMatch/foo_foo2293=== CONT TestValidateToken_BoundClaimsMismatch2294=== PAUSE TestGlobMatch/foo_foo2295=== RUN TestGlobMatch/foo_bar2296=== CONT TestValidateToken_ValidToken2297=== CONT TestValidateToken_BoundSubjectMismatch2298=== CONT TestValidateToken_Expired2299=== CONT TestHTTPClientForHasTimeouts2300=== CONT TestAudienceForIssuer2301=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2302=== CONT TestScopes_LegacyProviderDefaultsToWrite2303=== CONT TestScopes_Rules2304=== CONT TestScopes_ConfigValidation2305=== CONT TestPins_ConfigValidation2306=== CONT TestPins_ReservedForMatchingRule2307=== CONT TestNewValidator_KubernetesRequiresCA2308=== CONT TestPins_TopLevelShorthand2309=== PAUSE TestGlobMatch/foo_bar2310--- PASS: TestAudienceForIssuer (0.00s)2311=== RUN TestGlobMatch/*_2312=== PAUSE TestGlobMatch/*_2313=== RUN TestGlobMatch/*_anything2314=== PAUSE TestGlobMatch/*_anything2315=== RUN TestGlobMatch/foo*_foo2316=== PAUSE TestGlobMatch/foo*_foo2317=== RUN TestGlobMatch/foo*_foobar2318=== PAUSE TestGlobMatch/foo*_foobar2319=== RUN TestGlobMatch/foo*_bar2320=== PAUSE TestGlobMatch/foo*_bar2321=== RUN TestGlobMatch/*bar_bar2322=== PAUSE TestGlobMatch/*bar_bar2323=== RUN TestGlobMatch/*bar_foobar2324=== PAUSE TestGlobMatch/*bar_foobar2325=== RUN TestGlobMatch/*bar_foo2326=== PAUSE TestGlobMatch/*bar_foo2327=== RUN TestGlobMatch/foo*bar_foobar2328=== PAUSE TestGlobMatch/foo*bar_foobar2329--- PASS: TestScopes_ConfigValidation (0.00s)2330=== RUN TestGlobMatch/foo*bar_foo123bar2331=== PAUSE TestGlobMatch/foo*bar_foo123bar2332=== RUN TestGlobMatch/foo*bar_foobarbaz2333=== PAUSE TestGlobMatch/foo*bar_foobarbaz2334=== RUN TestGlobMatch/*/*_foo/bar2335=== PAUSE TestGlobMatch/*/*_foo/bar2336=== RUN TestGlobMatch/*/*_foo2337=== PAUSE TestGlobMatch/*/*_foo2338=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2339--- PASS: TestPins_ConfigValidation (0.01s)2340=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2341=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02342=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02343=== RUN TestGlobMatch/refs/*/main_refs/heads/main2344=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2345=== RUN TestGlobMatch/fo?_foo2346=== PAUSE TestGlobMatch/fo?_foo2347=== RUN TestGlobMatch/fo?_fo2348=== PAUSE TestGlobMatch/fo?_fo2349=== RUN TestGlobMatch/fo?_fooo2350=== PAUSE TestGlobMatch/fo?_fooo2351=== RUN TestGlobMatch/?oo_foo2352=== PAUSE TestGlobMatch/?oo_foo2353=== RUN TestGlobMatch/?oo_boo2354=== PAUSE TestGlobMatch/?oo_boo2355=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2356=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2357=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2358=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2359=== CONT TestGlobMatch/foo_foo2360=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02361=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2362=== CONT TestGlobMatch/*bar_foo2363=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2364=== CONT TestGlobMatch/?oo_boo2365=== CONT TestGlobMatch/fo?_foo2366=== CONT TestGlobMatch/foo*bar_foo123bar2367=== CONT TestGlobMatch/foo*bar_foobar2368=== CONT TestGlobMatch/*bar_bar2369=== CONT TestGlobMatch/*bar_foobar2370=== CONT TestGlobMatch/*/*_foo/bar2371=== CONT TestGlobMatch/foo*_foobar2372=== CONT TestGlobMatch/?oo_foo2373=== CONT TestGlobMatch/fo?_fo2374=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2375=== CONT TestGlobMatch/fo?_fooo2376=== CONT TestGlobMatch/foo*bar_foobarbaz2377=== CONT TestGlobMatch/*/*_foo2378=== CONT TestGlobMatch/refs/*/main_refs/heads/main2379=== CONT TestGlobMatch/*_2380=== CONT TestGlobMatch/foo*_bar2381=== CONT TestGlobMatch/*_anything2382=== CONT TestGlobMatch/foo_bar2383=== CONT TestGlobMatch/foo*_foo2384--- PASS: TestGlobMatch (0.02s)2385 --- PASS: TestGlobMatch/foo_foo (0.00s)2386 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2387 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2388 --- PASS: TestGlobMatch/*bar_foo (0.00s)2389 --- PASS: TestGlobMatch/?oo_boo (0.00s)2390 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2391 --- PASS: TestGlobMatch/fo?_foo (0.00s)2392 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2393 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2394 --- PASS: TestGlobMatch/*bar_bar (0.00s)2395 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2396 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2397 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2398 --- PASS: TestGlobMatch/?oo_foo (0.00s)2399 --- PASS: TestGlobMatch/fo?_fo (0.00s)2400 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2401 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2402 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2403 --- PASS: TestGlobMatch/*/*_foo (0.00s)2404 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2405 --- PASS: TestGlobMatch/*_ (0.00s)2406 --- PASS: TestGlobMatch/foo*_bar (0.00s)2407 --- PASS: TestGlobMatch/*_anything (0.00s)2408 --- PASS: TestGlobMatch/foo_bar (0.00s)2409 --- PASS: TestGlobMatch/foo*_foo (0.00s)24102026/09/24 18:05:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39891/oidc2411--- PASS: TestValidateToken_Expired (0.03s)24122026/09/24 18:05:38 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12324132026/09/24 18:05:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45113/oidc24142026/09/24 18:05:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35101/oidc2415--- PASS: TestValidateToken_ValidToken (0.04s)2416--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.04s)2417--- PASS: TestScopes_Rules (0.05s)24182026/09/24 18:05:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41433/oidc2419--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.07s)24202026/09/24 18:05:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33867/oidc24212026/09/24 18:05:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45155/oidc2422--- PASS: TestPins_TopLevelShorthand (0.08s)2423--- PASS: TestValidateToken_BoundClaimsMismatch (0.09s)24242026/09/24 18:05:38 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:457432425--- PASS: TestValidateToken_KubernetesServiceAccount (0.10s)24262026/09/24 18:05:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33455/oidc2427--- PASS: TestValidateToken_BoundSubjectMismatch (0.11s)24282026/09/24 18:05:38 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46179/oidc2429--- PASS: TestValidateToken_NoMatchingProvider (0.12s)24302026/09/24 18:05:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40083/oidc24312026/09/24 18:05:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37995/oidc2432--- PASS: TestValidateToken_WrongAudience (0.14s)2433--- PASS: TestPins_ReservedForMatchingRule (0.13s)24342026/09/24 18:05:38 http: TLS handshake error from 127.0.0.1:33066: remote error: tls: bad certificate2435--- PASS: TestNewValidator_KubernetesRequiresCA (0.16s)2436--- PASS: TestHTTPClientForHasTimeouts (0.20s)24372026/09/24 18:05:38 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:44649/oidc24382026/09/24 18:05:38 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:45373/oidc2439--- PASS: TestValidateToken_MultipleProviders (0.23s)2440PASS2441Running signing tests...2442=== RUN TestGenerateFingerprint2443=== PAUSE TestGenerateFingerprint2444=== RUN TestParseSigningKey2445=== PAUSE TestParseSigningKey2446=== RUN TestSignMessage2447=== PAUSE TestSignMessage2448=== RUN TestSignNarinfo2449=== PAUSE TestSignNarinfo2450=== CONT TestGenerateFingerprint2451=== RUN TestGenerateFingerprint/basic_with_references2452=== CONT TestSignNarinfo2453=== CONT TestSignMessage2454=== PAUSE TestGenerateFingerprint/basic_with_references2455=== CONT TestParseSigningKey2456=== RUN TestParseSigningKey/valid_32-byte_key2457=== RUN TestGenerateFingerprint/no_references2458=== PAUSE TestParseSigningKey/valid_32-byte_key2459=== PAUSE TestGenerateFingerprint/no_references2460=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2461=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2462=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2463=== RUN TestParseSigningKey/no_colon2464=== PAUSE TestParseSigningKey/no_colon2465=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2466=== RUN TestParseSigningKey/empty_name2467=== PAUSE TestParseSigningKey/empty_name2468=== RUN TestParseSigningKey/invalid_base642469=== PAUSE TestParseSigningKey/invalid_base642470=== RUN TestParseSigningKey/wrong_length2471=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2472=== PAUSE TestParseSigningKey/wrong_length2473=== CONT TestParseSigningKey/valid_32-byte_key2474=== CONT TestParseSigningKey/invalid_base642475=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2476=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2477=== CONT TestParseSigningKey/wrong_length2478=== RUN TestGenerateFingerprint/invalid_nar_hash_length2479=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2480=== RUN TestGenerateFingerprint/invalid_store_path_prefix2481=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2482=== CONT TestParseSigningKey/empty_name2483=== CONT TestParseSigningKey/no_colon2484=== RUN TestGenerateFingerprint/invalid_reference_prefix2485--- PASS: TestParseSigningKey (0.00s)2486 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2487 --- PASS: TestParseSigningKey/wrong_length (0.00s)2488 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2489 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2490 --- PASS: TestParseSigningKey/no_colon (0.00s)2491 --- PASS: TestParseSigningKey/empty_name (0.00s)2492=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2493=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2494=== CONT TestGenerateFingerprint/invalid_store_path_prefix2495=== CONT TestGenerateFingerprint/invalid_nar_hash_length2496=== CONT TestGenerateFingerprint/invalid_reference_prefix2497=== CONT TestGenerateFingerprint/no_references2498--- PASS: TestSignMessage (0.00s)2499=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2500=== CONT TestGenerateFingerprint/basic_with_references2501--- PASS: TestGenerateFingerprint (0.00s)2502 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2503 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2504 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2505 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2506 --- PASS: TestGenerateFingerprint/no_references (0.00s)2507 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2508 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2509--- PASS: TestSignNarinfo (0.01s)2510PASS2511Running hook tests...2512=== RUN TestSendPathsEmpty2513=== PAUSE TestSendPathsEmpty2514=== RUN TestQueueEnqueueAndFetch2515=== PAUSE TestQueueEnqueueAndFetch2516=== RUN TestQueueDeduplication2517=== PAUSE TestQueueDeduplication2518=== RUN TestQueueRemove2519=== PAUSE TestQueueRemove2520=== RUN TestQueueFetchBatchLimit2521=== PAUSE TestQueueFetchBatchLimit2522=== RUN TestQueueRetryMovesToBack2523=== PAUSE TestQueueRetryMovesToBack2524=== RUN TestQueueFetchRemoveLifecycle2525=== PAUSE TestQueueFetchRemoveLifecycle2526=== RUN TestQueueConcurrentWriters2527=== PAUSE TestQueueConcurrentWriters2528=== RUN TestQueueEnqueueWaitsOutSlowWriter2529=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2530=== RUN TestQueueRemoveLargeClosure2531=== PAUSE TestQueueRemoveLargeClosure2532=== RUN TestServerClientIntegration2533=== PAUSE TestServerClientIntegration2534=== RUN TestServerQueueError2535=== PAUSE TestServerQueueError2536=== RUN TestServerRefusesOversizedAndNonStoreRequests2537=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2538=== RUN TestGetListenerSocketActivation2539 server_test.go:317: === RUN TestGetListenerSocketActivation2540 --- PASS: TestGetListenerSocketActivation (0.00s)2541 PASS2542 2543--- PASS: TestGetListenerSocketActivation (1.02s)2544=== RUN TestServerStalledClientDoesNotBlockShutdown2545=== PAUSE TestServerStalledClientDoesNotBlockShutdown2546=== RUN TestServerBacksOffOnAcceptErrors2547=== PAUSE TestServerBacksOffOnAcceptErrors2548=== RUN TestDrainIsolatesPoisonPath2549=== PAUSE TestDrainIsolatesPoisonPath2550=== RUN TestRunNotBlockedByPoisonHead2551=== PAUSE TestRunNotBlockedByPoisonHead2552=== RUN TestDrainGivesUpWhenServerDown2553=== PAUSE TestDrainGivesUpWhenServerDown2554=== RUN TestFailedPathPrunedByLaterClosure2555=== PAUSE TestFailedPathPrunedByLaterClosure2556=== RUN TestWorkerUploadsAndRemoves2557=== PAUSE TestWorkerUploadsAndRemoves2558=== RUN TestWorkerSkipsGCdPaths2559=== PAUSE TestWorkerSkipsGCdPaths2560=== RUN TestWorkerPrunesClosureDeps2561=== PAUSE TestWorkerPrunesClosureDeps2562=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2563=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2564=== RUN TestDrainTimeout2565=== PAUSE TestDrainTimeout2566=== RUN TestDrainTimeoutDuringIsolation2567=== PAUSE TestDrainTimeoutDuringIsolation2568=== RUN TestShutdownFinishesInFlightPush2569=== PAUSE TestShutdownFinishesInFlightPush2570=== RUN TestWorkerRemoveFailureIsNotProgress2571=== PAUSE TestWorkerRemoveFailureIsNotProgress2572=== RUN TestWorkerKeepsPathItCannotStat2573=== PAUSE TestWorkerKeepsPathItCannotStat2574=== CONT TestSendPathsEmpty2575=== CONT TestServerBacksOffOnAcceptErrors2576=== CONT TestQueueFetchRemoveLifecycle2577=== CONT TestServerStalledClientDoesNotBlockShutdown25782026/09/24 18:05:41 ERROR Accept failed error="too many open files"2579=== CONT TestServerRefusesOversizedAndNonStoreRequests2580=== CONT TestServerQueueError2581=== CONT TestServerClientIntegration2582=== CONT TestQueueRemoveLargeClosure25832026/09/24 18:05:41 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2584=== CONT TestQueueConcurrentWriters25852026/09/24 18:05:41 ERROR Failed to queue paths error="permission denied" count=12586=== CONT TestWorkerSkipsGCdPaths25872026/09/24 18:05:41 ERROR Refusing path outside the store path=/nix/store store=/nix/store2588=== CONT TestWorkerKeepsPathItCannotStat2589=== CONT TestShutdownFinishesInFlightPush2590=== CONT TestWorkerRemoveFailureIsNotProgress2591=== CONT TestDrainTimeoutDuringIsolation2592=== CONT TestDrainTimeout2593=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2594=== CONT TestQueueRemove2595=== CONT TestQueueRetryMovesToBack2596=== CONT TestDrainGivesUpWhenServerDown25972026/09/24 18:05:41 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store2598=== CONT TestQueueEnqueueWaitsOutSlowWriter2599=== CONT TestQueueDeduplication2600=== CONT TestQueueFetchBatchLimit2601=== CONT TestQueueEnqueueAndFetch2602=== CONT TestWorkerPrunesClosureDeps2603=== CONT TestWorkerUploadsAndRemoves2604=== CONT TestFailedPathPrunedByLaterClosure2605--- PASS: TestSendPathsEmpty (0.00s)2606=== CONT TestDrainIsolatesPoisonPath2607=== RUN TestShutdownFinishesInFlightPush/completes2608=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2609=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path26102026/09/24 18:05:41 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store2611=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2612=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2613--- PASS: TestServerQueueError (0.00s)2614=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2615--- PASS: TestServerClientIntegration (0.00s)2616=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline26172026/09/24 18:05:41 ERROR Accept failed error="too many open files"2618=== PAUSE TestShutdownFinishesInFlightPush/completes26192026/09/24 18:05:41 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store2620=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2621=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2622=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2623=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2624=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2625=== CONT TestRunNotBlockedByPoisonHead2626=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short2627=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2628=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline26292026/09/24 18:05:41 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26302026/09/24 18:05:41 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26312026/09/24 18:05:41 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store26322026/09/24 18:05:41 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store26332026/09/24 18:05:41 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store26342026/09/24 18:05:41 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store26352026/09/24 18:05:41 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store26362026/09/24 18:05:41 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store26372026/09/24 18:05:41 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store26382026/09/24 18:05:41 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store26392026/09/24 18:05:41 ERROR Accept failed error="too many open files"26402026/09/24 18:05:41 ERROR Failed to decode request error="unexpected EOF"2641--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.02s)2642=== CONT TestShutdownFinishesInFlightPush/completes26432026/09/24 18:05:41 ERROR Accept failed error="too many open files"26442026/09/24 18:05:41 INFO Upload queue status pending=326452026/09/24 18:05:41 INFO Upload queue status pending=226462026/09/24 18:05:41 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3304602685/002/nonexistent26472026/09/24 18:05:41 INFO Uploading batch count=226482026/09/24 18:05:41 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2814123384/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2814123384/002/locked/aaa: permission denied"26492026/09/24 18:05:41 INFO Uploading batch count=426502026/09/24 18:05:41 ERROR Upload failed error="upload failed" count=426512026/09/24 18:05:41 INFO Uploading batch count=226522026/09/24 18:05:41 INFO Upload queue status pending=226532026/09/24 18:05:41 INFO Uploading batch count=226542026/09/24 18:05:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2054478250/002/bbb26552026/09/24 18:05:41 INFO Upload queue status pending=226562026/09/24 18:05:41 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2814123384/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2814123384/002/locked/aaa: permission denied"26572026/09/24 18:05:41 INFO Uploading batch count=226582026/09/24 18:05:41 INFO Upload queue status pending=326592026/09/24 18:05:41 INFO Uploading batch count=126602026/09/24 18:05:41 ERROR Accept failed error="too many open files"26612026/09/24 18:05:41 INFO Uploading batch count=126622026/09/24 18:05:41 INFO Uploading batch count=226632026/09/24 18:05:41 ERROR Upload failed error="upload failed" count=126642026/09/24 18:05:41 ERROR Upload failed error="upload failed" count=226652026/09/24 18:05:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3355823646/002/a2666--- PASS: TestQueueFetchBatchLimit (0.07s)26672026/09/24 18:05:41 INFO Upload queue status pending=22668=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout26692026/09/24 18:05:41 INFO Uploading batch count=126702026/09/24 18:05:41 ERROR Upload failed error="upload failed" count=126712026/09/24 18:05:41 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2814123384/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2814123384/002/locked/aaa: permission denied"26722026/09/24 18:05:41 INFO Uploading batch count=426732026/09/24 18:05:41 ERROR Upload failed error="upload failed" count=426742026/09/24 18:05:41 INFO Uploading batch count=226752026/09/24 18:05:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3355823646/002/b2676--- PASS: TestQueueRetryMovesToBack (0.08s)26772026/09/24 18:05:41 INFO Uploading batch count=42678=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path26792026/09/24 18:05:41 ERROR Upload failed error="upload failed" count=426802026/09/24 18:05:41 INFO Uploading batch count=126812026/09/24 18:05:41 ERROR Upload failed error="upload failed" count=126822026/09/24 18:05:41 ERROR Drain finished with paths left in queue remaining=126832026/09/24 18:05:41 INFO Uploading batch count=12684--- PASS: TestWorkerSkipsGCdPaths (0.09s)2685=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths26862026/09/24 18:05:41 INFO Uploading batch count=126872026/09/24 18:05:41 ERROR Upload failed error="upload failed" count=126882026/09/24 18:05:41 INFO Uploading batch count=226892026/09/24 18:05:41 ERROR Upload failed error="upload failed" count=226902026/09/24 18:05:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3355823646/002/c2691=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch2692--- PASS: TestQueueEnqueueAndFetch (0.09s)2693--- PASS: TestQueueRemove (0.09s)2694--- PASS: TestWorkerKeepsPathItCannotStat (0.09s)2695--- PASS: TestQueueDeduplication (0.09s)26962026/09/24 18:05:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3355823646/002/d2697--- PASS: TestWorkerUploadsAndRemoves (0.09s)26982026/09/24 18:05:41 INFO Uploading batch count=12699--- PASS: TestQueueFetchRemoveLifecycle (0.10s)27002026/09/24 18:05:41 INFO Uploading batch count=127012026/09/24 18:05:41 ERROR Upload failed error="upload failed" count=12702--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.09s)27032026/09/24 18:05:41 ERROR Drain finished with paths left in queue remaining=127042026/09/24 18:05:41 INFO Uploading batch count=227052026/09/24 18:05:41 ERROR Upload failed error="upload failed" count=227062026/09/24 18:05:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3355823646/002/e2707--- PASS: TestWorkerPrunesClosureDeps (0.10s)27082026/09/24 18:05:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3355823646/002/f2709--- PASS: TestFailedPathPrunedByLaterClosure (0.10s)27102026/09/24 18:05:41 ERROR Drain finished with paths left in queue remaining=102711--- PASS: TestDrainIsolatesPoisonPath (0.10s)27122026/09/24 18:05:41 INFO Upload queue status pending=227132026/09/24 18:05:41 INFO Uploading batch count=22714--- PASS: TestDrainGivesUpWhenServerDown (0.11s)27152026/09/24 18:05:41 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path2314609625/001/nonexistent27162026/09/24 18:05:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127172026/09/24 18:05:41 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path2314609625/001/nonexistent27182026/09/24 18:05:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127192026/09/24 18:05:41 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path2314609625/001/nonexistent27202026/09/24 18:05:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127212026/09/24 18:05:41 INFO Uploading batch count=227222026/09/24 18:05:41 ERROR Drain finished with paths left in queue remaining=127232026/09/24 18:05:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227242026/09/24 18:05:41 INFO Uploading batch count=227252026/09/24 18:05:41 ERROR Upload failed error="upload failed" count=227262026/09/24 18:05:41 INFO Uploading batch count=227272026/09/24 18:05:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127282026/09/24 18:05:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227292026/09/24 18:05:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127302026/09/24 18:05:41 INFO Uploading batch count=227312026/09/24 18:05:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227322026/09/24 18:05:41 INFO Uploading batch count=227332026/09/24 18:05:41 ERROR Upload failed error="upload failed" count=227342026/09/24 18:05:41 ERROR Drain finished with paths left in queue remaining=227352026/09/24 18:05:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127362026/09/24 18:05:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127372026/09/24 18:05:41 INFO Uploading batch count=227382026/09/24 18:05:41 ERROR Upload failed error="upload failed" count=227392026/09/24 18:05:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127402026/09/24 18:05:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127412026/09/24 18:05:41 ERROR Drain finished with paths left in queue remaining=22742--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2743 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.04s)2744 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.04s)2745 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.05s)27462026/09/24 18:05:41 ERROR Accept failed error="too many open files"27472026/09/24 18:05:41 ERROR Failed to decode request error="read unix /build/hook900945269/test.sock->@: i/o timeout"27482026/09/24 18:05:41 ERROR Failed to write response error="write unix /build/hook900945269/test.sock->@: i/o timeout"2749--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)27502026/09/24 18:05:41 ERROR Upload failed error="context canceled" count=227512026/09/24 18:05:41 ERROR Drain finished with paths left in queue remaining=42752--- PASS: TestDrainTimeout (0.27s)27532026/09/24 18:05:41 ERROR Drain finished with paths left in queue remaining=427542026/09/24 18:05:41 ERROR Upload failed error="context canceled" count=227552026/09/24 18:05:41 ERROR Drain finished with paths left in queue remaining=22756--- PASS: TestShutdownFinishesInFlightPush (0.00s)2757 --- PASS: TestShutdownFinishesInFlightPush/completes (0.17s)2758 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.24s)27592026/09/24 18:05:41 ERROR Accept failed error="too many open files"27602026/09/24 18:05:41 ERROR Drain finished with paths left in queue remaining=32761--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2762 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.28s)2763 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.38s)27642026/09/24 18:05:42 ERROR Accept failed error="too many open files"2765--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)2766--- PASS: TestQueueConcurrentWriters (0.71s)27672026/09/24 18:05:42 INFO Uploading batch count=127682026/09/24 18:05:42 INFO Uploading batch count=127692026/09/24 18:05:42 INFO Uploading batch count=127702026/09/24 18:05:42 ERROR Upload failed error="upload failed" count=127712026/09/24 18:05:42 INFO Uploading batch count=127722026/09/24 18:05:42 ERROR Upload failed error="upload failed" count=127732026/09/24 18:05:42 INFO Uploading batch count=127742026/09/24 18:05:42 ERROR Upload failed error="upload failed" count=127752026/09/24 18:05:42 INFO Uploading batch count=127762026/09/24 18:05:42 ERROR Upload failed error="upload failed" count=127772026/09/24 18:05:42 ERROR Drain finished with paths left in queue remaining=12778--- PASS: TestRunNotBlockedByPoisonHead (1.10s)2779--- PASS: TestQueueRemoveLargeClosure (2.10s)2780--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.07s)2781PASS2782Running niks3-hook command tests...2783=== RUN TestServeSecondSignalEndsDrain2784=== PAUSE TestServeSecondSignalEndsDrain2785=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown2786=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown2787=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown2788=== CONT TestServeSecondSignalEndsDrain2789--- PASS: TestServeSecondSignalEndsDrain (0.08s)27902026/09/24 18:05:48 INFO Upload queue status pending=127912026/09/24 18:05:48 INFO Uploading batch count=12792--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.13s)2793PASS2794Running rate limiter tests...2795=== RUN TestAdaptiveRateLimiter_ThreadSafety2796=== PAUSE TestAdaptiveRateLimiter_ThreadSafety2797=== CONT TestAdaptiveRateLimiter_ThreadSafety27982026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=112.7357000000000727992026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=78.9149900000000528002026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=55.2404930000000328012026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=38.6683451000000228022026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=27.0678415700000128032026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=18.94748909900000628042026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=13.26324236930000428052026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=9.28426965851000228062026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=6.49898876095700128072026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528082026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528092026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528102026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528112026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528122026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528132026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528142026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528152026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528162026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528172026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528182026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528192026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528202026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528212026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528222026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528232026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528242026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528252026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528262026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528272026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528282026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528292026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528302026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528312026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528322026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528332026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528342026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528352026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528362026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528372026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528382026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528392026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528402026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528412026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528422026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528432026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528442026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528452026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528462026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528472026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528482026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528492026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528502026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528512026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528522026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528532026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528542026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528552026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528562026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528572026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528582026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528592026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528602026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528612026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528622026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528632026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528642026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528652026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528662026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528672026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528682026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528692026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528702026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528712026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=5.12435000000000128722026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528732026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528742026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528752026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528762026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528772026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528782026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528792026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528802026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=6.82050985000000228812026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528822026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528832026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528842026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528852026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528862026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=5.12435000000000128872026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528882026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528892026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528902026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528912026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528922026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528932026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528942026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528952026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528962026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=528972026/09/24 18:05:49 WARN Rate limiter backed off name=test rate=6.20046350000000152898--- PASS: TestAdaptiveRateLimiter_ThreadSafety (3.61s)2899PASS