niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #342
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure18=== PAUSE TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure19=== RUN TestUploadMultipart_PartsInParallel20=== PAUSE TestUploadMultipart_PartsInParallel21=== RUN TestUploadMultipart_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.03s)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 122 of 32768000 bytes45--- PASS: TestDumpPathWriterErrorStopsReading (0.60s)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 TestSetClientTLSDoesNotMutateDefaultTransport129=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure130=== CONT TestSetClientTLS131=== CONT TestSupersededNARStillUploadsListing132=== CONT TestStreamPushStopsOnCancel133=== CONT TestScriptTokenNoExpiryRerunsEveryCall134=== CONT TestSetClientTLSErrors135=== CONT TestScriptTokenDoesNotWaitForItsChildren136=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs137=== CONT TestStreamPushReportsSignatures138=== CONT TestScriptTokenEmptyToken139=== CONT TestScriptTokenEmptyCommand140=== CONT TestScriptTokenCachesUntilRefresh141=== CONT TestStreamPushIsolatesFailures142=== CONT TestFileTokenMissing143=== CONT TestStaticToken144=== CONT TestUploadMultipart_FailedPartBufferNotReused145=== CONT TestUploadMultipart_SupersededByPeer146=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica147=== RUN TestUploadMultipart_SupersededByPeer/exists148=== CONT TestGetStorePathHash149=== RUN TestGetStorePathHash/valid_store_path150=== CONT TestConvertHashToNix32151=== RUN TestConvertHashToNix32/SRI_format_to_Nix32152=== CONT TestPathInfoCACompatibility153=== CONT TestShellSplit154=== CONT TestRegisterUploadedObjectReusesConnections155=== CONT TestFilterOversizedClosures156=== RUN TestSupersededNARStillUploadsListing/small_NAR157=== RUN TestStreamPushStopsOnCancel/waiting_for_input158=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs159--- PASS: TestScriptTokenEmptyCommand (0.00s)160=== CONT TestDoServerRequestAttachesToken161=== CONT TestRateLimiterFeedback162=== PAUSE TestUploadMultipart_SupersededByPeer/exists163=== CONT TestUploadMultipart_PartsInParallel164=== PAUSE TestGetStorePathHash/valid_store_path165=== RUN TestPathInfoCACompatibility/null_ca_field166=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32167=== RUN TestSetClientTLSErrors/missing_cert_file168=== CONT TestFileTokenEmpty169=== RUN TestRateLimiterFeedback/429_enables_limiter170=== RUN TestUploadMultipart_SupersededByPeer/missing171=== RUN TestConvertHashToNix32/already_Nix32_format172=== PAUSE TestSetClientTLSErrors/missing_cert_file173=== CONT TestStreamPushRequestLine174=== RUN TestFilterOversizedClosures/no_limit_keeps_everything175=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout176=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything177=== PAUSE TestSupersededNARStillUploadsListing/small_NAR178=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input179=== RUN TestGetStorePathHash/basename_without_hyphen_should_error180=== PAUSE TestPathInfoCACompatibility/null_ca_field181=== CONT TestClientSignaturesByStorePath182--- PASS: TestStaticToken (0.00s)183=== PAUSE TestRateLimiterFeedback/429_enables_limiter184=== CONT TestEncodeNixBase32185=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout186--- PASS: TestFileTokenMissing (0.00s)187=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error188=== RUN TestSupersededNARStillUploadsListing/dump_cut_short189=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot190=== RUN TestPathInfoCACompatibility/old_string_format_-_text191=== CONT TestEncodeNixBase32WithRealHash192=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot193=== CONT TestScriptTokenBadJSON194=== RUN TestRateLimiterFeedback/503_enables_limiter195=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot196=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text197=== CONT TestScriptTokenScriptFails198=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive199=== PAUSE TestRateLimiterFeedback/503_enables_limiter200=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter201=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot202=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive203=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter204=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped205=== RUN TestPathInfoCACompatibility/new_structured_format_-_text206=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot207=== CONT TestUploadMultipart_ProducerErrorIsNotEOF208=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot209=== CONT TestDumpPathWriterError210--- PASS: TestClientSignaturesByStorePath (0.00s)211=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error212=== RUN TestEncodeNixBase32/test_string_hash213=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter214=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text215=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short216=== PAUSE TestEncodeNixBase32/test_string_hash217=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error218=== PAUSE TestConvertHashToNix32/already_Nix32_format219=== RUN TestConvertHashToNix32/invalid_format220=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error221=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot222--- PASS: TestStreamPushIsolatesFailures (0.00s)223=== RUN TestSetClientTLSErrors/missing_key_file224=== PAUSE TestUploadMultipart_SupersededByPeer/missing225=== CONT TestResolveStorePath226=== PAUSE TestSetClientTLSErrors/missing_key_file227=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part228=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter229=== RUN TestSetClientTLSErrors/missing_ca_file230=== PAUSE TestSetClientTLSErrors/missing_ca_file231=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part232=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary233=== CONT TestTruncatedNARDumpIsNotCompleted234=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary235=== CONT TestParsePathInfoJSON236=== RUN TestParsePathInfoJSON/Nix_format237=== CONT TestStreamPushReportsEveryPath238=== PAUSE TestParsePathInfoJSON/Nix_format239=== RUN TestEncodeNixBase32/empty_input240=== RUN TestParsePathInfoJSON/Lix_format241=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped242=== PAUSE TestConvertHashToNix32/invalid_format243=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error244--- PASS: TestShellSplit (0.00s)245=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot246=== CONT TestPartSizeForNAR247=== CONT TestDumpPathSingleFile248=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method249=== CONT TestStreamPushBatchesUnderLoad250=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails251=== RUN TestSetClientTLS/rejects_connection_without_client_cert252=== PAUSE TestEncodeNixBase32/empty_input253=== CONT TestStreamPushGivesUpOnDeadServer254=== CONT TestShellSplitErrors255=== PAUSE TestParsePathInfoJSON/Lix_format256=== RUN TestFilterOversizedClosures/all_closures_skipped257=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess258--- PASS: TestStreamPushReportsSignatures (0.01s)259=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken260=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent261=== RUN TestPartSizeForNAR/zero_stays_at_minimum262=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method263=== CONT TestDoWithRetry_FinalResponseBodyReadable264=== RUN TestStreamPushBatchesUnderLoad/together265=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails266=== CONT TestPathInfoHashCompatibility267=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert268=== CONT TestDoWithRetry_BodyReplayedViaGetBody269=== PAUSE TestFilterOversizedClosures/all_closures_skipped270=== RUN TestParsePathInfoJSON/empty_input271=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer272--- PASS: TestScriptTokenEmptyToken (0.01s)273=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier274=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken275=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum276=== PAUSE TestStreamPushBatchesUnderLoad/together277=== CONT TestCaseHackSuffix278=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)279=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA280=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun281=== CONT TestFileTokenReadsAndCaches282=== PAUSE TestParsePathInfoJSON/empty_input283--- PASS: TestFileTokenEmpty (0.00s)284=== RUN TestPartSizeForNAR/small_stays_at_minimum285=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry286=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier287=== CONT TestDumpPathMatchesNix288=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)289=== CONT TestParsePathInfoJSONMultiplePaths290=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon291=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time292=== CONT TestCompletePendingClosure_NotFoundWithoutKey293=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time294=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout295=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths296=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths297=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths298=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths299=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs300=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA301=== RUN TestSetClientTLS/preserves_debug_logging_transport302--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)303--- PASS: TestEncodeNixBase32WithRealHash (0.00s)304--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)305=== PAUSE TestSetClientTLS/preserves_debug_logging_transport306=== RUN TestParsePathInfoJSON/whitespace_only307--- PASS: TestDoServerRequestAttachesToken (0.00s)308=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up309=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon310=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI311--- PASS: TestScriptTokenScriptFails (0.00s)312--- PASS: TestResolveStorePath (0.00s)313=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI314=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512315=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up316=== PAUSE TestPartSizeForNAR/small_stays_at_minimum317=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter318=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum319--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)320=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum321=== PAUSE TestParsePathInfoJSON/whitespace_only322--- PASS: TestScriptTokenBadJSON (0.00s)323=== RUN TestParsePathInfoJSON/invalid_JSON324=== PAUSE TestParsePathInfoJSON/invalid_JSON325=== CONT TestUploadMultipart_SupersededByPeer/exists326--- PASS: TestStreamPushReportsEveryPath (0.00s)327=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512328--- PASS: TestShellSplitErrors (0.00s)329--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.02s)330--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)331=== CONT TestRateLimiterFeedback/429_enables_limiter332=== CONT TestUploadMultipart_SupersededByPeer/missing333=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts334=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part335=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts336=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary337=== RUN TestPartSizeForNAR/1_TiB338=== PAUSE TestPartSizeForNAR/1_TiB339=== RUN TestPartSizeForNAR/5_TiB_S3_max_object340=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object341=== RUN TestSetClientTLSErrors/invalid_ca_file342=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter343=== CONT TestRateLimiterFeedback/503_enables_limiter344--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)345=== RUN TestPartSizeForNAR/capped_at_5_GiB346=== PAUSE TestPartSizeForNAR/capped_at_5_GiB347=== CONT TestConvertHashToNix32/SRI_format_to_Nix32348=== CONT TestConvertHashToNix32/invalid_format349=== PAUSE TestSetClientTLSErrors/invalid_ca_file350=== CONT TestConvertHashToNix32/already_Nix32_format351=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error352=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error353=== CONT TestGetStorePathHash/basename_without_hyphen_should_error354=== CONT TestGetStorePathHash/valid_store_path355--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)356=== CONT TestEncodeNixBase32/empty_input357=== CONT TestPathInfoCACompatibility/null_ca_field358--- PASS: TestFileTokenReadsAndCaches (0.00s)359=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method360=== CONT TestPathInfoCACompatibility/new_structured_format_-_text361=== CONT TestEncodeNixBase32/test_string_hash362=== CONT TestPathInfoCACompatibility/old_string_format_-_text363=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive364=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails365=== CONT TestSupersededNARStillUploadsListing/dump_cut_short366--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.00s)367--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)368--- PASS: TestCaseHackSuffix (0.23s)369=== CONT TestFilterOversizedClosures/no_limit_keeps_everything370=== CONT TestSupersededNARStillUploadsListing/small_NAR371=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped372=== CONT TestFilterOversizedClosures/all_closures_skipped373--- PASS: TestDumpPathSingleFile (0.24s)374=== CONT TestStreamPushStopsOnCancel/waiting_for_input375=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken376=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot377=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot378--- PASS: TestConvertHashToNix32 (0.01s)379 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)380 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)381 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)382=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot383=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot384--- PASS: TestGetStorePathHash (0.01s)385 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)386 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)387 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)388 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)389--- PASS: TestEncodeNixBase32 (0.01s)390 --- PASS: TestEncodeNixBase32/empty_input (0.00s)391 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)392--- PASS: TestPathInfoCACompatibility (0.01s)393 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)394 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)395 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)396 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)397 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)398--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)399 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.23s)400 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.23s)401--- PASS: TestFilterOversizedClosures (0.02s)402 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)403 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)404 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)405--- PASS: TestRateLimiterFeedback (0.01s)406 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)407 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.23s)408 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)409 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)410--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.23s)411=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time412=== CONT TestStreamPushBatchesUnderLoad/together413=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths414--- PASS: TestStreamPushBatchesUnderLoad (0.01s)415 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)416 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)417=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths418=== CONT TestSetClientTLS/rejects_connection_without_client_cert419--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)420 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)421 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)422=== CONT TestSetClientTLS/preserves_debug_logging_transport423=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA424=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up425=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier426=== CONT TestParsePathInfoJSON/Nix_format427=== CONT TestParsePathInfoJSON/empty_input428=== CONT TestParsePathInfoJSON/whitespace_only429=== CONT TestParsePathInfoJSON/Lix_format430=== CONT TestParsePathInfoJSON/invalid_JSON431=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon432--- PASS: TestParsePathInfoJSON (0.02s)433 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)434 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)435 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)436 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)437 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)438=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512439=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI440=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)441=== CONT TestPartSizeForNAR/capped_at_5_GiB442--- PASS: TestPathInfoHashCompatibility (0.01s)443 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)444 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)445 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)446 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)447=== CONT TestPartSizeForNAR/5_TiB_S3_max_object448=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts449=== CONT TestPartSizeForNAR/1_TiB450=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum451--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.01s)452 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.00s)453 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.00s)454=== CONT TestPartSizeForNAR/small_stays_at_minimum455=== CONT TestPartSizeForNAR/zero_stays_at_minimum456=== CONT TestSetClientTLSErrors/missing_cert_file457=== CONT TestSetClientTLSErrors/invalid_ca_file458--- PASS: TestDumpPathWriterError (0.29s)459=== CONT TestSetClientTLSErrors/missing_ca_file460--- PASS: TestPartSizeForNAR (0.24s)461 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)462 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)463 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)464 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)465 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)466 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)467 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)468=== CONT TestSetClientTLSErrors/missing_key_file469--- PASS: TestSetClientTLSErrors (0.26s)470 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)471 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)472 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)473 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)474--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.30s)475--- PASS: TestStreamPushStopsOnCancel (0.03s)476 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.05s)477 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.05s)478 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)479 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.05s)480 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.05s)481 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.05s)482--- PASS: TestSetClientTLS (0.03s)483 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)484 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)485 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.35s)486--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.00s)487 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.59s)488 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.60s)489--- PASS: TestRegisterUploadedObjectReusesConnections (0.65s)490--- PASS: TestStreamPushRequestLine (0.67s)491--- PASS: TestDumpPathMatchesNix (0.66s)492--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)493--- PASS: TestSupersededNARStillUploadsListing (0.02s)494 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.01s)495 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.02s)496 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.11s)497--- PASS: TestTruncatedNARDumpIsNotCompleted (1.36s)498--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.42s)499--- PASS: TestUploadMultipart_PartsInParallel (1.43s)500--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (2.00s)501--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.01s)502 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.00s)503 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.22s)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/postgres129369186/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/postgres129369186/data -l logfile start532533/build/postgres129369186:5432 - no response5342026-10-01 10:34:02.494 UTC [168] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5352026-10-01 10:34:02.495 UTC [168] LOG: listening on Unix socket "/build/postgres129369186/.s.PGSQL.5432"5362026-10-01 10:34:02.499 UTC [175] LOG: database system was shut down at 2026-10-01 10:34:02 UTC5372026-10-01 10:34:02.502 UTC [168] LOG: database system is ready to accept connections538/build/postgres129369186:5432 - accepting connections539=== RUN TestService_AuthMiddleware540=== PAUSE TestService_AuthMiddleware541=== RUN TestService_AuthMiddleware_MTLSProxyHeader542=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader543=== RUN TestService_AuthMiddleware_MTLSBoundSubjects544=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects545=== RUN TestService_ReadAuthMiddleware546=== PAUSE TestService_ReadAuthMiddleware547=== RUN TestService_AuthMiddleware_OIDC548=== PAUSE TestService_AuthMiddleware_OIDC549=== RUN TestService_RequireScope_OIDC550=== PAUSE TestService_RequireScope_OIDC551=== RUN TestService_ReadScope_PublicByDefault552=== PAUSE TestService_ReadScope_PublicByDefault553=== RUN TestCacheConfigHandler554=== PAUSE TestCacheConfigHandler555=== RUN TestCacheStatsHandler556=== PAUSE TestCacheStatsHandler557=== RUN TestClientCADerivations558=== PAUSE TestClientCADerivations559=== RUN TestClientErrorHandling560=== PAUSE TestClientErrorHandling561=== RUN TestClientIntegration562=== PAUSE TestClientIntegration563=== RUN TestClientMultipleUploads564=== PAUSE TestClientMultipleUploads565=== RUN TestClientWithDependencies566=== PAUSE TestClientWithDependencies567=== RUN TestClientSharedPathCommittedMidPush568=== PAUSE TestClientSharedPathCommittedMidPush569=== RUN TestPinProtectsFromGC570=== PAUSE TestPinProtectsFromGC571=== RUN TestClientPushesUseOnePush572=== PAUSE TestClientPushesUseOnePush573=== RUN TestClientFallsBackToClosures574=== PAUSE TestClientFallsBackToClosures575=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock576=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock577=== RUN TestResolveDBConnectionString578=== PAUSE TestResolveDBConnectionString579=== RUN TestConnectWaitsForAPeerMigration580=== PAUSE TestConnectWaitsForAPeerMigration581=== RUN TestConnectSerialisesConcurrentMigrations582=== PAUSE TestConnectSerialisesConcurrentMigrations583=== RUN TestLeadElectsOneAndHandsOver584=== PAUSE TestLeadElectsOneAndHandsOver585=== RUN TestLeadIncumbentWinsAfterRestart5862026/10/01 10:34:02 INFO lead: acquired remote=192.0.2.1:12345872026/10/01 10:34:03 INFO lead: released remote=192.0.2.1:12345882026/10/01 10:34:04 INFO lead: acquired remote=192.0.2.1:12345892026/10/01 10:34:05 INFO lead: released remote=192.0.2.1:1234590--- PASS: TestLeadIncumbentWinsAfterRestart (2.31s)591=== RUN TestLeadEndsOnShutdown592=== PAUSE TestLeadEndsOnShutdown593=== RUN TestLeadEndsWhenItsConnectionHangs5942026/10/01 10:34:05 INFO lead: acquired remote=192.0.2.1:12345952026-10-01 10:34:06.440 UTC [424] FATAL: terminating connection due to administrator command5962026/10/01 10:34:06 INFO lead: acquired remote=192.0.2.1:12345972026/10/01 10:34:07 WARN lead: lock connection lost error="timeout: context deadline exceeded"5982026/10/01 10:34:07 INFO lead: released remote=192.0.2.1:12345992026/10/01 10:34:07 INFO lead: released remote=192.0.2.1:1234600--- PASS: TestLeadEndsWhenItsConnectionHangs (2.74s)601=== RUN TestGCAdvisoryLockBlocksConcurrentRun602=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun603=== RUN TestGCBugBareHashReferences604=== PAUSE TestGCBugBareHashReferences605=== RUN TestGCMetrics606=== PAUSE TestGCMetrics607=== RUN TestPushDedupSurvivesConcurrentGC608=== PAUSE TestPushDedupSurvivesConcurrentGC609=== RUN TestDeduplicatedObjectsRecordedAsPending610=== PAUSE TestDeduplicatedObjectsRecordedAsPending611=== RUN TestGCSweepSkipsPendingObjects612=== PAUSE TestGCSweepSkipsPendingObjects613=== RUN TestTombstonedObjectOfferedWithoutWaiting614=== PAUSE TestTombstonedObjectOfferedWithoutWaiting615=== RUN TestGCSweepDeliversEachKeyOnce616=== PAUSE TestGCSweepDeliversEachKeyOnce617=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection618=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection619=== RUN TestForceGCDuringPushOffersSweptObject620=== PAUSE TestForceGCDuringPushOffersSweptObject621=== RUN TestFailedS3DeleteKeepsTombstone622=== PAUSE TestFailedS3DeleteKeepsTombstone623=== RUN TestSweepSkipsRowsLockedByPush624=== PAUSE TestSweepSkipsRowsLockedByPush625=== RUN TestRegisterCompletedObjectNeedsPendingRow626=== PAUSE TestRegisterCompletedObjectNeedsPendingRow627=== RUN TestGetExistingObjectsLocksRows628=== PAUSE TestGetExistingObjectsLocksRows629=== RUN TestSweepRechecksPendingAfterLocking630=== PAUSE TestSweepRechecksPendingAfterLocking631=== RUN TestPushWaitsForSweepHoldingRow632=== PAUSE TestPushWaitsForSweepHoldingRow633=== RUN TestCommitRacingPendingCleanupKeepsObjects634=== PAUSE TestCommitRacingPendingCleanupKeepsObjects635=== RUN TestGCEndsOnShutdown636=== PAUSE TestGCEndsOnShutdown637=== RUN TestGCTaskStore_StartNew638=== PAUSE TestGCTaskStore_StartNew639=== RUN TestGCTaskStore_DeduplicateSameParams640=== PAUSE TestGCTaskStore_DeduplicateSameParams641=== RUN TestGCTaskStore_ConflictDifferentParams642=== PAUSE TestGCTaskStore_ConflictDifferentParams643=== RUN TestGCTaskStore_GetEmpty644=== PAUSE TestGCTaskStore_GetEmpty645=== RUN TestGCTaskStore_GetReturnsLatest646=== PAUSE TestGCTaskStore_GetReturnsLatest647=== RUN TestGCTaskStore_CompletedAllowsNewTask648=== PAUSE TestGCTaskStore_CompletedAllowsNewTask649=== RUN TestGCTaskStore_PhaseUpdates650=== PAUSE TestGCTaskStore_PhaseUpdates651=== RUN TestGCTaskStore_Fail652=== PAUSE TestGCTaskStore_Fail653=== RUN TestGracefulShutdownDrainsInflight654=== PAUSE TestGracefulShutdownDrainsInflight655=== RUN TestService_healthCheckHandler656=== PAUSE TestService_healthCheckHandler657=== RUN TestService_readinessHandler658=== PAUSE TestService_readinessHandler659=== RUN TestGenerateLandingPage660=== PAUSE TestGenerateLandingPage661=== RUN TestCacheConfigHandlerMaxNarSize662=== PAUSE TestCacheConfigHandlerMaxNarSize663=== RUN TestCreatePendingClosureRejectsOversizedNAR664=== PAUSE TestCreatePendingClosureRejectsOversizedNAR665=== RUN TestNARDeduplicationMetadataUploadBug666=== PAUSE TestNARDeduplicationMetadataUploadBug667=== RUN TestMetricsInventory668=== PAUSE TestMetricsInventory669=== RUN TestService_NativeMTLS670=== PAUSE TestService_NativeMTLS671=== RUN TestServerTLSConfig672=== PAUSE TestServerTLSConfig673=== RUN TestMultipartCleanup674=== PAUSE TestMultipartCleanup675=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded676=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded677=== RUN TestPendingCleanupUsesOneCutoff678=== PAUSE TestPendingCleanupUsesOneCutoff679=== RUN TestPendingClosureFailureTracksEveryUpload680=== PAUSE TestPendingClosureFailureTracksEveryUpload681=== RUN TestPendingClosureFailureAbortsItsUploads682=== PAUSE TestPendingClosureFailureAbortsItsUploads683=== RUN TestObjectStatsTrigger684=== PAUSE TestObjectStatsTrigger685=== RUN TestReconnectLeavesObjectsUnlocked686=== PAUSE TestReconnectLeavesObjectsUnlocked687=== RUN TestOrphanedObjectsGC688=== PAUSE TestOrphanedObjectsGC689=== RUN TestOrphanedObjectsGCStressTest690=== PAUSE TestOrphanedObjectsGCStressTest691=== RUN TestCreatePin_ReservedPins692=== PAUSE TestCreatePin_ReservedPins693=== RUN TestConcurrentPinUpdatesAgree694=== PAUSE TestConcurrentPinUpdatesAgree695=== RUN TestCreatePinRejectsBadInput696=== PAUSE TestCreatePinRejectsBadInput697=== RUN TestDeletePinKeepsRowWhenS3Fails698=== PAUSE TestDeletePinKeepsRowWhenS3Fails699=== RUN TestPresentReportsOnlyClosureRoots700=== PAUSE TestPresentReportsOnlyClosureRoots701=== RUN TestPresentNotReportedWhileGCDeletesClosure702=== PAUSE TestPresentNotReportedWhileGCDeletesClosure703=== RUN TestParseSingleRange704=== PAUSE TestParseSingleRange705=== RUN TestProxyHeadersOnlyTrustedOnSocket706=== PAUSE TestProxyHeadersOnlyTrustedOnSocket707=== RUN TestIsValidCachePath708=== PAUSE TestIsValidCachePath709=== RUN TestReadProxyNarinfo710=== PAUSE TestReadProxyNarinfo711=== RUN TestReadProxyNarinfoAlreadyDecompressed712=== PAUSE TestReadProxyNarinfoAlreadyDecompressed713=== RUN TestReadProxyNarStreaming714=== PAUSE TestReadProxyNarStreaming715=== RUN TestReadProxy404716=== PAUSE TestReadProxy404717=== RUN TestReadProxyInvalidPath718=== PAUSE TestReadProxyInvalidPath719=== RUN TestReadProxyHead720=== PAUSE TestReadProxyHead721=== RUN TestReadProxyOutlastsServerWriteTimeout722=== PAUSE TestReadProxyOutlastsServerWriteTimeout723=== RUN TestReadProxyConditionalGet724=== PAUSE TestReadProxyConditionalGet725=== RUN TestReadProxyRootRedirectsToIndexHTML726=== PAUSE TestReadProxyRootRedirectsToIndexHTML727=== RUN TestReadProxyDisabled728=== PAUSE TestReadProxyDisabled729=== RUN TestReadRedirectNar730=== PAUSE TestReadRedirectNar731=== RUN TestReadRedirectKeepsNarinfoProxied732=== PAUSE TestReadRedirectKeepsNarinfoProxied733=== RUN TestReadProxyRangeRequest734=== PAUSE TestReadProxyRangeRequest735=== RUN TestReadRedirectUsesPublicS3URL736=== PAUSE TestReadRedirectUsesPublicS3URL737=== RUN TestPush_OverlappingRootsStoreOneRowPerKey738=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey739=== RUN TestPush_CompleteCommitsEveryRoot740=== PAUSE TestPush_CompleteCommitsEveryRoot741=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit742=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit743=== RUN TestPush_RejectsBadRequests744=== PAUSE TestPush_RejectsBadRequests745=== RUN TestPush_SignsNarinfosOfItsPendingObjects746=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects747=== RUN TestRedundantMultipartUpload748=== PAUSE TestRedundantMultipartUpload749=== RUN TestCompleteMultipartUpload_ErrorButObjectExists750=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists751=== RUN TestCompletedNarNotReofferedAcrossClosures752=== PAUSE TestCompletedNarNotReofferedAcrossClosures753=== RUN TestPresignedUploadRegisteredBeforeCommit754=== PAUSE TestPresignedUploadRegisteredBeforeCommit755=== RUN TestService_Rustfstest756=== PAUSE TestService_Rustfstest757=== RUN TestParseSize758=== PAUSE TestParseSize759=== RUN TestSkippedUploadsHandler760=== PAUSE TestSkippedUploadsHandler761=== RUN TestSystemdListenerNotActivated762--- PASS: TestSystemdListenerNotActivated (0.00s)763=== RUN TestWatchdogBeatsWhenHealthy764--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)765=== RUN TestWatchdogSkipsWhenUnhealthy7662026/10/01 10:34:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7672026/10/01 10:34:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7682026/10/01 10:34:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/10/01 10:34:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/10/01 10:34:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/10/01 10:34:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/10/01 10:34:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/10/01 10:34:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/10/01 10:34:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7752026/10/01 10:34:08 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"776--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)777=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle778=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle779=== RUN TestProxyWriteTimeout780=== PAUSE TestProxyWriteTimeout781=== RUN TestPendingClosureWriteTimeout782=== PAUSE TestPendingClosureWriteTimeout783=== RUN TestIsValidUploadKey784=== PAUSE TestIsValidUploadKey785=== RUN TestUploadHandlersRejectInvalidKeys786=== PAUSE TestUploadHandlersRejectInvalidKeys787=== RUN TestUploadHandlersRejectOversizedBody788=== PAUSE TestUploadHandlersRejectOversizedBody789=== RUN TestService_cleanupPendingClosuresHandler790=== PAUSE TestService_cleanupPendingClosuresHandler791=== RUN TestService_createPendingClosureHandler792=== PAUSE TestService_createPendingClosureHandler793=== RUN TestService_verifyS3Integrity794=== PAUSE TestService_verifyS3Integrity795=== RUN TestCompleteMultipartUnregistered796=== PAUSE TestCompleteMultipartUnregistered797=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT798=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT799=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle800=== CONT TestGracefulShutdownDrainsInflight801=== CONT TestPresentNotReportedWhileGCDeletesClosure802=== CONT TestReadProxyRootRedirectsToIndexHTML803=== CONT TestService_AuthMiddleware_MTLSBoundSubjects8042026/10/01 10:34:08 INFO Starting HTTP server address=127.0.0.1:38925805=== CONT TestReadProxyNarinfo806=== CONT TestService_readinessHandler807=== CONT TestPresentReportsOnlyClosureRoots808=== CONT TestService_healthCheckHandler809=== CONT TestIsValidCachePath810=== RUN TestIsValidCachePath/narinfo811=== CONT TestParseSingleRange812=== CONT TestReadProxyNarinfoAlreadyDecompressed813=== CONT TestProxyHeadersOnlyTrustedOnSocket814=== CONT TestPendingClosureFailureTracksEveryUpload815=== CONT TestProxyWriteTimeout816=== CONT TestCreatePinRejectsBadInput817=== CONT TestParseSize818=== CONT TestOrphanedObjectsGC819=== CONT TestReadRedirectKeepsNarinfoProxied820=== CONT TestReconnectLeavesObjectsUnlocked8212026/10/01 10:34:08 INFO Shutdown signal received, draining in-flight requests timeout=10s822=== CONT TestReadProxyDisabled823=== CONT TestDeletePinKeepsRowWhenS3Fails824=== CONT TestReadProxyRangeRequest825=== CONT TestOrphanedObjectsGCStressTest826=== PAUSE TestIsValidCachePath/narinfo827=== RUN TestParseSingleRange/none828=== RUN TestProxyWriteTimeout/narinfo829--- PASS: TestParseSize (0.00s)830=== CONT TestObjectStatsTrigger831=== PAUSE TestProxyWriteTimeout/narinfo832=== RUN TestProxyWriteTimeout/1_GiB_nar833=== PAUSE TestProxyWriteTimeout/1_GiB_nar834=== RUN TestProxyWriteTimeout/10_GiB_nar835=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars836=== PAUSE TestProxyWriteTimeout/10_GiB_nar837=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars838=== RUN TestIsValidCachePath/nar_zst839=== PAUSE TestIsValidCachePath/nar_zst840=== RUN TestProxyWriteTimeout/unknown_size841=== RUN TestIsValidCachePath/nar_xz842=== PAUSE TestIsValidCachePath/nar_xz843=== RUN TestIsValidCachePath/nar_bz2844=== PAUSE TestProxyWriteTimeout/unknown_size845=== PAUSE TestIsValidCachePath/nar_bz2846=== CONT TestSkippedUploadsHandler847=== RUN TestIsValidCachePath/nar_uncompressed848=== PAUSE TestIsValidCachePath/nar_uncompressed849=== RUN TestIsValidCachePath/ls850=== PAUSE TestIsValidCachePath/ls851=== RUN TestIsValidCachePath/log852=== PAUSE TestIsValidCachePath/log853=== RUN TestIsValidCachePath/realisation854=== PAUSE TestIsValidCachePath/realisation855=== RUN TestIsValidCachePath/nix-cache-info856=== PAUSE TestIsValidCachePath/nix-cache-info857=== RUN TestIsValidCachePath/index.html858=== PAUSE TestIsValidCachePath/index.html859=== RUN TestIsValidCachePath/traversal_parent860=== PAUSE TestIsValidCachePath/traversal_parent861=== PAUSE TestParseSingleRange/none862=== RUN TestIsValidCachePath/traversal_in_middle863=== RUN TestParseSingleRange/unknown_unit864=== PAUSE TestIsValidCachePath/traversal_in_middle865=== RUN TestIsValidCachePath/invalid_char_e866=== PAUSE TestIsValidCachePath/invalid_char_e867=== RUN TestIsValidCachePath/invalid_char_u868=== PAUSE TestIsValidCachePath/invalid_char_u869=== PAUSE TestParseSingleRange/unknown_unit870=== RUN TestIsValidCachePath/random_path871=== RUN TestParseSingleRange/multi-range_ignored872=== PAUSE TestParseSingleRange/multi-range_ignored873=== PAUSE TestIsValidCachePath/random_path874=== RUN TestParseSingleRange/malformed_no_dash875=== PAUSE TestParseSingleRange/malformed_no_dash876=== RUN TestParseSingleRange/malformed_both_empty877=== RUN TestIsValidCachePath/empty878=== PAUSE TestParseSingleRange/malformed_both_empty879=== PAUSE TestIsValidCachePath/empty880=== RUN TestIsValidCachePath/leading_slash881=== RUN TestParseSingleRange/malformed_end_before_start882=== PAUSE TestIsValidCachePath/leading_slash883=== PAUSE TestParseSingleRange/malformed_end_before_start884=== RUN TestIsValidCachePath/wrong_extension885=== RUN TestParseSingleRange/closed886=== PAUSE TestParseSingleRange/closed887=== PAUSE TestIsValidCachePath/wrong_extension888=== RUN TestParseSingleRange/open-ended889=== RUN TestIsValidCachePath/short_hash890=== PAUSE TestParseSingleRange/open-ended891=== PAUSE TestIsValidCachePath/short_hash892=== RUN TestParseSingleRange/end_clamped_to_size893=== CONT TestPush_RejectsBadRequests894=== PAUSE TestParseSingleRange/end_clamped_to_size895=== RUN TestParseSingleRange/suffix896=== PAUSE TestParseSingleRange/suffix897=== RUN TestParseSingleRange/suffix_exceeds_size898=== PAUSE TestParseSingleRange/suffix_exceeds_size899=== RUN TestParseSingleRange/single_byte900=== PAUSE TestParseSingleRange/single_byte901=== RUN TestParseSingleRange/start_past_EOF902=== PAUSE TestParseSingleRange/start_past_EOF903=== RUN TestParseSingleRange/start_far_past_EOF904=== PAUSE TestParseSingleRange/start_far_past_EOF905=== CONT TestCompleteMultipartUpload_ErrorButObjectExists9062026/10/01 10:34:08 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000907--- PASS: TestSkippedUploadsHandler (0.03s)908=== CONT TestGCTaskStore_CompletedAllowsNewTask909--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)910=== CONT TestGCSweepSkipsPendingObjects911--- PASS: TestGracefulShutdownDrainsInflight (0.07s)912=== CONT TestPushDedupSurvivesConcurrentGC9132026/10/01 10:34:08 WARN readiness check failed error="closed pool"914--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.27s)915=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection916--- PASS: TestService_readinessHandler (0.28s)917=== CONT TestCacheConfigHandler918=== RUN TestCacheConfigHandler/full_config,_no_issuer919=== PAUSE TestCacheConfigHandler/full_config,_no_issuer920=== RUN TestCacheConfigHandler/no_cache_url_configured921=== PAUSE TestCacheConfigHandler/no_cache_url_configured922=== RUN TestCacheConfigHandler/no_signing_keys923=== PAUSE TestCacheConfigHandler/no_signing_keys924=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator925=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator926=== CONT TestGCSweepDeliversEachKeyOnce927--- PASS: TestPresentReportsOnlyClosureRoots (0.32s)928=== CONT TestClientErrorHandling929=== RUN TestClientErrorHandling/InvalidStorePath930=== PAUSE TestClientErrorHandling/InvalidStorePath931=== RUN TestClientErrorHandling/InvalidAuthToken932=== PAUSE TestClientErrorHandling/InvalidAuthToken933=== RUN TestClientErrorHandling/ServerNotAvailable934=== PAUSE TestClientErrorHandling/ServerNotAvailable935=== CONT TestGCEndsOnShutdown936=== RUN TestGCEndsOnShutdown/before_the_run937=== PAUSE TestGCEndsOnShutdown/before_the_run938=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete939=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete940=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark941=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark942=== CONT TestGCTaskStore_GetEmpty943=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock944--- PASS: TestGCTaskStore_GetEmpty (0.00s)9452026/10/01 10:34:08 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"9462026/10/01 10:34:08 WARN mTLS auth: bound subjects configured but subject DN unavailable9472026/10/01 10:34:08 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"948--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.35s)949=== CONT TestCommitRacingPendingCleanupKeepsObjects950--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.36s)951=== CONT TestGenerateLandingPage952--- PASS: TestService_healthCheckHandler (0.38s)953=== CONT TestService_AuthMiddleware_MTLSProxyHeader954=== CONT TestPendingClosureWriteTimeout955--- PASS: TestGenerateLandingPage (0.02s)956=== RUN TestPendingClosureWriteTimeout/empty957=== PAUSE TestPendingClosureWriteTimeout/empty958=== RUN TestPendingClosureWriteTimeout/400_objects959=== PAUSE TestPendingClosureWriteTimeout/400_objects960=== RUN TestPendingClosureWriteTimeout/670k_objects961=== PAUSE TestPendingClosureWriteTimeout/670k_objects962=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline963=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline964=== CONT TestPush_SignsNarinfosOfItsPendingObjects965--- PASS: TestReadProxyDisabled (0.39s)966=== CONT TestService_AuthMiddleware_OIDC9672026/10/01 10:34:08 INFO Received uploads request method=POST path=/api/pending_closures9682026/10/01 10:34:08 INFO Starting HTTP server address=127.0.0.1:417699692026/10/01 10:34:08 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket3239559813/001/proxy.sock9702026/10/01 10:34:08 WARN mTLS auth: subject not in bound subjects subject="CN=someone"9712026/10/01 10:34:08 INFO Shutdown signal received, draining in-flight requests timeout=10s972--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.48s)973=== CONT TestService_RequireScope_OIDC9742026/10/01 10:34:08 INFO Received uploads request method=POST path=/api/pending_closures975--- PASS: TestObjectStatsTrigger (0.50s)976=== CONT TestReadProxyConditionalGet9772026/10/01 10:34:08 INFO Received uploads request method=POST path=/api/pending_closures9782026/10/01 10:34:08 INFO Received create pin request method=POST path=/api/pins/app9792026/10/01 10:34:08 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo9802026/10/01 10:34:08 INFO Received delete pin request method=DELETE path=/api/pins/app9812026/10/01 10:34:08 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket18/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"9822026/10/01 10:34:08 INFO Received delete pin request method=DELETE path=/api/pins/app9832026/10/01 10:34:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9842026/10/01 10:34:08 INFO Received create pin request method=POST path=/api/pins/deploy9852026/10/01 10:34:08 INFO Received create pin request method=POST path=/api/pins/deploy9862026/10/01 10:34:08 INFO Received create pin request method=POST path=/api/pins/deploy9872026/10/01 10:34:08 INFO Received create pin request method=POST path=/api/pins/deploy9882026/10/01 10:34:08 INFO Received create pin request method=POST path=/api/pins/deploy9892026/10/01 10:34:08 INFO Received create pin request method=POST path=/api/pins/deploy9902026/10/01 10:34:08 INFO Received create pin request method=POST path=/api/pins/deploy9912026/10/01 10:34:08 INFO Received create pin request method=POST path=/api/pins/deploy9922026/10/01 10:34:08 INFO Deleted pin name=app993--- PASS: TestReadRedirectKeepsNarinfoProxied (0.55s)994=== CONT TestReadProxy4049952026/10/01 10:34:08 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NDcxODI4MjEtYjQ5MC00ZTlkLTlmNmUtMmM0YTMxNDBiM2Y0LjdjNTEyYTc5LWFiZDAtNGE2Yi05YmI4LTc3MjljMzJmMWNlMXgxNzkwODUwODQ4NjA2MTI0Mzk09962026/10/01 10:34:08 INFO Received uploads request method=POST path=/api/pending_closures997=== CONT TestPush_CompleteCommitsEveryRoot998--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.57s)9992026/10/01 10:34:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10002026/10/01 10:34:08 INFO Received create pin request method=POST path=/api/pins/deploy10012026/10/01 10:34:08 INFO Aborted multipart uploads count=0 kept=010022026/10/01 10:34:08 WARN Force mode enabled - objects will be deleted immediately without grace period10032026/10/01 10:34:08 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010042026/10/01 10:34:08 INFO Vacuumed table table=pending_closures10052026/10/01 10:34:08 INFO Vacuumed table table=pending_objects10062026/10/01 10:34:08 INFO Vacuumed table table=multipart_uploads10072026/10/01 10:34:08 INFO Vacuumed table table=closures10082026/10/01 10:34:08 INFO Vacuumed table table=objects10092026/10/01 10:34:08 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NDcxODI4MjEtYjQ5MC00ZTlkLTlmNmUtMmM0YTMxNDBiM2Y0LjdjNTEyYTc5LWFiZDAtNGE2Yi05YmI4LTc3MjljMzJmMWNlMXgxNzkwODUwODQ4NjA2MTI0Mzk0 error="Delete \"http://localhost:45055/bucket17/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=NDcxODI4MjEtYjQ5MC00ZTlkLTlmNmUtMmM0YTMxNDBiM2Y0LjdjNTEyYTc5LWFiZDAtNGE2Yi05YmI4LTc3MjljMzJmMWNlMXgxNzkwODUwODQ4NjA2MTI0Mzk0\": injected: abort refused"10102026/10/01 10:34:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10112026/10/01 10:34:08 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NDcxODI4MjEtYjQ5MC00ZTlkLTlmNmUtMmM0YTMxNDBiM2Y0LjdjNTEyYTc5LWFiZDAtNGE2Yi05YmI4LTc3MjljMzJmMWNlMXgxNzkwODUwODQ4NjA2MTI0Mzk010122026/10/01 10:34:08 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NDcxODI4MjEtYjQ5MC00ZTlkLTlmNmUtMmM0YTMxNDBiM2Y0LjdjNTEyYTc5LWFiZDAtNGE2Yi05YmI4LTc3MjljMzJmMWNlMXgxNzkwODUwODQ4NjA2MTI0Mzk0 parts=11013--- PASS: TestGCSweepSkipsPendingObjects (0.60s)1014=== CONT TestGCAdvisoryLockBlocksConcurrentRun1015--- PASS: TestReconnectLeavesObjectsUnlocked (0.64s)1016=== CONT TestGCTaskStore_Fail1017--- PASS: TestGCTaskStore_Fail (0.00s)1018=== CONT TestSweepRechecksPendingAfterLocking10192026/10/01 10:34:08 INFO Received uploads request method=POST path=/api/pending_closures1020--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.65s)1021=== CONT TestGetExistingObjectsLocksRows1022=== RUN TestPush_RejectsBadRequests/no_roots1023=== PAUSE TestPush_RejectsBadRequests/no_roots1024=== RUN TestPush_RejectsBadRequests/no_objects1025=== PAUSE TestPush_RejectsBadRequests/no_objects1026=== RUN TestPush_RejectsBadRequests/bad_root1027=== PAUSE TestPush_RejectsBadRequests/bad_root1028=== RUN TestPush_RejectsBadRequests/root_not_in_objects1029=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1030=== CONT TestService_Rustfstest10312026/10/01 10:34:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41747/oidc1032--- PASS: TestReadProxyRangeRequest (0.67s)1033=== CONT TestCreatePin_ReservedPins10342026/10/01 10:34:08 INFO Received uploads request method=POST path=/api/pending_closures10352026/10/01 10:34:08 INFO Aborted multipart uploads count=0 kept=010362026/10/01 10:34:08 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=010372026/10/01 10:34:08 INFO Vacuumed table table=pending_closures10382026/10/01 10:34:08 INFO Vacuumed table table=pending_objects10392026/10/01 10:34:08 INFO Vacuumed table table=multipart_uploads10402026/10/01 10:34:08 INFO Vacuumed table table=closures10412026/10/01 10:34:08 INFO Vacuumed table table=objects10422026/10/01 10:34:08 INFO Aborted multipart uploads count=0 kept=010432026/10/01 10:34:08 WARN Force mode enabled - objects will be deleted immediately without grace period10442026/10/01 10:34:08 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010452026/10/01 10:34:08 INFO Vacuumed table table=pending_closures10462026/10/01 10:34:08 INFO Vacuumed table table=pending_objects10472026/10/01 10:34:08 INFO Vacuumed table table=multipart_uploads10482026/10/01 10:34:08 INFO Aborted multipart uploads count=0 kept=010492026/10/01 10:34:08 INFO Vacuumed table table=closures10502026/10/01 10:34:08 INFO Vacuumed table table=objects10512026/10/01 10:34:08 WARN Force mode enabled - objects will be deleted immediately without grace period1052--- PASS: TestPushDedupSurvivesConcurrentGC (0.69s)1053=== CONT TestSweepSkipsRowsLockedByPush10542026/10/01 10:34:08 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=010552026/10/01 10:34:08 INFO Vacuumed table table=pending_closures10562026/10/01 10:34:08 INFO Vacuumed table table=pending_objects10572026/10/01 10:34:08 INFO Vacuumed table table=multipart_uploads10582026/10/01 10:34:08 INFO Vacuumed table table=closures10592026/10/01 10:34:08 INFO Vacuumed table table=objects10602026/10/01 10:34:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36621/oidc10612026/10/01 10:34:08 INFO Aborted multipart uploads count=0 kept=01062--- PASS: TestGCSweepDeliversEachKeyOnce (0.51s)1063=== CONT TestPresignedUploadRegisteredBeforeCommit10642026/10/01 10:34:08 WARN Force mode enabled - objects will be deleted immediately without grace period1065--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.41s)1066=== CONT TestFailedS3DeleteKeepsTombstone10672026/10/01 10:34:08 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010682026/10/01 10:34:08 INFO Vacuumed table table=pending_closures10692026/10/01 10:34:08 INFO Received push request method=POST path=/api/pushes10702026/10/01 10:34:08 INFO Vacuumed table table=pending_objects10712026/10/01 10:34:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39831/oidc10722026/10/01 10:34:08 INFO Vacuumed table table=multipart_uploads10732026/10/01 10:34:08 INFO Vacuumed table table=closures10742026/10/01 10:34:08 INFO Vacuumed table table=objects1075--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.81s)1076=== CONT TestGCTaskStore_PhaseUpdates1077=== CONT TestCompletedNarNotReofferedAcrossClosures1078--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)10792026/10/01 10:34:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10802026/10/01 10:34:08 INFO Signed narinfos id=1 count=11081=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1082--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.50s)1083--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.47s)1084=== CONT TestPush_OverlappingRootsStoreOneRowPerKey10852026/10/01 10:34:08 INFO Received push request method=POST path=/api/pushes1086--- PASS: TestGetExistingObjectsLocksRows (0.27s)1087=== CONT TestRegisterCompletedObjectNeedsPendingRow1088=== CONT TestDeduplicatedObjectsRecordedAsPending1089--- PASS: TestReadProxyConditionalGet (0.43s)10902026/10/01 10:34:09 INFO Aborted multipart uploads count=0 kept=01091--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.67s)1092=== CONT TestRedundantMultipartUpload10932026/10/01 10:34:09 WARN Force mode enabled - objects will be deleted immediately without grace period10942026/10/01 10:34:09 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=010952026/10/01 10:34:09 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"10962026/10/01 10:34:09 INFO Vacuumed table table=pending_closures10972026/10/01 10:34:09 INFO Vacuumed table table=pending_objects10982026/10/01 10:34:09 INFO Vacuumed table table=multipart_uploads10992026/10/01 10:34:09 INFO Vacuumed table table=closures11002026/10/01 10:34:09 INFO Vacuumed table table=objects1101=== CONT TestReadRedirectUsesPublicS3URL1102--- PASS: TestPendingClosureFailureTracksEveryUpload (1.05s)1103--- PASS: TestSweepRechecksPendingAfterLocking (0.42s)1104=== CONT TestTombstonedObjectOfferedWithoutWaiting1105=== RUN TestService_RequireScope_OIDC/builder_may_write1106=== PAUSE TestService_RequireScope_OIDC/builder_may_write1107=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1108=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1109=== RUN TestService_RequireScope_OIDC/ops_may_admin1110=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1111=== RUN TestService_RequireScope_OIDC/ops_may_not_write1112=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1113=== RUN TestService_RequireScope_OIDC/reader_may_not_write1114=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1115=== RUN TestService_RequireScope_OIDC/static_token_may_admin1116=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1117=== RUN TestService_RequireScope_OIDC/static_token_may_write1118=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1119=== RUN TestService_RequireScope_OIDC/reader_may_read1120=== PAUSE TestService_RequireScope_OIDC/reader_may_read1121=== RUN TestService_RequireScope_OIDC/writer_implies_read1122=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1123=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1124=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1125=== CONT TestGCMetrics1126=== CONT TestClientIntegration1127--- PASS: TestService_Rustfstest (0.42s)1128=== NAME TestOrphanedObjectsGC1129 orphaned_objects_gc_test.go:290: GC Test Summary:1130 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1131 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1132 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1133 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1134 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects11352026/10/01 10:34:09 INFO Aborted multipart uploads count=0 kept=011362026/10/01 10:34:09 WARN Force mode enabled - objects will be deleted immediately without grace period11372026/10/01 10:34:09 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=011382026/10/01 10:34:09 INFO Vacuumed table table=pending_closures11392026/10/01 10:34:09 INFO Vacuumed table table=pending_objects11402026/10/01 10:34:09 INFO Vacuumed table table=multipart_uploads11412026/10/01 10:34:09 INFO Vacuumed table table=closures11422026/10/01 10:34:09 INFO Vacuumed table table=objects11432026/10/01 10:34:09 INFO Received uploads request method=POST path=/api/pending_closures1144=== CONT TestForceGCDuringPushOffersSweptObject1145--- PASS: TestOrphanedObjectsGC (1.13s)1146=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1147=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1148=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1149=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1150=== CONT TestGCTaskStore_StartNew11512026/10/01 10:34:09 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1152=== CONT TestGCTaskStore_GetReturnsLatest11532026/10/01 10:34:09 WARN Refused reserved pin name=worker-x86_64-linux1154--- PASS: TestGCTaskStore_StartNew (0.00s)1155--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1156=== CONT TestCreatePendingClosureRejectsOversizedNAR11572026/10/01 10:34:09 INFO Received uploads request method=POST path=/api/pending_closures11582026/10/01 10:34:09 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1159--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1160=== CONT TestCacheStatsHandler11612026/10/01 10:34:09 INFO Received create pin request method=POST path=/api/pins/my-app11622026/10/01 10:34:09 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11632026/10/01 10:34:09 INFO Aborted multipart uploads count=0 kept=011642026/10/01 10:34:09 WARN Force mode enabled - objects will be deleted immediately without grace period11652026/10/01 10:34:09 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=01166--- PASS: TestCreatePin_ReservedPins (0.48s)1167=== CONT TestClientFallsBackToClosures11682026/10/01 10:34:09 INFO Vacuumed table table=pending_closures11692026/10/01 10:34:09 INFO Received uploads request method=POST path=/api/pending_closures11702026/10/01 10:34:09 INFO Vacuumed table table=pending_objects11712026/10/01 10:34:09 INFO Vacuumed table table=multipart_uploads11722026/10/01 10:34:09 INFO Vacuumed table table=closures11732026/10/01 10:34:09 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11742026/10/01 10:34:09 INFO Received uploads request method=POST path=/api/pending_closures11752026/10/01 10:34:09 INFO Vacuumed table table=objects11762026/10/01 10:34:09 WARN Rate limiter enabled after throttle name=s3-test rate=511772026/10/01 10:34:09 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."11782026/10/01 10:34:09 INFO Received uploads request method=POST path=/api/pending_closures1179--- PASS: TestSweepSkipsRowsLockedByPush (0.42s)1180=== CONT TestClientPushesUseOnePush1181=== CONT TestGCTaskStore_ConflictDifferentParams1182--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.40s)1183=== CONT TestClientSharedPathCommittedMidPush1184--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1185=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1186=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1187=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1188=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1189=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1190=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1191=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1192=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1193=== CONT TestLeadEndsOnShutdown11942026/10/01 10:34:09 INFO Received push request method=POST path=/api/pushes11952026/10/01 10:34:09 INFO Aborted multipart uploads count=0 kept=011962026/10/01 10:34:09 WARN Force mode enabled - objects will be deleted immediately without grace period11972026/10/01 10:34:09 INFO Received push request method=POST path=/api/pushes11982026/10/01 10:34:09 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11992026/10/01 10:34:09 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1200--- PASS: TestFailedS3DeleteKeepsTombstone (0.49s)1201=== CONT TestResolveDBConnectionString1202=== RUN TestResolveDBConnectionString/flag_wins1203=== PAUSE TestResolveDBConnectionString/flag_wins1204=== RUN TestResolveDBConnectionString/file_when_flag_empty1205=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1206=== RUN TestResolveDBConnectionString/missing_file_is_an_error1207=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1208=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1209=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1210=== RUN TestResolveDBConnectionString/nothing_configured1211=== PAUSE TestResolveDBConnectionString/nothing_configured1212=== CONT TestClientCADerivations12132026/10/01 10:34:09 INFO Received uploads request method=POST path=/api/pending_closures12142026/10/01 10:34:09 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"1215--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.37s)1216=== CONT TestService_NativeMTLS1217--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.46s)1218=== CONT TestPendingClosureFailureAbortsItsUploads12192026/10/01 10:34:09 WARN Rate limiter backed off name=s3-test rate=512202026/10/01 10:34:09 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."1221=== CONT TestPinProtectsFromGC1222--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.70s)1223=== CONT TestServerTLSConfig1224--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.42s)1225=== RUN TestServerTLSConfig/no_client_CA1226=== PAUSE TestServerTLSConfig/no_client_CA1227=== RUN TestServerTLSConfig/missing_CA_file1228=== PAUSE TestServerTLSConfig/missing_CA_file1229=== RUN TestServerTLSConfig/not_a_PEM_file1230--- PASS: TestReadProxy404 (0.79s)1231=== CONT TestService_verifyS3Integrity1232=== PAUSE TestServerTLSConfig/not_a_PEM_file1233=== CONT TestMetricsInventory12342026/10/01 10:34:09 INFO Received uploads request method=POST path=/api/pending_closures12352026/10/01 10:34:09 INFO Received uploads request method=POST path=/api/pending_closures12362026/10/01 10:34:09 INFO Received uploads request method=POST path=/api/pending_closures12372026/10/01 10:34:09 INFO Aborted multipart uploads count=0 kept=01238=== CONT TestClientMultipleUploads1239--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.35s)12402026/10/01 10:34:09 WARN Force mode enabled - objects will be deleted immediately without grace period12412026/10/01 10:34:09 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=012422026/10/01 10:34:09 INFO Vacuumed table table=pending_closures12432026/10/01 10:34:09 INFO Vacuumed table table=pending_objects12442026/10/01 10:34:09 INFO Vacuumed table table=multipart_uploads12452026/10/01 10:34:09 INFO Vacuumed table table=closures12462026/10/01 10:34:09 INFO Vacuumed table table=objects1247=== NAME TestClientIntegration1248 client_integration_test.go:334: Created store path: /build/TestClientIntegration1431695531/002/store/d8394lankm5x898mb7ak0rsc0ib1qbrp-test-file.txt1249--- PASS: TestGCMetrics (0.43s)1250=== CONT TestCacheConfigHandlerMaxNarSize1251--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1252=== CONT TestClientWithDependencies1253=== CONT TestService_ReadScope_PublicByDefault1254--- PASS: TestCacheStatsHandler (0.39s)12552026/10/01 10:34:09 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=1677721612562026/10/01 10:34:09 INFO Received push request method=POST path=/api/pushes12572026/10/01 10:34:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12582026/10/01 10:34:09 INFO lead: acquired remote=192.0.2.1:123412592026/10/01 10:34:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12602026/10/01 10:34:09 INFO Uploading d8394lankm5x898mb7ak0rsc0ib1qbrp-test-file.txt (152B)1261=== CONT TestConcurrentPinUpdatesAgree1262--- PASS: TestReadProxyNarinfo (1.57s)12632026/10/01 10:34:09 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12642026/10/01 10:34:09 WARN Failed to register uploaded object key=d8394lankm5x898mb7ak0rsc0ib1qbrp.ls error="server returned 404: 404 page not found\n"12652026/10/01 10:34:09 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12662026/10/01 10:34:09 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NDcxODI4MjEtYjQ5MC00ZTlkLTlmNmUtMmM0YTMxNDBiM2Y0LmY2OGZkN2ZkLWY2ZGEtNDM2OS1hODRjLWFkYWFlMWIxMWQxOXgxNzkwODUwODQ4OTc5NTA0MDkw parts=1012672026/10/01 10:34:09 INFO Signed narinfos id=1 count=112682026/10/01 10:34:09 INFO Uploading 1 narinfos12692026/10/01 10:34:09 INFO Received complete push request method=POST path=/api/pushes/1/complete12702026/10/01 10:34:09 WARN Failed to register uploaded object key=d8394lankm5x898mb7ak0rsc0ib1qbrp.narinfo error="server returned 404: 404 page not found\n"1271--- PASS: TestReadRedirectUsesPublicS3URL (0.54s)1272=== CONT TestLeadElectsOneAndHandsOver12732026/10/01 10:34:09 INFO Upload complete. (87ms)12742026/10/01 10:34:09 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12752026/10/01 10:34:09 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1276=== CONT TestNARDeduplicationMetadataUploadBug1277--- PASS: TestService_NativeMTLS (0.32s)12782026/10/01 10:34:09 INFO Received uploads request method=POST path=/api/pending_closures12792026/10/01 10:34:09 INFO All 1 paths already cached1280=== NAME TestClientIntegration1281 client_integration_test.go:360: Retrieved narinfo from S3:1282 StorePath: /build/TestClientIntegration1431695531/002/store/d8394lankm5x898mb7ak0rsc0ib1qbrp-test-file.txt1283 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1284 Compression: zstd1285 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11286 NarSize: 1521287 References: 1288 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11289 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)1290 client_integration_test.go:361: Decompressed .ls content (64 bytes):1291 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1292=== NAME TestClientCADerivations1293 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2493072658/001/store/6w5jd6z98q4rpgngibcbd8bh57v7bwrs-ca-test12942026/10/01 10:34:09 INFO Received uploads request method=POST path=/api/pending_closures12952026/10/01 10:34:09 INFO Received push request method=POST path=/api/pushes12962026/10/01 10:34:09 INFO Received create pin request method=POST path=/api/pins/deploy1297 client_ca_test.go:139: Found 1 dependencies (including self)1298--- PASS: TestPendingClosureFailureAbortsItsUploads (0.40s)1299=== CONT TestMultipartCleanup13002026/10/01 10:34:09 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)13012026/10/01 10:34:09 INFO Uploading lbpcbls1z8g2rbmyin9i052dj048n6x1-top (224B)13022026/10/01 10:34:09 INFO Uploading cfy776pdca3s19sccdnhx1k1akra1w7j-shared-dep (136B)13032026/10/01 10:34:09 INFO Received uploads request method=POST path=/api/pending_closures13042026/10/01 10:34:09 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo13052026/10/01 10:34:09 INFO Received push request method=POST path=/api/pushes13062026/10/01 10:34:09 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13072026/10/01 10:34:09 INFO Uploading hd2qmnlaswfgwjm3qmk800wfwsymnz6r-shared-dep (136B)13082026/10/01 10:34:09 INFO Uploading 311kll7pj2j8bl94rbr3664aw9c7wdqh-b (216B)13092026/10/01 10:34:09 WARN Failed to register uploaded object key=nar/1g3vxnk4y2a03bq5jflad05kn6f42455lly04l8nl0xyqfd2vcl6.nar.zst error="server returned 404: 404 page not found\n"13102026/10/01 10:34:09 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13112026/10/01 10:34:09 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13122026/10/01 10:34:09 INFO Uploading xifw0wh0z22dqhisi8khq1b3vya8bkgy-shared-dep (136B)13132026/10/01 10:34:09 INFO Uploading zhp502q8d433phrnnqkg2g2a5fgvff1j-b (216B)13142026/10/01 10:34:09 INFO Received uploads request method=POST path=/api/pending_closures13152026/10/01 10:34:09 WARN Failed to register uploaded object key=cfy776pdca3s19sccdnhx1k1akra1w7j.ls error="server returned 404: 404 page not found\n"13162026/10/01 10:34:09 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13172026/10/01 10:34:09 WARN Failed to register uploaded object key=lbpcbls1z8g2rbmyin9i052dj048n6x1.ls error="server returned 404: 404 page not found\n"13182026/10/01 10:34:09 INFO Signed narinfos id=1 count=213192026/10/01 10:34:09 INFO Uploading 2 narinfos1320--- PASS: TestCreatePinRejectsBadInput (1.74s)1321=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT13222026/10/01 10:34:09 WARN Failed to register uploaded object key=xglnh7sbmaq39kh5y66ij84vpzm5hb9d.ls error="server returned 404: 404 page not found\n"13232026/10/01 10:34:09 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13242026/10/01 10:34:09 WARN Failed to register uploaded object key=nar/01mc4p2l1pl9pblxg3h6gz6qag978hbqdm38qik60sy3zdn3as2x.nar.zst error="server returned 404: 404 page not found\n"13252026/10/01 10:34:09 WARN Failed to register uploaded object key=8nkp2s5qq9s29191c0vj9gm7v344hdph.ls error="server returned 404: 404 page not found\n"13262026/10/01 10:34:09 WARN Failed to register uploaded object key=cfy776pdca3s19sccdnhx1k1akra1w7j.narinfo error="server returned 404: 404 page not found\n"13272026/10/01 10:34:09 INFO Received push request method=POST path=/api/pushes1328=== NAME TestPinProtectsFromGC1329 client_integration_test.go:867: Pinned store path: /build/TestPinProtectsFromGC4198171417/001/store/xb2d42cpva3h7kmymw2j5a9rwwar6k2n-pinned-file.txt1330 client_integration_test.go:868: Unpinned store path: /build/TestPinProtectsFromGC4198171417/001/store/dr6m79wfksjf58rg8cddljw2pn7akx8s-unpinned-file.txt13312026/10/01 10:34:09 WARN Failed to register uploaded object key=hd2qmnlaswfgwjm3qmk800wfwsymnz6r.ls error="server returned 404: 404 page not found\n"13322026/10/01 10:34:09 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13332026/10/01 10:34:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13342026/10/01 10:34:09 WARN Failed to register uploaded object key=311kll7pj2j8bl94rbr3664aw9c7wdqh.ls error="server returned 404: 404 page not found\n"13352026/10/01 10:34:09 WARN Failed to register uploaded object key=nar/0kc82rx82ci3ba9zlxl0kp1q5rw8m8a3z21wl2gc3vspfsbkrnsz.nar.zst error="server returned 404: 404 page not found\n"13362026/10/01 10:34:09 INFO Signed narinfos id=2 count=213372026/10/01 10:34:09 WARN Failed to register uploaded object key=xifw0wh0z22dqhisi8khq1b3vya8bkgy.ls error="server returned 404: 404 page not found\n"13382026/10/01 10:34:09 INFO Object in database but missing from S3 key=d8394lankm5x898mb7ak0rsc0ib1qbrp.ls13392026/10/01 10:34:09 WARN Found objects in DB but missing from S3, will re-upload count=113402026/10/01 10:34:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13412026/10/01 10:34:09 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13422026/10/01 10:34:09 INFO Signed narinfos id=1 count=213432026/10/01 10:34:09 INFO Uploading 4 narinfos13442026/10/01 10:34:09 INFO Received complete push request method=POST path=/api/pushes/1/complete13452026/10/01 10:34:09 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13462026/10/01 10:34:09 WARN Failed to register uploaded object key=zhp502q8d433phrnnqkg2g2a5fgvff1j.ls error="server returned 404: 404 page not found\n"13472026/10/01 10:34:09 WARN Failed to register uploaded object key=lbpcbls1z8g2rbmyin9i052dj048n6x1.narinfo error="server returned 404: 404 page not found\n"13482026/10/01 10:34:09 INFO Signed narinfos id=1 count=313492026/10/01 10:34:09 INFO Uploading 3 narinfos13502026/10/01 10:34:09 WARN Failed to register uploaded object key=hd2qmnlaswfgwjm3qmk800wfwsymnz6r.narinfo error="server returned 404: 404 page not found\n"13512026/10/01 10:34:09 INFO Received complete push request method=POST path=/api/pushes/2/complete13522026/10/01 10:34:09 WARN Failed to register uploaded object key=xglnh7sbmaq39kh5y66ij84vpzm5hb9d.narinfo error="server returned 404: 404 page not found\n"13532026/10/01 10:34:09 WARN Failed to register uploaded object key=d8394lankm5x898mb7ak0rsc0ib1qbrp.ls error="server returned 404: 404 page not found\n"1354--- PASS: TestMetricsInventory (0.42s)1355=== CONT TestService_createPendingClosureHandler13562026/10/01 10:34:09 WARN Failed to register uploaded object key=xifw0wh0z22dqhisi8khq1b3vya8bkgy.narinfo error="server returned 404: 404 page not found\n"13572026/10/01 10:34:09 WARN Failed to register uploaded object key=zhp502q8d433phrnnqkg2g2a5fgvff1j.narinfo error="server returned 404: 404 page not found\n"13582026/10/01 10:34:09 INFO Upload complete. (63ms)13592026/10/01 10:34:09 INFO Upload complete. (105ms)13602026/10/01 10:34:09 WARN Failed to register uploaded object key=311kll7pj2j8bl94rbr3664aw9c7wdqh.narinfo error="server returned 404: 404 page not found\n"13612026/10/01 10:34:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1362=== NAME TestClientIntegration1363 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)13642026/10/01 10:34:09 WARN Failed to register uploaded object key=hd2qmnlaswfgwjm3qmk800wfwsymnz6r.narinfo error="server returned 404: 404 page not found\n"1365 client_integration_test.go:389: Decompressed .ls content (49 bytes):1366 {"version":1,"root":{"type":"regular","size":39}}1367=== NAME TestClientSharedPathCommittedMidPush1368 client_integration_test.go:816: Retrieved narinfo from S3:1369 StorePath: /build/TestClientSharedPathCommittedMidPush3422129064/001/store/cfy776pdca3s19sccdnhx1k1akra1w7j-shared-dep1370 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1371 Compression: zstd1372 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821373 NarSize: 1361374 References: 1375 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13762026/10/01 10:34:09 INFO Received complete push request method=POST path=/api/pushes/1/complete13772026/10/01 10:34:09 WARN Failed to register uploaded object key=8nkp2s5qq9s29191c0vj9gm7v344hdph.narinfo error="server returned 404: 404 page not found\n"13782026/10/01 10:34:09 INFO Completed upload id=11379 client_integration_test.go:816: Retrieved narinfo from S3:1380 StorePath: /build/TestClientSharedPathCommittedMidPush3422129064/001/store/lbpcbls1z8g2rbmyin9i052dj048n6x1-top1381 URL: nar/1g3vxnk4y2a03bq5jflad05kn6f42455lly04l8nl0xyqfd2vcl6.nar.zst1382 Compression: zstd1383 NarHash: sha256:1g3vxnk4y2a03bq5jflad05kn6f42455lly04l8nl0xyqfd2vcl61384 NarSize: 2241385 References: /build/TestClientSharedPathCommittedMidPush3422129064/001/store/cfy776pdca3s19sccdnhx1k1akra1w7j-shared-dep1386 CA: text:sha256:15lzfspplrdbl5i8z7pa637a0svxqvjqyzzvysmhkx39f7z8xa4013872026/10/01 10:34:09 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13882026/10/01 10:34:09 INFO Completed upload id=213892026/10/01 10:34:09 INFO Upload complete. (116ms)13902026/10/01 10:34:09 INFO Upload complete. (97ms)1391=== NAME TestClientFallsBackToClosures1392 client_pushes_test.go:112: Retrieved narinfo from S3:1393 StorePath: /build/TestClientFallsBackToClosures2586957110/001/store/hd2qmnlaswfgwjm3qmk800wfwsymnz6r-shared-dep1394 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1395 Compression: zstd1396 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821397 NarSize: 1361398 References: 1399 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1400=== NAME TestClientPushesUseOnePush1401 client_pushes_test.go:97: Retrieved narinfo from S3:1402 StorePath: /build/TestClientPushesUseOnePush1508212712/001/store/xifw0wh0z22dqhisi8khq1b3vya8bkgy-shared-dep1403 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1404 Compression: zstd1405 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821406 NarSize: 1361407 References: 1408 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1409=== NAME TestClientFallsBackToClosures1410 client_pushes_test.go:112: Retrieved narinfo from S3:1411 StorePath: /build/TestClientFallsBackToClosures2586957110/001/store/xglnh7sbmaq39kh5y66ij84vpzm5hb9d-a1412 URL: nar/01mc4p2l1pl9pblxg3h6gz6qag978hbqdm38qik60sy3zdn3as2x.nar.zst1413 Compression: zstd1414 NarHash: sha256:01mc4p2l1pl9pblxg3h6gz6qag978hbqdm38qik60sy3zdn3as2x1415 NarSize: 2161416 References: /build/TestClientFallsBackToClosures2586957110/001/store/hd2qmnlaswfgwjm3qmk800wfwsymnz6r-shared-dep1417 CA: text:sha256:0xsgjisp0jgnbnkv9aq0s0mgva54kwpipmjyy11v8mz8k24wg14l1418=== NAME TestClientPushesUseOnePush1419 client_pushes_test.go:97: Retrieved narinfo from S3:1420 StorePath: /build/TestClientPushesUseOnePush1508212712/001/store/8nkp2s5qq9s29191c0vj9gm7v344hdph-a1421 URL: nar/0kc82rx82ci3ba9zlxl0kp1q5rw8m8a3z21wl2gc3vspfsbkrnsz.nar.zst1422 Compression: zstd1423 NarHash: sha256:0kc82rx82ci3ba9zlxl0kp1q5rw8m8a3z21wl2gc3vspfsbkrnsz1424 NarSize: 2161425 References: /build/TestClientPushesUseOnePush1508212712/001/store/xifw0wh0z22dqhisi8khq1b3vya8bkgy-shared-dep1426 CA: text:sha256:1vwy2qaa3s29x7ap354ndvn1fqg8nyzvl9x2vw1k3gw5r91hwiql1427=== NAME TestClientFallsBackToClosures1428 client_pushes_test.go:112: Retrieved narinfo from S3:1429 StorePath: /build/TestClientFallsBackToClosures2586957110/001/store/311kll7pj2j8bl94rbr3664aw9c7wdqh-b1430 URL: nar/01mc4p2l1pl9pblxg3h6gz6qag978hbqdm38qik60sy3zdn3as2x.nar.zst1431 Compression: zstd1432 NarHash: sha256:01mc4p2l1pl9pblxg3h6gz6qag978hbqdm38qik60sy3zdn3as2x1433 NarSize: 2161434 References: /build/TestClientFallsBackToClosures2586957110/001/store/hd2qmnlaswfgwjm3qmk800wfwsymnz6r-shared-dep1435 CA: text:sha256:0xsgjisp0jgnbnkv9aq0s0mgva54kwpipmjyy11v8mz8k24wg14l1436=== NAME TestClientPushesUseOnePush1437 client_pushes_test.go:97: Retrieved narinfo from S3:1438 StorePath: /build/TestClientPushesUseOnePush1508212712/001/store/zhp502q8d433phrnnqkg2g2a5fgvff1j-b1439 URL: nar/0kc82rx82ci3ba9zlxl0kp1q5rw8m8a3z21wl2gc3vspfsbkrnsz.nar.zst1440 Compression: zstd1441 NarHash: sha256:0kc82rx82ci3ba9zlxl0kp1q5rw8m8a3z21wl2gc3vspfsbkrnsz1442 NarSize: 2161443 References: /build/TestClientPushesUseOnePush1508212712/001/store/xifw0wh0z22dqhisi8khq1b3vya8bkgy-shared-dep1444 CA: text:sha256:1vwy2qaa3s29x7ap354ndvn1fqg8nyzvl9x2vw1k3gw5r91hwiql1445=== CONT TestCompleteMultipartUnregistered1446--- PASS: TestClientSharedPathCommittedMidPush (0.62s)1447=== NAME TestClientMultipleUploads1448 client_integration_test.go:480: Created store path 0: /build/TestClientMultipleUploads1552213165/001/store/rjr0ypmr6v4j2w7bcr7mbkw913pvf3yb-test-file-0.txt14492026/10/01 10:34:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14502026/10/01 10:34:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1451=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1452--- PASS: TestClientFallsBackToClosures (0.67s)1453--- PASS: TestClientPushesUseOnePush (0.64s)1454=== CONT TestPendingCleanupUsesOneCutoff14552026/10/01 10:34:09 INFO Received push request method=POST path=/api/pushes1456--- PASS: TestService_ReadScope_PublicByDefault (0.30s)1457=== CONT TestGCTaskStore_DeduplicateSameParams1458=== CONT TestConnectWaitsForAPeerMigration1459--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)14602026/10/01 10:34:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14612026/10/01 10:34:09 INFO Uploading xb2d42cpva3h7kmymw2j5a9rwwar6k2n-pinned-file.txt (128B)14622026/10/01 10:34:09 INFO Received push request method=POST path=/api/pushes14632026/10/01 10:34:09 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NDcxODI4MjEtYjQ5MC00ZTlkLTlmNmUtMmM0YTMxNDBiM2Y0LmM5MmU4YWRlLWJiZDUtNGNmMC04MDY0LWU1YWY0MzZjOGU5N3gxNzkwODUwODQ5MzI3ODAxNTYy parts=1014642026/10/01 10:34:09 INFO Received create pin request method=POST path=/api/pins/app14652026/10/01 10:34:09 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NDcxODI4MjEtYjQ5MC00ZTlkLTlmNmUtMmM0YTMxNDBiM2Y0LmQ1Yjg4NGExLThlMDktNGRkMi1iMjQ1LTRhMTYwYzkzMjdkN3gxNzkwODUwODQ5Mjc2MTk3ODYw parts=121466=== NAME TestClientMultipleUploads1467 client_integration_test.go:480: Created store path 1: /build/TestClientMultipleUploads1552213165/001/store/va2if0ya6njklwhld6azqi8szy1fwdzc-test-file-1.txt14682026/10/01 10:34:09 INFO Received uploads request method=POST path=/api/pending_closures14692026/10/01 10:34:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14702026/10/01 10:34:09 INFO Uploading 6w5jd6z98q4rpgngibcbd8bh57v7bwrs-ca-test (144B)14712026/10/01 10:34:09 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14722026/10/01 10:34:09 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14732026/10/01 10:34:09 WARN Failed to register uploaded object key=xb2d42cpva3h7kmymw2j5a9rwwar6k2n.ls error="server returned 404: 404 page not found\n"14742026/10/01 10:34:09 INFO Received create pin request method=POST path=/api/pins/app14752026/10/01 10:34:09 INFO Signed narinfos id=1 count=114762026/10/01 10:34:09 INFO Uploading 1 narinfos14772026/10/01 10:34:09 INFO lead: acquired remote=192.0.2.1:123414782026/10/01 10:34:09 WARN Failed to register uploaded object key=log/qzw0nwjl1wya8dvqj78907pq4fha53b4-ca-test.drv error="server returned 404: 404 page not found\n"14792026/10/01 10:34:09 INFO Received push request method=POST path=/api/pushes14802026/10/01 10:34:09 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"14812026/10/01 10:34:09 WARN Failed to register uploaded object key=6w5jd6z98q4rpgngibcbd8bh57v7bwrs.ls error="server returned 404: 404 page not found\n"14822026/10/01 10:34:09 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14832026/10/01 10:34:09 INFO Received complete push request method=POST path=/api/pushes/1/complete1484=== CONT TestUploadHandlersRejectOversizedBody1485--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.06s)14862026/10/01 10:34:09 WARN Failed to register uploaded object key=xb2d42cpva3h7kmymw2j5a9rwwar6k2n.narinfo error="server returned 404: 404 page not found\n"14872026/10/01 10:34:09 INFO Signed narinfos id=1 count=114882026/10/01 10:34:09 INFO Uploading 1 narinfos1489=== NAME TestClientWithDependencies1490 client_integration_test.go:735: Built derivation: /build/TestClientWithDependencies3824794935/001/store/yz9fm9xdqvjlgg4g46l93csjv7wqdyma-test-script14912026/10/01 10:34:09 INFO Upload complete. (95ms)14922026/10/01 10:34:09 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1493=== NAME TestClientMultipleUploads1494 client_integration_test.go:480: Created store path 2: /build/TestClientMultipleUploads1552213165/001/store/24h43hkll51hlzbh4akgpz09lgvgj06d-test-file-2.txt14952026/10/01 10:34:09 INFO Received complete push request method=POST path=/api/pushes/1/complete14962026/10/01 10:34:09 WARN Failed to register uploaded object key=6w5jd6z98q4rpgngibcbd8bh57v7bwrs.narinfo error="server returned 404: 404 page not found\n"14972026/10/01 10:34:09 INFO Received complete push request method=POST path=/api/pushes/3/complete14982026/10/01 10:34:09 WARN Failed to register uploaded object key=d8394lankm5x898mb7ak0rsc0ib1qbrp.ls error="server returned 404: 404 page not found\n"14992026/10/01 10:34:09 INFO Upload complete. (155ms)15002026/10/01 10:34:09 INFO Upload complete. (88ms)1501=== NAME TestClientIntegration1502 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)1503 client_integration_test.go:405: Decompressed .ls content (49 bytes):1504 {"version":1,"root":{"type":"regular","size":39}}1505=== NAME TestClientCADerivations1506 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2493072658/001/store/6w5jd6z98q4rpgngibcbd8bh57v7bwrs-ca-test1507 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1508 Compression: zstd1509 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1510 NarSize: 1441511 References: 1512 Deriver: /build/TestClientCADerivations2493072658/001/store/qzw0nwjl1wya8dvqj78907pq4fha53b4-ca-test.drv1513 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1514 client_ca_test.go:185: Checking for realisation files in S3...1515=== NAME TestClientWithDependencies1516 client_integration_test.go:737: Found 1 dependencies (including self)1517=== NAME TestClientCADerivations1518 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1519 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1520--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.59s)1521=== CONT TestGCBugBareHashReferences15222026/10/01 10:34:10 INFO Received uploads request method=POST path=/api/pending_closures1523=== NAME TestNARDeduplicationMetadataUploadBug1524 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1761613923/001/store/psx0q4r4319j5a2wz38m37ga8bq9q80y-file1.txt15252026/10/01 10:34:10 INFO Received push request method=POST path=/api/pushes15262026/10/01 10:34:10 INFO Received uploads request method=POST path=/api/pending_closures15272026/10/01 10:34:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15282026/10/01 10:34:10 INFO Uploading dr6m79wfksjf58rg8cddljw2pn7akx8s-unpinned-file.txt (128B)15292026/10/01 10:34:10 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15302026/10/01 10:34:10 WARN Failed to register uploaded object key=dr6m79wfksjf58rg8cddljw2pn7akx8s.ls error="server returned 404: 404 page not found\n"15312026/10/01 10:34:10 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15322026/10/01 10:34:10 INFO Signed narinfos id=2 count=115332026/10/01 10:34:10 INFO Uploading 1 narinfos15342026/10/01 10:34:10 INFO Received uploads request method=POST path=/api/pending_closures15352026/10/01 10:34:10 INFO Received uploads request method=POST path=/api/pending_closures15362026/10/01 10:34:10 INFO Received uploads request method=POST path=/api/pending_closures15372026/10/01 10:34:10 INFO Received complete push request method=POST path=/api/pushes/2/complete15382026/10/01 10:34:10 WARN Failed to register uploaded object key=dr6m79wfksjf58rg8cddljw2pn7akx8s.narinfo error="server returned 404: 404 page not found\n"15392026/10/01 10:34:10 INFO Upload complete. (60ms)1540=== CONT TestUploadHandlersRejectInvalidKeys1541--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.23s)1542=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1543=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1544=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1545=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1546=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1547=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1548=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1549=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1550=== CONT TestService_AuthMiddleware15512026/10/01 10:34:10 INFO Received push request method=POST path=/api/pushes15522026/10/01 10:34:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15532026/10/01 10:34:10 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst15542026/10/01 10:34:10 INFO Received push request method=POST path=/api/pushes15552026/10/01 10:34:10 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15562026/10/01 10:34:10 INFO Uploading 24h43hkll51hlzbh4akgpz09lgvgj06d-test-file-2.txt (160B)15572026/10/01 10:34:10 INFO Uploading rjr0ypmr6v4j2w7bcr7mbkw913pvf3yb-test-file-0.txt (160B)15582026/10/01 10:34:10 INFO Uploading va2if0ya6njklwhld6azqi8szy1fwdzc-test-file-1.txt (160B)15592026/10/01 10:34:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15602026/10/01 10:34:10 INFO Uploading yz9fm9xdqvjlgg4g46l93csjv7wqdyma-test-script (136B)1561=== NAME TestClientCADerivations1562 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1563 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1564 error: binary cache 's3://bucket62?endpoint=http://localhost:45055®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2493072658/001/store'1565 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 115662026/10/01 10:34:10 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"1567--- PASS: TestCompleteMultipartUnregistered (0.20s)1568=== CONT TestConnectSerialisesConcurrentMigrations15692026/10/01 10:34:10 WARN Failed to register uploaded object key=rjr0ypmr6v4j2w7bcr7mbkw913pvf3yb.ls error="server returned 404: 404 page not found\n"15702026/10/01 10:34:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15712026/10/01 10:34:10 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15722026/10/01 10:34:10 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15732026/10/01 10:34:10 INFO Starting cleanup of old closures method=DELETE path=/api/closures15742026/10/01 10:34:10 INFO Received push request method=POST path=/api/pushes15752026/10/01 10:34:10 INFO Garbage collection started15762026/10/01 10:34:10 INFO Received push request method=POST path=/api/pushes15772026/10/01 10:34:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15782026/10/01 10:34:10 WARN Failed to register uploaded object key=24h43hkll51hlzbh4akgpz09lgvgj06d.ls error="server returned 404: 404 page not found\n"15792026/10/01 10:34:10 WARN Failed to register uploaded object key=va2if0ya6njklwhld6azqi8szy1fwdzc.ls error="server returned 404: 404 page not found\n"15802026/10/01 10:34:10 INFO Signed narinfos id=1 count=315812026/10/01 10:34:10 INFO Uploading 3 narinfos15822026/10/01 10:34:10 INFO Received uploads request method=POST path=/api/pending_closures15832026/10/01 10:34:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15842026/10/01 10:34:10 INFO Uploading 8fhy9k1d9pncapvgm3xvhv9x2mgsgcsf-lost-commit.txt (152B)15852026/10/01 10:34:10 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15862026/10/01 10:34:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15872026/10/01 10:34:10 WARN Failed to register uploaded object key=yz9fm9xdqvjlgg4g46l93csjv7wqdyma.ls error="server returned 404: 404 page not found\n"15882026/10/01 10:34:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15892026/10/01 10:34:10 WARN Failed to register uploaded object key=log/9i4aa1f5pyza83rxim291bifcaalbhjf-test-script.drv error="server returned 404: 404 page not found\n"15902026/10/01 10:34:10 INFO Uploading psx0q4r4319j5a2wz38m37ga8bq9q80y-file1.txt (160B)15912026/10/01 10:34:10 WARN Failed to register uploaded object key=rjr0ypmr6v4j2w7bcr7mbkw913pvf3yb.narinfo error="server returned 404: 404 page not found\n"15922026/10/01 10:34:10 INFO Signed narinfos id=1 count=115932026/10/01 10:34:10 WARN Failed to register uploaded object key=24h43hkll51hlzbh4akgpz09lgvgj06d.narinfo error="server returned 404: 404 page not found\n"15942026/10/01 10:34:10 INFO Uploading 1 narinfos15952026/10/01 10:34:10 INFO Aborted multipart uploads count=0 kept=015962026/10/01 10:34:10 INFO Received complete push request method=POST path=/api/pushes/1/complete15972026/10/01 10:34:10 WARN Failed to register uploaded object key=va2if0ya6njklwhld6azqi8szy1fwdzc.narinfo error="server returned 404: 404 page not found\n"15982026/10/01 10:34:10 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"15992026/10/01 10:34:10 WARN Force mode enabled - objects will be deleted immediately without grace period1600=== CONT TestService_ReadAuthMiddleware1601--- PASS: TestClientCADerivations (0.76s)16022026/10/01 10:34:10 INFO Upload complete. (122ms)1603=== NAME TestClientMultipleUploads1604 client_integration_test.go:491: Uploaded 3 paths in 158.534116ms16052026/10/01 10:34:10 INFO Received complete push request method=POST path=/api/pushes/1/complete16062026/10/01 10:34:10 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"16072026/10/01 10:34:10 WARN Failed to register uploaded object key=8fhy9k1d9pncapvgm3xvhv9x2mgsgcsf.ls error="server returned 404: 404 page not found\n"16082026/10/01 10:34:10 WARN Failed to register uploaded object key=yz9fm9xdqvjlgg4g46l93csjv7wqdyma.narinfo error="server returned 404: 404 page not found\n"16092026/10/01 10:34:10 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign16102026/10/01 10:34:10 INFO Signed narinfos id=4 count=116112026/10/01 10:34:10 INFO Uploading 1 narinfos16122026/10/01 10:34:10 INFO Received uploads request method=POST path=/api/pending_closures16132026/10/01 10:34:10 INFO Received cleanup request method=DELETE path=/api/pending_closures16142026/10/01 10:34:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16152026/10/01 10:34:10 WARN Failed to register uploaded object key=psx0q4r4319j5a2wz38m37ga8bq9q80y.ls error="server returned 404: 404 page not found\n"16162026/10/01 10:34:10 INFO Signed narinfos id=1 count=116172026/10/01 10:34:10 INFO Uploading 1 narinfos16182026/10/01 10:34:10 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket74/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""16192026/10/01 10:34:10 INFO Aborted multipart uploads count=0 kept=116202026/10/01 10:34:10 INFO Upload complete. (100ms)16212026/10/01 10:34:10 INFO Received complete push request method=POST path=/api/pushes/4/complete16222026/10/01 10:34:10 WARN Failed to register uploaded object key=8fhy9k1d9pncapvgm3xvhv9x2mgsgcsf.narinfo error="server returned 404: 404 page not found\n"16232026/10/01 10:34:10 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NDcxODI4MjEtYjQ5MC00ZTlkLTlmNmUtMmM0YTMxNDBiM2Y0LmQzYWJmMDMyLTg4Y2MtNDg0Ny04YjFiLTgwMTQ3MGY4NTYyMHgxNzkwODUwODQ5NDM5NjEyMTIx parts=1216242026/10/01 10:34:10 INFO Received uploads request method=POST path=/api/pending_closures16252026/10/01 10:34:10 INFO Received uploads request method=POST path=/api/pending_closures16262026/10/01 10:34:10 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://127.0.0.1:44703/api/pushes/4/complete\": EOF" url=http://127.0.0.1:44703/api/pushes/4/complete16272026/10/01 10:34:10 INFO Received complete push request method=POST path=/api/pushes/1/complete16282026/10/01 10:34:10 WARN Failed to register uploaded object key=psx0q4r4319j5a2wz38m37ga8bq9q80y.narinfo error="server returned 404: 404 page not found\n"16292026/10/01 10:34:10 INFO Received cleanup request method=DELETE path=/api/pending_closures16302026/10/01 10:34:10 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=016312026/10/01 10:34:10 INFO Aborted multipart uploads count=1 kept=016322026/10/01 10:34:10 INFO Vacuumed table table=pending_closures16332026/10/01 10:34:10 INFO Upload complete. (84ms)16342026/10/01 10:34:10 INFO Received cleanup request method=DELETE path=/api/pending_closures1635=== NAME TestNARDeduplicationMetadataUploadBug1636 metadata_upload_test.go:54: Retrieved narinfo from S3:1637 StorePath: /build/TestNARDeduplicationMetadataUploadBug1761613923/001/store/psx0q4r4319j5a2wz38m37ga8bq9q80y-file1.txt1638 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1639 Compression: zstd1640 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1641 NarSize: 1601642 References: 1643 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf16442026/10/01 10:34:10 INFO Aborted multipart uploads count=0 kept=016452026/10/01 10:34:10 INFO Vacuumed table table=pending_objects16462026/10/01 10:34:10 INFO Vacuumed table table=multipart_uploads16472026/10/01 10:34:10 INFO Vacuumed table table=closures16482026/10/01 10:34:10 WARN Force mode enabled - objects will be deleted immediately without grace period1649 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1650 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1651 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}16522026/10/01 10:34:10 INFO Vacuumed table table=objects16532026/10/01 10:34:10 INFO Received uploads request method=POST path=/api/pending_closures16542026/10/01 10:34:10 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=016552026/10/01 10:34:10 INFO Vacuumed table table=pending_closures16562026/10/01 10:34:10 INFO Vacuumed table table=pending_objects1657--- PASS: TestMultipartCleanup (0.36s)1658--- PASS: TestClientMultipleUploads (0.65s)1659=== CONT TestReadProxyOutlastsServerWriteTimeout1660=== CONT TestReadProxyHead16612026/10/01 10:34:10 INFO Vacuumed table table=multipart_uploads16622026/10/01 10:34:10 INFO Vacuumed table table=closures16632026/10/01 10:34:10 INFO Vacuumed table table=objects1664=== NAME TestClientWithDependencies1665 client_integration_test.go:753: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3824794935/001/store) requires matching store prefix1666--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.26s)1667=== CONT TestIsValidUploadKey1668=== RUN TestIsValidUploadKey/narinfo1669=== PAUSE TestIsValidUploadKey/narinfo1670=== RUN TestIsValidUploadKey/nar_zst1671=== PAUSE TestIsValidUploadKey/nar_zst1672=== RUN TestIsValidUploadKey/nar_xz1673=== PAUSE TestIsValidUploadKey/nar_xz1674=== RUN TestIsValidUploadKey/nar_plain1675=== PAUSE TestIsValidUploadKey/nar_plain1676=== RUN TestIsValidUploadKey/listing1677=== PAUSE TestIsValidUploadKey/listing1678=== RUN TestIsValidUploadKey/build_log1679=== PAUSE TestIsValidUploadKey/build_log1680=== RUN TestIsValidUploadKey/build_log_home-manager_file1681=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1682=== RUN TestIsValidUploadKey/build_log_plus_in_name1683=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1684=== RUN TestIsValidUploadKey/build_log_question_mark1685=== PAUSE TestIsValidUploadKey/build_log_question_mark1686=== RUN TestIsValidUploadKey/build_log_equals1687=== PAUSE TestIsValidUploadKey/build_log_equals1688=== RUN TestIsValidUploadKey/realisation1689=== PAUSE TestIsValidUploadKey/realisation1690=== RUN TestIsValidUploadKey/realisation_plus_in_output1691=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1692=== RUN TestIsValidUploadKey/nix-cache-info1693=== PAUSE TestIsValidUploadKey/nix-cache-info1694=== RUN TestIsValidUploadKey/index.html1695=== PAUSE TestIsValidUploadKey/index.html1696=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1697=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1698=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1699=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1700=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1701=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1702=== RUN TestIsValidUploadKey/traversal1703=== PAUSE TestIsValidUploadKey/traversal1704=== RUN TestIsValidUploadKey/traversal_nar1705=== PAUSE TestIsValidUploadKey/traversal_nar1706=== RUN TestIsValidUploadKey/absolute1707=== PAUSE TestIsValidUploadKey/absolute1708=== RUN TestIsValidUploadKey/empty_key1709=== PAUSE TestIsValidUploadKey/empty_key1710=== RUN TestIsValidUploadKey/unknown_type1711=== PAUSE TestIsValidUploadKey/unknown_type1712=== CONT TestReadProxyNarStreaming17132026-10-01 10:34:10.184 UTC [1838] ERROR: duplicate key value violates unique constraint "pg_type_typname_nsp_index"17142026-10-01 10:34:10.184 UTC [1838] DETAIL: Key (typname, typnamespace)=(goose_db_version, 2200) already exists.17152026-10-01 10:34:10.184 UTC [1838] STATEMENT: CREATE TABLE goose_db_version (1716 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1717 version_id bigint NOT NULL,1718 is_applied boolean NOT NULL,1719 tstamp timestamp NOT NULL DEFAULT now()1720 )17212026/10/01 10:34:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1722=== NAME TestNARDeduplicationMetadataUploadBug1723 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1761613923/001/store/iyv9scy4vwyc2w3b9mlvs079ax5h7g80-file2.txt1724--- PASS: TestClientWithDependencies (0.59s)1725=== CONT TestReadRedirectNar17262026/10/01 10:34:10 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NDcxODI4MjEtYjQ5MC00ZTlkLTlmNmUtMmM0YTMxNDBiM2Y0LmYzNDc4ZTA3LWY0NWEtNDg0NS04Mjk4LWUzODE3MzEyZGZjN3gxNzkwODUwODQ4OTc5NDI3NDkw parts=1017272026/10/01 10:34:10 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1728--- PASS: TestService_AuthMiddleware (0.16s)1729=== CONT TestReadProxyInvalidPath17302026/10/01 10:34:10 INFO Received complete push request method=POST path=/api/pushes/4/complete17312026-10-01 10:34:10.238 UTC [674] ERROR: Push does not exist: id=417322026-10-01 10:34:10.238 UTC [674] CONTEXT: PL/pgSQL function commit_push(bigint) line 9 at RAISE17332026-10-01 10:34:10.238 UTC [674] STATEMENT: -- name: CommitPush :exec1734 SELECT commit_push($1::bigint)1735 17362026/10/01 10:34:10 INFO Upload complete. (181ms)1737=== NAME TestClientIntegration1738 client_integration_test.go:435: Retrieved narinfo from S3:1739 StorePath: /build/TestClientIntegration1431695531/002/store/8fhy9k1d9pncapvgm3xvhv9x2mgsgcsf-lost-commit.txt1740 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1741 Compression: zstd1742 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1743 NarSize: 1521744 References: 1745 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1746 client_integration_test.go:438: Testing garbage collection...17472026/10/01 10:34:10 INFO Received push request method=POST path=/api/pushes17482026/10/01 10:34:10 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17492026/10/01 10:34:10 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17502026/10/01 10:34:10 WARN Failed to register uploaded object key=iyv9scy4vwyc2w3b9mlvs079ax5h7g80.ls error="server returned 404: 404 page not found\n"17512026/10/01 10:34:10 INFO Signed narinfos id=2 count=117522026/10/01 10:34:10 INFO Uploading 1 narinfos17532026/10/01 10:34:10 INFO Received complete push request method=POST path=/api/pushes/2/complete17542026/10/01 10:34:10 WARN Failed to register uploaded object key=iyv9scy4vwyc2w3b9mlvs079ax5h7g80.narinfo error="server returned 404: 404 page not found\n"17552026/10/01 10:34:10 INFO Starting cleanup of old closures method=DELETE path=/api/closures17562026/10/01 10:34:10 INFO Garbage collection started17572026/10/01 10:34:10 INFO Upload complete. (62ms)1758=== NAME TestNARDeduplicationMetadataUploadBug1759 metadata_upload_test.go:76: Retrieved narinfo from S3:1760 StorePath: /build/TestNARDeduplicationMetadataUploadBug1761613923/001/store/iyv9scy4vwyc2w3b9mlvs079ax5h7g80-file2.txt1761 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1762 Compression: zstd1763 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1764 NarSize: 1601765 References: 1766 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf17672026/10/01 10:34:10 INFO Aborted multipart uploads count=0 kept=01768 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1769 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1770 {"version":1,"root":{"type":"regular","size":44}}17712026/10/01 10:34:10 WARN Force mode enabled - objects will be deleted immediately without grace period1772--- PASS: TestService_ReadAuthMiddleware (0.19s)1773=== CONT TestService_cleanupPendingClosuresHandler17742026/10/01 10:34:10 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=01775--- PASS: TestNARDeduplicationMetadataUploadBug (0.61s)1776=== CONT TestPushWaitsForSweepHoldingRow17772026/10/01 10:34:10 INFO Vacuumed table table=pending_closures17782026/10/01 10:34:10 INFO Vacuumed table table=pending_objects17792026/10/01 10:34:10 INFO Vacuumed table table=multipart_uploads17802026/10/01 10:34:10 INFO Vacuumed table table=closures17812026/10/01 10:34:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17822026/10/01 10:34:10 INFO Vacuumed table table=objects17832026/10/01 10:34:10 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NDcxODI4MjEtYjQ5MC00ZTlkLTlmNmUtMmM0YTMxNDBiM2Y0LjhkNmZjMWQ4LWVhNGEtNGY0Mi1hZTBlLTU4ZDI1ZjFjZGM3YngxNzkwODUwODQ5ODM2NDAwMTQ1 parts=1017842026/10/01 10:34:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17852026/10/01 10:34:10 INFO Completed upload id=117862026/10/01 10:34:10 INFO Received uploads request method=POST path=/api/pending_closures17872026/10/01 10:34:10 INFO Received uploads request method=POST path=/api/pending_closures17882026/10/01 10:34:10 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo17892026/10/01 10:34:10 WARN Found objects in DB but missing from S3, will re-upload count=117902026/10/01 10:34:10 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete17912026/10/01 10:34:10 INFO Completed upload id=317922026/10/01 10:34:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1793=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1794=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1795=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1796=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1797=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1798=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1799=== CONT TestProxyWriteTimeout/1_GiB_nar1800=== CONT TestProxyWriteTimeout/10_GiB_nar1801=== CONT TestProxyWriteTimeout/unknown_size1802=== CONT TestProxyWriteTimeout/narinfo1803=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1804--- PASS: TestProxyWriteTimeout (0.00s)1805 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1806 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1807 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1808 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1809=== CONT TestIsValidCachePath/short_hash18102026/10/01 10:34:10 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo1811=== CONT TestIsValidCachePath/wrong_extension1812=== CONT TestIsValidCachePath/leading_slash1813=== CONT TestIsValidCachePath/empty1814=== CONT TestIsValidCachePath/log1815=== CONT TestIsValidCachePath/invalid_char_u1816=== CONT TestIsValidCachePath/invalid_char_e1817=== CONT TestIsValidCachePath/random_path1818=== CONT TestIsValidCachePath/traversal_in_middle1819=== CONT TestIsValidCachePath/traversal_parent1820=== CONT TestIsValidCachePath/index.html1821=== CONT TestIsValidCachePath/realisation1822=== CONT TestIsValidCachePath/nar_xz1823=== CONT TestIsValidCachePath/ls18242026/10/01 10:34:10 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NDcxODI4MjEtYjQ5MC00ZTlkLTlmNmUtMmM0YTMxNDBiM2Y0LmNiOTI0MzUzLTEwM2EtNDY1My1iY2FhLWI3YjZjNTk1MzcxZHgxNzkwODUwODQ5MzI4NDEzMTI3 parts=101825=== CONT TestIsValidCachePath/nix-cache-info1826=== CONT TestIsValidCachePath/nar_bz21827=== CONT TestIsValidCachePath/nar_uncompressed1828=== CONT TestIsValidCachePath/nar_zst1829=== CONT TestIsValidCachePath/narinfo1830=== CONT TestParseSingleRange/unknown_unit1831--- PASS: TestIsValidCachePath (0.00s)1832 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1833 --- PASS: TestIsValidCachePath/short_hash (0.00s)1834 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1835 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1836 --- PASS: TestIsValidCachePath/empty (0.00s)1837 --- PASS: TestIsValidCachePath/log (0.00s)1838 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1839 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1840 --- PASS: TestIsValidCachePath/random_path (0.00s)1841 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1842 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1843 --- PASS: TestIsValidCachePath/index.html (0.00s)1844 --- PASS: TestIsValidCachePath/realisation (0.00s)1845 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1846 --- PASS: TestIsValidCachePath/ls (0.00s)1847 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1848 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1849 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1850 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1851 --- PASS: TestIsValidCachePath/narinfo (0.00s)1852=== CONT TestParseSingleRange/start_far_past_EOF1853=== CONT TestParseSingleRange/closed1854=== CONT TestParseSingleRange/start_past_EOF1855=== CONT TestParseSingleRange/suffix_exceeds_size1856=== CONT TestParseSingleRange/suffix1857=== CONT TestParseSingleRange/single_byte1858=== CONT TestParseSingleRange/open-ended1859=== CONT TestParseSingleRange/malformed_end_before_start1860=== CONT TestParseSingleRange/end_clamped_to_size1861=== CONT TestParseSingleRange/malformed_both_empty1862=== CONT TestParseSingleRange/malformed_no_dash1863--- PASS: TestService_verifyS3Integrity (1.02s)1864=== CONT TestParseSingleRange/multi-range_ignored1865=== CONT TestParseSingleRange/none1866=== CONT TestCacheConfigHandler/no_cache_url_configured1867=== CONT TestCacheConfigHandler/full_config,_no_issuer1868--- PASS: TestParseSingleRange (0.01s)1869 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1870 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1871 --- PASS: TestParseSingleRange/closed (0.00s)1872 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1873 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1874 --- PASS: TestParseSingleRange/suffix (0.00s)1875 --- PASS: TestParseSingleRange/single_byte (0.00s)1876 --- PASS: TestParseSingleRange/open-ended (0.00s)1877 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1878 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1879 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1880 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1881 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1882 --- PASS: TestParseSingleRange/none (0.00s)1883=== CONT TestCacheConfigHandler/no_signing_keys1884=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1885=== CONT TestClientErrorHandling/InvalidStorePath1886--- PASS: TestCacheConfigHandler (0.00s)1887 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1888 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1889 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1890 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1891=== CONT TestClientErrorHandling/InvalidAuthToken18922026/10/01 10:34:10 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo1893--- PASS: TestGCBugBareHashReferences (0.45s)1894--- PASS: TestReadProxyNarStreaming (0.29s)1895=== CONT TestClientErrorHandling/ServerNotAvailable1896=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete18972026/10/01 10:34:10 INFO Received complete push request method=POST path=/api/pushes/1/complete18982026/10/01 10:34:10 INFO Received push request method=POST path=/api/pushes1899=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1900--- PASS: TestReadRedirectNar (0.29s)1901--- PASS: TestConcurrentPinUpdatesAgree (0.83s)1902=== CONT TestGCEndsOnShutdown/before_the_run1903--- PASS: TestReadProxyInvalidPath (0.27s)1904=== CONT TestPendingClosureWriteTimeout/400_objects1905=== CONT TestPendingClosureWriteTimeout/670k_objects1906=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1907=== CONT TestPendingClosureWriteTimeout/empty1908--- PASS: TestReadProxyHead (0.36s)1909=== CONT TestPush_RejectsBadRequests/no_objects19102026/10/01 10:34:10 INFO Received push request method=POST path=/api/pushes1911=== CONT TestPush_RejectsBadRequests/root_not_in_objects19122026/10/01 10:34:10 INFO Received push request method=POST path=/api/pushes1913=== CONT TestPush_RejectsBadRequests/bad_root19142026/10/01 10:34:10 INFO Received push request method=POST path=/api/pushes1915=== CONT TestPush_RejectsBadRequests/no_roots19162026/10/01 10:34:10 INFO Received push request method=POST path=/api/pushes1917=== CONT TestService_RequireScope_OIDC/builder_may_write1918=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1919=== CONT TestService_RequireScope_OIDC/writer_implies_read1920=== CONT TestService_RequireScope_OIDC/ops_may_not_write1921=== CONT TestService_RequireScope_OIDC/reader_may_not_write1922=== CONT TestService_RequireScope_OIDC/reader_may_read1923=== CONT TestService_RequireScope_OIDC/static_token_may_admin1924=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1925=== CONT TestService_RequireScope_OIDC/static_token_may_write1926=== CONT TestService_RequireScope_OIDC/ops_may_admin1927=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check19282026/10/01 10:34:10 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/present19292026/10/01 10:34:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1930--- PASS: TestPush_RejectsBadRequests (0.68s)1931 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1932 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1933 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1934 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)19352026/10/01 10:34:10 INFO Aborted multipart uploads count=0 kept=019362026/10/01 10:34:10 INFO Received uploads request method=POST path=/api/pending_closures19372026/10/01 10:34:10 WARN Force mode enabled - objects will be deleted immediately without grace period1938--- PASS: TestService_RequireScope_OIDC (0.62s)1939 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1940 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1941 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1942 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1943 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1944 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1945 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1946 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1947 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1948 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)19492026/10/01 10:34:10 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NDcxODI4MjEtYjQ5MC00ZTlkLTlmNmUtMmM0YTMxNDBiM2Y0LmIwNDE2MTcxLTYyNzYtNGFjMC1hY2M2LWI1ZDFmZDQzYTllOXgxNzkwODUwODUwMDYzNTI0MjU0 parts=1019502026/10/01 10:34:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19512026/10/01 10:34:10 INFO Completed upload id=119522026/10/01 10:34:10 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000019532026/10/01 10:34:10 INFO Received uploads request method=POST path=/api/pending_closures19542026/10/01 10:34:10 INFO Received cleanup request method=DELETE path=/api/pending_closures19552026/10/01 10:34:10 INFO Starting cleanup of old closures method=DELETE path=/api/closures19562026/10/01 10:34:10 INFO Aborted multipart uploads count=0 kept=019572026/10/01 10:34:10 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=019582026/10/01 10:34:10 INFO Received uploads request method=POST path=/api/pending_closures19592026/10/01 10:34:10 INFO Vacuumed table table=pending_closures19602026/10/01 10:34:10 INFO Vacuumed table table=pending_objects19612026/10/01 10:34:10 INFO Aborted multipart uploads count=0 kept=019622026/10/01 10:34:10 INFO Vacuumed table table=multipart_uploads19632026/10/01 10:34:10 INFO Vacuumed table table=closures19642026/10/01 10:34:10 INFO Vacuumed table table=objects19652026/10/01 10:34:10 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=019662026/10/01 10:34:10 INFO Received cleanup request method=DELETE path=/api/pending_closures19672026/10/01 10:34:10 INFO Vacuumed table table=pending_closures19682026/10/01 10:34:10 INFO Aborted multipart uploads count=1 kept=019692026/10/01 10:34:10 INFO Vacuumed table table=pending_objects19702026/10/01 10:34:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete19712026-10-01 10:34:10.603 UTC [1930] ERROR: Closure does not exist: id=119722026-10-01 10:34:10.603 UTC [1930] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE19732026-10-01 10:34:10.603 UTC [1930] STATEMENT: -- name: CommitPendingClosure :exec1974 SELECT commit_pending_closure($1::bigint)1975 19762026/10/01 10:34:10 INFO Vacuumed table table=multipart_uploads19772026/10/01 10:34:10 INFO Vacuumed table table=closures19782026/10/01 10:34:10 INFO Vacuumed table table=objects19792026/10/01 10:34:10 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001980--- PASS: TestService_cleanupPendingClosuresHandler (0.32s)1981=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows19822026/10/01 10:34:10 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=197.829034ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1983=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1984--- PASS: TestService_createPendingClosureHandler (0.79s)1985=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1986=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected19872026/10/01 10:34:10 WARN Authentication failed token_preview=eyJhbGciOi...oc2__BdXqQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1988=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected19892026/10/01 10:34:10 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]1990=== CONT TestResolveDBConnectionString/file_when_flag_empty1991=== CONT TestResolveDBConnectionString/nothing_configured1992=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1993=== CONT TestResolveDBConnectionString/missing_file_is_an_error1994=== CONT TestResolveDBConnectionString/flag_wins1995=== CONT TestServerTLSConfig/not_a_PEM_file1996--- PASS: TestResolveDBConnectionString (0.00s)1997 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1998 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1999 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2000 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2001 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2002=== CONT TestServerTLSConfig/missing_CA_file2003=== CONT TestServerTLSConfig/no_client_CA2004=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key2005--- PASS: TestServerTLSConfig (0.00s)2006 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2007 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2008 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)20092026/10/01 10:34:10 INFO Received complete multipart upload request method=POST path=/2010=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal20112026/10/01 10:34:10 INFO Received uploads request method=POST path=/2012=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key20132026/10/01 10:34:10 INFO Received request for more parts method=POST path=/2014=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info20152026/10/01 10:34:10 INFO Received uploads request method=POST path=/2016=== CONT TestIsValidUploadKey/narinfo2017--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2018 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2019 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2020 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2021 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2022=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2023=== CONT TestIsValidUploadKey/absolute2024=== CONT TestIsValidUploadKey/traversal_nar2025=== CONT TestIsValidUploadKey/build_log_home-manager_file2026=== CONT TestIsValidUploadKey/nix-cache-info2027=== CONT TestIsValidUploadKey/traversal2028=== CONT TestIsValidUploadKey/build_log_equals2029=== CONT TestIsValidUploadKey/realisation2030=== CONT TestIsValidUploadKey/empty_key2031=== CONT TestIsValidUploadKey/nar_xz2032=== CONT TestIsValidUploadKey/build_log_question_mark2033=== CONT TestIsValidUploadKey/nar_plain2034=== CONT TestIsValidUploadKey/nar_zst2035=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2036=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2037=== CONT TestIsValidUploadKey/index.html2038=== CONT TestIsValidUploadKey/unknown_type2039=== CONT TestIsValidUploadKey/realisation_plus_in_output2040=== CONT TestIsValidUploadKey/build_log2041=== CONT TestIsValidUploadKey/build_log_plus_in_name2042=== CONT TestIsValidUploadKey/listing2043=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart2044--- PASS: TestIsValidUploadKey (0.00s)2045 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2046 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2047 --- PASS: TestIsValidUploadKey/absolute (0.00s)2048 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2049 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2050 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2051 --- PASS: TestIsValidUploadKey/traversal (0.00s)2052 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2053 --- PASS: TestIsValidUploadKey/realisation (0.00s)2054 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2055 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2056 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2057 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2058 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2059 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2060 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2061 --- PASS: TestIsValidUploadKey/index.html (0.00s)2062 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2063 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2064 --- PASS: TestIsValidUploadKey/build_log (0.00s)2065 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2066 --- PASS: TestIsValidUploadKey/listing (0.00s)20672026/10/01 10:34:10 INFO Received complete multipart upload request method=POST path=/2068=== NAME TestOrphanedObjectsGCStressTest2069 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains20702026/10/01 10:34:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20712026/10/01 10:34:10 INFO Aborted multipart uploads count=0 kept=020722026/10/01 10:34:10 WARN Force mode enabled - objects will be deleted immediately without grace period2073--- PASS: TestService_AuthMiddleware_OIDC (0.83s)2074 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2075 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2076 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2077 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)20782026/10/01 10:34:10 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NDcxODI4MjEtYjQ5MC00ZTlkLTlmNmUtMmM0YTMxNDBiM2Y0LjdiNjgyNjIxLTdkMDAtNGU1YS1hMDBhLTI1NmQ0YTM4N2YwY3gxNzkwODUwODQ4OTc4MTUyMTU4 parts=1020792026/10/01 10:34:10 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:45055/bucket90/?delete=\": context canceled"20802026/10/01 10:34:10 INFO Received complete push request method=POST path=/api/pushes/1/complete2081=== NAME TestOrphanedObjectsGCStressTest2082 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion20832026/10/01 10:34:10 INFO lead: released remote=192.0.2.1:12342084=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure20852026/10/01 10:34:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20862026/10/01 10:34:10 INFO Received uploads request method=POST path=/20872026/10/01 10:34:10 INFO Aborted multipart uploads count=0 kept=020882026/10/01 10:34:10 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NDcxODI4MjEtYjQ5MC00ZTlkLTlmNmUtMmM0YTMxNDBiM2Y0LjY1M2VkMDhmLWVkYzYtNDFhZC04ZGFhLTA2MGI4OTJmNzViMHgxNzkwODUwODUwMTU3MTIzMDMw error="Get \"http://127.0.0.1:1/bucket52/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"20892026/10/01 10:34:10 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NDcxODI4MjEtYjQ5MC00ZTlkLTlmNmUtMmM0YTMxNDBiM2Y0LmUwYjI0ZDAwLWZkOGYtNDQ2Zi1iNWZmLTZhOGUxNWU3NTc4OHgxNzkwODUwODUwMTQxODUyMDU0 parts=1220902026/10/01 10:34:10 WARN Force mode enabled - objects will be deleted immediately without grace period2091=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts2092--- PASS: TestLeadEndsOnShutdown (1.43s)20932026/10/01 10:34:10 INFO Received request for more parts method=POST path=/20942026/10/01 10:34:10 INFO Received cleanup request method=DELETE path=/api/pending_closures2095--- PASS: TestPush_CompleteCommitsEveryRoot (2.06s)20962026-10-01 10:34:10.723 UTC [2029] ERROR: canceling statement due to user request20972026-10-01 10:34:10.723 UTC [2029] CONTEXT: PL/pgSQL function object_stats_apply() line 5 at statement block20982026-10-01 10:34:10.723 UTC [2029] STATEMENT: -- name: MarkStaleObjects :execrows2099 WITH RECURSIVE ct AS (2100 SELECT timezone('UTC', now()) AS now2101 ),2102 closure_reach AS (2103 -- Start with all closure keys2104 SELECT o.key, o.refs2105 FROM objects o2106 INNER JOIN closures c ON o.key = c.key2107 UNION2108 -- Recursively add all referenced objects2109 SELECT o.key, o.refs2110 FROM objects o2111 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2112 ),2113 reachable_objects AS (2114 SELECT DISTINCT key FROM closure_reach2115 ),2116 stale_objects AS (2117 SELECT o.key2118 FROM objects AS o, ct2119 WHERE2120 NOT EXISTS (2121 SELECT 12122 FROM reachable_objects ro2123 WHERE ro.key = o.key2124 )2125 AND NOT EXISTS (2126 SELECT 12127 FROM pending_objects AS po2128 WHERE po.key = o.key2129 )2130 AND o.deleted_at IS NULL -- Only mark fresh objects2131 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2132 FOR UPDATE2133 )2134 UPDATE objects2135 SET2136 deleted_at = ct.now,2137 first_deleted_at = COALESCE(first_deleted_at, ct.now)2138 FROM stale_objects, ct2139 WHERE objects.key = stale_objects.key2140 21412026/10/01 10:34:10 INFO Aborted multipart uploads count=1 kept=021422026/10/01 10:34:10 INFO Received uploads request method=POST path=/api/pending_closures2143--- PASS: TestRedundantMultipartUpload (1.72s)2144--- PASS: TestGCEndsOnShutdown (0.00s)2145 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.24s)2146 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.27s)2147 --- PASS: TestGCEndsOnShutdown/before_the_run (0.30s)21482026/10/01 10:34:10 INFO Received uploads request method=POST path=/api/pending_closures21492026/10/01 10:34:10 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21502026/10/01 10:34:10 INFO Aborted multipart uploads count=0 kept=021512026/10/01 10:34:10 WARN Force mode enabled - objects will be deleted immediately without grace period21522026/10/01 10:34:10 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=021532026/10/01 10:34:10 INFO Received uploads request method=POST path=/api/pending_closures21542026/10/01 10:34:10 INFO Vacuumed table table=pending_closures21552026/10/01 10:34:10 INFO Vacuumed table table=pending_objects21562026/10/01 10:34:10 INFO Vacuumed table table=multipart_uploads21572026/10/01 10:34:10 INFO Vacuumed table table=closures21582026/10/01 10:34:10 INFO Vacuumed table table=objects21592026/10/01 10:34:10 INFO Aborted multipart uploads count=0 kept=021602026/10/01 10:34:10 WARN Force mode enabled - objects will be deleted immediately without grace period21612026/10/01 10:34:10 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=021622026/10/01 10:34:10 INFO Vacuumed table table=pending_closures21632026/10/01 10:34:10 INFO Vacuumed table table=pending_objects21642026/10/01 10:34:10 INFO Vacuumed table table=multipart_uploads21652026/10/01 10:34:10 INFO Vacuumed table table=closures21662026/10/01 10:34:10 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21672026/10/01 10:34:10 INFO Vacuumed table table=objects21682026/10/01 10:34:10 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=375.95518ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2169--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2170 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.30s)2171 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.22s)2172=== NAME TestOrphanedObjectsGCStressTest2173 orphaned_objects_gc_test.go:509: Stress test completed successfully:2174 orphaned_objects_gc_test.go:510: - Active objects preserved: 202175 orphaned_objects_gc_test.go:511: - Objects deleted: 2102176 orphaned_objects_gc_test.go:512: - Total GC'd: 2102177--- PASS: TestOrphanedObjectsGCStressTest (2.94s)21782026/10/01 10:34:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2179--- PASS: TestPushWaitsForSweepHoldingRow (0.74s)21802026/10/01 10:34:11 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NDcxODI4MjEtYjQ5MC00ZTlkLTlmNmUtMmM0YTMxNDBiM2Y0LmE3NDBiYjllLThjZTctNDhjOC1iNzUzLTkwMDg4YjJkNjNlMXgxNzkwODUwODUwNDg0NjY0OTU2 parts=1021812026/10/01 10:34:11 INFO Received complete push request method=POST path=/api/pushes/2/complete2182--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.16s)21832026/10/01 10:34:11 INFO lead: released remote=192.0.2.1:12342184--- PASS: TestConnectSerialisesConcurrentMigrations (1.10s)21852026/10/01 10:34:11 INFO lead: acquired remote=192.0.2.1:123421862026/10/01 10:34:11 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=860.823754ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2187--- PASS: TestPendingClosureWriteTimeout (0.00s)2188 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2189 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2190 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2191 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.07s)21922026/10/01 10:34:12 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.744826548s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21932026/10/01 10:34:12 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021942026/10/01 10:34:12 INFO Received create pin request method=POST path=/api/pins/myapp21952026/10/01 10:34:12 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC4198171417/001/store/xb2d42cpva3h7kmymw2j5a9rwwar6k2n-pinned-file.txt narinfo_key=xb2d42cpva3h7kmymw2j5a9rwwar6k2n.narinfo21962026/10/01 10:34:12 INFO Starting cleanup of old closures method=DELETE path=/api/closures21972026/10/01 10:34:12 INFO Garbage collection started21982026/10/01 10:34:12 INFO Aborted multipart uploads count=0 kept=021992026/10/01 10:34:12 WARN Force mode enabled - objects will be deleted immediately without grace period22002026/10/01 10:34:12 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=022012026/10/01 10:34:12 INFO Vacuumed table table=pending_closures22022026/10/01 10:34:12 INFO Vacuumed table table=pending_objects22032026/10/01 10:34:12 INFO Vacuumed table table=multipart_uploads22042026/10/01 10:34:12 INFO Vacuumed table table=closures22052026/10/01 10:34:12 INFO Vacuumed table table=objects22062026/10/01 10:34:12 INFO lead: released remote=192.0.2.1:12342207--- PASS: TestLeadElectsOneAndHandsOver (2.59s)22082026/10/01 10:34:12 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02209=== NAME TestClientIntegration2210 client_integration_test.go:445: Objects in database after GC:2211 client_integration_test.go:445: Successfully deleted all objects with GC --force2212--- PASS: TestClientIntegration (3.13s)22132026/10/01 10:34:12 WARN Rate limiter enabled after throttle name=s3-test rate=522142026/10/01 10:34:12 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2215=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2216 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102217 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002218--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.83s)22192026/10/01 10:34:13 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-config22202026/10/01 10:34:13 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=204.931235ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2221=== NAME TestPinProtectsFromGC2222 client_integration_test.go:976: Pin successfully protected closure from garbage collection2223--- PASS: TestPinProtectsFromGC (4.71s)22242026/10/01 10:34:14 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=417.674932ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22252026/10/01 10:34:14 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=816.252964ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2226--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.54s)2227--- PASS: TestConnectWaitsForAPeerMigration (5.14s)22282026/10/01 10:34:15 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.461956539s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22292026/10/01 10:34:16 INFO Aborted multipart uploads count=1 kept=022302026/10/01 10:34:16 INFO Received cleanup request method=DELETE path=/api/pending_closures22312026/10/01 10:34:16 INFO Aborted multipart uploads count=1 kept=02232--- PASS: TestPendingCleanupUsesOneCutoff (6.27s)22332026/10/01 10:34:16 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"22342026/10/01 10:34:16 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-config22352026/10/01 10:34:16 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=182.408236ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22362026/10/01 10:34:17 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=414.183094ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22372026/10/01 10:34:17 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=725.226065ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22382026/10/01 10:34:18 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.485768814s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22392026/10/01 10:34:19 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_closures22402026/10/01 10:34:19 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=212.475277ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22412026/10/01 10:34:20 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=386.829218ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22422026/10/01 10:34:20 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=876.42455ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22432026/10/01 10:34:21 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.605288378s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2244--- PASS: TestClientErrorHandling (0.00s)2245 --- PASS: TestClientErrorHandling/InvalidStorePath (0.27s)2246 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.39s)2247 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.52s)2248--- PASS: TestUploadHandlersRejectOversizedBody (0.49s)2249 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.86s)2250 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.85s)2251 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (14.57s)2252PASS2253{"timestamp":"2026-10-01T10:34:25.276492171Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:52260","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(206)"}2254{"timestamp":"2026-10-01T10:34:25.277089896Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:52564","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(194)"}2255{"timestamp":"2026-10-01T10:34:25.277180417Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:52634","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(204)"}22562026-10-01 10:34:25.538 UTC [168] LOG: received smart shutdown request22572026-10-01 10:34:25.542 UTC [168] LOG: background worker "logical replication launcher" (PID 178) exited with exit code 122582026-10-01 10:34:25.554 UTC [173] LOG: shutting down22592026-10-01 10:34:25.555 UTC [173] LOG: checkpoint starting: shutdown immediate22602026-10-01 10:34:26.093 UTC [173] LOG: checkpoint complete: wrote 9882 buffers (60.3%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 28 recycled; write=0.177 s, sync=0.337 s, total=0.539 s; sync files=33361, longest=0.004 s, average=0.001 s; distance=467293 kB, estimate=467293 kB; lsn=0/1DFBD318, redo lsn=0/1DFBD31822612026-10-01 10:34:26.158 UTC [168] LOG: database system is shut down2262Running OIDC tests...2263=== RUN TestAudienceForIssuer2264=== PAUSE TestAudienceForIssuer2265=== RUN TestHTTPClientForHasTimeouts2266=== PAUSE TestHTTPClientForHasTimeouts2267=== RUN TestGlobMatch2268=== PAUSE TestGlobMatch2269=== RUN TestValidateToken_ValidToken2270=== PAUSE TestValidateToken_ValidToken2271=== RUN TestValidateToken_WrongAudience2272=== PAUSE TestValidateToken_WrongAudience2273=== RUN TestValidateToken_Expired2274=== PAUSE TestValidateToken_Expired2275=== RUN TestValidateToken_BoundClaimsMismatch2276=== PAUSE TestValidateToken_BoundClaimsMismatch2277=== RUN TestValidateToken_BoundSubjectMismatch2278=== PAUSE TestValidateToken_BoundSubjectMismatch2279=== RUN TestValidateToken_MultipleProviders2280=== PAUSE TestValidateToken_MultipleProviders2281=== RUN TestValidateToken_NoMatchingProvider2282=== PAUSE TestValidateToken_NoMatchingProvider2283=== RUN TestValidateToken_KubernetesServiceAccount2284=== PAUSE TestValidateToken_KubernetesServiceAccount2285=== RUN TestNewValidator_KubernetesRequiresCA2286=== PAUSE TestNewValidator_KubernetesRequiresCA2287=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2288=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2289=== RUN TestPins_ReservedForMatchingRule2290=== PAUSE TestPins_ReservedForMatchingRule2291=== RUN TestPins_TopLevelShorthand2292=== PAUSE TestPins_TopLevelShorthand2293=== RUN TestPins_ConfigValidation2294=== PAUSE TestPins_ConfigValidation2295=== RUN TestScopes_LegacyProviderDefaultsToWrite2296=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2297=== RUN TestScopes_Rules2298=== PAUSE TestScopes_Rules2299=== RUN TestScopes_ConfigValidation2300=== PAUSE TestScopes_ConfigValidation2301=== CONT TestAudienceForIssuer2302=== CONT TestPins_TopLevelShorthand2303=== CONT TestScopes_LegacyProviderDefaultsToWrite2304=== CONT TestValidateToken_MultipleProviders2305=== CONT TestValidateToken_NoMatchingProvider2306=== CONT TestValidateToken_BoundSubjectMismatch2307=== CONT TestValidateToken_BoundClaimsMismatch2308=== CONT TestValidateToken_Expired2309=== CONT TestPins_ReservedForMatchingRule2310=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2311=== CONT TestScopes_ConfigValidation2312=== CONT TestScopes_Rules2313=== CONT TestValidateToken_ValidToken2314=== CONT TestValidateToken_WrongAudience2315=== CONT TestNewValidator_KubernetesRequiresCA2316=== CONT TestGlobMatch2317=== RUN TestGlobMatch/foo_foo2318=== PAUSE TestGlobMatch/foo_foo2319=== CONT TestHTTPClientForHasTimeouts2320=== CONT TestPins_ConfigValidation2321--- PASS: TestAudienceForIssuer (0.00s)2322=== CONT TestValidateToken_KubernetesServiceAccount2323=== RUN TestGlobMatch/foo_bar2324=== PAUSE TestGlobMatch/foo_bar2325=== RUN TestGlobMatch/*_2326=== PAUSE TestGlobMatch/*_2327=== RUN TestGlobMatch/*_anything2328--- PASS: TestScopes_ConfigValidation (0.00s)2329=== PAUSE TestGlobMatch/*_anything2330=== RUN TestGlobMatch/foo*_foo2331=== PAUSE TestGlobMatch/foo*_foo2332=== RUN TestGlobMatch/foo*_foobar2333=== PAUSE TestGlobMatch/foo*_foobar2334=== RUN TestGlobMatch/foo*_bar2335=== PAUSE TestGlobMatch/foo*_bar2336=== RUN TestGlobMatch/*bar_bar2337=== PAUSE TestGlobMatch/*bar_bar2338=== RUN TestGlobMatch/*bar_foobar2339=== PAUSE TestGlobMatch/*bar_foobar2340=== RUN TestGlobMatch/*bar_foo2341=== PAUSE TestGlobMatch/*bar_foo2342=== RUN TestGlobMatch/foo*bar_foobar2343=== PAUSE TestGlobMatch/foo*bar_foobar2344=== RUN TestGlobMatch/foo*bar_foo123bar2345=== PAUSE TestGlobMatch/foo*bar_foo123bar2346--- PASS: TestPins_ConfigValidation (0.00s)2347=== RUN TestGlobMatch/foo*bar_foobarbaz2348=== PAUSE TestGlobMatch/foo*bar_foobarbaz2349=== RUN TestGlobMatch/*/*_foo/bar2350=== PAUSE TestGlobMatch/*/*_foo/bar2351=== RUN TestGlobMatch/*/*_foo2352=== PAUSE TestGlobMatch/*/*_foo2353=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2354=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2355=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02356=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02357=== RUN TestGlobMatch/refs/*/main_refs/heads/main2358=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2359=== RUN TestGlobMatch/fo?_foo2360=== PAUSE TestGlobMatch/fo?_foo2361=== RUN TestGlobMatch/fo?_fo2362=== PAUSE TestGlobMatch/fo?_fo2363=== RUN TestGlobMatch/fo?_fooo2364=== PAUSE TestGlobMatch/fo?_fooo2365=== RUN TestGlobMatch/?oo_foo2366=== PAUSE TestGlobMatch/?oo_foo2367=== RUN TestGlobMatch/?oo_boo2368=== PAUSE TestGlobMatch/?oo_boo2369=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2370=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2371=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2372=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2373=== CONT TestGlobMatch/foo_foo2374=== CONT TestGlobMatch/*/*_foo/bar2375=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2376=== CONT TestGlobMatch/*/*_foo2377=== CONT TestGlobMatch/foo*_foo2378=== CONT TestGlobMatch/foo*bar_foo123bar2379=== CONT TestGlobMatch/*bar_bar2380=== CONT TestGlobMatch/foo*_bar2381=== CONT TestGlobMatch/fo?_foo2382=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2383=== CONT TestGlobMatch/foo_bar2384=== CONT TestGlobMatch/?oo_boo2385=== CONT TestGlobMatch/?oo_foo2386=== CONT TestGlobMatch/*bar_foobar2387=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02388=== CONT TestGlobMatch/foo*bar_foobar2389=== CONT TestGlobMatch/*_anything2390=== CONT TestGlobMatch/*bar_foo2391=== CONT TestGlobMatch/foo*bar_foobarbaz2392=== CONT TestGlobMatch/refs/*/main_refs/heads/main2393=== CONT TestGlobMatch/fo?_fooo2394=== CONT TestGlobMatch/foo*_foobar2395=== CONT TestGlobMatch/*_2396=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2397=== CONT TestGlobMatch/fo?_fo2398--- PASS: TestGlobMatch (0.01s)2399 --- PASS: TestGlobMatch/foo_foo (0.00s)2400 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2401 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2402 --- PASS: TestGlobMatch/*/*_foo (0.00s)2403 --- PASS: TestGlobMatch/foo*_foo (0.00s)2404 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2405 --- PASS: TestGlobMatch/foo*_bar (0.00s)2406 --- PASS: TestGlobMatch/*bar_bar (0.00s)2407 --- PASS: TestGlobMatch/fo?_foo (0.00s)2408 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2409 --- PASS: TestGlobMatch/foo_bar (0.00s)2410 --- PASS: TestGlobMatch/?oo_boo (0.00s)2411 --- PASS: TestGlobMatch/?oo_foo (0.00s)2412 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2413 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2414 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2415 --- PASS: TestGlobMatch/*_anything (0.00s)2416 --- PASS: TestGlobMatch/*bar_foo (0.00s)2417 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2418 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2419 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2420 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2421 --- PASS: TestGlobMatch/*_ (0.00s)2422 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2423 --- PASS: TestGlobMatch/fo?_fo (0.00s)24242026/10/01 10:34:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44193/oidc2425--- PASS: TestValidateToken_BoundClaimsMismatch (0.12s)24262026/10/01 10:34:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39863/oidc2427--- PASS: TestValidateToken_Expired (0.19s)24282026/10/01 10:34:29 http: TLS handshake error from 127.0.0.1:35534: remote error: tls: bad certificate2429--- PASS: TestNewValidator_KubernetesRequiresCA (0.20s)2430--- PASS: TestHTTPClientForHasTimeouts (0.20s)24312026/10/01 10:34:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39653/oidc2432--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.22s)24332026/10/01 10:34:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42645/oidc24342026/10/01 10:34:29 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:343172435--- PASS: TestScopes_Rules (0.25s)2436--- PASS: TestValidateToken_KubernetesServiceAccount (0.25s)24372026/10/01 10:34:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44781/oidc24382026/10/01 10:34:29 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232439--- PASS: TestPins_TopLevelShorthand (0.27s)2440--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.29s)24412026/10/01 10:34:29 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:38411/oidc2442--- PASS: TestValidateToken_NoMatchingProvider (0.36s)24432026/10/01 10:34:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36137/oidc2444--- PASS: TestValidateToken_BoundSubjectMismatch (0.39s)24452026/10/01 10:34:29 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45085/oidc24462026/10/01 10:34:29 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:33015/oidc2447--- PASS: TestValidateToken_MultipleProviders (0.43s)24482026/10/01 10:34:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45681/oidc2449--- PASS: TestValidateToken_ValidToken (0.53s)24502026/10/01 10:34:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45987/oidc2451--- PASS: TestPins_ReservedForMatchingRule (0.55s)24522026/10/01 10:34:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36375/oidc2453--- PASS: TestValidateToken_WrongAudience (0.88s)2454PASS2455Running signing tests...2456=== RUN TestGenerateFingerprint2457=== PAUSE TestGenerateFingerprint2458=== RUN TestParseSigningKey2459=== PAUSE TestParseSigningKey2460=== RUN TestSignMessage2461=== PAUSE TestSignMessage2462=== RUN TestSignNarinfo2463=== PAUSE TestSignNarinfo2464=== CONT TestGenerateFingerprint2465=== CONT TestSignMessage2466=== CONT TestSignNarinfo2467=== RUN TestGenerateFingerprint/basic_with_references2468=== CONT TestParseSigningKey2469=== PAUSE TestGenerateFingerprint/basic_with_references2470=== RUN TestParseSigningKey/valid_32-byte_key2471=== RUN TestGenerateFingerprint/no_references2472=== PAUSE TestParseSigningKey/valid_32-byte_key2473=== PAUSE TestGenerateFingerprint/no_references2474=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2475=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2476=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2477=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2478=== RUN TestParseSigningKey/no_colon2479=== PAUSE TestParseSigningKey/no_colon2480=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2481=== RUN TestParseSigningKey/empty_name2482=== PAUSE TestParseSigningKey/empty_name2483=== RUN TestParseSigningKey/invalid_base642484=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2485=== RUN TestGenerateFingerprint/invalid_nar_hash_length2486=== PAUSE TestParseSigningKey/invalid_base642487=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2488=== RUN TestParseSigningKey/wrong_length2489=== PAUSE TestParseSigningKey/wrong_length2490=== RUN TestGenerateFingerprint/invalid_store_path_prefix2491=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2492=== CONT TestParseSigningKey/no_colon2493=== CONT TestParseSigningKey/wrong_length2494=== CONT TestParseSigningKey/empty_name2495=== CONT TestParseSigningKey/invalid_base642496=== CONT TestParseSigningKey/valid_32-byte_key2497=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2498=== RUN TestGenerateFingerprint/invalid_reference_prefix2499=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2500=== CONT TestGenerateFingerprint/no_references2501=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2502=== CONT TestGenerateFingerprint/invalid_store_path_prefix2503=== CONT TestGenerateFingerprint/invalid_reference_prefix2504=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2505=== CONT TestGenerateFingerprint/basic_with_references2506=== CONT TestGenerateFingerprint/invalid_nar_hash_length2507--- PASS: TestGenerateFingerprint (0.00s)2508 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2509 --- PASS: TestGenerateFingerprint/no_references (0.00s)2510 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2511 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2512 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2513 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2514 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2515--- PASS: TestParseSigningKey (0.00s)2516 --- PASS: TestParseSigningKey/wrong_length (0.00s)2517 --- PASS: TestParseSigningKey/no_colon (0.00s)2518 --- PASS: TestParseSigningKey/empty_name (0.00s)2519 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2520 --- PASS: TestParseSigningKey/valid_32-byte_key (0.01s)2521 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.01s)2522--- PASS: TestSignMessage (0.02s)2523--- PASS: TestSignNarinfo (0.02s)2524PASS2525Running hook tests...2526=== RUN TestSendPathsEmpty2527=== PAUSE TestSendPathsEmpty2528=== RUN TestQueueEnqueueAndFetch2529=== PAUSE TestQueueEnqueueAndFetch2530=== RUN TestQueueDeduplication2531=== PAUSE TestQueueDeduplication2532=== RUN TestQueueRemove2533=== PAUSE TestQueueRemove2534=== RUN TestQueueFetchBatchLimit2535=== PAUSE TestQueueFetchBatchLimit2536=== RUN TestQueueRetryMovesToBack2537=== PAUSE TestQueueRetryMovesToBack2538=== RUN TestQueueFetchRemoveLifecycle2539=== PAUSE TestQueueFetchRemoveLifecycle2540=== RUN TestQueueConcurrentWriters2541=== PAUSE TestQueueConcurrentWriters2542=== RUN TestQueueEnqueueWaitsOutSlowWriter2543=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2544=== RUN TestQueueRemoveLargeClosure2545=== PAUSE TestQueueRemoveLargeClosure2546=== RUN TestServerClientIntegration2547=== PAUSE TestServerClientIntegration2548=== RUN TestServerQueueError2549=== PAUSE TestServerQueueError2550=== RUN TestServerRefusesOversizedAndNonStoreRequests2551=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2552=== RUN TestGetListenerSocketActivation2553 server_test.go:317: === RUN TestGetListenerSocketActivation2554 --- PASS: TestGetListenerSocketActivation (0.00s)2555 PASS2556 2557--- PASS: TestGetListenerSocketActivation (1.02s)2558=== RUN TestServerStalledClientDoesNotBlockShutdown2559=== PAUSE TestServerStalledClientDoesNotBlockShutdown2560=== RUN TestServerBacksOffOnAcceptErrors2561=== PAUSE TestServerBacksOffOnAcceptErrors2562=== RUN TestDrainIsolatesPoisonPath2563=== PAUSE TestDrainIsolatesPoisonPath2564=== RUN TestRunNotBlockedByPoisonHead2565=== PAUSE TestRunNotBlockedByPoisonHead2566=== RUN TestDrainGivesUpWhenServerDown2567=== PAUSE TestDrainGivesUpWhenServerDown2568=== RUN TestFailedPathPrunedByLaterClosure2569=== PAUSE TestFailedPathPrunedByLaterClosure2570=== RUN TestWorkerUploadsAndRemoves2571=== PAUSE TestWorkerUploadsAndRemoves2572=== RUN TestWorkerSkipsGCdPaths2573=== PAUSE TestWorkerSkipsGCdPaths2574=== RUN TestWorkerPrunesClosureDeps2575=== PAUSE TestWorkerPrunesClosureDeps2576=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2577=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2578=== RUN TestDrainTimeout2579=== PAUSE TestDrainTimeout2580=== RUN TestDrainTimeoutDuringIsolation2581=== PAUSE TestDrainTimeoutDuringIsolation2582=== RUN TestShutdownFinishesInFlightPush2583=== PAUSE TestShutdownFinishesInFlightPush2584=== RUN TestWorkerRemoveFailureIsNotProgress2585=== PAUSE TestWorkerRemoveFailureIsNotProgress2586=== RUN TestWorkerKeepsPathItCannotStat2587=== PAUSE TestWorkerKeepsPathItCannotStat2588=== CONT TestServerStalledClientDoesNotBlockShutdown2589=== CONT TestWorkerUploadsAndRemoves2590=== CONT TestQueueFetchRemoveLifecycle2591=== CONT TestDrainTimeout2592=== CONT TestQueueRetryMovesToBack2593=== CONT TestQueueFetchBatchLimit2594=== CONT TestQueueRemoveLargeClosure2595=== CONT TestQueueRemove2596=== CONT TestQueueDeduplication2597=== CONT TestSendPathsEmpty2598=== CONT TestDrainTimeoutDuringIsolation2599=== CONT TestQueueEnqueueWaitsOutSlowWriter2600=== CONT TestWorkerKeepsPathItCannotStat2601=== CONT TestWorkerRemoveFailureIsNotProgress2602=== CONT TestServerRefusesOversizedAndNonStoreRequests2603=== CONT TestDrainGivesUpWhenServerDown2604=== CONT TestServerQueueError2605=== CONT TestFailedPathPrunedByLaterClosure2606=== CONT TestWorkerSkipsGCdPaths2607=== CONT TestShutdownFinishesInFlightPush2608=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2609=== CONT TestWorkerPrunesClosureDeps2610=== CONT TestDrainIsolatesPoisonPath2611=== CONT TestRunNotBlockedByPoisonHead2612=== CONT TestQueueEnqueueAndFetch2613=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2614--- PASS: TestSendPathsEmpty (0.00s)2615=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2616=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2617=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2618=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2619=== RUN TestShutdownFinishesInFlightPush/completes2620=== PAUSE TestShutdownFinishesInFlightPush/completes2621=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2622=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2623=== CONT TestServerClientIntegration2624=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2625=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2626=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2627=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2628=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths26292026/10/01 10:34:33 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2630=== CONT TestQueueConcurrentWriters2631=== CONT TestServerBacksOffOnAcceptErrors26322026/10/01 10:34:33 ERROR Failed to queue paths error="permission denied" count=126332026/10/01 10:34:33 ERROR Accept failed error="too many open files"26342026/10/01 10:34:33 ERROR Refusing path outside the store path=/nix/store store=/nix/store2635--- PASS: TestServerQueueError (0.00s)2636=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout26372026/10/01 10:34:33 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store26382026/10/01 10:34:33 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store2639--- PASS: TestServerClientIntegration (0.00s)2640=== CONT TestShutdownFinishesInFlightPush/completes26412026/10/01 10:34:33 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store26422026/10/01 10:34:33 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26432026/10/01 10:34:33 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26442026/10/01 10:34:33 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store26452026/10/01 10:34:33 ERROR Accept failed error="too many open files"26462026/10/01 10:34:33 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store26472026/10/01 10:34:33 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store26482026/10/01 10:34:33 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store26492026/10/01 10:34:33 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store26502026/10/01 10:34:33 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store26512026/10/01 10:34:33 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store26522026/10/01 10:34:33 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store26532026/10/01 10:34:33 ERROR Failed to decode request error="unexpected EOF"2654--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2655=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short26562026/10/01 10:34:33 ERROR Accept failed error="too many open files"26572026/10/01 10:34:33 ERROR Accept failed error="too many open files"26582026/10/01 10:34:33 INFO Uploading batch count=126592026/10/01 10:34:33 ERROR Upload failed error="upload failed" count=126602026/10/01 10:34:33 INFO Upload queue status pending=326612026/10/01 10:34:33 INFO Upload queue status pending=226622026/10/01 10:34:33 INFO Upload queue status pending=226632026/10/01 10:34:33 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2860040801/002/nonexistent26642026/10/01 10:34:33 INFO Uploading batch count=426652026/10/01 10:34:33 ERROR Upload failed error="upload failed" count=426662026/10/01 10:34:33 INFO Uploading batch count=226672026/10/01 10:34:33 INFO Uploading batch count=126682026/10/01 10:34:33 INFO Uploading batch count=226692026/10/01 10:34:33 INFO Uploading batch count=126702026/10/01 10:34:33 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3575513474/002/bbb26712026/10/01 10:34:33 INFO Uploading batch count=426722026/10/01 10:34:33 ERROR Upload failed error="upload failed" count=426732026/10/01 10:34:33 INFO Upload queue status pending=226742026/10/01 10:34:33 INFO Uploading batch count=226752026/10/01 10:34:33 INFO Upload queue status pending=326762026/10/01 10:34:33 INFO Upload queue status pending=226772026/10/01 10:34:33 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1562719383/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat1562719383/002/locked/aaa: permission denied"26782026/10/01 10:34:33 INFO Uploading batch count=126792026/10/01 10:34:33 INFO Uploading batch count=226802026/10/01 10:34:33 INFO Uploading batch count=126812026/10/01 10:34:33 ERROR Upload failed error="upload failed" count=126822026/10/01 10:34:33 INFO Uploading batch count=22683--- PASS: TestQueueRetryMovesToBack (0.08s)2684=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline26852026/10/01 10:34:33 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1562719383/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat1562719383/002/locked/aaa: permission denied"26862026/10/01 10:34:33 ERROR Accept failed error="too many open files"26872026/10/01 10:34:33 INFO Uploading batch count=126882026/10/01 10:34:33 ERROR Upload failed error="upload failed" count=126892026/10/01 10:34:33 INFO Upload queue status pending=22690--- PASS: TestQueueFetchBatchLimit (0.08s)2691=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch2692=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths2693--- PASS: TestQueueDeduplication (0.08s)26942026/10/01 10:34:33 INFO Uploading batch count=226952026/10/01 10:34:33 ERROR Upload failed error="upload failed" count=226962026/10/01 10:34:33 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3122844253/002/a26972026/10/01 10:34:33 INFO Uploading batch count=22698--- PASS: TestQueueFetchRemoveLifecycle (0.08s)2699=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27002026/10/01 10:34:33 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1562719383/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat1562719383/002/locked/aaa: permission denied"27012026/10/01 10:34:33 INFO Uploading batch count=127022026/10/01 10:34:33 ERROR Upload failed error="upload failed" count=127032026/10/01 10:34:33 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3122844253/002/b2704--- PASS: TestFailedPathPrunedByLaterClosure (0.09s)27052026/10/01 10:34:33 ERROR Drain finished with paths left in queue remaining=127062026/10/01 10:34:33 INFO Uploading batch count=127072026/10/01 10:34:33 ERROR Upload failed error="upload failed" count=127082026/10/01 10:34:33 INFO Uploading batch count=227092026/10/01 10:34:33 ERROR Upload failed error="upload failed" count=227102026/10/01 10:34:33 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3122844253/002/c2711--- PASS: TestQueueRemove (0.09s)27122026/10/01 10:34:33 ERROR Drain finished with paths left in queue remaining=127132026/10/01 10:34:33 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3122844253/002/d2714--- PASS: TestQueueEnqueueAndFetch (0.09s)2715--- PASS: TestWorkerSkipsGCdPaths (0.09s)2716--- PASS: TestWorkerKeepsPathItCannotStat (0.10s)2717--- PASS: TestWorkerPrunesClosureDeps (0.10s)27182026/10/01 10:34:33 INFO Uploading batch count=227192026/10/01 10:34:33 ERROR Upload failed error="upload failed" count=227202026/10/01 10:34:33 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3122844253/002/e2721--- PASS: TestWorkerUploadsAndRemoves (0.10s)2722--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.10s)27232026/10/01 10:34:33 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3122844253/002/f2724--- PASS: TestDrainIsolatesPoisonPath (0.10s)27252026/10/01 10:34:33 ERROR Drain finished with paths left in queue remaining=102726--- PASS: TestDrainGivesUpWhenServerDown (0.11s)27272026/10/01 10:34:33 INFO Uploading batch count=427282026/10/01 10:34:33 ERROR Upload failed error="upload failed" count=427292026/10/01 10:34:33 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path952129667/001/nonexistent27302026/10/01 10:34:33 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127312026/10/01 10:34:33 INFO Uploading batch count=227322026/10/01 10:34:33 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path952129667/001/nonexistent27332026/10/01 10:34:33 ERROR Upload failed error="upload failed" count=227342026/10/01 10:34:33 INFO Uploading batch count=227352026/10/01 10:34:33 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127362026/10/01 10:34:33 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127372026/10/01 10:34:33 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227382026/10/01 10:34:33 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127392026/10/01 10:34:33 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path952129667/001/nonexistent27402026/10/01 10:34:33 INFO Uploading batch count=227412026/10/01 10:34:33 INFO Uploading batch count=227422026/10/01 10:34:33 ERROR Upload failed error="upload failed" count=227432026/10/01 10:34:33 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127442026/10/01 10:34:33 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227452026/10/01 10:34:33 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127462026/10/01 10:34:33 ERROR Drain finished with paths left in queue remaining=127472026/10/01 10:34:33 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127482026/10/01 10:34:33 INFO Uploading batch count=227492026/10/01 10:34:33 INFO Uploading batch count=227502026/10/01 10:34:33 ERROR Upload failed error="upload failed" count=227512026/10/01 10:34:33 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227522026/10/01 10:34:33 ERROR Drain finished with paths left in queue remaining=227532026/10/01 10:34:33 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127542026/10/01 10:34:33 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127552026/10/01 10:34:33 ERROR Drain finished with paths left in queue remaining=22756--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2757 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.04s)2758 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.05s)2759 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.05s)27602026/10/01 10:34:33 ERROR Accept failed error="too many open files"27612026/10/01 10:34:33 ERROR Failed to decode request error="read unix /build/hook2741670660/test.sock->@: i/o timeout"27622026/10/01 10:34:33 ERROR Failed to write response error="write unix /build/hook2741670660/test.sock->@: i/o timeout"2763--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)27642026/10/01 10:34:33 ERROR Drain finished with paths left in queue remaining=427652026/10/01 10:34:33 ERROR Upload failed error="context canceled" count=227662026/10/01 10:34:33 ERROR Drain finished with paths left in queue remaining=42767--- PASS: TestDrainTimeout (0.27s)27682026/10/01 10:34:33 ERROR Upload failed error="context canceled" count=227692026/10/01 10:34:33 ERROR Drain finished with paths left in queue remaining=22770--- PASS: TestShutdownFinishesInFlightPush (0.00s)2771 --- PASS: TestShutdownFinishesInFlightPush/completes (0.17s)2772 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.28s)27732026/10/01 10:34:33 ERROR Accept failed error="too many open files"27742026/10/01 10:34:33 ERROR Drain finished with paths left in queue remaining=32775--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2776 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.26s)2777 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.34s)2778--- PASS: TestQueueConcurrentWriters (0.51s)27792026/10/01 10:34:33 ERROR Accept failed error="too many open files"2780--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)27812026/10/01 10:34:34 INFO Uploading batch count=127822026/10/01 10:34:34 INFO Uploading batch count=127832026/10/01 10:34:34 INFO Uploading batch count=127842026/10/01 10:34:34 ERROR Upload failed error="upload failed" count=127852026/10/01 10:34:34 INFO Uploading batch count=127862026/10/01 10:34:34 ERROR Upload failed error="upload failed" count=127872026/10/01 10:34:34 INFO Uploading batch count=127882026/10/01 10:34:34 ERROR Upload failed error="upload failed" count=127892026/10/01 10:34:34 INFO Uploading batch count=127902026/10/01 10:34:34 ERROR Upload failed error="upload failed" count=127912026/10/01 10:34:34 ERROR Drain finished with paths left in queue remaining=12792--- PASS: TestRunNotBlockedByPoisonHead (1.10s)2793--- PASS: TestQueueRemoveLargeClosure (4.08s)2794--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.07s)2795PASS2796Running niks3-hook command tests...2797=== RUN TestServeSecondSignalEndsDrain2798=== PAUSE TestServeSecondSignalEndsDrain2799=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown2800=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown2801=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown2802=== CONT TestServeSecondSignalEndsDrain2803--- PASS: TestServeSecondSignalEndsDrain (0.07s)28042026/10/01 10:34:40 INFO Upload queue status pending=128052026/10/01 10:34:40 INFO Uploading batch count=12806--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.13s)2807PASS2808Running rate limiter tests...2809=== RUN TestAdaptiveRateLimiter_ThreadSafety2810=== PAUSE TestAdaptiveRateLimiter_ThreadSafety2811=== CONT TestAdaptiveRateLimiter_ThreadSafety28122026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=7028132026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=4928142026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=34.328152026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=24.00999999999999828162026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=16.80728172026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=11.76489999999999928182026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=8.2354328192026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=5.76480099999999928202026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528212026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528222026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528232026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528242026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528252026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528262026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528272026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528282026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528292026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528302026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528312026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528322026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528332026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528342026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528352026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528362026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528372026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528382026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528392026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528402026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528412026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528422026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528432026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528442026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528452026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528462026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528472026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528482026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528492026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528502026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528512026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528522026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528532026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528542026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528552026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528562026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528572026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528582026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528592026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528602026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528612026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=5.12435000000000128622026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528632026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528642026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528652026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528662026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528672026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528682026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528692026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528702026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528712026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528722026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528732026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528742026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528752026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=16.08240545225027428762026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=11.25768381657519228772026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=7.88037867160263328782026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=5.51626507012184328792026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528802026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528812026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528822026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528832026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528842026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528852026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528862026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528872026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528882026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528892026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528902026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528912026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528922026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528932026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528942026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528952026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528962026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528972026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528982026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=528992026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=529002026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=529012026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=529022026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=529032026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=529042026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=529052026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=529062026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=529072026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=529082026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=529092026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=7.50256083500000329102026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=5.25179258450000229112026/10/01 10:34:41 WARN Rate limiter backed off name=test rate=52912--- PASS: TestAdaptiveRateLimiter_ThreadSafety (0.09s)2913PASS