niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #360
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure18=== PAUSE TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure19=== RUN TestUploadMultipart_PartsInParallel20=== PAUSE TestUploadMultipart_PartsInParallel21=== RUN TestUploadMultipart_ProducerErrorIsNotEOF22=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF23=== RUN TestUploadMultipart_FailedPartBufferNotReused24=== PAUSE TestUploadMultipart_FailedPartBufferNotReused25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestUploadMultipart_SupersededByPeer28=== PAUSE TestUploadMultipart_SupersededByPeer29=== RUN TestDumpPathCaseHackMatchesNix30--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)31=== RUN TestDumpPathCaseHackCollision32--- PASS: TestDumpPathCaseHackCollision (0.00s)33=== RUN TestSupersededNARStillUploadsListing34=== PAUSE TestSupersededNARStillUploadsListing35=== RUN TestTruncatedNARDumpIsNotCompleted36=== PAUSE TestTruncatedNARDumpIsNotCompleted37=== RUN TestDumpPathMatchesNix38=== PAUSE TestDumpPathMatchesNix39=== RUN TestDumpPathSingleFile40=== PAUSE TestDumpPathSingleFile41=== RUN TestDumpPathWriterError42=== PAUSE TestDumpPathWriterError43=== RUN TestDumpPathWriterErrorStopsReading44 nar_test.go:289: read 114 of 32768000 bytes45--- PASS: TestDumpPathWriterErrorStopsReading (0.64s)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 TestRateLimiterFeedback130=== CONT TestScriptTokenCachesUntilRefresh131=== CONT TestSetClientTLS132=== CONT TestScriptTokenDoesNotWaitForItsChildren133=== CONT TestScriptTokenEmptyCommand134=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs135=== CONT TestScriptTokenScriptFails136=== CONT TestScriptTokenEmptyToken137=== CONT TestStreamPushReportsEveryPath138=== CONT TestStaticToken139=== CONT TestScriptTokenBadJSON140=== CONT TestSetClientTLSDoesNotMutateDefaultTransport141=== CONT TestStreamPushStopsOnCancel142=== CONT TestFileTokenReadsAndCaches143=== CONT TestScriptTokenNoExpiryRerunsEveryCall144=== CONT TestStreamPushGivesUpOnDeadServer145=== CONT TestClientSignaturesByStorePath146=== CONT TestSetClientTLSErrors147=== CONT TestStreamPushRequestLine148=== CONT TestStreamPushBatchesUnderLoad149=== CONT TestDoWithRetry_BodyReplayedViaGetBody150=== CONT TestDoWithRetry_FinalResponseBodyReadable151=== CONT TestResolveStorePath152=== CONT TestStreamPushReportsSignatures153=== RUN TestRateLimiterFeedback/429_enables_limiter154--- PASS: TestScriptTokenEmptyCommand (0.00s)155=== CONT TestFileTokenEmpty156=== PAUSE TestRateLimiterFeedback/429_enables_limiter157=== RUN TestRateLimiterFeedback/503_enables_limiter158=== PAUSE TestRateLimiterFeedback/503_enables_limiter159=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs160=== RUN TestSetClientTLSErrors/missing_cert_file161=== CONT TestStreamPushIsolatesFailures162=== RUN TestStreamPushStopsOnCancel/waiting_for_input163=== CONT TestShellSplit164=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input165=== CONT TestCompletePendingClosure_NotFoundWithoutKey166=== CONT TestShellSplitErrors167=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent168=== CONT TestUploadMultipart_SupersededByPeer169=== CONT TestDumpPathMatchesNix170=== RUN TestStreamPushBatchesUnderLoad/together171=== CONT TestPathInfoCACompatibility172=== CONT TestCaseHackSuffix173=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter174=== PAUSE TestStreamPushBatchesUnderLoad/together175=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter176--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)177=== PAUSE TestSetClientTLSErrors/missing_cert_file178=== CONT TestFileTokenMissing179=== CONT TestUploadMultipart_ProducerErrorIsNotEOF180=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot181=== RUN TestUploadMultipart_SupersededByPeer/exists182=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier183=== CONT TestEncodeNixBase32184=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun185=== RUN TestPathInfoCACompatibility/null_ca_field186=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout187=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time188=== CONT TestDumpPathWriterError189--- PASS: TestStaticToken (0.00s)190=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter191=== RUN TestSetClientTLSErrors/missing_key_file192=== CONT TestDumpPathSingleFile193=== CONT TestPathInfoHashCompatibility194=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part195=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)196=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot197=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier198=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot199=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up200=== RUN TestEncodeNixBase32/test_string_hash201=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer202=== CONT TestTruncatedNARDumpIsNotCompleted203=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout204=== PAUSE TestPathInfoCACompatibility/null_ca_field205=== CONT TestSupersededNARStillUploadsListing206=== RUN TestPathInfoCACompatibility/old_string_format_-_text207=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text208--- PASS: TestScriptTokenScriptFails (0.00s)209=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter210=== PAUSE TestSetClientTLSErrors/missing_key_file211=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part212=== PAUSE TestUploadMultipart_SupersededByPeer/exists213=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot214=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)215=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up216=== PAUSE TestEncodeNixBase32/test_string_hash217=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess218=== CONT TestGetStorePathHash219=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time220=== RUN TestSupersededNARStillUploadsListing/small_NAR221--- PASS: TestStreamPushReportsEveryPath (0.00s)222=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica223=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive224=== CONT TestConvertHashToNix32225=== RUN TestSetClientTLSErrors/missing_ca_file226=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary227=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon228=== RUN TestUploadMultipart_SupersededByPeer/missing229=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot230=== CONT TestParsePathInfoJSONMultiplePaths231=== RUN TestEncodeNixBase32/empty_input232=== CONT TestUploadMultipart_FailedPartBufferNotReused233=== RUN TestSetClientTLS/rejects_connection_without_client_cert234=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure235--- PASS: TestScriptTokenEmptyToken (0.01s)236=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert237=== PAUSE TestSupersededNARStillUploadsListing/small_NAR238=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA239=== RUN TestSupersededNARStillUploadsListing/dump_cut_short240=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA241=== RUN TestConvertHashToNix32/SRI_format_to_Nix32242=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive243=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32244=== PAUSE TestSetClientTLSErrors/missing_ca_file245=== RUN TestPathInfoCACompatibility/new_structured_format_-_text246=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary247=== RUN TestGetStorePathHash/valid_store_path248=== PAUSE TestUploadMultipart_SupersededByPeer/missing249=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon250=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot251=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths252--- PASS: TestScriptTokenBadJSON (0.01s)253=== CONT TestRegisterUploadedObjectReusesConnections254=== PAUSE TestEncodeNixBase32/empty_input255=== RUN TestSetClientTLS/preserves_debug_logging_transport256=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short257=== RUN TestSetClientTLSErrors/invalid_ca_file258=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails259=== RUN TestConvertHashToNix32/already_Nix32_format260=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text261=== CONT TestParsePathInfoJSON262=== PAUSE TestConvertHashToNix32/already_Nix32_format263=== CONT TestUploadMultipart_PartsInParallel264=== RUN TestConvertHashToNix32/invalid_format265=== CONT TestPartSizeForNAR266=== PAUSE TestGetStorePathHash/valid_store_path267=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI268=== CONT TestFilterOversizedClosures269=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot270--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)271=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths272=== CONT TestDoServerRequestAttachesToken273=== PAUSE TestSetClientTLS/preserves_debug_logging_transport274=== PAUSE TestSetClientTLSErrors/invalid_ca_file275=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails276=== RUN TestParsePathInfoJSON/Nix_format277=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method278=== PAUSE TestConvertHashToNix32/invalid_format279=== RUN TestPartSizeForNAR/zero_stays_at_minimum280=== RUN TestGetStorePathHash/basename_without_hyphen_should_error281=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI282=== RUN TestFilterOversizedClosures/no_limit_keeps_everything283=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot284--- PASS: TestClientSignaturesByStorePath (0.00s)285=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths286=== CONT TestEncodeNixBase32WithRealHash287=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout288=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum289=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs290=== PAUSE TestParsePathInfoJSON/Nix_format291=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error292=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything293=== RUN TestParsePathInfoJSON/Lix_format294=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error295=== RUN TestPartSizeForNAR/small_stays_at_minimum296=== PAUSE TestPartSizeForNAR/small_stays_at_minimum297=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths298=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped299=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter300=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped301=== CONT TestRateLimiterFeedback/429_enables_limiter302=== RUN TestFilterOversizedClosures/all_closures_skipped303=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error304=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512305=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error306=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512307--- PASS: TestFileTokenReadsAndCaches (0.00s)308=== PAUSE TestParsePathInfoJSON/Lix_format309=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken310=== CONT TestRateLimiterFeedback/503_enables_limiter311=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum312=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method313=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter314=== PAUSE TestFilterOversizedClosures/all_closures_skipped315=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up316=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error317=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum318=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time319=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts320=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts321--- PASS: TestShellSplit (0.00s)322=== RUN TestParsePathInfoJSON/empty_input323=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken324=== CONT TestStreamPushBatchesUnderLoad/together325=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier326=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary327=== RUN TestPartSizeForNAR/1_TiB328--- PASS: TestFileTokenEmpty (0.00s)329=== PAUSE TestParsePathInfoJSON/empty_input330=== CONT TestUploadMultipart_SupersededByPeer/missing331--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)332--- PASS: TestShellSplitErrors (0.00s)333--- PASS: TestStreamPushReportsSignatures (0.00s)334=== CONT TestUploadMultipart_SupersededByPeer/exists335=== CONT TestEncodeNixBase32/test_string_hash336=== CONT TestSetClientTLS/rejects_connection_without_client_cert337=== CONT TestEncodeNixBase32/empty_input338=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part339=== RUN TestParsePathInfoJSON/whitespace_only340=== PAUSE TestPartSizeForNAR/1_TiB341=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA342=== CONT TestConvertHashToNix32/already_Nix32_format343--- PASS: TestResolveStorePath (0.00s)344=== CONT TestSetClientTLS/preserves_debug_logging_transport345=== CONT TestSupersededNARStillUploadsListing/dump_cut_short346=== CONT TestSetClientTLSErrors/missing_cert_file347=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails348=== RUN TestPartSizeForNAR/5_TiB_S3_max_object349=== PAUSE TestParsePathInfoJSON/whitespace_only350=== CONT TestSupersededNARStillUploadsListing/small_NAR351=== CONT TestConvertHashToNix32/invalid_format352--- PASS: TestStreamPushIsolatesFailures (0.00s)353=== CONT TestConvertHashToNix32/SRI_format_to_Nix32354=== RUN TestParsePathInfoJSON/invalid_JSON355=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object356--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.00s)357--- PASS: TestFileTokenMissing (0.00s)358--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.02s)359=== CONT TestSetClientTLSErrors/missing_key_file360=== CONT TestSetClientTLSErrors/invalid_ca_file361=== PAUSE TestParsePathInfoJSON/invalid_JSON362=== RUN TestPartSizeForNAR/capped_at_5_GiB363--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)364=== CONT TestSetClientTLSErrors/missing_ca_file365=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths366=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths367=== PAUSE TestPartSizeForNAR/capped_at_5_GiB368--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)369=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI370=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)371=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512372--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)373=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon374=== CONT TestPathInfoCACompatibility/null_ca_field375=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive376=== CONT TestFilterOversizedClosures/no_limit_keeps_everything377=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error378=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method379--- PASS: TestDumpPathSingleFile (0.04s)380=== CONT TestPathInfoCACompatibility/old_string_format_-_text381=== CONT TestPathInfoCACompatibility/new_structured_format_-_text382=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error383=== CONT TestGetStorePathHash/basename_without_hyphen_should_error384=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped385--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.28s)386=== CONT TestGetStorePathHash/valid_store_path387=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot388=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken389=== CONT TestFilterOversizedClosures/all_closures_skipped390=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot391=== CONT TestStreamPushStopsOnCancel/waiting_for_input392--- PASS: TestCaseHackSuffix (0.28s)393--- PASS: TestDoServerRequestAttachesToken (0.00s)394--- PASS: TestEncodeNixBase32WithRealHash (0.00s)395--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.02s)396=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot397--- PASS: TestStreamPushBatchesUnderLoad (0.01s)398 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)399 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)400--- PASS: TestRateLimiterFeedback (0.02s)401 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)402 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)403 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)404 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)405--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.01s)406 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.01s)407 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.01s)408--- PASS: TestUploadMultipart_SupersededByPeer (0.28s)409 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)410 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)411--- PASS: TestEncodeNixBase32 (0.28s)412 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)413 --- PASS: TestEncodeNixBase32/empty_input (0.00s)414--- PASS: TestConvertHashToNix32 (0.01s)415 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)416 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)417 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)418--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)419 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)420 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)421--- PASS: TestPathInfoHashCompatibility (0.29s)422 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)423 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)424 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)425 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)426--- PASS: TestPathInfoCACompatibility (0.30s)427 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)428 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)429 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)430 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)431 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)432--- PASS: TestFilterOversizedClosures (0.01s)433 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)434 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)435 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)436--- PASS: TestGetStorePathHash (0.02s)437 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)438 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)439 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)440 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)441--- PASS: TestSetClientTLSErrors (0.30s)442 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)443 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)444 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)445 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.01s)446=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot447--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.25s)448=== CONT TestParsePathInfoJSON/Lix_format449=== CONT TestParsePathInfoJSON/whitespace_only450=== CONT TestParsePathInfoJSON/invalid_JSON451=== CONT TestParsePathInfoJSON/empty_input452=== CONT TestParsePathInfoJSON/Nix_format453=== CONT TestPartSizeForNAR/zero_stays_at_minimum454=== CONT TestPartSizeForNAR/capped_at_5_GiB455--- PASS: TestParsePathInfoJSON (0.19s)456 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)457 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)458 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)459 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)460 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)461=== CONT TestPartSizeForNAR/1_TiB462=== CONT TestPartSizeForNAR/small_stays_at_minimum463=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts464=== CONT TestPartSizeForNAR/5_TiB_S3_max_object465=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum466--- PASS: TestPartSizeForNAR (0.19s)467 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)468 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)469 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)470 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)471 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)472 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)473 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)474--- PASS: TestDumpPathWriterError (0.54s)475--- PASS: TestStreamPushStopsOnCancel (0.31s)476 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.05s)477 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.05s)478 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.05s)479 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)480 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.05s)481 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.05s)482--- PASS: TestSetClientTLS (0.31s)483 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.17s)484 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.18s)485 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.27s)486--- PASS: TestStreamPushRequestLine (0.66s)487--- PASS: TestRegisterUploadedObjectReusesConnections (0.40s)488--- PASS: TestDumpPathMatchesNix (0.74s)489--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.28s)490 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.46s)491 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.47s)492--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.07s)493--- PASS: TestTruncatedNARDumpIsNotCompleted (1.52s)494--- PASS: TestSupersededNARStillUploadsListing (0.29s)495 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.23s)496 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.24s)497 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.34s)498--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.42s)499--- PASS: TestUploadMultipart_PartsInParallel (1.44s)500--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (2.00s)501--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.02s)502 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.01s)503 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.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/postgres2757724859/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/postgres2757724859/data -l logfile start532533/build/postgres2757724859:5432 - no response5342026-10-05 12:09:21.754 UTC [170] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit5352026-10-05 12:09:21.754 UTC [170] LOG: listening on Unix socket "/build/postgres2757724859/.s.PGSQL.5432"5362026-10-05 12:09:21.759 UTC [177] LOG: database system was shut down at 2026-10-05 12:09:21 UTC5372026-10-05 12:09:21.763 UTC [170] LOG: database system is ready to accept connections538/build/postgres2757724859:5432 - accepting connections539{"timestamp":"2026-10-05T12:09:22.063992739Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"2c52ff81-5fc4-46b2-876b-825d18b1b079","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(397)"}540=== RUN TestService_AuthMiddleware541=== PAUSE TestService_AuthMiddleware542=== RUN TestService_AuthMiddleware_MTLSProxyHeader543=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader544=== RUN TestService_AuthMiddleware_MTLSBoundSubjects545=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects546=== RUN TestService_ReadAuthMiddleware547=== PAUSE TestService_ReadAuthMiddleware548=== RUN TestService_AuthMiddleware_OIDC549=== PAUSE TestService_AuthMiddleware_OIDC550=== RUN TestService_RequireScope_OIDC551=== PAUSE TestService_RequireScope_OIDC552=== RUN TestService_ReadScope_PublicByDefault553=== PAUSE TestService_ReadScope_PublicByDefault554=== RUN TestCacheConfigHandler555=== PAUSE TestCacheConfigHandler556=== RUN TestCacheStatsHandler557=== PAUSE TestCacheStatsHandler558=== RUN TestClientCADerivations559=== PAUSE TestClientCADerivations560=== RUN TestClientErrorHandling561=== PAUSE TestClientErrorHandling562=== RUN TestClientIntegration563=== PAUSE TestClientIntegration564=== RUN TestClientMultipleUploads565=== PAUSE TestClientMultipleUploads566=== RUN TestClientWithDependencies567=== PAUSE TestClientWithDependencies568=== RUN TestClientSharedPathCommittedMidPush569=== PAUSE TestClientSharedPathCommittedMidPush570=== RUN TestPinProtectsFromGC571=== PAUSE TestPinProtectsFromGC572=== RUN TestClientPushesUseOnePush573=== PAUSE TestClientPushesUseOnePush574=== RUN TestClientFallsBackToClosures575=== PAUSE TestClientFallsBackToClosures576=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock577=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock578=== RUN TestResolveDBConnectionString579=== PAUSE TestResolveDBConnectionString580=== RUN TestConnectWaitsForAPeerMigration581=== PAUSE TestConnectWaitsForAPeerMigration582=== RUN TestConnectSerialisesConcurrentMigrations583=== PAUSE TestConnectSerialisesConcurrentMigrations584=== RUN TestLeadElectsOneAndHandsOver585=== PAUSE TestLeadElectsOneAndHandsOver586=== RUN TestLeadIncumbentWinsAfterRestart5872026/10/05 12:09:22 INFO lead: acquired remote=192.0.2.1:12345882026/10/05 12:09:22 INFO lead: released remote=192.0.2.1:12345892026/10/05 12:09:23 INFO lead: acquired remote=192.0.2.1:12345902026/10/05 12:09:24 INFO lead: released remote=192.0.2.1:1234591--- PASS: TestLeadIncumbentWinsAfterRestart (1.95s)592=== RUN TestLeadIncumbentAnnouncesAtOnce593=== PAUSE TestLeadIncumbentAnnouncesAtOnce594=== RUN TestLeadEndsOnShutdown595=== PAUSE TestLeadEndsOnShutdown596=== RUN TestLeadEndsWhenItsConnectionHangs5972026/10/05 12:09:24 INFO lead: acquired remote=192.0.2.1:12345982026-10-05 12:09:25.661 UTC [617] FATAL: terminating connection due to administrator command5992026/10/05 12:09:25 INFO lead: acquired remote=192.0.2.1:12346002026/10/05 12:09:26 WARN lead: lock connection lost error="timeout: context deadline exceeded"6012026/10/05 12:09:26 INFO lead: released remote=192.0.2.1:12346022026/10/05 12:09:27 INFO lead: released remote=192.0.2.1:1234603--- PASS: TestLeadEndsWhenItsConnectionHangs (3.15s)604=== RUN TestGCAdvisoryLockBlocksConcurrentRun605=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun606=== RUN TestGCBugBareHashReferences607=== PAUSE TestGCBugBareHashReferences608=== RUN TestGCMetrics609=== PAUSE TestGCMetrics610=== RUN TestPushDedupSurvivesConcurrentGC611=== PAUSE TestPushDedupSurvivesConcurrentGC612=== RUN TestDeduplicatedObjectsRecordedAsPending613=== PAUSE TestDeduplicatedObjectsRecordedAsPending614=== RUN TestGCSweepSkipsPendingObjects615=== PAUSE TestGCSweepSkipsPendingObjects616=== RUN TestTombstonedObjectOfferedWithoutWaiting617=== PAUSE TestTombstonedObjectOfferedWithoutWaiting618=== RUN TestGCSweepDeliversEachKeyOnce619=== PAUSE TestGCSweepDeliversEachKeyOnce620=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection621=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection622=== RUN TestForceGCDuringPushOffersSweptObject623=== PAUSE TestForceGCDuringPushOffersSweptObject624=== RUN TestFailedS3DeleteKeepsTombstone625=== PAUSE TestFailedS3DeleteKeepsTombstone626=== RUN TestSweepSkipsRowsLockedByPush627=== PAUSE TestSweepSkipsRowsLockedByPush628=== RUN TestRegisterCompletedObjectNeedsPendingRow629=== PAUSE TestRegisterCompletedObjectNeedsPendingRow630=== RUN TestGetExistingObjectsLocksRows631=== PAUSE TestGetExistingObjectsLocksRows632=== RUN TestSweepRechecksPendingAfterLocking633=== PAUSE TestSweepRechecksPendingAfterLocking634=== RUN TestPushWaitsForSweepHoldingRow635=== PAUSE TestPushWaitsForSweepHoldingRow636=== RUN TestCommitRacingPendingCleanupKeepsObjects637=== PAUSE TestCommitRacingPendingCleanupKeepsObjects638=== RUN TestGCEndsOnShutdown639=== PAUSE TestGCEndsOnShutdown640=== RUN TestGCTaskStore_StartNew641=== PAUSE TestGCTaskStore_StartNew642=== RUN TestGCTaskStore_DeduplicateSameParams643=== PAUSE TestGCTaskStore_DeduplicateSameParams644=== RUN TestGCTaskStore_ConflictDifferentParams645=== PAUSE TestGCTaskStore_ConflictDifferentParams646=== RUN TestGCTaskStore_GetEmpty647=== PAUSE TestGCTaskStore_GetEmpty648=== RUN TestGCTaskStore_GetReturnsLatest649=== PAUSE TestGCTaskStore_GetReturnsLatest650=== RUN TestGCTaskStore_CompletedAllowsNewTask651=== PAUSE TestGCTaskStore_CompletedAllowsNewTask652=== RUN TestGCTaskStore_PhaseUpdates653=== PAUSE TestGCTaskStore_PhaseUpdates654=== RUN TestGCTaskStore_Fail655=== PAUSE TestGCTaskStore_Fail656=== RUN TestGracefulShutdownDrainsInflight657=== PAUSE TestGracefulShutdownDrainsInflight658=== RUN TestService_healthCheckHandler659=== PAUSE TestService_healthCheckHandler660=== RUN TestService_readinessHandler661=== PAUSE TestService_readinessHandler662=== RUN TestGenerateLandingPage663=== PAUSE TestGenerateLandingPage664=== RUN TestCacheConfigHandlerMaxNarSize665=== PAUSE TestCacheConfigHandlerMaxNarSize666=== RUN TestCreatePendingClosureRejectsOversizedNAR667=== PAUSE TestCreatePendingClosureRejectsOversizedNAR668=== RUN TestNARDeduplicationMetadataUploadBug669=== PAUSE TestNARDeduplicationMetadataUploadBug670=== RUN TestMetricsInventory671=== PAUSE TestMetricsInventory672=== RUN TestService_NativeMTLS673=== PAUSE TestService_NativeMTLS674=== RUN TestServerTLSConfig675=== PAUSE TestServerTLSConfig676=== RUN TestMultipartCleanup677=== PAUSE TestMultipartCleanup678=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded679=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded680=== RUN TestPendingCleanupUsesOneCutoff681=== PAUSE TestPendingCleanupUsesOneCutoff682=== RUN TestPendingClosureFailureTracksEveryUpload683=== PAUSE TestPendingClosureFailureTracksEveryUpload684=== RUN TestPendingClosureFailureAbortsItsUploads685=== PAUSE TestPendingClosureFailureAbortsItsUploads686=== RUN TestObjectStatsTrigger687=== PAUSE TestObjectStatsTrigger688=== RUN TestReconnectLeavesObjectsUnlocked689=== PAUSE TestReconnectLeavesObjectsUnlocked690=== RUN TestOrphanedObjectsGC691=== PAUSE TestOrphanedObjectsGC692=== RUN TestOrphanedObjectsGCStressTest693=== PAUSE TestOrphanedObjectsGCStressTest694=== RUN TestCreatePin_ReservedPins695=== PAUSE TestCreatePin_ReservedPins696=== RUN TestConcurrentPinUpdatesAgree697=== PAUSE TestConcurrentPinUpdatesAgree698=== RUN TestCreatePinRejectsBadInput699=== PAUSE TestCreatePinRejectsBadInput700=== RUN TestDeletePinKeepsRowWhenS3Fails701=== PAUSE TestDeletePinKeepsRowWhenS3Fails702=== RUN TestPresentReportsOnlyClosureRoots703=== PAUSE TestPresentReportsOnlyClosureRoots704=== RUN TestPresentNotReportedWhileGCDeletesClosure705=== PAUSE TestPresentNotReportedWhileGCDeletesClosure706=== RUN TestParseSingleRange707=== PAUSE TestParseSingleRange708=== RUN TestProxyHeadersOnlyTrustedOnSocket709=== PAUSE TestProxyHeadersOnlyTrustedOnSocket710=== RUN TestIsValidCachePath711=== PAUSE TestIsValidCachePath712=== RUN TestReadProxyNarinfo713=== PAUSE TestReadProxyNarinfo714=== RUN TestReadProxyNarinfoAlreadyDecompressed715=== PAUSE TestReadProxyNarinfoAlreadyDecompressed716=== RUN TestReadProxyNarStreaming717=== PAUSE TestReadProxyNarStreaming718=== RUN TestReadProxy404719=== PAUSE TestReadProxy404720=== RUN TestReadProxyInvalidPath721=== PAUSE TestReadProxyInvalidPath722=== RUN TestReadProxyHead723=== PAUSE TestReadProxyHead724=== RUN TestReadProxyOutlastsServerWriteTimeout725=== PAUSE TestReadProxyOutlastsServerWriteTimeout726=== RUN TestReadProxyConditionalGet727=== PAUSE TestReadProxyConditionalGet728=== RUN TestReadProxyRootRedirectsToIndexHTML729=== PAUSE TestReadProxyRootRedirectsToIndexHTML730=== RUN TestReadProxyDisabled731=== PAUSE TestReadProxyDisabled732=== RUN TestReadRedirectNar733=== PAUSE TestReadRedirectNar734=== RUN TestReadRedirectKeepsNarinfoProxied735=== PAUSE TestReadRedirectKeepsNarinfoProxied736=== RUN TestReadProxyRangeRequest737=== PAUSE TestReadProxyRangeRequest738=== RUN TestReadRedirectUsesPublicS3URL739=== PAUSE TestReadRedirectUsesPublicS3URL740=== RUN TestPush_OverlappingRootsStoreOneRowPerKey741=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey742=== RUN TestPush_CompleteCommitsEveryRoot743=== PAUSE TestPush_CompleteCommitsEveryRoot744=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit745=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit746=== RUN TestPush_RejectsBadRequests747=== PAUSE TestPush_RejectsBadRequests748=== RUN TestPush_SignsNarinfosOfItsPendingObjects749=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects750=== RUN TestRedundantMultipartUpload751=== PAUSE TestRedundantMultipartUpload752=== RUN TestCompleteMultipartUpload_ErrorButObjectExists753=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists754=== RUN TestCompletedNarNotReofferedAcrossClosures755=== PAUSE TestCompletedNarNotReofferedAcrossClosures756=== RUN TestPresignedUploadRegisteredBeforeCommit757=== PAUSE TestPresignedUploadRegisteredBeforeCommit758=== RUN TestService_Rustfstest759=== PAUSE TestService_Rustfstest760=== RUN TestParseSize761=== PAUSE TestParseSize762=== RUN TestSkippedUploadsHandler763=== PAUSE TestSkippedUploadsHandler764=== RUN TestSystemdListenerNotActivated765--- PASS: TestSystemdListenerNotActivated (0.00s)766=== RUN TestWatchdogBeatsWhenHealthy767--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)768=== RUN TestWatchdogSkipsWhenUnhealthy7692026/10/05 12:09:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/10/05 12:09:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/10/05 12:09:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/10/05 12:09:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/10/05 12:09:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/10/05 12:09:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7752026/10/05 12:09:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7762026/10/05 12:09:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7772026/10/05 12:09:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7782026/10/05 12:09:27 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"779--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)780=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle781=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle782=== RUN TestProxyWriteTimeout783=== PAUSE TestProxyWriteTimeout784=== RUN TestPendingClosureWriteTimeout785=== PAUSE TestPendingClosureWriteTimeout786=== RUN TestIsValidUploadKey787=== PAUSE TestIsValidUploadKey788=== RUN TestUploadHandlersRejectInvalidKeys789=== PAUSE TestUploadHandlersRejectInvalidKeys790=== RUN TestUploadHandlersRejectOversizedBody791=== PAUSE TestUploadHandlersRejectOversizedBody792=== RUN TestService_cleanupPendingClosuresHandler793=== PAUSE TestService_cleanupPendingClosuresHandler794=== RUN TestService_createPendingClosureHandler795=== PAUSE TestService_createPendingClosureHandler796=== RUN TestService_verifyS3Integrity797=== PAUSE TestService_verifyS3Integrity798=== RUN TestCompleteMultipartUnregistered799=== PAUSE TestCompleteMultipartUnregistered800=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT801=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT802=== CONT TestService_AuthMiddleware803=== CONT TestUploadHandlersRejectInvalidKeys804=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info805=== CONT TestReadProxyRootRedirectsToIndexHTML806=== CONT TestCompleteMultipartUnregistered807=== CONT TestService_verifyS3Integrity808=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT809=== CONT TestService_cleanupPendingClosuresHandler810=== CONT TestUploadHandlersRejectOversizedBody811=== CONT TestService_createPendingClosureHandler812=== CONT TestIsValidUploadKey813=== CONT TestPendingClosureWriteTimeout814=== CONT TestProxyWriteTimeout815=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle816=== RUN TestPendingClosureWriteTimeout/empty817=== CONT TestParseSize818=== CONT TestSkippedUploadsHandler819=== CONT TestPresignedUploadRegisteredBeforeCommit820=== CONT TestCompletedNarNotReofferedAcrossClosures821=== CONT TestRedundantMultipartUpload822=== CONT TestCompleteMultipartUpload_ErrorButObjectExists823=== CONT TestDeduplicatedObjectsRecordedAsPending824=== CONT TestPush_SignsNarinfosOfItsPendingObjects825=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit826=== CONT TestCacheConfigHandlerMaxNarSize827=== CONT TestNARDeduplicationMetadataUploadBug828=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info829=== RUN TestIsValidUploadKey/narinfo830=== RUN TestProxyWriteTimeout/narinfo831=== PAUSE TestPendingClosureWriteTimeout/empty832--- PASS: TestParseSize (0.00s)833=== CONT TestPush_CompleteCommitsEveryRoot834=== CONT TestMultipartCleanup835=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal836=== PAUSE TestProxyWriteTimeout/narinfo837=== PAUSE TestIsValidUploadKey/narinfo838=== RUN TestProxyWriteTimeout/1_GiB_nar839=== RUN TestIsValidUploadKey/nar_zst840=== PAUSE TestProxyWriteTimeout/1_GiB_nar841=== PAUSE TestIsValidUploadKey/nar_zst842=== RUN TestProxyWriteTimeout/10_GiB_nar843=== RUN TestIsValidUploadKey/nar_xz844=== RUN TestPendingClosureWriteTimeout/400_objects8452026/10/05 12:09:27 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000846=== PAUSE TestPendingClosureWriteTimeout/400_objects847=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal848--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)849=== PAUSE TestProxyWriteTimeout/10_GiB_nar850=== PAUSE TestIsValidUploadKey/nar_xz851=== RUN TestPendingClosureWriteTimeout/670k_objects852=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key853=== RUN TestProxyWriteTimeout/unknown_size854=== PAUSE TestProxyWriteTimeout/unknown_size855=== RUN TestIsValidUploadKey/nar_plain856=== PAUSE TestIsValidUploadKey/nar_plain857=== PAUSE TestPendingClosureWriteTimeout/670k_objects858=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline859=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key860=== CONT TestClientWithDependencies861=== RUN TestIsValidUploadKey/listing862=== PAUSE TestIsValidUploadKey/listing863=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline864=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key865=== CONT TestPush_OverlappingRootsStoreOneRowPerKey866=== RUN TestIsValidUploadKey/build_log867=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key868=== PAUSE TestIsValidUploadKey/build_log869=== CONT TestGenerateLandingPage870=== RUN TestIsValidUploadKey/build_log_home-manager_file871=== PAUSE TestIsValidUploadKey/build_log_home-manager_file872=== RUN TestIsValidUploadKey/build_log_plus_in_name873=== PAUSE TestIsValidUploadKey/build_log_plus_in_name874=== RUN TestIsValidUploadKey/build_log_question_mark875=== PAUSE TestIsValidUploadKey/build_log_question_mark876=== RUN TestIsValidUploadKey/build_log_equals877=== PAUSE TestIsValidUploadKey/build_log_equals878=== RUN TestIsValidUploadKey/realisation879=== PAUSE TestIsValidUploadKey/realisation880=== RUN TestIsValidUploadKey/realisation_plus_in_output881=== PAUSE TestIsValidUploadKey/realisation_plus_in_output882=== RUN TestIsValidUploadKey/nix-cache-info883=== PAUSE TestIsValidUploadKey/nix-cache-info884=== RUN TestIsValidUploadKey/index.html885=== PAUSE TestIsValidUploadKey/index.html886=== RUN TestIsValidUploadKey/narinfo_key,_nar_type887=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type888=== RUN TestIsValidUploadKey/nar_key,_narinfo_type889=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type890=== RUN TestIsValidUploadKey/listing_key,_narinfo_type891=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type892=== RUN TestIsValidUploadKey/traversal893=== PAUSE TestIsValidUploadKey/traversal894=== RUN TestIsValidUploadKey/traversal_nar895=== PAUSE TestIsValidUploadKey/traversal_nar896=== RUN TestIsValidUploadKey/absolute897=== PAUSE TestIsValidUploadKey/absolute898=== RUN TestIsValidUploadKey/empty_key899=== PAUSE TestIsValidUploadKey/empty_key900=== RUN TestIsValidUploadKey/unknown_type901=== PAUSE TestIsValidUploadKey/unknown_type902=== CONT TestGCAdvisoryLockBlocksConcurrentRun903--- PASS: TestGenerateLandingPage (0.01s)904=== CONT TestSweepRechecksPendingAfterLocking905--- PASS: TestSkippedUploadsHandler (0.05s)906=== CONT TestReadProxyConditionalGet9072026/10/05 12:09:27 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"908=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure909=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure910=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart911=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart912=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts913=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts914=== CONT TestCommitRacingPendingCleanupKeepsObjects915--- PASS: TestService_AuthMiddleware (0.57s)916=== CONT TestReadProxyOutlastsServerWriteTimeout9172026/10/05 12:09:28 INFO Received cleanup request method=DELETE path=/api/pending_closures9182026/10/05 12:09:28 INFO Aborted multipart uploads count=0 kept=09192026/10/05 12:09:28 INFO Received uploads request method=POST path=/api/pending_closures9202026/10/05 12:09:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9212026/10/05 12:09:28 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst9222026/10/05 12:09:28 INFO Received cleanup request method=DELETE path=/api/pending_closures923--- PASS: TestCompleteMultipartUnregistered (0.70s)924=== CONT TestIsValidCachePath925=== RUN TestIsValidCachePath/narinfo926=== PAUSE TestIsValidCachePath/narinfo927=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars928=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars929=== RUN TestIsValidCachePath/nar_zst930=== PAUSE TestIsValidCachePath/nar_zst9312026/10/05 12:09:28 INFO Aborted multipart uploads count=1 kept=0932=== RUN TestIsValidCachePath/nar_xz933=== PAUSE TestIsValidCachePath/nar_xz934=== RUN TestIsValidCachePath/nar_bz2935=== PAUSE TestIsValidCachePath/nar_bz2936=== RUN TestIsValidCachePath/nar_uncompressed937=== PAUSE TestIsValidCachePath/nar_uncompressed938=== RUN TestIsValidCachePath/ls939=== PAUSE TestIsValidCachePath/ls940=== RUN TestIsValidCachePath/log941=== PAUSE TestIsValidCachePath/log942=== RUN TestIsValidCachePath/realisation943=== PAUSE TestIsValidCachePath/realisation944=== RUN TestIsValidCachePath/nix-cache-info945=== PAUSE TestIsValidCachePath/nix-cache-info946=== RUN TestIsValidCachePath/index.html947=== PAUSE TestIsValidCachePath/index.html948=== RUN TestIsValidCachePath/traversal_parent949=== PAUSE TestIsValidCachePath/traversal_parent950=== RUN TestIsValidCachePath/traversal_in_middle951=== PAUSE TestIsValidCachePath/traversal_in_middle952=== RUN TestIsValidCachePath/invalid_char_e953=== PAUSE TestIsValidCachePath/invalid_char_e954=== RUN TestIsValidCachePath/invalid_char_u955=== PAUSE TestIsValidCachePath/invalid_char_u956=== RUN TestIsValidCachePath/random_path957=== PAUSE TestIsValidCachePath/random_path958=== RUN TestIsValidCachePath/empty9592026/10/05 12:09:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete960=== PAUSE TestIsValidCachePath/empty961=== RUN TestIsValidCachePath/leading_slash962=== PAUSE TestIsValidCachePath/leading_slash963=== RUN TestIsValidCachePath/wrong_extension964=== PAUSE TestIsValidCachePath/wrong_extension965=== RUN TestIsValidCachePath/short_hash9662026-10-05 12:09:28.226 UTC [685] ERROR: Closure does not exist: id=19672026-10-05 12:09:28.226 UTC [685] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE9682026-10-05 12:09:28.226 UTC [685] STATEMENT: -- name: CommitPendingClosure :exec969 SELECT commit_pending_closure($1::bigint)970 971=== PAUSE TestIsValidCachePath/short_hash972=== CONT TestReadProxyNarinfoAlreadyDecompressed9732026/10/05 12:09:28 INFO Received uploads request method=POST path=/api/pending_closures974--- PASS: TestService_cleanupPendingClosuresHandler (0.72s)975=== CONT TestCreatePendingClosureRejectsOversizedNAR9762026/10/05 12:09:28 INFO Received uploads request method=POST path=/api/pending_closures977--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)978=== CONT TestReadRedirectKeepsNarinfoProxied9792026/10/05 12:09:28 INFO Received uploads request method=POST path=/api/pending_closures980--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.77s)9812026/10/05 12:09:28 INFO Received uploads request method=POST path=/api/pending_closures982=== CONT TestPush_RejectsBadRequests9832026/10/05 12:09:28 INFO Received uploads request method=POST path=/api/pending_closures9842026/10/05 12:09:28 INFO Received uploads request method=POST path=/api/pending_closures9852026/10/05 12:09:28 INFO Received uploads request method=POST path=/api/pending_closures9862026/10/05 12:09:28 INFO Aborted multipart uploads count=0 kept=09872026/10/05 12:09:28 INFO Received uploads request method=POST path=/api/pending_closures9882026/10/05 12:09:28 WARN Force mode enabled - objects will be deleted immediately without grace period9892026/10/05 12:09:28 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=09902026/10/05 12:09:28 INFO Vacuumed table table=pending_closures9912026/10/05 12:09:28 INFO Vacuumed table table=pending_objects9922026/10/05 12:09:28 INFO Vacuumed table table=multipart_uploads9932026/10/05 12:09:28 INFO Vacuumed table table=closures9942026/10/05 12:09:28 INFO Vacuumed table table=objects9952026/10/05 12:09:28 INFO Received push request method=POST path=/api/pushes9962026/10/05 12:09:28 INFO Received uploads request method=POST path=/api/pending_closures997--- PASS: TestSweepRechecksPendingAfterLocking (0.88s)998=== CONT TestService_readinessHandler999=== CONT TestPushDedupSurvivesConcurrentGC10002026/10/05 12:09:28 INFO Received uploads request method=POST path=/api/pending_closures1001--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.91s)10022026/10/05 12:09:28 INFO Received uploads request method=POST path=/api/pending_closures10032026/10/05 12:09:28 INFO Received push request method=POST path=/api/pushes1004--- PASS: TestDeduplicatedObjectsRecordedAsPending (1.00s)1005=== CONT TestGCMetrics10062026/10/05 12:09:28 INFO Received push request method=POST path=/api/pushes10072026/10/05 12:09:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10082026/10/05 12:09:28 INFO Received cleanup request method=DELETE path=/api/pending_closures10092026/10/05 12:09:28 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket14/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10102026/10/05 12:09:28 INFO Aborted multipart uploads count=0 kept=110112026/10/05 12:09:28 INFO Received cleanup request method=DELETE path=/api/pending_closures10122026/10/05 12:09:28 INFO Aborted multipart uploads count=1 kept=010132026/10/05 12:09:28 INFO Received uploads request method=POST path=/api/pending_closures1014--- PASS: TestMultipartCleanup (1.09s)1015=== CONT TestReadRedirectUsesPublicS3URL10162026/10/05 12:09:28 INFO Received uploads request method=POST path=/api/pending_closures10172026/10/05 12:09:28 INFO Received uploads request method=POST path=/api/pending_closures10182026/10/05 12:09:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10192026/10/05 12:09:28 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MjRjMjA4OGEtNzc2OS00MTEzLTk3MmYtMjc0NjZkZGMzMjYzLmE4MmQ0ZjUwLWM0MjYtNDQ2Ni1iODc2LTBmNDFhYjE2MDk4OXgxNzkxMjAyMTY4NjMzODU0NzI410202026/10/05 12:09:28 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10212026/10/05 12:09:28 INFO Received uploads request method=POST path=/api/pending_closures1022--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.20s)1023=== CONT TestPushWaitsForSweepHoldingRow1024--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.21s)1025=== CONT TestReadProxyRangeRequest1026--- PASS: TestReadProxyConditionalGet (1.18s)1027=== CONT TestLeadEndsOnShutdown1028=== NAME TestNARDeduplicationMetadataUploadBug1029 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug302934160/001/store/0zmg4xsdy3bfwkbrkm2lw1kyyxl8hh70-file1.txt10302026/10/05 12:09:28 INFO Received push request method=POST path=/api/pushes1031=== NAME TestClientWithDependencies1032 client_integration_test.go:735: Built derivation: /build/TestClientWithDependencies1045790509/001/store/w1bv2lc08i9gg20am6gij8kj0vhnkavf-test-script10332026/10/05 12:09:28 INFO Aborted multipart uploads count=0 kept=010342026/10/05 12:09:28 WARN Force mode enabled - objects will be deleted immediately without grace period10352026/10/05 12:09:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10362026/10/05 12:09:28 INFO Signed narinfos id=1 count=110372026/10/05 12:09:28 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=010382026/10/05 12:09:28 INFO Vacuumed table table=pending_closures10392026/10/05 12:09:28 INFO Vacuumed table table=pending_objects10402026/10/05 12:09:28 INFO Vacuumed table table=multipart_uploads10412026/10/05 12:09:28 INFO Vacuumed table table=closures10422026/10/05 12:09:28 INFO Vacuumed table table=objects1043=== CONT TestReadProxyDisabled1044--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.31s)1045=== NAME TestClientWithDependencies1046 client_integration_test.go:737: Found 1 dependencies (including self)10472026/10/05 12:09:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1048--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.79s)1049=== CONT TestGCBugBareHashReferences10502026/10/05 12:09:28 INFO Received push request method=POST path=/api/pushes1051--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.67s)10522026/10/05 12:09:28 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MjRjMjA4OGEtNzc2OS00MTEzLTk3MmYtMjc0NjZkZGMzMjYzLmE4MmQ0ZjUwLWM0MjYtNDQ2Ni1iODc2LTBmNDFhYjE2MDk4OXgxNzkxMjAyMTY4NjMzODU0NzI4 error="Delete \"http://localhost:44927/bucket20/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=MjRjMjA4OGEtNzc2OS00MTEzLTk3MmYtMjc0NjZkZGMzMjYzLmE4MmQ0ZjUwLWM0MjYtNDQ2Ni1iODc2LTBmNDFhYjE2MDk4OXgxNzkxMjAyMTY4NjMzODU0NzI4\": injected: abort refused"1053=== CONT TestService_healthCheckHandler10542026/10/05 12:09:28 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MjRjMjA4OGEtNzc2OS00MTEzLTk3MmYtMjc0NjZkZGMzMjYzLmE1MTMzOGE4LTkyMzMtNDQ0OC1hZjJkLThmMmE5YjBhMjA4MHgxNzkxMjAyMTY4MjM4NTYyNDAz parts=1010552026/10/05 12:09:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10562026/10/05 12:09:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10572026/10/05 12:09:28 INFO Uploading 0zmg4xsdy3bfwkbrkm2lw1kyyxl8hh70-file1.txt (160B)10582026/10/05 12:09:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10592026/10/05 12:09:28 INFO Completed upload id=110602026/10/05 12:09:28 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MjRjMjA4OGEtNzc2OS00MTEzLTk3MmYtMjc0NjZkZGMzMjYzLmE4MmQ0ZjUwLWM0MjYtNDQ2Ni1iODc2LTBmNDFhYjE2MDk4OXgxNzkxMjAyMTY4NjMzODU0NzI410612026/10/05 12:09:28 INFO Received uploads request method=POST path=/api/pending_closures10622026/10/05 12:09:28 INFO Received uploads request method=POST path=/api/pending_closures10632026/10/05 12:09:28 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MjRjMjA4OGEtNzc2OS00MTEzLTk3MmYtMjc0NjZkZGMzMjYzLmE4MmQ0ZjUwLWM0MjYtNDQ2Ni1iODc2LTBmNDFhYjE2MDk4OXgxNzkxMjAyMTY4NjMzODU0NzI4 parts=110642026/10/05 12:09:28 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"1065=== RUN TestPush_RejectsBadRequests/no_roots10662026/10/05 12:09:28 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo1067=== PAUSE TestPush_RejectsBadRequests/no_roots10682026/10/05 12:09:28 WARN Found objects in DB but missing from S3, will re-upload count=11069=== RUN TestPush_RejectsBadRequests/no_objects1070=== PAUSE TestPush_RejectsBadRequests/no_objects1071=== RUN TestPush_RejectsBadRequests/bad_root1072=== PAUSE TestPush_RejectsBadRequests/bad_root1073=== RUN TestPush_RejectsBadRequests/root_not_in_objects1074=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1075=== CONT TestLeadIncumbentAnnouncesAtOnce10762026/10/05 12:09:28 INFO Received push request method=POST path=/api/pushes10772026/10/05 12:09:28 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete10782026/10/05 12:09:28 INFO Completed upload id=310792026/10/05 12:09:28 WARN Failed to register uploaded object key=0zmg4xsdy3bfwkbrkm2lw1kyyxl8hh70.ls error="server returned 404: 404 page not found\n"10802026/10/05 12:09:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10812026/10/05 12:09:28 INFO Signed narinfos id=1 count=110822026/10/05 12:09:28 INFO Uploading 1 narinfos10832026/10/05 12:09:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10842026/10/05 12:09:28 INFO Uploading w1bv2lc08i9gg20am6gij8kj0vhnkavf-test-script (136B)1085--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.42s)1086=== CONT TestGracefulShutdownDrainsInflight10872026/10/05 12:09:28 WARN readiness check failed error="closed pool"10882026/10/05 12:09:28 INFO Starting HTTP server address=127.0.0.1:4110310892026/10/05 12:09:28 INFO Shutdown signal received, draining in-flight requests timeout=10s10902026/10/05 12:09:28 WARN Failed to register uploaded object key=log/dyzwhjdr0dyhpa5bk3q83i3kdrxlag5g-test-script.drv error="server returned 404: 404 page not found\n"1091--- PASS: TestService_verifyS3Integrity (1.44s)1092=== CONT TestReadRedirectNar10932026/10/05 12:09:28 INFO Received complete push request method=POST path=/api/pushes/1/complete10942026/10/05 12:09:28 WARN Failed to register uploaded object key=0zmg4xsdy3bfwkbrkm2lw1kyyxl8hh70.narinfo error="server returned 404: 404 page not found\n"10952026/10/05 12:09:28 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"1096--- PASS: TestService_readinessHandler (0.55s)1097=== CONT TestGCTaskStore_Fail1098--- PASS: TestGCTaskStore_Fail (0.00s)1099=== CONT TestConnectSerialisesConcurrentMigrations11002026/10/05 12:09:28 INFO Upload complete. (144ms)1101=== NAME TestNARDeduplicationMetadataUploadBug11022026/10/05 12:09:28 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1103 metadata_upload_test.go:54: Retrieved narinfo from S3:1104 StorePath: /build/TestNARDeduplicationMetadataUploadBug302934160/001/store/0zmg4xsdy3bfwkbrkm2lw1kyyxl8hh70-file1.txt1105 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1106 Compression: zstd1107 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1108 NarSize: 1601109 References: 1110 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf11112026/10/05 12:09:28 WARN Failed to register uploaded object key=w1bv2lc08i9gg20am6gij8kj0vhnkavf.ls error="server returned 404: 404 page not found\n"11122026/10/05 12:09:28 INFO Signed narinfos id=1 count=111132026/10/05 12:09:28 INFO Uploading 1 narinfos11142026/10/05 12:09:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1115 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1116 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):11172026/10/05 12:09:28 INFO Received complete push request method=POST path=/api/pushes/1/complete1118 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}11192026/10/05 12:09:28 WARN Failed to register uploaded object key=w1bv2lc08i9gg20am6gij8kj0vhnkavf.narinfo error="server returned 404: 404 page not found\n"11202026/10/05 12:09:29 INFO Upload complete. (119ms)11212026/10/05 12:09:29 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MjRjMjA4OGEtNzc2OS00MTEzLTk3MmYtMjc0NjZkZGMzMjYzLjA4NTBkOTYwLWEzN2QtNDExOC05YmI1LWI3MzVkNjg5MDVkZXgxNzkxMjAyMTY4MzA3Mjg4NzYx parts=1011222026/10/05 12:09:29 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11232026/10/05 12:09:29 INFO Received uploads request method=POST path=/api/pending_closures11242026/10/05 12:09:29 INFO Aborted multipart uploads count=0 kept=011252026/10/05 12:09:29 INFO Completed upload id=111262026/10/05 12:09:29 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011272026/10/05 12:09:29 WARN Force mode enabled - objects will be deleted immediately without grace period1128=== CONT TestGCTaskStore_CompletedAllowsNewTask1129--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1130=== CONT TestConnectWaitsForAPeerMigration11312026/10/05 12:09:29 INFO Received uploads request method=POST path=/api/pending_closures1132--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)11332026/10/05 12:09:29 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=01134=== NAME TestNARDeduplicationMetadataUploadBug1135 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug302934160/001/store/pwkgpm0wpz4l53icaw7md6pvk3gb2z7m-file2.txt11362026/10/05 12:09:29 INFO Aborted multipart uploads count=0 kept=011372026/10/05 12:09:29 INFO Starting cleanup of old closures method=DELETE path=/api/closures11382026/10/05 12:09:29 INFO Vacuumed table table=pending_closures11392026/10/05 12:09:29 INFO Vacuumed table table=pending_objects11402026/10/05 12:09:29 INFO Vacuumed table table=multipart_uploads11412026/10/05 12:09:29 WARN Force mode enabled - objects will be deleted immediately without grace period11422026/10/05 12:09:29 INFO Vacuumed table table=closures11432026/10/05 12:09:29 INFO Vacuumed table table=objects11442026/10/05 12:09:29 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=011452026/10/05 12:09:29 INFO Aborted multipart uploads count=0 kept=01146=== NAME TestClientWithDependencies1147 client_integration_test.go:753: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1045790509/001/store) requires matching store prefix11482026/10/05 12:09:29 INFO Vacuumed table table=pending_closures11492026/10/05 12:09:29 INFO Vacuumed table table=pending_objects11502026/10/05 12:09:29 INFO Vacuumed table table=multipart_uploads11512026/10/05 12:09:29 INFO Vacuumed table table=closures11522026/10/05 12:09:29 INFO Vacuumed table table=objects11532026/10/05 12:09:29 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=011542026/10/05 12:09:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11552026/10/05 12:09:29 INFO Vacuumed table table=pending_closures11562026/10/05 12:09:29 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"11572026/10/05 12:09:29 INFO Vacuumed table table=pending_objects11582026/10/05 12:09:29 INFO Vacuumed table table=multipart_uploads11592026/10/05 12:09:29 INFO Vacuumed table table=closures11602026/10/05 12:09:29 INFO Vacuumed table table=objects1161=== CONT TestLeadElectsOneAndHandsOver1162--- PASS: TestClientWithDependencies (1.54s)11632026/10/05 12:09:29 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011642026/10/05 12:09:29 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MjRjMjA4OGEtNzc2OS00MTEzLTk3MmYtMjc0NjZkZGMzMjYzLjlkNjIxOWY5LTkwMzAtNGZhYi1hNGQ5LTQwNmRlMDBlNjgwOXgxNzkxMjAyMTY4MzMwNzMxNDgy parts=1211652026-10-05 12:09:29.093 UTC [1014] ERROR: duplicate key value violates unique constraint "pg_type_typname_nsp_index"11662026-10-05 12:09:29.093 UTC [1014] DETAIL: Key (typname, typnamespace)=(goose_db_version, 2200) already exists.11672026-10-05 12:09:29.093 UTC [1014] STATEMENT: CREATE TABLE goose_db_version (1168 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1169 version_id bigint NOT NULL,1170 is_applied boolean NOT NULL,1171 tstamp timestamp NOT NULL DEFAULT now()1172 )11732026/10/05 12:09:29 INFO Received uploads request method=POST path=/api/pending_closures1174=== CONT TestGCTaskStore_PhaseUpdates1175--- PASS: TestReadRedirectKeepsNarinfoProxied (0.85s)1176--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1177=== CONT TestGCEndsOnShutdown1178=== RUN TestGCEndsOnShutdown/before_the_run1179=== PAUSE TestGCEndsOnShutdown/before_the_run1180=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1181=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1182=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1183=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1184=== CONT TestGCTaskStore_GetReturnsLatest1185=== CONT TestGCTaskStore_GetEmpty1186--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1187=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1188--- PASS: TestGCTaskStore_GetEmpty (0.00s)11892026/10/05 12:09:29 INFO Aborted multipart uploads count=0 kept=01190--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (1.56s)1191=== CONT TestGetExistingObjectsLocksRows11922026/10/05 12:09:29 INFO Received push request method=POST path=/api/pushes1193--- PASS: TestService_createPendingClosureHandler (1.58s)1194=== CONT TestClientFallsBackToClosures11952026/10/05 12:09:29 INFO Received uploads request method=POST path=/api/pending_closures1196--- PASS: TestGCMetrics (0.58s)1197=== CONT TestGCTaskStore_ConflictDifferentParams1198--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1199=== CONT TestSweepSkipsRowsLockedByPush12002026/10/05 12:09:29 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=012012026/10/05 12:09:29 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12022026/10/05 12:09:29 INFO Vacuumed table table=pending_closures12032026/10/05 12:09:29 INFO Vacuumed table table=pending_objects12042026/10/05 12:09:29 INFO Vacuumed table table=multipart_uploads12052026/10/05 12:09:29 WARN Failed to register uploaded object key=pwkgpm0wpz4l53icaw7md6pvk3gb2z7m.ls error="server returned 404: 404 page not found\n"12062026/10/05 12:09:29 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12072026/10/05 12:09:29 INFO Signed narinfos id=2 count=112082026/10/05 12:09:29 INFO Uploading 1 narinfos12092026/10/05 12:09:29 INFO Vacuumed table table=closures12102026/10/05 12:09:29 INFO Received uploads request method=POST path=/api/pending_closures12112026/10/05 12:09:29 INFO Vacuumed table table=objects12122026/10/05 12:09:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12132026/10/05 12:09:29 INFO Received complete push request method=POST path=/api/pushes/2/complete12142026/10/05 12:09:29 WARN Failed to register uploaded object key=pwkgpm0wpz4l53icaw7md6pvk3gb2z7m.narinfo error="server returned 404: 404 page not found\n"12152026/10/05 12:09:29 INFO Aborted multipart uploads count=0 kept=012162026/10/05 12:09:29 WARN Force mode enabled - objects will be deleted immediately without grace period12172026/10/05 12:09:29 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=012182026/10/05 12:09:29 INFO Upload complete. (79ms)1219=== NAME TestNARDeduplicationMetadataUploadBug1220 metadata_upload_test.go:76: Retrieved narinfo from S3:1221 StorePath: /build/TestNARDeduplicationMetadataUploadBug302934160/001/store/pwkgpm0wpz4l53icaw7md6pvk3gb2z7m-file2.txt1222 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1223 Compression: zstd1224 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1225 NarSize: 1601226 References: 1227 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf12282026/10/05 12:09:29 INFO Vacuumed table table=pending_closures12292026/10/05 12:09:29 INFO Vacuumed table table=pending_objects12302026/10/05 12:09:29 INFO Vacuumed table table=multipart_uploads12312026/10/05 12:09:29 INFO Vacuumed table table=closures1232 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1233 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1234 {"version":1,"root":{"type":"regular","size":44}}12352026/10/05 12:09:29 INFO Vacuumed table table=objects12362026/10/05 12:09:29 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MjRjMjA4OGEtNzc2OS00MTEzLTk3MmYtMjc0NjZkZGMzMjYzLmVkYzAwOTRhLTZiYTYtNDBjNC1hOTY3LWMwN2I4N2YzYTg3YngxNzkxMjAyMTY4Mzg2NzM4NjU1 parts=1212372026/10/05 12:09:29 INFO Received uploads request method=POST path=/api/pending_closures1238--- PASS: TestPushDedupSurvivesConcurrentGC (0.74s)1239=== CONT TestClientPushesUseOnePush1240--- PASS: TestNARDeduplicationMetadataUploadBug (1.65s)1241=== CONT TestGCTaskStore_StartNew1242--- PASS: TestGCTaskStore_StartNew (0.00s)1243=== CONT TestResolveDBConnectionString1244=== RUN TestResolveDBConnectionString/flag_wins1245=== PAUSE TestResolveDBConnectionString/flag_wins1246=== RUN TestResolveDBConnectionString/file_when_flag_empty1247=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1248=== RUN TestResolveDBConnectionString/missing_file_is_an_error1249=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1250=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1251=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1252=== RUN TestResolveDBConnectionString/nothing_configured1253=== PAUSE TestResolveDBConnectionString/nothing_configured1254=== CONT TestFailedS3DeleteKeepsTombstone12552026/10/05 12:09:29 INFO lead: acquired remote=192.0.2.1:12341256--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.67s)1257=== CONT TestRegisterCompletedObjectNeedsPendingRow1258=== CONT TestForceGCDuringPushOffersSweptObject1259--- PASS: TestReadProxyRangeRequest (0.47s)1260=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1261=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1262=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1263=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1264=== CONT TestPinProtectsFromGC12652026/10/05 12:09:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12662026/10/05 12:09:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1267--- PASS: TestReadRedirectUsesPublicS3URL (0.60s)1268=== CONT TestGCSweepDeliversEachKeyOnce1269=== CONT TestService_Rustfstest1270--- PASS: TestReadProxyDisabled (0.40s)12712026/10/05 12:09:29 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MjRjMjA4OGEtNzc2OS00MTEzLTk3MmYtMjc0NjZkZGMzMjYzLjhhYzE1MzliLTkwYmItNDZmMi05OGJlLWQ3OTcyMzI4NTAwMHgxNzkxMjAyMTY4NTE3NjYxOTg3 parts=1012722026/10/05 12:09:29 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MjRjMjA4OGEtNzc2OS00MTEzLTk3MmYtMjc0NjZkZGMzMjYzLmVjZjIwMTEyLWNhNTgtNDU3Yi1iNDUwLWFlYjkxZTIyYWZhY3gxNzkxMjAyMTY4NTQ3MjIyOTgy parts=101273--- PASS: TestService_healthCheckHandler (0.43s)1274=== CONT TestGCSweepSkipsPendingObjects12752026/10/05 12:09:29 INFO lead: acquired remote=192.0.2.1:123412762026/10/05 12:09:29 INFO lead: released remote=192.0.2.1:12341277--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.43s)1278=== CONT TestGCTaskStore_DeduplicateSameParams1279--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1280=== CONT TestTombstonedObjectOfferedWithoutWaiting12812026/10/05 12:09:29 INFO lead: acquired remote=192.0.2.1:12341282--- PASS: TestReadRedirectNar (0.44s)1283=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1284--- PASS: TestGetExistingObjectsLocksRows (0.39s)1285=== CONT TestPresentReportsOnlyClosureRoots12862026/10/05 12:09:29 INFO Aborted multipart uploads count=0 kept=012872026/10/05 12:09:29 WARN Force mode enabled - objects will be deleted immediately without grace period12882026/10/05 12:09:29 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=01289--- PASS: TestGCBugBareHashReferences (0.65s)1290=== CONT TestDeletePinKeepsRowWhenS3Fails12912026/10/05 12:09:29 INFO Vacuumed table table=pending_closures12922026/10/05 12:09:29 INFO Vacuumed table table=pending_objects12932026/10/05 12:09:29 INFO Vacuumed table table=multipart_uploads12942026/10/05 12:09:29 INFO Vacuumed table table=closures12952026/10/05 12:09:29 INFO Vacuumed table table=objects12962026/10/05 12:09:29 INFO Aborted multipart uploads count=0 kept=012972026/10/05 12:09:29 WARN Force mode enabled - objects will be deleted immediately without grace period12982026/10/05 12:09:29 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=012992026/10/05 12:09:29 INFO Vacuumed table table=pending_closures13002026/10/05 12:09:29 INFO Vacuumed table table=pending_objects13012026/10/05 12:09:29 INFO Vacuumed table table=multipart_uploads13022026/10/05 12:09:29 INFO Vacuumed table table=closures13032026/10/05 12:09:29 INFO Vacuumed table table=objects1304--- PASS: TestSweepSkipsRowsLockedByPush (0.48s)1305=== CONT TestReadProxyHead1306=== CONT TestParseSingleRange1307--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.43s)1308=== RUN TestParseSingleRange/none1309=== PAUSE TestParseSingleRange/none1310=== RUN TestParseSingleRange/unknown_unit1311=== PAUSE TestParseSingleRange/unknown_unit1312=== RUN TestParseSingleRange/multi-range_ignored1313=== PAUSE TestParseSingleRange/multi-range_ignored1314=== RUN TestParseSingleRange/malformed_no_dash1315=== PAUSE TestParseSingleRange/malformed_no_dash1316=== RUN TestParseSingleRange/malformed_both_empty1317=== PAUSE TestParseSingleRange/malformed_both_empty1318=== RUN TestParseSingleRange/malformed_end_before_start1319=== PAUSE TestParseSingleRange/malformed_end_before_start1320=== RUN TestParseSingleRange/closed1321=== PAUSE TestParseSingleRange/closed1322=== RUN TestParseSingleRange/open-ended1323=== PAUSE TestParseSingleRange/open-ended1324=== RUN TestParseSingleRange/end_clamped_to_size1325=== PAUSE TestParseSingleRange/end_clamped_to_size1326=== RUN TestParseSingleRange/suffix1327=== PAUSE TestParseSingleRange/suffix1328=== RUN TestParseSingleRange/suffix_exceeds_size1329=== PAUSE TestParseSingleRange/suffix_exceeds_size1330=== RUN TestParseSingleRange/single_byte1331=== PAUSE TestParseSingleRange/single_byte1332=== RUN TestParseSingleRange/start_past_EOF1333=== PAUSE TestParseSingleRange/start_past_EOF1334=== RUN TestParseSingleRange/start_far_past_EOF1335=== PAUSE TestParseSingleRange/start_far_past_EOF1336=== CONT TestPresentNotReportedWhileGCDeletesClosure1337--- PASS: TestPushWaitsForSweepHoldingRow (0.93s)1338=== CONT TestProxyHeadersOnlyTrustedOnSocket13392026/10/05 12:09:29 INFO Received uploads request method=POST path=/api/pending_closures1340=== NAME TestPinProtectsFromGC1341 client_integration_test.go:867: Pinned store path: /build/TestPinProtectsFromGC3982918121/001/store/g7ld78ki3qrfm5krl1s5cdqgmsmgr6rh-pinned-file.txt1342 client_integration_test.go:868: Unpinned store path: /build/TestPinProtectsFromGC3982918121/001/store/46sny6c78sz5id0kyy96630yw8irdqz1-unpinned-file.txt13432026/10/05 12:09:29 INFO Aborted multipart uploads count=0 kept=013442026/10/05 12:09:29 WARN Force mode enabled - objects will be deleted immediately without grace period1345--- PASS: TestService_Rustfstest (0.50s)1346=== CONT TestConcurrentPinUpdatesAgree13472026/10/05 12:09:29 INFO Received uploads request method=POST path=/api/pending_closures13482026/10/05 12:09:29 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=013492026/10/05 12:09:29 INFO Vacuumed table table=pending_closures13502026/10/05 12:09:29 INFO Vacuumed table table=pending_objects13512026/10/05 12:09:29 INFO Vacuumed table table=multipart_uploads13522026/10/05 12:09:29 INFO Vacuumed table table=closures13532026/10/05 12:09:29 INFO Received uploads request method=POST path=/api/pending_closures13542026/10/05 12:09:29 INFO Received uploads request method=POST path=/api/pending_closures13552026/10/05 12:09:29 INFO Vacuumed table table=objects13562026/10/05 12:09:29 INFO Aborted multipart uploads count=0 kept=013572026/10/05 12:09:29 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13582026/10/05 12:09:29 INFO Uploading rdlhlar7bsm9892sqjc5f30mjvxy6pd0-shared-dep (136B)13592026/10/05 12:09:29 INFO Uploading 96wllra6xqcwwd6awz2v75mnl39l27jp-a (216B)13602026/10/05 12:09:29 WARN Force mode enabled - objects will be deleted immediately without grace period1361--- PASS: TestGCSweepDeliversEachKeyOnce (0.55s)1362=== CONT TestReadProxyInvalidPath13632026/10/05 12:09:29 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."13642026/10/05 12:09:29 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."13652026/10/05 12:09:29 INFO Received push request method=POST path=/api/pushes13662026/10/05 12:09:29 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13672026/10/05 12:09:29 INFO Received uploads request method=POST path=/api/pending_closures13682026/10/05 12:09:29 INFO Aborted multipart uploads count=0 kept=013692026/10/05 12:09:29 WARN Failed to register uploaded object key=nar/05g2wkh8r459hfbj9v8rsb6plj6am49lc14f725q56m0jscrsrrm.nar.zst error="server returned 404: 404 page not found\n"13702026/10/05 12:09:29 WARN Force mode enabled - objects will be deleted immediately without grace period13712026/10/05 12:09:29 INFO Received push request method=POST path=/api/pushes13722026/10/05 12:09:29 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=013732026/10/05 12:09:29 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13742026/10/05 12:09:29 INFO Uploading hqav2kyfd2mmq2idgfcsd5yy3b6pcqfx-b (216B)13752026/10/05 12:09:29 INFO Uploading y4bfbvrkxvgxjr0kg886l5sxj3h41fk8-shared-dep (136B)13762026/10/05 12:09:29 INFO Vacuumed table table=pending_closures13772026/10/05 12:09:29 WARN Failed to register uploaded object key=rdlhlar7bsm9892sqjc5f30mjvxy6pd0.ls error="server returned 404: 404 page not found\n"13782026/10/05 12:09:29 WARN Failed to register uploaded object key=96wllra6xqcwwd6awz2v75mnl39l27jp.ls error="server returned 404: 404 page not found\n"13792026/10/05 12:09:29 INFO Vacuumed table table=pending_objects13802026/10/05 12:09:29 INFO Vacuumed table table=multipart_uploads13812026/10/05 12:09:29 INFO Vacuumed table table=closures13822026/10/05 12:09:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13832026/10/05 12:09:29 INFO Uploading g7ld78ki3qrfm5krl1s5cdqgmsmgr6rh-pinned-file.txt (128B)13842026/10/05 12:09:29 INFO Vacuumed table table=objects1385--- PASS: TestFailedS3DeleteKeepsTombstone (0.63s)1386=== CONT TestObjectStatsTrigger13872026/10/05 12:09:29 WARN Failed to register uploaded object key=nar/1x280jcnz4fccxhqi9k4dc2m062f44crmcq5gc9866m0f8x6b6qy.nar.zst error="server returned 404: 404 page not found\n"13882026/10/05 12:09:29 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13892026/10/05 12:09:29 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13902026/10/05 12:09:29 WARN Failed to register uploaded object key=6xvb38cv2j77sq2p9zc13z0fgkqk6xav.ls error="server returned 404: 404 page not found\n"13912026/10/05 12:09:29 INFO Signed narinfos id=1 count=213922026/10/05 12:09:29 WARN Failed to register uploaded object key=hqav2kyfd2mmq2idgfcsd5yy3b6pcqfx.ls error="server returned 404: 404 page not found\n"13932026/10/05 12:09:29 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13942026/10/05 12:09:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13952026/10/05 12:09:29 WARN Failed to register uploaded object key=y4bfbvrkxvgxjr0kg886l5sxj3h41fk8.ls error="server returned 404: 404 page not found\n"13962026/10/05 12:09:29 INFO Signed narinfos id=2 count=213972026/10/05 12:09:29 WARN Failed to register uploaded object key=2pkjc5wxjc6mz7i00k4h0bxk29aqp2kk.ls error="server returned 404: 404 page not found\n"13982026/10/05 12:09:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13992026/10/05 12:09:29 INFO Uploading 4 narinfos14002026/10/05 12:09:29 INFO Signed narinfos id=1 count=314012026/10/05 12:09:29 INFO Received uploads request method=POST path=/api/pending_closures14022026/10/05 12:09:29 INFO Uploading 3 narinfos1403--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.48s)1404=== CONT TestReadProxy40414052026/10/05 12:09:29 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14062026/10/05 12:09:29 WARN Failed to register uploaded object key=rdlhlar7bsm9892sqjc5f30mjvxy6pd0.narinfo error="server returned 404: 404 page not found\n"14072026/10/05 12:09:29 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MjRjMjA4OGEtNzc2OS00MTEzLTk3MmYtMjc0NjZkZGMzMjYzLmEyMjk2NGMzLTJkNzAtNGJmMi1iNmI0LTRmZDkxZTU1MGIwZngxNzkxMjAyMTY5MTIwODk0MDYx error="Get \"http://127.0.0.1:1/bucket9/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"14082026/10/05 12:09:29 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MjRjMjA4OGEtNzc2OS00MTEzLTk3MmYtMjc0NjZkZGMzMjYzLmNkN2U0YWY5LTIwMDQtNDgyNS04OTE5LWZlYmQ3NzNhODNjYngxNzkxMjAyMTY5MDk5NzY4NDM3 parts=1214092026/10/05 12:09:29 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14102026/10/05 12:09:29 WARN Failed to register uploaded object key=6xvb38cv2j77sq2p9zc13z0fgkqk6xav.narinfo error="server returned 404: 404 page not found\n"14112026/10/05 12:09:29 WARN Failed to register uploaded object key=y4bfbvrkxvgxjr0kg886l5sxj3h41fk8.narinfo error="server returned 404: 404 page not found\n"14122026/10/05 12:09:29 WARN Failed to register uploaded object key=96wllra6xqcwwd6awz2v75mnl39l27jp.narinfo error="server returned 404: 404 page not found\n"1413--- PASS: TestGCSweepSkipsPendingObjects (0.53s)14142026/10/05 12:09:29 WARN Failed to register uploaded object key=2pkjc5wxjc6mz7i00k4h0bxk29aqp2kk.narinfo error="server returned 404: 404 page not found\n"1415=== CONT TestOrphanedObjectsGCStressTest14162026/10/05 12:09:29 WARN Failed to register uploaded object key=rdlhlar7bsm9892sqjc5f30mjvxy6pd0.narinfo error="server returned 404: 404 page not found\n"14172026/10/05 12:09:29 INFO Received cleanup request method=DELETE path=/api/pending_closures14182026/10/05 12:09:29 WARN Failed to register uploaded object key=g7ld78ki3qrfm5krl1s5cdqgmsmgr6rh.ls error="server returned 404: 404 page not found\n"14192026/10/05 12:09:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14202026/10/05 12:09:29 INFO Received complete push request method=POST path=/api/pushes/1/complete14212026/10/05 12:09:29 WARN Failed to register uploaded object key=hqav2kyfd2mmq2idgfcsd5yy3b6pcqfx.narinfo error="server returned 404: 404 page not found\n"14222026/10/05 12:09:29 INFO Signed narinfos id=1 count=114232026/10/05 12:09:29 INFO Uploading 1 narinfos14242026/10/05 12:09:29 INFO Aborted multipart uploads count=1 kept=014252026/10/05 12:09:29 INFO Completed upload id=114262026/10/05 12:09:29 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14272026/10/05 12:09:29 INFO Received complete push request method=POST path=/api/pushes/1/complete14282026/10/05 12:09:29 WARN Failed to register uploaded object key=g7ld78ki3qrfm5krl1s5cdqgmsmgr6rh.narinfo error="server returned 404: 404 page not found\n"14292026/10/05 12:09:29 INFO Completed upload id=214302026/10/05 12:09:29 INFO Upload complete. (165ms)14312026/10/05 12:09:29 INFO Upload complete. (134ms)1432=== NAME TestClientFallsBackToClosures1433 client_pushes_test.go:112: Retrieved narinfo from S3:1434 StorePath: /build/TestClientFallsBackToClosures1531852973/001/store/rdlhlar7bsm9892sqjc5f30mjvxy6pd0-shared-dep1435 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1436 Compression: zstd1437 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821438 NarSize: 1361439 References: 1440 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1441=== NAME TestClientPushesUseOnePush1442 client_pushes_test.go:97: Retrieved narinfo from S3:1443 StorePath: /build/TestClientPushesUseOnePush3917086019/001/store/y4bfbvrkxvgxjr0kg886l5sxj3h41fk8-shared-dep1444 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1445 Compression: zstd1446 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821447 NarSize: 1361448 References: 1449 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1450=== NAME TestClientFallsBackToClosures1451 client_pushes_test.go:112: Retrieved narinfo from S3:1452 StorePath: /build/TestClientFallsBackToClosures1531852973/001/store/96wllra6xqcwwd6awz2v75mnl39l27jp-a1453 URL: nar/05g2wkh8r459hfbj9v8rsb6plj6am49lc14f725q56m0jscrsrrm.nar.zst1454 Compression: zstd1455 NarHash: sha256:05g2wkh8r459hfbj9v8rsb6plj6am49lc14f725q56m0jscrsrrm1456 NarSize: 2161457 References: /build/TestClientFallsBackToClosures1531852973/001/store/rdlhlar7bsm9892sqjc5f30mjvxy6pd0-shared-dep1458 CA: text:sha256:16xz2bagwcyqdzqjcgcp1f2il7nq04xzdzcixy9sv4wkwpnsvks614592026/10/05 12:09:29 INFO Upload complete. (125ms)1460=== NAME TestClientPushesUseOnePush1461 client_pushes_test.go:97: Retrieved narinfo from S3:1462 StorePath: /build/TestClientPushesUseOnePush3917086019/001/store/2pkjc5wxjc6mz7i00k4h0bxk29aqp2kk-a1463 URL: nar/1x280jcnz4fccxhqi9k4dc2m062f44crmcq5gc9866m0f8x6b6qy.nar.zst1464 Compression: zstd1465 NarHash: sha256:1x280jcnz4fccxhqi9k4dc2m062f44crmcq5gc9866m0f8x6b6qy1466 NarSize: 2161467 References: /build/TestClientPushesUseOnePush3917086019/001/store/y4bfbvrkxvgxjr0kg886l5sxj3h41fk8-shared-dep1468 CA: text:sha256:11m68lcl9d27a0jyl0lay5qx63dgs3qpxmjw1ha64cfrddz9pkqc1469=== NAME TestClientFallsBackToClosures1470 client_pushes_test.go:112: Retrieved narinfo from S3:1471 StorePath: /build/TestClientFallsBackToClosures1531852973/001/store/6xvb38cv2j77sq2p9zc13z0fgkqk6xav-b1472 URL: nar/05g2wkh8r459hfbj9v8rsb6plj6am49lc14f725q56m0jscrsrrm.nar.zst1473 Compression: zstd1474 NarHash: sha256:05g2wkh8r459hfbj9v8rsb6plj6am49lc14f725q56m0jscrsrrm1475 NarSize: 2161476 References: /build/TestClientFallsBackToClosures1531852973/001/store/rdlhlar7bsm9892sqjc5f30mjvxy6pd0-shared-dep1477 CA: text:sha256:16xz2bagwcyqdzqjcgcp1f2il7nq04xzdzcixy9sv4wkwpnsvks61478=== NAME TestClientPushesUseOnePush1479 client_pushes_test.go:97: Retrieved narinfo from S3:1480 StorePath: /build/TestClientPushesUseOnePush3917086019/001/store/hqav2kyfd2mmq2idgfcsd5yy3b6pcqfx-b1481 URL: nar/1x280jcnz4fccxhqi9k4dc2m062f44crmcq5gc9866m0f8x6b6qy.nar.zst1482 Compression: zstd1483 NarHash: sha256:1x280jcnz4fccxhqi9k4dc2m062f44crmcq5gc9866m0f8x6b6qy1484 NarSize: 2161485 References: /build/TestClientPushesUseOnePush3917086019/001/store/y4bfbvrkxvgxjr0kg886l5sxj3h41fk8-shared-dep1486 CA: text:sha256:11m68lcl9d27a0jyl0lay5qx63dgs3qpxmjw1ha64cfrddz9pkqc1487--- PASS: TestPresentReportsOnlyClosureRoots (0.39s)1488=== CONT TestReadProxyNarStreaming14892026/10/05 12:09:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14902026/10/05 12:09:29 INFO Received create pin request method=POST path=/api/pins/app1491--- PASS: TestRedundantMultipartUpload (2.37s)1492=== CONT TestReadProxyNarinfo14932026/10/05 12:09:29 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo14942026/10/05 12:09:29 INFO Received delete pin request method=DELETE path=/api/pins/app14952026/10/05 12:09:29 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket59/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"14962026/10/05 12:09:29 INFO Received delete pin request method=DELETE path=/api/pins/app14972026/10/05 12:09:29 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MjRjMjA4OGEtNzc2OS00MTEzLTk3MmYtMjc0NjZkZGMzMjYzLjVkOTUzYWE3LTY4YmUtNDY1My1iOWEwLTcyNWYzNTNhNDdhY3gxNzkxMjAyMTY4NTE2NDUzOTc5 parts=1014982026/10/05 12:09:29 INFO Deleted pin name=app14992026/10/05 12:09:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1500=== CONT TestCreatePin_ReservedPins1501--- PASS: TestClientPushesUseOnePush (0.74s)1502--- PASS: TestClientFallsBackToClosures (0.82s)1503=== CONT TestCacheStatsHandler1504=== CONT TestClientSharedPathCommittedMidPush1505--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.40s)15062026/10/05 12:09:29 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MjRjMjA4OGEtNzc2OS00MTEzLTk3MmYtMjc0NjZkZGMzMjYzLjZjMDkyOTQ3LWRjMTAtNDZiMC05MTIyLTdlNjQ3Y2RiMTBiZngxNzkxMjAyMTY4NTQ5NjgyMTA5 parts=1015072026/10/05 12:09:29 INFO Received complete push request method=POST path=/api/pushes/1/complete15082026/10/05 12:09:29 INFO Received push request method=POST path=/api/pushes15092026/10/05 12:09:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15102026/10/05 12:09:29 INFO Uploading 46sny6c78sz5id0kyy96630yw8irdqz1-unpinned-file.txt (128B)15112026/10/05 12:09:29 INFO Received push request method=POST path=/api/pushes15122026/10/05 12:09:29 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15132026/10/05 12:09:29 WARN Failed to register uploaded object key=46sny6c78sz5id0kyy96630yw8irdqz1.ls error="server returned 404: 404 page not found\n"15142026/10/05 12:09:29 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15152026/10/05 12:09:29 INFO Signed narinfos id=2 count=115162026/10/05 12:09:29 INFO Uploading 1 narinfos15172026/10/05 12:09:29 INFO Received complete push request method=POST path=/api/pushes/2/complete15182026/10/05 12:09:29 WARN Failed to register uploaded object key=46sny6c78sz5id0kyy96630yw8irdqz1.narinfo error="server returned 404: 404 page not found\n"15192026/10/05 12:09:29 INFO Upload complete. (69ms)15202026/10/05 12:09:29 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket712976042/001/proxy.sock15212026/10/05 12:09:29 INFO Starting HTTP server address=127.0.0.1:4653715222026/10/05 12:09:29 WARN mTLS auth: subject not in bound subjects subject="CN=someone"15232026/10/05 12:09:29 INFO Shutdown signal received, draining in-flight requests timeout=10s1524--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.35s)1525=== CONT TestService_ReadAuthMiddleware15262026/10/05 12:09:30 INFO Starting cleanup of old closures method=DELETE path=/api/closures15272026/10/05 12:09:30 INFO Received create pin request method=POST path=/api/pins/app15282026/10/05 12:09:30 INFO Garbage collection started15292026/10/05 12:09:30 INFO Aborted multipart uploads count=0 kept=015302026/10/05 12:09:30 INFO Received create pin request method=POST path=/api/pins/app15312026/10/05 12:09:30 INFO Aborted multipart uploads count=0 kept=015322026/10/05 12:09:30 WARN Force mode enabled - objects will be deleted immediately without grace period15332026/10/05 12:09:30 WARN Force mode enabled - objects will be deleted immediately without grace period15342026/10/05 12:09:30 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=01535--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.66s)1536=== CONT TestClientMultipleUploads15372026/10/05 12:09:30 INFO Vacuumed table table=pending_closures1538=== CONT TestOrphanedObjectsGC1539--- PASS: TestReadProxyInvalidPath (0.29s)15402026/10/05 12:09:30 INFO Vacuumed table table=pending_objects15412026/10/05 12:09:30 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=015422026/10/05 12:09:30 INFO Vacuumed table table=multipart_uploads15432026/10/05 12:09:30 INFO Vacuumed table table=closures15442026/10/05 12:09:30 INFO Vacuumed table table=objects15452026/10/05 12:09:30 INFO Vacuumed table table=pending_closures15462026/10/05 12:09:30 INFO Vacuumed table table=pending_objects15472026/10/05 12:09:30 INFO Vacuumed table table=multipart_uploads15482026/10/05 12:09:30 INFO Vacuumed table table=closures15492026/10/05 12:09:30 INFO Vacuumed table table=objects15502026/10/05 12:09:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37959/oidc1551--- PASS: TestObjectStatsTrigger (0.30s)1552=== CONT TestClientErrorHandling1553=== RUN TestClientErrorHandling/InvalidStorePath1554=== PAUSE TestClientErrorHandling/InvalidStorePath1555=== RUN TestClientErrorHandling/InvalidAuthToken1556=== PAUSE TestClientErrorHandling/InvalidAuthToken1557=== RUN TestClientErrorHandling/ServerNotAvailable1558=== PAUSE TestClientErrorHandling/ServerNotAvailable1559=== CONT TestPendingClosureFailureAbortsItsUploads1560--- PASS: TestConnectSerialisesConcurrentMigrations (1.14s)1561=== CONT TestService_ReadScope_PublicByDefault1562--- PASS: TestReadProxyHead (0.53s)1563=== CONT TestCacheConfigHandler1564=== RUN TestCacheConfigHandler/full_config,_no_issuer1565=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1566=== RUN TestCacheConfigHandler/no_cache_url_configured1567=== PAUSE TestCacheConfigHandler/no_cache_url_configured1568=== RUN TestCacheConfigHandler/no_signing_keys1569=== PAUSE TestCacheConfigHandler/no_signing_keys1570=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1571=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1572=== CONT TestService_AuthMiddleware_OIDC1573=== CONT TestClientCADerivations1574--- PASS: TestReadProxyNarStreaming (0.33s)15752026/10/05 12:09:30 INFO lead: released remote=192.0.2.1:12341576--- PASS: TestLeadEndsOnShutdown (1.52s)1577=== CONT TestServerTLSConfig1578=== RUN TestServerTLSConfig/no_client_CA1579=== PAUSE TestServerTLSConfig/no_client_CA1580=== RUN TestServerTLSConfig/missing_CA_file1581=== PAUSE TestServerTLSConfig/missing_CA_file1582=== RUN TestServerTLSConfig/not_a_PEM_file1583=== PAUSE TestServerTLSConfig/not_a_PEM_file1584=== CONT TestMetricsInventory1585--- PASS: TestCacheStatsHandler (0.39s)1586=== CONT TestPendingCleanupUsesOneCutoff1587--- PASS: TestService_ReadAuthMiddleware (0.32s)1588=== CONT TestPendingClosureFailureTracksEveryUpload1589--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.26s)1590=== CONT TestService_NativeMTLS15912026/10/05 12:09:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45411/oidc1592=== NAME TestClientMultipleUploads1593 client_integration_test.go:480: Created store path 0: /build/TestClientMultipleUploads2635864666/001/store/h38l7pfbp48a8a49s2pkkgkh1m4px99w-test-file-0.txt15942026/10/05 12:09:30 INFO Received uploads request method=POST path=/api/pending_closures15952026/10/05 12:09:30 INFO Received push request method=POST path=/api/pushes15962026/10/05 12:09:30 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15972026/10/05 12:09:30 INFO Uploading 58rlld8841djn9j3bsm9l41faj90njh6-shared-dep (136B)15982026/10/05 12:09:30 INFO Uploading nnaxr3fcxq9v4z0wg65pcnbrlaz4z800-top (224B)1599 client_integration_test.go:480: Created store path 1: /build/TestClientMultipleUploads2635864666/001/store/6awkpx3xzh7c8pzvqcfy6shmcpp9sl59-test-file-1.txt16002026/10/05 12:09:30 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16012026/10/05 12:09:30 WARN Failed to register uploaded object key=nar/1xhsxh8knb7jb9vycxwbqxcwhkp361rxhmn5bdrx0vimfr82fkjz.nar.zst error="server returned 404: 404 page not found\n"1602--- PASS: TestService_ReadScope_PublicByDefault (0.34s)1603=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1604=== NAME TestClientMultipleUploads1605 client_integration_test.go:480: Created store path 2: /build/TestClientMultipleUploads2635864666/001/store/j24jpsh1wh8hsvwh91mgv6j0dzs2wg8l-test-file-2.txt16062026/10/05 12:09:30 WARN Failed to register uploaded object key=nnaxr3fcxq9v4z0wg65pcnbrlaz4z800.ls error="server returned 404: 404 page not found\n"16072026/10/05 12:09:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16082026/10/05 12:09:30 WARN Failed to register uploaded object key=58rlld8841djn9j3bsm9l41faj90njh6.ls error="server returned 404: 404 page not found\n"16092026/10/05 12:09:30 INFO Signed narinfos id=1 count=216102026/10/05 12:09:30 INFO Uploading 2 narinfos16112026/10/05 12:09:30 WARN Failed to register uploaded object key=nnaxr3fcxq9v4z0wg65pcnbrlaz4z800.narinfo error="server returned 404: 404 page not found\n"1612=== CONT TestService_RequireScope_OIDC1613--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.85s)1614--- PASS: TestPendingClosureFailureAbortsItsUploads (0.37s)1615=== CONT TestClientIntegration16162026/10/05 12:09:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux16172026/10/05 12:09:30 WARN Refused reserved pin name=worker-x86_64-linux16182026/10/05 12:09:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux16192026/10/05 12:09:30 INFO Received create pin request method=POST path=/api/pins/my-app16202026/10/05 12:09:30 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux16212026/10/05 12:09:30 INFO Received complete push request method=POST path=/api/pushes/1/complete16222026/10/05 12:09:30 WARN Failed to register uploaded object key=58rlld8841djn9j3bsm9l41faj90njh6.narinfo error="server returned 404: 404 page not found\n"16232026/10/05 12:09:30 INFO Upload complete. (131ms)1624=== NAME TestClientSharedPathCommittedMidPush1625 client_integration_test.go:816: Retrieved narinfo from S3:1626 StorePath: /build/TestClientSharedPathCommittedMidPush2974298808/001/store/58rlld8841djn9j3bsm9l41faj90njh6-shared-dep1627 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1628 Compression: zstd1629 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821630 NarSize: 1361631 References: 1632 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1633=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1634--- PASS: TestCreatePin_ReservedPins (0.59s)1635=== NAME TestClientSharedPathCommittedMidPush1636 client_integration_test.go:816: Retrieved narinfo from S3:1637 StorePath: /build/TestClientSharedPathCommittedMidPush2974298808/001/store/nnaxr3fcxq9v4z0wg65pcnbrlaz4z800-top1638 URL: nar/1xhsxh8knb7jb9vycxwbqxcwhkp361rxhmn5bdrx0vimfr82fkjz.nar.zst1639 Compression: zstd1640 NarHash: sha256:1xhsxh8knb7jb9vycxwbqxcwhkp361rxhmn5bdrx0vimfr82fkjz1641 NarSize: 2241642 References: /build/TestClientSharedPathCommittedMidPush2974298808/001/store/58rlld8841djn9j3bsm9l41faj90njh6-shared-dep1643 CA: text:sha256:1h1zxgkapjlaxfbfmp129jq27v7n0px9ks75nfq90d3fya2mms5y16442026/10/05 12:09:30 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo1645=== CONT TestService_AuthMiddleware_MTLSProxyHeader1646--- PASS: TestClientSharedPathCommittedMidPush (0.62s)16472026/10/05 12:09:30 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo16482026/10/05 12:09:30 INFO Received push request method=POST path=/api/pushes16492026/10/05 12:09:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36313/oidc16502026/10/05 12:09:30 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16512026/10/05 12:09:30 INFO Uploading 6awkpx3xzh7c8pzvqcfy6shmcpp9sl59-test-file-1.txt (160B)16522026/10/05 12:09:30 INFO Uploading j24jpsh1wh8hsvwh91mgv6j0dzs2wg8l-test-file-2.txt (160B)16532026/10/05 12:09:30 INFO Uploading h38l7pfbp48a8a49s2pkkgkh1m4px99w-test-file-0.txt (160B)1654--- PASS: TestConcurrentPinUpdatesAgree (0.85s)1655=== CONT TestCreatePinRejectsBadInput16562026/10/05 12:09:30 INFO Received uploads request method=POST path=/api/pending_closures16572026/10/05 12:09:30 INFO lead: released remote=192.0.2.1:123416582026/10/05 12:09:30 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16592026/10/05 12:09:30 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16602026/10/05 12:09:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16612026/10/05 12:09:30 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16622026/10/05 12:09:30 INFO Received uploads request method=POST path=/api/pending_closures16632026/10/05 12:09:30 INFO Received uploads request method=POST path=/api/pending_closures1664=== CONT TestReconnectLeavesObjectsUnlocked1665--- PASS: TestMetricsInventory (0.35s)16662026/10/05 12:09:30 WARN Failed to register uploaded object key=6awkpx3xzh7c8pzvqcfy6shmcpp9sl59.ls error="server returned 404: 404 page not found\n"16672026/10/05 12:09:30 WARN Failed to register uploaded object key=j24jpsh1wh8hsvwh91mgv6j0dzs2wg8l.ls error="server returned 404: 404 page not found\n"16682026/10/05 12:09:30 WARN Failed to register uploaded object key=h38l7pfbp48a8a49s2pkkgkh1m4px99w.ls error="server returned 404: 404 page not found\n"16692026/10/05 12:09:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16702026/10/05 12:09:30 INFO Signed narinfos id=1 count=31671=== NAME TestClientCADerivations16722026/10/05 12:09:30 INFO Uploading 3 narinfos1673 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1638569885/001/store/50hxcbflnw26qwcmy75wd14q68jv6h8r-ca-test16742026/10/05 12:09:30 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=MjRjMjA4OGEtNzc2OS00MTEzLTk3MmYtMjc0NjZkZGMzMjYzLjAxM2VjYjU0LWI4YTYtNGU3MC04MjQxLTE3MDZhOWVlYzQ4MngxNzkxMjAyMTY4NTE4MjE3MTM3 parts=1016752026/10/05 12:09:30 WARN Failed to register uploaded object key=h38l7pfbp48a8a49s2pkkgkh1m4px99w.narinfo error="server returned 404: 404 page not found\n"16762026/10/05 12:09:30 INFO Received complete push request method=POST path=/api/pushes/1/complete16772026/10/05 12:09:30 WARN Failed to register uploaded object key=6awkpx3xzh7c8pzvqcfy6shmcpp9sl59.narinfo error="server returned 404: 404 page not found\n"16782026/10/05 12:09:30 WARN Failed to register uploaded object key=j24jpsh1wh8hsvwh91mgv6j0dzs2wg8l.narinfo error="server returned 404: 404 page not found\n"16792026/10/05 12:09:30 WARN Rate limiter enabled after throttle name=s3-test rate=516802026/10/05 12:09:30 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."16812026/10/05 12:09:30 INFO lead: acquired remote=192.0.2.1:123416822026/10/05 12:09:30 INFO Received cleanup request method=DELETE path=/api/pending_closures16832026/10/05 12:09:30 INFO Upload complete. (150ms)16842026/10/05 12:09:30 INFO Received complete push request method=POST path=/api/pushes/1/complete1685=== NAME TestClientMultipleUploads1686 client_integration_test.go:491: Uploaded 3 paths in 187.304305ms16872026/10/05 12:09:30 WARN mTLS auth: subject not in bound subjects subject="CN=reader"16882026/10/05 12:09:30 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1689=== NAME TestClientCADerivations1690 client_ca_test.go:139: Found 1 dependencies (including self)1691=== CONT TestProxyWriteTimeout/narinfo1692--- PASS: TestService_NativeMTLS (0.33s)1693=== CONT TestProxyWriteTimeout/10_GiB_nar1694=== CONT TestProxyWriteTimeout/unknown_size1695=== CONT TestProxyWriteTimeout/1_GiB_nar1696=== CONT TestPendingClosureWriteTimeout/670k_objects1697=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1698--- PASS: TestProxyWriteTimeout (0.01s)1699 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1700 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1701 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1702 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1703=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1704=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1705=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1706=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1707=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1708=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1709=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1710=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1711=== CONT TestPendingClosureWriteTimeout/400_objects1712=== CONT TestPendingClosureWriteTimeout/empty1713=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17142026/10/05 12:09:30 INFO Received complete multipart upload request method=POST path=/1715=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17162026/10/05 12:09:30 INFO Received request for more parts method=POST path=/1717=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17182026/10/05 12:09:30 INFO Received uploads request method=POST path=/1719=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17202026/10/05 12:09:30 INFO Received uploads request method=POST path=/1721=== CONT TestIsValidUploadKey/narinfo1722--- PASS: TestUploadHandlersRejectInvalidKeys (0.02s)1723 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1724 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1725 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1726 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1727=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1728=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1729=== CONT TestIsValidUploadKey/traversal1730=== CONT TestIsValidUploadKey/build_log1731=== CONT TestIsValidUploadKey/build_log_question_mark1732=== CONT TestIsValidUploadKey/empty_key1733=== CONT TestIsValidUploadKey/absolute1734=== CONT TestIsValidUploadKey/build_log_home-manager_file1735=== CONT TestIsValidUploadKey/traversal_nar1736=== CONT TestIsValidUploadKey/nix-cache-info1737--- PASS: TestPush_CompleteCommitsEveryRoot (3.17s)1738=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1739=== CONT TestIsValidUploadKey/realisation_plus_in_output1740=== CONT TestIsValidUploadKey/unknown_type1741=== CONT TestIsValidUploadKey/nar_plain1742=== CONT TestIsValidUploadKey/realisation1743=== CONT TestIsValidUploadKey/nar_xz1744=== CONT TestIsValidUploadKey/listing1745=== CONT TestIsValidUploadKey/index.html1746=== CONT TestIsValidUploadKey/nar_zst1747=== CONT TestIsValidUploadKey/build_log_plus_in_name1748=== CONT TestIsValidUploadKey/build_log_equals1749=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts1750--- PASS: TestIsValidUploadKey (0.01s)1751 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1752 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1753 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1754 --- PASS: TestIsValidUploadKey/traversal (0.00s)1755 --- PASS: TestIsValidUploadKey/build_log (0.00s)1756 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1757 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1758 --- PASS: TestIsValidUploadKey/absolute (0.00s)1759 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1760 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1761 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1762 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1763 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1764 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1765 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1766 --- PASS: TestIsValidUploadKey/realisation (0.00s)1767 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1768 --- PASS: TestIsValidUploadKey/listing (0.00s)1769 --- PASS: TestIsValidUploadKey/index.html (0.00s)1770 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1771 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1772 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)17732026/10/05 12:09:30 INFO Received request for more parts method=POST path=/1774=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17752026/10/05 12:09:30 INFO Received complete multipart upload request method=POST path=/1776--- PASS: TestClientMultipleUploads (0.65s)1777=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17782026/10/05 12:09:30 INFO Received uploads request method=POST path=/17792026/10/05 12:09:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17802026/10/05 12:09:30 INFO Received uploads request method=POST path=/api/pending_closures17812026/10/05 12:09:30 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=MjRjMjA4OGEtNzc2OS00MTEzLTk3MmYtMjc0NjZkZGMzMjYzLjU3YzFkZGIxLTBmNWMtNDQ4OC05Njk1LTQxMGZiYTdhOGM5MXgxNzkxMjAyMTY5OTc4OTE3NzU4 parts=1017822026/10/05 12:09:30 INFO Received complete push request method=POST path=/api/pushes/2/complete1783=== NAME TestOrphanedObjectsGC1784 orphaned_objects_gc_test.go:290: GC Test Summary:1785 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1786 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1787 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1788 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1789 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects17902026/10/05 12:09:30 WARN Rate limiter backed off name=s3-test rate=517912026/10/05 12:09:30 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."1792--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.31s)1793=== CONT TestIsValidCachePath/narinfo1794=== CONT TestIsValidCachePath/nix-cache-info1795=== CONT TestIsValidCachePath/short_hash1796--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.24s)1797=== CONT TestIsValidCachePath/leading_slash1798=== CONT TestIsValidCachePath/wrong_extension1799=== CONT TestIsValidCachePath/empty1800=== CONT TestIsValidCachePath/invalid_char_u1801=== CONT TestIsValidCachePath/invalid_char_e1802=== CONT TestIsValidCachePath/traversal_in_middle1803=== CONT TestIsValidCachePath/ls1804=== CONT TestIsValidCachePath/random_path1805=== CONT TestIsValidCachePath/nar_bz21806=== CONT TestIsValidCachePath/nar_uncompressed1807=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1808=== CONT TestIsValidCachePath/realisation1809=== CONT TestIsValidCachePath/index.html1810=== CONT TestIsValidCachePath/traversal_parent1811=== CONT TestIsValidCachePath/nar_xz1812=== CONT TestIsValidCachePath/log1813=== CONT TestPush_RejectsBadRequests/no_objects1814=== CONT TestIsValidCachePath/nar_zst18152026/10/05 12:09:30 INFO Received push request method=POST path=/api/pushes1816=== CONT TestPush_RejectsBadRequests/no_roots1817=== CONT TestPush_RejectsBadRequests/bad_root18182026/10/05 12:09:30 INFO Received push request method=POST path=/api/pushes1819--- PASS: TestIsValidCachePath (0.01s)1820 --- PASS: TestIsValidCachePath/narinfo (0.00s)1821 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1822 --- PASS: TestIsValidCachePath/short_hash (0.00s)1823 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1824 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1825 --- PASS: TestIsValidCachePath/empty (0.00s)1826 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1827 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1828 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1829 --- PASS: TestIsValidCachePath/ls (0.00s)1830 --- PASS: TestIsValidCachePath/random_path (0.00s)1831 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1832 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1833 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1834 --- PASS: TestIsValidCachePath/realisation (0.00s)1835 --- PASS: TestIsValidCachePath/index.html (0.00s)1836 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1837 --- PASS: TestIsValidCachePath/log (0.00s)1838 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1839 --- PASS: TestIsValidCachePath/nar_zst (0.00s)18402026/10/05 12:09:30 INFO Received push request method=POST path=/api/pushes1841=== CONT TestPush_RejectsBadRequests/root_not_in_objects1842=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete18432026/10/05 12:09:30 INFO Received push request method=POST path=/api/pushes1844=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1845--- PASS: TestOrphanedObjectsGC (0.72s)18462026/10/05 12:09:30 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"1847=== CONT TestGCEndsOnShutdown/before_the_run18482026/10/05 12:09:30 WARN mTLS auth: bound subjects configured but subject DN unavailable18492026/10/05 12:09:30 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"18502026/10/05 12:09:30 INFO Received push request method=POST path=/api/pushes1851--- PASS: TestReadProxy404 (0.96s)1852=== CONT TestResolveDBConnectionString/file_when_flag_empty1853=== CONT TestResolveDBConnectionString/nothing_configured1854=== CONT TestResolveDBConnectionString/flag_wins1855=== CONT TestResolveDBConnectionString/missing_file_is_an_error1856=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1857=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1858--- PASS: TestResolveDBConnectionString (0.00s)1859 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1860 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1861 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1862 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1863 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)18642026/10/05 12:09:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1865=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows18662026/10/05 12:09:30 INFO Uploading 50hxcbflnw26qwcmy75wd14q68jv6h8r-ca-test (144B)1867--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.30s)18682026/10/05 12:09:30 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"1869--- PASS: TestPush_RejectsBadRequests (0.66s)1870 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1871 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1872 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1873 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1874=== NAME TestClientIntegration1875 client_integration_test.go:334: Created store path: /build/TestClientIntegration2582498676/002/store/llfysp3b3r9mhg62m2h66iqf9mdzai71-test-file.txt18762026/10/05 12:09:30 WARN Failed to register uploaded object key=50hxcbflnw26qwcmy75wd14q68jv6h8r.ls error="server returned 404: 404 page not found\n"18772026/10/05 12:09:30 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18782026/10/05 12:09:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18792026/10/05 12:09:30 WARN Failed to register uploaded object key=log/fgkj0qz6av9b9krmb5ls3kvmzgzh4avf-ca-test.drv error="server returned 404: 404 page not found\n"18802026/10/05 12:09:30 INFO Signed narinfos id=1 count=118812026/10/05 12:09:30 INFO Uploading 1 narinfos18822026/10/05 12:09:30 INFO Received complete push request method=POST path=/api/pushes/1/complete18832026/10/05 12:09:30 WARN Failed to register uploaded object key=50hxcbflnw26qwcmy75wd14q68jv6h8r.narinfo error="server returned 404: 404 page not found\n"18842026/10/05 12:09:30 INFO Upload complete. (122ms)1885--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.29s)1886=== CONT TestParseSingleRange/none1887=== CONT TestParseSingleRange/start_far_past_EOF1888=== CONT TestParseSingleRange/end_clamped_to_size1889=== CONT TestParseSingleRange/malformed_both_empty1890=== CONT TestParseSingleRange/malformed_end_before_start1891=== CONT TestParseSingleRange/multi-range_ignored1892=== CONT TestParseSingleRange/closed1893=== CONT TestParseSingleRange/malformed_no_dash1894=== CONT TestParseSingleRange/suffix_exceeds_size1895=== CONT TestParseSingleRange/single_byte1896=== CONT TestParseSingleRange/start_past_EOF1897=== CONT TestParseSingleRange/suffix1898=== NAME TestClientCADerivations1899 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1638569885/001/store/50hxcbflnw26qwcmy75wd14q68jv6h8r-ca-test1900 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1901 Compression: zstd1902 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1903 NarSize: 1441904 References: 1905 Deriver: /build/TestClientCADerivations1638569885/001/store/fgkj0qz6av9b9krmb5ls3kvmzgzh4avf-ca-test.drv1906 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1907 client_ca_test.go:185: Checking for realisation files in S3...1908=== CONT TestParseSingleRange/unknown_unit1909=== CONT TestParseSingleRange/open-ended1910=== CONT TestClientErrorHandling/InvalidStorePath1911--- PASS: TestParseSingleRange (0.00s)1912 --- PASS: TestParseSingleRange/none (0.00s)1913 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1914 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1915 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1916 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1917 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1918 --- PASS: TestParseSingleRange/closed (0.00s)1919 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1920 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1921 --- PASS: TestParseSingleRange/single_byte (0.00s)1922 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1923 --- PASS: TestParseSingleRange/suffix (0.00s)1924 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1925 --- PASS: TestParseSingleRange/open-ended (0.00s)1926=== NAME TestClientCADerivations1927 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1928 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1929=== RUN TestService_RequireScope_OIDC/builder_may_write1930=== PAUSE TestService_RequireScope_OIDC/builder_may_write1931=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1932=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1933=== RUN TestService_RequireScope_OIDC/ops_may_admin1934=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1935=== RUN TestService_RequireScope_OIDC/ops_may_not_write1936=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1937=== RUN TestService_RequireScope_OIDC/reader_may_not_write1938=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1939=== RUN TestService_RequireScope_OIDC/static_token_may_admin1940=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1941=== RUN TestService_RequireScope_OIDC/static_token_may_write1942=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1943=== RUN TestService_RequireScope_OIDC/reader_may_read1944=== PAUSE TestService_RequireScope_OIDC/reader_may_read1945=== RUN TestService_RequireScope_OIDC/writer_implies_read1946=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1947=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1948=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1949=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1950=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1951=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1952=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1953=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1954=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1955=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1956=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1957=== CONT TestClientErrorHandling/ServerNotAvailable19582026/10/05 12:09:30 INFO Received push request method=POST path=/api/pushes19592026/10/05 12:09:30 INFO Received create pin request method=POST path=/api/pins/deploy19602026/10/05 12:09:30 INFO Received create pin request method=POST path=/api/pins/deploy19612026/10/05 12:09:30 INFO Received create pin request method=POST path=/api/pins/deploy19622026/10/05 12:09:30 INFO Received create pin request method=POST path=/api/pins/deploy19632026/10/05 12:09:30 INFO Received create pin request method=POST path=/api/pins/deploy19642026/10/05 12:09:30 INFO Received create pin request method=POST path=/api/pins/deploy19652026/10/05 12:09:30 INFO Received create pin request method=POST path=/api/pins/deploy19662026/10/05 12:09:30 INFO Received create pin request method=POST path=/api/pins/deploy19672026/10/05 12:09:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19682026/10/05 12:09:30 INFO Uploading llfysp3b3r9mhg62m2h66iqf9mdzai71-test-file.txt (152B)1969=== NAME TestClientCADerivations1970 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1971 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1972 error: binary cache 's3://bucket78?endpoint=http://localhost:44927®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1638569885/001/store'1973 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 119742026/10/05 12:09:30 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"19752026/10/05 12:09:30 WARN Failed to register uploaded object key=llfysp3b3r9mhg62m2h66iqf9mdzai71.ls error="server returned 404: 404 page not found\n"19762026/10/05 12:09:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19772026/10/05 12:09:30 INFO Signed narinfos id=1 count=119782026/10/05 12:09:30 INFO Uploading 1 narinfos19792026/10/05 12:09:30 INFO Received uploads request method=POST path=/api/pending_closures19802026/10/05 12:09:30 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/present19812026/10/05 12:09:30 INFO Received complete push request method=POST path=/api/pushes/1/complete19822026/10/05 12:09:30 WARN Failed to register uploaded object key=llfysp3b3r9mhg62m2h66iqf9mdzai71.narinfo error="server returned 404: 404 page not found\n"19832026/10/05 12:09:30 INFO Upload complete. (125ms)1984--- PASS: TestReconnectLeavesObjectsUnlocked (0.34s)1985=== CONT TestClientErrorHandling/InvalidAuthToken1986=== CONT TestCacheConfigHandler/full_config,_no_issuer1987--- PASS: TestClientCADerivations (0.76s)1988=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1989=== CONT TestCacheConfigHandler/no_cache_url_configured1990=== CONT TestCacheConfigHandler/no_signing_keys1991=== CONT TestServerTLSConfig/not_a_PEM_file1992--- PASS: TestCacheConfigHandler (0.00s)1993 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1994 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1995 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1996 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1997=== CONT TestServerTLSConfig/missing_CA_file1998=== CONT TestServerTLSConfig/no_client_CA1999=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2000--- PASS: TestServerTLSConfig (0.00s)2001 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2002 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2003 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2004=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20052026/10/05 12:09:30 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]2006=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20072026/10/05 12:09:30 INFO Received create pin request method=POST path=/api/pins/deploy20082026/10/05 12:09:30 WARN Authentication failed token_preview=eyJhbGciOi...XjY7Fwo8BA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2009=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2010=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2011=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2012=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read20132026/10/05 12:09:31 WARN Authentication failed token_preview=wrong token_length=5 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2014=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2015=== CONT TestService_RequireScope_OIDC/static_token_may_write2016=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2017=== CONT TestService_RequireScope_OIDC/reader_may_read2018=== CONT TestService_RequireScope_OIDC/writer_implies_read2019=== CONT TestService_RequireScope_OIDC/ops_may_admin2020=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2021=== CONT TestService_RequireScope_OIDC/static_token_may_admin2022=== CONT TestService_RequireScope_OIDC/reader_may_not_write2023=== CONT TestService_RequireScope_OIDC/ops_may_not_write2024=== CONT TestService_RequireScope_OIDC/builder_may_write20252026/10/05 12:09:31 INFO Aborted multipart uploads count=0 kept=020262026/10/05 12:09:31 WARN Force mode enabled - objects will be deleted immediately without grace period2027--- PASS: TestService_AuthMiddleware_OIDC (0.59s)2028 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2029 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2030 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)2031 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)20322026/10/05 12:09:31 INFO All 1 paths already cached20332026-10-05 12:09:31.020 UTC [2158] ERROR: canceling statement due to user request20342026-10-05 12:09:31.020 UTC [2158] CONTEXT: SQL statement "UPDATE object_stats2035 SET object_count = object_count + d_count,2036 total_bytes = total_bytes + d_bytes2037 WHERE id"2038 PL/pgSQL function object_stats_apply() line 17 at SQL statement20392026-10-05 12:09:31.020 UTC [2158] STATEMENT: -- name: MarkStaleObjects :execrows2040 WITH RECURSIVE ct AS (2041 SELECT timezone('UTC', now()) AS now2042 ),2043 closure_reach AS (2044 -- Start with all closure keys2045 SELECT o.key, o.refs2046 FROM objects o2047 INNER JOIN closures c ON o.key = c.key2048 UNION2049 -- Recursively add all referenced objects2050 SELECT o.key, o.refs2051 FROM objects o2052 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2053 ),2054 reachable_objects AS (2055 SELECT DISTINCT key FROM closure_reach2056 ),2057 stale_objects AS (2058 SELECT o.key2059 FROM objects AS o, ct2060 WHERE2061 NOT EXISTS (2062 SELECT 12063 FROM reachable_objects ro2064 WHERE ro.key = o.key2065 )2066 AND NOT EXISTS (2067 SELECT 12068 FROM pending_objects AS po2069 WHERE po.key = o.key2070 )2071 AND o.deleted_at IS NULL -- Only mark fresh objects2072 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2073 FOR UPDATE2074 )2075 UPDATE objects2076 SET2077 deleted_at = ct.now,2078 first_deleted_at = COALESCE(first_deleted_at, ct.now)2079 FROM stale_objects, ct2080 WHERE objects.key = stale_objects.key2081 2082=== NAME TestClientIntegration2083 client_integration_test.go:360: Retrieved narinfo from S3:2084 StorePath: /build/TestClientIntegration2582498676/002/store/llfysp3b3r9mhg62m2h66iqf9mdzai71-test-file.txt2085 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2086 Compression: zstd2087 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12088 NarSize: 1522089 References: 2090 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12091--- PASS: TestService_RequireScope_OIDC (0.41s)2092 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2093 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2094 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2095 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2096 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2097 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2098 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2099 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2100 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2101 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2102 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2103 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2104 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2105 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2106=== NAME TestClientIntegration2107 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)2108 client_integration_test.go:361: Decompressed .ls content (64 bytes):2109 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}21102026/10/05 12:09:31 INFO Received uploads request method=POST path=/api/pending_closures21112026/10/05 12:09:31 INFO Aborted multipart uploads count=0 kept=021122026/10/05 12:09:31 WARN Force mode enabled - objects will be deleted immediately without grace period21132026/10/05 12:09:31 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=021142026/10/05 12:09:31 INFO Vacuumed table table=pending_closures21152026/10/05 12:09:31 INFO Vacuumed table table=pending_objects21162026/10/05 12:09:31 INFO Vacuumed table table=multipart_uploads21172026/10/05 12:09:31 INFO Vacuumed table table=closures21182026/10/05 12:09:31 INFO Vacuumed table table=objects21192026/10/05 12:09:31 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=205.501095ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21202026/10/05 12:09:31 INFO Received push request method=POST path=/api/pushes21212026/10/05 12:09:31 INFO Object in database but missing from S3 key=llfysp3b3r9mhg62m2h66iqf9mdzai71.ls21222026/10/05 12:09:31 WARN Found objects in DB but missing from S3, will re-upload count=121232026/10/05 12:09:31 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21242026/10/05 12:09:31 INFO Received uploads request method=POST path=/api/pending_closures21252026/10/05 12:09:31 INFO Aborted multipart uploads count=0 kept=021262026/10/05 12:09:31 WARN Force mode enabled - objects will be deleted immediately without grace period21272026/10/05 12:09:31 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=021282026/10/05 12:09:31 INFO Received complete push request method=POST path=/api/pushes/2/complete21292026/10/05 12:09:31 INFO Vacuumed table table=pending_closures21302026/10/05 12:09:31 WARN Failed to register uploaded object key=llfysp3b3r9mhg62m2h66iqf9mdzai71.ls error="server returned 404: 404 page not found\n"21312026/10/05 12:09:31 INFO Vacuumed table table=pending_objects21322026/10/05 12:09:31 INFO Vacuumed table table=multipart_uploads21332026/10/05 12:09:31 INFO Upload complete. (76ms)21342026/10/05 12:09:31 INFO Vacuumed table table=closures21352026/10/05 12:09:31 INFO Vacuumed table table=objects2136 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)2137 client_integration_test.go:389: Decompressed .ls content (49 bytes):2138 {"version":1,"root":{"type":"regular","size":39}}21392026/10/05 12:09:31 INFO Aborted multipart uploads count=0 kept=021402026/10/05 12:09:31 WARN Force mode enabled - objects will be deleted immediately without grace period21412026/10/05 12:09:31 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:44927/bucket97/?delete=\": context canceled"2142--- PASS: TestPendingClosureFailureTracksEveryUpload (0.85s)2143--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2144 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.30s)2145 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.38s)2146--- PASS: TestGCEndsOnShutdown (0.00s)2147 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.26s)2148 --- PASS: TestGCEndsOnShutdown/before_the_run (0.29s)2149 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.41s)21502026/10/05 12:09:31 INFO Received push request method=POST path=/api/pushes21512026/10/05 12:09:31 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21522026/10/05 12:09:31 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21532026/10/05 12:09:31 INFO Received complete push request method=POST path=/api/pushes/3/complete21542026/10/05 12:09:31 WARN Failed to register uploaded object key=llfysp3b3r9mhg62m2h66iqf9mdzai71.ls error="server returned 404: 404 page not found\n"21552026/10/05 12:09:31 INFO Upload complete. (63ms)2156=== NAME TestClientIntegration2157 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)2158 client_integration_test.go:405: Decompressed .ls content (49 bytes):2159 {"version":1,"root":{"type":"regular","size":39}}21602026/10/05 12:09:31 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=372.40171ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21612026/10/05 12:09:31 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21622026/10/05 12:09:31 INFO Received push request method=POST path=/api/pushes21632026/10/05 12:09:31 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21642026/10/05 12:09:31 INFO Uploading m6r1i6srxn38iaz280xkv5q8mdvg3wcx-lost-commit.txt (152B)21652026/10/05 12:09:31 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"21662026/10/05 12:09:31 WARN Failed to register uploaded object key=m6r1i6srxn38iaz280xkv5q8mdvg3wcx.ls error="server returned 404: 404 page not found\n"21672026/10/05 12:09:31 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign21682026/10/05 12:09:31 INFO Signed narinfos id=4 count=121692026/10/05 12:09:31 INFO Uploading 1 narinfos21702026/10/05 12:09:31 INFO Received complete push request method=POST path=/api/pushes/4/complete21712026/10/05 12:09:31 WARN Failed to register uploaded object key=m6r1i6srxn38iaz280xkv5q8mdvg3wcx.narinfo error="server returned 404: 404 page not found\n"21722026/10/05 12:09:31 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=1677721621732026/10/05 12:09:31 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://127.0.0.1:41351/api/pushes/4/complete\": EOF" url=http://127.0.0.1:41351/api/pushes/4/complete2174--- PASS: TestReadProxyNarinfo (1.59s)21752026/10/05 12:09:31 INFO Received complete push request method=POST path=/api/pushes/4/complete21762026-10-05 12:09:31.561 UTC [1701] ERROR: Push does not exist: id=421772026-10-05 12:09:31.561 UTC [1701] CONTEXT: PL/pgSQL function commit_push(bigint) line 9 at RAISE21782026-10-05 12:09:31.561 UTC [1701] STATEMENT: -- name: CommitPush :exec2179 SELECT commit_push($1::bigint)2180 21812026/10/05 12:09:31 INFO Upload complete. (228ms)2182=== NAME TestClientIntegration2183 client_integration_test.go:435: Retrieved narinfo from S3:2184 StorePath: /build/TestClientIntegration2582498676/002/store/m6r1i6srxn38iaz280xkv5q8mdvg3wcx-lost-commit.txt2185 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst2186 Compression: zstd2187 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2188 NarSize: 1522189 References: 2190 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2191 client_integration_test.go:438: Testing garbage collection...21922026/10/05 12:09:31 INFO Starting cleanup of old closures method=DELETE path=/api/closures21932026/10/05 12:09:31 INFO Garbage collection started21942026/10/05 12:09:31 INFO Aborted multipart uploads count=0 kept=021952026/10/05 12:09:31 WARN Force mode enabled - objects will be deleted immediately without grace period21962026/10/05 12:09:31 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=021972026/10/05 12:09:31 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=772.644353ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21982026/10/05 12:09:31 INFO Vacuumed table table=pending_closures21992026/10/05 12:09:31 INFO Vacuumed table table=pending_objects22002026/10/05 12:09:31 INFO Vacuumed table table=multipart_uploads22012026/10/05 12:09:31 INFO Vacuumed table table=closures22022026/10/05 12:09:31 INFO Vacuumed table table=objects22032026/10/05 12:09:31 INFO Received create pin request method=POST path=/api/pins/deploy22042026/10/05 12:09:31 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo22052026/10/05 12:09:31 INFO lead: released remote=192.0.2.1:12342206--- PASS: TestCreatePinRejectsBadInput (1.13s)2207--- PASS: TestLeadElectsOneAndHandsOver (2.65s)2208--- PASS: TestPendingClosureWriteTimeout (0.01s)2209 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2210 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2211 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2212 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.11s)22132026/10/05 12:09:32 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=022142026/10/05 12:09:32 INFO Received create pin request method=POST path=/api/pins/myapp22152026/10/05 12:09:32 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3982918121/001/store/g7ld78ki3qrfm5krl1s5cdqgmsmgr6rh-pinned-file.txt narinfo_key=g7ld78ki3qrfm5krl1s5cdqgmsmgr6rh.narinfo22162026/10/05 12:09:32 INFO Starting cleanup of old closures method=DELETE path=/api/closures22172026/10/05 12:09:32 INFO Garbage collection started22182026/10/05 12:09:32 INFO Aborted multipart uploads count=0 kept=022192026/10/05 12:09:32 WARN Force mode enabled - objects will be deleted immediately without grace period22202026/10/05 12:09:32 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=022212026/10/05 12:09:32 INFO Vacuumed table table=pending_closures22222026/10/05 12:09:32 INFO Vacuumed table table=pending_objects22232026/10/05 12:09:32 INFO Vacuumed table table=multipart_uploads22242026/10/05 12:09:32 INFO Vacuumed table table=closures22252026/10/05 12:09:32 INFO Vacuumed table table=objects2226=== NAME TestOrphanedObjectsGCStressTest2227 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2228 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion22292026/10/05 12:09:32 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.650120819s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2230 orphaned_objects_gc_test.go:509: Stress test completed successfully:2231 orphaned_objects_gc_test.go:510: - Active objects preserved: 202232 orphaned_objects_gc_test.go:511: - Objects deleted: 2102233 orphaned_objects_gc_test.go:512: - Total GC'd: 2102234--- PASS: TestOrphanedObjectsGCStressTest (2.83s)2235--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.13s)22362026/10/05 12:09:33 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02237=== NAME TestClientIntegration2238 client_integration_test.go:445: Objects in database after GC:2239 client_integration_test.go:445: Successfully deleted all objects with GC --force2240--- PASS: TestClientIntegration (3.16s)22412026/10/05 12:09:34 WARN Rate limiter enabled after throttle name=s3-test rate=522422026/10/05 12:09:34 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2243=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2244 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102245 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002246=== NAME TestPinProtectsFromGC2247 client_integration_test.go:976: Pin successfully protected closure from garbage collection2248--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.54s)2249--- PASS: TestPinProtectsFromGC (4.89s)22502026/10/05 12:09:34 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-config22512026/10/05 12:09:34 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=218.655812ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2252--- PASS: TestConnectWaitsForAPeerMigration (5.23s)22532026/10/05 12:09:34 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=425.207962ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22542026/10/05 12:09:34 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=801.959409ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22552026/10/05 12:09:35 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.705850266s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22562026/10/05 12:09:36 INFO Aborted multipart uploads count=1 kept=022572026/10/05 12:09:36 INFO Received cleanup request method=DELETE path=/api/pending_closures22582026/10/05 12:09:36 INFO Aborted multipart uploads count=1 kept=02259--- PASS: TestPendingCleanupUsesOneCutoff (6.39s)22602026/10/05 12:09:37 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"22612026/10/05 12:09:37 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-config22622026/10/05 12:09:37 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=213.174345ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22632026/10/05 12:09:37 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=436.883602ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2264--- PASS: TestUploadHandlersRejectOversizedBody (0.57s)2265 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.79s)2266 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.79s)2267 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (7.27s)22682026/10/05 12:09:38 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=878.03932ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22692026/10/05 12:09:39 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.737389635s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22702026/10/05 12:09:40 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_closures22712026/10/05 12:09:40 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=219.971956ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22722026/10/05 12:09:41 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=411.909051ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22732026/10/05 12:09:41 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=756.786403ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22742026/10/05 12:09:42 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.562042856s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2275--- PASS: TestClientErrorHandling (0.00s)2276 --- PASS: TestClientErrorHandling/InvalidStorePath (0.29s)2277 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.34s)2278 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.97s)2279PASS2280{"timestamp":"2026-10-05T12:09:43.859693783Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:47446","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(396)"}22812026-10-05 12:09:44.285 UTC [170] LOG: received smart shutdown request22822026-10-05 12:09:44.291 UTC [170] LOG: background worker "logical replication launcher" (PID 180) exited with exit code 122832026-10-05 12:09:44.304 UTC [175] LOG: shutting down22842026-10-05 12:09:44.305 UTC [175] LOG: checkpoint starting: shutdown immediate22852026-10-05 12:09:45.247 UTC [175] LOG: checkpoint complete: wrote 10802 buffers (65.9%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 29 recycled; write=0.269 s, sync=0.627 s, total=0.942 s; sync files=33698, longest=0.069 s, average=0.001 s; distance=471866 kB, estimate=471866 kB; lsn=0/1E434870, redo lsn=0/1E43487022862026-10-05 12:09:45.330 UTC [170] LOG: database system is shut down2287Running OIDC tests...2288=== RUN TestAudienceForIssuer2289=== PAUSE TestAudienceForIssuer2290=== RUN TestHTTPClientForHasTimeouts2291=== PAUSE TestHTTPClientForHasTimeouts2292=== RUN TestGlobMatch2293=== PAUSE TestGlobMatch2294=== RUN TestValidateToken_ValidToken2295=== PAUSE TestValidateToken_ValidToken2296=== RUN TestValidateToken_WrongAudience2297=== PAUSE TestValidateToken_WrongAudience2298=== RUN TestValidateToken_Expired2299=== PAUSE TestValidateToken_Expired2300=== RUN TestValidateToken_BoundClaimsMismatch2301=== PAUSE TestValidateToken_BoundClaimsMismatch2302=== RUN TestValidateToken_BoundSubjectMismatch2303=== PAUSE TestValidateToken_BoundSubjectMismatch2304=== RUN TestValidateToken_MultipleProviders2305=== PAUSE TestValidateToken_MultipleProviders2306=== RUN TestValidateToken_NoMatchingProvider2307=== PAUSE TestValidateToken_NoMatchingProvider2308=== RUN TestValidateToken_KubernetesServiceAccount2309=== PAUSE TestValidateToken_KubernetesServiceAccount2310=== RUN TestNewValidator_KubernetesRequiresCA2311=== PAUSE TestNewValidator_KubernetesRequiresCA2312=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2313=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2314=== RUN TestPins_ReservedForMatchingRule2315=== PAUSE TestPins_ReservedForMatchingRule2316=== RUN TestPins_TopLevelShorthand2317=== PAUSE TestPins_TopLevelShorthand2318=== RUN TestPins_ConfigValidation2319=== PAUSE TestPins_ConfigValidation2320=== RUN TestScopes_LegacyProviderDefaultsToWrite2321=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2322=== RUN TestScopes_Rules2323=== PAUSE TestScopes_Rules2324=== RUN TestScopes_ConfigValidation2325=== PAUSE TestScopes_ConfigValidation2326=== CONT TestValidateToken_WrongAudience2327=== CONT TestValidateToken_Expired2328=== CONT TestValidateToken_KubernetesServiceAccount2329=== CONT TestScopes_ConfigValidation2330=== CONT TestGlobMatch2331=== RUN TestGlobMatch/foo_foo2332=== PAUSE TestGlobMatch/foo_foo2333=== RUN TestGlobMatch/foo_bar2334=== PAUSE TestGlobMatch/foo_bar2335=== RUN TestGlobMatch/*_2336=== PAUSE TestGlobMatch/*_2337=== RUN TestGlobMatch/*_anything2338=== CONT TestScopes_Rules2339=== CONT TestPins_ConfigValidation2340=== CONT TestHTTPClientForHasTimeouts2341=== CONT TestPins_TopLevelShorthand2342=== CONT TestPins_ReservedForMatchingRule2343=== CONT TestScopes_LegacyProviderDefaultsToWrite2344=== CONT TestAudienceForIssuer2345=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2346=== CONT TestValidateToken_BoundSubjectMismatch2347=== CONT TestNewValidator_KubernetesRequiresCA2348=== CONT TestValidateToken_NoMatchingProvider2349=== CONT TestValidateToken_MultipleProviders2350=== CONT TestValidateToken_BoundClaimsMismatch2351=== CONT TestValidateToken_ValidToken2352=== PAUSE TestGlobMatch/*_anything2353--- PASS: TestScopes_ConfigValidation (0.00s)2354--- PASS: TestPins_ConfigValidation (0.00s)2355--- PASS: TestAudienceForIssuer (0.00s)2356=== RUN TestGlobMatch/foo*_foo2357=== PAUSE TestGlobMatch/foo*_foo2358=== RUN TestGlobMatch/foo*_foobar2359=== PAUSE TestGlobMatch/foo*_foobar2360=== RUN TestGlobMatch/foo*_bar2361=== PAUSE TestGlobMatch/foo*_bar2362=== RUN TestGlobMatch/*bar_bar2363=== PAUSE TestGlobMatch/*bar_bar2364=== RUN TestGlobMatch/*bar_foobar2365=== PAUSE TestGlobMatch/*bar_foobar2366=== RUN TestGlobMatch/*bar_foo2367=== PAUSE TestGlobMatch/*bar_foo2368=== RUN TestGlobMatch/foo*bar_foobar2369=== PAUSE TestGlobMatch/foo*bar_foobar2370=== RUN TestGlobMatch/foo*bar_foo123bar2371=== PAUSE TestGlobMatch/foo*bar_foo123bar2372=== RUN TestGlobMatch/foo*bar_foobarbaz2373=== PAUSE TestGlobMatch/foo*bar_foobarbaz2374=== RUN TestGlobMatch/*/*_foo/bar2375=== PAUSE TestGlobMatch/*/*_foo/bar2376=== RUN TestGlobMatch/*/*_foo2377=== PAUSE TestGlobMatch/*/*_foo2378=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2379=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2380=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02381=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02382=== RUN TestGlobMatch/refs/*/main_refs/heads/main2383=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2384=== RUN TestGlobMatch/fo?_foo2385=== PAUSE TestGlobMatch/fo?_foo2386=== RUN TestGlobMatch/fo?_fo2387=== PAUSE TestGlobMatch/fo?_fo2388=== RUN TestGlobMatch/fo?_fooo2389=== PAUSE TestGlobMatch/fo?_fooo2390=== RUN TestGlobMatch/?oo_foo2391=== PAUSE TestGlobMatch/?oo_foo2392=== RUN TestGlobMatch/?oo_boo2393=== PAUSE TestGlobMatch/?oo_boo2394=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2395=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2396=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2397=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2398=== CONT TestGlobMatch/*_2399=== CONT TestGlobMatch/foo*bar_foobarbaz2400=== CONT TestGlobMatch/*bar_bar2401=== CONT TestGlobMatch/*/*_foo2402=== CONT TestGlobMatch/foo*bar_foo123bar2403=== CONT TestGlobMatch/*bar_foo2404=== CONT TestGlobMatch/foo*bar_foobar2405=== CONT TestGlobMatch/*bar_foobar2406=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2407=== CONT TestGlobMatch/fo?_foo2408=== CONT TestGlobMatch/*_anything2409=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2410=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02411=== CONT TestGlobMatch/?oo_boo2412=== CONT TestGlobMatch/?oo_foo2413=== CONT TestGlobMatch/*/*_foo/bar2414=== CONT TestGlobMatch/foo*_foo2415=== CONT TestGlobMatch/foo_foo2416=== CONT TestGlobMatch/fo?_fooo2417=== CONT TestGlobMatch/foo*_foobar2418=== CONT TestGlobMatch/fo?_fo2419=== CONT TestGlobMatch/foo*_bar2420=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2421=== CONT TestGlobMatch/foo_bar2422=== CONT TestGlobMatch/refs/*/main_refs/heads/main2423--- PASS: TestGlobMatch (0.02s)2424 --- PASS: TestGlobMatch/*_ (0.00s)2425 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2426 --- PASS: TestGlobMatch/*bar_bar (0.00s)2427 --- PASS: TestGlobMatch/*/*_foo (0.00s)2428 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2429 --- PASS: TestGlobMatch/*bar_foo (0.00s)2430 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2431 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2432 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2433 --- PASS: TestGlobMatch/fo?_foo (0.00s)2434 --- PASS: TestGlobMatch/*_anything (0.00s)2435 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2436 --- PASS: TestGlobMatch/?oo_boo (0.00s)2437 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2438 --- PASS: TestGlobMatch/?oo_foo (0.00s)2439 --- PASS: TestGlobMatch/foo*_foo (0.00s)2440 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2441 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2442 --- PASS: TestGlobMatch/foo_foo (0.00s)2443 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2444 --- PASS: TestGlobMatch/fo?_fo (0.00s)2445 --- PASS: TestGlobMatch/foo*_bar (0.00s)2446 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2447 --- PASS: TestGlobMatch/foo_bar (0.00s)2448 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)24492026/10/05 12:09:48 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12324502026/10/05 12:09:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36647/oidc2451--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.04s)2452--- PASS: TestPins_TopLevelShorthand (0.04s)24532026/10/05 12:09:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40607/oidc24542026/10/05 12:09:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37773/oidc2455--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.05s)2456--- PASS: TestScopes_Rules (0.06s)24572026/10/05 12:09:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35257/oidc2458--- PASS: TestValidateToken_BoundSubjectMismatch (0.07s)24592026/10/05 12:09:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46549/oidc2460--- PASS: TestValidateToken_WrongAudience (0.12s)24612026/10/05 12:09:48 http: TLS handshake error from 127.0.0.1:50696: remote error: tls: bad certificate2462--- PASS: TestNewValidator_KubernetesRequiresCA (0.12s)24632026/10/05 12:09:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45481/oidc24642026/10/05 12:09:48 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:403272465--- PASS: TestValidateToken_Expired (0.13s)2466--- PASS: TestValidateToken_KubernetesServiceAccount (0.14s)24672026/10/05 12:09:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42705/oidc2468--- PASS: TestValidateToken_ValidToken (0.14s)24692026/10/05 12:09:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45037/oidc2470--- PASS: TestPins_ReservedForMatchingRule (0.16s)24712026/10/05 12:09:48 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38971/oidc2472--- PASS: TestValidateToken_BoundClaimsMismatch (0.19s)2473--- PASS: TestHTTPClientForHasTimeouts (0.20s)24742026/10/05 12:09:48 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45385/oidc2475--- PASS: TestValidateToken_NoMatchingProvider (0.24s)24762026/10/05 12:09:48 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46489/oidc24772026/10/05 12:09:48 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:38911/oidc2478--- PASS: TestValidateToken_MultipleProviders (0.31s)2479PASS2480Running signing tests...2481=== RUN TestGenerateFingerprint2482=== PAUSE TestGenerateFingerprint2483=== RUN TestParseSigningKey2484=== PAUSE TestParseSigningKey2485=== RUN TestSignMessage2486=== PAUSE TestSignMessage2487=== RUN TestSignNarinfo2488=== PAUSE TestSignNarinfo2489=== CONT TestGenerateFingerprint2490=== CONT TestSignNarinfo2491=== CONT TestParseSigningKey2492=== RUN TestGenerateFingerprint/basic_with_references2493=== CONT TestSignMessage2494=== PAUSE TestGenerateFingerprint/basic_with_references2495=== RUN TestParseSigningKey/valid_32-byte_key2496=== RUN TestGenerateFingerprint/no_references2497=== PAUSE TestGenerateFingerprint/no_references2498=== PAUSE TestParseSigningKey/valid_32-byte_key2499=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2500=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2501=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2502=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2503=== RUN TestParseSigningKey/no_colon2504=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2505=== PAUSE TestParseSigningKey/no_colon2506=== RUN TestParseSigningKey/empty_name2507=== PAUSE TestParseSigningKey/empty_name2508=== RUN TestParseSigningKey/invalid_base642509=== PAUSE TestParseSigningKey/invalid_base642510=== RUN TestParseSigningKey/wrong_length2511=== PAUSE TestParseSigningKey/wrong_length2512=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2513=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2514=== CONT TestParseSigningKey/no_colon2515=== CONT TestParseSigningKey/wrong_length2516=== RUN TestGenerateFingerprint/invalid_nar_hash_length2517=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2518=== CONT TestParseSigningKey/invalid_base642519=== CONT TestParseSigningKey/valid_32-byte_key2520=== CONT TestParseSigningKey/empty_name2521=== RUN TestGenerateFingerprint/invalid_store_path_prefix2522--- PASS: TestSignMessage (0.00s)2523=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2524--- PASS: TestSignNarinfo (0.00s)2525=== RUN TestGenerateFingerprint/invalid_reference_prefix2526=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2527--- PASS: TestParseSigningKey (0.00s)2528 --- PASS: TestParseSigningKey/no_colon (0.00s)2529 --- PASS: TestParseSigningKey/wrong_length (0.00s)2530 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2531 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2532 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2533 --- PASS: TestParseSigningKey/empty_name (0.00s)2534=== CONT TestGenerateFingerprint/basic_with_references2535=== CONT TestGenerateFingerprint/invalid_store_path_prefix2536=== CONT TestGenerateFingerprint/no_references2537=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2538=== CONT TestGenerateFingerprint/invalid_nar_hash_length2539=== CONT TestGenerateFingerprint/invalid_reference_prefix2540=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2541--- PASS: TestGenerateFingerprint (0.00s)2542 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2543 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2544 --- PASS: TestGenerateFingerprint/no_references (0.00s)2545 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2546 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2547 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2548 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2549PASS2550Running hook tests...2551=== RUN TestSendPathsEmpty2552=== PAUSE TestSendPathsEmpty2553=== RUN TestQueueEnqueueAndFetch2554=== PAUSE TestQueueEnqueueAndFetch2555=== RUN TestQueueDeduplication2556=== PAUSE TestQueueDeduplication2557=== RUN TestQueueRemove2558=== PAUSE TestQueueRemove2559=== RUN TestQueueFetchBatchLimit2560=== PAUSE TestQueueFetchBatchLimit2561=== RUN TestQueueRetryMovesToBack2562=== PAUSE TestQueueRetryMovesToBack2563=== RUN TestQueueFetchRemoveLifecycle2564=== PAUSE TestQueueFetchRemoveLifecycle2565=== RUN TestQueueConcurrentWriters2566=== PAUSE TestQueueConcurrentWriters2567=== RUN TestQueueEnqueueWaitsOutSlowWriter2568=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2569=== RUN TestQueueRemoveLargeClosure2570=== PAUSE TestQueueRemoveLargeClosure2571=== RUN TestServerClientIntegration2572=== PAUSE TestServerClientIntegration2573=== RUN TestServerQueueError2574=== PAUSE TestServerQueueError2575=== RUN TestServerRefusesOversizedAndNonStoreRequests2576=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2577=== RUN TestGetListenerSocketActivation2578 server_test.go:317: === RUN TestGetListenerSocketActivation2579 --- PASS: TestGetListenerSocketActivation (0.00s)2580 PASS2581 2582--- PASS: TestGetListenerSocketActivation (1.02s)2583=== RUN TestServerStalledClientDoesNotBlockShutdown2584=== PAUSE TestServerStalledClientDoesNotBlockShutdown2585=== RUN TestServerBacksOffOnAcceptErrors2586=== PAUSE TestServerBacksOffOnAcceptErrors2587=== RUN TestDrainIsolatesPoisonPath2588=== PAUSE TestDrainIsolatesPoisonPath2589=== RUN TestRunNotBlockedByPoisonHead2590=== PAUSE TestRunNotBlockedByPoisonHead2591=== RUN TestDrainGivesUpWhenServerDown2592=== PAUSE TestDrainGivesUpWhenServerDown2593=== RUN TestFailedPathPrunedByLaterClosure2594=== PAUSE TestFailedPathPrunedByLaterClosure2595=== RUN TestWorkerUploadsAndRemoves2596=== PAUSE TestWorkerUploadsAndRemoves2597=== RUN TestWorkerSkipsGCdPaths2598=== PAUSE TestWorkerSkipsGCdPaths2599=== RUN TestWorkerPrunesClosureDeps2600=== PAUSE TestWorkerPrunesClosureDeps2601=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2602=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2603=== RUN TestDrainTimeout2604=== PAUSE TestDrainTimeout2605=== RUN TestDrainTimeoutDuringIsolation2606=== PAUSE TestDrainTimeoutDuringIsolation2607=== RUN TestShutdownFinishesInFlightPush2608=== PAUSE TestShutdownFinishesInFlightPush2609=== RUN TestWorkerRemoveFailureIsNotProgress2610=== PAUSE TestWorkerRemoveFailureIsNotProgress2611=== RUN TestWorkerKeepsPathItCannotStat2612=== PAUSE TestWorkerKeepsPathItCannotStat2613=== CONT TestQueueEnqueueAndFetch2614=== CONT TestServerBacksOffOnAcceptErrors2615=== CONT TestWorkerSkipsGCdPaths26162026/10/05 12:09:52 ERROR Accept failed error="too many open files"2617=== CONT TestWorkerRemoveFailureIsNotProgress2618=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2619=== CONT TestWorkerPrunesClosureDeps2620=== CONT TestWorkerKeepsPathItCannotStat2621=== CONT TestShutdownFinishesInFlightPush2622=== CONT TestQueueConcurrentWriters2623=== CONT TestServerRefusesOversizedAndNonStoreRequests2624=== CONT TestServerQueueError2625=== CONT TestServerClientIntegration2626=== CONT TestServerStalledClientDoesNotBlockShutdown2627=== CONT TestQueueRemoveLargeClosure26282026/10/05 12:09:52 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store26292026/10/05 12:09:52 ERROR Failed to queue paths error="permission denied" count=12630=== CONT TestQueueEnqueueWaitsOutSlowWriter2631=== CONT TestDrainGivesUpWhenServerDown26322026/10/05 12:09:52 ERROR Refusing path outside the store path=/nix/store store=/nix/store2633=== CONT TestDrainTimeout2634=== CONT TestFailedPathPrunedByLaterClosure26352026/10/05 12:09:52 ERROR Accept failed error="too many open files"26362026/10/05 12:09:52 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store2637=== CONT TestQueueRetryMovesToBack2638=== CONT TestQueueFetchRemoveLifecycle26392026/10/05 12:09:52 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store2640=== CONT TestQueueFetchBatchLimit2641=== CONT TestRunNotBlockedByPoisonHead2642=== CONT TestWorkerUploadsAndRemoves2643=== CONT TestDrainIsolatesPoisonPath26442026/10/05 12:09:52 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store2645=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2646=== RUN TestShutdownFinishesInFlightPush/completes2647--- PASS: TestServerClientIntegration (0.00s)2648=== CONT TestQueueDeduplication2649=== CONT TestQueueRemove2650=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2651=== PAUSE TestShutdownFinishesInFlightPush/completes2652--- PASS: TestServerQueueError (0.00s)26532026/10/05 12:09:52 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store2654=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2655=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2656=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch26572026/10/05 12:09:52 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store2658=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2659=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2660=== CONT TestSendPathsEmpty2661=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2662--- PASS: TestSendPathsEmpty (0.00s)2663=== CONT TestShutdownFinishesInFlightPush/completes2664=== CONT TestDrainTimeoutDuringIsolation26652026/10/05 12:09:52 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store2666=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2667=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2668=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2669=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2670=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout26712026/10/05 12:09:52 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store26722026/10/05 12:09:52 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store26732026/10/05 12:09:52 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store26742026/10/05 12:09:52 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store26752026/10/05 12:09:52 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store26762026/10/05 12:09:52 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store26772026/10/05 12:09:52 ERROR Accept failed error="too many open files"26782026/10/05 12:09:52 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store26792026/10/05 12:09:52 ERROR Failed to decode request error="unexpected EOF"2680=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path2681--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.02s)26822026/10/05 12:09:52 ERROR Accept failed error="too many open files"26832026/10/05 12:09:52 INFO Upload queue status pending=226842026/10/05 12:09:52 INFO Upload queue status pending=226852026/10/05 12:09:52 INFO Upload queue status pending=226862026/10/05 12:09:52 INFO Uploading batch count=226872026/10/05 12:09:52 INFO Uploading batch count=126882026/10/05 12:09:52 INFO Uploading batch count=226892026/10/05 12:09:52 INFO Uploading batch count=226902026/10/05 12:09:52 INFO Upload queue status pending=22691--- PASS: TestQueueEnqueueAndFetch (0.07s)26922026/10/05 12:09:52 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2439524668/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2439524668/002/locked/aaa: permission denied"2693=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch26942026/10/05 12:09:52 INFO Upload queue status pending=326952026/10/05 12:09:52 INFO Uploading batch count=426962026/10/05 12:09:52 ERROR Upload failed error="upload failed" count=426972026/10/05 12:09:52 INFO Upload queue status pending=32698--- PASS: TestQueueFetchRemoveLifecycle (0.07s)26992026/10/05 12:09:52 INFO Upload queue status pending=227002026/10/05 12:09:52 INFO Uploading batch count=12701=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths27022026/10/05 12:09:52 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3715912991/002/nonexistent27032026/10/05 12:09:52 ERROR Upload failed error="upload failed" count=127042026/10/05 12:09:52 INFO Uploading batch count=227052026/10/05 12:09:52 INFO Uploading batch count=227062026/10/05 12:09:52 ERROR Upload failed error="upload failed" count=227072026/10/05 12:09:52 INFO Uploading batch count=127082026/10/05 12:09:52 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3325409979/002/a27092026/10/05 12:09:52 ERROR Accept failed error="too many open files"27102026/10/05 12:09:52 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2519792458/002/bbb27112026/10/05 12:09:52 ERROR Upload failed error="upload failed" count=127122026/10/05 12:09:52 INFO Uploading batch count=227132026/10/05 12:09:52 INFO Uploading batch count=227142026/10/05 12:09:52 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2439524668/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2439524668/002/locked/aaa: permission denied"27152026/10/05 12:09:52 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3325409979/002/b27162026/10/05 12:09:52 INFO Uploading batch count=12717--- PASS: TestQueueFetchBatchLimit (0.08s)2718=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short2719--- PASS: TestQueueRemove (0.07s)2720=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline27212026/10/05 12:09:52 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2439524668/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2439524668/002/locked/aaa: permission denied"2722--- PASS: TestQueueRetryMovesToBack (0.08s)27232026/10/05 12:09:52 INFO Uploading batch count=127242026/10/05 12:09:52 ERROR Upload failed error="upload failed" count=127252026/10/05 12:09:52 INFO Uploading batch count=227262026/10/05 12:09:52 ERROR Upload failed error="upload failed" count=227272026/10/05 12:09:52 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3325409979/002/c2728--- PASS: TestQueueDeduplication (0.08s)27292026/10/05 12:09:52 ERROR Drain finished with paths left in queue remaining=127302026/10/05 12:09:52 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3325409979/002/d27312026/10/05 12:09:52 INFO Uploading batch count=127322026/10/05 12:09:52 INFO Uploading batch count=127332026/10/05 12:09:52 ERROR Upload failed error="upload failed" count=12734--- PASS: TestWorkerUploadsAndRemoves (0.09s)2735--- PASS: TestWorkerPrunesClosureDeps (0.09s)2736--- PASS: TestWorkerKeepsPathItCannotStat (0.10s)27372026/10/05 12:09:52 INFO Uploading batch count=227382026/10/05 12:09:52 ERROR Upload failed error="upload failed" count=227392026/10/05 12:09:52 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3325409979/002/e27402026/10/05 12:09:52 INFO Uploading batch count=127412026/10/05 12:09:52 ERROR Upload failed error="upload failed" count=127422026/10/05 12:09:52 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path3206053008/001/nonexistent27432026/10/05 12:09:52 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3325409979/002/f27442026/10/05 12:09:52 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127452026/10/05 12:09:52 ERROR Drain finished with paths left in queue remaining=127462026/10/05 12:09:52 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path3206053008/001/nonexistent2747--- PASS: TestWorkerSkipsGCdPaths (0.11s)27482026/10/05 12:09:52 ERROR Drain finished with paths left in queue remaining=102749--- PASS: TestFailedPathPrunedByLaterClosure (0.10s)2750--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.11s)27512026/10/05 12:09:52 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127522026/10/05 12:09:52 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path3206053008/001/nonexistent27532026/10/05 12:09:52 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127542026/10/05 12:09:52 ERROR Drain finished with paths left in queue remaining=12755--- PASS: TestDrainIsolatesPoisonPath (0.10s)2756--- PASS: TestDrainGivesUpWhenServerDown (0.11s)27572026/10/05 12:09:52 INFO Uploading batch count=427582026/10/05 12:09:52 INFO Uploading batch count=427592026/10/05 12:09:52 ERROR Upload failed error="upload failed" count=427602026/10/05 12:09:52 ERROR Upload failed error="upload failed" count=427612026/10/05 12:09:52 INFO Uploading batch count=227622026/10/05 12:09:52 ERROR Upload failed error="upload failed" count=227632026/10/05 12:09:52 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127642026/10/05 12:09:52 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127652026/10/05 12:09:52 INFO Uploading batch count=227662026/10/05 12:09:52 ERROR Upload failed error="upload failed" count=227672026/10/05 12:09:52 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127682026/10/05 12:09:52 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127692026/10/05 12:09:52 INFO Uploading batch count=227702026/10/05 12:09:52 ERROR Upload failed error="upload failed" count=227712026/10/05 12:09:52 INFO Uploading batch count=227722026/10/05 12:09:52 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127732026/10/05 12:09:52 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127742026/10/05 12:09:52 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227752026/10/05 12:09:52 ERROR Drain finished with paths left in queue remaining=227762026/10/05 12:09:52 INFO Uploading batch count=227772026/10/05 12:09:52 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227782026/10/05 12:09:52 INFO Uploading batch count=227792026/10/05 12:09:52 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227802026/10/05 12:09:52 ERROR Drain finished with paths left in queue remaining=22781--- PASS: TestWorkerRemoveFailureIsNotProgress (0.01s)2782 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.10s)2783 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.05s)2784 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.05s)27852026/10/05 12:09:52 ERROR Accept failed error="too many open files"27862026/10/05 12:09:52 ERROR Failed to decode request error="read unix /build/hook1864559663/test.sock->@: i/o timeout"27872026/10/05 12:09:52 ERROR Failed to write response error="write unix /build/hook1864559663/test.sock->@: i/o timeout"2788--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)27892026/10/05 12:09:52 ERROR Upload failed error="context canceled" count=227902026/10/05 12:09:52 ERROR Drain finished with paths left in queue remaining=427912026/10/05 12:09:52 ERROR Upload failed error="context canceled" count=227922026/10/05 12:09:52 ERROR Drain finished with paths left in queue remaining=22793--- PASS: TestDrainTimeout (0.27s)2794--- PASS: TestShutdownFinishesInFlightPush (0.01s)2795 --- PASS: TestShutdownFinishesInFlightPush/completes (0.18s)2796 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.26s)27972026/10/05 12:09:52 ERROR Drain finished with paths left in queue remaining=427982026/10/05 12:09:52 ERROR Accept failed error="too many open files"27992026/10/05 12:09:52 ERROR Drain finished with paths left in queue remaining=32800--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2801 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.24s)2802 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.34s)28032026/10/05 12:09:52 ERROR Accept failed error="too many open files"2804--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)2805--- PASS: TestQueueConcurrentWriters (0.69s)28062026/10/05 12:09:53 INFO Uploading batch count=128072026/10/05 12:09:53 INFO Uploading batch count=128082026/10/05 12:09:53 INFO Uploading batch count=128092026/10/05 12:09:53 ERROR Upload failed error="upload failed" count=128102026/10/05 12:09:53 INFO Uploading batch count=128112026/10/05 12:09:53 ERROR Upload failed error="upload failed" count=128122026/10/05 12:09:53 INFO Uploading batch count=128132026/10/05 12:09:53 ERROR Upload failed error="upload failed" count=128142026/10/05 12:09:53 INFO Uploading batch count=128152026/10/05 12:09:53 ERROR Upload failed error="upload failed" count=128162026/10/05 12:09:53 ERROR Drain finished with paths left in queue remaining=12817--- PASS: TestRunNotBlockedByPoisonHead (1.10s)2818--- PASS: TestQueueRemoveLargeClosure (2.00s)2819--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.07s)2820PASS2821Running niks3-hook command tests...2822=== RUN TestServeSecondSignalEndsDrain2823=== PAUSE TestServeSecondSignalEndsDrain2824=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown2825=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown2826=== CONT TestServeSecondSignalEndsDrain2827=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown2828--- PASS: TestServeSecondSignalEndsDrain (0.08s)28292026/10/05 12:09:59 INFO Upload queue status pending=128302026/10/05 12:09:59 INFO Uploading batch count=12831--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.13s)2832PASS2833Running rate limiter tests...2834=== RUN TestAdaptiveRateLimiter_ThreadSafety2835=== PAUSE TestAdaptiveRateLimiter_ThreadSafety2836=== CONT TestAdaptiveRateLimiter_ThreadSafety28372026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=7028382026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=4928392026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=34.328402026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=24.00999999999999828412026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=16.80728422026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=11.76489999999999928432026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=8.2354328442026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=5.76480099999999928452026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528462026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528472026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528482026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528492026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528502026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528512026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528522026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528532026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528542026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528552026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528562026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528572026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528582026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528592026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528602026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528612026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528622026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528632026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528642026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528652026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528662026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528672026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528682026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528692026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528702026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528712026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528722026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528732026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528742026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528752026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528762026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528772026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528782026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528792026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528802026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528812026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528822026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528832026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528842026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528852026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528862026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528872026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528882026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528892026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528902026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528912026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528922026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528932026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528942026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528952026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528962026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528972026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528982026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=528992026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529002026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529012026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529022026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529032026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529042026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529052026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529062026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529072026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529082026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529092026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529102026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529112026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529122026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=8.25281691850000429132026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=5.77697184295000329142026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529152026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529162026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529172026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529182026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529192026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529202026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529212026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529222026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529232026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=5.12435000000000129242026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529252026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529262026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529272026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529282026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529292026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529302026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529312026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529322026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529332026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=5.12435000000000129342026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=529352026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=9.98590847138500629362026/10/05 12:10:00 WARN Rate limiter backed off name=test rate=6.9901359299695042937--- PASS: TestAdaptiveRateLimiter_ThreadSafety (3.03s)2938PASS