niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #342
· 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 118 of 32768000 bytes45--- PASS: TestDumpPathWriterErrorStopsReading (0.65s)46=== RUN TestEncodeNixBase3247=== PAUSE TestEncodeNixBase3248=== RUN TestEncodeNixBase32WithRealHash49=== PAUSE TestEncodeNixBase32WithRealHash50=== RUN TestConvertHashToNix3251=== PAUSE TestConvertHashToNix3252=== RUN TestGetStorePathHash53=== PAUSE TestGetStorePathHash54=== RUN TestPathInfoHashCompatibility55=== PAUSE TestPathInfoHashCompatibility56=== RUN TestParsePathInfoJSON57=== PAUSE TestParsePathInfoJSON58=== RUN TestParsePathInfoJSONMultiplePaths59=== PAUSE TestParsePathInfoJSONMultiplePaths60=== RUN TestPathInfoCACompatibility61=== PAUSE TestPathInfoCACompatibility62=== RUN TestUploadPendingObjectsStopsStartingAfterFailure63--- PASS: TestUploadPendingObjectsStopsStartingAfterFailure (0.02s)64=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent65=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent66=== RUN TestCompletePendingClosure_NotFoundWithoutKey67=== PAUSE TestCompletePendingClosure_NotFoundWithoutKey68=== RUN TestRateLimiterFeedback69=== PAUSE TestRateLimiterFeedback70=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess71=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess72=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer73=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer74=== RUN TestResolveStorePath75=== PAUSE TestResolveStorePath76=== RUN TestDoWithRetry_BodyReplayedViaGetBody77=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody78=== RUN TestDoWithRetry_FinalResponseBodyReadable79=== PAUSE TestDoWithRetry_FinalResponseBodyReadable80=== RUN TestShellSplit81=== PAUSE TestShellSplit82=== RUN TestShellSplitErrors83=== PAUSE TestShellSplitErrors84=== RUN TestStreamPushReportsEveryPath85=== PAUSE TestStreamPushReportsEveryPath86=== RUN TestStreamPushBatchesUnderLoad87=== PAUSE TestStreamPushBatchesUnderLoad88=== RUN TestStreamPushIsolatesFailures89=== PAUSE TestStreamPushIsolatesFailures90=== RUN TestStreamPushGivesUpOnDeadServer91=== PAUSE TestStreamPushGivesUpOnDeadServer92=== RUN TestStreamPushRequestLine93=== PAUSE TestStreamPushRequestLine94=== RUN TestStreamPushReportsSignatures95=== PAUSE TestStreamPushReportsSignatures96=== RUN TestClientSignaturesByStorePath97=== PAUSE TestClientSignaturesByStorePath98=== RUN TestStreamPushStopsOnCancel99=== PAUSE TestStreamPushStopsOnCancel100=== RUN TestSetClientTLS101=== PAUSE TestSetClientTLS102=== RUN TestSetClientTLSDoesNotMutateDefaultTransport103=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport104=== RUN TestSetClientTLSErrors105=== PAUSE TestSetClientTLSErrors106=== RUN TestStaticToken107=== PAUSE TestStaticToken108=== RUN TestFileTokenReadsAndCaches109=== PAUSE TestFileTokenReadsAndCaches110=== RUN TestFileTokenMissing111=== PAUSE TestFileTokenMissing112=== RUN TestFileTokenEmpty113=== PAUSE TestFileTokenEmpty114=== RUN TestScriptTokenNoExpiryRerunsEveryCall115=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall116=== RUN TestScriptTokenCachesUntilRefresh117=== PAUSE TestScriptTokenCachesUntilRefresh118=== RUN TestScriptTokenEmptyToken119=== PAUSE TestScriptTokenEmptyToken120=== RUN TestScriptTokenBadJSON121=== PAUSE TestScriptTokenBadJSON122=== RUN TestScriptTokenScriptFails123=== PAUSE TestScriptTokenScriptFails124=== RUN TestScriptTokenEmptyCommand125=== PAUSE TestScriptTokenEmptyCommand126=== RUN TestScriptTokenDoesNotWaitForItsChildren127=== PAUSE TestScriptTokenDoesNotWaitForItsChildren128=== CONT TestDoServerRequestAttachesToken129=== CONT TestScriptTokenEmptyCommand130=== CONT TestUploadMultipart_SupersededByPeer131=== CONT TestCaseHackSuffix132--- PASS: TestScriptTokenEmptyCommand (0.00s)133=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer134=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess135=== CONT TestDumpPathMatchesNix136=== CONT TestPathInfoCACompatibility137=== RUN TestPathInfoCACompatibility/null_ca_field138=== CONT TestSetClientTLSDoesNotMutateDefaultTransport139=== CONT TestFilterOversizedClosures140=== CONT TestRateLimiterFeedback141=== CONT TestPartSizeForNAR142=== RUN TestPartSizeForNAR/zero_stays_at_minimum143=== CONT TestCompletePendingClosure_NotFoundWithoutKey144=== CONT TestConvertHashToNix32145=== RUN TestConvertHashToNix32/SRI_format_to_Nix32146=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure147=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum148=== RUN TestPartSizeForNAR/small_stays_at_minimum149=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32150=== CONT TestSupersededNARStillUploadsListing151=== CONT TestParsePathInfoJSON152=== CONT TestPathInfoHashCompatibility153=== CONT TestEncodeNixBase32WithRealHash154=== CONT TestFileTokenEmpty155=== CONT TestStreamPushReportsSignatures156=== CONT TestDumpPathSingleFile157=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica158=== CONT TestStreamPushStopsOnCancel159=== RUN TestUploadMultipart_SupersededByPeer/exists160=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry161=== PAUSE TestPathInfoCACompatibility/null_ca_field162=== RUN TestFilterOversizedClosures/no_limit_keeps_everything163=== RUN TestRateLimiterFeedback/429_enables_limiter164=== CONT TestScriptTokenDoesNotWaitForItsChildren165=== RUN TestConvertHashToNix32/already_Nix32_format166=== PAUSE TestPartSizeForNAR/small_stays_at_minimum167=== RUN TestSupersededNARStillUploadsListing/small_NAR168=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs169=== PAUSE TestConvertHashToNix32/already_Nix32_format170=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)171=== CONT TestDoWithRetry_FinalResponseBodyReadable172--- PASS: TestDoServerRequestAttachesToken (0.01s)173=== CONT TestShellSplitErrors174=== RUN TestStreamPushStopsOnCancel/waiting_for_input175=== CONT TestScriptTokenBadJSON176=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun177=== PAUSE TestUploadMultipart_SupersededByPeer/exists178=== RUN TestPathInfoCACompatibility/old_string_format_-_text179=== PAUSE TestRateLimiterFeedback/429_enables_limiter180=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything181=== RUN TestParsePathInfoJSON/Nix_format182=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped183=== PAUSE TestSupersededNARStillUploadsListing/small_NAR184=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs185=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum186=== RUN TestConvertHashToNix32/invalid_format187=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)188=== CONT TestShellSplit189--- PASS: TestEncodeNixBase32WithRealHash (0.00s)190=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input191=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text192=== RUN TestUploadMultipart_SupersededByPeer/missing193=== RUN TestRateLimiterFeedback/503_enables_limiter194=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped195=== PAUSE TestParsePathInfoJSON/Nix_format196=== RUN TestFilterOversizedClosures/all_closures_skipped197=== RUN TestSupersededNARStillUploadsListing/dump_cut_short198=== CONT TestResolveStorePath199=== PAUSE TestFilterOversizedClosures/all_closures_skipped200=== PAUSE TestConvertHashToNix32/invalid_format201--- PASS: TestFileTokenEmpty (0.00s)202=== CONT TestUploadMultipart_FailedPartBufferNotReused203=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon204=== PAUSE TestUploadMultipart_SupersededByPeer/missing205=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive206=== PAUSE TestRateLimiterFeedback/503_enables_limiter207=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot208=== CONT TestStreamPushBatchesUnderLoad209=== RUN TestStreamPushBatchesUnderLoad/together210=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot211=== RUN TestParsePathInfoJSON/Lix_format212=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum213=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short214=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent215=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier216=== CONT TestUploadMultipart_PartsInParallel217--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.01s)218=== CONT TestClientSignaturesByStorePath219--- PASS: TestStreamPushReportsSignatures (0.00s)220=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon221=== CONT TestDumpPathWriterError222=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive223=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout224=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter225=== PAUSE TestStreamPushBatchesUnderLoad/together226=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot227=== PAUSE TestParsePathInfoJSON/Lix_format228=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts229=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails230--- PASS: TestClientSignaturesByStorePath (0.00s)231=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier232=== CONT TestGetStorePathHash233=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI234=== RUN TestPathInfoCACompatibility/new_structured_format_-_text235=== CONT TestScriptTokenEmptyToken236=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI237=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text238=== RUN TestGetStorePathHash/valid_store_path239=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512240=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter241=== RUN TestParsePathInfoJSON/empty_input242=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512243=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method244=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter245=== CONT TestScriptTokenCachesUntilRefresh246=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails247=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time248=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout249=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up250=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter251=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts252=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot253=== PAUSE TestGetStorePathHash/valid_store_path254--- PASS: TestShellSplitErrors (0.00s)255=== PAUSE TestParsePathInfoJSON/empty_input256=== CONT TestScriptTokenScriptFails257=== CONT TestStreamPushRequestLine258=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time259=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method260=== CONT TestEncodeNixBase32261=== CONT TestFileTokenMissing262=== CONT TestParsePathInfoJSONMultiplePaths263=== RUN TestPartSizeForNAR/1_TiB264=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot265=== RUN TestGetStorePathHash/basename_without_hyphen_should_error266--- PASS: TestShellSplit (0.00s)267=== CONT TestScriptTokenNoExpiryRerunsEveryCall268=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up269=== CONT TestFileTokenReadsAndCaches270=== RUN TestParsePathInfoJSON/whitespace_only271=== RUN TestEncodeNixBase32/test_string_hash272=== CONT TestStreamPushGivesUpOnDeadServer273=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths274=== PAUSE TestPartSizeForNAR/1_TiB275=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot276=== CONT TestStaticToken277=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot278--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.02s)279=== CONT TestRegisterUploadedObjectReusesConnections280=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot281=== CONT TestUploadMultipart_ProducerErrorIsNotEOF282=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error283=== PAUSE TestParsePathInfoJSON/whitespace_only284=== PAUSE TestEncodeNixBase32/test_string_hash285=== CONT TestStreamPushIsolatesFailures286=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths287=== RUN TestPartSizeForNAR/5_TiB_S3_max_object288=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths289=== CONT TestSetClientTLS290--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.02s)291--- PASS: TestScriptTokenBadJSON (0.02s)292=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part293=== CONT TestStreamPushReportsEveryPath294=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken295=== CONT TestSetClientTLSErrors296=== CONT TestTruncatedNARDumpIsNotCompleted297=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error298=== RUN TestParsePathInfoJSON/invalid_JSON299=== CONT TestFilterOversizedClosures/all_closures_skipped300=== RUN TestEncodeNixBase32/empty_input301=== CONT TestDoWithRetry_BodyReplayedViaGetBody302=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped303=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error304=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken305=== PAUSE TestParsePathInfoJSON/invalid_JSON306=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error307=== CONT TestFilterOversizedClosures/no_limit_keeps_everything308=== CONT TestConvertHashToNix32/already_Nix32_format309=== CONT TestConvertHashToNix32/SRI_format_to_Nix32310=== CONT TestUploadMultipart_SupersededByPeer/missing311=== CONT TestUploadMultipart_SupersededByPeer/exists312=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error313=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)314=== PAUSE TestEncodeNixBase32/empty_input315--- PASS: TestResolveStorePath (0.00s)316=== CONT TestConvertHashToNix32/invalid_format317=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part318--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.03s)319=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512320=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI321=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object322=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths323--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.03s)324--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.03s)325=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs326=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary327=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails328=== CONT TestSupersededNARStillUploadsListing/dump_cut_short329=== CONT TestSupersededNARStillUploadsListing/small_NAR330=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout331=== RUN TestPartSizeForNAR/capped_at_5_GiB332=== PAUSE TestPartSizeForNAR/capped_at_5_GiB333=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter334--- PASS: TestScriptTokenScriptFails (0.00s)335=== RUN TestSetClientTLSErrors/missing_cert_file336=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary337=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time338=== PAUSE TestSetClientTLSErrors/missing_cert_file339=== RUN TestSetClientTLS/rejects_connection_without_client_cert340=== RUN TestSetClientTLSErrors/missing_key_file341=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert342=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA343=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon344=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA345=== PAUSE TestSetClientTLSErrors/missing_key_file346=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter347=== CONT TestRateLimiterFeedback/503_enables_limiter348=== CONT TestRateLimiterFeedback/429_enables_limiter349--- PASS: TestDumpPathSingleFile (0.04s)350--- PASS: TestFileTokenMissing (0.00s)351=== CONT TestStreamPushBatchesUnderLoad/together352=== CONT TestPathInfoCACompatibility/null_ca_field353=== RUN TestSetClientTLS/preserves_debug_logging_transport354=== RUN TestSetClientTLSErrors/missing_ca_file355=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method356=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive357--- PASS: TestStaticToken (0.00s)358=== PAUSE TestSetClientTLSErrors/missing_ca_file359=== CONT TestPathInfoCACompatibility/old_string_format_-_text360=== RUN TestSetClientTLSErrors/invalid_ca_file361=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up362=== CONT TestParsePathInfoJSON/Lix_format363=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot364=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken365=== CONT TestPathInfoCACompatibility/new_structured_format_-_text366=== PAUSE TestSetClientTLSErrors/invalid_ca_file367=== CONT TestStreamPushStopsOnCancel/waiting_for_input368=== PAUSE TestSetClientTLS/preserves_debug_logging_transport369=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier370=== CONT TestEncodeNixBase32/empty_input371--- PASS: TestScriptTokenEmptyToken (0.01s)372=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot373=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot374=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot375--- PASS: TestCaseHackSuffix (0.05s)376=== CONT TestParsePathInfoJSON/empty_input377=== CONT TestParsePathInfoJSON/invalid_JSON378=== CONT TestParsePathInfoJSON/whitespace_only379--- PASS: TestFileTokenReadsAndCaches (0.00s)380=== CONT TestEncodeNixBase32/test_string_hash381=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error382=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error383--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)384--- PASS: TestStreamPushIsolatesFailures (0.00s)385=== CONT TestGetStorePathHash/valid_store_path386=== CONT TestParsePathInfoJSON/Nix_format387--- PASS: TestStreamPushReportsEveryPath (0.00s)388--- PASS: TestScriptTokenCachesUntilRefresh (0.14s)389=== CONT TestGetStorePathHash/basename_without_hyphen_should_error390--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.15s)391=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths392=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths393=== CONT TestPartSizeForNAR/capped_at_5_GiB394=== CONT TestPartSizeForNAR/5_TiB_S3_max_object395--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.16s)396=== CONT TestPartSizeForNAR/1_TiB397=== CONT TestPartSizeForNAR/small_stays_at_minimum398=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts399=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part400=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum401=== CONT TestPartSizeForNAR/zero_stays_at_minimum402=== CONT TestSetClientTLSErrors/missing_ca_file403=== CONT TestSetClientTLSErrors/invalid_ca_file404--- PASS: TestFilterOversizedClosures (0.03s)405 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)406 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)407 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)408=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary409=== CONT TestSetClientTLSErrors/missing_cert_file410--- PASS: TestConvertHashToNix32 (0.03s)411 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)412 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)413 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)414=== CONT TestSetClientTLS/rejects_connection_without_client_cert415--- PASS: TestUploadMultipart_SupersededByPeer (0.03s)416 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.15s)417 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.15s)418--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.22s)419--- PASS: TestPathInfoHashCompatibility (0.03s)420 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.14s)421 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.02s)422 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)423 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)424--- PASS: TestStreamPushBatchesUnderLoad (0.01s)425 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)426 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)427--- PASS: TestRateLimiterFeedback (0.04s)428 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)429 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)430 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)431 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)432=== CONT TestSetClientTLSErrors/missing_key_file433--- PASS: TestPathInfoCACompatibility (0.05s)434 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)435 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)436 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)437 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)438 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)439=== CONT TestSetClientTLS/preserves_debug_logging_transport440--- PASS: TestEncodeNixBase32 (0.13s)441 --- PASS: TestEncodeNixBase32/empty_input (0.00s)442 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)443--- PASS: TestParsePathInfoJSON (0.05s)444 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)445 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)446 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)447 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)448 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)449--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.01s)450 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.01s)451 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.01s)452--- PASS: TestGetStorePathHash (0.02s)453 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)454 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)455 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)456 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)457--- PASS: TestParsePathInfoJSONMultiplePaths (0.15s)458 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)459 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)460--- PASS: TestPartSizeForNAR (0.20s)461 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)462 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)463 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)464 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)465 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)466 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)467 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)468--- PASS: TestSetClientTLSErrors (0.16s)469 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)470 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)471 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)472 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)473=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA474--- PASS: TestStreamPushStopsOnCancel (0.04s)475 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.05s)476 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.05s)477 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.05s)478 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.05s)479 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.05s)480 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)481--- PASS: TestDumpPathWriterError (0.24s)482--- PASS: TestSetClientTLS (0.17s)483 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)484 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)485 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.26s)486--- PASS: TestRegisterUploadedObjectReusesConnections (0.49s)487--- PASS: TestStreamPushRequestLine (0.50s)488--- PASS: TestDumpPathMatchesNix (0.56s)489--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.15s)490 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.38s)491 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.41s)492--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)493--- PASS: TestTruncatedNARDumpIsNotCompleted (1.36s)494--- PASS: TestSupersededNARStillUploadsListing (0.04s)495 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.05s)496 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.05s)497 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.27s)498--- PASS: TestUploadMultipart_PartsInParallel (1.47s)499--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.52s)500--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (2.00s)501--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.03s)502 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.01s)503 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.23s)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/postgres3674477077/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/postgres3674477077/data -l logfile start532533/build/postgres3674477077:5432 - no response5342026-10-01 10:33:53.658 UTC [171] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit5352026-10-01 10:33:53.659 UTC [171] LOG: listening on Unix socket "/build/postgres3674477077/.s.PGSQL.5432"5362026-10-01 10:33:53.664 UTC [178] LOG: database system was shut down at 2026-10-01 10:33:53 UTC5372026-10-01 10:33:53.667 UTC [171] LOG: database system is ready to accept connections538/build/postgres3674477077:5432 - accepting connections539{"timestamp":"2026-10-01T10:33:53.972362065Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"11afd243-4b1e-4557-853f-6cf37b65fb13","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(399)"}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/01 10:33:54 INFO lead: acquired remote=192.0.2.1:12345882026/10/01 10:33:55 INFO lead: released remote=192.0.2.1:12345892026/10/01 10:33:55 INFO lead: acquired remote=192.0.2.1:12345902026/10/01 10:33:56 INFO lead: released remote=192.0.2.1:1234591--- PASS: TestLeadIncumbentWinsAfterRestart (2.34s)592=== RUN TestLeadEndsOnShutdown593=== PAUSE TestLeadEndsOnShutdown594=== RUN TestLeadEndsWhenItsConnectionHangs5952026/10/01 10:33:56 INFO lead: acquired remote=192.0.2.1:12345962026-10-01 10:33:57.759 UTC [622] FATAL: terminating connection due to administrator command5972026/10/01 10:33:57 INFO lead: acquired remote=192.0.2.1:12345982026/10/01 10:33:58 WARN lead: lock connection lost error="timeout: context deadline exceeded"5992026/10/01 10:33:58 INFO lead: released remote=192.0.2.1:12346002026/10/01 10:33:59 INFO lead: released remote=192.0.2.1:1234601--- PASS: TestLeadEndsWhenItsConnectionHangs (2.75s)602=== RUN TestGCAdvisoryLockBlocksConcurrentRun603=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun604=== RUN TestGCBugBareHashReferences605=== PAUSE TestGCBugBareHashReferences606=== RUN TestGCMetrics607=== PAUSE TestGCMetrics608=== RUN TestPushDedupSurvivesConcurrentGC609=== PAUSE TestPushDedupSurvivesConcurrentGC610=== RUN TestDeduplicatedObjectsRecordedAsPending611=== PAUSE TestDeduplicatedObjectsRecordedAsPending612=== RUN TestGCSweepSkipsPendingObjects613=== PAUSE TestGCSweepSkipsPendingObjects614=== RUN TestTombstonedObjectOfferedWithoutWaiting615=== PAUSE TestTombstonedObjectOfferedWithoutWaiting616=== RUN TestGCSweepDeliversEachKeyOnce617=== PAUSE TestGCSweepDeliversEachKeyOnce618=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection619=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection620=== RUN TestForceGCDuringPushOffersSweptObject621=== PAUSE TestForceGCDuringPushOffersSweptObject622=== RUN TestFailedS3DeleteKeepsTombstone623=== PAUSE TestFailedS3DeleteKeepsTombstone624=== RUN TestSweepSkipsRowsLockedByPush625=== PAUSE TestSweepSkipsRowsLockedByPush626=== RUN TestRegisterCompletedObjectNeedsPendingRow627=== PAUSE TestRegisterCompletedObjectNeedsPendingRow628=== RUN TestGetExistingObjectsLocksRows629=== PAUSE TestGetExistingObjectsLocksRows630=== RUN TestSweepRechecksPendingAfterLocking631=== PAUSE TestSweepRechecksPendingAfterLocking632=== RUN TestPushWaitsForSweepHoldingRow633=== PAUSE TestPushWaitsForSweepHoldingRow634=== RUN TestCommitRacingPendingCleanupKeepsObjects635=== PAUSE TestCommitRacingPendingCleanupKeepsObjects636=== RUN TestGCEndsOnShutdown637=== PAUSE TestGCEndsOnShutdown638=== RUN TestGCTaskStore_StartNew639=== PAUSE TestGCTaskStore_StartNew640=== RUN TestGCTaskStore_DeduplicateSameParams641=== PAUSE TestGCTaskStore_DeduplicateSameParams642=== RUN TestGCTaskStore_ConflictDifferentParams643=== PAUSE TestGCTaskStore_ConflictDifferentParams644=== RUN TestGCTaskStore_GetEmpty645=== PAUSE TestGCTaskStore_GetEmpty646=== RUN TestGCTaskStore_GetReturnsLatest647=== PAUSE TestGCTaskStore_GetReturnsLatest648=== RUN TestGCTaskStore_CompletedAllowsNewTask649=== PAUSE TestGCTaskStore_CompletedAllowsNewTask650=== RUN TestGCTaskStore_PhaseUpdates651=== PAUSE TestGCTaskStore_PhaseUpdates652=== RUN TestGCTaskStore_Fail653=== PAUSE TestGCTaskStore_Fail654=== RUN TestGracefulShutdownDrainsInflight655=== PAUSE TestGracefulShutdownDrainsInflight656=== RUN TestService_healthCheckHandler657=== PAUSE TestService_healthCheckHandler658=== RUN TestService_readinessHandler659=== PAUSE TestService_readinessHandler660=== RUN TestGenerateLandingPage661=== PAUSE TestGenerateLandingPage662=== RUN TestCacheConfigHandlerMaxNarSize663=== PAUSE TestCacheConfigHandlerMaxNarSize664=== RUN TestCreatePendingClosureRejectsOversizedNAR665=== PAUSE TestCreatePendingClosureRejectsOversizedNAR666=== RUN TestNARDeduplicationMetadataUploadBug667=== PAUSE TestNARDeduplicationMetadataUploadBug668=== RUN TestMetricsInventory669=== PAUSE TestMetricsInventory670=== RUN TestService_NativeMTLS671=== PAUSE TestService_NativeMTLS672=== RUN TestServerTLSConfig673=== PAUSE TestServerTLSConfig674=== RUN TestMultipartCleanup675=== PAUSE TestMultipartCleanup676=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded677=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded678=== RUN TestPendingCleanupUsesOneCutoff679=== PAUSE TestPendingCleanupUsesOneCutoff680=== RUN TestPendingClosureFailureTracksEveryUpload681=== PAUSE TestPendingClosureFailureTracksEveryUpload682=== RUN TestPendingClosureFailureAbortsItsUploads683=== PAUSE TestPendingClosureFailureAbortsItsUploads684=== RUN TestObjectStatsTrigger685=== PAUSE TestObjectStatsTrigger686=== RUN TestReconnectLeavesObjectsUnlocked687=== PAUSE TestReconnectLeavesObjectsUnlocked688=== RUN TestOrphanedObjectsGC689=== PAUSE TestOrphanedObjectsGC690=== RUN TestOrphanedObjectsGCStressTest691=== PAUSE TestOrphanedObjectsGCStressTest692=== RUN TestCreatePin_ReservedPins693=== PAUSE TestCreatePin_ReservedPins694=== RUN TestConcurrentPinUpdatesAgree695=== PAUSE TestConcurrentPinUpdatesAgree696=== RUN TestCreatePinRejectsBadInput697=== PAUSE TestCreatePinRejectsBadInput698=== RUN TestDeletePinKeepsRowWhenS3Fails699=== PAUSE TestDeletePinKeepsRowWhenS3Fails700=== RUN TestPresentReportsOnlyClosureRoots701=== PAUSE TestPresentReportsOnlyClosureRoots702=== RUN TestPresentNotReportedWhileGCDeletesClosure703=== PAUSE TestPresentNotReportedWhileGCDeletesClosure704=== RUN TestParseSingleRange705=== PAUSE TestParseSingleRange706=== RUN TestProxyHeadersOnlyTrustedOnSocket707=== PAUSE TestProxyHeadersOnlyTrustedOnSocket708=== RUN TestIsValidCachePath709=== PAUSE TestIsValidCachePath710=== RUN TestReadProxyNarinfo711=== PAUSE TestReadProxyNarinfo712=== RUN TestReadProxyNarinfoAlreadyDecompressed713=== PAUSE TestReadProxyNarinfoAlreadyDecompressed714=== RUN TestReadProxyNarStreaming715=== PAUSE TestReadProxyNarStreaming716=== RUN TestReadProxy404717=== PAUSE TestReadProxy404718=== RUN TestReadProxyInvalidPath719=== PAUSE TestReadProxyInvalidPath720=== RUN TestReadProxyHead721=== PAUSE TestReadProxyHead722=== RUN TestReadProxyOutlastsServerWriteTimeout723=== PAUSE TestReadProxyOutlastsServerWriteTimeout724=== RUN TestReadProxyConditionalGet725=== PAUSE TestReadProxyConditionalGet726=== RUN TestReadProxyRootRedirectsToIndexHTML727=== PAUSE TestReadProxyRootRedirectsToIndexHTML728=== RUN TestReadProxyDisabled729=== PAUSE TestReadProxyDisabled730=== RUN TestReadRedirectNar731=== PAUSE TestReadRedirectNar732=== RUN TestReadRedirectKeepsNarinfoProxied733=== PAUSE TestReadRedirectKeepsNarinfoProxied734=== RUN TestReadProxyRangeRequest735=== PAUSE TestReadProxyRangeRequest736=== RUN TestReadRedirectUsesPublicS3URL737=== PAUSE TestReadRedirectUsesPublicS3URL738=== RUN TestPush_OverlappingRootsStoreOneRowPerKey739=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey740=== RUN TestPush_CompleteCommitsEveryRoot741=== PAUSE TestPush_CompleteCommitsEveryRoot742=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit743=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit744=== RUN TestPush_RejectsBadRequests745=== PAUSE TestPush_RejectsBadRequests746=== RUN TestPush_SignsNarinfosOfItsPendingObjects747=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects748=== RUN TestRedundantMultipartUpload749=== PAUSE TestRedundantMultipartUpload750=== RUN TestCompleteMultipartUpload_ErrorButObjectExists751=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists752=== RUN TestCompletedNarNotReofferedAcrossClosures753=== PAUSE TestCompletedNarNotReofferedAcrossClosures754=== RUN TestPresignedUploadRegisteredBeforeCommit755=== PAUSE TestPresignedUploadRegisteredBeforeCommit756=== RUN TestService_Rustfstest757=== PAUSE TestService_Rustfstest758=== RUN TestParseSize759=== PAUSE TestParseSize760=== RUN TestSkippedUploadsHandler761=== PAUSE TestSkippedUploadsHandler762=== RUN TestSystemdListenerNotActivated763--- PASS: TestSystemdListenerNotActivated (0.00s)764=== RUN TestWatchdogBeatsWhenHealthy765--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)766=== RUN TestWatchdogSkipsWhenUnhealthy7672026/10/01 10:33:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7682026/10/01 10:33:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/10/01 10:33:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/10/01 10:33:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/10/01 10:33:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/10/01 10:33:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/10/01 10:33:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/10/01 10:33:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7752026/10/01 10:33:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7762026/10/01 10:33:59 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"777--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)778=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle779=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle780=== RUN TestProxyWriteTimeout781=== PAUSE TestProxyWriteTimeout782=== RUN TestPendingClosureWriteTimeout783=== PAUSE TestPendingClosureWriteTimeout784=== RUN TestIsValidUploadKey785=== PAUSE TestIsValidUploadKey786=== RUN TestUploadHandlersRejectInvalidKeys787=== PAUSE TestUploadHandlersRejectInvalidKeys788=== RUN TestUploadHandlersRejectOversizedBody789=== PAUSE TestUploadHandlersRejectOversizedBody790=== RUN TestService_cleanupPendingClosuresHandler791=== PAUSE TestService_cleanupPendingClosuresHandler792=== RUN TestService_createPendingClosureHandler793=== PAUSE TestService_createPendingClosureHandler794=== RUN TestService_verifyS3Integrity795=== PAUSE TestService_verifyS3Integrity796=== RUN TestCompleteMultipartUnregistered797=== PAUSE TestCompleteMultipartUnregistered798=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT799=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT800=== CONT TestService_AuthMiddleware_MTLSBoundSubjects801=== CONT TestCompletedNarNotReofferedAcrossClosures802=== CONT TestPushWaitsForSweepHoldingRow803=== CONT TestCompleteMultipartUnregistered804=== CONT TestService_createPendingClosureHandler805=== CONT TestService_cleanupPendingClosuresHandler806=== CONT TestUploadHandlersRejectOversizedBody807=== CONT TestService_verifyS3Integrity808=== CONT TestUploadHandlersRejectInvalidKeys809=== CONT TestIsValidUploadKey810=== CONT TestPendingClosureWriteTimeout811=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle812=== CONT TestSkippedUploadsHandler813=== CONT TestProxyWriteTimeout814=== CONT TestParseSize815=== CONT TestPresignedUploadRegisteredBeforeCommit816=== CONT TestService_Rustfstest817=== CONT TestPresentReportsOnlyClosureRoots818=== CONT TestDeletePinKeepsRowWhenS3Fails819=== CONT TestProxyHeadersOnlyTrustedOnSocket820=== CONT TestConcurrentPinUpdatesAgree821=== CONT TestCreatePin_ReservedPins822=== CONT TestOrphanedObjectsGCStressTest823=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT824=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info825=== RUN TestIsValidUploadKey/narinfo826=== RUN TestPendingClosureWriteTimeout/empty827=== RUN TestProxyWriteTimeout/narinfo8282026/10/01 10:33:59 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000829--- PASS: TestParseSize (0.00s)830=== CONT TestOrphanedObjectsGC831=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info832=== PAUSE TestIsValidUploadKey/narinfo833=== PAUSE TestPendingClosureWriteTimeout/empty834=== PAUSE TestProxyWriteTimeout/narinfo835=== RUN TestIsValidUploadKey/nar_zst836=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal837=== RUN TestPendingClosureWriteTimeout/400_objects838=== RUN TestProxyWriteTimeout/1_GiB_nar839=== PAUSE TestPendingClosureWriteTimeout/400_objects840=== PAUSE TestIsValidUploadKey/nar_zst841=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal842=== PAUSE TestProxyWriteTimeout/1_GiB_nar843=== RUN TestPendingClosureWriteTimeout/670k_objects844=== RUN TestIsValidUploadKey/nar_xz845=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key846=== PAUSE TestIsValidUploadKey/nar_xz847=== RUN TestProxyWriteTimeout/10_GiB_nar848=== PAUSE TestPendingClosureWriteTimeout/670k_objects849=== RUN TestIsValidUploadKey/nar_plain850=== PAUSE TestProxyWriteTimeout/10_GiB_nar851=== PAUSE TestIsValidUploadKey/nar_plain852=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline853=== RUN TestProxyWriteTimeout/unknown_size854=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key855=== RUN TestIsValidUploadKey/listing856=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline857=== PAUSE TestIsValidUploadKey/listing858=== PAUSE TestProxyWriteTimeout/unknown_size859=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key860=== CONT TestCreatePinRejectsBadInput861=== RUN TestIsValidUploadKey/build_log862=== CONT TestReconnectLeavesObjectsUnlocked863=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key864=== PAUSE TestIsValidUploadKey/build_log865=== RUN TestIsValidUploadKey/build_log_home-manager_file866=== CONT TestPendingClosureFailureAbortsItsUploads867=== PAUSE TestIsValidUploadKey/build_log_home-manager_file868=== RUN TestIsValidUploadKey/build_log_plus_in_name869=== PAUSE TestIsValidUploadKey/build_log_plus_in_name870=== RUN TestIsValidUploadKey/build_log_question_mark871=== PAUSE TestIsValidUploadKey/build_log_question_mark872=== RUN TestIsValidUploadKey/build_log_equals873=== PAUSE TestIsValidUploadKey/build_log_equals874=== RUN TestIsValidUploadKey/realisation875=== PAUSE TestIsValidUploadKey/realisation876=== RUN TestIsValidUploadKey/realisation_plus_in_output877=== PAUSE TestIsValidUploadKey/realisation_plus_in_output878=== RUN TestIsValidUploadKey/nix-cache-info879=== PAUSE TestIsValidUploadKey/nix-cache-info880=== RUN TestIsValidUploadKey/index.html881=== PAUSE TestIsValidUploadKey/index.html882=== RUN TestIsValidUploadKey/narinfo_key,_nar_type883=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type884=== RUN TestIsValidUploadKey/nar_key,_narinfo_type885=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type886=== RUN TestIsValidUploadKey/listing_key,_narinfo_type887=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type888=== RUN TestIsValidUploadKey/traversal889=== PAUSE TestIsValidUploadKey/traversal890=== RUN TestIsValidUploadKey/traversal_nar891=== PAUSE TestIsValidUploadKey/traversal_nar892=== RUN TestIsValidUploadKey/absolute893=== PAUSE TestIsValidUploadKey/absolute894=== RUN TestIsValidUploadKey/empty_key895=== PAUSE TestIsValidUploadKey/empty_key896=== RUN TestIsValidUploadKey/unknown_type897=== PAUSE TestIsValidUploadKey/unknown_type898=== CONT TestPendingClosureFailureTracksEveryUpload899=== CONT TestPendingCleanupUsesOneCutoff900--- PASS: TestSkippedUploadsHandler (0.04s)9012026/10/01 10:33:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39205/oidc9022026/10/01 10:33:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9032026/10/01 10:33:59 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst904--- PASS: TestCompleteMultipartUnregistered (0.42s)905=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded9062026/10/01 10:33:59 INFO Received uploads request method=POST path=/api/pending_closures9072026/10/01 10:33:59 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"9082026/10/01 10:33:59 WARN mTLS auth: bound subjects configured but subject DN unavailable9092026/10/01 10:33:59 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"910=== CONT TestMultipartCleanup911--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.46s)9122026/10/01 10:33:59 INFO Received uploads request method=POST path=/api/pending_closures9132026/10/01 10:33:59 INFO Received uploads request method=POST path=/api/pending_closures9142026/10/01 10:33:59 INFO Received uploads request method=POST path=/api/pending_closures9152026/10/01 10:33:59 INFO Received cleanup request method=DELETE path=/api/pending_closures9162026/10/01 10:33:59 INFO Aborted multipart uploads count=0 kept=09172026/10/01 10:33:59 INFO Received uploads request method=POST path=/api/pending_closures9182026/10/01 10:33:59 INFO Received uploads request method=POST path=/api/pending_closures9192026/10/01 10:33:59 INFO Received cleanup request method=DELETE path=/api/pending_closures9202026/10/01 10:33:59 INFO Aborted multipart uploads count=1 kept=09212026/10/01 10:33:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9222026-10-01 10:33:59.966 UTC [687] ERROR: Closure does not exist: id=19232026-10-01 10:33:59.966 UTC [687] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE9242026-10-01 10:33:59.966 UTC [687] STATEMENT: -- name: CommitPendingClosure :exec925 SELECT commit_pending_closure($1::bigint)926 9272026/10/01 10:33:59 INFO Received uploads request method=POST path=/api/pending_closures928=== CONT TestObjectStatsTrigger929--- PASS: TestService_cleanupPendingClosuresHandler (0.56s)930=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure931=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure932=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart933=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart934=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts935=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts936=== CONT TestServerTLSConfig937=== RUN TestServerTLSConfig/no_client_CA938=== PAUSE TestServerTLSConfig/no_client_CA939=== RUN TestServerTLSConfig/missing_CA_file940=== PAUSE TestServerTLSConfig/missing_CA_file941=== RUN TestServerTLSConfig/not_a_PEM_file942=== PAUSE TestServerTLSConfig/not_a_PEM_file943=== CONT TestMetricsInventory944--- PASS: TestPresentReportsOnlyClosureRoots (0.75s)945=== CONT TestNARDeduplicationMetadataUploadBug9462026/10/01 10:34:00 INFO Received uploads request method=POST path=/api/pending_closures9472026/10/01 10:34:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9482026/10/01 10:34:00 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9492026/10/01 10:34:00 INFO Received uploads request method=POST path=/api/pending_closures9502026/10/01 10:34:00 INFO Received create pin request method=POST path=/api/pins/app9512026/10/01 10:34:00 INFO Received create pin request method=POST path=/api/pins/app952--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.82s)953=== CONT TestService_NativeMTLS9542026/10/01 10:34:00 INFO Received uploads request method=POST path=/api/pending_closures9552026/10/01 10:34:00 INFO Received create pin request method=POST path=/api/pins/app9562026/10/01 10:34:00 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo9572026/10/01 10:34:00 INFO Received delete pin request method=DELETE path=/api/pins/app9582026/10/01 10:34:00 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket16/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"9592026/10/01 10:34:00 INFO Received delete pin request method=DELETE path=/api/pins/app9602026/10/01 10:34:00 INFO Received uploads request method=POST path=/api/pending_closures9612026/10/01 10:34:00 INFO Deleted pin name=app962--- PASS: TestPushWaitsForSweepHoldingRow (0.96s)963=== CONT TestCacheConfigHandlerMaxNarSize964--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)965=== CONT TestGenerateLandingPage966--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.95s)967=== CONT TestCreatePendingClosureRejectsOversizedNAR9682026/10/01 10:34:00 INFO Received uploads request method=POST path=/api/pending_closures969--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)970=== CONT TestService_readinessHandler9712026/10/01 10:34:00 INFO Received uploads request method=POST path=/api/pending_closures9722026/10/01 10:34:00 INFO Received uploads request method=POST path=/api/pending_closures973--- PASS: TestGenerateLandingPage (0.02s)974=== CONT TestGracefulShutdownDrainsInflight9752026/10/01 10:34:00 INFO Starting HTTP server address=127.0.0.1:421779762026/10/01 10:34:00 INFO Shutdown signal received, draining in-flight requests timeout=10s9772026/10/01 10:34:00 INFO Received cleanup request method=DELETE path=/api/pending_closures978=== CONT TestGCTaskStore_Fail979--- PASS: TestService_Rustfstest (1.01s)980--- PASS: TestGCTaskStore_Fail (0.00s)981=== CONT TestGCTaskStore_PhaseUpdates982=== CONT TestGCTaskStore_CompletedAllowsNewTask983--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)984=== CONT TestReadRedirectKeepsNarinfoProxied985--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)986--- PASS: TestPendingClosureFailureAbortsItsUploads (1.00s)987=== CONT TestGCTaskStore_GetReturnsLatest988--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)989=== CONT TestService_healthCheckHandler9902026/10/01 10:34:00 INFO Received uploads request method=POST path=/api/pending_closures991=== CONT TestPush_SignsNarinfosOfItsPendingObjects992--- PASS: TestGracefulShutdownDrainsInflight (0.07s)9932026/10/01 10:34:00 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9942026/10/01 10:34:00 WARN Refused reserved pin name=worker-x86_64-linux9952026/10/01 10:34:00 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9962026/10/01 10:34:00 INFO Received create pin request method=POST path=/api/pins/my-app9972026/10/01 10:34:00 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9982026/10/01 10:34:00 INFO Received uploads request method=POST path=/api/pending_closures999--- PASS: TestCreatePin_ReservedPins (1.09s)1000=== CONT TestGCTaskStore_GetEmpty1001--- PASS: TestGCTaskStore_GetEmpty (0.00s)1002=== CONT TestRedundantMultipartUpload1003=== NAME TestOrphanedObjectsGC1004 orphaned_objects_gc_test.go:290: GC Test Summary:1005 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1006 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1007 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1008 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1009 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects10102026/10/01 10:34:00 INFO Received create pin request method=POST path=/api/pins/deploy10112026/10/01 10:34:00 INFO Received create pin request method=POST path=/api/pins/deploy10122026/10/01 10:34:00 INFO Received create pin request method=POST path=/api/pins/deploy10132026/10/01 10:34:00 INFO Received create pin request method=POST path=/api/pins/deploy10142026/10/01 10:34:00 INFO Received create pin request method=POST path=/api/pins/deploy10152026/10/01 10:34:00 INFO Received create pin request method=POST path=/api/pins/deploy10162026/10/01 10:34:00 INFO Received create pin request method=POST path=/api/pins/deploy10172026/10/01 10:34:00 INFO Received create pin request method=POST path=/api/pins/deploy1018--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.13s)1019=== CONT TestGCTaskStore_StartNew1020--- PASS: TestGCTaskStore_StartNew (0.00s)1021=== CONT TestGCEndsOnShutdown1022=== RUN TestGCEndsOnShutdown/before_the_run1023=== PAUSE TestGCEndsOnShutdown/before_the_run1024=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1025=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1026=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1027=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1028=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1029--- PASS: TestOrphanedObjectsGC (1.13s)1030=== CONT TestCompleteMultipartUpload_ErrorButObjectExists10312026/10/01 10:34:00 INFO Starting HTTP server address=127.0.0.1:3684310322026/10/01 10:34:00 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket123989174/001/proxy.sock10332026/10/01 10:34:00 WARN mTLS auth: subject not in bound subjects subject="CN=someone"10342026/10/01 10:34:00 INFO Shutdown signal received, draining in-flight requests timeout=10s1035--- PASS: TestProxyHeadersOnlyTrustedOnSocket (1.18s)1036=== CONT TestPush_CompleteCommitsEveryRoot10372026/10/01 10:34:00 INFO Received create pin request method=POST path=/api/pins/deploy10382026/10/01 10:34:00 INFO Received uploads request method=POST path=/api/pending_closures10392026/10/01 10:34:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1040--- PASS: TestReconnectLeavesObjectsUnlocked (1.24s)10412026/10/01 10:34:00 INFO Received uploads request method=POST path=/api/pending_closures1042=== CONT TestGCTaskStore_DeduplicateSameParams1043=== CONT TestPush_RejectsBadRequests1044--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)10452026/10/01 10:34:00 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZmRlMzYxNDItYTUyOS00MWNjLThiNTEtOWI2YWI2Mzc1OGE3LmViNWZmMjRkLWIyN2EtNGMxZi05OTE2LTdmMmI2MjVjMTE4OHgxNzkwODUwODM5OTEzOTk3OTM2 parts=1010462026/10/01 10:34:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10472026/10/01 10:34:00 INFO Completed upload id=110482026/10/01 10:34:00 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010492026/10/01 10:34:00 INFO Received uploads request method=POST path=/api/pending_closures1050--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.87s)1051=== CONT TestSweepRechecksPendingAfterLocking10522026/10/01 10:34:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures10532026/10/01 10:34:00 INFO Aborted multipart uploads count=0 kept=010542026/10/01 10:34:00 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010552026/10/01 10:34:00 INFO Vacuumed table table=pending_closures10562026/10/01 10:34:00 INFO Vacuumed table table=pending_objects10572026/10/01 10:34:00 INFO Vacuumed table table=multipart_uploads10582026/10/01 10:34:00 INFO Vacuumed table table=closures10592026/10/01 10:34:00 INFO Vacuumed table table=objects10602026/10/01 10:34:00 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo10612026/10/01 10:34:00 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001062--- PASS: TestObjectStatsTrigger (0.77s)1063=== CONT TestCommitRacingPendingCleanupKeepsObjects1064--- PASS: TestService_createPendingClosureHandler (1.36s)1065=== CONT TestReadProxyHead10662026/10/01 10:34:00 INFO Received cleanup request method=DELETE path=/api/pending_closures10672026/10/01 10:34:00 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket27/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10682026/10/01 10:34:00 INFO Aborted multipart uploads count=0 kept=110692026/10/01 10:34:00 INFO Received cleanup request method=DELETE path=/api/pending_closures10702026/10/01 10:34:00 INFO Aborted multipart uploads count=1 kept=010712026/10/01 10:34:01 INFO Received create pin request method=POST path=/api/pins/deploy10722026/10/01 10:34:01 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo10732026/10/01 10:34:01 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo10742026/10/01 10:34:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1075--- PASS: TestMultipartCleanup (1.25s)1076=== CONT TestReadProxyNarStreaming1077--- PASS: TestConcurrentPinUpdatesAgree (1.70s)1078=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1079=== CONT TestReadProxyInvalidPath1080--- PASS: TestPendingClosureFailureTracksEveryUpload (1.68s)1081=== CONT TestReadProxyDisabled1082--- PASS: TestCreatePinRejectsBadInput (1.69s)10832026/10/01 10:34:01 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZmRlMzYxNDItYTUyOS00MWNjLThiNTEtOWI2YWI2Mzc1OGE3LmRmMDNlYzdjLThhYzAtNDE2Ni1hMTU3LThmN2QyZDcwZjU5M3gxNzkwODUwODM5OTY3MDUxODYy parts=1210842026/10/01 10:34:01 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10852026/10/01 10:34:01 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10862026/10/01 10:34:01 INFO Received uploads request method=POST path=/api/pending_closures1087--- PASS: TestMetricsInventory (1.00s)1088=== CONT TestReadProxyNarinfo1089--- PASS: TestService_NativeMTLS (0.92s)1090=== CONT TestReadProxyConditionalGet1091=== NAME TestNARDeduplicationMetadataUploadBug1092 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug4089677393/001/store/mkm0zaanvvkapwhckbw1zms9j8a1l7s3-file1.txt1093--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.76s)1094=== CONT TestReadProxyNarinfoAlreadyDecompressed10952026/10/01 10:34:01 WARN readiness check failed error="closed pool"1096--- PASS: TestService_readinessHandler (0.82s)1097=== CONT TestReadProxyOutlastsServerWriteTimeout10982026/10/01 10:34:01 INFO Received push request method=POST path=/api/pushes1099--- PASS: TestService_healthCheckHandler (0.83s)1100=== CONT TestClientIntegration11012026/10/01 10:34:01 INFO Received push request method=POST path=/api/pushes11022026/10/01 10:34:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11032026/10/01 10:34:01 INFO Uploading mkm0zaanvvkapwhckbw1zms9j8a1l7s3-file1.txt (160B)11042026/10/01 10:34:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11052026/10/01 10:34:01 INFO Received uploads request method=POST path=/api/pending_closures11062026/10/01 10:34:01 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11072026/10/01 10:34:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11082026/10/01 10:34:01 INFO Signed narinfos id=1 count=111092026/10/01 10:34:01 INFO Received push request method=POST path=/api/pushes11102026/10/01 10:34:01 INFO Received uploads request method=POST path=/api/pending_closures11112026/10/01 10:34:01 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZmRlMzYxNDItYTUyOS00MWNjLThiNTEtOWI2YWI2Mzc1OGE3LmVlMjU4ZGY5LWQyNWUtNDI2NC05MmY4LTI2ZGZiZDA4OWExNHgxNzkwODUwODQwMzI5ODQzNjUw parts=1011122026/10/01 10:34:01 WARN Failed to register uploaded object key=mkm0zaanvvkapwhckbw1zms9j8a1l7s3.ls error="server returned 404: 404 page not found\n"11132026/10/01 10:34:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11142026/10/01 10:34:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11152026/10/01 10:34:01 INFO Signed narinfos id=1 count=111162026/10/01 10:34:01 INFO Completed upload id=111172026/10/01 10:34:01 INFO Uploading 1 narinfos11182026/10/01 10:34:01 INFO Received uploads request method=POST path=/api/pending_closures1119--- PASS: TestReadRedirectKeepsNarinfoProxied (0.93s)1120=== CONT TestReadRedirectUsesPublicS3URL11212026/10/01 10:34:01 INFO Received uploads request method=POST path=/api/pending_closures1122--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.90s)1123=== CONT TestSweepSkipsRowsLockedByPush11242026/10/01 10:34:01 INFO Received complete push request method=POST path=/api/pushes/1/complete11252026/10/01 10:34:01 WARN Failed to register uploaded object key=mkm0zaanvvkapwhckbw1zms9j8a1l7s3.narinfo error="server returned 404: 404 page not found\n"11262026/10/01 10:34:01 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11272026/10/01 10:34:01 WARN Found objects in DB but missing from S3, will re-upload count=111282026/10/01 10:34:01 INFO Received uploads request method=POST path=/api/pending_closures11292026/10/01 10:34:01 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete11302026/10/01 10:34:01 INFO Upload complete. (169ms)11312026/10/01 10:34:01 INFO Completed upload id=31132=== NAME TestNARDeduplicationMetadataUploadBug1133 metadata_upload_test.go:54: Retrieved narinfo from S3:1134 StorePath: /build/TestNARDeduplicationMetadataUploadBug4089677393/001/store/mkm0zaanvvkapwhckbw1zms9j8a1l7s3-file1.txt1135 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1136 Compression: zstd1137 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1138 NarSize: 1601139 References: 1140 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1141 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1142 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1143 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}11442026/10/01 10:34:01 INFO Received push request method=POST path=/api/pushes1145=== CONT TestClientFallsBackToClosures1146--- PASS: TestService_verifyS3Integrity (1.99s)1147=== NAME TestNARDeduplicationMetadataUploadBug1148 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug4089677393/001/store/f4p6506d3gcmidfjcmciwn316clp1g52-file2.txt11492026/10/01 10:34:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11502026/10/01 10:34:01 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZmRlMzYxNDItYTUyOS00MWNjLThiNTEtOWI2YWI2Mzc1OGE3LjczNzM0ZjhkLTQ5MWUtNDdjMC05NTU0LTYwOGIwYmNmNTQ5ZXgxNzkwODUwODQxNDAyNzA1Mzg211512026/10/01 10:34:01 INFO Aborted multipart uploads count=0 kept=011522026/10/01 10:34:01 WARN Force mode enabled - objects will be deleted immediately without grace period1153=== RUN TestPush_RejectsBadRequests/no_roots1154=== PAUSE TestPush_RejectsBadRequests/no_roots1155=== RUN TestPush_RejectsBadRequests/no_objects1156=== PAUSE TestPush_RejectsBadRequests/no_objects1157=== RUN TestPush_RejectsBadRequests/bad_root1158=== PAUSE TestPush_RejectsBadRequests/bad_root1159=== RUN TestPush_RejectsBadRequests/root_not_in_objects1160=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1161=== CONT TestReadProxyRangeRequest11622026/10/01 10:34:01 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011632026/10/01 10:34:01 INFO Vacuumed table table=pending_closures11642026/10/01 10:34:01 INFO Vacuumed table table=pending_objects11652026/10/01 10:34:01 INFO Vacuumed table table=multipart_uploads11662026/10/01 10:34:01 INFO Vacuumed table table=closures11672026/10/01 10:34:01 INFO Vacuumed table table=objects11682026/10/01 10:34:01 INFO Received push request method=POST path=/api/pushes11692026/10/01 10:34:01 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11702026/10/01 10:34:01 WARN Failed to register uploaded object key=f4p6506d3gcmidfjcmciwn316clp1g52.ls error="server returned 404: 404 page not found\n"11712026/10/01 10:34:01 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign1172--- PASS: TestSweepRechecksPendingAfterLocking (0.83s)1173=== CONT TestClientPushesUseOnePush11742026/10/01 10:34:01 INFO Signed narinfos id=2 count=111752026/10/01 10:34:01 INFO Uploading 1 narinfos11762026/10/01 10:34:01 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZmRlMzYxNDItYTUyOS00MWNjLThiNTEtOWI2YWI2Mzc1OGE3LjczNzM0ZjhkLTQ5MWUtNDdjMC05NTU0LTYwOGIwYmNmNTQ5ZXgxNzkwODUwODQxNDAyNzA1Mzg2 error="Delete \"http://localhost:34839/bucket38/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=ZmRlMzYxNDItYTUyOS00MWNjLThiNTEtOWI2YWI2Mzc1OGE3LjczNzM0ZjhkLTQ5MWUtNDdjMC05NTU0LTYwOGIwYmNmNTQ5ZXgxNzkwODUwODQxNDAyNzA1Mzg2\": injected: abort refused"11772026/10/01 10:34:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11782026/10/01 10:34:01 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZmRlMzYxNDItYTUyOS00MWNjLThiNTEtOWI2YWI2Mzc1OGE3LjczNzM0ZjhkLTQ5MWUtNDdjMC05NTU0LTYwOGIwYmNmNTQ5ZXgxNzkwODUwODQxNDAyNzA1Mzg211792026/10/01 10:34:01 INFO Received complete push request method=POST path=/api/pushes/2/complete11802026/10/01 10:34:01 WARN Failed to register uploaded object key=f4p6506d3gcmidfjcmciwn316clp1g52.narinfo error="server returned 404: 404 page not found\n"11812026/10/01 10:34:01 INFO Upload complete. (80ms)1182=== NAME TestNARDeduplicationMetadataUploadBug1183 metadata_upload_test.go:76: Retrieved narinfo from S3:1184 StorePath: /build/TestNARDeduplicationMetadataUploadBug4089677393/001/store/f4p6506d3gcmidfjcmciwn316clp1g52-file2.txt1185 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1186 Compression: zstd1187 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1188 NarSize: 1601189 References: 1190 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf11912026/10/01 10:34:01 INFO Aborted multipart uploads count=0 kept=011922026/10/01 10:34:01 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZmRlMzYxNDItYTUyOS00MWNjLThiNTEtOWI2YWI2Mzc1OGE3LjczNzM0ZjhkLTQ5MWUtNDdjMC05NTU0LTYwOGIwYmNmNTQ5ZXgxNzkwODUwODQxNDAyNzA1Mzg2 parts=11193 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1194 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1195 {"version":1,"root":{"type":"regular","size":44}}11962026/10/01 10:34:01 WARN Force mode enabled - objects will be deleted immediately without grace period11972026/10/01 10:34:01 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=01198--- PASS: TestReadProxyDisabled (0.44s)1199=== CONT TestParseSingleRange1200=== RUN TestParseSingleRange/none1201=== PAUSE TestParseSingleRange/none1202=== RUN TestParseSingleRange/unknown_unit1203=== PAUSE TestParseSingleRange/unknown_unit1204=== RUN TestParseSingleRange/multi-range_ignored1205=== PAUSE TestParseSingleRange/multi-range_ignored12062026/10/01 10:34:01 INFO Vacuumed table table=pending_closures1207=== RUN TestParseSingleRange/malformed_no_dash1208=== PAUSE TestParseSingleRange/malformed_no_dash1209=== RUN TestParseSingleRange/malformed_both_empty1210=== PAUSE TestParseSingleRange/malformed_both_empty1211=== RUN TestParseSingleRange/malformed_end_before_start1212=== PAUSE TestParseSingleRange/malformed_end_before_start1213=== RUN TestParseSingleRange/closed1214=== PAUSE TestParseSingleRange/closed1215=== RUN TestParseSingleRange/open-ended1216=== PAUSE TestParseSingleRange/open-ended1217=== RUN TestParseSingleRange/end_clamped_to_size1218=== PAUSE TestParseSingleRange/end_clamped_to_size1219=== RUN TestParseSingleRange/suffix1220=== PAUSE TestParseSingleRange/suffix1221=== RUN TestParseSingleRange/suffix_exceeds_size1222=== PAUSE TestParseSingleRange/suffix_exceeds_size1223=== RUN TestParseSingleRange/single_byte1224=== PAUSE TestParseSingleRange/single_byte1225=== RUN TestParseSingleRange/start_past_EOF1226=== PAUSE TestParseSingleRange/start_past_EOF1227=== RUN TestParseSingleRange/start_far_past_EOF1228=== PAUSE TestParseSingleRange/start_far_past_EOF1229=== CONT TestClientSharedPathCommittedMidPush12302026/10/01 10:34:01 INFO Vacuumed table table=pending_objects12312026/10/01 10:34:01 INFO Vacuumed table table=multipart_uploads12322026/10/01 10:34:01 INFO Vacuumed table table=closures12332026/10/01 10:34:01 INFO Vacuumed table table=objects1234=== CONT TestTombstonedObjectOfferedWithoutWaiting1235--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.02s)1236--- PASS: TestNARDeduplicationMetadataUploadBug (1.41s)1237=== CONT TestClientWithDependencies1238--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.84s)1239=== CONT TestClientErrorHandling1240=== RUN TestClientErrorHandling/InvalidStorePath1241=== PAUSE TestClientErrorHandling/InvalidStorePath1242=== RUN TestClientErrorHandling/InvalidAuthToken1243=== PAUSE TestClientErrorHandling/InvalidAuthToken1244=== RUN TestClientErrorHandling/ServerNotAvailable1245=== PAUSE TestClientErrorHandling/ServerNotAvailable1246=== CONT TestConnectWaitsForAPeerMigration1247--- PASS: TestReadProxyNarStreaming (0.49s)1248=== CONT TestLeadElectsOneAndHandsOver1249=== CONT TestLeadEndsOnShutdown1250--- PASS: TestReadProxyInvalidPath (0.54s)12512026/10/01 10:34:01 INFO Received push request method=POST path=/api/pushes1252--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.62s)1253=== CONT TestConnectSerialisesConcurrentMigrations1254--- PASS: TestReadProxyHead (0.99s)1255=== CONT TestService_ReadAuthMiddleware1256--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.63s)1257=== CONT TestService_AuthMiddleware_MTLSProxyHeader12582026-10-01 10:34:01.850 UTC [1021] ERROR: duplicate key value violates unique constraint "pg_type_typname_nsp_index"12592026-10-01 10:34:01.850 UTC [1021] DETAIL: Key (typname, typnamespace)=(goose_db_version, 2200) already exists.12602026-10-01 10:34:01.850 UTC [1021] STATEMENT: CREATE TABLE goose_db_version (1261 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1262 version_id bigint NOT NULL,1263 is_applied boolean NOT NULL,1264 tstamp timestamp NOT NULL DEFAULT now()1265 )1266=== NAME TestClientIntegration1267 client_integration_test.go:334: Created store path: /build/TestClientIntegration1287834305/002/store/g3cm5n8lhxv81m7m6n9hghm606skm677-test-file.txt12682026/10/01 10:34:01 INFO Aborted multipart uploads count=0 kept=012692026/10/01 10:34:01 WARN Force mode enabled - objects will be deleted immediately without grace period12702026/10/01 10:34:01 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=01271--- PASS: TestReadProxyConditionalGet (0.77s)12722026/10/01 10:34:01 INFO Vacuumed table table=pending_closures1273=== CONT TestService_AuthMiddleware12742026/10/01 10:34:01 INFO Vacuumed table table=pending_objects12752026/10/01 10:34:01 INFO Vacuumed table table=multipart_uploads12762026/10/01 10:34:01 INFO Vacuumed table table=closures12772026/10/01 10:34:01 INFO Vacuumed table table=objects12782026/10/01 10:34:01 INFO Aborted multipart uploads count=0 kept=012792026/10/01 10:34:01 WARN Force mode enabled - objects will be deleted immediately without grace period12802026/10/01 10:34:01 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=012812026/10/01 10:34:01 INFO Vacuumed table table=pending_closures12822026/10/01 10:34:01 INFO Vacuumed table table=pending_objects12832026/10/01 10:34:01 INFO Vacuumed table table=multipart_uploads12842026/10/01 10:34:01 INFO Vacuumed table table=closures12852026/10/01 10:34:01 INFO Received push request method=POST path=/api/pushes12862026/10/01 10:34:01 INFO Vacuumed table table=objects12872026/10/01 10:34:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12882026/10/01 10:34:01 INFO Uploading g3cm5n8lhxv81m7m6n9hghm606skm677-test-file.txt (152B)1289--- PASS: TestSweepSkipsRowsLockedByPush (0.63s)1290=== CONT TestService_AuthMiddleware_OIDC12912026/10/01 10:34:02 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12922026/10/01 10:34:02 WARN Failed to register uploaded object key=g3cm5n8lhxv81m7m6n9hghm606skm677.ls error="server returned 404: 404 page not found\n"12932026/10/01 10:34:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12942026/10/01 10:34:02 INFO Signed narinfos id=1 count=112952026/10/01 10:34:02 INFO Uploading 1 narinfos1296=== CONT TestCacheConfigHandler1297--- PASS: TestReadProxyRangeRequest (0.54s)1298=== RUN TestCacheConfigHandler/full_config,_no_issuer1299=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1300=== RUN TestCacheConfigHandler/no_cache_url_configured1301=== PAUSE TestCacheConfigHandler/no_cache_url_configured1302=== RUN TestCacheConfigHandler/no_signing_keys1303=== PAUSE TestCacheConfigHandler/no_signing_keys1304=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1305=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1306=== CONT TestService_RequireScope_OIDC13072026/10/01 10:34:02 INFO Received complete push request method=POST path=/api/pushes/1/complete13082026/10/01 10:34:02 WARN Failed to register uploaded object key=g3cm5n8lhxv81m7m6n9hghm606skm677.narinfo error="server returned 404: 404 page not found\n"13092026/10/01 10:34:02 INFO Upload complete. (107ms)1310--- PASS: TestReadRedirectUsesPublicS3URL (0.68s)1311=== CONT TestReadProxyRootRedirectsToIndexHTML13122026/10/01 10:34:02 INFO Received uploads request method=POST path=/api/pending_closures13132026/10/01 10:34:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13142026/10/01 10:34:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45181/oidc13152026/10/01 10:34:02 INFO All 1 paths already cached1316=== NAME TestClientIntegration1317 client_integration_test.go:360: Retrieved narinfo from S3:1318 StorePath: /build/TestClientIntegration1287834305/002/store/g3cm5n8lhxv81m7m6n9hghm606skm677-test-file.txt1319 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1320 Compression: zstd1321 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11322 NarSize: 1521323 References: 1324 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk113252026/10/01 10:34:02 INFO lead: acquired remote=192.0.2.1:12341326=== CONT TestGCBugBareHashReferences1327--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.51s)1328=== NAME TestClientIntegration1329 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)1330 client_integration_test.go:361: Decompressed .ls content (64 bytes):1331 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}13322026/10/01 10:34:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45763/oidc13332026/10/01 10:34:02 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZmRlMzYxNDItYTUyOS00MWNjLThiNTEtOWI2YWI2Mzc1OGE3LjMzMTYxYTg5LWRiNzktNGUxYS04MDJhLThhNTQ2NzYzNGI5MXgxNzkwODUwODQxMzcwOTEwMDgx parts=1013342026/10/01 10:34:02 INFO Received uploads request method=POST path=/api/pending_closures13352026/10/01 10:34:02 INFO Received uploads request method=POST path=/api/pending_closures13362026/10/01 10:34:02 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13372026/10/01 10:34:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13382026/10/01 10:34:02 INFO Uploading l8fqx8lkgm9pdv5f52yim5imvbp2msjb-shared-dep (136B)13392026/10/01 10:34:02 INFO Uploading mdmdwqr2l87m075sfm1p8n5vsyifdx3k-b (216B)13402026/10/01 10:34:02 WARN Failed to register uploaded object key=44xxrxhgwzlc4p3djgjwvraxwszgxcc6.ls error="server returned 404: 404 page not found\n"13412026/10/01 10:34:02 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13422026/10/01 10:34:02 INFO lead: acquired remote=192.0.2.1:123413432026/10/01 10:34:02 INFO Received push request method=POST path=/api/pushes13442026/10/01 10:34:02 WARN Failed to register uploaded object key=nar/0n6k2zgd782ba0r9hj4ici38xjlf87h79wcdgk9mj7qndl9ljh5r.nar.zst error="server returned 404: 404 page not found\n"13452026/10/01 10:34:02 WARN Failed to register uploaded object key=mdmdwqr2l87m075sfm1p8n5vsyifdx3k.ls error="server returned 404: 404 page not found\n"13462026/10/01 10:34:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13472026/10/01 10:34:02 INFO Object in database but missing from S3 key=g3cm5n8lhxv81m7m6n9hghm606skm677.ls13482026/10/01 10:34:02 WARN Found objects in DB but missing from S3, will re-upload count=113492026/10/01 10:34:02 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13502026/10/01 10:34:02 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13512026/10/01 10:34:02 WARN Failed to register uploaded object key=l8fqx8lkgm9pdv5f52yim5imvbp2msjb.ls error="server returned 404: 404 page not found\n"13522026/10/01 10:34:02 INFO Signed narinfos id=1 count=213532026/10/01 10:34:02 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13542026/10/01 10:34:02 INFO Signed narinfos id=2 count=213552026/10/01 10:34:02 INFO Received complete push request method=POST path=/api/pushes/2/complete13562026/10/01 10:34:02 INFO Uploading 4 narinfos13572026/10/01 10:34:02 WARN Failed to register uploaded object key=g3cm5n8lhxv81m7m6n9hghm606skm677.ls error="server returned 404: 404 page not found\n"13582026/10/01 10:34:02 INFO Upload complete. (58ms)13592026/10/01 10:34:02 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZmRlMzYxNDItYTUyOS00MWNjLThiNTEtOWI2YWI2Mzc1OGE3LmZhNzMyMzE2LTFlOWEtNDA5Zi05ZTA1LTBhMTJhMjAxN2Y4OHgxNzkwODUwODQxNDQzNjMwODEx parts=101360 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)1361 client_integration_test.go:389: Decompressed .ls content (49 bytes):1362 {"version":1,"root":{"type":"regular","size":39}}13632026/10/01 10:34:02 INFO Received push request method=POST path=/api/pushes13642026/10/01 10:34:02 WARN Failed to register uploaded object key=l8fqx8lkgm9pdv5f52yim5imvbp2msjb.narinfo error="server returned 404: 404 page not found\n"13652026/10/01 10:34:02 WARN Failed to register uploaded object key=l8fqx8lkgm9pdv5f52yim5imvbp2msjb.narinfo error="server returned 404: 404 page not found\n"13662026/10/01 10:34:02 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZmRlMzYxNDItYTUyOS00MWNjLThiNTEtOWI2YWI2Mzc1OGE3LjMwMmY3N2M0LTNhN2YtNGVhNS05NWE3LTU4ZDI2YTBkNmRkMXgxNzkwODUwODQxMzMwNzcyOTAy parts=1213672026/10/01 10:34:02 WARN Failed to register uploaded object key=mdmdwqr2l87m075sfm1p8n5vsyifdx3k.narinfo error="server returned 404: 404 page not found\n"13682026/10/01 10:34:02 INFO Received push request method=POST path=/api/pushes13692026/10/01 10:34:02 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)13702026/10/01 10:34:02 INFO Uploading 84nlcmbpjmgipg7wbdi80r4amq4khd4l-top (224B)13712026/10/01 10:34:02 INFO Uploading lzmf9i11hafwddglf5yzvh175iy8jwjr-shared-dep (136B)13722026/10/01 10:34:02 INFO Received uploads request method=POST path=/api/pending_closures13732026/10/01 10:34:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13742026/10/01 10:34:02 WARN Failed to register uploaded object key=44xxrxhgwzlc4p3djgjwvraxwszgxcc6.narinfo error="server returned 404: 404 page not found\n"1375=== CONT TestGCMetrics1376--- PASS: TestService_ReadAuthMiddleware (0.47s)13772026/10/01 10:34:02 INFO Completed upload id=11378=== NAME TestClientWithDependencies13792026/10/01 10:34:02 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1380 client_integration_test.go:735: Built derivation: /build/TestClientWithDependencies3712303337/001/store/p82fm0pr5swxmvxdgxr1ivrlw2hv330s-test-script13812026/10/01 10:34:02 INFO Completed upload id=213822026/10/01 10:34:02 INFO Upload complete. (159ms)1383=== NAME TestClientFallsBackToClosures1384 client_pushes_test.go:112: Retrieved narinfo from S3:1385 StorePath: /build/TestClientFallsBackToClosures2534555384/001/store/l8fqx8lkgm9pdv5f52yim5imvbp2msjb-shared-dep1386 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1387 Compression: zstd1388 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821389 NarSize: 1361390 References: 1391 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13922026/10/01 10:34:02 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"13932026/10/01 10:34:02 INFO Received uploads request method=POST path=/api/pending_closures13942026/10/01 10:34:02 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)1395--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.45s)1396=== CONT TestReadRedirectNar13972026/10/01 10:34:02 INFO Uploading mhn6w4vy0aip6qw4wl2giww5ipwg5s1q-shared-dep (136B)13982026/10/01 10:34:02 INFO Uploading i1c5x8qij6dk7vszkm8gs2pd9z2lccc2-a (216B)1399=== NAME TestClientFallsBackToClosures1400 client_pushes_test.go:112: Retrieved narinfo from S3:1401 StorePath: /build/TestClientFallsBackToClosures2534555384/001/store/44xxrxhgwzlc4p3djgjwvraxwszgxcc6-a1402 URL: nar/0n6k2zgd782ba0r9hj4ici38xjlf87h79wcdgk9mj7qndl9ljh5r.nar.zst1403 Compression: zstd1404 NarHash: sha256:0n6k2zgd782ba0r9hj4ici38xjlf87h79wcdgk9mj7qndl9ljh5r1405 NarSize: 2161406 References: /build/TestClientFallsBackToClosures2534555384/001/store/l8fqx8lkgm9pdv5f52yim5imvbp2msjb-shared-dep1407 CA: text:sha256:05p3y5pj7np0b4dsl9z83ljxczyrhnxz2vdcs5vghjrlk4ssq4w114082026/10/01 10:34:02 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1409 client_pushes_test.go:112: Retrieved narinfo from S3:1410 StorePath: /build/TestClientFallsBackToClosures2534555384/001/store/mdmdwqr2l87m075sfm1p8n5vsyifdx3k-b1411 URL: nar/0n6k2zgd782ba0r9hj4ici38xjlf87h79wcdgk9mj7qndl9ljh5r.nar.zst1412 Compression: zstd1413 NarHash: sha256:0n6k2zgd782ba0r9hj4ici38xjlf87h79wcdgk9mj7qndl9ljh5r1414 NarSize: 2161415 References: /build/TestClientFallsBackToClosures2534555384/001/store/l8fqx8lkgm9pdv5f52yim5imvbp2msjb-shared-dep14162026/10/01 10:34:02 WARN Failed to register uploaded object key=nar/0j8j5q28qr3jagsws69v5ajkyp22b29pc6awiilczcj3ml4d4vqp.nar.zst error="server returned 404: 404 page not found\n"1417 CA: text:sha256:05p3y5pj7np0b4dsl9z83ljxczyrhnxz2vdcs5vghjrlk4ssq4w11418--- PASS: TestService_AuthMiddleware (0.34s)1419=== CONT TestGCTaskStore_ConflictDifferentParams1420--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1421=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1422=== NAME TestClientWithDependencies1423 client_integration_test.go:737: Found 1 dependencies (including self)14242026/10/01 10:34:02 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14252026/10/01 10:34:02 INFO Received push request method=POST path=/api/pushes14262026/10/01 10:34:02 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14272026/10/01 10:34:02 WARN Failed to register uploaded object key=lzmf9i11hafwddglf5yzvh175iy8jwjr.ls error="server returned 404: 404 page not found\n"14282026/10/01 10:34:02 WARN Failed to register uploaded object key=nar/14jqc84r9fxsspy8spnw8azxvqh8kyd5akdx6560qpijkz3ibqwv.nar.zst error="server returned 404: 404 page not found\n"14292026/10/01 10:34:02 WARN Failed to register uploaded object key=i1c5x8qij6dk7vszkm8gs2pd9z2lccc2.ls error="server returned 404: 404 page not found\n"14302026/10/01 10:34:02 WARN Failed to register uploaded object key=03b1ps3kzr7vi2vzbn3iaa3nf14bia0k.ls error="server returned 404: 404 page not found\n"14312026/10/01 10:34:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14322026/10/01 10:34:02 WARN Failed to register uploaded object key=mhn6w4vy0aip6qw4wl2giww5ipwg5s1q.ls error="server returned 404: 404 page not found\n"14332026/10/01 10:34:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14342026/10/01 10:34:02 WARN Failed to register uploaded object key=84nlcmbpjmgipg7wbdi80r4amq4khd4l.ls error="server returned 404: 404 page not found\n"14352026/10/01 10:34:02 INFO Signed narinfos id=1 count=314362026/10/01 10:34:02 INFO Signed narinfos id=1 count=214372026/10/01 10:34:02 INFO Uploading 3 narinfos14382026/10/01 10:34:02 INFO Uploading 2 narinfos14392026/10/01 10:34:02 WARN Failed to register uploaded object key=g3cm5n8lhxv81m7m6n9hghm606skm677.ls error="server returned 404: 404 page not found\n"14402026/10/01 10:34:02 INFO Received complete push request method=POST path=/api/pushes/3/complete14412026/10/01 10:34:02 INFO Upload complete. (57ms)14422026/10/01 10:34:02 WARN Failed to register uploaded object key=mhn6w4vy0aip6qw4wl2giww5ipwg5s1q.narinfo error="server returned 404: 404 page not found\n"14432026/10/01 10:34:02 WARN Failed to register uploaded object key=03b1ps3kzr7vi2vzbn3iaa3nf14bia0k.narinfo error="server returned 404: 404 page not found\n"1444=== NAME TestClientIntegration1445 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)1446 client_integration_test.go:405: Decompressed .ls content (49 bytes):1447 {"version":1,"root":{"type":"regular","size":39}}1448=== CONT TestRegisterCompletedObjectNeedsPendingRow1449--- PASS: TestClientFallsBackToClosures (0.90s)14502026/10/01 10:34:02 INFO Received complete push request method=POST path=/api/pushes/1/complete14512026/10/01 10:34:02 WARN Failed to register uploaded object key=i1c5x8qij6dk7vszkm8gs2pd9z2lccc2.narinfo error="server returned 404: 404 page not found\n"1452=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1453=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1454--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.27s)1455=== CONT TestResolveDBConnectionString1456=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1457=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1458=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1459=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1460=== RUN TestResolveDBConnectionString/flag_wins1461=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1462=== PAUSE TestResolveDBConnectionString/flag_wins1463=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1464=== RUN TestResolveDBConnectionString/file_when_flag_empty1465=== CONT TestGetExistingObjectsLocksRows1466=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1467=== RUN TestResolveDBConnectionString/missing_file_is_an_error1468=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1469=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1470=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1471=== RUN TestResolveDBConnectionString/nothing_configured1472=== PAUSE TestResolveDBConnectionString/nothing_configured1473=== CONT TestFailedS3DeleteKeepsTombstone14742026/10/01 10:34:02 INFO Received complete push request method=POST path=/api/pushes/1/complete14752026/10/01 10:34:02 WARN Failed to register uploaded object key=84nlcmbpjmgipg7wbdi80r4amq4khd4l.narinfo error="server returned 404: 404 page not found\n"14762026/10/01 10:34:02 WARN Failed to register uploaded object key=lzmf9i11hafwddglf5yzvh175iy8jwjr.narinfo error="server returned 404: 404 page not found\n"14772026/10/01 10:34:02 INFO Upload complete. (152ms)1478=== NAME TestClientPushesUseOnePush1479 client_pushes_test.go:97: Retrieved narinfo from S3:1480 StorePath: /build/TestClientPushesUseOnePush2563332381/001/store/mhn6w4vy0aip6qw4wl2giww5ipwg5s1q-shared-dep1481 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1482 Compression: zstd14832026/10/01 10:34:02 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"1484 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821485 NarSize: 1361486 References: 1487 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n14882026/10/01 10:34:02 INFO Upload complete. (172ms)1489=== NAME TestClientSharedPathCommittedMidPush1490 client_integration_test.go:816: Retrieved narinfo from S3:1491 StorePath: /build/TestClientSharedPathCommittedMidPush4101518907/001/store/lzmf9i11hafwddglf5yzvh175iy8jwjr-shared-dep1492 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1493 Compression: zstd1494 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821495 NarSize: 1361496 References: 1497 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1498=== NAME TestClientPushesUseOnePush1499 client_pushes_test.go:97: Retrieved narinfo from S3:1500 StorePath: /build/TestClientPushesUseOnePush2563332381/001/store/i1c5x8qij6dk7vszkm8gs2pd9z2lccc2-a1501 URL: nar/14jqc84r9fxsspy8spnw8azxvqh8kyd5akdx6560qpijkz3ibqwv.nar.zst1502 Compression: zstd1503 NarHash: sha256:14jqc84r9fxsspy8spnw8azxvqh8kyd5akdx6560qpijkz3ibqwv1504 NarSize: 2161505 References: /build/TestClientPushesUseOnePush2563332381/001/store/mhn6w4vy0aip6qw4wl2giww5ipwg5s1q-shared-dep1506 CA: text:sha256:175n3pf7yimi2y2qrkkyl27nrblfwxawkkzffglrvl7vq6lf1plp1507 client_pushes_test.go:97: Retrieved narinfo from S3:1508 StorePath: /build/TestClientPushesUseOnePush2563332381/001/store/03b1ps3kzr7vi2vzbn3iaa3nf14bia0k-b1509 URL: nar/14jqc84r9fxsspy8spnw8azxvqh8kyd5akdx6560qpijkz3ibqwv.nar.zst1510 Compression: zstd1511 NarHash: sha256:14jqc84r9fxsspy8spnw8azxvqh8kyd5akdx6560qpijkz3ibqwv1512 NarSize: 2161513 References: /build/TestClientPushesUseOnePush2563332381/001/store/mhn6w4vy0aip6qw4wl2giww5ipwg5s1q-shared-dep1514 CA: text:sha256:175n3pf7yimi2y2qrkkyl27nrblfwxawkkzffglrvl7vq6lf1plp1515=== NAME TestClientSharedPathCommittedMidPush1516 client_integration_test.go:816: Retrieved narinfo from S3:1517 StorePath: /build/TestClientSharedPathCommittedMidPush4101518907/001/store/84nlcmbpjmgipg7wbdi80r4amq4khd4l-top1518 URL: nar/0j8j5q28qr3jagsws69v5ajkyp22b29pc6awiilczcj3ml4d4vqp.nar.zst1519 Compression: zstd1520 NarHash: sha256:0j8j5q28qr3jagsws69v5ajkyp22b29pc6awiilczcj3ml4d4vqp1521 NarSize: 2241522 References: /build/TestClientSharedPathCommittedMidPush4101518907/001/store/lzmf9i11hafwddglf5yzvh175iy8jwjr-shared-dep1523 CA: text:sha256:0ay9b5qh7hc38vgbdfndc039f2p9h2qgm3ikxvbxdxwl8rnfks9r15242026/10/01 10:34:02 INFO Received push request method=POST path=/api/pushes15252026/10/01 10:34:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15262026/10/01 10:34:02 INFO Uploading p82fm0pr5swxmvxdgxr1ivrlw2hv330s-test-script (136B)1527=== CONT TestPinProtectsFromGC1528--- PASS: TestClientSharedPathCommittedMidPush (0.81s)1529--- PASS: TestClientPushesUseOnePush (0.85s)1530=== CONT TestForceGCDuringPushOffersSweptObject1531=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1532=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1533=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1534=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1535=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection15362026/10/01 10:34:02 WARN Failed to register uploaded object key=log/qhrsnxwcqhavi3z4zn413049mhj2bvxl-test-script.drv error="server returned 404: 404 page not found\n"15372026/10/01 10:34:02 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"1538=== RUN TestService_RequireScope_OIDC/builder_may_write1539=== PAUSE TestService_RequireScope_OIDC/builder_may_write1540=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1541=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1542=== RUN TestService_RequireScope_OIDC/ops_may_admin1543=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1544=== RUN TestService_RequireScope_OIDC/ops_may_not_write1545=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1546=== RUN TestService_RequireScope_OIDC/reader_may_not_write1547=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1548=== RUN TestService_RequireScope_OIDC/static_token_may_admin1549=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1550=== RUN TestService_RequireScope_OIDC/static_token_may_write1551=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1552=== RUN TestService_RequireScope_OIDC/reader_may_read1553=== PAUSE TestService_RequireScope_OIDC/reader_may_read1554=== RUN TestService_RequireScope_OIDC/writer_implies_read1555=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1556=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1557=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1558=== CONT TestGCSweepDeliversEachKeyOnce15592026/10/01 10:34:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15602026/10/01 10:34:02 WARN Failed to register uploaded object key=p82fm0pr5swxmvxdgxr1ivrlw2hv330s.ls error="server returned 404: 404 page not found\n"15612026/10/01 10:34:02 INFO Signed narinfos id=1 count=115622026/10/01 10:34:02 INFO Uploading 1 narinfos15632026/10/01 10:34:02 INFO Received complete push request method=POST path=/api/pushes/1/complete15642026/10/01 10:34:02 WARN Failed to register uploaded object key=p82fm0pr5swxmvxdgxr1ivrlw2hv330s.narinfo error="server returned 404: 404 page not found\n"15652026/10/01 10:34:02 INFO Upload complete. (91ms)15662026/10/01 10:34:02 INFO Received push request method=POST path=/api/pushes15672026/10/01 10:34:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15682026/10/01 10:34:02 INFO Uploading 78n3ynl7d8bnwb7rd3rhh9q10f0lhzx5-lost-commit.txt (152B)15692026/10/01 10:34:02 INFO Aborted multipart uploads count=0 kept=015702026/10/01 10:34:02 WARN Force mode enabled - objects will be deleted immediately without grace period15712026/10/01 10:34:02 WARN Failed to register uploaded object key=78n3ynl7d8bnwb7rd3rhh9q10f0lhzx5.ls error="server returned 404: 404 page not found\n"15722026/10/01 10:34:02 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015732026/10/01 10:34:02 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"15742026/10/01 10:34:02 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign15752026/10/01 10:34:02 INFO Signed narinfos id=4 count=115762026/10/01 10:34:02 INFO Uploading 1 narinfos15772026/10/01 10:34:02 INFO Vacuumed table table=pending_closures15782026/10/01 10:34:02 INFO Received complete push request method=POST path=/api/pushes/4/complete15792026/10/01 10:34:02 WARN Failed to register uploaded object key=78n3ynl7d8bnwb7rd3rhh9q10f0lhzx5.narinfo error="server returned 404: 404 page not found\n"15802026/10/01 10:34:02 INFO Vacuumed table table=pending_objects15812026/10/01 10:34:02 INFO Vacuumed table table=multipart_uploads15822026/10/01 10:34:02 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://127.0.0.1:39229/api/pushes/4/complete\": EOF" url=http://127.0.0.1:39229/api/pushes/4/complete15832026/10/01 10:34:02 INFO Vacuumed table table=closures15842026/10/01 10:34:02 INFO Vacuumed table table=objects1585=== NAME TestClientWithDependencies1586 client_integration_test.go:753: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3712303337/001/store) requires matching store prefix15872026/10/01 10:34:02 INFO Aborted multipart uploads count=0 kept=015882026/10/01 10:34:02 WARN Force mode enabled - objects will be deleted immediately without grace period15892026/10/01 10:34:02 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015902026/10/01 10:34:02 INFO Vacuumed table table=pending_closures15912026/10/01 10:34:02 INFO Vacuumed table table=pending_objects15922026/10/01 10:34:02 INFO Vacuumed table table=multipart_uploads15932026/10/01 10:34:02 INFO Vacuumed table table=closures15942026/10/01 10:34:02 INFO Vacuumed table table=objects1595--- PASS: TestClientWithDependencies (0.89s)1596=== CONT TestIsValidCachePath1597=== RUN TestIsValidCachePath/narinfo1598=== PAUSE TestIsValidCachePath/narinfo1599=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1600=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1601=== RUN TestIsValidCachePath/nar_zst1602=== PAUSE TestIsValidCachePath/nar_zst1603=== RUN TestIsValidCachePath/nar_xz1604=== PAUSE TestIsValidCachePath/nar_xz1605=== RUN TestIsValidCachePath/nar_bz21606=== PAUSE TestIsValidCachePath/nar_bz21607=== RUN TestIsValidCachePath/nar_uncompressed1608=== PAUSE TestIsValidCachePath/nar_uncompressed1609=== RUN TestIsValidCachePath/ls1610=== PAUSE TestIsValidCachePath/ls1611=== RUN TestIsValidCachePath/log1612=== PAUSE TestIsValidCachePath/log1613=== RUN TestIsValidCachePath/realisation1614=== PAUSE TestIsValidCachePath/realisation1615=== RUN TestIsValidCachePath/nix-cache-info1616=== PAUSE TestIsValidCachePath/nix-cache-info1617=== RUN TestIsValidCachePath/index.html1618=== PAUSE TestIsValidCachePath/index.html1619=== RUN TestIsValidCachePath/traversal_parent1620=== PAUSE TestIsValidCachePath/traversal_parent1621=== RUN TestIsValidCachePath/traversal_in_middle1622=== PAUSE TestIsValidCachePath/traversal_in_middle1623=== RUN TestIsValidCachePath/invalid_char_e1624=== PAUSE TestIsValidCachePath/invalid_char_e1625=== RUN TestIsValidCachePath/invalid_char_u1626=== PAUSE TestIsValidCachePath/invalid_char_u1627=== RUN TestIsValidCachePath/random_path1628=== PAUSE TestIsValidCachePath/random_path1629=== RUN TestIsValidCachePath/empty1630=== PAUSE TestIsValidCachePath/empty1631=== RUN TestIsValidCachePath/leading_slash1632=== PAUSE TestIsValidCachePath/leading_slash1633=== RUN TestIsValidCachePath/wrong_extension1634=== PAUSE TestIsValidCachePath/wrong_extension1635=== RUN TestIsValidCachePath/short_hash1636=== PAUSE TestIsValidCachePath/short_hash1637=== CONT TestClientMultipleUploads1638=== CONT TestReadProxy4041639--- PASS: TestReadRedirectNar (0.25s)1640--- PASS: TestGCMetrics (0.30s)1641=== CONT TestGCAdvisoryLockBlocksConcurrentRun16422026/10/01 10:34:02 INFO Received complete push request method=POST path=/api/pushes/4/complete16432026-10-01 10:34:02.552 UTC [910] ERROR: Push does not exist: id=416442026-10-01 10:34:02.552 UTC [910] CONTEXT: PL/pgSQL function commit_push(bigint) line 9 at RAISE16452026-10-01 10:34:02.552 UTC [910] STATEMENT: -- name: CommitPush :exec1646 SELECT commit_push($1::bigint)1647 16482026/10/01 10:34:02 INFO Upload complete. (172ms)1649=== NAME TestClientIntegration1650 client_integration_test.go:435: Retrieved narinfo from S3:1651 StorePath: /build/TestClientIntegration1287834305/002/store/78n3ynl7d8bnwb7rd3rhh9q10f0lhzx5-lost-commit.txt1652 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1653 Compression: zstd1654 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1655 NarSize: 1521656 References: 1657 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1658 client_integration_test.go:438: Testing garbage collection...1659--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.25s)1660=== CONT TestGCSweepSkipsPendingObjects16612026/10/01 10:34:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures16622026/10/01 10:34:02 INFO Garbage collection started16632026/10/01 10:34:02 INFO Received uploads request method=POST path=/api/pending_closures16642026/10/01 10:34:02 INFO Aborted multipart uploads count=0 kept=01665--- PASS: TestGetExistingObjectsLocksRows (0.29s)1666=== CONT TestClientCADerivations1667--- PASS: TestGCBugBareHashReferences (0.53s)1668=== CONT TestPushDedupSurvivesConcurrentGC16692026/10/01 10:34:02 WARN Force mode enabled - objects will be deleted immediately without grace period16702026/10/01 10:34:02 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=016712026/10/01 10:34:02 INFO Vacuumed table table=pending_closures16722026/10/01 10:34:02 INFO Vacuumed table table=pending_objects16732026/10/01 10:34:02 INFO Vacuumed table table=multipart_uploads16742026/10/01 10:34:02 INFO Vacuumed table table=closures16752026/10/01 10:34:02 INFO Vacuumed table table=objects16762026/10/01 10:34:02 INFO Received uploads request method=POST path=/api/pending_closures16772026/10/01 10:34:02 INFO Aborted multipart uploads count=0 kept=016782026/10/01 10:34:02 WARN Force mode enabled - objects will be deleted immediately without grace period16792026/10/01 10:34:02 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."16802026/10/01 10:34:02 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1681=== NAME TestPinProtectsFromGC1682 client_integration_test.go:867: Pinned store path: /build/TestPinProtectsFromGC325237784/001/store/2nvwsgn3rg2799ba1iwdpcfxds1xjvy6-pinned-file.txt1683 client_integration_test.go:868: Unpinned store path: /build/TestPinProtectsFromGC325237784/001/store/hnjbchcwzzi29p651lz049fmkwphsdp4-unpinned-file.txt16842026/10/01 10:34:02 INFO Aborted multipart uploads count=0 kept=016852026/10/01 10:34:02 WARN Force mode enabled - objects will be deleted immediately without grace period16862026/10/01 10:34:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1687--- PASS: TestFailedS3DeleteKeepsTombstone (0.43s)1688=== CONT TestCacheStatsHandler16892026/10/01 10:34:02 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=016902026/10/01 10:34:02 INFO Vacuumed table table=pending_closures16912026/10/01 10:34:02 INFO Vacuumed table table=pending_objects16922026/10/01 10:34:02 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZmRlMzYxNDItYTUyOS00MWNjLThiNTEtOWI2YWI2Mzc1OGE3Ljg0ZDY0MTM2LWM5ZTAtNGU4Ny05N2NkLTI4Mjk5NzFmN2MwM3gxNzkwODUwODQxMzcyNzU5OTkx parts=1016932026/10/01 10:34:02 INFO Vacuumed table table=multipart_uploads16942026/10/01 10:34:02 INFO Vacuumed table table=closures16952026/10/01 10:34:02 INFO Vacuumed table table=objects16962026/10/01 10:34:02 INFO Received complete push request method=POST path=/api/pushes/1/complete1697=== CONT TestDeduplicatedObjectsRecordedAsPending1698--- PASS: TestGCSweepDeliversEachKeyOnce (0.40s)16992026/10/01 10:34:02 INFO Received push request method=POST path=/api/pushes17002026/10/01 10:34:02 INFO Received push request method=POST path=/api/pushes1701=== NAME TestClientMultipleUploads1702 client_integration_test.go:480: Created store path 0: /build/TestClientMultipleUploads312161383/001/store/s4hv12dlhxmfabbih40yg2qf4spblngj-test-file-0.txt17032026/10/01 10:34:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17042026/10/01 10:34:02 INFO Uploading 2nvwsgn3rg2799ba1iwdpcfxds1xjvy6-pinned-file.txt (128B)1705 client_integration_test.go:480: Created store path 1: /build/TestClientMultipleUploads312161383/001/store/nxd66kysy0m0l45c035plq3zgi3vp64k-test-file-1.txt17062026/10/01 10:34:02 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"1707=== CONT TestPresentNotReportedWhileGCDeletesClosure1708--- PASS: TestConnectSerialisesConcurrentMigrations (1.12s)17092026/10/01 10:34:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17102026/10/01 10:34:02 INFO Signed narinfos id=1 count=117112026/10/01 10:34:02 WARN Failed to register uploaded object key=2nvwsgn3rg2799ba1iwdpcfxds1xjvy6.ls error="server returned 404: 404 page not found\n"17122026/10/01 10:34:02 INFO Uploading 1 narinfos17132026/10/01 10:34:02 INFO Received uploads request method=POST path=/api/pending_closures1714=== NAME TestClientMultipleUploads1715 client_integration_test.go:480: Created store path 2: /build/TestClientMultipleUploads312161383/001/store/h2hs23yccsjz0szv8i7ayqy86yagy7mr-test-file-2.txt17162026/10/01 10:34:02 INFO Received complete push request method=POST path=/api/pushes/1/complete17172026/10/01 10:34:02 WARN Failed to register uploaded object key=2nvwsgn3rg2799ba1iwdpcfxds1xjvy6.narinfo error="server returned 404: 404 page not found\n"17182026/10/01 10:34:02 INFO Aborted multipart uploads count=0 kept=017192026/10/01 10:34:02 INFO Upload complete. (126ms)17202026/10/01 10:34:02 WARN Force mode enabled - objects will be deleted immediately without grace period17212026/10/01 10:34:02 INFO Aborted multipart uploads count=0 kept=017222026/10/01 10:34:02 WARN Force mode enabled - objects will be deleted immediately without grace period17232026/10/01 10:34:02 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=1677721617242026/10/01 10:34:02 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=017252026/10/01 10:34:02 INFO Vacuumed table table=pending_closures17262026/10/01 10:34:02 INFO Vacuumed table table=pending_objects17272026/10/01 10:34:02 INFO Vacuumed table table=multipart_uploads17282026/10/01 10:34:02 INFO Vacuumed table table=closures17292026/10/01 10:34:02 INFO Vacuumed table table=objects17302026/10/01 10:34:02 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=017312026/10/01 10:34:02 INFO Received uploads request method=POST path=/api/pending_closures1732=== NAME TestOrphanedObjectsGCStressTest1733 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains17342026/10/01 10:34:02 INFO Vacuumed table table=pending_closures17352026/10/01 10:34:02 INFO Vacuumed table table=pending_objects1736=== NAME TestClientCADerivations1737 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2366644328/001/store/20fpn7q0w3rgmarjgnzsca0f6l23vapp-ca-test17382026/10/01 10:34:02 INFO Vacuumed table table=multipart_uploads1739--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.56s)1740=== CONT TestService_ReadScope_PublicByDefault17412026/10/01 10:34:02 INFO Vacuumed table table=closures1742--- PASS: TestReadProxyNarinfo (1.78s)1743=== CONT TestPendingClosureWriteTimeout/670k_objects1744=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline17452026/10/01 10:34:02 INFO Vacuumed table table=objects17462026/10/01 10:34:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1747--- PASS: TestGCSweepSkipsPendingObjects (0.39s)1748=== CONT TestPendingClosureWriteTimeout/400_objects1749=== CONT TestPendingClosureWriteTimeout/empty1750=== CONT TestProxyWriteTimeout/narinfo1751=== CONT TestProxyWriteTimeout/unknown_size1752=== CONT TestProxyWriteTimeout/1_GiB_nar1753=== CONT TestProxyWriteTimeout/10_GiB_nar1754=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1755--- PASS: TestProxyWriteTimeout (0.01s)1756 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1757 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1758 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1759 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)17602026/10/01 10:34:02 INFO Received complete multipart upload request method=POST path=/1761=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17622026/10/01 10:34:02 INFO Received request for more parts method=POST path=/1763=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17642026/10/01 10:34:02 INFO Received uploads request method=POST path=/1765=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17662026/10/01 10:34:02 INFO Received uploads request method=POST path=/1767=== CONT TestIsValidUploadKey/nar_zst1768--- PASS: TestUploadHandlersRejectInvalidKeys (0.02s)1769 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1770 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1771 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1772 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1773=== CONT TestIsValidUploadKey/realisation1774=== CONT TestIsValidUploadKey/empty_key1775=== CONT TestIsValidUploadKey/absolute1776=== CONT TestIsValidUploadKey/traversal_nar1777=== CONT TestIsValidUploadKey/unknown_type1778=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1779=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1780=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1781=== CONT TestIsValidUploadKey/index.html1782=== CONT TestIsValidUploadKey/traversal1783=== CONT TestIsValidUploadKey/nix-cache-info1784=== CONT TestIsValidUploadKey/nar_xz1785=== CONT TestIsValidUploadKey/listing1786=== CONT TestIsValidUploadKey/realisation_plus_in_output1787=== CONT TestIsValidUploadKey/build_log_question_mark1788=== CONT TestIsValidUploadKey/build_log1789=== CONT TestIsValidUploadKey/build_log_plus_in_name1790=== CONT TestIsValidUploadKey/build_log_home-manager_file1791=== CONT TestIsValidUploadKey/nar_plain1792=== CONT TestIsValidUploadKey/narinfo1793=== CONT TestIsValidUploadKey/build_log_equals1794=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure1795--- PASS: TestIsValidUploadKey (0.02s)1796 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1797 --- PASS: TestIsValidUploadKey/realisation (0.00s)1798 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1799 --- PASS: TestIsValidUploadKey/absolute (0.00s)1800 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1801 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1802 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1803 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1804 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1805 --- PASS: TestIsValidUploadKey/index.html (0.00s)1806 --- PASS: TestIsValidUploadKey/traversal (0.00s)1807 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1808 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1809 --- PASS: TestIsValidUploadKey/listing (0.00s)1810 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1811 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1812 --- PASS: TestIsValidUploadKey/build_log (0.00s)1813 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1814 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1815 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1816 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1817 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)18182026/10/01 10:34:02 INFO Received uploads request method=POST path=/1819=== NAME TestClientCADerivations1820 client_ca_test.go:139: Found 1 dependencies (including self)18212026/10/01 10:34:02 INFO Received push request method=POST path=/api/pushes1822=== NAME TestOrphanedObjectsGCStressTest1823 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion18242026/10/01 10:34:02 INFO Received push request method=POST path=/api/pushes18252026/10/01 10:34:02 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZmRlMzYxNDItYTUyOS00MWNjLThiNTEtOWI2YWI2Mzc1OGE3LmM4NTMwNTgwLTA2ZTgtNDNmNy04MWZhLTZiMzUxMzBmNzQ4ZXgxNzkwODUwODQxNDQyMDAyOTYw parts=1018262026/10/01 10:34:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18272026/10/01 10:34:02 INFO Uploading hnjbchcwzzi29p651lz049fmkwphsdp4-unpinned-file.txt (128B)18282026/10/01 10:34:02 INFO Received uploads request method=POST path=/api/pending_closures18292026/10/01 10:34:02 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18302026/10/01 10:34:02 INFO Uploading h2hs23yccsjz0szv8i7ayqy86yagy7mr-test-file-2.txt (160B)18312026/10/01 10:34:02 INFO Uploading nxd66kysy0m0l45c035plq3zgi3vp64k-test-file-1.txt (160B)1832--- PASS: TestCacheStatsHandler (0.24s)1833=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18342026/10/01 10:34:02 INFO Uploading s4hv12dlhxmfabbih40yg2qf4spblngj-test-file-0.txt (160B)18352026/10/01 10:34:02 INFO Received complete multipart upload request method=POST path=/18362026/10/01 10:34:03 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18372026/10/01 10:34:03 INFO Aborted multipart uploads count=0 kept=01838--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.22s)18392026/10/01 10:34:03 WARN Failed to register uploaded object key=hnjbchcwzzi29p651lz049fmkwphsdp4.ls error="server returned 404: 404 page not found\n"1840=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18412026/10/01 10:34:03 INFO Received request for more parts method=POST path=/18422026/10/01 10:34:03 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18432026/10/01 10:34:03 INFO Signed narinfos id=2 count=118442026/10/01 10:34:03 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18452026/10/01 10:34:03 INFO Uploading 1 narinfos18462026/10/01 10:34:03 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18472026/10/01 10:34:03 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18482026/10/01 10:34:03 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=018492026/10/01 10:34:03 INFO Received complete push request method=POST path=/api/pushes/2/complete18502026/10/01 10:34:03 WARN Failed to register uploaded object key=hnjbchcwzzi29p651lz049fmkwphsdp4.narinfo error="server returned 404: 404 page not found\n"18512026/10/01 10:34:03 INFO Vacuumed table table=pending_closures18522026/10/01 10:34:03 WARN Failed to register uploaded object key=s4hv12dlhxmfabbih40yg2qf4spblngj.ls error="server returned 404: 404 page not found\n"18532026/10/01 10:34:03 INFO Vacuumed table table=pending_objects18542026/10/01 10:34:03 INFO Vacuumed table table=multipart_uploads18552026/10/01 10:34:03 WARN Failed to register uploaded object key=nxd66kysy0m0l45c035plq3zgi3vp64k.ls error="server returned 404: 404 page not found\n"18562026/10/01 10:34:03 INFO Upload complete. (96ms)18572026/10/01 10:34:03 INFO Vacuumed table table=closures18582026/10/01 10:34:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18592026/10/01 10:34:03 WARN Failed to register uploaded object key=h2hs23yccsjz0szv8i7ayqy86yagy7mr.ls error="server returned 404: 404 page not found\n"18602026/10/01 10:34:03 INFO Signed narinfos id=1 count=318612026/10/01 10:34:03 INFO Vacuumed table table=objects18622026/10/01 10:34:03 INFO Uploading 3 narinfos18632026/10/01 10:34:03 INFO Aborted multipart uploads count=0 kept=018642026/10/01 10:34:03 WARN Failed to register uploaded object key=h2hs23yccsjz0szv8i7ayqy86yagy7mr.narinfo error="server returned 404: 404 page not found\n"18652026/10/01 10:34:03 WARN Failed to register uploaded object key=nxd66kysy0m0l45c035plq3zgi3vp64k.narinfo error="server returned 404: 404 page not found\n"18662026/10/01 10:34:03 WARN Force mode enabled - objects will be deleted immediately without grace period18672026/10/01 10:34:03 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=018682026/10/01 10:34:03 INFO Vacuumed table table=pending_closures18692026/10/01 10:34:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18702026/10/01 10:34:03 INFO Vacuumed table table=pending_objects18712026/10/01 10:34:03 INFO Vacuumed table table=multipart_uploads18722026/10/01 10:34:03 INFO Vacuumed table table=closures18732026/10/01 10:34:03 INFO Vacuumed table table=objects18742026/10/01 10:34:03 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"18752026/10/01 10:34:03 INFO Received complete push request method=POST path=/api/pushes/1/complete18762026/10/01 10:34:03 WARN Failed to register uploaded object key=s4hv12dlhxmfabbih40yg2qf4spblngj.narinfo error="server returned 404: 404 page not found\n"18772026/10/01 10:34:03 INFO Upload complete. (143ms)1878=== NAME TestClientMultipleUploads1879 client_integration_test.go:491: Uploaded 3 paths in 175.892444ms18802026/10/01 10:34:03 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZmRlMzYxNDItYTUyOS00MWNjLThiNTEtOWI2YWI2Mzc1OGE3LjE5NDJjOTc1LTlkNTYtNGE0MC04N2NmLTNiOGM1YzgzODBjOHgxNzkwODUwODQyMjcwOTE4ODQ5 error="Get \"http://127.0.0.1:1/bucket36/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"18812026/10/01 10:34:03 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZmRlMzYxNDItYTUyOS00MWNjLThiNTEtOWI2YWI2Mzc1OGE3LjIxMmFkNTJlLTRhMGEtNDY2Zi04YWZjLTg4NWRiNDBiYTQ0ZXgxNzkwODUwODQyMjU2ODg0MzM2 parts=1218822026/10/01 10:34:03 INFO Starting cleanup of old closures method=DELETE path=/api/closures18832026/10/01 10:34:03 INFO Garbage collection started18842026/10/01 10:34:03 INFO Received cleanup request method=DELETE path=/api/pending_closures1885--- PASS: TestPushDedupSurvivesConcurrentGC (0.45s)1886=== CONT TestServerTLSConfig/not_a_PEM_file1887=== CONT TestServerTLSConfig/missing_CA_file1888=== CONT TestServerTLSConfig/no_client_CA1889=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1890--- PASS: TestServerTLSConfig (0.00s)1891 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1892 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1893 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)18942026/10/01 10:34:03 INFO Received push request method=POST path=/api/pushes18952026/10/01 10:34:03 INFO Aborted multipart uploads count=1 kept=018962026/10/01 10:34:03 INFO Aborted multipart uploads count=0 kept=018972026/10/01 10:34:03 WARN Rate limiter enabled after throttle name=s3-test rate=518982026/10/01 10:34:03 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1899=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1900 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101901 throttle_test.go:215: Rate limiter: enabled=true, rate=5.0019022026/10/01 10:34:03 WARN Force mode enabled - objects will be deleted immediately without grace period19032026/10/01 10:34:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19042026/10/01 10:34:03 INFO Uploading 20fpn7q0w3rgmarjgnzsca0f6l23vapp-ca-test (144B)1905--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.55s)1906=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark19072026/10/01 10:34:03 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"19082026/10/01 10:34:03 WARN Failed to register uploaded object key=log/xrf5hbhw6rw3siaf664k72vw451dsp96-ca-test.drv error="server returned 404: 404 page not found\n"19092026/10/01 10:34:03 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=019102026/10/01 10:34:03 WARN Failed to register uploaded object key=20fpn7q0w3rgmarjgnzsca0f6l23vapp.ls error="server returned 404: 404 page not found\n"19112026/10/01 10:34:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19122026/10/01 10:34:03 INFO Signed narinfos id=1 count=119132026/10/01 10:34:03 INFO Uploading 1 narinfos19142026/10/01 10:34:03 INFO Vacuumed table table=pending_closures1915--- PASS: TestClientMultipleUploads (0.63s)1916=== CONT TestGCEndsOnShutdown/before_the_run1917--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.69s)1918=== CONT TestPush_RejectsBadRequests/root_not_in_objects19192026/10/01 10:34:03 INFO Received push request method=POST path=/api/pushes1920=== CONT TestPush_RejectsBadRequests/no_objects19212026/10/01 10:34:03 INFO Received complete push request method=POST path=/api/pushes/1/complete19222026/10/01 10:34:03 INFO Vacuumed table table=pending_objects19232026/10/01 10:34:03 WARN Failed to register uploaded object key=20fpn7q0w3rgmarjgnzsca0f6l23vapp.narinfo error="server returned 404: 404 page not found\n"19242026/10/01 10:34:03 INFO Received push request method=POST path=/api/pushes19252026/10/01 10:34:03 INFO Vacuumed table table=multipart_uploads1926=== CONT TestPush_RejectsBadRequests/bad_root1927--- PASS: TestRedundantMultipartUpload (2.60s)19282026/10/01 10:34:03 INFO Received push request method=POST path=/api/pushes1929=== CONT TestPush_RejectsBadRequests/no_roots1930=== CONT TestParseSingleRange/none19312026/10/01 10:34:03 INFO Received push request method=POST path=/api/pushes1932=== CONT TestParseSingleRange/start_past_EOF1933=== CONT TestParseSingleRange/start_far_past_EOF1934=== CONT TestParseSingleRange/suffix_exceeds_size1935=== CONT TestParseSingleRange/suffix1936=== CONT TestParseSingleRange/single_byte1937=== CONT TestParseSingleRange/open-ended19382026/10/01 10:34:03 INFO Vacuumed table table=closures1939=== CONT TestParseSingleRange/malformed_end_before_start1940=== CONT TestParseSingleRange/end_clamped_to_size1941=== CONT TestParseSingleRange/malformed_both_empty1942=== CONT TestParseSingleRange/closed1943=== CONT TestParseSingleRange/malformed_no_dash1944=== CONT TestParseSingleRange/unknown_unit1945=== CONT TestParseSingleRange/multi-range_ignored1946=== CONT TestClientErrorHandling/InvalidAuthToken1947=== CONT TestClientErrorHandling/InvalidStorePath1948--- PASS: TestParseSingleRange (0.00s)1949 --- PASS: TestParseSingleRange/none (0.00s)1950 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1951 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1952 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1953 --- PASS: TestParseSingleRange/suffix (0.00s)1954 --- PASS: TestParseSingleRange/single_byte (0.00s)1955 --- PASS: TestParseSingleRange/open-ended (0.00s)1956 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1957 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1958 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1959 --- PASS: TestParseSingleRange/closed (0.00s)1960 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1961 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1962 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)19632026/10/01 10:34:03 INFO Vacuumed table table=objects19642026/10/01 10:34:03 INFO Upload complete. (125ms)1965--- PASS: TestService_ReadScope_PublicByDefault (0.20s)1966=== CONT TestClientErrorHandling/ServerNotAvailable1967=== NAME TestClientCADerivations1968 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2366644328/001/store/20fpn7q0w3rgmarjgnzsca0f6l23vapp-ca-test1969 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1970 Compression: zstd1971 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1972 NarSize: 1441973 References: 1974 Deriver: /build/TestClientCADerivations2366644328/001/store/xrf5hbhw6rw3siaf664k72vw451dsp96-ca-test.drv1975 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1976 client_ca_test.go:185: Checking for realisation files in S3...1977 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1978 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache19792026/10/01 10:34:03 INFO Received uploads request method=POST path=/api/pending_closures1980--- PASS: TestPush_RejectsBadRequests (0.83s)1981 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1982 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1983 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1984 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)19852026/10/01 10:34:03 INFO lead: released remote=192.0.2.1:12341986=== NAME TestClientCADerivations1987 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1988 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1989 error: binary cache 's3://bucket82?endpoint=http://localhost:34839®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2366644328/001/store'1990 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11991--- PASS: TestLeadEndsOnShutdown (1.60s)1992=== CONT TestCacheConfigHandler/no_cache_url_configured1993=== CONT TestCacheConfigHandler/full_config,_no_issuer1994=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1995=== CONT TestCacheConfigHandler/no_signing_keys1996=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1997--- PASS: TestCacheConfigHandler (0.00s)1998 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1999 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2000 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2001 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2002--- PASS: TestClientCADerivations (0.66s)2003=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20042026/10/01 10:34:03 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]2005=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2006=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2007=== CONT TestResolveDBConnectionString/file_when_flag_empty2008=== CONT TestResolveDBConnectionString/nothing_configured2009=== CONT TestResolveDBConnectionString/flag_wins2010=== CONT TestResolveDBConnectionString/missing_file_is_an_error2011=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2012=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check2013--- PASS: TestResolveDBConnectionString (0.00s)2014 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2015 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2016 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2017 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2018 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)20192026/10/01 10:34:03 WARN Authentication failed token_preview=eyJhbGciOi...hPbF5uc8Kw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2020=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows20212026/10/01 10:34:03 INFO lead: released remote=192.0.2.1:123420222026/10/01 10:34:03 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/present2023--- PASS: TestService_AuthMiddleware_OIDC (0.35s)2024 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2025 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2026 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2027 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)20282026/10/01 10:34:03 INFO lead: acquired remote=192.0.2.1:123420292026/10/01 10:34:03 WARN Rate limiter enabled after throttle name=s3-test rate=520302026/10/01 10:34:03 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."20312026/10/01 10:34:03 INFO Aborted multipart uploads count=0 kept=020322026/10/01 10:34:03 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=193.677099ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20332026/10/01 10:34:03 WARN Force mode enabled - objects will be deleted immediately without grace period20342026/10/01 10:34:03 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:34839/bucket91/?delete=\": context canceled"2035=== CONT TestService_RequireScope_OIDC/static_token_may_admin2036=== CONT TestService_RequireScope_OIDC/writer_implies_read2037=== CONT TestService_RequireScope_OIDC/ops_may_not_write2038=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2039=== CONT TestService_RequireScope_OIDC/builder_may_write2040=== CONT TestService_RequireScope_OIDC/reader_may_read2041=== CONT TestService_RequireScope_OIDC/ops_may_admin2042=== CONT TestService_RequireScope_OIDC/reader_may_not_write2043=== CONT TestService_RequireScope_OIDC/static_token_may_write2044=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2045=== CONT TestIsValidCachePath/narinfo2046=== CONT TestIsValidCachePath/short_hash2047=== NAME TestOrphanedObjectsGCStressTest2048 orphaned_objects_gc_test.go:509: Stress test completed successfully:2049 orphaned_objects_gc_test.go:510: - Active objects preserved: 202050 orphaned_objects_gc_test.go:511: - Objects deleted: 2102051 orphaned_objects_gc_test.go:512: - Total GC'd: 2102052=== CONT TestIsValidCachePath/wrong_extension2053=== CONT TestIsValidCachePath/realisation2054=== CONT TestIsValidCachePath/empty2055=== CONT TestIsValidCachePath/leading_slash2056=== CONT TestIsValidCachePath/invalid_char_u2057=== CONT TestIsValidCachePath/random_path2058=== CONT TestIsValidCachePath/traversal_in_middle2059=== CONT TestIsValidCachePath/index.html2060=== CONT TestIsValidCachePath/nix-cache-info2061=== CONT TestIsValidCachePath/log2062=== CONT TestIsValidCachePath/ls2063=== CONT TestIsValidCachePath/traversal_parent2064=== CONT TestIsValidCachePath/invalid_char_e2065=== CONT TestIsValidCachePath/nar_uncompressed2066=== CONT TestIsValidCachePath/nar_bz22067=== CONT TestIsValidCachePath/nar_xz2068=== CONT TestIsValidCachePath/nar_zst2069=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2070--- PASS: TestIsValidCachePath (0.00s)2071 --- PASS: TestIsValidCachePath/narinfo (0.00s)2072 --- PASS: TestIsValidCachePath/short_hash (0.00s)2073 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2074 --- PASS: TestIsValidCachePath/realisation (0.00s)2075 --- PASS: TestIsValidCachePath/empty (0.00s)2076 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2077 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2078 --- PASS: TestIsValidCachePath/random_path (0.00s)2079 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2080 --- PASS: TestIsValidCachePath/index.html (0.00s)2081 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2082 --- PASS: TestIsValidCachePath/log (0.00s)2083 --- PASS: TestIsValidCachePath/ls (0.00s)2084 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2085 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2086 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2087 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2088 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2089 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2090 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)20912026/10/01 10:34:03 INFO Aborted multipart uploads count=0 kept=02092--- PASS: TestService_RequireScope_OIDC (0.40s)2093 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2094 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2095 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2096 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2097 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2098 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2099 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2100 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2101 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2102 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)21032026/10/01 10:34:03 WARN Force mode enabled - objects will be deleted immediately without grace period21042026-10-01 10:34:03.480 UTC [2317] ERROR: canceling statement due to user request21052026-10-01 10:34:03.480 UTC [2317] CONTEXT: PL/pgSQL function object_stats_apply() line 5 at statement block21062026-10-01 10:34:03.480 UTC [2317] STATEMENT: -- name: MarkStaleObjects :execrows2107 WITH RECURSIVE ct AS (2108 SELECT timezone('UTC', now()) AS now2109 ),2110 closure_reach AS (2111 -- Start with all closure keys2112 SELECT o.key, o.refs2113 FROM objects o2114 INNER JOIN closures c ON o.key = c.key2115 UNION2116 -- Recursively add all referenced objects2117 SELECT o.key, o.refs2118 FROM objects o2119 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2120 ),2121 reachable_objects AS (2122 SELECT DISTINCT key FROM closure_reach2123 ),2124 stale_objects AS (2125 SELECT o.key2126 FROM objects AS o, ct2127 WHERE2128 NOT EXISTS (2129 SELECT 12130 FROM reachable_objects ro2131 WHERE ro.key = o.key2132 )2133 AND NOT EXISTS (2134 SELECT 12135 FROM pending_objects AS po2136 WHERE po.key = o.key2137 )2138 AND o.deleted_at IS NULL -- Only mark fresh objects2139 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2140 FOR UPDATE2141 )2142 UPDATE objects2143 SET2144 deleted_at = ct.now,2145 first_deleted_at = COALESCE(first_deleted_at, ct.now)2146 FROM stale_objects, ct2147 WHERE objects.key = stale_objects.key2148 2149--- PASS: TestOrphanedObjectsGCStressTest (4.05s)2150--- PASS: TestGCEndsOnShutdown (0.00s)2151 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.36s)2152 --- PASS: TestGCEndsOnShutdown/before_the_run (0.32s)2153 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.40s)21542026/10/01 10:34:03 WARN Rate limiter backed off name=s3-test rate=521552026/10/01 10:34:03 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."2156--- PASS: TestReadProxy404 (0.99s)21572026/10/01 10:34:03 INFO Received uploads request method=POST path=/api/pending_closures21582026/10/01 10:34:03 INFO Aborted multipart uploads count=0 kept=021592026/10/01 10:34:03 WARN Force mode enabled - objects will be deleted immediately without grace period2160--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.27s)21612026/10/01 10:34:03 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=021622026/10/01 10:34:03 INFO Vacuumed table table=pending_closures21632026/10/01 10:34:03 INFO Vacuumed table table=pending_objects21642026/10/01 10:34:03 INFO Vacuumed table table=multipart_uploads21652026/10/01 10:34:03 INFO Vacuumed table table=closures21662026/10/01 10:34:03 INFO Vacuumed table table=objects21672026/10/01 10:34:03 INFO Received uploads request method=POST path=/api/pending_closures21682026/10/01 10:34:03 INFO Aborted multipart uploads count=0 kept=021692026/10/01 10:34:03 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21702026/10/01 10:34:03 WARN Force mode enabled - objects will be deleted immediately without grace period21712026/10/01 10:34:03 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=021722026/10/01 10:34:03 INFO Vacuumed table table=pending_closures21732026/10/01 10:34:03 INFO Vacuumed table table=pending_objects21742026/10/01 10:34:03 INFO Vacuumed table table=multipart_uploads21752026/10/01 10:34:03 INFO Vacuumed table table=closures21762026/10/01 10:34:03 INFO Vacuumed table table=objects2177--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.73s)21782026/10/01 10:34:03 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=376.004314ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21792026/10/01 10:34:03 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2180--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2181 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.32s)2182 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.36s)21832026/10/01 10:34:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21842026/10/01 10:34:03 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ZmRlMzYxNDItYTUyOS00MWNjLThiNTEtOWI2YWI2Mzc1OGE3LjEwM2VkMGQwLTRmMjUtNGY2OC05YTBiLTNkNzkzYTE0MzAwNXgxNzkwODUwODQyODE4NTg4MTQ5 parts=1021852026/10/01 10:34:03 INFO Received complete push request method=POST path=/api/pushes/2/complete21862026/10/01 10:34:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2187--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.16s)21882026/10/01 10:34:03 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ZmRlMzYxNDItYTUyOS00MWNjLThiNTEtOWI2YWI2Mzc1OGE3LjAwY2E4YmUwLTAzZGQtNDVlYi05ZDFkLTg0ZjNkNzEzNjAxZngxNzkwODUwODQxNDQzNzMwODkw parts=1021892026/10/01 10:34:03 INFO Received complete push request method=POST path=/api/pushes/1/complete2190--- PASS: TestPush_CompleteCommitsEveryRoot (3.17s)21912026/10/01 10:34:03 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=786.549837ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2192--- PASS: TestPendingClosureWriteTimeout (0.01s)2193 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2194 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2195 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2196 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.03s)21972026/10/01 10:34:04 INFO lead: released remote=192.0.2.1:12342198--- PASS: TestLeadElectsOneAndHandsOver (2.81s)21992026/10/01 10:34:04 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02200=== NAME TestClientIntegration2201 client_integration_test.go:445: Objects in database after GC:2202 client_integration_test.go:445: Successfully deleted all objects with GC --force2203--- PASS: TestClientIntegration (3.37s)22042026/10/01 10:34:04 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.731500342s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22052026/10/01 10:34:05 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=022062026/10/01 10:34:05 INFO Received create pin request method=POST path=/api/pins/myapp22072026/10/01 10:34:05 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC325237784/001/store/2nvwsgn3rg2799ba1iwdpcfxds1xjvy6-pinned-file.txt narinfo_key=2nvwsgn3rg2799ba1iwdpcfxds1xjvy6.narinfo22082026/10/01 10:34:05 INFO Starting cleanup of old closures method=DELETE path=/api/closures22092026/10/01 10:34:05 INFO Garbage collection started22102026/10/01 10:34:05 INFO Aborted multipart uploads count=0 kept=022112026/10/01 10:34:05 WARN Force mode enabled - objects will be deleted immediately without grace period22122026/10/01 10:34:05 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=022132026/10/01 10:34:05 INFO Vacuumed table table=pending_closures22142026/10/01 10:34:05 INFO Vacuumed table table=pending_objects22152026/10/01 10:34:05 INFO Vacuumed table table=multipart_uploads22162026/10/01 10:34:05 INFO Vacuumed table table=closures22172026/10/01 10:34:05 INFO Vacuumed table table=objects2218--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.06s)22192026/10/01 10:34:06 INFO Aborted multipart uploads count=1 kept=022202026/10/01 10:34:06 INFO Received cleanup request method=DELETE path=/api/pending_closures22212026/10/01 10:34:06 INFO Aborted multipart uploads count=1 kept=02222--- PASS: TestPendingCleanupUsesOneCutoff (6.99s)22232026/10/01 10:34:06 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-config22242026/10/01 10:34:06 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=200.791937ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2225--- PASS: TestConnectWaitsForAPeerMigration (5.20s)22262026/10/01 10:34:06 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=362.338602ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2227=== NAME TestPinProtectsFromGC2228 client_integration_test.go:976: Pin successfully protected closure from garbage collection2229--- PASS: TestPinProtectsFromGC (4.76s)22302026/10/01 10:34:07 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=821.121694ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22312026/10/01 10:34:08 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.44689278s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22322026/10/01 10:34:09 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"22332026/10/01 10:34:09 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-config22342026/10/01 10:34:09 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=195.080728ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22352026/10/01 10:34:09 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=432.985078ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22362026/10/01 10:34:10 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=737.466025ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2237--- PASS: TestUploadHandlersRejectOversizedBody (0.75s)2238 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.59s)2239 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.69s)2240 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (7.54s)22412026/10/01 10:34:10 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.684503865s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22422026/10/01 10:34:12 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_closures22432026/10/01 10:34:12 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.774637ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22442026/10/01 10:34:12 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=408.608366ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22452026/10/01 10:34:13 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=755.627298ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22462026/10/01 10:34:14 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.503140578s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2247--- PASS: TestClientErrorHandling (0.00s)2248 --- PASS: TestClientErrorHandling/InvalidStorePath (0.40s)2249 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.51s)2250 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.51s)2251PASS2252{"timestamp":"2026-10-01T10:34:15.66455928Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:60120","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(388)"}22532026-10-01 10:34:16.075 UTC [171] LOG: received smart shutdown request22542026-10-01 10:34:16.080 UTC [171] LOG: background worker "logical replication launcher" (PID 181) exited with exit code 122552026-10-01 10:34:16.092 UTC [176] LOG: shutting down22562026-10-01 10:34:16.093 UTC [176] LOG: checkpoint starting: shutdown immediate22572026-10-01 10:34:16.808 UTC [176] LOG: checkpoint complete: wrote 10362 buffers (63.2%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 28 recycled; write=0.256 s, sync=0.408 s, total=0.715 s; sync files=33362, longest=0.062 s, average=0.001 s; distance=467325 kB, estimate=467325 kB; lsn=0/1DFC5250, redo lsn=0/1DFC525022582026-10-01 10:34:16.885 UTC [171] LOG: database system is shut down2259Running OIDC tests...2260=== RUN TestAudienceForIssuer2261=== PAUSE TestAudienceForIssuer2262=== RUN TestHTTPClientForHasTimeouts2263=== PAUSE TestHTTPClientForHasTimeouts2264=== RUN TestGlobMatch2265=== PAUSE TestGlobMatch2266=== RUN TestValidateToken_ValidToken2267=== PAUSE TestValidateToken_ValidToken2268=== RUN TestValidateToken_WrongAudience2269=== PAUSE TestValidateToken_WrongAudience2270=== RUN TestValidateToken_Expired2271=== PAUSE TestValidateToken_Expired2272=== RUN TestValidateToken_BoundClaimsMismatch2273=== PAUSE TestValidateToken_BoundClaimsMismatch2274=== RUN TestValidateToken_BoundSubjectMismatch2275=== PAUSE TestValidateToken_BoundSubjectMismatch2276=== RUN TestValidateToken_MultipleProviders2277=== PAUSE TestValidateToken_MultipleProviders2278=== RUN TestValidateToken_NoMatchingProvider2279=== PAUSE TestValidateToken_NoMatchingProvider2280=== RUN TestValidateToken_KubernetesServiceAccount2281=== PAUSE TestValidateToken_KubernetesServiceAccount2282=== RUN TestNewValidator_KubernetesRequiresCA2283=== PAUSE TestNewValidator_KubernetesRequiresCA2284=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2285=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2286=== RUN TestPins_ReservedForMatchingRule2287=== PAUSE TestPins_ReservedForMatchingRule2288=== RUN TestPins_TopLevelShorthand2289=== PAUSE TestPins_TopLevelShorthand2290=== RUN TestPins_ConfigValidation2291=== PAUSE TestPins_ConfigValidation2292=== RUN TestScopes_LegacyProviderDefaultsToWrite2293=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2294=== RUN TestScopes_Rules2295=== PAUSE TestScopes_Rules2296=== RUN TestScopes_ConfigValidation2297=== PAUSE TestScopes_ConfigValidation2298=== CONT TestGlobMatch2299=== CONT TestValidateToken_WrongAudience2300=== RUN TestGlobMatch/foo_foo2301=== CONT TestHTTPClientForHasTimeouts2302=== PAUSE TestGlobMatch/foo_foo2303=== CONT TestAudienceForIssuer2304=== CONT TestValidateToken_NoMatchingProvider2305=== CONT TestValidateToken_MultipleProviders2306=== CONT TestValidateToken_Expired2307=== CONT TestValidateToken_BoundClaimsMismatch2308=== CONT TestPins_ConfigValidation2309=== CONT TestScopes_ConfigValidation2310=== CONT TestScopes_LegacyProviderDefaultsToWrite2311=== CONT TestScopes_Rules2312=== CONT TestValidateToken_BoundSubjectMismatch2313=== CONT TestPins_ReservedForMatchingRule2314=== CONT TestValidateToken_KubernetesServiceAccount2315=== CONT TestPins_TopLevelShorthand2316=== CONT TestNewValidator_KubernetesRequiresCA2317=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2318=== CONT TestValidateToken_ValidToken2319=== RUN TestGlobMatch/foo_bar2320=== PAUSE TestGlobMatch/foo_bar2321--- PASS: TestAudienceForIssuer (0.00s)2322=== RUN TestGlobMatch/*_2323=== PAUSE TestGlobMatch/*_2324--- PASS: TestScopes_ConfigValidation (0.00s)2325--- PASS: TestPins_ConfigValidation (0.00s)2326=== RUN TestGlobMatch/*_anything2327=== PAUSE TestGlobMatch/*_anything2328=== RUN TestGlobMatch/foo*_foo2329=== PAUSE TestGlobMatch/foo*_foo2330=== RUN TestGlobMatch/foo*_foobar2331=== PAUSE TestGlobMatch/foo*_foobar2332=== RUN TestGlobMatch/foo*_bar2333=== PAUSE TestGlobMatch/foo*_bar2334=== RUN TestGlobMatch/*bar_bar2335=== PAUSE TestGlobMatch/*bar_bar2336=== RUN TestGlobMatch/*bar_foobar2337=== PAUSE TestGlobMatch/*bar_foobar2338=== RUN TestGlobMatch/*bar_foo2339=== PAUSE TestGlobMatch/*bar_foo2340=== RUN TestGlobMatch/foo*bar_foobar2341=== PAUSE TestGlobMatch/foo*bar_foobar2342=== RUN TestGlobMatch/foo*bar_foo123bar2343=== PAUSE TestGlobMatch/foo*bar_foo123bar2344=== RUN TestGlobMatch/foo*bar_foobarbaz2345=== PAUSE TestGlobMatch/foo*bar_foobarbaz2346=== RUN TestGlobMatch/*/*_foo/bar2347=== PAUSE TestGlobMatch/*/*_foo/bar2348=== RUN TestGlobMatch/*/*_foo2349=== PAUSE TestGlobMatch/*/*_foo2350=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2351=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2352=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02353=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02354=== RUN TestGlobMatch/refs/*/main_refs/heads/main2355=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2356=== RUN TestGlobMatch/fo?_foo2357=== PAUSE TestGlobMatch/fo?_foo2358=== RUN TestGlobMatch/fo?_fo2359=== PAUSE TestGlobMatch/fo?_fo2360=== RUN TestGlobMatch/fo?_fooo2361=== PAUSE TestGlobMatch/fo?_fooo2362=== RUN TestGlobMatch/?oo_foo2363=== PAUSE TestGlobMatch/?oo_foo2364=== RUN TestGlobMatch/?oo_boo2365=== PAUSE TestGlobMatch/?oo_boo2366=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2367=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2368=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2369=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2370=== CONT TestGlobMatch/foo_foo2371=== CONT TestGlobMatch/*bar_foobar2372=== CONT TestGlobMatch/foo*bar_foobarbaz2373=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2374=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2375=== CONT TestGlobMatch/refs/*/main_refs/heads/main2376=== CONT TestGlobMatch/?oo_boo2377=== CONT TestGlobMatch/fo?_fooo2378=== CONT TestGlobMatch/*_anything2379=== CONT TestGlobMatch/foo_bar2380=== CONT TestGlobMatch/fo?_foo2381=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2382=== CONT TestGlobMatch/foo*bar_foobar2383=== CONT TestGlobMatch/foo*_bar2384=== CONT TestGlobMatch/*bar_foo2385=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02386=== CONT TestGlobMatch/*/*_foo2387=== CONT TestGlobMatch/*_2388=== CONT TestGlobMatch/fo?_fo2389=== CONT TestGlobMatch/foo*_foo2390=== CONT TestGlobMatch/foo*bar_foo123bar2391=== CONT TestGlobMatch/?oo_foo2392=== CONT TestGlobMatch/foo*_foobar2393=== CONT TestGlobMatch/*/*_foo/bar2394=== CONT TestGlobMatch/*bar_bar2395--- PASS: TestGlobMatch (0.02s)2396 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2397 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2398 --- PASS: TestGlobMatch/foo_foo (0.00s)2399 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2400 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2401 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2402 --- PASS: TestGlobMatch/?oo_boo (0.00s)2403 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2404 --- PASS: TestGlobMatch/*_anything (0.00s)2405 --- PASS: TestGlobMatch/foo_bar (0.00s)2406 --- PASS: TestGlobMatch/fo?_foo (0.00s)2407 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2408 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2409 --- PASS: TestGlobMatch/foo*_bar (0.00s)2410 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2411 --- PASS: TestGlobMatch/*bar_foo (0.00s)2412 --- PASS: TestGlobMatch/*/*_foo (0.00s)2413 --- PASS: TestGlobMatch/*_ (0.00s)2414 --- PASS: TestGlobMatch/fo?_fo (0.00s)2415 --- PASS: TestGlobMatch/foo*_foo (0.00s)2416 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2417 --- PASS: TestGlobMatch/?oo_foo (0.00s)2418 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2419 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2420 --- PASS: TestGlobMatch/*bar_bar (0.00s)24212026/10/01 10:34:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40175/oidc2422--- PASS: TestPins_TopLevelShorthand (0.03s)24232026/10/01 10:34:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44295/oidc2424--- PASS: TestValidateToken_Expired (0.04s)24252026/10/01 10:34:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39961/oidc2426--- PASS: TestValidateToken_ValidToken (0.05s)24272026/10/01 10:34:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34021/oidc24282026/10/01 10:34:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39945/oidc2429--- PASS: TestPins_ReservedForMatchingRule (0.07s)2430--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.07s)24312026/10/01 10:34:20 http: TLS handshake error from 127.0.0.1:33632: remote error: tls: bad certificate2432--- PASS: TestNewValidator_KubernetesRequiresCA (0.09s)24332026/10/01 10:34:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33263/oidc24342026/10/01 10:34:20 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41095/oidc2435--- PASS: TestValidateToken_BoundSubjectMismatch (0.09s)24362026/10/01 10:34:20 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:45445/oidc24372026/10/01 10:34:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40885/oidc2438--- PASS: TestValidateToken_BoundClaimsMismatch (0.11s)2439--- PASS: TestValidateToken_MultipleProviders (0.11s)24402026/10/01 10:34:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41521/oidc2441--- PASS: TestScopes_Rules (0.14s)24422026/10/01 10:34:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33375/oidc2443--- PASS: TestValidateToken_WrongAudience (0.15s)24442026/10/01 10:34:20 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232445--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.15s)24462026/10/01 10:34:20 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:437472447--- PASS: TestValidateToken_KubernetesServiceAccount (0.19s)2448--- PASS: TestHTTPClientForHasTimeouts (0.20s)24492026/10/01 10:34:20 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34603/oidc2450--- PASS: TestValidateToken_NoMatchingProvider (0.36s)2451PASS2452Running signing tests...2453=== RUN TestGenerateFingerprint2454=== PAUSE TestGenerateFingerprint2455=== RUN TestParseSigningKey2456=== PAUSE TestParseSigningKey2457=== RUN TestSignMessage2458=== PAUSE TestSignMessage2459=== RUN TestSignNarinfo2460=== PAUSE TestSignNarinfo2461=== CONT TestGenerateFingerprint2462=== CONT TestParseSigningKey2463=== CONT TestSignMessage2464=== RUN TestGenerateFingerprint/basic_with_references2465=== CONT TestSignNarinfo2466=== PAUSE TestGenerateFingerprint/basic_with_references2467=== RUN TestParseSigningKey/valid_32-byte_key2468=== RUN TestGenerateFingerprint/no_references2469=== PAUSE TestParseSigningKey/valid_32-byte_key2470=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2471=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2472=== PAUSE TestGenerateFingerprint/no_references2473=== RUN TestParseSigningKey/no_colon2474=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2475=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2476=== PAUSE TestParseSigningKey/no_colon2477=== RUN TestParseSigningKey/empty_name2478=== PAUSE TestParseSigningKey/empty_name2479=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2480=== RUN TestParseSigningKey/invalid_base642481=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2482=== PAUSE TestParseSigningKey/invalid_base642483=== RUN TestParseSigningKey/wrong_length2484=== PAUSE TestParseSigningKey/wrong_length2485=== RUN TestGenerateFingerprint/invalid_nar_hash_length2486=== CONT TestParseSigningKey/no_colon2487=== CONT TestParseSigningKey/invalid_base642488=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2489=== CONT TestParseSigningKey/wrong_length2490=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2491=== CONT TestParseSigningKey/empty_name2492=== CONT TestParseSigningKey/valid_32-byte_key2493=== RUN TestGenerateFingerprint/invalid_store_path_prefix2494=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2495=== RUN TestGenerateFingerprint/invalid_reference_prefix2496--- PASS: TestParseSigningKey (0.00s)2497 --- PASS: TestParseSigningKey/no_colon (0.00s)2498 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2499 --- PASS: TestParseSigningKey/wrong_length (0.00s)2500 --- PASS: TestParseSigningKey/empty_name (0.00s)2501 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2502 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2503=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2504=== CONT TestGenerateFingerprint/basic_with_references2505=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2506=== CONT TestGenerateFingerprint/no_references2507=== CONT TestGenerateFingerprint/invalid_reference_prefix2508=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2509=== CONT TestGenerateFingerprint/invalid_nar_hash_length2510=== CONT TestGenerateFingerprint/invalid_store_path_prefix2511--- PASS: TestSignMessage (0.00s)2512--- PASS: TestGenerateFingerprint (0.00s)2513 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2514 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2515 --- PASS: TestGenerateFingerprint/no_references (0.00s)2516 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2517 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2518 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2519 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2520--- PASS: TestSignNarinfo (0.00s)2521PASS2522Running hook tests...2523=== RUN TestSendPathsEmpty2524=== PAUSE TestSendPathsEmpty2525=== RUN TestQueueEnqueueAndFetch2526=== PAUSE TestQueueEnqueueAndFetch2527=== RUN TestQueueDeduplication2528=== PAUSE TestQueueDeduplication2529=== RUN TestQueueRemove2530=== PAUSE TestQueueRemove2531=== RUN TestQueueFetchBatchLimit2532=== PAUSE TestQueueFetchBatchLimit2533=== RUN TestQueueRetryMovesToBack2534=== PAUSE TestQueueRetryMovesToBack2535=== RUN TestQueueFetchRemoveLifecycle2536=== PAUSE TestQueueFetchRemoveLifecycle2537=== RUN TestQueueConcurrentWriters2538=== PAUSE TestQueueConcurrentWriters2539=== RUN TestQueueEnqueueWaitsOutSlowWriter2540=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2541=== RUN TestQueueRemoveLargeClosure2542=== PAUSE TestQueueRemoveLargeClosure2543=== RUN TestServerClientIntegration2544=== PAUSE TestServerClientIntegration2545=== RUN TestServerQueueError2546=== PAUSE TestServerQueueError2547=== RUN TestServerRefusesOversizedAndNonStoreRequests2548=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2549=== RUN TestGetListenerSocketActivation2550 server_test.go:317: === RUN TestGetListenerSocketActivation2551 --- PASS: TestGetListenerSocketActivation (0.00s)2552 PASS2553 2554--- PASS: TestGetListenerSocketActivation (1.02s)2555=== RUN TestServerStalledClientDoesNotBlockShutdown2556=== PAUSE TestServerStalledClientDoesNotBlockShutdown2557=== RUN TestServerBacksOffOnAcceptErrors2558=== PAUSE TestServerBacksOffOnAcceptErrors2559=== RUN TestDrainIsolatesPoisonPath2560=== PAUSE TestDrainIsolatesPoisonPath2561=== RUN TestRunNotBlockedByPoisonHead2562=== PAUSE TestRunNotBlockedByPoisonHead2563=== RUN TestDrainGivesUpWhenServerDown2564=== PAUSE TestDrainGivesUpWhenServerDown2565=== RUN TestFailedPathPrunedByLaterClosure2566=== PAUSE TestFailedPathPrunedByLaterClosure2567=== RUN TestWorkerUploadsAndRemoves2568=== PAUSE TestWorkerUploadsAndRemoves2569=== RUN TestWorkerSkipsGCdPaths2570=== PAUSE TestWorkerSkipsGCdPaths2571=== RUN TestWorkerPrunesClosureDeps2572=== PAUSE TestWorkerPrunesClosureDeps2573=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2574=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2575=== RUN TestDrainTimeout2576=== PAUSE TestDrainTimeout2577=== RUN TestDrainTimeoutDuringIsolation2578=== PAUSE TestDrainTimeoutDuringIsolation2579=== RUN TestShutdownFinishesInFlightPush2580=== PAUSE TestShutdownFinishesInFlightPush2581=== RUN TestWorkerRemoveFailureIsNotProgress2582=== PAUSE TestWorkerRemoveFailureIsNotProgress2583=== RUN TestWorkerKeepsPathItCannotStat2584=== PAUSE TestWorkerKeepsPathItCannotStat2585=== CONT TestQueueEnqueueAndFetch2586=== CONT TestWorkerPrunesClosureDeps2587=== CONT TestServerClientIntegration2588=== CONT TestDrainGivesUpWhenServerDown2589=== CONT TestQueueRemoveLargeClosure2590=== CONT TestQueueEnqueueWaitsOutSlowWriter2591=== CONT TestServerStalledClientDoesNotBlockShutdown2592=== CONT TestQueueRemove2593=== CONT TestQueueFetchRemoveLifecycle2594=== CONT TestQueueFetchBatchLimit2595=== CONT TestQueueRetryMovesToBack2596=== CONT TestWorkerSkipsGCdPaths2597=== CONT TestWorkerKeepsPathItCannotStat2598=== CONT TestWorkerRemoveFailureIsNotProgress2599=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2600=== CONT TestShutdownFinishesInFlightPush2601=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2602=== CONT TestDrainTimeoutDuringIsolation2603=== RUN TestShutdownFinishesInFlightPush/completes2604=== CONT TestDrainTimeout2605=== CONT TestSendPathsEmpty2606=== CONT TestQueueDeduplication2607=== CONT TestFailedPathPrunedByLaterClosure2608=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2609=== CONT TestServerRefusesOversizedAndNonStoreRequests2610=== CONT TestServerQueueError2611=== CONT TestWorkerUploadsAndRemoves2612=== CONT TestQueueConcurrentWriters2613=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2614=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2615=== PAUSE TestShutdownFinishesInFlightPush/completes2616--- PASS: TestSendPathsEmpty (0.00s)2617=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout26182026/10/01 10:34:23 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2619=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short26202026/10/01 10:34:23 ERROR Failed to queue paths error="permission denied" count=12621=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2622=== CONT TestDrainIsolatesPoisonPath2623=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2624--- PASS: TestServerClientIntegration (0.01s)2625=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2626=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2627=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2628--- PASS: TestServerQueueError (0.00s)26292026/10/01 10:34:23 ERROR Refusing path outside the store path=/nix/store store=/nix/store2630=== CONT TestServerBacksOffOnAcceptErrors2631=== CONT TestRunNotBlockedByPoisonHead2632=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2633=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout26342026/10/01 10:34:23 ERROR Accept failed error="too many open files"26352026/10/01 10:34:23 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store2636=== CONT TestShutdownFinishesInFlightPush/completes26372026/10/01 10:34:23 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store26382026/10/01 10:34:23 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store26392026/10/01 10:34:23 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26402026/10/01 10:34:23 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26412026/10/01 10:34:23 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store26422026/10/01 10:34:23 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store26432026/10/01 10:34:23 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store26442026/10/01 10:34:23 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store26452026/10/01 10:34:23 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store26462026/10/01 10:34:23 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store26472026/10/01 10:34:23 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store26482026/10/01 10:34:23 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store26492026/10/01 10:34:23 ERROR Accept failed error="too many open files"26502026/10/01 10:34:23 ERROR Failed to decode request error="unexpected EOF"2651--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2652=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths26532026/10/01 10:34:23 ERROR Accept failed error="too many open files"26542026/10/01 10:34:23 ERROR Accept failed error="too many open files"26552026/10/01 10:34:23 INFO Upload queue status pending=226562026/10/01 10:34:23 INFO Upload queue status pending=226572026/10/01 10:34:23 INFO Uploading batch count=226582026/10/01 10:34:23 INFO Uploading batch count=126592026/10/01 10:34:23 INFO Uploading batch count=226602026/10/01 10:34:23 INFO Upload queue status pending=226612026/10/01 10:34:23 INFO Upload queue status pending=226622026/10/01 10:34:23 ERROR Upload failed error="upload failed" count=226632026/10/01 10:34:23 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4249014144/002/a26642026/10/01 10:34:23 INFO Uploading batch count=226652026/10/01 10:34:23 INFO Uploading batch count=226662026/10/01 10:34:23 INFO Uploading batch count=226672026/10/01 10:34:23 INFO Upload queue status pending=326682026/10/01 10:34:23 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths908683765/002/nonexistent26692026/10/01 10:34:23 INFO Upload queue status pending=226702026/10/01 10:34:23 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4249014144/002/b26712026/10/01 10:34:23 INFO Uploading batch count=226722026/10/01 10:34:23 INFO Uploading batch count=226732026/10/01 10:34:23 INFO Uploading batch count=126742026/10/01 10:34:23 INFO Uploading batch count=226752026/10/01 10:34:23 ERROR Upload failed error="upload failed" count=126762026/10/01 10:34:23 ERROR Upload failed error="upload failed" count=226772026/10/01 10:34:23 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4249014144/002/c2678--- PASS: TestQueueDeduplication (0.07s)2679=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch26802026/10/01 10:34:23 INFO Upload queue status pending=32681--- PASS: TestQueueEnqueueAndFetch (0.08s)2682=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path2683--- PASS: TestQueueRemove (0.08s)26842026/10/01 10:34:23 INFO Uploading batch count=126852026/10/01 10:34:23 ERROR Upload failed error="upload failed" count=12686=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short2687=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2688--- PASS: TestQueueFetchBatchLimit (0.08s)26892026/10/01 10:34:23 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1020350462/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat1020350462/002/locked/aaa: permission denied"26902026/10/01 10:34:23 INFO Uploading batch count=426912026/10/01 10:34:23 ERROR Upload failed error="upload failed" count=426922026/10/01 10:34:23 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4249014144/002/d2693--- PASS: TestQueueFetchRemoveLifecycle (0.08s)26942026/10/01 10:34:23 INFO Uploading batch count=126952026/10/01 10:34:23 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3772192210/002/bbb26962026/10/01 10:34:23 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1020350462/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat1020350462/002/locked/aaa: permission denied"2697--- PASS: TestQueueRetryMovesToBack (0.08s)26982026/10/01 10:34:23 ERROR Accept failed error="too many open files"26992026/10/01 10:34:23 INFO Uploading batch count=227002026/10/01 10:34:23 ERROR Upload failed error="upload failed" count=227012026/10/01 10:34:23 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4249014144/002/e27022026/10/01 10:34:23 INFO Uploading batch count=127032026/10/01 10:34:23 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat1020350462/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat1020350462/002/locked/aaa: permission denied"27042026/10/01 10:34:23 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4249014144/002/f2705--- PASS: TestWorkerPrunesClosureDeps (0.10s)27062026/10/01 10:34:23 ERROR Drain finished with paths left in queue remaining=1027072026/10/01 10:34:23 INFO Uploading batch count=127082026/10/01 10:34:23 ERROR Upload failed error="upload failed" count=127092026/10/01 10:34:23 ERROR Drain finished with paths left in queue remaining=12710--- PASS: TestWorkerSkipsGCdPaths (0.09s)27112026/10/01 10:34:23 INFO Uploading batch count=227122026/10/01 10:34:23 ERROR Upload failed error="upload failed" count=22713--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.09s)27142026/10/01 10:34:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127152026/10/01 10:34:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127162026/10/01 10:34:23 INFO Uploading batch count=127172026/10/01 10:34:23 ERROR Upload failed error="upload failed" count=127182026/10/01 10:34:23 INFO Uploading batch count=22719--- PASS: TestWorkerUploadsAndRemoves (0.10s)27202026/10/01 10:34:23 ERROR Upload failed error="upload failed" count=22721--- PASS: TestWorkerKeepsPathItCannotStat (0.10s)27222026/10/01 10:34:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127232026/10/01 10:34:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127242026/10/01 10:34:23 INFO Uploading batch count=127252026/10/01 10:34:23 ERROR Upload failed error="upload failed" count=12726--- PASS: TestFailedPathPrunedByLaterClosure (0.10s)27272026/10/01 10:34:23 INFO Uploading batch count=22728--- PASS: TestDrainGivesUpWhenServerDown (0.11s)27292026/10/01 10:34:23 ERROR Upload failed error="upload failed" count=227302026/10/01 10:34:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127312026/10/01 10:34:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127322026/10/01 10:34:23 ERROR Drain finished with paths left in queue remaining=227332026/10/01 10:34:23 ERROR Drain finished with paths left in queue remaining=127342026/10/01 10:34:23 INFO Uploading batch count=427352026/10/01 10:34:23 ERROR Upload failed error="upload failed" count=427362026/10/01 10:34:23 INFO Uploading batch count=427372026/10/01 10:34:23 ERROR Upload failed error="upload failed" count=42738--- PASS: TestDrainIsolatesPoisonPath (0.11s)27392026/10/01 10:34:23 INFO Uploading batch count=227402026/10/01 10:34:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227412026/10/01 10:34:23 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path2870154965/001/nonexistent27422026/10/01 10:34:23 INFO Uploading batch count=227432026/10/01 10:34:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127442026/10/01 10:34:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227452026/10/01 10:34:23 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path2870154965/001/nonexistent27462026/10/01 10:34:23 INFO Uploading batch count=227472026/10/01 10:34:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127482026/10/01 10:34:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227492026/10/01 10:34:23 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path2870154965/001/nonexistent27502026/10/01 10:34:23 ERROR Drain finished with paths left in queue remaining=227512026/10/01 10:34:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127522026/10/01 10:34:23 ERROR Drain finished with paths left in queue remaining=12753--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2754 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.10s)2755 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.05s)2756 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.05s)27572026/10/01 10:34:23 ERROR Accept failed error="too many open files"27582026/10/01 10:34:23 ERROR Failed to decode request error="read unix /build/hook1206653681/test.sock->@: i/o timeout"27592026/10/01 10:34:23 ERROR Failed to write response error="write unix /build/hook1206653681/test.sock->@: i/o timeout"2760--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)27612026/10/01 10:34:23 ERROR Upload failed error="context canceled" count=227622026/10/01 10:34:23 ERROR Drain finished with paths left in queue remaining=427632026/10/01 10:34:23 ERROR Upload failed error="context canceled" count=227642026/10/01 10:34:23 ERROR Drain finished with paths left in queue remaining=22765--- PASS: TestDrainTimeout (0.27s)2766--- PASS: TestShutdownFinishesInFlightPush (0.00s)2767 --- PASS: TestShutdownFinishesInFlightPush/completes (0.16s)2768 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.27s)27692026/10/01 10:34:24 ERROR Drain finished with paths left in queue remaining=427702026/10/01 10:34:24 ERROR Accept failed error="too many open files"27712026/10/01 10:34:24 ERROR Drain finished with paths left in queue remaining=32772--- PASS: TestDrainTimeoutDuringIsolation (0.01s)2773 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.24s)2774 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.34s)27752026/10/01 10:34:24 ERROR Accept failed error="too many open files"2776--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)2777--- PASS: TestQueueConcurrentWriters (0.68s)27782026/10/01 10:34:24 INFO Uploading batch count=127792026/10/01 10:34:24 INFO Uploading batch count=127802026/10/01 10:34:24 INFO Uploading batch count=127812026/10/01 10:34:24 ERROR Upload failed error="upload failed" count=127822026/10/01 10:34:24 INFO Uploading batch count=127832026/10/01 10:34:24 ERROR Upload failed error="upload failed" count=127842026/10/01 10:34:24 INFO Uploading batch count=127852026/10/01 10:34:24 ERROR Upload failed error="upload failed" count=127862026/10/01 10:34:24 INFO Uploading batch count=127872026/10/01 10:34:24 ERROR Upload failed error="upload failed" count=127882026/10/01 10:34:24 ERROR Drain finished with paths left in queue remaining=12789--- PASS: TestRunNotBlockedByPoisonHead (1.11s)2790--- PASS: TestQueueRemoveLargeClosure (2.03s)2791--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.07s)2792PASS2793Running niks3-hook command tests...2794=== RUN TestServeSecondSignalEndsDrain2795=== PAUSE TestServeSecondSignalEndsDrain2796=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown2797=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown2798=== CONT TestServeSecondSignalEndsDrain2799=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown2800--- PASS: TestServeSecondSignalEndsDrain (0.08s)28012026/10/01 10:34:30 INFO Upload queue status pending=128022026/10/01 10:34:30 INFO Uploading batch count=12803--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.13s)2804PASS2805Running rate limiter tests...2806=== RUN TestAdaptiveRateLimiter_ThreadSafety2807=== PAUSE TestAdaptiveRateLimiter_ThreadSafety2808=== CONT TestAdaptiveRateLimiter_ThreadSafety28092026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=112.7357000000000728102026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=78.9149900000000528112026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=55.2404930000000328122026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=38.6683451000000228132026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=27.0678415700000128142026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=18.94748909900000628152026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=13.26324236930000428162026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=9.28426965851000228172026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=6.49898876095700128182026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528192026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528202026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528212026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528222026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528232026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528242026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528252026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528262026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528272026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528282026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528292026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528302026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528312026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528322026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528332026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528342026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528352026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528362026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528372026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528382026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528392026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528402026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528412026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528422026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528432026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528442026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528452026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528462026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528472026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528482026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528492026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528502026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528512026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528522026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528532026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528542026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528552026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528562026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528572026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528582026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528592026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528602026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528612026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528622026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528632026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528642026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528652026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528662026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528672026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528682026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=8.25281691850000428692026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=5.77697184295000328702026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528712026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528722026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528732026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528742026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528752026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528762026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528772026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528782026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528792026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528802026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528812026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528822026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528832026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528842026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528852026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528862026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528872026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528882026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528892026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=5.12435000000000128902026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528912026/10/01 10:34:31 WARN Rate limiter backed off name=test rate=528922026/10/01 10:34:32 WARN Rate limiter backed off name=test rate=5.63678500000000128932026/10/01 10:34:32 WARN Rate limiter backed off name=test rate=528942026/10/01 10:34:32 WARN Rate limiter backed off name=test rate=528952026/10/01 10:34:32 WARN Rate limiter backed off name=test rate=528962026/10/01 10:34:32 WARN Rate limiter backed off name=test rate=528972026/10/01 10:34:32 WARN Rate limiter backed off name=test rate=528982026/10/01 10:34:32 WARN Rate limiter backed off name=test rate=528992026/10/01 10:34:32 WARN Rate limiter backed off name=test rate=529002026/10/01 10:34:32 WARN Rate limiter backed off name=test rate=529012026/10/01 10:34:32 WARN Rate limiter backed off name=test rate=529022026/10/01 10:34:32 WARN Rate limiter backed off name=test rate=529032026/10/01 10:34:32 WARN Rate limiter backed off name=test rate=529042026/10/01 10:34:32 WARN Rate limiter backed off name=test rate=529052026/10/01 10:34:32 WARN Rate limiter backed off name=test rate=529062026/10/01 10:34:32 WARN Rate limiter backed off name=test rate=16.08240545225027429072026/10/01 10:34:32 WARN Rate limiter backed off name=test rate=11.25768381657519229082026/10/01 10:34:32 WARN Rate limiter backed off name=test rate=7.8803786716026332909--- PASS: TestAdaptiveRateLimiter_ThreadSafety (0.10s)2910PASS