niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #327
· 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 114 of 32768000 bytes45--- PASS: TestDumpPathWriterErrorStopsReading (0.63s)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 TestUploadBuildLog_FileBodyReplayedOnRetry129=== CONT TestScriptTokenScriptFails130=== CONT TestGetStorePathHash131=== CONT TestDumpPathSingleFile132=== CONT TestFileTokenReadsAndCaches133=== CONT TestFileTokenEmpty134=== CONT TestConvertHashToNix32135=== CONT TestScriptTokenDoesNotWaitForItsChildren136=== CONT TestScriptTokenEmptyCommand137=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs138=== CONT TestScriptTokenEmptyToken139=== CONT TestScriptTokenCachesUntilRefresh140=== CONT TestScriptTokenBadJSON141=== CONT TestPathInfoHashCompatibility142=== CONT TestScriptTokenNoExpiryRerunsEveryCall143=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)144=== CONT TestDoWithRetry_BodyReplayedViaGetBody145=== CONT TestResolveStorePath146=== CONT TestStreamPushRequestLine147=== CONT TestStreamPushIsolatesFailures148=== CONT TestStreamPushReportsSignatures149=== CONT TestDumpPathMatchesNix150=== CONT TestParsePathInfoJSON151=== CONT TestStaticToken152=== CONT TestUploadMultipart_SupersededByPeer153=== RUN TestGetStorePathHash/valid_store_path154=== CONT TestSetClientTLSDoesNotMutateDefaultTransport155=== CONT TestCaseHackSuffix156=== RUN TestConvertHashToNix32/SRI_format_to_Nix32157=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun158--- PASS: TestScriptTokenEmptyCommand (0.00s)159=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs160=== CONT TestSetClientTLS161=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)162=== RUN TestParsePathInfoJSON/Nix_format163=== RUN TestUploadMultipart_SupersededByPeer/exists164=== CONT TestShellSplit165=== PAUSE TestGetStorePathHash/valid_store_path166=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32167=== PAUSE TestUploadMultipart_SupersededByPeer/exists168=== RUN TestConvertHashToNix32/already_Nix32_format169=== RUN TestUploadMultipart_SupersededByPeer/missing170=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer171=== PAUSE TestParsePathInfoJSON/Nix_format172--- PASS: TestFileTokenReadsAndCaches (0.00s)173=== PAUSE TestUploadMultipart_SupersededByPeer/missing174=== RUN TestGetStorePathHash/basename_without_hyphen_should_error175=== CONT TestDoWithRetry_FinalResponseBodyReadable176--- PASS: TestFileTokenEmpty (0.00s)177=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout178=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon179=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout180=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon181=== CONT TestClientSignaturesByStorePath182=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess183=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent184=== RUN TestParsePathInfoJSON/Lix_format185=== PAUSE TestConvertHashToNix32/already_Nix32_format186=== CONT TestFilterOversizedClosures187=== CONT TestCompletePendingClosure_NotFoundWithoutKey188=== CONT TestEncodeNixBase32WithRealHash189=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error190--- PASS: TestStaticToken (0.00s)191=== CONT TestStreamPushStopsOnCancel192=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI193=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier194=== PAUSE TestParsePathInfoJSON/Lix_format195=== CONT TestPathInfoCACompatibility196=== CONT TestRateLimiterFeedback197=== RUN TestConvertHashToNix32/invalid_format198=== RUN TestFilterOversizedClosures/no_limit_keeps_everything199=== CONT TestParsePathInfoJSONMultiplePaths200=== RUN TestParsePathInfoJSON/empty_input201=== CONT TestFileTokenMissing202--- PASS: TestScriptTokenScriptFails (0.00s)203=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error204=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI205=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error206=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier207=== RUN TestStreamPushStopsOnCancel/waiting_for_input208=== RUN TestPathInfoCACompatibility/null_ca_field209=== RUN TestRateLimiterFeedback/429_enables_limiter210=== PAUSE TestConvertHashToNix32/invalid_format211=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths212=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything213=== PAUSE TestParsePathInfoJSON/empty_input214=== CONT TestUploadMultipart_ProducerErrorIsNotEOF215--- PASS: TestScriptTokenEmptyToken (0.00s)216=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped217=== RUN TestParsePathInfoJSON/whitespace_only218=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped219=== PAUSE TestParsePathInfoJSON/whitespace_only220--- PASS: TestScriptTokenBadJSON (0.00s)221=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part222=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error223=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up224=== CONT TestUploadMultipart_FailedPartBufferNotReused225=== PAUSE TestPathInfoCACompatibility/null_ca_field226=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input227=== PAUSE TestRateLimiterFeedback/429_enables_limiter228=== CONT TestPartSizeForNAR229=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths230=== CONT TestStreamPushGivesUpOnDeadServer231=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512232=== CONT TestUploadMultipart_PartsInParallel233=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths234=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512235--- PASS: TestFileTokenMissing (0.00s)236--- PASS: TestResolveStorePath (0.01s)237--- PASS: TestClientSignaturesByStorePath (0.00s)238=== CONT TestTruncatedNARDumpIsNotCompleted239=== RUN TestFilterOversizedClosures/all_closures_skipped240=== RUN TestParsePathInfoJSON/invalid_JSON241=== PAUSE TestFilterOversizedClosures/all_closures_skipped242=== CONT TestStreamPushBatchesUnderLoad243=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part244=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error245=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up246=== RUN TestPathInfoCACompatibility/old_string_format_-_text247=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot248=== RUN TestRateLimiterFeedback/503_enables_limiter249=== RUN TestPartSizeForNAR/zero_stays_at_minimum250=== CONT TestSupersededNARStillUploadsListing251=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure252--- PASS: TestStreamPushReportsSignatures (0.01s)253=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths254=== CONT TestEncodeNixBase32255=== RUN TestSupersededNARStillUploadsListing/small_NAR256=== CONT TestDoServerRequestAttachesToken257=== RUN TestEncodeNixBase32/test_string_hash258=== RUN TestStreamPushBatchesUnderLoad/together259=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary260=== CONT TestStreamPushReportsEveryPath261=== CONT TestRegisterUploadedObjectReusesConnections262=== PAUSE TestStreamPushBatchesUnderLoad/together263=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text264=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot265=== PAUSE TestRateLimiterFeedback/503_enables_limiter266=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum267--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)268=== RUN TestSetClientTLS/rejects_connection_without_client_cert269=== PAUSE TestParsePathInfoJSON/invalid_JSON270=== PAUSE TestSupersededNARStillUploadsListing/small_NAR271=== PAUSE TestEncodeNixBase32/test_string_hash272=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary273=== CONT TestShellSplitErrors274=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time275=== CONT TestDumpPathWriterError276=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive277=== CONT TestUploadMultipart_SupersededByPeer/exists278=== CONT TestUploadMultipart_SupersededByPeer/missing279=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot280--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)281=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot282--- PASS: TestDumpPathSingleFile (0.27s)283=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot284--- PASS: TestEncodeNixBase32WithRealHash (0.01s)285=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout286=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter287=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert288=== RUN TestPartSizeForNAR/small_stays_at_minimum289=== CONT TestSetClientTLSErrors290=== RUN TestEncodeNixBase32/empty_input291=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica292=== RUN TestSupersededNARStillUploadsListing/dump_cut_short293=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time294=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive295--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)296=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot297=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA298=== PAUSE TestPartSizeForNAR/small_stays_at_minimum299=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs300=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter301=== RUN TestSetClientTLSErrors/missing_cert_file302=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short303=== PAUSE TestEncodeNixBase32/empty_input304=== CONT TestConvertHashToNix32/SRI_format_to_Nix32305--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.02s)306=== RUN TestPathInfoCACompatibility/new_structured_format_-_text307=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot308=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum309=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA310=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter311=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails312=== PAUSE TestSetClientTLSErrors/missing_cert_file313=== CONT TestConvertHashToNix32/invalid_format314=== CONT TestConvertHashToNix32/already_Nix32_format315--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.02s)316=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)317=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text318=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum319=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot320=== RUN TestSetClientTLS/preserves_debug_logging_transport321=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method322=== PAUSE TestSetClientTLS/preserves_debug_logging_transport323=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken324=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method325=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512326=== CONT TestFilterOversizedClosures/all_closures_skipped327=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts328=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped329=== CONT TestFilterOversizedClosures/no_limit_keeps_everything330=== CONT TestGetStorePathHash/valid_store_path331=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error332=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up333=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error334=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier335=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts336--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.02s)337--- PASS: TestShellSplit (0.00s)338--- PASS: TestStreamPushIsolatesFailures (0.00s)339=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter340--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)341=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken342=== RUN TestSetClientTLSErrors/missing_key_file343=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI344=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon345=== CONT TestGetStorePathHash/basename_without_hyphen_should_error346=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths347=== CONT TestParsePathInfoJSON/Lix_format348=== CONT TestParsePathInfoJSON/empty_input349=== RUN TestPartSizeForNAR/1_TiB350=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary351=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part352=== PAUSE TestSetClientTLSErrors/missing_key_file353=== CONT TestParsePathInfoJSON/whitespace_only354=== CONT TestStreamPushBatchesUnderLoad/together355=== RUN TestSetClientTLSErrors/missing_ca_file356=== CONT TestParsePathInfoJSON/invalid_JSON357=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails358=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths359--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.01s)360=== CONT TestParsePathInfoJSON/Nix_format361=== PAUSE TestPartSizeForNAR/1_TiB362=== RUN TestPartSizeForNAR/5_TiB_S3_max_object363=== CONT TestEncodeNixBase32/empty_input364=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object365=== CONT TestEncodeNixBase32/test_string_hash366=== RUN TestPartSizeForNAR/capped_at_5_GiB367=== CONT TestSetClientTLS/preserves_debug_logging_transport368=== PAUSE TestPartSizeForNAR/capped_at_5_GiB369=== CONT TestSetClientTLS/rejects_connection_without_client_cert370=== CONT TestPathInfoCACompatibility/old_string_format_-_text371=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time372=== PAUSE TestSetClientTLSErrors/missing_ca_file373=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA374=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method375=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive376=== CONT TestPathInfoCACompatibility/new_structured_format_-_text377=== CONT TestRateLimiterFeedback/429_enables_limiter378=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter379=== CONT TestRateLimiterFeedback/503_enables_limiter380=== CONT TestStreamPushStopsOnCancel/waiting_for_input381=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter382=== RUN TestSetClientTLSErrors/invalid_ca_file383--- PASS: TestStreamPushReportsEveryPath (0.00s)384--- PASS: TestCaseHackSuffix (0.27s)385=== CONT TestPathInfoCACompatibility/null_ca_field386=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken387=== PAUSE TestSetClientTLSErrors/invalid_ca_file388--- PASS: TestShellSplitErrors (0.00s)389--- PASS: TestStreamPushGivesUpOnDeadServer (0.25s)390--- PASS: TestDoServerRequestAttachesToken (0.25s)391=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot392=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot393--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)394 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)395 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)396=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot397--- PASS: TestConvertHashToNix32 (0.02s)398 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)399 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)400 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)401--- PASS: TestFilterOversizedClosures (0.01s)402 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)403 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)404 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)405=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot406--- PASS: TestPathInfoHashCompatibility (0.02s)407 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)408 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)409 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)410 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)411--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)412=== CONT TestSupersededNARStillUploadsListing/small_NAR413--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.02s)414 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.01s)415 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.01s)416--- PASS: TestRateLimiterFeedback (0.26s)417 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)418 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)419 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)420 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)421--- PASS: TestGetStorePathHash (0.03s)422 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)423 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)424 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)425 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)426--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)427 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)428 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)429--- PASS: TestEncodeNixBase32 (0.25s)430 --- PASS: TestEncodeNixBase32/empty_input (0.00s)431 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)432--- PASS: TestStreamPushBatchesUnderLoad (0.25s)433 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)434 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)435--- PASS: TestPathInfoCACompatibility (0.26s)436 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)437 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)438 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)439 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)440 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)441--- PASS: TestParsePathInfoJSON (0.27s)442 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)443 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)444 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)445 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)446 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)447=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails448=== CONT TestSupersededNARStillUploadsListing/dump_cut_short449=== CONT TestPartSizeForNAR/zero_stays_at_minimum450=== CONT TestPartSizeForNAR/5_TiB_S3_max_object451=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum452=== CONT TestSetClientTLSErrors/missing_key_file453=== CONT TestSetClientTLSErrors/invalid_ca_file454=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts455--- PASS: TestStreamPushStopsOnCancel (0.27s)456 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.14s)457 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.14s)458 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.14s)459 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.15s)460 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.14s)461 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.15s)462=== CONT TestSetClientTLSErrors/missing_cert_file463=== CONT TestPartSizeForNAR/small_stays_at_minimum464=== CONT TestSetClientTLSErrors/missing_ca_file465=== CONT TestPartSizeForNAR/capped_at_5_GiB466=== CONT TestPartSizeForNAR/1_TiB467--- PASS: TestPartSizeForNAR (0.26s)468 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)469 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)470 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)471 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)472 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)473 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)474 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)475--- PASS: TestSetClientTLSErrors (0.02s)476 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)477 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)478 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)479 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)480--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.44s)481--- PASS: TestDumpPathWriterError (0.22s)482--- PASS: TestSetClientTLS (0.28s)483 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)484 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)485 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.22s)486--- PASS: TestDumpPathMatchesNix (0.88s)487--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.25s)488 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.58s)489 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.62s)490--- PASS: TestRegisterUploadedObjectReusesConnections (0.65s)491--- PASS: TestStreamPushRequestLine (0.93s)492--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)493--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.42s)494--- PASS: TestUploadMultipart_PartsInParallel (1.45s)495--- PASS: TestSupersededNARStillUploadsListing (0.26s)496 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.13s)497 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.16s)498 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.18s)499--- PASS: TestTruncatedNARDumpIsNotCompleted (1.55s)500--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (2.00s)501--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.01s)502 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.01s)503 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.20s)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/postgres2968688385/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/postgres2968688385/data -l logfile start532533/build/postgres2968688385:5432 - no response5342026-10-01 09:57:53.830 UTC [171] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5352026-10-01 09:57:53.831 UTC [171] LOG: listening on Unix socket "/build/postgres2968688385/.s.PGSQL.5432"5362026-10-01 09:57:53.835 UTC [178] LOG: database system was shut down at 2026-10-01 09:57:53 UTC5372026-10-01 09:57:53.838 UTC [171] LOG: database system is ready to accept connections538/build/postgres2968688385: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 09:57:54 INFO lead: acquired remote=192.0.2.1:12345872026/10/01 09:57:55 INFO lead: released remote=192.0.2.1:12345882026/10/01 09:57:55 INFO lead: acquired remote=192.0.2.1:12345892026/10/01 09:57:56 INFO lead: released remote=192.0.2.1:1234590--- PASS: TestLeadIncumbentWinsAfterRestart (2.31s)591=== RUN TestLeadEndsOnShutdown592=== PAUSE TestLeadEndsOnShutdown593=== RUN TestLeadEndsWhenItsConnectionHangs5942026/10/01 09:57:56 INFO lead: acquired remote=192.0.2.1:12345952026-10-01 09:57:57.771 UTC [435] FATAL: terminating connection due to administrator command5962026/10/01 09:57:57 INFO lead: acquired remote=192.0.2.1:12345972026/10/01 09:57:58 WARN lead: lock connection lost error="timeout: context deadline exceeded"5982026/10/01 09:57:58 INFO lead: released remote=192.0.2.1:12345992026/10/01 09:57:59 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 TestValidateS3Concurrency688=== PAUSE TestValidateS3Concurrency689=== RUN TestOrphanedObjectsGC690=== PAUSE TestOrphanedObjectsGC691=== RUN TestOrphanedObjectsGCStressTest692=== PAUSE TestOrphanedObjectsGCStressTest693=== RUN TestCreatePin_ReservedPins694=== PAUSE TestCreatePin_ReservedPins695=== RUN TestConcurrentPinUpdatesAgree696=== PAUSE TestConcurrentPinUpdatesAgree697=== RUN TestCreatePinRejectsBadInput698=== PAUSE TestCreatePinRejectsBadInput699=== RUN TestDeletePinKeepsRowWhenS3Fails700=== PAUSE TestDeletePinKeepsRowWhenS3Fails701=== RUN TestPresentReportsOnlyClosureRoots702=== PAUSE TestPresentReportsOnlyClosureRoots703=== RUN TestPresentNotReportedWhileGCDeletesClosure704=== PAUSE TestPresentNotReportedWhileGCDeletesClosure705=== RUN TestParseSingleRange706=== PAUSE TestParseSingleRange707=== RUN TestProxyHeadersOnlyTrustedOnSocket708=== PAUSE TestProxyHeadersOnlyTrustedOnSocket709=== RUN TestIsValidCachePath710=== PAUSE TestIsValidCachePath711=== RUN TestReadProxyNarinfo712=== PAUSE TestReadProxyNarinfo713=== RUN TestReadProxyNarinfoAlreadyDecompressed714=== PAUSE TestReadProxyNarinfoAlreadyDecompressed715=== RUN TestReadProxyNarStreaming716=== PAUSE TestReadProxyNarStreaming717=== RUN TestReadProxy404718=== PAUSE TestReadProxy404719=== RUN TestReadProxyInvalidPath720=== PAUSE TestReadProxyInvalidPath721=== RUN TestReadProxyHead722=== PAUSE TestReadProxyHead723=== RUN TestReadProxyOutlastsServerWriteTimeout724=== PAUSE TestReadProxyOutlastsServerWriteTimeout725=== RUN TestReadProxyConditionalGet726=== PAUSE TestReadProxyConditionalGet727=== RUN TestReadProxyRootRedirectsToIndexHTML728=== PAUSE TestReadProxyRootRedirectsToIndexHTML729=== RUN TestReadProxyDisabled730=== PAUSE TestReadProxyDisabled731=== RUN TestReadRedirectNar732=== PAUSE TestReadRedirectNar733=== RUN TestReadRedirectKeepsNarinfoProxied734=== PAUSE TestReadRedirectKeepsNarinfoProxied735=== RUN TestReadProxyRangeRequest736=== PAUSE TestReadProxyRangeRequest737=== RUN TestReadRedirectUsesPublicS3URL738=== PAUSE TestReadRedirectUsesPublicS3URL739=== RUN TestPush_OverlappingRootsStoreOneRowPerKey740=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey741=== RUN TestPush_CompleteCommitsEveryRoot742=== PAUSE TestPush_CompleteCommitsEveryRoot743=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit744=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit745=== RUN TestPush_RejectsBadRequests746=== PAUSE TestPush_RejectsBadRequests747=== RUN TestPush_SignsNarinfosOfItsPendingObjects748=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects749=== RUN TestRedundantMultipartUpload750=== PAUSE TestRedundantMultipartUpload751=== RUN TestCompleteMultipartUpload_ErrorButObjectExists752=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists753=== RUN TestCompletedNarNotReofferedAcrossClosures754=== PAUSE TestCompletedNarNotReofferedAcrossClosures755=== RUN TestPresignedUploadRegisteredBeforeCommit756=== PAUSE TestPresignedUploadRegisteredBeforeCommit757=== RUN TestService_Rustfstest758=== PAUSE TestService_Rustfstest759=== RUN TestParseSize760=== PAUSE TestParseSize761=== RUN TestSkippedUploadsHandler762=== PAUSE TestSkippedUploadsHandler763=== RUN TestSystemdListenerNotActivated764--- PASS: TestSystemdListenerNotActivated (0.00s)765=== RUN TestWatchdogBeatsWhenHealthy766--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)767=== RUN TestWatchdogSkipsWhenUnhealthy7682026/10/01 09:57:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/10/01 09:57:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/10/01 09:57:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/10/01 09:57:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/10/01 09:57:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/10/01 09:57:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/10/01 09:57:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7752026/10/01 09:57:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7762026/10/01 09:57:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7772026/10/01 09:57:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"778--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)779=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle780=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle781=== RUN TestProxyWriteTimeout782=== PAUSE TestProxyWriteTimeout783=== RUN TestPendingClosureWriteTimeout784=== PAUSE TestPendingClosureWriteTimeout785=== RUN TestIsValidUploadKey786=== PAUSE TestIsValidUploadKey787=== RUN TestUploadHandlersRejectInvalidKeys788=== PAUSE TestUploadHandlersRejectInvalidKeys789=== RUN TestUploadHandlersRejectOversizedBody790=== PAUSE TestUploadHandlersRejectOversizedBody791=== RUN TestService_cleanupPendingClosuresHandler792=== PAUSE TestService_cleanupPendingClosuresHandler793=== RUN TestService_createPendingClosureHandler794=== PAUSE TestService_createPendingClosureHandler795=== RUN TestService_verifyS3Integrity796=== PAUSE TestService_verifyS3Integrity797=== RUN TestCompleteMultipartUnregistered798=== PAUSE TestCompleteMultipartUnregistered799=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT800=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT801=== CONT TestSkippedUploadsHandler802=== CONT TestGCSweepSkipsPendingObjects803=== CONT TestPinProtectsFromGC804=== CONT TestLeadElectsOneAndHandsOver805=== CONT TestService_AuthMiddleware806=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT807=== CONT TestService_healthCheckHandler808=== CONT TestCreatePendingClosureRejectsOversizedNAR809=== CONT TestService_readinessHandler810=== CONT TestService_verifyS3Integrity811=== CONT TestCompleteMultipartUnregistered812=== CONT TestService_createPendingClosureHandler813=== CONT TestGCAdvisoryLockBlocksConcurrentRun8142026/10/01 09:57:59 INFO Received uploads request method=POST path=/api/pending_closures815=== CONT TestService_Rustfstest816=== CONT TestClientCADerivations817--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)818=== CONT TestRegisterCompletedObjectNeedsPendingRow819=== CONT TestCompletedNarNotReofferedAcrossClosures820=== CONT TestClientFallsBackToClosures821=== CONT TestClientWithDependencies822=== CONT TestCacheStatsHandler8232026/10/01 09:57:59 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000824=== CONT TestConnectWaitsForAPeerMigration825=== CONT TestParseSize826--- PASS: TestParseSize (0.00s)827=== CONT TestParseSingleRange828=== CONT TestResolveDBConnectionString829=== CONT TestClientSharedPathCommittedMidPush830=== CONT TestService_cleanupPendingClosuresHandler831=== RUN TestParseSingleRange/none832=== PAUSE TestParseSingleRange/none833=== RUN TestResolveDBConnectionString/flag_wins834=== RUN TestParseSingleRange/unknown_unit835=== PAUSE TestResolveDBConnectionString/flag_wins836=== PAUSE TestParseSingleRange/unknown_unit837=== RUN TestResolveDBConnectionString/file_when_flag_empty838=== PAUSE TestResolveDBConnectionString/file_when_flag_empty839=== RUN TestResolveDBConnectionString/missing_file_is_an_error840=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error841=== RUN TestResolveDBConnectionString/PGHOST_allows_empty842=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty843=== RUN TestParseSingleRange/multi-range_ignored844=== RUN TestResolveDBConnectionString/nothing_configured845=== PAUSE TestParseSingleRange/multi-range_ignored846=== RUN TestParseSingleRange/malformed_no_dash847=== PAUSE TestResolveDBConnectionString/nothing_configured848=== PAUSE TestParseSingleRange/malformed_no_dash849=== CONT TestService_AuthMiddleware_MTLSProxyHeader850=== RUN TestParseSingleRange/malformed_both_empty851=== PAUSE TestParseSingleRange/malformed_both_empty852=== RUN TestParseSingleRange/malformed_end_before_start853=== PAUSE TestParseSingleRange/malformed_end_before_start854=== RUN TestParseSingleRange/closed855=== PAUSE TestParseSingleRange/closed856=== RUN TestParseSingleRange/open-ended857=== PAUSE TestParseSingleRange/open-ended858=== RUN TestParseSingleRange/end_clamped_to_size859=== PAUSE TestParseSingleRange/end_clamped_to_size860=== RUN TestParseSingleRange/suffix861=== PAUSE TestParseSingleRange/suffix862=== RUN TestParseSingleRange/suffix_exceeds_size863=== PAUSE TestParseSingleRange/suffix_exceeds_size864=== RUN TestParseSingleRange/single_byte865=== PAUSE TestParseSingleRange/single_byte866=== RUN TestParseSingleRange/start_past_EOF867=== PAUSE TestParseSingleRange/start_past_EOF868=== RUN TestParseSingleRange/start_far_past_EOF869=== PAUSE TestParseSingleRange/start_far_past_EOF870=== CONT TestGCTaskStore_ConflictDifferentParams871--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)872=== CONT TestGCTaskStore_PhaseUpdates873--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)874=== CONT TestReadProxy404875--- PASS: TestSkippedUploadsHandler (0.03s)876=== CONT TestReadRedirectNar8772026/10/01 09:57:59 INFO lead: acquired remote=192.0.2.1:12348782026/10/01 09:57:59 INFO Received uploads request method=POST path=/api/pending_closures8792026/10/01 09:57:59 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"8802026/10/01 09:57:59 INFO Aborted multipart uploads count=0 kept=08812026/10/01 09:57:59 WARN Force mode enabled - objects will be deleted immediately without grace period882--- PASS: TestService_AuthMiddleware (0.43s)883=== CONT TestPresentNotReportedWhileGCDeletesClosure8842026/10/01 09:57:59 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=08852026/10/01 09:57:59 INFO Received uploads request method=POST path=/api/pending_closures8862026/10/01 09:57:59 INFO Vacuumed table table=pending_closures8872026/10/01 09:57:59 INFO Vacuumed table table=pending_objects8882026/10/01 09:57:59 INFO Vacuumed table table=multipart_uploads8892026/10/01 09:57:59 INFO Vacuumed table table=closures8902026/10/01 09:57:59 INFO Vacuumed table table=objects891--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.46s)892=== CONT TestForceGCDuringPushOffersSweptObject893=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows894=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows895=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check896=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check897=== CONT TestCacheConfigHandlerMaxNarSize898--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)899=== CONT TestMetricsInventory900=== CONT TestClientIntegration901--- PASS: TestGCSweepSkipsPendingObjects (0.46s)9022026/10/01 09:57:59 INFO Received uploads request method=POST path=/api/pending_closures9032026/10/01 09:57:59 INFO Received uploads request method=POST path=/api/pending_closures9042026/10/01 09:57:59 INFO Received uploads request method=POST path=/api/pending_closures9052026/10/01 09:57:59 INFO Received uploads request method=POST path=/api/pending_closures906--- PASS: TestService_healthCheckHandler (0.52s)907=== CONT TestService_AuthMiddleware_OIDC9082026/10/01 09:57:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9092026/10/01 09:57:59 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst910=== NAME TestPinProtectsFromGC911 client_integration_test.go:867: Pinned store path: /build/TestPinProtectsFromGC4056775227/001/store/1p21kvc86mryzkddg0xp72ngz55hn7mx-pinned-file.txt912 client_integration_test.go:868: Unpinned store path: /build/TestPinProtectsFromGC4056775227/001/store/f23gdk4s5brq099qy25s8fg03crjcasy-unpinned-file.txt913--- PASS: TestCompleteMultipartUnregistered (0.55s)914=== CONT TestPendingClosureWriteTimeout915=== RUN TestPendingClosureWriteTimeout/empty916=== PAUSE TestPendingClosureWriteTimeout/empty917=== RUN TestPendingClosureWriteTimeout/negative918=== PAUSE TestPendingClosureWriteTimeout/negative919=== RUN TestPendingClosureWriteTimeout/400_objects920=== PAUSE TestPendingClosureWriteTimeout/400_objects921=== RUN TestPendingClosureWriteTimeout/670k_objects922=== PAUSE TestPendingClosureWriteTimeout/670k_objects923=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline924=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline925=== CONT TestClientErrorHandling926=== RUN TestClientErrorHandling/InvalidStorePath927=== PAUSE TestClientErrorHandling/InvalidStorePath928=== RUN TestClientErrorHandling/InvalidAuthToken929=== PAUSE TestClientErrorHandling/InvalidAuthToken930=== RUN TestClientErrorHandling/ServerNotAvailable931=== PAUSE TestClientErrorHandling/ServerNotAvailable932=== CONT TestGCTaskStore_Fail933--- PASS: TestGCTaskStore_Fail (0.00s)934=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock9352026/10/01 09:58:00 INFO Received uploads request method=POST path=/api/pending_closures9362026/10/01 09:58:00 INFO Received push request method=POST path=/api/pushes9372026/10/01 09:58:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9382026/10/01 09:58:00 INFO Uploading 1p21kvc86mryzkddg0xp72ngz55hn7mx-pinned-file.txt (128B)9392026/10/01 09:58:00 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"940=== CONT TestPresignedUploadRegisteredBeforeCommit941--- PASS: TestCacheStatsHandler (0.64s)9422026/10/01 09:58:00 WARN Failed to register uploaded object key=1p21kvc86mryzkddg0xp72ngz55hn7mx.ls error="server returned 404: 404 page not found\n"9432026/10/01 09:58:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9442026/10/01 09:58:00 INFO Signed narinfos id=1 count=19452026/10/01 09:58:00 INFO Uploading 1 narinfos9462026/10/01 09:58:00 INFO Received cleanup request method=DELETE path=/api/pending_closures9472026/10/01 09:58:00 INFO Aborted multipart uploads count=0 kept=09482026/10/01 09:58:00 INFO Received uploads request method=POST path=/api/pending_closures949=== NAME TestClientCADerivations950 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3756743868/001/store/sidzqp06x825gz6jmy634s4ls3qqggrm-ca-test9512026/10/01 09:58:00 INFO Received complete push request method=POST path=/api/pushes/1/complete9522026/10/01 09:58:00 WARN Failed to register uploaded object key=1p21kvc86mryzkddg0xp72ngz55hn7mx.narinfo error="server returned 404: 404 page not found\n"9532026/10/01 09:58:00 INFO Upload complete. (102ms)9542026/10/01 09:58:00 INFO Received cleanup request method=DELETE path=/api/pending_closures9552026/10/01 09:58:00 INFO Aborted multipart uploads count=1 kept=09562026/10/01 09:58:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9572026-10-01 09:58:00.101 UTC [528] ERROR: Closure does not exist: id=19582026-10-01 09:58:00.101 UTC [528] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE9592026-10-01 09:58:00.101 UTC [528] STATEMENT: -- name: CommitPendingClosure :exec960 SELECT commit_pending_closure($1::bigint)961 962 client_ca_test.go:139: Found 1 dependencies (including self)963--- PASS: TestService_cleanupPendingClosuresHandler (0.70s)964=== CONT TestLeadEndsOnShutdown9652026/10/01 09:58:00 INFO Received push request method=POST path=/api/pushes9662026/10/01 09:58:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9672026/10/01 09:58:00 INFO Uploading f23gdk4s5brq099qy25s8fg03crjcasy-unpinned-file.txt (128B)9682026/10/01 09:58:00 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"9692026/10/01 09:58:00 WARN Failed to register uploaded object key=f23gdk4s5brq099qy25s8fg03crjcasy.ls error="server returned 404: 404 page not found\n"9702026/10/01 09:58:00 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign9712026/10/01 09:58:00 INFO Signed narinfos id=2 count=19722026/10/01 09:58:00 INFO Uploading 1 narinfos973=== NAME TestClientWithDependencies974 client_integration_test.go:735: Built derivation: /build/TestClientWithDependencies389059761/001/store/izd6w1amk3l7f0h27jfk5jgi5q7p7bw8-test-script9752026/10/01 09:58:00 INFO Received complete push request method=POST path=/api/pushes/2/complete9762026/10/01 09:58:00 WARN Failed to register uploaded object key=f23gdk4s5brq099qy25s8fg03crjcasy.narinfo error="server returned 404: 404 page not found\n"9772026/10/01 09:58:00 INFO Upload complete. (75ms)978--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.79s)979=== CONT TestSweepRechecksPendingAfterLocking9802026/10/01 09:58:00 INFO Received push request method=POST path=/api/pushes981--- PASS: TestService_Rustfstest (0.80s)982=== NAME TestClientWithDependencies983 client_integration_test.go:737: Found 1 dependencies (including self)984=== CONT TestCacheConfigHandler985=== RUN TestCacheConfigHandler/full_config,_no_issuer986=== PAUSE TestCacheConfigHandler/full_config,_no_issuer987=== RUN TestCacheConfigHandler/no_cache_url_configured988=== PAUSE TestCacheConfigHandler/no_cache_url_configured989=== RUN TestCacheConfigHandler/no_signing_keys9902026/10/01 09:58:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41793/oidc991=== PAUSE TestCacheConfigHandler/no_signing_keys992=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator993=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator994=== CONT TestClientPushesUseOnePush9952026/10/01 09:58:00 INFO Received push request method=POST path=/api/pushes9962026/10/01 09:58:00 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)9972026/10/01 09:58:00 INFO Uploading hfjvfh5gcqnc0c7jrda0pj56w7s9swfm-shared-dep (136B)9982026/10/01 09:58:00 INFO Uploading 79hg7k8b9ri6rijrglnnhqdajmljxxs3-top (224B)9992026/10/01 09:58:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures10002026/10/01 09:58:00 INFO Garbage collection started10012026/10/01 09:58:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10022026/10/01 09:58:00 INFO Uploading sidzqp06x825gz6jmy634s4ls3qqggrm-ca-test (144B)10032026/10/01 09:58:00 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10042026/10/01 09:58:00 WARN Failed to register uploaded object key=nar/0vrify0mmprmv2hngd100x16hpk5k4ls39yr00bl95ifvfbkjsi3.nar.zst error="server returned 404: 404 page not found\n"10052026/10/01 09:58:00 WARN Failed to register uploaded object key=79hg7k8b9ri6rijrglnnhqdajmljxxs3.ls error="server returned 404: 404 page not found\n"10062026/10/01 09:58:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10072026/10/01 09:58:00 WARN Failed to register uploaded object key=hfjvfh5gcqnc0c7jrda0pj56w7s9swfm.ls error="server returned 404: 404 page not found\n"10082026/10/01 09:58:00 INFO Signed narinfos id=1 count=210092026/10/01 09:58:00 INFO Uploading 2 narinfos10102026/10/01 09:58:00 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"10112026/10/01 09:58:00 INFO Aborted multipart uploads count=0 kept=010122026/10/01 09:58:00 WARN readiness check failed error="closed pool"10132026/10/01 09:58:00 WARN Failed to register uploaded object key=log/wwc3g9nm095i63yhvj7bsa6yx60lw4d2-ca-test.drv error="server returned 404: 404 page not found\n"10142026/10/01 09:58:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10152026/10/01 09:58:00 WARN Failed to register uploaded object key=sidzqp06x825gz6jmy634s4ls3qqggrm.ls error="server returned 404: 404 page not found\n"10162026/10/01 09:58:00 WARN Failed to register uploaded object key=hfjvfh5gcqnc0c7jrda0pj56w7s9swfm.narinfo error="server returned 404: 404 page not found\n"10172026/10/01 09:58:00 INFO Received complete push request method=POST path=/api/pushes/1/complete10182026/10/01 09:58:00 WARN Failed to register uploaded object key=79hg7k8b9ri6rijrglnnhqdajmljxxs3.narinfo error="server returned 404: 404 page not found\n"10192026/10/01 09:58:00 INFO Signed narinfos id=1 count=110202026/10/01 09:58:00 WARN Force mode enabled - objects will be deleted immediately without grace period10212026/10/01 09:58:00 INFO Uploading 1 narinfos1022--- PASS: TestReadRedirectNar (0.82s)1023=== CONT TestService_ReadScope_PublicByDefault10242026/10/01 09:58:00 INFO Received complete push request method=POST path=/api/pushes/1/complete10252026/10/01 09:58:00 WARN Failed to register uploaded object key=sidzqp06x825gz6jmy634s4ls3qqggrm.narinfo error="server returned 404: 404 page not found\n"10262026/10/01 09:58:00 INFO Upload complete. (94ms)1027=== CONT TestClientMultipleUploads1028--- PASS: TestService_readinessHandler (0.85s)1029=== NAME TestClientSharedPathCommittedMidPush1030 client_integration_test.go:816: Retrieved narinfo from S3:1031 StorePath: /build/TestClientSharedPathCommittedMidPush250733328/001/store/hfjvfh5gcqnc0c7jrda0pj56w7s9swfm-shared-dep1032 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1033 Compression: zstd1034 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821035 NarSize: 1361036 References: 1037 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n10382026/10/01 09:58:00 INFO Upload complete. (124ms)1039 client_integration_test.go:816: Retrieved narinfo from S3:1040 StorePath: /build/TestClientSharedPathCommittedMidPush250733328/001/store/79hg7k8b9ri6rijrglnnhqdajmljxxs3-top1041 URL: nar/0vrify0mmprmv2hngd100x16hpk5k4ls39yr00bl95ifvfbkjsi3.nar.zst1042 Compression: zstd1043 NarHash: sha256:0vrify0mmprmv2hngd100x16hpk5k4ls39yr00bl95ifvfbkjsi31044 NarSize: 2241045 References: /build/TestClientSharedPathCommittedMidPush250733328/001/store/hfjvfh5gcqnc0c7jrda0pj56w7s9swfm-shared-dep1046 CA: text:sha256:0w00q7zak0jimha7d81pja86hcra28hgj16la8vljxfiyxn6ijab1047=== NAME TestClientCADerivations1048 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3756743868/001/store/sidzqp06x825gz6jmy634s4ls3qqggrm-ca-test1049 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1050 Compression: zstd1051 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1052 NarSize: 1441053 References: 1054 Deriver: /build/TestClientCADerivations3756743868/001/store/wwc3g9nm095i63yhvj7bsa6yx60lw4d2-ca-test.drv1055 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1056 client_ca_test.go:185: Checking for realisation files in S3...1057 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1058 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache10592026/10/01 09:58:00 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=01060=== CONT TestService_RequireScope_OIDC1061--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.86s)10622026/10/01 09:58:00 INFO Vacuumed table table=pending_closures10632026/10/01 09:58:00 INFO Vacuumed table table=pending_objects10642026/10/01 09:58:00 INFO Vacuumed table table=multipart_uploads10652026/10/01 09:58:00 INFO Vacuumed table table=closures10662026/10/01 09:58:00 INFO Vacuumed table table=objects10672026/10/01 09:58:00 INFO Received push request method=POST path=/api/pushes1068--- PASS: TestClientSharedPathCommittedMidPush (0.89s)1069=== CONT TestConnectSerialisesConcurrentMigrations10702026/10/01 09:58:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10712026/10/01 09:58:00 INFO Uploading izd6w1amk3l7f0h27jfk5jgi5q7p7bw8-test-script (136B)10722026/10/01 09:58:00 INFO Received uploads request method=POST path=/api/pending_closures10732026/10/01 09:58:00 WARN Failed to register uploaded object key=log/gcjv3dp14i6l6l126qj4v32wp7sam01w-test-script.drv error="server returned 404: 404 page not found\n"10742026/10/01 09:58:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10752026/10/01 09:58:00 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"10762026/10/01 09:58:00 WARN Failed to register uploaded object key=izd6w1amk3l7f0h27jfk5jgi5q7p7bw8.ls error="server returned 404: 404 page not found\n"10772026/10/01 09:58:00 INFO Signed narinfos id=1 count=110782026/10/01 09:58:00 INFO Uploading 1 narinfos10792026/10/01 09:58:00 INFO Received uploads request method=POST path=/api/pending_closures10802026/10/01 09:58:00 INFO Received complete push request method=POST path=/api/pushes/1/complete10812026/10/01 09:58:00 WARN Failed to register uploaded object key=izd6w1amk3l7f0h27jfk5jgi5q7p7bw8.narinfo error="server returned 404: 404 page not found\n"10822026/10/01 09:58:00 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10832026/10/01 09:58:00 INFO Uploading znxcgq9qnjcw963b78fasw0s0l3q1idx-shared-dep (136B)10842026/10/01 09:58:00 INFO Uploading j3mbi63s3nlgr6wwf3y5pxm0x9pp7pkj-a (216B)10852026/10/01 09:58:00 INFO Upload complete. (91ms)10862026/10/01 09:58:00 WARN Failed to register uploaded object key=h5ivjix7r78cg0ffy7l7iy6g18j1xv6j.ls error="server returned 404: 404 page not found\n"10872026/10/01 09:58:00 WARN Failed to register uploaded object key=nar/1d78fjs8dvwbb3axmg3ild6mg6w9gprg0sds4qr5r20ijm1z0kg5.nar.zst error="server returned 404: 404 page not found\n"1088=== NAME TestClientIntegration1089 client_integration_test.go:334: Created store path: /build/TestClientIntegration2632323934/002/store/xyfxacsqwyd5344nvvavpsb8a1dcahm6-test-file.txt10902026/10/01 09:58:00 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10912026/10/01 09:58:00 WARN Failed to register uploaded object key=znxcgq9qnjcw963b78fasw0s0l3q1idx.ls error="server returned 404: 404 page not found\n"10922026/10/01 09:58:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign10932026/10/01 09:58:00 WARN Failed to register uploaded object key=j3mbi63s3nlgr6wwf3y5pxm0x9pp7pkj.ls error="server returned 404: 404 page not found\n"10942026/10/01 09:58:00 INFO Signed narinfos id=1 count=21095=== NAME TestClientCADerivations1096 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1097 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1098 error: binary cache 's3://bucket13?endpoint=http://localhost:37323®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3756743868/001/store'1099 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 111002026/10/01 09:58:00 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11012026/10/01 09:58:00 INFO Aborted multipart uploads count=0 kept=011022026/10/01 09:58:00 INFO Signed narinfos id=2 count=211032026/10/01 09:58:00 INFO Uploading 4 narinfos11042026/10/01 09:58:00 WARN Force mode enabled - objects will be deleted immediately without grace period11052026/10/01 09:58:00 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"11062026/10/01 09:58:00 WARN Failed to register uploaded object key=znxcgq9qnjcw963b78fasw0s0l3q1idx.narinfo error="server returned 404: 404 page not found\n"11072026/10/01 09:58:00 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=011082026/10/01 09:58:00 INFO Vacuumed table table=pending_closures11092026/10/01 09:58:00 WARN Failed to register uploaded object key=h5ivjix7r78cg0ffy7l7iy6g18j1xv6j.narinfo error="server returned 404: 404 page not found\n"11102026/10/01 09:58:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11112026/10/01 09:58:00 WARN Failed to register uploaded object key=j3mbi63s3nlgr6wwf3y5pxm0x9pp7pkj.narinfo error="server returned 404: 404 page not found\n"11122026/10/01 09:58:00 WARN Failed to register uploaded object key=znxcgq9qnjcw963b78fasw0s0l3q1idx.narinfo error="server returned 404: 404 page not found\n"11132026/10/01 09:58:00 INFO Vacuumed table table=pending_objects11142026-10-01 09:58:00.388 UTC [1206] ERROR: duplicate key value violates unique constraint "pg_class_relname_nsp_index"11152026-10-01 09:58:00.388 UTC [1206] DETAIL: Key (relname, relnamespace)=(goose_db_version_id_seq, 2200) already exists.11162026-10-01 09:58:00.388 UTC [1206] STATEMENT: CREATE TABLE goose_db_version (1117 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1118 version_id bigint NOT NULL,1119 is_applied boolean NOT NULL,1120 tstamp timestamp NOT NULL DEFAULT now()1121 )11222026/10/01 09:58:00 INFO Vacuumed table table=multipart_uploads11232026/10/01 09:58:00 INFO Vacuumed table table=closures11242026/10/01 09:58:00 INFO Vacuumed table table=objects11252026/10/01 09:58:00 INFO Completed upload id=111262026/10/01 09:58:00 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1127=== NAME TestClientWithDependencies1128 client_integration_test.go:753: Skipping nix copy test - isolated store (/build/TestClientWithDependencies389059761/001/store) requires matching store prefix11292026/10/01 09:58:00 INFO Completed upload id=211302026/10/01 09:58:00 INFO Upload complete. (109ms)1131=== NAME TestClientFallsBackToClosures1132 client_pushes_test.go:112: Retrieved narinfo from S3:1133 StorePath: /build/TestClientFallsBackToClosures64984608/001/store/znxcgq9qnjcw963b78fasw0s0l3q1idx-shared-dep1134 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1135 Compression: zstd1136 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821137 NarSize: 1361138 References: 1139 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1140--- PASS: TestClientCADerivations (0.98s)1141=== CONT TestService_ReadAuthMiddleware1142--- PASS: TestMetricsInventory (0.52s)1143=== CONT TestRedundantMultipartUpload11442026/10/01 09:58:00 INFO Received uploads request method=POST path=/api/pending_closures1145=== NAME TestClientFallsBackToClosures1146 client_pushes_test.go:112: Retrieved narinfo from S3:1147 StorePath: /build/TestClientFallsBackToClosures64984608/001/store/j3mbi63s3nlgr6wwf3y5pxm0x9pp7pkj-a1148 URL: nar/1d78fjs8dvwbb3axmg3ild6mg6w9gprg0sds4qr5r20ijm1z0kg5.nar.zst1149 Compression: zstd1150 NarHash: sha256:1d78fjs8dvwbb3axmg3ild6mg6w9gprg0sds4qr5r20ijm1z0kg51151 NarSize: 2161152 References: /build/TestClientFallsBackToClosures64984608/001/store/znxcgq9qnjcw963b78fasw0s0l3q1idx-shared-dep1153 CA: text:sha256:096ahhabncj649d1xr7ihv2zxl23ncsfxdbn70n57z0757cgphws1154 client_pushes_test.go:112: Retrieved narinfo from S3:1155 StorePath: /build/TestClientFallsBackToClosures64984608/001/store/h5ivjix7r78cg0ffy7l7iy6g18j1xv6j-b1156 URL: nar/1d78fjs8dvwbb3axmg3ild6mg6w9gprg0sds4qr5r20ijm1z0kg5.nar.zst1157 Compression: zstd1158 NarHash: sha256:1d78fjs8dvwbb3axmg3ild6mg6w9gprg0sds4qr5r20ijm1z0kg51159 NarSize: 2161160 References: /build/TestClientFallsBackToClosures64984608/001/store/znxcgq9qnjcw963b78fasw0s0l3q1idx-shared-dep1161 CA: text:sha256:096ahhabncj649d1xr7ihv2zxl23ncsfxdbn70n57z0757cgphws1162=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1163--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.99s)1164=== CONT TestReadProxyRootRedirectsToIndexHTML1165--- PASS: TestClientWithDependencies (0.99s)11662026/10/01 09:58:00 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11672026/10/01 09:58:00 INFO Received uploads request method=POST path=/api/pending_closures11682026/10/01 09:58:00 INFO lead: acquired remote=192.0.2.1:123411692026/10/01 09:58:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1170--- PASS: TestClientFallsBackToClosures (1.01s)1171=== CONT TestPush_SignsNarinfosOfItsPendingObjects1172--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.38s)1173=== CONT TestCompleteMultipartUpload_ErrorButObjectExists11742026/10/01 09:58:00 INFO Received push request method=POST path=/api/pushes11752026/10/01 09:58:00 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YzIwZDlkYzAtYmY4OS00YzFlLWEwZjktZjY1ZjAzMmUyZGEzLmEzOTg1ZWVjLTA0ZWYtNDIzNS05MzQyLTg5YzgyY2JkNWI1MXgxNzkwODQ4Njc5ODk2NzA0NDQ1 parts=1011762026/10/01 09:58:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11772026/10/01 09:58:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11782026/10/01 09:58:00 INFO Uploading xyfxacsqwyd5344nvvavpsb8a1dcahm6-test-file.txt (152B)11792026/10/01 09:58:00 INFO Completed upload id=111802026/10/01 09:58:00 INFO Received uploads request method=POST path=/api/pending_closures11812026/10/01 09:58:00 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"11822026/10/01 09:58:00 WARN Failed to register uploaded object key=xyfxacsqwyd5344nvvavpsb8a1dcahm6.ls error="server returned 404: 404 page not found\n"11832026/10/01 09:58:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11842026/10/01 09:58:00 INFO Signed narinfos id=1 count=111852026/10/01 09:58:00 INFO Uploading 1 narinfos11862026/10/01 09:58:00 INFO Received uploads request method=POST path=/api/pending_closures11872026/10/01 09:58:00 INFO Aborted multipart uploads count=0 kept=011882026/10/01 09:58:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11892026/10/01 09:58:00 INFO Received complete push request method=POST path=/api/pushes/1/complete11902026/10/01 09:58:00 WARN Failed to register uploaded object key=xyfxacsqwyd5344nvvavpsb8a1dcahm6.narinfo error="server returned 404: 404 page not found\n"11912026/10/01 09:58:00 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11922026/10/01 09:58:00 WARN Found objects in DB but missing from S3, will re-upload count=111932026/10/01 09:58:00 WARN Force mode enabled - objects will be deleted immediately without grace period11942026/10/01 09:58:00 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete11952026/10/01 09:58:00 INFO Upload complete. (77ms)11962026/10/01 09:58:00 INFO Completed upload id=31197=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1198=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1199=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1200=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1201=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1202=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1203=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1204=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1205=== CONT TestGCSweepDeliversEachKeyOnce12062026/10/01 09:58:00 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YzIwZDlkYzAtYmY4OS00YzFlLWEwZjktZjY1ZjAzMmUyZGEzLjFiNGY5ZjY3LWFjYzEtNDRkNi1iZGRiLTBjZjAyZDYxMGQ2YXgxNzkwODQ4Njc5OTI1NDQzMjYx parts=1012072026/10/01 09:58:00 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=012082026/10/01 09:58:00 INFO Vacuumed table table=pending_closures12092026/10/01 09:58:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12102026/10/01 09:58:00 INFO Vacuumed table table=pending_objects12112026/10/01 09:58:00 INFO Vacuumed table table=multipart_uploads1212=== CONT TestSweepSkipsRowsLockedByPush1213--- PASS: TestService_verifyS3Integrity (1.08s)12142026/10/01 09:58:00 INFO Vacuumed table table=closures12152026/10/01 09:58:00 INFO Completed upload id=112162026/10/01 09:58:00 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012172026/10/01 09:58:00 INFO Vacuumed table table=objects12182026/10/01 09:58:00 INFO Received uploads request method=POST path=/api/pending_closures12192026/10/01 09:58:00 INFO All 1 paths already cached12202026/10/01 09:58:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures1221=== NAME TestClientIntegration1222 client_integration_test.go:360: Retrieved narinfo from S3:1223 StorePath: /build/TestClientIntegration2632323934/002/store/xyfxacsqwyd5344nvvavpsb8a1dcahm6-test-file.txt1224 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1225 Compression: zstd1226 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11227 NarSize: 1521228 References: 1229 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk112302026/10/01 09:58:00 WARN Rate limiter enabled after throttle name=s3-test rate=512312026/10/01 09:58:00 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."12322026/10/01 09:58:00 INFO Aborted multipart uploads count=0 kept=01233 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)1234 client_integration_test.go:361: Decompressed .ls content (64 bytes):1235 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1236=== CONT TestPush_RejectsBadRequests1237--- PASS: TestSweepRechecksPendingAfterLocking (0.33s)12382026/10/01 09:58:00 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=012392026/10/01 09:58:00 INFO Vacuumed table table=pending_closures12402026/10/01 09:58:00 INFO Vacuumed table table=pending_objects12412026/10/01 09:58:00 INFO Vacuumed table table=multipart_uploads12422026/10/01 09:58:00 INFO Vacuumed table table=closures12432026/10/01 09:58:00 INFO Vacuumed table table=objects1244--- PASS: TestService_ReadScope_PublicByDefault (0.30s)1245=== CONT TestReadProxyOutlastsServerWriteTimeout1246=== NAME TestClientMultipleUploads1247 client_integration_test.go:480: Created store path 0: /build/TestClientMultipleUploads2833293167/001/store/ny8d6bi1h8ffn8g699l1c4ykp71dhp3p-test-file-0.txt12482026/10/01 09:58:00 WARN Rate limiter backed off name=s3-test rate=512492026/10/01 09:58:00 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012502026/10/01 09:58:00 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."1251=== CONT TestPresentReportsOnlyClosureRoots1252--- PASS: TestService_createPendingClosureHandler (1.17s)12532026/10/01 09:58:00 INFO Received uploads request method=POST path=/api/pending_closures1254--- PASS: TestReadProxy404 (1.16s)1255=== CONT TestGCTaskStore_StartNew1256=== CONT TestReadProxyHead1257--- PASS: TestGCTaskStore_StartNew (0.00s)1258=== NAME TestClientMultipleUploads1259 client_integration_test.go:480: Created store path 1: /build/TestClientMultipleUploads2833293167/001/store/5f3g77r6p6jgv6lggngh03bi1rkmwrza-test-file-1.txt12602026/10/01 09:58:00 INFO Received uploads request method=POST path=/api/pending_closures12612026/10/01 09:58:00 INFO Received push request method=POST path=/api/pushes12622026/10/01 09:58:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12632026/10/01 09:58:00 INFO Object in database but missing from S3 key=xyfxacsqwyd5344nvvavpsb8a1dcahm6.ls12642026/10/01 09:58:00 WARN Found objects in DB but missing from S3, will re-upload count=112652026/10/01 09:58:00 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1266--- PASS: TestService_ReadAuthMiddleware (0.23s)1267=== CONT TestReadProxyConditionalGet12682026/10/01 09:58:00 INFO Received complete push request method=POST path=/api/pushes/2/complete12692026/10/01 09:58:00 WARN Failed to register uploaded object key=xyfxacsqwyd5344nvvavpsb8a1dcahm6.ls error="server returned 404: 404 page not found\n"12702026/10/01 09:58:00 INFO Upload complete. (63ms)1271=== NAME TestClientMultipleUploads1272 client_integration_test.go:480: Created store path 2: /build/TestClientMultipleUploads2833293167/001/store/fls1h6f34vdiil35yh0mmslcybwj305d-test-file-2.txt12732026/10/01 09:58:00 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YzIwZDlkYzAtYmY4OS00YzFlLWEwZjktZjY1ZjAzMmUyZGEzLmY3MDBlNzY1LTExZTktNDEzYy1hMjcwLWZiNjEzY2U1MTc5ZHgxNzkwODQ4NjgwMDEyMTI1OTEy parts=121274=== NAME TestClientIntegration1275 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)1276 client_integration_test.go:389: Decompressed .ls content (49 bytes):1277 {"version":1,"root":{"type":"regular","size":39}}12782026/10/01 09:58:00 INFO Received uploads request method=POST path=/api/pending_closures12792026/10/01 09:58:00 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"12802026/10/01 09:58:00 WARN mTLS auth: bound subjects configured but subject DN unavailable12812026/10/01 09:58:00 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1282=== CONT TestGCTaskStore_DeduplicateSameParams1283--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.25s)1284=== CONT TestReadProxyInvalidPath1285--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1286=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1287--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.25s)12882026/10/01 09:58:00 INFO Received push request method=POST path=/api/pushes1289=== CONT TestReadProxyNarStreaming1290--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.26s)12912026/10/01 09:58:00 INFO Received push request method=POST path=/api/pushes12922026/10/01 09:58:00 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12932026/10/01 09:58:00 INFO Uploading 3m5bziisvv499a47k08fzldak2p053g0-a (216B)12942026/10/01 09:58:00 INFO Uploading f7l68hgss7f9mv6ivkdh8ifigy1wmm7w-shared-dep (136B)12952026/10/01 09:58:00 WARN Failed to register uploaded object key=lh57kkcykldphccp16wyqfnvmxk3w46q.ls error="server returned 404: 404 page not found\n"12962026/10/01 09:58:00 WARN Failed to register uploaded object key=nar/08mx86n694kil1pk7h7clr374hnjjnnrj6m4xhalz45x60zlmwk8.nar.zst error="server returned 404: 404 page not found\n"12972026/10/01 09:58:00 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12982026/10/01 09:58:00 INFO Received uploads request method=POST path=/api/pending_closures12992026/10/01 09:58:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13002026/10/01 09:58:00 WARN Failed to register uploaded object key=3m5bziisvv499a47k08fzldak2p053g0.ls error="server returned 404: 404 page not found\n"13012026/10/01 09:58:00 WARN Failed to register uploaded object key=f7l68hgss7f9mv6ivkdh8ifigy1wmm7w.ls error="server returned 404: 404 page not found\n"13022026/10/01 09:58:00 INFO Received push request method=POST path=/api/pushes13032026/10/01 09:58:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13042026/10/01 09:58:00 INFO Signed narinfos id=1 count=313052026/10/01 09:58:00 INFO Uploading 3 narinfos13062026/10/01 09:58:00 INFO Received push request method=POST path=/api/pushes13072026/10/01 09:58:00 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13082026/10/01 09:58:00 INFO Uploading fls1h6f34vdiil35yh0mmslcybwj305d-test-file-2.txt (160B)13092026/10/01 09:58:00 INFO Uploading 5f3g77r6p6jgv6lggngh03bi1rkmwrza-test-file-1.txt (160B)13102026/10/01 09:58:00 INFO Uploading ny8d6bi1h8ffn8g699l1c4ykp71dhp3p-test-file-0.txt (160B)13112026/10/01 09:58:00 WARN Failed to register uploaded object key=3m5bziisvv499a47k08fzldak2p053g0.narinfo error="server returned 404: 404 page not found\n"13122026/10/01 09:58:00 INFO Signed narinfos id=1 count=113132026/10/01 09:58:00 WARN Failed to register uploaded object key=f7l68hgss7f9mv6ivkdh8ifigy1wmm7w.narinfo error="server returned 404: 404 page not found\n"13142026/10/01 09:58:00 INFO Received complete push request method=POST path=/api/pushes/1/complete13152026/10/01 09:58:00 WARN Failed to register uploaded object key=lh57kkcykldphccp16wyqfnvmxk3w46q.narinfo error="server returned 404: 404 page not found\n"13162026/10/01 09:58:00 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13172026/10/01 09:58:00 INFO Upload complete. (124ms)13182026/10/01 09:58:00 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"1319=== NAME TestClientPushesUseOnePush1320 client_pushes_test.go:97: Retrieved narinfo from S3:1321 StorePath: /build/TestClientPushesUseOnePush1045996708/001/store/f7l68hgss7f9mv6ivkdh8ifigy1wmm7w-shared-dep1322 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1323 Compression: zstd1324 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821325 NarSize: 1361326 References: 1327 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13282026/10/01 09:58:00 INFO Received complete push request method=POST path=/api/pushes/3/complete1329--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.32s)1330=== CONT TestGracefulShutdownDrainsInflight13312026/10/01 09:58:00 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"13322026/10/01 09:58:00 INFO Starting HTTP server address=127.0.0.1:4135513332026/10/01 09:58:00 WARN Failed to register uploaded object key=xyfxacsqwyd5344nvvavpsb8a1dcahm6.ls error="server returned 404: 404 page not found\n"13342026/10/01 09:58:00 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"13352026/10/01 09:58:00 WARN Failed to register uploaded object key=fls1h6f34vdiil35yh0mmslcybwj305d.ls error="server returned 404: 404 page not found\n"13362026/10/01 09:58:00 WARN Failed to register uploaded object key=5f3g77r6p6jgv6lggngh03bi1rkmwrza.ls error="server returned 404: 404 page not found\n"13372026/10/01 09:58:00 INFO Shutdown signal received, draining in-flight requests timeout=10s13382026/10/01 09:58:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13392026/10/01 09:58:00 WARN Failed to register uploaded object key=ny8d6bi1h8ffn8g699l1c4ykp71dhp3p.ls error="server returned 404: 404 page not found\n"13402026/10/01 09:58:00 INFO Upload complete. (68ms)13412026/10/01 09:58:00 INFO Signed narinfos id=1 count=313422026/10/01 09:58:00 INFO Uploading 3 narinfos1343=== NAME TestClientIntegration1344 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)1345=== NAME TestClientPushesUseOnePush1346 client_pushes_test.go:97: Retrieved narinfo from S3:1347 StorePath: /build/TestClientPushesUseOnePush1045996708/001/store/3m5bziisvv499a47k08fzldak2p053g0-a1348 URL: nar/08mx86n694kil1pk7h7clr374hnjjnnrj6m4xhalz45x60zlmwk8.nar.zst1349 Compression: zstd1350 NarHash: sha256:08mx86n694kil1pk7h7clr374hnjjnnrj6m4xhalz45x60zlmwk81351 NarSize: 2161352=== NAME TestClientIntegration1353 client_integration_test.go:405: Decompressed .ls content (49 bytes):1354 {"version":1,"root":{"type":"regular","size":39}}1355=== NAME TestClientPushesUseOnePush1356 References: /build/TestClientPushesUseOnePush1045996708/001/store/f7l68hgss7f9mv6ivkdh8ifigy1wmm7w-shared-dep1357 CA: text:sha256:0mi3nkd6b4i9j0vniggzqn3fl04qvp435nw34w06zww8lwz7xr4l13582026/10/01 09:58:00 WARN Failed to register uploaded object key=5f3g77r6p6jgv6lggngh03bi1rkmwrza.narinfo error="server returned 404: 404 page not found\n"1359 client_pushes_test.go:97: Retrieved narinfo from S3:1360 StorePath: /build/TestClientPushesUseOnePush1045996708/001/store/lh57kkcykldphccp16wyqfnvmxk3w46q-b1361 URL: nar/08mx86n694kil1pk7h7clr374hnjjnnrj6m4xhalz45x60zlmwk8.nar.zst1362 Compression: zstd1363 NarHash: sha256:08mx86n694kil1pk7h7clr374hnjjnnrj6m4xhalz45x60zlmwk81364 NarSize: 2161365 References: /build/TestClientPushesUseOnePush1045996708/001/store/f7l68hgss7f9mv6ivkdh8ifigy1wmm7w-shared-dep1366 CA: text:sha256:0mi3nkd6b4i9j0vniggzqn3fl04qvp435nw34w06zww8lwz7xr4l13672026/10/01 09:58:00 INFO Aborted multipart uploads count=0 kept=013682026/10/01 09:58:00 INFO Received complete push request method=POST path=/api/pushes/1/complete13692026/10/01 09:58:00 WARN Failed to register uploaded object key=fls1h6f34vdiil35yh0mmslcybwj305d.narinfo error="server returned 404: 404 page not found\n"13702026/10/01 09:58:00 WARN Failed to register uploaded object key=ny8d6bi1h8ffn8g699l1c4ykp71dhp3p.narinfo error="server returned 404: 404 page not found\n"13712026/10/01 09:58:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13722026/10/01 09:58:00 INFO Aborted multipart uploads count=0 kept=013732026/10/01 09:58:00 WARN Force mode enabled - objects will be deleted immediately without grace period13742026/10/01 09:58:00 WARN Force mode enabled - objects will be deleted immediately without grace period1375=== RUN TestPush_RejectsBadRequests/no_roots1376=== PAUSE TestPush_RejectsBadRequests/no_roots1377=== RUN TestPush_RejectsBadRequests/no_objects1378=== PAUSE TestPush_RejectsBadRequests/no_objects1379=== RUN TestPush_RejectsBadRequests/bad_root1380=== PAUSE TestPush_RejectsBadRequests/bad_root1381=== RUN TestPush_RejectsBadRequests/root_not_in_objects1382=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1383=== CONT TestReadProxyNarinfoAlreadyDecompressed13842026/10/01 09:58:00 INFO Upload complete. (105ms)1385=== NAME TestClientMultipleUploads1386 client_integration_test.go:491: Uploaded 3 paths in 140.013805ms13872026/10/01 09:58:00 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=013882026/10/01 09:58:00 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzIwZDlkYzAtYmY4OS00YzFlLWEwZjktZjY1ZjAzMmUyZGEzLjdkMjZhMjNlLTIyZTMtNDBhOC04YzRiLWJiOTJhMmY3N2RiYXgxNzkwODQ4NjgwNzMwNDg4MTAw13892026/10/01 09:58:00 INFO Vacuumed table table=pending_closures13902026/10/01 09:58:00 INFO Vacuumed table table=pending_objects13912026/10/01 09:58:00 INFO Vacuumed table table=multipart_uploads13922026/10/01 09:58:00 INFO Vacuumed table table=closures13932026/10/01 09:58:00 INFO Vacuumed table table=objects13942026/10/01 09:58:00 INFO Aborted multipart uploads count=0 kept=013952026/10/01 09:58:00 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=013962026/10/01 09:58:00 WARN Force mode enabled - objects will be deleted immediately without grace period13972026/10/01 09:58:00 INFO Vacuumed table table=pending_closures13982026/10/01 09:58:00 INFO Vacuumed table table=pending_objects13992026/10/01 09:58:00 INFO Vacuumed table table=multipart_uploads14002026/10/01 09:58:00 INFO Vacuumed table table=closures1401--- PASS: TestClientPushesUseOnePush (0.57s)1402=== CONT TestGCTaskStore_CompletedAllowsNewTask1403--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1404=== CONT TestPush_OverlappingRootsStoreOneRowPerKey14052026/10/01 09:58:00 INFO Vacuumed table table=objects14062026/10/01 09:58:00 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=014072026/10/01 09:58:00 INFO Vacuumed table table=pending_closures14082026/10/01 09:58:00 INFO Vacuumed table table=pending_objects14092026/10/01 09:58:00 INFO Vacuumed table table=multipart_uploads14102026/10/01 09:58:00 INFO Vacuumed table table=closures14112026/10/01 09:58:00 INFO Vacuumed table table=objects1412--- PASS: TestGCSweepDeliversEachKeyOnce (0.32s)1413=== CONT TestPush_CompleteCommitsEveryRoot1414--- PASS: TestClientMultipleUploads (0.54s)1415=== CONT TestReadProxyNarinfo1416--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.97s)1417=== CONT TestDeletePinKeepsRowWhenS3Fails1418--- PASS: TestSweepSkipsRowsLockedByPush (0.33s)1419=== CONT TestGCEndsOnShutdown1420=== RUN TestGCEndsOnShutdown/before_the_run1421=== PAUSE TestGCEndsOnShutdown/before_the_run1422=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1423=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1424=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1425=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1426=== CONT TestReadProxyRangeRequest1427--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1428=== CONT TestUploadHandlersRejectInvalidKeys1429=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1430=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1431=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1432=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1433=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1434=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1435=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1436=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1437=== CONT TestIsValidCachePath1438=== RUN TestIsValidCachePath/narinfo1439=== PAUSE TestIsValidCachePath/narinfo1440=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1441=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1442=== RUN TestIsValidCachePath/nar_zst1443=== PAUSE TestIsValidCachePath/nar_zst1444=== RUN TestIsValidCachePath/nar_xz1445=== PAUSE TestIsValidCachePath/nar_xz1446=== RUN TestIsValidCachePath/nar_bz21447=== PAUSE TestIsValidCachePath/nar_bz21448=== RUN TestIsValidCachePath/nar_uncompressed1449=== PAUSE TestIsValidCachePath/nar_uncompressed1450=== RUN TestIsValidCachePath/ls1451=== PAUSE TestIsValidCachePath/ls1452=== RUN TestIsValidCachePath/log1453=== PAUSE TestIsValidCachePath/log1454=== RUN TestIsValidCachePath/realisation1455=== PAUSE TestIsValidCachePath/realisation1456=== RUN TestIsValidCachePath/nix-cache-info1457=== PAUSE TestIsValidCachePath/nix-cache-info1458=== RUN TestIsValidCachePath/index.html1459=== PAUSE TestIsValidCachePath/index.html1460=== RUN TestIsValidCachePath/traversal_parent1461=== PAUSE TestIsValidCachePath/traversal_parent1462=== RUN TestIsValidCachePath/traversal_in_middle1463=== PAUSE TestIsValidCachePath/traversal_in_middle1464=== RUN TestIsValidCachePath/invalid_char_e1465=== PAUSE TestIsValidCachePath/invalid_char_e1466=== RUN TestIsValidCachePath/invalid_char_u1467=== PAUSE TestIsValidCachePath/invalid_char_u1468=== RUN TestIsValidCachePath/random_path1469=== PAUSE TestIsValidCachePath/random_path1470=== RUN TestIsValidCachePath/empty1471=== PAUSE TestIsValidCachePath/empty1472=== RUN TestIsValidCachePath/leading_slash1473=== PAUSE TestIsValidCachePath/leading_slash1474=== RUN TestIsValidCachePath/wrong_extension1475=== PAUSE TestIsValidCachePath/wrong_extension1476=== RUN TestIsValidCachePath/short_hash1477=== PAUSE TestIsValidCachePath/short_hash1478=== CONT TestFailedS3DeleteKeepsTombstone14792026/10/01 09:58:00 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzIwZDlkYzAtYmY4OS00YzFlLWEwZjktZjY1ZjAzMmUyZGEzLjdkMjZhMjNlLTIyZTMtNDBhOC04YzRiLWJiOTJhMmY3N2RiYXgxNzkwODQ4NjgwNzMwNDg4MTAw error="Delete \"http://localhost:37323/bucket43/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=YzIwZDlkYzAtYmY4OS00YzFlLWEwZjktZjY1ZjAzMmUyZGEzLjdkMjZhMjNlLTIyZTMtNDBhOC04YzRiLWJiOTJhMmY3N2RiYXgxNzkwODQ4NjgwNzMwNDg4MTAw\": injected: abort refused"14802026/10/01 09:58:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44001/oidc14812026/10/01 09:58:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14822026/10/01 09:58:00 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzIwZDlkYzAtYmY4OS00YzFlLWEwZjktZjY1ZjAzMmUyZGEzLjdkMjZhMjNlLTIyZTMtNDBhOC04YzRiLWJiOTJhMmY3N2RiYXgxNzkwODQ4NjgwNzMwNDg4MTAw14832026/10/01 09:58:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YzIwZDlkYzAtYmY4OS00YzFlLWEwZjktZjY1ZjAzMmUyZGEzLjdkMjZhMjNlLTIyZTMtNDBhOC04YzRiLWJiOTJhMmY3N2RiYXgxNzkwODQ4NjgwNzMwNDg4MTAw parts=114842026/10/01 09:58:00 INFO Received push request method=POST path=/api/pushes14852026/10/01 09:58:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14862026/10/01 09:58:00 INFO Uploading cvr9lc5yaxnxfqq80ynxsnrvwr9cdiwf-lost-commit.txt (152B)1487=== CONT TestUploadHandlersRejectOversizedBody1488--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.44s)14892026/10/01 09:58:00 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"14902026/10/01 09:58:00 WARN Failed to register uploaded object key=cvr9lc5yaxnxfqq80ynxsnrvwr9cdiwf.ls error="server returned 404: 404 page not found\n"14912026/10/01 09:58:00 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign14922026/10/01 09:58:00 INFO Signed narinfos id=4 count=114932026/10/01 09:58:00 INFO Uploading 1 narinfos14942026/10/01 09:58:00 INFO Received complete push request method=POST path=/api/pushes/4/complete14952026/10/01 09:58:00 WARN Failed to register uploaded object key=cvr9lc5yaxnxfqq80ynxsnrvwr9cdiwf.narinfo error="server returned 404: 404 page not found\n"14962026/10/01 09:58:00 INFO Received push request method=POST path=/api/pushes14972026/10/01 09:58:00 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://127.0.0.1:33075/api/pushes/4/complete\": EOF" url=http://127.0.0.1:33075/api/pushes/4/complete1498--- PASS: TestPresentReportsOnlyClosureRoots (0.31s)1499=== CONT TestReadRedirectUsesPublicS3URL1500--- PASS: TestReadProxyHead (0.36s)1501=== CONT TestCreatePinRejectsBadInput1502--- PASS: TestReadProxyNarStreaming (0.27s)1503=== CONT TestProxyWriteTimeout1504=== RUN TestProxyWriteTimeout/narinfo1505=== PAUSE TestProxyWriteTimeout/narinfo1506=== RUN TestProxyWriteTimeout/1_GiB_nar1507=== PAUSE TestProxyWriteTimeout/1_GiB_nar1508=== RUN TestProxyWriteTimeout/10_GiB_nar1509=== PAUSE TestProxyWriteTimeout/10_GiB_nar1510=== RUN TestProxyWriteTimeout/unknown_size1511=== PAUSE TestProxyWriteTimeout/unknown_size1512=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1513=== CONT TestCommitRacingPendingCleanupKeepsObjects1514--- PASS: TestReadProxyConditionalGet (0.32s)1515--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.19s)1516=== CONT TestReadRedirectKeepsNarinfoProxied1517--- PASS: TestReadProxyInvalidPath (0.32s)1518=== CONT TestGetExistingObjectsLocksRows15192026/10/01 09:58:00 INFO Received push request method=POST path=/api/pushes15202026/10/01 09:58:01 INFO Received complete push request method=POST path=/api/pushes/4/complete15212026-10-01 09:58:01.001 UTC [586] ERROR: Push does not exist: id=415222026-10-01 09:58:01.001 UTC [586] CONTEXT: PL/pgSQL function commit_push(bigint) line 9 at RAISE15232026-10-01 09:58:01.001 UTC [586] STATEMENT: -- name: CommitPush :exec1524 SELECT commit_push($1::bigint)1525 15262026/10/01 09:58:01 INFO lead: released remote=192.0.2.1:123415272026/10/01 09:58:01 INFO Upload complete. (173ms)1528=== NAME TestClientIntegration1529 client_integration_test.go:435: Retrieved narinfo from S3:1530 StorePath: /build/TestClientIntegration2632323934/002/store/cvr9lc5yaxnxfqq80ynxsnrvwr9cdiwf-lost-commit.txt1531 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1532 Compression: zstd1533 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1534 NarSize: 1521535 References: 1536 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1537 client_integration_test.go:438: Testing garbage collection...15382026/10/01 09:58:01 INFO Starting cleanup of old closures method=DELETE path=/api/closures15392026/10/01 09:58:01 INFO lead: acquired remote=192.0.2.1:123415402026/10/01 09:58:01 INFO Garbage collection started15412026/10/01 09:58:01 INFO Received create pin request method=POST path=/api/pins/app15422026/10/01 09:58:01 INFO Aborted multipart uploads count=0 kept=01543--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.27s)1544=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection15452026/10/01 09:58:01 WARN Force mode enabled - objects will be deleted immediately without grace period15462026/10/01 09:58:01 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo15472026/10/01 09:58:01 INFO Received delete pin request method=DELETE path=/api/pins/app15482026/10/01 09:58:01 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket57/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"15492026/10/01 09:58:01 INFO Received delete pin request method=DELETE path=/api/pins/app15502026/10/01 09:58:01 INFO Received push request method=POST path=/api/pushes15512026/10/01 09:58:01 INFO Deleted pin name=app15522026/10/01 09:58:01 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=015532026/10/01 09:58:01 INFO Received uploads request method=POST path=/api/pending_closures15542026/10/01 09:58:01 INFO Vacuumed table table=pending_closures1555--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.29s)1556=== CONT TestReadProxyDisabled15572026/10/01 09:58:01 INFO Vacuumed table table=pending_objects15582026/10/01 09:58:01 INFO Vacuumed table table=multipart_uploads15592026/10/01 09:58:01 INFO Vacuumed table table=closures15602026/10/01 09:58:01 INFO Vacuumed table table=objects1561--- PASS: TestReadProxyRangeRequest (0.34s)1562=== CONT TestGCTaskStore_GetEmpty1563--- PASS: TestGCTaskStore_GetEmpty (0.00s)1564=== CONT TestProxyHeadersOnlyTrustedOnSocket1565=== RUN TestService_RequireScope_OIDC/builder_may_write1566=== PAUSE TestService_RequireScope_OIDC/builder_may_write1567=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1568=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1569=== RUN TestService_RequireScope_OIDC/ops_may_admin1570=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1571=== RUN TestService_RequireScope_OIDC/ops_may_not_write1572=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1573=== RUN TestService_RequireScope_OIDC/reader_may_not_write1574=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1575=== RUN TestService_RequireScope_OIDC/static_token_may_admin1576=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1577=== RUN TestService_RequireScope_OIDC/static_token_may_write1578=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1579=== RUN TestService_RequireScope_OIDC/reader_may_read1580=== PAUSE TestService_RequireScope_OIDC/reader_may_read1581=== RUN TestService_RequireScope_OIDC/writer_implies_read1582=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1583=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1584=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1585=== CONT TestGCTaskStore_GetReturnsLatest1586=== CONT TestPendingClosureFailureTracksEveryUpload1587--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)15882026/10/01 09:58:01 INFO Aborted multipart uploads count=0 kept=015892026/10/01 09:58:01 WARN Force mode enabled - objects will be deleted immediately without grace period15902026/10/01 09:58:01 INFO Received create pin request method=POST path=/api/pins/deploy15912026/10/01 09:58:01 INFO Received create pin request method=POST path=/api/pins/deploy15922026/10/01 09:58:01 INFO Received create pin request method=POST path=/api/pins/deploy15932026/10/01 09:58:01 INFO Received create pin request method=POST path=/api/pins/deploy15942026/10/01 09:58:01 INFO Received create pin request method=POST path=/api/pins/deploy15952026/10/01 09:58:01 INFO Received create pin request method=POST path=/api/pins/deploy15962026/10/01 09:58:01 INFO Received create pin request method=POST path=/api/pins/deploy15972026/10/01 09:58:01 INFO Received create pin request method=POST path=/api/pins/deploy15982026/10/01 09:58:01 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."15992026/10/01 09:58:01 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."16002026/10/01 09:58:01 INFO Received uploads request method=POST path=/api/pending_closures1601=== CONT TestIsValidUploadKey1602=== RUN TestIsValidUploadKey/narinfo1603--- PASS: TestFailedS3DeleteKeepsTombstone (0.41s)1604=== PAUSE TestIsValidUploadKey/narinfo1605=== RUN TestIsValidUploadKey/nar_zst1606=== PAUSE TestIsValidUploadKey/nar_zst1607=== RUN TestIsValidUploadKey/nar_xz16082026/10/01 09:58:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1609=== PAUSE TestIsValidUploadKey/nar_xz1610=== RUN TestIsValidUploadKey/nar_plain1611=== PAUSE TestIsValidUploadKey/nar_plain1612=== RUN TestIsValidUploadKey/listing1613=== PAUSE TestIsValidUploadKey/listing1614=== RUN TestIsValidUploadKey/build_log1615=== PAUSE TestIsValidUploadKey/build_log1616=== RUN TestIsValidUploadKey/build_log_home-manager_file1617=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1618=== RUN TestIsValidUploadKey/build_log_plus_in_name1619=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1620=== RUN TestIsValidUploadKey/build_log_question_mark1621=== PAUSE TestIsValidUploadKey/build_log_question_mark1622=== RUN TestIsValidUploadKey/build_log_equals1623=== PAUSE TestIsValidUploadKey/build_log_equals1624=== RUN TestIsValidUploadKey/realisation1625=== PAUSE TestIsValidUploadKey/realisation1626=== RUN TestIsValidUploadKey/realisation_plus_in_output1627=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1628=== RUN TestIsValidUploadKey/nix-cache-info1629=== PAUSE TestIsValidUploadKey/nix-cache-info1630=== RUN TestIsValidUploadKey/index.html1631=== PAUSE TestIsValidUploadKey/index.html1632=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1633=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1634=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1635=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1636=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1637=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1638=== RUN TestIsValidUploadKey/traversal1639=== PAUSE TestIsValidUploadKey/traversal1640=== RUN TestIsValidUploadKey/traversal_nar1641=== PAUSE TestIsValidUploadKey/traversal_nar1642=== RUN TestIsValidUploadKey/absolute1643=== PAUSE TestIsValidUploadKey/absolute1644=== RUN TestIsValidUploadKey/empty_key1645=== PAUSE TestIsValidUploadKey/empty_key1646=== RUN TestIsValidUploadKey/unknown_type1647=== PAUSE TestIsValidUploadKey/unknown_type1648=== CONT TestReconnectLeavesObjectsUnlocked16492026/10/01 09:58:01 INFO Received create pin request method=POST path=/api/pins/deploy16502026/10/01 09:58:01 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YzIwZDlkYzAtYmY4OS00YzFlLWEwZjktZjY1ZjAzMmUyZGEzLjY2NzM2ODg5LTMwOTYtNGFkYy1hYWJmLThiZWI3MTkzMTBiNXgxNzkwODQ4NjgwNjAwMjE2OTQy parts=1216512026/10/01 09:58:01 INFO Received uploads request method=POST path=/api/pending_closures16522026/10/01 09:58:01 INFO Received uploads request method=POST path=/api/pending_closures16532026/10/01 09:58:01 INFO Aborted multipart uploads count=0 kept=016542026/10/01 09:58:01 WARN Force mode enabled - objects will be deleted immediately without grace period16552026/10/01 09:58:01 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=01656=== CONT TestOrphanedObjectsGCStressTest1657--- PASS: TestGetExistingObjectsLocksRows (0.32s)16582026/10/01 09:58:01 INFO Vacuumed table table=pending_closures16592026/10/01 09:58:01 INFO Vacuumed table table=pending_objects16602026/10/01 09:58:01 INFO Vacuumed table table=multipart_uploads16612026/10/01 09:58:01 INFO Vacuumed table table=closures16622026/10/01 09:58:01 INFO Vacuumed table table=objects16632026/10/01 09:58:01 INFO Received uploads request method=POST path=/api/pending_closures1664--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.38s)1665=== CONT TestObjectStatsTrigger16662026/10/01 09:58:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1667--- PASS: TestReadProxyDisabled (0.25s)1668=== CONT TestGCMetrics16692026/10/01 09:58:01 INFO Starting HTTP server address=127.0.0.1:3711316702026/10/01 09:58:01 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket730205019/001/proxy.sock16712026/10/01 09:58:01 WARN mTLS auth: subject not in bound subjects subject="CN=someone"16722026/10/01 09:58:01 INFO Shutdown signal received, draining in-flight requests timeout=10s1673--- PASS: TestReadRedirectUsesPublicS3URL (0.47s)1674=== CONT TestConcurrentPinUpdatesAgree16752026/10/01 09:58:01 INFO Received uploads request method=POST path=/api/pending_closures1676=== CONT TestPendingClosureFailureAbortsItsUploads1677--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.23s)16782026/10/01 09:58:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1679=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1680=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1681=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1682=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1683=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1684=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1685=== CONT TestOrphanedObjectsGC16862026/10/01 09:58:01 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=YzIwZDlkYzAtYmY4OS00YzFlLWEwZjktZjY1ZjAzMmUyZGEzLjMzZmRkZjNlLThkYTYtNDY0NC1iNTA2LTA1ZGMxNWI3ODZkM3gxNzkwODQ4NjgwOTA0Njc2OTkw parts=101687--- PASS: TestConnectSerialisesConcurrentMigrations (1.15s)1688=== CONT TestCreatePin_ReservedPins16892026/10/01 09:58:01 INFO lead: released remote=192.0.2.1:12341690--- PASS: TestReadRedirectKeepsNarinfoProxied (0.52s)1691=== CONT TestValidateS3Concurrency1692--- PASS: TestValidateS3Concurrency (0.00s)1693=== CONT TestService_NativeMTLS1694--- PASS: TestLeadEndsOnShutdown (1.37s)1695=== CONT TestPushWaitsForSweepHoldingRow1696--- PASS: TestReconnectLeavesObjectsUnlocked (0.26s)1697=== CONT TestDeduplicatedObjectsRecordedAsPending16982026/10/01 09:58:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40893/oidc1699=== CONT TestPushDedupSurvivesConcurrentGC1700--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.48s)17012026/10/01 09:58:01 INFO Received create pin request method=POST path=/api/pins/app17022026/10/01 09:58:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17032026/10/01 09:58:01 INFO Received create pin request method=POST path=/api/pins/app1704=== CONT TestTombstonedObjectOfferedWithoutWaiting1705--- PASS: TestObjectStatsTrigger (0.24s)17062026/10/01 09:58:01 INFO Aborted multipart uploads count=0 kept=017072026/10/01 09:58:01 WARN Force mode enabled - objects will be deleted immediately without grace period17082026/10/01 09:58:01 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=YzIwZDlkYzAtYmY4OS00YzFlLWEwZjktZjY1ZjAzMmUyZGEzLmVmMDQyMzBlLTE0MmMtNDlkMi04NDI2LWUwN2Y3M2EwZmNkMHgxNzkwODQ4NjgxMDk5NDU3OTQy parts=1017092026/10/01 09:58:01 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=017102026/10/01 09:58:01 INFO Vacuumed table table=pending_closures17112026/10/01 09:58:01 INFO Vacuumed table table=pending_objects17122026/10/01 09:58:01 INFO Received uploads request method=POST path=/api/pending_closures17132026/10/01 09:58:01 INFO Vacuumed table table=multipart_uploads17142026/10/01 09:58:01 INFO Vacuumed table table=closures17152026/10/01 09:58:01 INFO Vacuumed table table=objects17162026/10/01 09:58:01 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"1717--- PASS: TestGCMetrics (0.29s)1718=== CONT TestPendingCleanupUsesOneCutoff1719--- PASS: TestPendingClosureFailureAbortsItsUploads (0.26s)1720=== CONT TestMultipartCleanup17212026/10/01 09:58:01 INFO Received uploads request method=POST path=/api/pending_closures17222026/10/01 09:58:01 WARN mTLS auth: subject not in bound subjects subject="CN=reader"17232026/10/01 09:58:01 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1724--- PASS: TestService_NativeMTLS (0.21s)1725=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded17262026/10/01 09:58:01 INFO Received uploads request method=POST path=/api/pending_closures1727=== CONT TestGCBugBareHashReferences1728--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.23s)17292026/10/01 09:58:01 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux17302026/10/01 09:58:01 WARN Refused reserved pin name=worker-x86_64-linux17312026/10/01 09:58:01 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux17322026/10/01 09:58:01 INFO Received create pin request method=POST path=/api/pins/my-app17332026/10/01 09:58:01 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1734--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.78s)1735=== CONT TestServerTLSConfig1736=== RUN TestServerTLSConfig/no_client_CA1737=== PAUSE TestServerTLSConfig/no_client_CA1738=== RUN TestServerTLSConfig/missing_CA_file1739=== PAUSE TestServerTLSConfig/missing_CA_file1740=== RUN TestServerTLSConfig/not_a_PEM_file1741=== PAUSE TestServerTLSConfig/not_a_PEM_file1742=== CONT TestGenerateLandingPage1743--- PASS: TestGenerateLandingPage (0.01s)1744=== CONT TestNARDeduplicationMetadataUploadBug1745--- PASS: TestCreatePin_ReservedPins (0.30s)1746=== CONT TestResolveDBConnectionString/flag_wins1747=== CONT TestResolveDBConnectionString/nothing_configured1748=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1749=== CONT TestResolveDBConnectionString/missing_file_is_an_error1750=== CONT TestResolveDBConnectionString/file_when_flag_empty1751=== CONT TestParseSingleRange/start_past_EOF1752=== CONT TestParseSingleRange/suffix_exceeds_size1753=== CONT TestParseSingleRange/malformed_no_dash1754=== CONT TestParseSingleRange/malformed_both_empty1755--- PASS: TestResolveDBConnectionString (0.00s)1756 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1757 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1758 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1759 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1760 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1761=== CONT TestParseSingleRange/none1762=== CONT TestParseSingleRange/suffix1763=== CONT TestParseSingleRange/closed1764=== CONT TestParseSingleRange/start_far_past_EOF1765=== CONT TestParseSingleRange/single_byte1766=== CONT TestParseSingleRange/unknown_unit1767=== CONT TestParseSingleRange/multi-range_ignored1768=== CONT TestParseSingleRange/malformed_end_before_start1769=== CONT TestParseSingleRange/end_clamped_to_size1770=== CONT TestParseSingleRange/open-ended1771=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1772--- PASS: TestParseSingleRange (0.01s)1773 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1774 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1775 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1776 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1777 --- PASS: TestParseSingleRange/none (0.00s)1778 --- PASS: TestParseSingleRange/suffix (0.00s)1779 --- PASS: TestParseSingleRange/closed (0.00s)1780 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1781 --- PASS: TestParseSingleRange/single_byte (0.00s)1782 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1783 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1784 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1785 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1786 --- PASS: TestParseSingleRange/open-ended (0.00s)17872026/10/01 09:58:01 INFO Received uploads request method=POST path=/api/pending_closures17882026/10/01 09:58:01 INFO Received uploads request method=POST path=/api/pending_closures1789=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1790--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.23s)17912026/10/01 09:58:01 INFO Received uploads request method=POST path=/api/pending_closures17922026/10/01 09:58:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17932026/10/01 09:58:01 INFO Received uploads request method=POST path=/api/pending_closures17942026/10/01 09:58:01 INFO Received uploads request method=POST path=/api/pending_closures17952026/10/01 09:58:01 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YzIwZDlkYzAtYmY4OS00YzFlLWEwZjktZjY1ZjAzMmUyZGEzLjQ3OTQ4ZDg5LWI2NzItNDE1Mi1iMmU2LWVkNTYwOGMzYTQxZHgxNzkwODQ4NjgxMjg0MjUzMTA1 error="Get \"http://127.0.0.1:1/bucket38/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"17962026/10/01 09:58:01 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YzIwZDlkYzAtYmY4OS00YzFlLWEwZjktZjY1ZjAzMmUyZGEzLmRlNjU3ZWM2LWNhMDctNDQyYS1hNTY3LWViZWVhMmI0ODQwM3gxNzkwODQ4NjgxMjcwMDA2OTM5 parts=1217972026/10/01 09:58:01 INFO Aborted multipart uploads count=0 kept=017982026/10/01 09:58:01 INFO Received cleanup request method=DELETE path=/api/pending_closures17992026/10/01 09:58:01 INFO Received cleanup request method=DELETE path=/api/pending_closures18002026/10/01 09:58:01 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=018012026/10/01 09:58:01 INFO Aborted multipart uploads count=1 kept=018022026/10/01 09:58:01 INFO Vacuumed table table=pending_closures18032026/10/01 09:58:01 INFO Received uploads request method=POST path=/api/pending_closures18042026/10/01 09:58:01 INFO Vacuumed table table=pending_objects18052026/10/01 09:58:01 INFO Vacuumed table table=multipart_uploads18062026/10/01 09:58:01 INFO Vacuumed table table=closures18072026/10/01 09:58:01 INFO Vacuumed table table=objects18082026/10/01 09:58:01 INFO Aborted multipart uploads count=0 kept=018092026/10/01 09:58:01 WARN Force mode enabled - objects will be deleted immediately without grace period18102026/10/01 09:58:01 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=018112026/10/01 09:58:01 INFO Vacuumed table table=pending_closures18122026/10/01 09:58:01 INFO Vacuumed table table=pending_objects18132026/10/01 09:58:01 INFO Vacuumed table table=multipart_uploads18142026/10/01 09:58:01 INFO Vacuumed table table=closures18152026/10/01 09:58:01 INFO Vacuumed table table=objects18162026/10/01 09:58:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1817=== CONT TestPendingClosureWriteTimeout/empty1818--- PASS: TestRedundantMultipartUpload (1.51s)1819=== CONT TestPendingClosureWriteTimeout/400_objects1820=== CONT TestPendingClosureWriteTimeout/670k_objects1821=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1822--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.21s)1823=== CONT TestPendingClosureWriteTimeout/negative1824=== CONT TestClientErrorHandling/InvalidStorePath18252026/10/01 09:58:01 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=YzIwZDlkYzAtYmY4OS00YzFlLWEwZjktZjY1ZjAzMmUyZGEzLjliN2M4Yjg1LWU0MmMtNDkyMC1hMDAyLWVmMDhlZjkwZTQ2ZXgxNzkwODQ4NjgwOTA1NDYwNjU3 parts=101826--- PASS: TestPushDedupSurvivesConcurrentGC (0.37s)1827=== CONT TestClientErrorHandling/ServerNotAvailable18282026/10/01 09:58:01 INFO Received complete push request method=POST path=/api/pushes/1/complete18292026/10/01 09:58:01 INFO Received push request method=POST path=/api/pushes18302026/10/01 09:58:01 INFO Received uploads request method=POST path=/api/pending_closures1831=== NAME TestOrphanedObjectsGC1832 orphaned_objects_gc_test.go:290: GC Test Summary:1833 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1834 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1835 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1836 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1837 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects18382026/10/01 09:58:01 INFO Aborted multipart uploads count=0 kept=018392026/10/01 09:58:01 WARN Force mode enabled - objects will be deleted immediately without grace period1840=== NAME TestNARDeduplicationMetadataUploadBug1841 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1806193313/001/store/s0bwm4wfqics20hfs1pswfljn229m1bl-file1.txt18422026/10/01 09:58:01 INFO Received uploads request method=POST path=/api/pending_closures1843--- PASS: TestOrphanedObjectsGC (0.53s)1844=== CONT TestClientErrorHandling/InvalidAuthToken1845--- PASS: TestPendingClosureFailureTracksEveryUpload (0.80s)1846=== CONT TestCacheConfigHandler/full_config,_no_issuer18472026/10/01 09:58:01 INFO Received cleanup request method=DELETE path=/api/pending_closures1848=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1849=== CONT TestCacheConfigHandler/no_signing_keys1850=== CONT TestCacheConfigHandler/no_cache_url_configured1851=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1852--- PASS: TestCacheConfigHandler (0.00s)1853 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1854 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1855 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1856 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)18572026/10/01 09:58:01 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket86/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""18582026/10/01 09:58:01 INFO Aborted multipart uploads count=0 kept=118592026/10/01 09:58:01 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=018602026/10/01 09:58:01 INFO Vacuumed table table=pending_closures18612026/10/01 09:58:01 INFO Vacuumed table table=pending_objects18622026/10/01 09:58:01 INFO Vacuumed table table=multipart_uploads18632026/10/01 09:58:01 INFO Vacuumed table table=closures18642026/10/01 09:58:01 INFO Aborted multipart uploads count=0 kept=018652026/10/01 09:58:01 INFO Vacuumed table table=objects18662026/10/01 09:58:01 WARN Authentication failed token_preview=eyJhbGciOi...30VskE2tdQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1867=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18682026/10/01 09:58:01 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]1869=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token18702026/10/01 09:58:01 INFO Received cleanup request method=DELETE path=/api/pending_closures18712026/10/01 09:58:01 WARN Force mode enabled - objects will be deleted immediately without grace period18722026/10/01 09:58:01 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/present18732026/10/01 09:58:01 INFO Aborted multipart uploads count=1 kept=018742026/10/01 09:58:01 INFO Aborted multipart uploads count=0 kept=01875=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1876=== CONT TestPush_RejectsBadRequests/no_roots18772026/10/01 09:58:01 INFO Received push request method=POST path=/api/pushes1878=== CONT TestPush_RejectsBadRequests/root_not_in_objects18792026/10/01 09:58:01 INFO Received push request method=POST path=/api/pushes1880=== CONT TestPush_RejectsBadRequests/bad_root18812026/10/01 09:58:01 INFO Received push request method=POST path=/api/pushes18822026/10/01 09:58:01 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=01883=== CONT TestPush_RejectsBadRequests/no_objects18842026/10/01 09:58:01 INFO Received push request method=POST path=/api/pushes1885=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete18862026/10/01 09:58:02 INFO Vacuumed table table=pending_closures18872026/10/01 09:58:02 WARN Force mode enabled - objects will be deleted immediately without grace period18882026/10/01 09:58:02 INFO Vacuumed table table=pending_objects18892026/10/01 09:58:02 INFO Vacuumed table table=multipart_uploads18902026/10/01 09:58:02 INFO Vacuumed table table=closures18912026/10/01 09:58:02 INFO Vacuumed table table=objects1892=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1893--- PASS: TestMultipartCleanup (0.41s)1894--- PASS: TestService_AuthMiddleware_OIDC (0.61s)1895 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)1896 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1897 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1898 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1899--- PASS: TestPush_RejectsBadRequests (0.30s)1900 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1901 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1902 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1903 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)19042026/10/01 09:58:02 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=019052026/10/01 09:58:02 INFO Vacuumed table table=pending_closures19062026/10/01 09:58:02 INFO Vacuumed table table=pending_objects19072026/10/01 09:58:02 INFO Vacuumed table table=multipart_uploads19082026/10/01 09:58:02 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=1677721619092026/10/01 09:58:02 INFO Vacuumed table table=closures1910=== CONT TestGCEndsOnShutdown/before_the_run1911=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1912--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1913 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.30s)1914 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.27s)19152026/10/01 09:58:02 INFO Received complete multipart upload request method=POST path=/1916=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19172026/10/01 09:58:02 INFO Received request for more parts method=POST path=/1918=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19192026/10/01 09:58:02 INFO Received uploads request method=POST path=/19202026/10/01 09:58:02 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo1921=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19222026/10/01 09:58:02 INFO Received uploads request method=POST path=/1923=== CONT TestIsValidCachePath/narinfo1924--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1925 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1926 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1927 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1928 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1929=== CONT TestIsValidCachePath/traversal_parent19302026/10/01 09:58:02 INFO Vacuumed table table=objects1931=== CONT TestIsValidCachePath/realisation1932=== CONT TestIsValidCachePath/ls1933=== CONT TestIsValidCachePath/nix-cache-info1934=== CONT TestIsValidCachePath/nar_bz21935=== CONT TestIsValidCachePath/nar_uncompressed1936=== CONT TestIsValidCachePath/short_hash1937=== CONT TestIsValidCachePath/empty1938=== CONT TestIsValidCachePath/traversal_in_middle1939=== CONT TestIsValidCachePath/random_path1940=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1941=== CONT TestIsValidCachePath/leading_slash1942=== CONT TestIsValidCachePath/index.html1943=== CONT TestIsValidCachePath/invalid_char_e1944=== CONT TestIsValidCachePath/nar_zst1945=== CONT TestIsValidCachePath/nar_xz1946=== CONT TestIsValidCachePath/invalid_char_u1947=== CONT TestIsValidCachePath/wrong_extension1948=== CONT TestIsValidCachePath/log1949=== CONT TestProxyWriteTimeout/narinfo1950--- PASS: TestIsValidCachePath (0.00s)1951 --- PASS: TestIsValidCachePath/narinfo (0.00s)1952 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1953 --- PASS: TestIsValidCachePath/realisation (0.00s)1954 --- PASS: TestIsValidCachePath/ls (0.00s)1955 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1956 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1957 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1958 --- PASS: TestIsValidCachePath/short_hash (0.00s)1959 --- PASS: TestIsValidCachePath/empty (0.00s)1960 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1961 --- PASS: TestIsValidCachePath/random_path (0.00s)1962 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1963 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1964 --- PASS: TestIsValidCachePath/index.html (0.00s)1965 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1966 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1967 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1968 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1969 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1970 --- PASS: TestIsValidCachePath/log (0.00s)1971=== CONT TestProxyWriteTimeout/1_GiB_nar1972=== CONT TestProxyWriteTimeout/10_GiB_nar1973=== CONT TestProxyWriteTimeout/unknown_size1974=== CONT TestService_RequireScope_OIDC/builder_may_write1975--- PASS: TestProxyWriteTimeout (0.00s)1976 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1977 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1978 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1979 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)19802026/10/01 09:58:02 INFO Received push request method=POST path=/api/pushes1981=== CONT TestService_RequireScope_OIDC/static_token_may_admin1982=== CONT TestService_RequireScope_OIDC/writer_implies_read1983=== CONT TestService_RequireScope_OIDC/reader_may_not_write1984=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1985=== CONT TestService_RequireScope_OIDC/ops_may_admin1986=== CONT TestService_RequireScope_OIDC/reader_may_read19872026/10/01 09:58:02 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo1988=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1989=== CONT TestService_RequireScope_OIDC/static_token_may_write1990=== CONT TestService_RequireScope_OIDC/ops_may_not_write1991=== CONT TestIsValidUploadKey/narinfo1992=== CONT TestIsValidUploadKey/unknown_type19932026/10/01 09:58:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1994=== CONT TestIsValidUploadKey/empty_key19952026/10/01 09:58:02 INFO Uploading s0bwm4wfqics20hfs1pswfljn229m1bl-file1.txt (160B)1996=== CONT TestIsValidUploadKey/absolute1997=== CONT TestIsValidUploadKey/build_log_equals1998=== CONT TestIsValidUploadKey/listing1999=== CONT TestIsValidUploadKey/traversal_nar2000=== CONT TestIsValidUploadKey/build_log_question_mark2001=== CONT TestIsValidUploadKey/traversal2002=== CONT TestIsValidUploadKey/realisation2003=== CONT TestIsValidUploadKey/build_log_home-manager_file2004=== CONT TestIsValidUploadKey/build_log_plus_in_name2005=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2006=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2007=== CONT TestIsValidUploadKey/nar_xz2008=== CONT TestIsValidUploadKey/nar_zst2009=== CONT TestIsValidUploadKey/realisation_plus_in_output2010=== CONT TestIsValidUploadKey/nar_plain2011=== CONT TestIsValidUploadKey/index.html2012=== CONT TestIsValidUploadKey/build_log2013=== CONT TestIsValidUploadKey/nix-cache-info2014=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2015=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart2016--- PASS: TestIsValidUploadKey (0.00s)2017 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2018 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2019 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2020 --- PASS: TestIsValidUploadKey/absolute (0.00s)2021 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2022 --- PASS: TestIsValidUploadKey/listing (0.00s)2023 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2024 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2025 --- PASS: TestIsValidUploadKey/traversal (0.00s)2026 --- PASS: TestIsValidUploadKey/realisation (0.00s)2027 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2028 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2029 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2030 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2031 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2032 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2033 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2034 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2035 --- PASS: TestIsValidUploadKey/index.html (0.00s)2036 --- PASS: TestIsValidUploadKey/build_log (0.00s)2037 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2038 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)20392026/10/01 09:58:02 INFO Received complete multipart upload request method=POST path=/2040--- PASS: TestReadProxyNarinfo (1.28s)2041=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts20422026/10/01 09:58:02 INFO Received request for more parts method=POST path=/20432026/10/01 09:58:02 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=217.947869ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20442026/10/01 09:58:02 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"2045--- PASS: TestConcurrentPinUpdatesAgree (0.73s)2046=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure20472026/10/01 09:58:02 INFO Received uploads request method=POST path=/20482026/10/01 09:58:02 WARN Failed to register uploaded object key=s0bwm4wfqics20hfs1pswfljn229m1bl.ls error="server returned 404: 404 page not found\n"20492026/10/01 09:58:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign2050--- PASS: TestService_RequireScope_OIDC (0.92s)2051 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2052 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2053 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2054 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2055 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2056 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2057 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2058 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2059 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2060 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)20612026/10/01 09:58:02 INFO lead: released remote=192.0.2.1:123420622026/10/01 09:58:02 INFO Signed narinfos id=1 count=120632026/10/01 09:58:02 INFO Uploading 1 narinfos20642026/10/01 09:58:02 INFO Received uploads request method=POST path=/api/pending_closures20652026/10/01 09:58:02 INFO Received complete push request method=POST path=/api/pushes/1/complete20662026/10/01 09:58:02 WARN Failed to register uploaded object key=s0bwm4wfqics20hfs1pswfljn229m1bl.narinfo error="server returned 404: 404 page not found\n"20672026/10/01 09:58:02 INFO Upload complete. (83ms)2068=== NAME TestNARDeduplicationMetadataUploadBug2069 metadata_upload_test.go:54: Retrieved narinfo from S3:2070 StorePath: /build/TestNARDeduplicationMetadataUploadBug1806193313/001/store/s0bwm4wfqics20hfs1pswfljn229m1bl-file1.txt2071 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2072 Compression: zstd2073 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2074 NarSize: 1602075 References: 2076 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2077=== CONT TestServerTLSConfig/not_a_PEM_file2078--- PASS: TestLeadElectsOneAndHandsOver (2.71s)2079=== CONT TestServerTLSConfig/missing_CA_file2080=== CONT TestServerTLSConfig/no_client_CA2081--- PASS: TestServerTLSConfig (0.00s)2082 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2083 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2084 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)20852026/10/01 09:58:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2086=== NAME TestNARDeduplicationMetadataUploadBug2087 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2088 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2089 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}20902026/10/01 09:58:02 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=YzIwZDlkYzAtYmY4OS00YzFlLWEwZjktZjY1ZjAzMmUyZGEzLjNiNDQ5OGQwLWJlYTYtNGFhOS1iYzUxLWRlODM3NzMwNGY4OXgxNzkwODQ4NjgxMTAwMDQxMzI3 parts=102091 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1806193313/001/store/fx0k9r4ba9fyg7lli0y0zxxxy1ysapy2-file2.txt2092--- PASS: TestGCBugBareHashReferences (0.44s)20932026/10/01 09:58:02 INFO Aborted multipart uploads count=0 kept=020942026/10/01 09:58:02 WARN Force mode enabled - objects will be deleted immediately without grace period2095--- PASS: TestPushWaitsForSweepHoldingRow (0.70s)20962026/10/01 09:58:02 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:37323/bucket95/?delete=\": context canceled"20972026/10/01 09:58:02 INFO Aborted multipart uploads count=0 kept=020982026/10/01 09:58:02 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20992026/10/01 09:58:02 WARN Force mode enabled - objects will be deleted immediately without grace period21002026/10/01 09:58:02 INFO Received push request method=POST path=/api/pushes21012026-10-01 09:58:02.234 UTC [2051] ERROR: canceling statement due to user request21022026-10-01 09:58:02.234 UTC [2051] CONTEXT: PL/pgSQL function object_stats_apply() line 5 at statement block21032026-10-01 09:58:02.234 UTC [2051] STATEMENT: -- name: MarkStaleObjects :execrows2104 WITH RECURSIVE ct AS (2105 SELECT timezone('UTC', now()) AS now2106 ),2107 closure_reach AS (2108 -- Start with all closure keys2109 SELECT o.key, o.refs2110 FROM objects o2111 INNER JOIN closures c ON o.key = c.key2112 UNION2113 -- Recursively add all referenced objects2114 SELECT o.key, o.refs2115 FROM objects o2116 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2117 ),2118 reachable_objects AS (2119 SELECT DISTINCT key FROM closure_reach2120 ),2121 stale_objects AS (2122 SELECT o.key2123 FROM objects AS o, ct2124 WHERE2125 NOT EXISTS (2126 SELECT 12127 FROM reachable_objects ro2128 WHERE ro.key = o.key2129 )2130 AND NOT EXISTS (2131 SELECT 12132 FROM pending_objects AS po2133 WHERE po.key = o.key2134 )2135 AND o.deleted_at IS NULL -- Only mark fresh objects2136 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2137 FOR UPDATE2138 )2139 UPDATE objects2140 SET2141 deleted_at = ct.now,2142 first_deleted_at = COALESCE(first_deleted_at, ct.now)2143 FROM stale_objects, ct2144 WHERE objects.key = stale_objects.key2145 21462026/10/01 09:58:02 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21472026/10/01 09:58:02 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021482026/10/01 09:58:02 INFO Received create pin request method=POST path=/api/pins/myapp21492026/10/01 09:58:02 INFO Received create pin request method=POST path=/api/pins/deploy21502026/10/01 09:58:02 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign21512026/10/01 09:58:02 WARN Failed to register uploaded object key=fx0k9r4ba9fyg7lli0y0zxxxy1ysapy2.ls error="server returned 404: 404 page not found\n"21522026/10/01 09:58:02 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC4056775227/001/store/1p21kvc86mryzkddg0xp72ngz55hn7mx-pinned-file.txt narinfo_key=1p21kvc86mryzkddg0xp72ngz55hn7mx.narinfo21532026/10/01 09:58:02 INFO Signed narinfos id=2 count=121542026/10/01 09:58:02 INFO Uploading 1 narinfos21552026/10/01 09:58:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures21562026/10/01 09:58:02 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo21572026/10/01 09:58:02 INFO Garbage collection started21582026/10/01 09:58:02 INFO Aborted multipart uploads count=0 kept=021592026/10/01 09:58:02 INFO Received complete push request method=POST path=/api/pushes/2/complete21602026/10/01 09:58:02 WARN Failed to register uploaded object key=fx0k9r4ba9fyg7lli0y0zxxxy1ysapy2.narinfo error="server returned 404: 404 page not found\n"21612026/10/01 09:58:02 INFO Upload complete. (65ms)21622026/10/01 09:58:02 WARN Force mode enabled - objects will be deleted immediately without grace period21632026/10/01 09:58:02 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=021642026/10/01 09:58:02 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21652026/10/01 09:58:02 INFO Vacuumed table table=pending_closures21662026/10/01 09:58:02 INFO Vacuumed table table=pending_objects21672026/10/01 09:58:02 INFO Vacuumed table table=multipart_uploads21682026/10/01 09:58:02 INFO Vacuumed table table=closures2169=== NAME TestNARDeduplicationMetadataUploadBug2170 metadata_upload_test.go:76: Retrieved narinfo from S3:2171 StorePath: /build/TestNARDeduplicationMetadataUploadBug1806193313/001/store/fx0k9r4ba9fyg7lli0y0zxxxy1ysapy2-file2.txt2172 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2173 Compression: zstd2174 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2175 NarSize: 1602176 References: 2177 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf21782026/10/01 09:58:02 INFO Vacuumed table table=objects2179--- PASS: TestCreatePinRejectsBadInput (1.33s)2180=== NAME TestNARDeduplicationMetadataUploadBug2181 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2182 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2183 {"version":1,"root":{"type":"regular","size":44}}2184--- PASS: TestGCEndsOnShutdown (0.00s)2185 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.22s)2186 --- PASS: TestGCEndsOnShutdown/before_the_run (0.20s)2187 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.22s)2188--- PASS: TestNARDeduplicationMetadataUploadBug (0.53s)21892026/10/01 09:58:02 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=372.733336ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21902026/10/01 09:58:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21912026/10/01 09:58:02 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=YzIwZDlkYzAtYmY4OS00YzFlLWEwZjktZjY1ZjAzMmUyZGEzLjE4ZWM4Y2ZmLWQ1NWItNDM4Yi1iY2RjLWRiMGY5MWI1ZGQyZngxNzkwODQ4NjgxOTM1Nzk3NTM5 parts=1021922026/10/01 09:58:02 INFO Received complete push request method=POST path=/api/pushes/2/complete21932026/10/01 09:58:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2194--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (1.90s)21952026/10/01 09:58:02 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=YzIwZDlkYzAtYmY4OS00YzFlLWEwZjktZjY1ZjAzMmUyZGEzLmVlZTUxYjg0LTVmZTUtNDA5OS05OWRjLWM3YmMyZDgzM2QzNngxNzkwODQ4NjgxMDk4NTA4NTUz parts=1021962026/10/01 09:58:02 INFO Received complete push request method=POST path=/api/pushes/1/complete2197--- PASS: TestPush_CompleteCommitsEveryRoot (1.79s)21982026/10/01 09:58:02 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=786.727686ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2199=== NAME TestOrphanedObjectsGCStressTest2200 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2201 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion2202--- PASS: TestPendingClosureWriteTimeout (0.00s)2203 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2204 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2205 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2206 --- PASS: TestPendingClosureWriteTimeout/negative (0.00s)2207 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.02s)22082026/10/01 09:58:03 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.20s)2213=== NAME TestOrphanedObjectsGCStressTest2214 orphaned_objects_gc_test.go:509: Stress test completed successfully:2215 orphaned_objects_gc_test.go:510: - Active objects preserved: 202216 orphaned_objects_gc_test.go:511: - Objects deleted: 2102217 orphaned_objects_gc_test.go:512: - Total GC'd: 2102218--- PASS: TestOrphanedObjectsGCStressTest (1.84s)22192026/10/01 09:58:03 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.749127624s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2220=== NAME TestPinProtectsFromGC2221 client_integration_test.go:976: Pin successfully protected closure from garbage collection2222--- PASS: TestPinProtectsFromGC (4.86s)2223--- PASS: TestConnectWaitsForAPeerMigration (5.41s)2224--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.56s)22252026/10/01 09:58:05 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-config22262026/10/01 09:58:05 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=203.560007ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22272026/10/01 09:58:05 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=436.588142ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22282026/10/01 09:58:05 WARN Rate limiter enabled after throttle name=s3-test rate=522292026/10/01 09:58:05 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2230=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2231 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102232 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002233--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.88s)22342026/10/01 09:58:06 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=785.666717ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22352026/10/01 09:58:06 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.625438295s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22362026/10/01 09:58:07 INFO Aborted multipart uploads count=1 kept=022372026/10/01 09:58:07 INFO Received cleanup request method=DELETE path=/api/pending_closures22382026/10/01 09:58:07 INFO Aborted multipart uploads count=1 kept=02239--- PASS: TestPendingCleanupUsesOneCutoff (6.26s)22402026/10/01 09:58:08 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"22412026/10/01 09:58:08 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-config22422026/10/01 09:58:08 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=219.938053ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22432026/10/01 09:58:08 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=437.217654ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22442026/10/01 09:58:09 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=794.362143ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22452026/10/01 09:58:09 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.688122075s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22462026/10/01 09:58:11 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_closures22472026/10/01 09:58:11 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=200.38311ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22482026/10/01 09:58:11 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=411.905592ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22492026/10/01 09:58:12 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=775.719439ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22502026/10/01 09:58:13 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.520568323s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2251--- PASS: TestClientErrorHandling (0.00s)2252 --- PASS: TestClientErrorHandling/InvalidStorePath (0.27s)2253 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.31s)2254 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.78s)2255--- PASS: TestUploadHandlersRejectOversizedBody (0.57s)2256 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.82s)2257 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.82s)2258 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (14.57s)2259PASS2260{"timestamp":"2026-10-01T09:58:16.679053623Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:47004","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)"}2261{"timestamp":"2026-10-01T09:58:16.679392606Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:46536","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(203)"}2262{"timestamp":"2026-10-01T09:58:16.679483447Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:47108","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(200)"}2263{"timestamp":"2026-10-01T09:58:16.679528888Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:46856","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(196)"}2264{"timestamp":"2026-10-01T09:58:16.679625909Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:46320","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(205)"}22652026-10-01 09:58:16.936 UTC [171] LOG: received smart shutdown request22662026-10-01 09:58:16.941 UTC [171] LOG: background worker "logical replication launcher" (PID 181) exited with exit code 122672026-10-01 09:58:16.954 UTC [176] LOG: shutting down22682026-10-01 09:58:16.955 UTC [176] LOG: checkpoint starting: shutdown immediate22692026-10-01 09:58:17.487 UTC [176] LOG: checkpoint complete: wrote 10220 buffers (62.4%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 28 recycled; write=0.176 s, sync=0.332 s, total=0.533 s; sync files=33361, longest=0.004 s, average=0.001 s; distance=467094 kB, estimate=467094 kB; lsn=0/1DF8B6A8, redo lsn=0/1DF8B6A822702026-10-01 09:58:17.562 UTC [171] LOG: database system is shut down2271Running OIDC tests...2272=== RUN TestAudienceForIssuer2273=== PAUSE TestAudienceForIssuer2274=== RUN TestHTTPClientForHasTimeouts2275=== PAUSE TestHTTPClientForHasTimeouts2276=== RUN TestGlobMatch2277=== PAUSE TestGlobMatch2278=== RUN TestValidateToken_ValidToken2279=== PAUSE TestValidateToken_ValidToken2280=== RUN TestValidateToken_WrongAudience2281=== PAUSE TestValidateToken_WrongAudience2282=== RUN TestValidateToken_Expired2283=== PAUSE TestValidateToken_Expired2284=== RUN TestValidateToken_BoundClaimsMismatch2285=== PAUSE TestValidateToken_BoundClaimsMismatch2286=== RUN TestValidateToken_BoundSubjectMismatch2287=== PAUSE TestValidateToken_BoundSubjectMismatch2288=== RUN TestValidateToken_MultipleProviders2289=== PAUSE TestValidateToken_MultipleProviders2290=== RUN TestValidateToken_NoMatchingProvider2291=== PAUSE TestValidateToken_NoMatchingProvider2292=== RUN TestValidateToken_KubernetesServiceAccount2293=== PAUSE TestValidateToken_KubernetesServiceAccount2294=== RUN TestNewValidator_KubernetesRequiresCA2295=== PAUSE TestNewValidator_KubernetesRequiresCA2296=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2297=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2298=== RUN TestPins_ReservedForMatchingRule2299=== PAUSE TestPins_ReservedForMatchingRule2300=== RUN TestPins_TopLevelShorthand2301=== PAUSE TestPins_TopLevelShorthand2302=== RUN TestPins_ConfigValidation2303=== PAUSE TestPins_ConfigValidation2304=== RUN TestScopes_LegacyProviderDefaultsToWrite2305=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2306=== RUN TestScopes_Rules2307=== PAUSE TestScopes_Rules2308=== RUN TestScopes_ConfigValidation2309=== PAUSE TestScopes_ConfigValidation2310=== CONT TestValidateToken_BoundClaimsMismatch2311=== CONT TestValidateToken_WrongAudience2312=== CONT TestValidateToken_NoMatchingProvider2313=== CONT TestGlobMatch2314=== CONT TestPins_ConfigValidation2315=== CONT TestPins_TopLevelShorthand2316=== CONT TestPins_ReservedForMatchingRule2317=== CONT TestScopes_ConfigValidation2318=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2319=== CONT TestScopes_LegacyProviderDefaultsToWrite2320=== CONT TestValidateToken_KubernetesServiceAccount2321=== CONT TestScopes_Rules2322=== CONT TestHTTPClientForHasTimeouts2323=== CONT TestAudienceForIssuer2324--- PASS: TestAudienceForIssuer (0.00s)2325=== CONT TestValidateToken_BoundSubjectMismatch2326=== CONT TestNewValidator_KubernetesRequiresCA2327=== CONT TestValidateToken_ValidToken2328=== CONT TestValidateToken_MultipleProviders2329=== CONT TestValidateToken_Expired2330=== RUN TestGlobMatch/foo_foo2331--- PASS: TestPins_ConfigValidation (0.00s)2332=== PAUSE TestGlobMatch/foo_foo2333--- PASS: TestScopes_ConfigValidation (0.00s)2334=== RUN TestGlobMatch/foo_bar2335=== PAUSE TestGlobMatch/foo_bar2336=== RUN TestGlobMatch/*_2337=== PAUSE TestGlobMatch/*_2338=== RUN TestGlobMatch/*_anything2339=== PAUSE TestGlobMatch/*_anything2340=== RUN TestGlobMatch/foo*_foo2341=== PAUSE TestGlobMatch/foo*_foo2342=== RUN TestGlobMatch/foo*_foobar2343=== PAUSE TestGlobMatch/foo*_foobar2344=== RUN TestGlobMatch/foo*_bar2345=== PAUSE TestGlobMatch/foo*_bar2346=== RUN TestGlobMatch/*bar_bar2347=== PAUSE TestGlobMatch/*bar_bar2348=== RUN TestGlobMatch/*bar_foobar2349=== PAUSE TestGlobMatch/*bar_foobar2350=== RUN TestGlobMatch/*bar_foo2351=== PAUSE TestGlobMatch/*bar_foo2352=== RUN TestGlobMatch/foo*bar_foobar2353=== PAUSE TestGlobMatch/foo*bar_foobar2354=== RUN TestGlobMatch/foo*bar_foo123bar2355=== PAUSE TestGlobMatch/foo*bar_foo123bar2356=== RUN TestGlobMatch/foo*bar_foobarbaz2357=== PAUSE TestGlobMatch/foo*bar_foobarbaz2358=== RUN TestGlobMatch/*/*_foo/bar2359=== PAUSE TestGlobMatch/*/*_foo/bar2360=== RUN TestGlobMatch/*/*_foo2361=== PAUSE TestGlobMatch/*/*_foo2362=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2363=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2364=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02365=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02366=== RUN TestGlobMatch/refs/*/main_refs/heads/main2367=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2368=== RUN TestGlobMatch/fo?_foo2369=== PAUSE TestGlobMatch/fo?_foo2370=== RUN TestGlobMatch/fo?_fo2371=== PAUSE TestGlobMatch/fo?_fo2372=== RUN TestGlobMatch/fo?_fooo2373=== PAUSE TestGlobMatch/fo?_fooo2374=== RUN TestGlobMatch/?oo_foo2375=== PAUSE TestGlobMatch/?oo_foo2376=== RUN TestGlobMatch/?oo_boo2377=== PAUSE TestGlobMatch/?oo_boo2378=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2379=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2380=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2381=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2382=== CONT TestGlobMatch/foo_foo2383=== CONT TestGlobMatch/*bar_bar2384=== CONT TestGlobMatch/foo*bar_foobar2385=== CONT TestGlobMatch/?oo_foo2386=== CONT TestGlobMatch/*bar_foo2387=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2388=== CONT TestGlobMatch/*bar_foobar2389=== CONT TestGlobMatch/foo*_foobar2390=== CONT TestGlobMatch/foo*bar_foobarbaz2391=== CONT TestGlobMatch/fo?_foo2392=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2393=== CONT TestGlobMatch/fo?_fo2394=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2395=== CONT TestGlobMatch/fo?_fooo2396=== CONT TestGlobMatch/foo*_foo2397=== CONT TestGlobMatch/?oo_boo2398=== CONT TestGlobMatch/*_anything2399=== CONT TestGlobMatch/*/*_foo/bar2400=== CONT TestGlobMatch/foo*bar_foo123bar2401=== CONT TestGlobMatch/*/*_foo2402=== CONT TestGlobMatch/*_2403=== CONT TestGlobMatch/foo_bar2404=== CONT TestGlobMatch/refs/*/main_refs/heads/main2405=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02406=== CONT TestGlobMatch/foo*_bar2407--- PASS: TestGlobMatch (0.01s)2408 --- PASS: TestGlobMatch/foo_foo (0.00s)2409 --- PASS: TestGlobMatch/*bar_bar (0.00s)2410 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2411 --- PASS: TestGlobMatch/?oo_foo (0.00s)2412 --- PASS: TestGlobMatch/*bar_foo (0.00s)2413 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2414 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2415 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2416 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2417 --- PASS: TestGlobMatch/fo?_foo (0.00s)2418 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2419 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2420 --- PASS: TestGlobMatch/foo*_foo (0.00s)2421 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2422 --- PASS: TestGlobMatch/fo?_fo (0.00s)2423 --- PASS: TestGlobMatch/*_anything (0.00s)2424 --- PASS: TestGlobMatch/*/*_foo (0.00s)2425 --- PASS: TestGlobMatch/?oo_boo (0.00s)2426 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2427 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2428 --- PASS: TestGlobMatch/*_ (0.00s)2429 --- PASS: TestGlobMatch/foo_bar (0.00s)2430 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2431 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2432 --- PASS: TestGlobMatch/foo*_bar (0.00s)24332026/10/01 09:58:20 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232434--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.11s)24352026/10/01 09:58:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39507/oidc24362026/10/01 09:58:20 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:44359/oidc24372026/10/01 09:58:20 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:38889/oidc2438--- PASS: TestPins_ReservedForMatchingRule (0.13s)2439--- PASS: TestValidateToken_MultipleProviders (0.14s)24402026/10/01 09:58:20 http: TLS handshake error from 127.0.0.1:58842: remote error: tls: bad certificate2441--- PASS: TestNewValidator_KubernetesRequiresCA (0.16s)24422026/10/01 09:58:20 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:4579324432026/10/01 09:58:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45829/oidc2444--- PASS: TestValidateToken_KubernetesServiceAccount (0.19s)2445--- PASS: TestValidateToken_BoundSubjectMismatch (0.19s)2446--- PASS: TestHTTPClientForHasTimeouts (0.20s)24472026/10/01 09:58:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44489/oidc2448--- PASS: TestPins_TopLevelShorthand (0.23s)24492026/10/01 09:58:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39361/oidc2450--- PASS: TestScopes_Rules (0.27s)24512026/10/01 09:58:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43291/oidc2452--- PASS: TestValidateToken_ValidToken (0.28s)24532026/10/01 09:58:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46139/oidc2454--- PASS: TestValidateToken_BoundClaimsMismatch (0.34s)24552026/10/01 09:58:20 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:32877/oidc2456--- PASS: TestValidateToken_NoMatchingProvider (0.41s)24572026/10/01 09:58:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45931/oidc2458--- PASS: TestValidateToken_WrongAudience (0.48s)24592026/10/01 09:58:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38315/oidc2460--- PASS: TestValidateToken_Expired (0.51s)24612026/10/01 09:58:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36573/oidc2462--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.72s)2463PASS2464Running signing tests...2465=== RUN TestGenerateFingerprint2466=== PAUSE TestGenerateFingerprint2467=== RUN TestParseSigningKey2468=== PAUSE TestParseSigningKey2469=== RUN TestSignMessage2470=== PAUSE TestSignMessage2471=== RUN TestSignNarinfo2472=== PAUSE TestSignNarinfo2473=== CONT TestGenerateFingerprint2474=== CONT TestParseSigningKey2475=== CONT TestSignNarinfo2476=== RUN TestGenerateFingerprint/basic_with_references2477=== PAUSE TestGenerateFingerprint/basic_with_references2478=== CONT TestSignMessage2479=== RUN TestGenerateFingerprint/no_references2480=== PAUSE TestGenerateFingerprint/no_references2481=== RUN TestParseSigningKey/valid_32-byte_key2482=== PAUSE TestParseSigningKey/valid_32-byte_key2483=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2484=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2485=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2486=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2487=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2488=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2489=== RUN TestParseSigningKey/no_colon2490=== RUN TestGenerateFingerprint/invalid_nar_hash_length2491=== PAUSE TestParseSigningKey/no_colon2492=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2493=== RUN TestParseSigningKey/empty_name2494=== RUN TestGenerateFingerprint/invalid_store_path_prefix2495=== PAUSE TestParseSigningKey/empty_name2496=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2497=== RUN TestParseSigningKey/invalid_base642498=== RUN TestGenerateFingerprint/invalid_reference_prefix2499=== PAUSE TestParseSigningKey/invalid_base642500=== RUN TestParseSigningKey/wrong_length2501=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2502=== PAUSE TestParseSigningKey/wrong_length2503=== CONT TestGenerateFingerprint/no_references2504=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2505=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2506=== CONT TestGenerateFingerprint/invalid_store_path_prefix2507=== CONT TestParseSigningKey/empty_name2508=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2509=== CONT TestGenerateFingerprint/invalid_nar_hash_length2510=== CONT TestParseSigningKey/wrong_length2511=== CONT TestGenerateFingerprint/basic_with_references2512=== CONT TestParseSigningKey/invalid_base642513=== CONT TestParseSigningKey/no_colon2514=== CONT TestParseSigningKey/valid_32-byte_key2515=== CONT TestGenerateFingerprint/invalid_reference_prefix2516--- PASS: TestGenerateFingerprint (0.00s)2517 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2518 --- PASS: TestGenerateFingerprint/no_references (0.00s)2519 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2520 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2521 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2522 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2523 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2524--- PASS: TestParseSigningKey (0.00s)2525 --- PASS: TestParseSigningKey/empty_name (0.00s)2526 --- PASS: TestParseSigningKey/wrong_length (0.00s)2527 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2528 --- PASS: TestParseSigningKey/no_colon (0.00s)2529 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.01s)2530 --- PASS: TestParseSigningKey/valid_32-byte_key (0.01s)2531--- PASS: TestSignMessage (0.02s)2532--- PASS: TestSignNarinfo (0.02s)2533PASS2534Running hook tests...2535=== RUN TestSendPathsEmpty2536=== PAUSE TestSendPathsEmpty2537=== RUN TestQueueEnqueueAndFetch2538=== PAUSE TestQueueEnqueueAndFetch2539=== RUN TestQueueDeduplication2540=== PAUSE TestQueueDeduplication2541=== RUN TestQueueRemove2542=== PAUSE TestQueueRemove2543=== RUN TestQueueFetchBatchLimit2544=== PAUSE TestQueueFetchBatchLimit2545=== RUN TestQueueRetryMovesToBack2546=== PAUSE TestQueueRetryMovesToBack2547=== RUN TestQueueFetchRemoveLifecycle2548=== PAUSE TestQueueFetchRemoveLifecycle2549=== RUN TestQueueConcurrentWriters2550=== PAUSE TestQueueConcurrentWriters2551=== RUN TestQueueEnqueueWaitsOutSlowWriter2552=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2553=== RUN TestQueueRemoveLargeClosure2554=== PAUSE TestQueueRemoveLargeClosure2555=== RUN TestServerClientIntegration2556=== PAUSE TestServerClientIntegration2557=== RUN TestServerQueueError2558=== PAUSE TestServerQueueError2559=== RUN TestServerRefusesOversizedAndNonStoreRequests2560=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2561=== RUN TestGetListenerSocketActivation2562 server_test.go:317: === RUN TestGetListenerSocketActivation2563 --- PASS: TestGetListenerSocketActivation (0.00s)2564 PASS2565 2566--- PASS: TestGetListenerSocketActivation (1.02s)2567=== RUN TestServerStalledClientDoesNotBlockShutdown2568=== PAUSE TestServerStalledClientDoesNotBlockShutdown2569=== RUN TestServerBacksOffOnAcceptErrors2570=== PAUSE TestServerBacksOffOnAcceptErrors2571=== RUN TestDrainIsolatesPoisonPath2572=== PAUSE TestDrainIsolatesPoisonPath2573=== RUN TestRunNotBlockedByPoisonHead2574=== PAUSE TestRunNotBlockedByPoisonHead2575=== RUN TestDrainGivesUpWhenServerDown2576=== PAUSE TestDrainGivesUpWhenServerDown2577=== RUN TestFailedPathPrunedByLaterClosure2578=== PAUSE TestFailedPathPrunedByLaterClosure2579=== RUN TestWorkerUploadsAndRemoves2580=== PAUSE TestWorkerUploadsAndRemoves2581=== RUN TestWorkerSkipsGCdPaths2582=== PAUSE TestWorkerSkipsGCdPaths2583=== RUN TestWorkerPrunesClosureDeps2584=== PAUSE TestWorkerPrunesClosureDeps2585=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2586=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2587=== RUN TestDrainTimeout2588=== PAUSE TestDrainTimeout2589=== RUN TestDrainTimeoutDuringIsolation2590=== PAUSE TestDrainTimeoutDuringIsolation2591=== RUN TestShutdownFinishesInFlightPush2592=== PAUSE TestShutdownFinishesInFlightPush2593=== RUN TestWorkerRemoveFailureIsNotProgress2594=== PAUSE TestWorkerRemoveFailureIsNotProgress2595=== RUN TestWorkerKeepsPathItCannotStat2596=== PAUSE TestWorkerKeepsPathItCannotStat2597=== CONT TestQueueDeduplication2598=== CONT TestQueueFetchRemoveLifecycle2599=== CONT TestWorkerPrunesClosureDeps2600=== CONT TestServerClientIntegration2601=== CONT TestQueueRemoveLargeClosure2602=== CONT TestSendPathsEmpty2603=== CONT TestDrainIsolatesPoisonPath2604--- PASS: TestSendPathsEmpty (0.00s)2605=== CONT TestServerStalledClientDoesNotBlockShutdown2606=== CONT TestDrainGivesUpWhenServerDown2607=== CONT TestServerBacksOffOnAcceptErrors2608=== CONT TestWorkerRemoveFailureIsNotProgress2609=== CONT TestDrainTimeoutDuringIsolation2610=== CONT TestDrainTimeout2611=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2612=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2613=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2614=== CONT TestQueueFetchBatchLimit2615=== CONT TestQueueConcurrentWriters26162026/10/01 09:58:24 ERROR Accept failed error="too many open files"2617=== CONT TestQueueRetryMovesToBack2618=== CONT TestQueueEnqueueAndFetch2619=== CONT TestQueueRemove2620=== CONT TestWorkerUploadsAndRemoves2621=== CONT TestWorkerSkipsGCdPaths2622=== CONT TestServerQueueError2623=== CONT TestFailedPathPrunedByLaterClosure2624=== CONT TestRunNotBlockedByPoisonHead2625=== CONT TestWorkerKeepsPathItCannotStat2626=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2627--- PASS: TestServerClientIntegration (0.00s)2628=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2629=== CONT TestQueueEnqueueWaitsOutSlowWriter2630=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short26312026/10/01 09:58:24 ERROR Failed to queue paths error="permission denied" count=12632=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2633=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2634=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2635=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2636=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2637=== CONT TestServerRefusesOversizedAndNonStoreRequests2638=== CONT TestShutdownFinishesInFlightPush2639=== RUN TestShutdownFinishesInFlightPush/completes2640=== PAUSE TestShutdownFinishesInFlightPush/completes2641=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short2642=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2643--- PASS: TestServerQueueError (0.00s)2644=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2645=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline26462026/10/01 09:58:24 ERROR Accept failed error="too many open files"26472026/10/01 09:58:24 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store26482026/10/01 09:58:24 ERROR Refusing path outside the store path=/nix/store store=/nix/store26492026/10/01 09:58:24 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store26502026/10/01 09:58:24 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store26512026/10/01 09:58:24 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store26522026/10/01 09:58:24 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26532026/10/01 09:58:24 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26542026/10/01 09:58:24 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store26552026/10/01 09:58:24 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store26562026/10/01 09:58:24 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store26572026/10/01 09:58:24 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store26582026/10/01 09:58:24 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store26592026/10/01 09:58:24 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store26602026/10/01 09:58:24 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store26612026/10/01 09:58:24 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store26622026/10/01 09:58:24 ERROR Failed to decode request error="unexpected EOF"2663--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2664=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path26652026/10/01 09:58:24 ERROR Accept failed error="too many open files"26662026/10/01 09:58:24 ERROR Accept failed error="too many open files"26672026/10/01 09:58:24 INFO Uploading batch count=426682026/10/01 09:58:24 ERROR Upload failed error="upload failed" count=426692026/10/01 09:58:24 INFO Upload queue status pending=226702026/10/01 09:58:24 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3302747145/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat3302747145/002/locked/aaa: permission denied"26712026/10/01 09:58:24 INFO Uploading batch count=226722026/10/01 09:58:24 INFO Uploading batch count=126732026/10/01 09:58:24 INFO Uploading batch count=226742026/10/01 09:58:24 ERROR Upload failed error="upload failed" count=226752026/10/01 09:58:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3497599140/002/a26762026/10/01 09:58:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath453999879/002/bbb26772026/10/01 09:58:24 INFO Upload queue status pending=326782026/10/01 09:58:24 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3302747145/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat3302747145/002/locked/aaa: permission denied"26792026/10/01 09:58:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3497599140/002/b26802026/10/01 09:58:24 INFO Uploading batch count=126812026/10/01 09:58:24 ERROR Upload failed error="upload failed" count=126822026/10/01 09:58:24 INFO Upload queue status pending=22683--- PASS: TestQueueFetchBatchLimit (0.07s)2684=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths26852026/10/01 09:58:24 INFO Upload queue status pending=326862026/10/01 09:58:24 INFO Uploading batch count=226872026/10/01 09:58:24 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3302747145/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat3302747145/002/locked/aaa: permission denied"26882026/10/01 09:58:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths4227488284/002/nonexistent26892026/10/01 09:58:24 INFO Uploading batch count=126902026/10/01 09:58:24 INFO Uploading batch count=226912026/10/01 09:58:24 ERROR Upload failed error="upload failed" count=226922026/10/01 09:58:24 ERROR Upload failed error="upload failed" count=126932026/10/01 09:58:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3497599140/002/c2694--- PASS: TestQueueFetchRemoveLifecycle (0.08s)2695=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch26962026/10/01 09:58:24 ERROR Drain finished with paths left in queue remaining=126972026/10/01 09:58:24 INFO Uploading batch count=226982026/10/01 09:58:24 INFO Upload queue status pending=226992026/10/01 09:58:24 INFO Uploading batch count=127002026/10/01 09:58:24 ERROR Upload failed error="upload failed" count=127012026/10/01 09:58:24 ERROR Accept failed error="too many open files"27022026/10/01 09:58:24 INFO Uploading batch count=227032026/10/01 09:58:24 INFO Uploading batch count=427042026/10/01 09:58:24 ERROR Upload failed error="upload failed" count=427052026/10/01 09:58:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3497599140/002/d2706--- PASS: TestQueueDeduplication (0.08s)2707=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout27082026/10/01 09:58:24 INFO Uploading batch count=127092026/10/01 09:58:24 INFO Uploading batch count=427102026/10/01 09:58:24 ERROR Upload failed error="upload failed" count=427112026/10/01 09:58:24 INFO Uploading batch count=227122026/10/01 09:58:24 ERROR Upload failed error="upload failed" count=227132026/10/01 09:58:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3497599140/002/e27142026/10/01 09:58:24 INFO Uploading batch count=127152026/10/01 09:58:24 ERROR Upload failed error="upload failed" count=127162026/10/01 09:58:24 INFO Uploading batch count=12717--- PASS: TestQueueRetryMovesToBack (0.08s)2718=== CONT TestShutdownFinishesInFlightPush/completes27192026/10/01 09:58:24 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3497599140/002/f2720--- PASS: TestWorkerKeepsPathItCannotStat (0.09s)2721--- PASS: TestQueueEnqueueAndFetch (0.09s)2722--- PASS: TestWorkerPrunesClosureDeps (0.09s)27232026/10/01 09:58:24 INFO Uploading batch count=127242026/10/01 09:58:24 ERROR Upload failed error="upload failed" count=127252026/10/01 09:58:24 ERROR Drain finished with paths left in queue remaining=102726--- PASS: TestQueueRemove (0.09s)27272026/10/01 09:58:24 ERROR Drain finished with paths left in queue remaining=12728--- PASS: TestFailedPathPrunedByLaterClosure (0.09s)2729--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.10s)2730--- PASS: TestWorkerSkipsGCdPaths (0.10s)2731--- PASS: TestDrainGivesUpWhenServerDown (0.10s)2732--- PASS: TestWorkerUploadsAndRemoves (0.10s)2733--- PASS: TestDrainIsolatesPoisonPath (0.11s)27342026/10/01 09:58:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path2470827403/001/nonexistent27352026/10/01 09:58:24 INFO Upload queue status pending=227362026/10/01 09:58:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127372026/10/01 09:58:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path2470827403/001/nonexistent27382026/10/01 09:58:24 INFO Uploading batch count=227392026/10/01 09:58:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127402026/10/01 09:58:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path2470827403/001/nonexistent27412026/10/01 09:58:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127422026/10/01 09:58:24 INFO Upload queue status pending=227432026/10/01 09:58:24 ERROR Drain finished with paths left in queue remaining=127442026/10/01 09:58:24 INFO Uploading batch count=227452026/10/01 09:58:24 INFO Uploading batch count=227462026/10/01 09:58:24 ERROR Upload failed error="upload failed" count=227472026/10/01 09:58:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127482026/10/01 09:58:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127492026/10/01 09:58:24 INFO Uploading batch count=227502026/10/01 09:58:24 INFO Uploading batch count=227512026/10/01 09:58:24 ERROR Upload failed error="upload failed" count=227522026/10/01 09:58:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227532026/10/01 09:58:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127542026/10/01 09:58:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127552026/10/01 09:58:24 INFO Uploading batch count=227562026/10/01 09:58:24 INFO Uploading batch count=227572026/10/01 09:58:24 ERROR Upload failed error="upload failed" count=227582026/10/01 09:58:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227592026/10/01 09:58:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127602026/10/01 09:58:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127612026/10/01 09:58:24 INFO Uploading batch count=227622026/10/01 09:58:24 ERROR Drain finished with paths left in queue remaining=227632026/10/01 09:58:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227642026/10/01 09:58:24 ERROR Drain finished with paths left in queue remaining=22765--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2766 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.10s)2767 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.06s)2768 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.05s)27692026/10/01 09:58:24 ERROR Accept failed error="too many open files"27702026/10/01 09:58:24 ERROR Failed to decode request error="read unix /build/hook2647571010/test.sock->@: i/o timeout"27712026/10/01 09:58:24 ERROR Failed to write response error="write unix /build/hook2647571010/test.sock->@: i/o timeout"2772--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)27732026/10/01 09:58:24 ERROR Upload failed error="context canceled" count=227742026/10/01 09:58:24 ERROR Drain finished with paths left in queue remaining=42775--- PASS: TestDrainTimeout (0.26s)27762026/10/01 09:58:24 ERROR Drain finished with paths left in queue remaining=427772026/10/01 09:58:24 ERROR Upload failed error="context canceled" count=227782026/10/01 09:58:24 ERROR Drain finished with paths left in queue remaining=22779--- PASS: TestShutdownFinishesInFlightPush (0.00s)2780 --- PASS: TestShutdownFinishesInFlightPush/completes (0.13s)2781 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.23s)27822026/10/01 09:58:24 ERROR Accept failed error="too many open files"27832026/10/01 09:58:24 ERROR Drain finished with paths left in queue remaining=32784--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2785 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.27s)2786 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.38s)2787--- PASS: TestQueueConcurrentWriters (0.50s)27882026/10/01 09:58:24 ERROR Accept failed error="too many open files"2789--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)27902026/10/01 09:58:25 INFO Uploading batch count=127912026/10/01 09:58:25 INFO Uploading batch count=127922026/10/01 09:58:25 INFO Uploading batch count=127932026/10/01 09:58:25 ERROR Upload failed error="upload failed" count=127942026/10/01 09:58:25 INFO Uploading batch count=127952026/10/01 09:58:25 ERROR Upload failed error="upload failed" count=127962026/10/01 09:58:25 INFO Uploading batch count=127972026/10/01 09:58:25 ERROR Upload failed error="upload failed" count=127982026/10/01 09:58:25 INFO Uploading batch count=127992026/10/01 09:58:25 ERROR Upload failed error="upload failed" count=128002026/10/01 09:58:25 ERROR Drain finished with paths left in queue remaining=12801--- PASS: TestRunNotBlockedByPoisonHead (1.11s)2802--- PASS: TestQueueRemoveLargeClosure (4.08s)2803--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.06s)2804PASS2805Running niks3-hook command tests...2806=== RUN TestServeSecondSignalEndsDrain2807=== PAUSE TestServeSecondSignalEndsDrain2808=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown2809=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown2810=== CONT TestServeSecondSignalEndsDrain2811=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown2812--- PASS: TestServeSecondSignalEndsDrain (0.07s)28132026/10/01 09:58:31 INFO Upload queue status pending=128142026/10/01 09:58:31 INFO Uploading batch count=12815--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.13s)2816PASS2817Running rate limiter tests...2818=== RUN TestAdaptiveRateLimiter_ThreadSafety2819=== PAUSE TestAdaptiveRateLimiter_ThreadSafety2820=== CONT TestAdaptiveRateLimiter_ThreadSafety28212026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=136.410197000000128222026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=95.4871379000000628232026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=66.8409965300000428242026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=46.7886975710000328252026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=32.7520882997000228262026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=22.92646180979001328272026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=16.04852326685300728282026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=11.23396628679710428292026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=7.86377640075797228302026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=5.5046434805305828312026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528322026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528332026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528342026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528352026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528362026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=5.63678500000000128372026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528382026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528392026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528402026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528412026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528422026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528432026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528442026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528452026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528462026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528472026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528482026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528492026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528502026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528512026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528522026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528532026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528542026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528552026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528562026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528572026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528582026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528592026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528602026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528612026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528622026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528632026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528642026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528652026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528662026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528672026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528682026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528692026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528702026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528712026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528722026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528732026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528742026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528752026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528762026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528772026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528782026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528792026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528802026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528812026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528822026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528832026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528842026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528852026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528862026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528872026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528882026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528892026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528902026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528912026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528922026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528932026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528942026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528952026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528962026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528972026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528982026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=528992026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=529002026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=529012026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=529022026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=529032026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=529042026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=5.12435000000000129052026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=529062026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=529072026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=529082026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=529092026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=529102026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=529112026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=529122026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=529132026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=529142026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=529152026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=529162026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=5.63678500000000129172026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=529182026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=529192026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=529202026/10/01 09:58:32 WARN Rate limiter backed off name=test rate=52921--- PASS: TestAdaptiveRateLimiter_ThreadSafety (1.90s)2922PASS