niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #434
· 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_FailedPartBufferNotReused22=== PAUSE TestUploadMultipart_FailedPartBufferNotReused23=== RUN TestUploadMultipart_ProducerErrorIsNotEOF24=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestUploadMultipart_SupersededByPeer28=== PAUSE TestUploadMultipart_SupersededByPeer29=== RUN TestDumpPathCaseHackMatchesNix30--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)31=== RUN TestDumpPathCaseHackCollision32--- PASS: TestDumpPathCaseHackCollision (0.00s)33=== RUN TestSupersededNARStillUploadsListing34=== PAUSE TestSupersededNARStillUploadsListing35=== RUN TestTruncatedNARDumpIsNotCompleted36=== PAUSE TestTruncatedNARDumpIsNotCompleted37=== RUN TestDumpPathMatchesNix38=== PAUSE TestDumpPathMatchesNix39=== RUN TestDumpPathSingleFile40=== PAUSE TestDumpPathSingleFile41=== RUN TestDumpPathWriterError42=== PAUSE TestDumpPathWriterError43=== RUN TestDumpPathWriterErrorStopsReading44 nar_test.go:289: read 130 of 32768000 bytes45--- PASS: TestDumpPathWriterErrorStopsReading (0.55s)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 TestRetryTimeoutOutlastsMaxRetries79=== PAUSE TestRetryTimeoutOutlastsMaxRetries80=== RUN TestDoWithRetry_FinalResponseBodyReadable81=== PAUSE TestDoWithRetry_FinalResponseBodyReadable82=== RUN TestShellSplit83=== PAUSE TestShellSplit84=== RUN TestShellSplitErrors85=== PAUSE TestShellSplitErrors86=== RUN TestStreamPushReportsEveryPath87=== PAUSE TestStreamPushReportsEveryPath88=== RUN TestStreamPushBatchesUnderLoad89=== PAUSE TestStreamPushBatchesUnderLoad90=== RUN TestStreamPushIsolatesFailures91=== PAUSE TestStreamPushIsolatesFailures92=== RUN TestStreamPushGivesUpOnDeadServer93=== PAUSE TestStreamPushGivesUpOnDeadServer94=== RUN TestStreamPushRequestLine95=== PAUSE TestStreamPushRequestLine96=== RUN TestStreamPushReportsSignatures97=== PAUSE TestStreamPushReportsSignatures98=== RUN TestStreamPushReportsSkippedPaths99=== PAUSE TestStreamPushReportsSkippedPaths100=== RUN TestClientSignaturesByStorePath101=== PAUSE TestClientSignaturesByStorePath102=== RUN TestStreamPushStopsWhenCanceled103=== PAUSE TestStreamPushStopsWhenCanceled104=== RUN TestStreamPushStopsOnCancel105=== PAUSE TestStreamPushStopsOnCancel106=== RUN TestSetClientTLS107=== PAUSE TestSetClientTLS108=== RUN TestSetClientTLSDoesNotMutateDefaultTransport109=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport110=== RUN TestSetClientTLSErrors111=== PAUSE TestSetClientTLSErrors112=== RUN TestStaticToken113=== PAUSE TestStaticToken114=== RUN TestFileTokenReadsAndCaches115=== PAUSE TestFileTokenReadsAndCaches116=== RUN TestFileTokenMissing117=== PAUSE TestFileTokenMissing118=== RUN TestFileTokenEmpty119=== PAUSE TestFileTokenEmpty120=== RUN TestScriptTokenNoExpiryRerunsEveryCall121=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall122=== RUN TestScriptTokenCachesUntilRefresh123=== PAUSE TestScriptTokenCachesUntilRefresh124=== RUN TestScriptTokenEmptyToken125=== PAUSE TestScriptTokenEmptyToken126=== RUN TestScriptTokenBadJSON127=== PAUSE TestScriptTokenBadJSON128=== RUN TestScriptTokenScriptFails129=== PAUSE TestScriptTokenScriptFails130=== RUN TestScriptTokenEmptyCommand131=== PAUSE TestScriptTokenEmptyCommand132=== RUN TestScriptTokenDoesNotWaitForItsChildren133=== PAUSE TestScriptTokenDoesNotWaitForItsChildren134=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry135=== CONT TestScriptTokenDoesNotWaitForItsChildren136=== CONT TestEncodeNixBase32137=== CONT TestClientSignaturesByStorePath138=== CONT TestTruncatedNARDumpIsNotCompleted139=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs140=== CONT TestDoWithRetry_BodyReplayedViaGetBody141=== CONT TestParsePathInfoJSON142=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer143=== CONT TestPathInfoHashCompatibility144=== CONT TestRateLimiterFeedback145=== CONT TestConvertHashToNix32146=== CONT TestParsePathInfoJSONMultiplePaths147=== RUN TestConvertHashToNix32/SRI_format_to_Nix32148=== CONT TestGetStorePathHash149=== CONT TestPathInfoCACompatibility150=== CONT TestUploadMultipart_FailedPartBufferNotReused151=== CONT TestDumpPathWriterError152=== CONT TestRegisterUploadedObjectReusesConnections153=== CONT TestShellSplitErrors154=== CONT TestDoServerRequestAttachesToken155=== CONT TestRetryTimeoutOutlastsMaxRetries156=== CONT TestDoWithRetry_FinalResponseBodyReadable157=== CONT TestUploadMultipart_PartsInParallel158=== CONT TestDumpPathMatchesNix159=== CONT TestStreamPushRequestLine160=== RUN TestEncodeNixBase32/test_string_hash161--- PASS: TestClientSignaturesByStorePath (0.00s)162=== CONT TestFilterOversizedClosures163=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs164=== RUN TestParsePathInfoJSON/Nix_format165=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)166=== RUN TestRateLimiterFeedback/429_enables_limiter167=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths168=== RUN TestGetStorePathHash/valid_store_path169=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32170=== RUN TestPathInfoCACompatibility/null_ca_field171=== CONT TestEncodeNixBase32WithRealHash172--- PASS: TestShellSplitErrors (0.00s)173=== PAUSE TestGetStorePathHash/valid_store_path174=== PAUSE TestRateLimiterFeedback/429_enables_limiter175=== RUN TestConvertHashToNix32/already_Nix32_format176--- PASS: TestEncodeNixBase32WithRealHash (0.00s)177=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent178=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier179=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier180=== PAUSE TestConvertHashToNix32/already_Nix32_format181=== RUN TestFilterOversizedClosures/no_limit_keeps_everything182=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout183=== PAUSE TestParsePathInfoJSON/Nix_format184=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)185=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths186=== PAUSE TestPathInfoCACompatibility/null_ca_field187=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up188=== PAUSE TestEncodeNixBase32/test_string_hash189=== RUN TestConvertHashToNix32/invalid_format190=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything191=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout192=== RUN TestRateLimiterFeedback/503_enables_limiter193=== RUN TestGetStorePathHash/basename_without_hyphen_should_error194=== RUN TestParsePathInfoJSON/Lix_format195=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths196=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon197=== RUN TestPathInfoCACompatibility/old_string_format_-_text198=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped199--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.13s)200=== CONT TestDumpPathSingleFile201=== PAUSE TestConvertHashToNix32/invalid_format202=== CONT TestCaseHackSuffix203=== RUN TestEncodeNixBase32/empty_input204=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up205=== PAUSE TestRateLimiterFeedback/503_enables_limiter206=== CONT TestCompletePendingClosure_NotFoundWithoutKey207=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error208=== CONT TestFileTokenMissing209=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon210=== PAUSE TestParsePathInfoJSON/Lix_format211=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths212=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped213=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text214--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.12s)215=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun216=== PAUSE TestEncodeNixBase32/empty_input217=== CONT TestSupersededNARStillUploadsListing218=== RUN TestSupersededNARStillUploadsListing/small_NAR219=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier220=== CONT TestScriptTokenBadJSON221=== CONT TestScriptTokenEmptyToken222=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI223=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error224=== PAUSE TestSupersededNARStillUploadsListing/small_NAR225=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error226=== RUN TestSupersededNARStillUploadsListing/dump_cut_short227=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI228=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short229=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier230=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512231=== CONT TestScriptTokenScriptFails232=== RUN TestFilterOversizedClosures/all_closures_skipped233=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive234--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)235=== CONT TestPartSizeForNAR236=== PAUSE TestFilterOversizedClosures/all_closures_skipped237=== RUN TestPartSizeForNAR/zero_stays_at_minimum238--- PASS: TestDoServerRequestAttachesToken (0.01s)239--- PASS: TestFileTokenMissing (0.00s)240--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.00s)241=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive242=== RUN TestPathInfoCACompatibility/new_structured_format_-_text243=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter244=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter245=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error246=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails247=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client248=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512249=== CONT TestScriptTokenCachesUntilRefresh250=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client251=== RUN TestParsePathInfoJSON/empty_input252=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum253=== PAUSE TestParsePathInfoJSON/empty_input254=== RUN TestPartSizeForNAR/small_stays_at_minimum255=== RUN TestParsePathInfoJSON/whitespace_only256=== PAUSE TestParsePathInfoJSON/whitespace_only257=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text258=== PAUSE TestPartSizeForNAR/small_stays_at_minimum259=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method260=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error261=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails262=== CONT TestUploadMultipart_SupersededByPeer263=== RUN TestUploadMultipart_SupersededByPeer/exists264=== PAUSE TestUploadMultipart_SupersededByPeer/exists265=== RUN TestUploadMultipart_SupersededByPeer/missing266=== CONT TestScriptTokenNoExpiryRerunsEveryCall267=== CONT TestUploadMultipart_ProducerErrorIsNotEOF268=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part269=== RUN TestParsePathInfoJSON/invalid_JSON270=== PAUSE TestParsePathInfoJSON/invalid_JSON271=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter272=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method273--- PASS: TestScriptTokenScriptFails (0.00s)274=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum275=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client276=== PAUSE TestUploadMultipart_SupersededByPeer/missing277=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part278=== CONT TestStreamPushBatchesUnderLoad279--- PASS: TestScriptTokenEmptyToken (0.00s)280=== CONT TestStreamPushGivesUpOnDeadServer281=== RUN TestStreamPushBatchesUnderLoad/together282=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter283=== CONT TestFileTokenReadsAndCaches284--- PASS: TestScriptTokenBadJSON (0.00s)285=== PAUSE TestStreamPushBatchesUnderLoad/together286=== CONT TestSetClientTLSErrors287--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)288=== CONT TestStreamPushReportsSkippedPaths289--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)290--- PASS: TestStreamPushReportsSkippedPaths (0.00s)291=== CONT TestSetClientTLS292--- PASS: TestFileTokenReadsAndCaches (0.00s)293=== CONT TestStreamPushIsolatesFailures294=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary295=== CONT TestScriptTokenEmptyCommand296=== CONT TestFileTokenEmpty297=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum298=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client299=== CONT TestStreamPushReportsSignatures300=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts301=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts302=== CONT TestStaticToken303=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess304=== CONT TestStreamPushReportsEveryPath305=== CONT TestStreamPushStopsOnCancel306=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary307--- PASS: TestScriptTokenEmptyCommand (0.00s)308=== RUN TestStreamPushStopsOnCancel/waiting_for_input309--- PASS: TestStreamPushIsolatesFailures (0.00s)310=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input311=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot312--- PASS: TestFileTokenEmpty (0.00s)313=== RUN TestPartSizeForNAR/1_TiB314=== CONT TestSetClientTLSDoesNotMutateDefaultTransport315=== CONT TestResolveStorePath316=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure317=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time318=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica319=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot320--- PASS: TestStaticToken (0.00s)321--- PASS: TestStreamPushReportsEveryPath (0.00s)322=== PAUSE TestPartSizeForNAR/1_TiB323=== RUN TestPartSizeForNAR/5_TiB_S3_max_object324--- PASS: TestStreamPushReportsSignatures (0.00s)325=== CONT TestStreamPushStopsWhenCanceled326=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time327=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot328=== RUN TestSetClientTLSErrors/missing_cert_file329=== PAUSE TestSetClientTLSErrors/missing_cert_file330=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object331=== RUN TestSetClientTLSErrors/missing_key_file332=== PAUSE TestSetClientTLSErrors/missing_key_file333=== RUN TestPartSizeForNAR/capped_at_5_GiB334=== CONT TestShellSplit335=== RUN TestSetClientTLSErrors/missing_ca_file336--- PASS: TestStreamPushStopsWhenCanceled (0.00s)337=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout338=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot339=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs340=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths341=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot342=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths343=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot344=== PAUSE TestSetClientTLSErrors/missing_ca_file345=== RUN TestSetClientTLS/rejects_connection_without_client_cert346=== RUN TestSetClientTLSErrors/invalid_ca_file347=== CONT TestEncodeNixBase32/test_string_hash348=== CONT TestConvertHashToNix32/already_Nix32_format349=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot350=== PAUSE TestPartSizeForNAR/capped_at_5_GiB351--- PASS: TestShellSplit (0.00s)352=== CONT TestEncodeNixBase32/empty_input353=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert354=== PAUSE TestSetClientTLSErrors/invalid_ca_file355=== CONT TestConvertHashToNix32/invalid_format356=== CONT TestConvertHashToNix32/SRI_format_to_Nix32357=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot358=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI359=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512360--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)361--- PASS: TestResolveStorePath (0.00s)362=== CONT TestFilterOversizedClosures/no_limit_keeps_everything363=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA364=== CONT TestFilterOversizedClosures/all_closures_skipped365=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped366=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken367=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon368=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)369=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails370=== CONT TestSupersededNARStillUploadsListing/dump_cut_short371--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)372=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error373--- PASS: TestEncodeNixBase32 (0.13s)374 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)375 --- PASS: TestEncodeNixBase32/empty_input (0.00s)376=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA377=== CONT TestGetStorePathHash/basename_without_hyphen_should_error378=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken379=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error380=== CONT TestGetStorePathHash/valid_store_path381=== CONT TestSupersededNARStillUploadsListing/small_NAR382=== CONT TestParsePathInfoJSON/Nix_format383=== CONT TestParsePathInfoJSON/Lix_format384=== CONT TestPathInfoCACompatibility/old_string_format_-_text385--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)386=== RUN TestSetClientTLS/preserves_debug_logging_transport387=== PAUSE TestSetClientTLS/preserves_debug_logging_transport388=== CONT TestParsePathInfoJSON/invalid_JSON389=== CONT TestParsePathInfoJSON/whitespace_only390=== CONT TestParsePathInfoJSON/empty_input391=== CONT TestPathInfoCACompatibility/new_structured_format_-_text392=== CONT TestRateLimiterFeedback/429_enables_limiter393--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)394 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)395 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)396=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive397=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method398=== CONT TestPathInfoCACompatibility/null_ca_field399=== CONT TestUploadMultipart_SupersededByPeer/missing400=== CONT TestUploadMultipart_SupersededByPeer/exists401--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)402=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter403--- PASS: TestFilterOversizedClosures (0.02s)404 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)405 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)406 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)407=== CONT TestRateLimiterFeedback/503_enables_limiter408=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter409--- PASS: TestConvertHashToNix32 (0.02s)410 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)411 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)412 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)413--- PASS: TestPathInfoHashCompatibility (0.13s)414 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)415 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)416 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)417 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)418--- PASS: TestGetStorePathHash (0.02s)419 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)420 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)421 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)422 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)423--- PASS: TestParsePathInfoJSON (0.13s)424 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)425 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)426 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)427 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)428 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)429--- PASS: TestPathInfoCACompatibility (0.02s)430 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)431 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)432 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)433 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)434 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)435=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier436=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up437=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client438=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier439=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client440--- PASS: TestRateLimiterFeedback (0.13s)441 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)442 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)443 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)444 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)445=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary446--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)447 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)448 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)449--- PASS: TestDumpPathSingleFile (0.18s)450=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part451=== CONT TestStreamPushBatchesUnderLoad/together452--- PASS: TestCaseHackSuffix (0.18s)453=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time454=== CONT TestPartSizeForNAR/capped_at_5_GiB455=== CONT TestPartSizeForNAR/1_TiB456=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts457=== CONT TestSetClientTLSErrors/invalid_ca_file458=== CONT TestSetClientTLSErrors/missing_ca_file459=== CONT TestSetClientTLSErrors/missing_key_file460=== CONT TestPartSizeForNAR/5_TiB_S3_max_object461=== CONT TestSetClientTLSErrors/missing_cert_file462=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken463=== CONT TestStreamPushStopsOnCancel/waiting_for_input464--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.02s)465 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.15s)466 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.15s)467 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.15s)468 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.15s)469 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.15s)470--- PASS: TestStreamPushBatchesUnderLoad (0.01s)471 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)472 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)473=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot474=== CONT TestPartSizeForNAR/small_stays_at_minimum475=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot476=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum477=== CONT TestPartSizeForNAR/zero_stays_at_minimum478=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot479=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot480--- PASS: TestPartSizeForNAR (0.01s)481 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)482 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)483 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)484 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)485 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)486 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)487 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)488--- PASS: TestSetClientTLSErrors (0.01s)489 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)490 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)491 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)492 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)493--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.21s)494=== CONT TestSetClientTLS/preserves_debug_logging_transport495=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA496=== CONT TestSetClientTLS/rejects_connection_without_client_cert497--- PASS: TestDumpPathWriterError (0.22s)498--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.21s)499--- PASS: TestStreamPushStopsOnCancel (0.01s)500 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.05s)501 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.05s)502 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.06s)503 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)504 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.06s)505 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.05s)506--- PASS: TestSetClientTLS (0.01s)507 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)508 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)509 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.09s)510--- PASS: TestRegisterUploadedObjectReusesConnections (0.31s)511--- PASS: TestStreamPushRequestLine (0.31s)512--- PASS: TestDumpPathMatchesNix (0.40s)513--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.00s)514 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.34s)515 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.22s)516--- PASS: TestTruncatedNARDumpIsNotCompleted (1.05s)517--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.12s)518--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)519--- PASS: TestSupersededNARStillUploadsListing (0.00s)520 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.18s)521 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.18s)522 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.16s)523--- PASS: TestUploadMultipart_PartsInParallel (1.25s)524--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.27s)525--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.13s)526 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.00s)527 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.20s)528PASS529Running server tests...530The files belonging to this database system will be owned by user "nixbld".531This user must also own the server process.532533The database cluster will be initialized with locale "C".534The default database encoding has accordingly been set to "SQL_ASCII".535The default text search configuration will be set to "english".536537Data page checksums are enabled.538539creating directory /build/postgres664634917/data ... ok540creating subdirectories ... ok541selecting dynamic shared memory implementation ... posix542selecting default "max_connections" ... 100543selecting default "shared_buffers" ... 128MB544selecting default time zone ... UTC545creating configuration files ... ok546running bootstrap script ... ok547performing post-bootstrap initialization ... ok548syncing data to disk ... ok549550initdb: warning: enabling "trust" authentication for local connections551initdb: 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.552553Success. You can now start the database server using:554555 pg_ctl -D /build/postgres664634917/data -l logfile start556557/build/postgres664634917:5432 - no response5582026-10-25 19:17:58.676 UTC [173] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit5592026-10-25 19:17:58.676 UTC [173] LOG: listening on Unix socket "/build/postgres664634917/.s.PGSQL.5432"5602026-10-25 19:17:58.681 UTC [180] LOG: database system was shut down at 2026-10-25 19:17:58 UTC5612026-10-25 19:17:58.685 UTC [173] LOG: database system is ready to accept connections562/build/postgres664634917:5432 - accepting connections563=== RUN TestService_AuthMiddleware564=== PAUSE TestService_AuthMiddleware565=== RUN TestService_AuthMiddleware_MTLSProxyHeader566=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader567=== RUN TestService_AuthMiddleware_MTLSBoundSubjects568=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects569=== RUN TestService_ReadAuthMiddleware570=== PAUSE TestService_ReadAuthMiddleware571=== RUN TestService_AuthMiddleware_OIDC572=== PAUSE TestService_AuthMiddleware_OIDC573=== RUN TestService_RequireScope_OIDC574=== PAUSE TestService_RequireScope_OIDC575=== RUN TestService_ReadScope_PublicByDefault576=== PAUSE TestService_ReadScope_PublicByDefault577=== RUN TestCacheConfigHandler578=== PAUSE TestCacheConfigHandler579=== RUN TestCacheStatsHandler580=== PAUSE TestCacheStatsHandler581=== RUN TestClientCADerivations582=== PAUSE TestClientCADerivations583=== RUN TestClientErrorHandling584=== PAUSE TestClientErrorHandling585=== RUN TestClientIntegration586=== PAUSE TestClientIntegration587=== RUN TestClientMultipleUploads588=== PAUSE TestClientMultipleUploads589=== RUN TestClientWithDependencies590=== PAUSE TestClientWithDependencies591=== RUN TestClientSharedPathCommittedMidPush592=== PAUSE TestClientSharedPathCommittedMidPush593=== RUN TestPinProtectsFromGC594=== PAUSE TestPinProtectsFromGC595=== RUN TestClientPushesUseOnePush596=== PAUSE TestClientPushesUseOnePush597=== RUN TestClientFallsBackToClosures598=== PAUSE TestClientFallsBackToClosures599=== RUN TestDeleteClosuresRacingPins600=== PAUSE TestDeleteClosuresRacingPins601=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock602=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock603=== RUN TestResolveDBConnectionString604=== PAUSE TestResolveDBConnectionString605=== RUN TestConnectWaitsForAPeerMigration606=== PAUSE TestConnectWaitsForAPeerMigration607=== RUN TestConnectSerialisesConcurrentMigrations608=== PAUSE TestConnectSerialisesConcurrentMigrations609=== RUN TestLeadElectsOneAndHandsOver610=== PAUSE TestLeadElectsOneAndHandsOver611=== RUN TestLeadIncumbentWinsAfterRestart6122026/10/25 19:17:59 INFO lead: acquired remote=192.0.2.1:12346132026/10/25 19:17:59 INFO lead: released remote=192.0.2.1:12346142026/10/25 19:17:59 INFO lead: acquired remote=192.0.2.1:12346152026/10/25 19:18:01 INFO lead: released remote=192.0.2.1:1234616--- PASS: TestLeadIncumbentWinsAfterRestart (1.91s)617=== RUN TestLeadIncumbentAnnouncesAtOnce618=== PAUSE TestLeadIncumbentAnnouncesAtOnce619=== RUN TestLeadEndsOnShutdown620=== PAUSE TestLeadEndsOnShutdown621=== RUN TestLeadEndsWhenItsConnectionHangs6222026/10/25 19:18:01 INFO lead: acquired remote=192.0.2.1:12346232026-10-25 19:18:02.633 UTC [374] FATAL: terminating connection due to administrator command6242026/10/25 19:18:02 INFO lead: acquired remote=192.0.2.1:12346252026/10/25 19:18:03 WARN lead: lock connection lost error="timeout: context deadline exceeded"6262026/10/25 19:18:03 INFO lead: released remote=192.0.2.1:12346272026/10/25 19:18:04 INFO lead: released remote=192.0.2.1:1234628--- PASS: TestLeadEndsWhenItsConnectionHangs (2.95s)629=== RUN TestGCAdvisoryLockBlocksConcurrentRun630=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun631=== RUN TestGCBugBareHashReferences632=== PAUSE TestGCBugBareHashReferences633=== RUN TestGCMetrics634=== PAUSE TestGCMetrics635=== RUN TestPushDedupSurvivesConcurrentGC636=== PAUSE TestPushDedupSurvivesConcurrentGC637=== RUN TestDeduplicatedObjectsRecordedAsPending638=== PAUSE TestDeduplicatedObjectsRecordedAsPending639=== RUN TestGCSweepSkipsPendingObjects640=== PAUSE TestGCSweepSkipsPendingObjects641=== RUN TestTombstonedObjectOfferedWithoutWaiting642=== PAUSE TestTombstonedObjectOfferedWithoutWaiting643=== RUN TestGCSweepDeliversEachKeyOnce644=== PAUSE TestGCSweepDeliversEachKeyOnce645=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection646=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection647=== RUN TestForceGCDuringPushOffersSweptObject648=== PAUSE TestForceGCDuringPushOffersSweptObject649=== RUN TestFailedS3DeleteKeepsTombstone650=== PAUSE TestFailedS3DeleteKeepsTombstone651=== RUN TestSweepSkipsRowsLockedByPush652=== PAUSE TestSweepSkipsRowsLockedByPush653=== RUN TestRegisterCompletedObjectNeedsPendingRow654=== PAUSE TestRegisterCompletedObjectNeedsPendingRow655=== RUN TestGetExistingObjectsLocksRows656=== PAUSE TestGetExistingObjectsLocksRows657=== RUN TestSweepRechecksPendingAfterLocking658=== PAUSE TestSweepRechecksPendingAfterLocking659=== RUN TestPushWaitsForSweepHoldingRow660=== PAUSE TestPushWaitsForSweepHoldingRow661=== RUN TestCommitRacingPendingCleanupKeepsObjects662=== PAUSE TestCommitRacingPendingCleanupKeepsObjects663=== RUN TestGCEndsOnShutdown664=== PAUSE TestGCEndsOnShutdown665=== RUN TestGCTaskStore_StartNew666=== PAUSE TestGCTaskStore_StartNew667=== RUN TestGCTaskStore_DeduplicateSameParams668=== PAUSE TestGCTaskStore_DeduplicateSameParams669=== RUN TestGCTaskStore_ConflictDifferentParams670=== PAUSE TestGCTaskStore_ConflictDifferentParams671=== RUN TestGCTaskStore_GetEmpty672=== PAUSE TestGCTaskStore_GetEmpty673=== RUN TestGCTaskStore_GetReturnsLatest674=== PAUSE TestGCTaskStore_GetReturnsLatest675=== RUN TestGCTaskStore_CompletedAllowsNewTask676=== PAUSE TestGCTaskStore_CompletedAllowsNewTask677=== RUN TestGCTaskStore_PhaseUpdates678=== PAUSE TestGCTaskStore_PhaseUpdates679=== RUN TestGCTaskStore_Fail680=== PAUSE TestGCTaskStore_Fail681=== RUN TestGracefulShutdownDrainsInflight682=== PAUSE TestGracefulShutdownDrainsInflight683=== RUN TestService_healthCheckHandler684=== PAUSE TestService_healthCheckHandler685=== RUN TestService_readinessHandler686=== PAUSE TestService_readinessHandler687=== RUN TestGenerateLandingPage688=== PAUSE TestGenerateLandingPage689=== RUN TestChildrenInheritRaisedFileLimit690=== PAUSE TestChildrenInheritRaisedFileLimit691=== RUN TestCacheConfigHandlerMaxNarSize692=== PAUSE TestCacheConfigHandlerMaxNarSize693=== RUN TestCreatePendingClosureRejectsOversizedNAR694=== PAUSE TestCreatePendingClosureRejectsOversizedNAR695=== RUN TestNARDeduplicationMetadataUploadBug696=== PAUSE TestNARDeduplicationMetadataUploadBug697=== RUN TestMetricsInventory698=== PAUSE TestMetricsInventory699=== RUN TestMetricsCommit700=== PAUSE TestMetricsCommit701=== RUN TestService_NativeMTLS702=== PAUSE TestService_NativeMTLS703=== RUN TestServerTLSConfig704=== PAUSE TestServerTLSConfig705=== RUN TestMultipartCleanup706=== PAUSE TestMultipartCleanup707=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded708=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded709=== RUN TestPendingCleanupUsesOneCutoff710=== PAUSE TestPendingCleanupUsesOneCutoff711=== RUN TestPendingClosureFailureTracksEveryUpload712=== PAUSE TestPendingClosureFailureTracksEveryUpload713=== RUN TestPendingClosureFailureAbortsItsUploads714=== PAUSE TestPendingClosureFailureAbortsItsUploads715=== RUN TestObjectStatsTrigger716=== PAUSE TestObjectStatsTrigger717=== RUN TestObjectStatsUpdatedOncePerCommit718=== PAUSE TestObjectStatsUpdatedOncePerCommit719=== RUN TestReconnectLeavesObjectsUnlocked720=== PAUSE TestReconnectLeavesObjectsUnlocked721=== RUN TestOrphanedObjectsGC722=== PAUSE TestOrphanedObjectsGC723=== RUN TestOrphanedObjectsGCStressTest724=== PAUSE TestOrphanedObjectsGCStressTest725=== RUN TestCreatePin_ReservedPins726=== PAUSE TestCreatePin_ReservedPins727=== RUN TestConcurrentPinUpdatesAgree728=== PAUSE TestConcurrentPinUpdatesAgree729=== RUN TestCreatePinRejectsBadInput730=== PAUSE TestCreatePinRejectsBadInput731=== RUN TestDeletePinKeepsRowWhenS3Fails732=== PAUSE TestDeletePinKeepsRowWhenS3Fails733=== RUN TestPresentReportsOnlyClosureRoots734=== PAUSE TestPresentReportsOnlyClosureRoots735=== RUN TestPresentRefreshesOnlyStaleClosures736=== PAUSE TestPresentRefreshesOnlyStaleClosures737=== RUN TestPresentNotReportedWhileGCDeletesClosure738=== PAUSE TestPresentNotReportedWhileGCDeletesClosure739=== RUN TestParseSingleRange740=== PAUSE TestParseSingleRange741=== RUN TestProxyHeadersOnlyTrustedOnSocket7422026/10/25 19:18:04 INFO Starting HTTP server address=127.0.0.1:345297432026/10/25 19:18:04 INFO Starting HTTP server address=proxy.sock7442026/10/25 19:18:04 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7452026/10/25 19:18:04 INFO Shutdown signal received, draining in-flight requests timeout=10s746--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.15s)747=== RUN TestIsValidCachePath748=== PAUSE TestIsValidCachePath749=== RUN TestReadProxyNarinfo750=== PAUSE TestReadProxyNarinfo751=== RUN TestReadProxyNarinfoAlreadyDecompressed752=== PAUSE TestReadProxyNarinfoAlreadyDecompressed753=== RUN TestReadProxyContentNegotiation754=== PAUSE TestReadProxyContentNegotiation755=== RUN TestReadProxyNarStreaming756=== PAUSE TestReadProxyNarStreaming757=== RUN TestReadProxy404758=== PAUSE TestReadProxy404759=== RUN TestReadProxyInvalidPath760=== PAUSE TestReadProxyInvalidPath761=== RUN TestReadProxyHead762=== PAUSE TestReadProxyHead763=== RUN TestReadProxyOutlastsServerWriteTimeout764=== PAUSE TestReadProxyOutlastsServerWriteTimeout765=== RUN TestReadProxyConditionalGet766=== PAUSE TestReadProxyConditionalGet767=== RUN TestReadProxyRootRedirectsToIndexHTML768=== PAUSE TestReadProxyRootRedirectsToIndexHTML769=== RUN TestReadProxyDisabled770=== PAUSE TestReadProxyDisabled771=== RUN TestReadRedirectNar772=== PAUSE TestReadRedirectNar773=== RUN TestReadRedirectKeepsNarinfoProxied774=== PAUSE TestReadRedirectKeepsNarinfoProxied775=== RUN TestReadProxyRangeRequest776=== PAUSE TestReadProxyRangeRequest777=== RUN TestReadRedirectUsesPublicS3URL778=== PAUSE TestReadRedirectUsesPublicS3URL779=== RUN TestPush_OverlappingRootsStoreOneRowPerKey780=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey781=== RUN TestPush_CompleteCommitsEveryRoot782=== PAUSE TestPush_CompleteCommitsEveryRoot783=== RUN TestPush_RepeatedRootCommitsOnce784=== PAUSE TestPush_RepeatedRootCommitsOnce785=== RUN TestPush_CompleteWaitsForCleanupOfThePush786=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush787=== RUN TestPush_RootsAreLockedInByteOrder788=== PAUSE TestPush_RootsAreLockedInByteOrder789=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit790=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit791=== RUN TestPush_RejectsBadRequests792=== PAUSE TestPush_RejectsBadRequests793=== RUN TestPush_SignsNarinfosOfItsPendingObjects794=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects795=== RUN TestRedundantMultipartUpload796=== PAUSE TestRedundantMultipartUpload797=== RUN TestCompleteMultipartUpload_ErrorButObjectExists798=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists799=== RUN TestCompletedNarNotReofferedAcrossClosures800=== PAUSE TestCompletedNarNotReofferedAcrossClosures801=== RUN TestPresignedUploadRegisteredBeforeCommit802=== PAUSE TestPresignedUploadRegisteredBeforeCommit803=== RUN TestService_Rustfstest804=== PAUSE TestService_Rustfstest805=== RUN TestParseSize806=== PAUSE TestParseSize807=== RUN TestSkippedUploadsHandler808=== PAUSE TestSkippedUploadsHandler809=== RUN TestSystemdListenerNotActivated810--- PASS: TestSystemdListenerNotActivated (0.00s)811=== RUN TestWatchdogBeatsWhenHealthy812--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)813=== RUN TestWatchdogSkipsWhenUnhealthy8142026/10/25 19:18:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8152026/10/25 19:18:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8162026/10/25 19:18:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8172026/10/25 19:18:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8182026/10/25 19:18:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8192026/10/25 19:18:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8202026/10/25 19:18:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8212026/10/25 19:18:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8222026/10/25 19:18:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8232026/10/25 19:18:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"824--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)825=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle826=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle827=== RUN TestProxyWriteTimeout828=== PAUSE TestProxyWriteTimeout829=== RUN TestPendingClosureWriteTimeout830=== PAUSE TestPendingClosureWriteTimeout831=== RUN TestIsValidUploadKey832=== PAUSE TestIsValidUploadKey833=== RUN TestUploadHandlersRejectInvalidKeys834=== PAUSE TestUploadHandlersRejectInvalidKeys835=== RUN TestUploadHandlersRejectOversizedBody836=== PAUSE TestUploadHandlersRejectOversizedBody837=== RUN TestService_cleanupPendingClosuresHandler838=== PAUSE TestService_cleanupPendingClosuresHandler839=== RUN TestService_createPendingClosureHandler840=== PAUSE TestService_createPendingClosureHandler841=== RUN TestService_verifyS3Integrity842=== PAUSE TestService_verifyS3Integrity843=== RUN TestCompleteMultipartUnregistered844=== PAUSE TestCompleteMultipartUnregistered845=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT846=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT847=== CONT TestReadProxyRootRedirectsToIndexHTML848=== CONT TestService_AuthMiddleware_MTLSProxyHeader849=== CONT TestReadProxyHead850=== CONT TestReadProxyInvalidPath851=== CONT TestReadProxyNarStreaming852=== CONT TestReadProxy404853=== CONT TestReadProxyContentNegotiation854=== CONT TestReadProxyNarinfoAlreadyDecompressed855=== CONT TestIsValidCachePath856=== CONT TestParseSingleRange857=== CONT TestPresentNotReportedWhileGCDeletesClosure858=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale859=== CONT TestPresentRefreshesOnlyStaleClosures860=== CONT TestReadProxyNarinfo861=== CONT TestPresentReportsOnlyClosureRoots862=== CONT TestDeletePinKeepsRowWhenS3Fails863=== CONT TestConcurrentPinUpdatesAgree864=== CONT TestSweepSkipsRowsLockedByPush865=== CONT TestFailedS3DeleteKeepsTombstone866=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection867=== CONT TestGCSweepDeliversEachKeyOnce868=== CONT TestTombstonedObjectOfferedWithoutWaiting869=== CONT TestForceGCDuringPushOffersSweptObject870=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows871=== CONT TestGCSweepSkipsPendingObjects872=== CONT TestGetExistingObjectsLocksRows873=== RUN TestIsValidCachePath/narinfo874=== RUN TestParseSingleRange/none875=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale876=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows877=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check878=== PAUSE TestParseSingleRange/none879=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh880=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check881=== PAUSE TestIsValidCachePath/narinfo882=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh883=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars884=== CONT TestGCMetrics885=== RUN TestParseSingleRange/unknown_unit886=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars887=== CONT TestPushDedupSurvivesConcurrentGC888=== RUN TestIsValidCachePath/nar_zst889=== PAUSE TestParseSingleRange/unknown_unit890=== PAUSE TestIsValidCachePath/nar_zst891=== RUN TestParseSingleRange/multi-range_ignored892=== RUN TestIsValidCachePath/nar_xz893=== PAUSE TestIsValidCachePath/nar_xz894=== PAUSE TestParseSingleRange/multi-range_ignored895=== RUN TestIsValidCachePath/nar_bz2896=== RUN TestParseSingleRange/malformed_no_dash897=== PAUSE TestParseSingleRange/malformed_no_dash898=== PAUSE TestIsValidCachePath/nar_bz2899=== RUN TestParseSingleRange/malformed_both_empty900=== RUN TestIsValidCachePath/nar_uncompressed901=== PAUSE TestParseSingleRange/malformed_both_empty902=== PAUSE TestIsValidCachePath/nar_uncompressed903=== RUN TestParseSingleRange/malformed_end_before_start904=== PAUSE TestParseSingleRange/malformed_end_before_start905=== RUN TestIsValidCachePath/ls906=== RUN TestParseSingleRange/closed907=== PAUSE TestIsValidCachePath/ls908=== PAUSE TestParseSingleRange/closed909=== RUN TestIsValidCachePath/log910=== PAUSE TestIsValidCachePath/log911=== RUN TestParseSingleRange/open-ended912=== RUN TestIsValidCachePath/realisation913=== PAUSE TestParseSingleRange/open-ended914=== RUN TestParseSingleRange/end_clamped_to_size915=== PAUSE TestIsValidCachePath/realisation916=== RUN TestIsValidCachePath/nix-cache-info917=== PAUSE TestParseSingleRange/end_clamped_to_size918=== RUN TestParseSingleRange/suffix919=== PAUSE TestIsValidCachePath/nix-cache-info920=== PAUSE TestParseSingleRange/suffix921=== RUN TestParseSingleRange/suffix_exceeds_size922=== PAUSE TestParseSingleRange/suffix_exceeds_size923=== RUN TestIsValidCachePath/index.html924=== RUN TestParseSingleRange/single_byte925=== PAUSE TestIsValidCachePath/index.html926=== PAUSE TestParseSingleRange/single_byte927=== RUN TestIsValidCachePath/traversal_parent928=== RUN TestParseSingleRange/start_past_EOF929=== PAUSE TestParseSingleRange/start_past_EOF930=== RUN TestParseSingleRange/start_far_past_EOF931=== PAUSE TestIsValidCachePath/traversal_parent932=== PAUSE TestParseSingleRange/start_far_past_EOF933=== RUN TestIsValidCachePath/traversal_in_middle934=== CONT TestGCBugBareHashReferences935=== PAUSE TestIsValidCachePath/traversal_in_middle936=== RUN TestIsValidCachePath/invalid_char_e937=== PAUSE TestIsValidCachePath/invalid_char_e938=== RUN TestIsValidCachePath/invalid_char_u939=== PAUSE TestIsValidCachePath/invalid_char_u940=== RUN TestIsValidCachePath/random_path941=== PAUSE TestIsValidCachePath/random_path942=== RUN TestIsValidCachePath/empty943=== PAUSE TestIsValidCachePath/empty944=== RUN TestIsValidCachePath/leading_slash945=== PAUSE TestIsValidCachePath/leading_slash946=== RUN TestIsValidCachePath/wrong_extension947=== PAUSE TestIsValidCachePath/wrong_extension948=== RUN TestIsValidCachePath/short_hash949=== PAUSE TestIsValidCachePath/short_hash950=== CONT TestGCAdvisoryLockBlocksConcurrentRun951--- PASS: TestReadProxyInvalidPath (0.33s)952=== CONT TestLeadEndsOnShutdown953--- PASS: TestReadProxyNarStreaming (0.37s)954=== CONT TestDeduplicatedObjectsRecordedAsPending955=== CONT TestLeadElectsOneAndHandsOver956--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.38s)9572026/10/25 19:18:04 INFO Aborted multipart uploads count=0 kept=09582026/10/25 19:18:04 WARN Force mode enabled - objects will be deleted immediately without grace period9592026/10/25 19:18:04 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=09602026/10/25 19:18:04 INFO Vacuumed table table=pending_closures9612026/10/25 19:18:04 INFO Vacuumed table table=pending_objects9622026/10/25 19:18:04 INFO Received create pin request method=POST path=/api/pins/app9632026/10/25 19:18:04 INFO Vacuumed table table=multipart_uploads9642026/10/25 19:18:04 INFO Vacuumed table table=closures9652026/10/25 19:18:04 INFO Vacuumed table table=objects9662026/10/25 19:18:04 INFO Received create pin request method=POST path=/api/pins/app967--- PASS: TestGCSweepDeliversEachKeyOnce (0.51s)968=== CONT TestLeadIncumbentAnnouncesAtOnce9692026/10/25 19:18:04 INFO Aborted multipart uploads count=0 kept=09702026/10/25 19:18:04 WARN Force mode enabled - objects will be deleted immediately without grace period9712026/10/25 19:18:04 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=09722026/10/25 19:18:04 INFO Vacuumed table table=pending_closures9732026/10/25 19:18:04 INFO Vacuumed table table=pending_objects9742026/10/25 19:18:04 INFO Vacuumed table table=multipart_uploads9752026/10/25 19:18:04 INFO Vacuumed table table=closures9762026/10/25 19:18:04 INFO Vacuumed table table=objects9772026/10/25 19:18:05 INFO Aborted multipart uploads count=0 kept=09782026/10/25 19:18:05 INFO Received uploads request method=POST path=/api/pending_closures9792026/10/25 19:18:05 WARN Force mode enabled - objects will be deleted immediately without grace period980--- PASS: TestPresentReportsOnlyClosureRoots (0.57s)981=== CONT TestConnectWaitsForAPeerMigration9822026/10/25 19:18:05 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=09832026/10/25 19:18:05 INFO Vacuumed table table=pending_closures9842026/10/25 19:18:05 INFO Vacuumed table table=pending_objects9852026/10/25 19:18:05 INFO Vacuumed table table=multipart_uploads9862026/10/25 19:18:05 INFO Vacuumed table table=closures9872026/10/25 19:18:05 INFO Vacuumed table table=objects9882026/10/25 19:18:05 INFO Received uploads request method=POST path=/api/pending_closures989=== CONT TestCreatePin_ReservedPins990--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.60s)991--- PASS: TestSweepSkipsRowsLockedByPush (0.61s)992=== CONT TestResolveDBConnectionString993=== RUN TestResolveDBConnectionString/flag_wins994=== PAUSE TestResolveDBConnectionString/flag_wins995=== RUN TestResolveDBConnectionString/file_when_flag_empty996=== PAUSE TestResolveDBConnectionString/file_when_flag_empty997=== RUN TestResolveDBConnectionString/missing_file_is_an_error998=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error999=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1000=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1001=== RUN TestResolveDBConnectionString/nothing_configured1002=== PAUSE TestResolveDBConnectionString/nothing_configured1003=== CONT TestCreatePinRejectsBadInput10042026/10/25 19:18:05 INFO Aborted multipart uploads count=0 kept=010052026/10/25 19:18:05 WARN Force mode enabled - objects will be deleted immediately without grace period10062026/10/25 19:18: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=01007=== CONT TestDeleteClosuresRacingPins1008--- PASS: TestReadProxyHead (0.64s)10092026/10/25 19:18:05 INFO Vacuumed table table=pending_closures10102026/10/25 19:18:05 INFO Vacuumed table table=pending_objects10112026/10/25 19:18:05 INFO Vacuumed table table=multipart_uploads10122026/10/25 19:18:05 INFO Vacuumed table table=closures10132026/10/25 19:18:05 INFO Vacuumed table table=objects10142026/10/25 19:18:05 INFO Received uploads request method=POST path=/api/pending_closures10152026/10/25 19:18:05 INFO Aborted multipart uploads count=0 kept=010162026/10/25 19:18:05 WARN Force mode enabled - objects will be deleted immediately without grace period1017=== CONT TestOrphanedObjectsGCStressTest1018--- PASS: TestGCMetrics (0.69s)1019=== CONT TestClientFallsBackToClosures1020--- PASS: TestGetExistingObjectsLocksRows (0.70s)10212026/10/25 19:18:05 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."10222026/10/25 19:18:05 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."10232026/10/25 19:18:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35303/oidc10242026/10/25 19:18:05 INFO Received uploads request method=POST path=/api/pending_closures10252026/10/25 19:18:05 INFO Received uploads request method=POST path=/api/pending_closures1026=== CONT TestReconnectLeavesObjectsUnlocked1027--- PASS: TestFailedS3DeleteKeepsTombstone (0.74s)1028=== CONT TestClientPushesUseOnePush1029--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.78s)10302026/10/25 19:18:05 INFO Aborted multipart uploads count=0 kept=010312026/10/25 19:18:05 WARN Force mode enabled - objects will be deleted immediately without grace period10322026/10/25 19:18: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=010332026/10/25 19:18:05 INFO Vacuumed table table=pending_closures10342026/10/25 19:18:05 INFO Vacuumed table table=pending_objects10352026/10/25 19:18:05 INFO Vacuumed table table=multipart_uploads10362026/10/25 19:18:05 INFO Vacuumed table table=closures10372026/10/25 19:18:05 INFO Vacuumed table table=objects1038=== CONT TestClientWithDependencies1039--- PASS: TestPresentRefreshesOnlyStaleClosures (0.81s)10402026/10/25 19:18:05 INFO Aborted multipart uploads count=0 kept=01041--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.83s)1042=== CONT TestObjectStatsUpdatedOncePerCommit10432026/10/25 19:18:05 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=010442026/10/25 19:18:05 INFO Vacuumed table table=pending_closures1045--- PASS: TestGCSweepSkipsPendingObjects (0.83s)1046=== CONT TestSkippedUploadsHandler10472026/10/25 19:18:05 INFO Vacuumed table table=pending_objects10482026/10/25 19:18:05 INFO Vacuumed table table=multipart_uploads10492026/10/25 19:18:05 INFO Vacuumed table table=closures10502026/10/25 19:18:05 INFO Vacuumed table table=objects1051--- PASS: TestGCBugBareHashReferences (0.84s)10522026/10/25 19:18:05 INFO Client skipped oversized paths paths=3 nar_bytes=500000000010532026/10/25 19:18:05 INFO Aborted multipart uploads count=0 kept=01054=== CONT TestClientIntegration10552026/10/25 19:18:05 WARN Force mode enabled - objects will be deleted immediately without grace period10562026/10/25 19:18: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=010572026/10/25 19:18:05 INFO Vacuumed table table=pending_closures10582026/10/25 19:18:05 INFO Received create pin request method=POST path=/api/pins/app10592026/10/25 19:18:05 INFO Vacuumed table table=pending_objects10602026/10/25 19:18:05 INFO Vacuumed table table=multipart_uploads10612026/10/25 19:18:05 INFO Vacuumed table table=closures10622026/10/25 19:18:05 INFO Vacuumed table table=objects10632026/10/25 19:18:05 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo10642026/10/25 19:18:05 INFO Received delete pin request method=DELETE path=/api/pins/app10652026/10/25 19:18:05 INFO lead: acquired remote=192.0.2.1:123410662026/10/25 19:18:05 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket27/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"1067--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.88s)1068=== CONT TestOrphanedObjectsGC10692026/10/25 19:18:05 INFO Received delete pin request method=DELETE path=/api/pins/app1070=== CONT TestClientErrorHandling1071=== RUN TestClientErrorHandling/InvalidStorePath1072--- PASS: TestPushDedupSurvivesConcurrentGC (0.89s)1073=== PAUSE TestClientErrorHandling/InvalidStorePath1074=== RUN TestClientErrorHandling/InvalidAuthToken1075=== PAUSE TestClientErrorHandling/InvalidAuthToken1076=== RUN TestClientErrorHandling/ServerNotAvailable1077=== PAUSE TestClientErrorHandling/ServerNotAvailable1078=== CONT TestIsValidUploadKey1079=== RUN TestIsValidUploadKey/narinfo1080=== PAUSE TestIsValidUploadKey/narinfo1081=== RUN TestIsValidUploadKey/nar_zst1082=== PAUSE TestIsValidUploadKey/nar_zst1083=== RUN TestIsValidUploadKey/nar_xz1084=== PAUSE TestIsValidUploadKey/nar_xz1085=== RUN TestIsValidUploadKey/nar_plain1086=== PAUSE TestIsValidUploadKey/nar_plain1087=== RUN TestIsValidUploadKey/listing1088=== PAUSE TestIsValidUploadKey/listing1089=== RUN TestIsValidUploadKey/build_log1090=== PAUSE TestIsValidUploadKey/build_log1091=== RUN TestIsValidUploadKey/build_log_home-manager_file1092=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1093=== RUN TestIsValidUploadKey/build_log_plus_in_name1094=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1095=== RUN TestIsValidUploadKey/build_log_question_mark1096=== PAUSE TestIsValidUploadKey/build_log_question_mark1097=== RUN TestIsValidUploadKey/build_log_equals1098=== PAUSE TestIsValidUploadKey/build_log_equals1099=== RUN TestIsValidUploadKey/realisation1100=== PAUSE TestIsValidUploadKey/realisation1101=== RUN TestIsValidUploadKey/realisation_plus_in_output1102=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1103=== RUN TestIsValidUploadKey/nix-cache-info1104=== PAUSE TestIsValidUploadKey/nix-cache-info1105=== RUN TestIsValidUploadKey/index.html1106=== PAUSE TestIsValidUploadKey/index.html1107=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1108=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1109=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1110=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1111=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1112=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1113=== RUN TestIsValidUploadKey/traversal1114=== PAUSE TestIsValidUploadKey/traversal1115=== RUN TestIsValidUploadKey/traversal_nar1116=== PAUSE TestIsValidUploadKey/traversal_nar1117=== RUN TestIsValidUploadKey/absolute1118=== PAUSE TestIsValidUploadKey/absolute1119=== RUN TestIsValidUploadKey/empty_key11202026/10/25 19:18:05 INFO Deleted pin name=app1121=== PAUSE TestIsValidUploadKey/empty_key1122=== RUN TestIsValidUploadKey/unknown_type11232026/10/25 19:18:05 INFO Received uploads request method=POST path=/api/pending_closures1124=== PAUSE TestIsValidUploadKey/unknown_type1125=== CONT TestCacheConfigHandler1126=== RUN TestCacheConfigHandler/full_config,_no_issuer1127=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1128=== RUN TestCacheConfigHandler/no_cache_url_configured1129=== PAUSE TestCacheConfigHandler/no_cache_url_configured1130=== RUN TestCacheConfigHandler/no_signing_keys1131=== PAUSE TestCacheConfigHandler/no_signing_keys1132=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1133=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1134=== CONT TestPendingClosureFailureTracksEveryUpload1135=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1136=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1137=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1138=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1139=== CONT TestService_AuthMiddleware1140--- PASS: TestSkippedUploadsHandler (0.08s)1141=== CONT TestPush_SignsNarinfosOfItsPendingObjects11422026/10/25 19:18:05 INFO lead: acquired remote=192.0.2.1:12341143--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.93s)1144=== CONT TestPresignedUploadRegisteredBeforeCommit1145--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.56s)1146=== CONT TestPush_RepeatedRootCommitsOnce11472026/10/25 19:18:05 INFO lead: acquired remote=192.0.2.1:123411482026/10/25 19:18:05 INFO lead: released remote=192.0.2.1:12341149--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.45s)1150=== CONT TestRedundantMultipartUpload11512026/10/25 19:18:05 WARN Rate limiter enabled after throttle name=s3-test rate=511522026/10/25 19:18:05 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."11532026/10/25 19:18:05 INFO Received create pin request method=POST path=/api/pins/deploy11542026/10/25 19:18:05 INFO Received create pin request method=POST path=/api/pins/deploy11552026/10/25 19:18:05 INFO Received create pin request method=POST path=/api/pins/deploy11562026/10/25 19:18:05 INFO Received create pin request method=POST path=/api/pins/deploy11572026/10/25 19:18:05 INFO Received create pin request method=POST path=/api/pins/deploy11582026/10/25 19:18:05 INFO Received create pin request method=POST path=/api/pins/deploy11592026/10/25 19:18:05 INFO Received create pin request method=POST path=/api/pins/deploy11602026/10/25 19:18:05 INFO Received create pin request method=POST path=/api/pins/deploy11612026/10/25 19:18:05 WARN Rate limiter backed off name=s3-test rate=511622026/10/25 19:18:05 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."11632026/10/25 19:18:05 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo1164=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1165--- PASS: TestReadProxy404 (1.03s)11662026/10/25 19:18:05 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo11672026/10/25 19:18:05 INFO Received create pin request method=POST path=/api/pins/deploy1168--- PASS: TestConcurrentPinUpdatesAgree (1.05s)1169=== CONT TestPush_RootsAreLockedInByteOrder11702026/10/25 19:18:05 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11712026/10/25 19:18:05 WARN Refused reserved pin name=worker-x86_64-linux11722026/10/25 19:18:05 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11732026/10/25 19:18:05 INFO Received create pin request method=POST path=/api/pins/my-app11742026/10/25 19:18:05 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1175--- PASS: TestCreatePin_ReservedPins (0.48s)1176=== CONT TestServerTLSConfig1177=== RUN TestServerTLSConfig/no_client_CA1178=== PAUSE TestServerTLSConfig/no_client_CA1179=== RUN TestServerTLSConfig/missing_CA_file1180=== PAUSE TestServerTLSConfig/missing_CA_file1181=== RUN TestServerTLSConfig/not_a_PEM_file1182=== PAUSE TestServerTLSConfig/not_a_PEM_file1183=== CONT TestConnectSerialisesConcurrentMigrations1184--- PASS: TestReconnectLeavesObjectsUnlocked (0.36s)1185=== CONT TestGCTaskStore_CompletedAllowsNewTask1186=== CONT TestService_AuthMiddleware_OIDC1187--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1188--- PASS: TestReadProxyContentNegotiation (1.14s)1189=== CONT TestGCEndsOnShutdown1190=== RUN TestGCEndsOnShutdown/before_the_run1191=== PAUSE TestGCEndsOnShutdown/before_the_run1192=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1193=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1194=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1195=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1196=== CONT TestGCTaskStore_StartNew1197--- PASS: TestGCTaskStore_StartNew (0.00s)1198=== CONT TestGCTaskStore_GetEmpty11992026/10/25 19:18:05 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"1200=== CONT TestPushWaitsForSweepHoldingRow1201--- PASS: TestGCTaskStore_GetEmpty (0.00s)12022026-10-25 19:18:05.611 UTC [711] ERROR: duplicate key value violates unique constraint "pg_class_relname_nsp_index"12032026-10-25 19:18:05.611 UTC [711] DETAIL: Key (relname, relnamespace)=(goose_db_version_id_seq, 2200) already exists.12042026-10-25 19:18:05.611 UTC [711] STATEMENT: CREATE TABLE goose_db_version (1205 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1206 version_id bigint NOT NULL,1207 is_applied boolean NOT NULL,1208 tstamp timestamp NOT NULL DEFAULT now()1209 )1210=== CONT TestService_healthCheckHandler1211--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (1.17s)12122026/10/25 19:18:05 INFO Received uploads request method=POST path=/api/pending_closures1213=== NAME TestClientWithDependencies1214 client_integration_test.go:735: Built derivation: /build/TestClientWithDependencies2344114026/001/store/fzzxjdrq0cb9fr13f3zmjzcipll3zar3-test-script12152026/10/25 19:18:05 INFO Received uploads request method=POST path=/api/pending_closures1216--- PASS: TestObjectStatsUpdatedOncePerCommit (0.38s)1217=== CONT TestGCTaskStore_GetReturnsLatest1218--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1219=== CONT TestGracefulShutdownDrainsInflight12202026/10/25 19:18:05 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12212026/10/25 19:18:05 INFO Starting HTTP server address=127.0.0.1:3890312222026/10/25 19:18:05 INFO Shutdown signal received, draining in-flight requests timeout=10s12232026/10/25 19:18:05 INFO Uploading z845lsgx9h75qx9c6bkwn4pyakd88zkl-a (216B)12242026/10/25 19:18:05 INFO Uploading 8ddvb62yz0zrm289ijfjshivxxva7b0b-shared-dep (136B)12252026/10/25 19:18:05 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"12262026/10/25 19:18:05 WARN Failed to register uploaded object key=nar/159mr3hxbpbj04q9k5qh8lsb6cnkk1z2am5yx0k5wcyyqy5hy0s3.nar.zst error="server returned 404: 404 page not found\n"12272026/10/25 19:18:05 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1228=== NAME TestClientIntegration1229 client_integration_test.go:334: Created store path: /build/TestClientIntegration2455808795/002/store/5r49846c1p0jhayn5vw69j6zxj5m5b5c-test-file.txt12302026/10/25 19:18:05 WARN Failed to register uploaded object key=7inm6zdvqbfndg30kf7c55rqjny92kfm.ls error="server returned 404: 404 page not found\n"1231=== NAME TestClientWithDependencies1232 client_integration_test.go:737: Found 1 dependencies (including self)12332026/10/25 19:18:05 WARN Failed to register uploaded object key=8ddvb62yz0zrm289ijfjshivxxva7b0b.ls error="server returned 404: 404 page not found\n"12342026/10/25 19:18:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12352026/10/25 19:18:05 WARN Failed to register uploaded object key=z845lsgx9h75qx9c6bkwn4pyakd88zkl.ls error="server returned 404: 404 page not found\n"12362026/10/25 19:18:05 INFO Signed narinfos id=1 count=212372026/10/25 19:18:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12382026/10/25 19:18:05 INFO Signed narinfos id=2 count=212392026/10/25 19:18:05 INFO Uploading 4 narinfos1240--- PASS: TestService_AuthMiddleware (0.33s)1241=== CONT TestChildrenInheritRaisedFileLimit12422026/10/25 19:18:05 WARN Failed to register uploaded object key=8ddvb62yz0zrm289ijfjshivxxva7b0b.narinfo error="server returned 404: 404 page not found\n"1243=== CONT TestGCTaskStore_ConflictDifferentParams1244--- PASS: TestChildrenInheritRaisedFileLimit (0.00s)1245=== CONT TestService_ReadAuthMiddleware1246--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)12472026/10/25 19:18:05 INFO Received push request method=POST path=/api/pushes12482026/10/25 19:18:05 WARN Failed to register uploaded object key=7inm6zdvqbfndg30kf7c55rqjny92kfm.narinfo error="server returned 404: 404 page not found\n"12492026/10/25 19:18:05 WARN Failed to register uploaded object key=z845lsgx9h75qx9c6bkwn4pyakd88zkl.narinfo error="server returned 404: 404 page not found\n"12502026/10/25 19:18:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12512026/10/25 19:18:05 WARN Failed to register uploaded object key=8ddvb62yz0zrm289ijfjshivxxva7b0b.narinfo error="server returned 404: 404 page not found\n"12522026/10/25 19:18:05 INFO Completed upload id=1 objects=6 duration=8.552486ms12532026/10/25 19:18:05 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12542026/10/25 19:18:05 INFO Completed upload id=2 objects=6 duration=2.677279ms12552026/10/25 19:18:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12562026/10/25 19:18:05 INFO Received uploads request method=POST path=/api/pending_closures12572026/10/25 19:18:05 INFO Upload complete. (114ms)1258=== NAME TestClientFallsBackToClosures1259 client_pushes_test.go:112: Retrieved narinfo from S3:1260 StorePath: /build/TestClientFallsBackToClosures2173808572/001/store/8ddvb62yz0zrm289ijfjshivxxva7b0b-shared-dep1261 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1262 Compression: zstd1263 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821264 NarSize: 1361265 References: 1266 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n12672026/10/25 19:18:05 INFO Signed narinfos id=1 count=112682026/10/25 19:18:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12692026/10/25 19:18:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12702026/10/25 19:18:05 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"12712026/10/25 19:18:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12722026/10/25 19:18:05 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"12732026/10/25 19:18:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12742026/10/25 19:18:05 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=112752026/10/25 19:18:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12762026/10/25 19:18:05 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1277 client_pushes_test.go:112: Retrieved narinfo from S3:1278 StorePath: /build/TestClientFallsBackToClosures2173808572/001/store/z845lsgx9h75qx9c6bkwn4pyakd88zkl-a1279 URL: nar/159mr3hxbpbj04q9k5qh8lsb6cnkk1z2am5yx0k5wcyyqy5hy0s3.nar.zst1280 Compression: zstd1281 NarHash: sha256:159mr3hxbpbj04q9k5qh8lsb6cnkk1z2am5yx0k5wcyyqy5hy0s31282 NarSize: 2161283 References: /build/TestClientFallsBackToClosures2173808572/001/store/8ddvb62yz0zrm289ijfjshivxxva7b0b-shared-dep1284 CA: text:sha256:0w7ppdyrak8r6il993fmlpvllnydh2zqd0p65a8ha9dpn0czbz8q1285 client_pushes_test.go:112: Retrieved narinfo from S3:1286 StorePath: /build/TestClientFallsBackToClosures2173808572/001/store/7inm6zdvqbfndg30kf7c55rqjny92kfm-b1287 URL: nar/159mr3hxbpbj04q9k5qh8lsb6cnkk1z2am5yx0k5wcyyqy5hy0s3.nar.zst1288 Compression: zstd1289 NarHash: sha256:159mr3hxbpbj04q9k5qh8lsb6cnkk1z2am5yx0k5wcyyqy5hy0s31290 NarSize: 2161291 References: /build/TestClientFallsBackToClosures2173808572/001/store/8ddvb62yz0zrm289ijfjshivxxva7b0b-shared-dep1292 CA: text:sha256:0w7ppdyrak8r6il993fmlpvllnydh2zqd0p65a8ha9dpn0czbz8q12932026/10/25 19:18:05 INFO Received push request method=POST path=/api/pushes12942026/10/25 19:18:05 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12952026/10/25 19:18:05 INFO Received uploads request method=POST path=/api/pending_closures1296=== CONT TestReadRedirectUsesPublicS3URL1297--- PASS: TestGracefulShutdownDrainsInflight (0.07s)12982026/10/25 19:18:05 INFO Received push request method=POST path=/api/pushes12992026/10/25 19:18:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33997/oidc1300--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.36s)1301=== CONT TestPush_OverlappingRootsStoreOneRowPerKey13022026/10/25 19:18:05 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13032026/10/25 19:18:05 INFO Uploading w04mxflmnr4mdh1d1jck3jqbjkjjklpa-a (216B)13042026/10/25 19:18:05 INFO Uploading nidm05rwgs9zx958y64p9px398f3m7gb-shared-dep (136B)13052026/10/25 19:18:05 INFO Received push request method=POST path=/api/pushes1306=== CONT TestReadProxyOutlastsServerWriteTimeout1307--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.36s)13082026/10/25 19:18:05 WARN Failed to register uploaded object key=1dqic9dkfzc6283irpqyn3kx2i8qlv6y.ls error="server returned 404: 404 page not found\n"13092026/10/25 19:18:05 WARN Failed to register uploaded object key=nar/1k2nw4ajn9hh74ha5k64bdh3hiz4zzi0rmcy8r7nhld0wfsjbhfm.nar.zst error="server returned 404: 404 page not found\n"13102026/10/25 19:18:05 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13112026/10/25 19:18:05 INFO Received push request method=POST path=/api/pushes13122026/10/25 19:18:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13132026/10/25 19:18:05 INFO Uploading 5r49846c1p0jhayn5vw69j6zxj5m5b5c-test-file.txt (152B)1314=== CONT TestReadProxyRangeRequest1315--- PASS: TestClientFallsBackToClosures (0.59s)13162026/10/25 19:18:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13172026/10/25 19:18:05 WARN Failed to register uploaded object key=w04mxflmnr4mdh1d1jck3jqbjkjjklpa.ls error="server returned 404: 404 page not found\n"13182026/10/25 19:18:05 WARN Failed to register uploaded object key=nidm05rwgs9zx958y64p9px398f3m7gb.ls error="server returned 404: 404 page not found\n"13192026/10/25 19:18:05 INFO Signed narinfos id=1 count=313202026/10/25 19:18:05 INFO Received uploads request method=POST path=/api/pending_closures13212026/10/25 19:18:05 INFO Uploading 3 narinfos13222026/10/25 19:18:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13232026/10/25 19:18:05 INFO Uploading fzzxjdrq0cb9fr13f3zmjzcipll3zar3-test-script (136B)13242026/10/25 19:18:05 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"13252026/10/25 19:18:05 INFO Received push request method=POST path=/api/pushes13262026/10/25 19:18:05 WARN Failed to register uploaded object key=nidm05rwgs9zx958y64p9px398f3m7gb.narinfo error="server returned 404: 404 page not found\n"13272026/10/25 19:18:05 WARN Failed to register uploaded object key=w04mxflmnr4mdh1d1jck3jqbjkjjklpa.narinfo error="server returned 404: 404 page not found\n"13282026/10/25 19:18:05 WARN Failed to register uploaded object key=5r49846c1p0jhayn5vw69j6zxj5m5b5c.ls error="server returned 404: 404 page not found\n"13292026/10/25 19:18:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13302026/10/25 19:18:05 INFO Signed narinfos id=1 count=113312026/10/25 19:18:05 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13322026/10/25 19:18:05 INFO Uploading 1 narinfos13332026/10/25 19:18:05 INFO Received complete push request method=POST path=/api/pushes/1/complete13342026/10/25 19:18:05 WARN Failed to register uploaded object key=1dqic9dkfzc6283irpqyn3kx2i8qlv6y.narinfo error="server returned 404: 404 page not found\n"13352026/10/25 19:18:05 WARN Failed to register uploaded object key=fzzxjdrq0cb9fr13f3zmjzcipll3zar3.ls error="server returned 404: 404 page not found\n"13362026/10/25 19:18:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13372026/10/25 19:18:05 WARN Failed to register uploaded object key=log/dgx19fwz0hfczgb7h6rv29z6bw2lgl3y-test-script.drv error="server returned 404: 404 page not found\n"13382026/10/25 19:18:05 INFO Received uploads request method=POST path=/api/pending_closures13392026/10/25 19:18:05 INFO Signed narinfos id=1 count=113402026/10/25 19:18:05 INFO Uploading 1 narinfos13412026/10/25 19:18:05 INFO Received complete push request method=POST path=/api/pushes/1/complete13422026/10/25 19:18:05 WARN Failed to register uploaded object key=5r49846c1p0jhayn5vw69j6zxj5m5b5c.narinfo error="server returned 404: 404 page not found\n"13432026/10/25 19:18:05 INFO Received push request method=POST path=/api/pushes13442026/10/25 19:18:05 INFO Completed push id=1 objects=8 duration=6.556987ms13452026/10/25 19:18:05 INFO Upload complete. (96ms)1346=== NAME TestClientPushesUseOnePush1347 client_pushes_test.go:97: Retrieved narinfo from S3:1348 StorePath: /build/TestClientPushesUseOnePush4033282944/001/store/nidm05rwgs9zx958y64p9px398f3m7gb-shared-dep1349 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1350 Compression: zstd1351 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821352 NarSize: 1361353 References: 1354 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13552026/10/25 19:18:05 INFO Completed push id=1 objects=3 duration=5.168137ms13562026/10/25 19:18:05 INFO Upload complete. (77ms)13572026/10/25 19:18:05 INFO Received complete push request method=POST path=/api/pushes/1/complete13582026/10/25 19:18:05 WARN Failed to register uploaded object key=fzzxjdrq0cb9fr13f3zmjzcipll3zar3.narinfo error="server returned 404: 404 page not found\n"1359 client_pushes_test.go:97: Retrieved narinfo from S3:1360 StorePath: /build/TestClientPushesUseOnePush4033282944/001/store/w04mxflmnr4mdh1d1jck3jqbjkjjklpa-a1361 URL: nar/1k2nw4ajn9hh74ha5k64bdh3hiz4zzi0rmcy8r7nhld0wfsjbhfm.nar.zst1362 Compression: zstd1363 NarHash: sha256:1k2nw4ajn9hh74ha5k64bdh3hiz4zzi0rmcy8r7nhld0wfsjbhfm1364 NarSize: 2161365 References: /build/TestClientPushesUseOnePush4033282944/001/store/nidm05rwgs9zx958y64p9px398f3m7gb-shared-dep1366 CA: text:sha256:1imvfgwdq39s94p22354yr7ii74g545yxj4z2sw2nnyzzxiryv521367 client_pushes_test.go:97: Retrieved narinfo from S3:1368 StorePath: /build/TestClientPushesUseOnePush4033282944/001/store/1dqic9dkfzc6283irpqyn3kx2i8qlv6y-b1369 URL: nar/1k2nw4ajn9hh74ha5k64bdh3hiz4zzi0rmcy8r7nhld0wfsjbhfm.nar.zst1370 Compression: zstd1371 NarHash: sha256:1k2nw4ajn9hh74ha5k64bdh3hiz4zzi0rmcy8r7nhld0wfsjbhfm1372 NarSize: 2161373 References: /build/TestClientPushesUseOnePush4033282944/001/store/nidm05rwgs9zx958y64p9px398f3m7gb-shared-dep1374 CA: text:sha256:1imvfgwdq39s94p22354yr7ii74g545yxj4z2sw2nnyzzxiryv5213752026/10/25 19:18:05 INFO Completed push id=1 objects=4 duration=16.009862ms13762026/10/25 19:18:05 INFO Upload complete. (93ms)13772026/10/25 19:18:05 INFO Received uploads request method=POST path=/api/pending_closures1378--- PASS: TestClientPushesUseOnePush (0.59s)1379=== CONT TestReadProxyConditionalGet13802026/10/25 19:18:05 INFO Aborted multipart uploads count=0 kept=013812026/10/25 19:18:05 WARN Force mode enabled - objects will be deleted immediately without grace period13822026/10/25 19:18:05 INFO All 1 paths already cached1383=== NAME TestClientIntegration1384 client_integration_test.go:360: Retrieved narinfo from S3:1385 StorePath: /build/TestClientIntegration2455808795/002/store/5r49846c1p0jhayn5vw69j6zxj5m5b5c-test-file.txt1386 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst13872026/10/25 19:18: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=01388 Compression: zstd1389 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11390 NarSize: 1521391 References: 1392 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11393--- PASS: TestService_healthCheckHandler (0.19s)1394=== CONT TestReadRedirectKeepsNarinfoProxied1395=== NAME TestClientIntegration1396 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)1397 client_integration_test.go:361: Decompressed .ls content (64 bytes):1398 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}13992026/10/25 19:18:05 INFO Vacuumed table table=pending_closures14002026/10/25 19:18:05 INFO Vacuumed table table=pending_objects14012026/10/25 19:18:05 INFO Vacuumed table table=multipart_uploads14022026/10/25 19:18:05 INFO Vacuumed table table=closures14032026/10/25 19:18:05 INFO Vacuumed table table=objects1404=== NAME TestClientWithDependencies1405 client_integration_test.go:753: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2344114026/001/store) requires matching store prefix1406--- PASS: TestClientWithDependencies (0.61s)1407=== CONT TestGenerateLandingPage1408--- PASS: TestGenerateLandingPage (0.03s)1409=== CONT TestCacheStatsHandler1410--- PASS: TestService_ReadAuthMiddleware (0.21s)1411=== CONT TestCompletedNarNotReofferedAcrossClosures14122026/10/25 19:18:05 INFO Received push request method=POST path=/api/pushes14132026/10/25 19:18:05 INFO Object in database but missing from S3 key=5r49846c1p0jhayn5vw69j6zxj5m5b5c.ls14142026/10/25 19:18:05 WARN Found objects in DB but missing from S3, will re-upload count=114152026/10/25 19:18:05 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14162026/10/25 19:18:05 INFO Received complete push request method=POST path=/api/pushes/2/complete14172026/10/25 19:18:05 WARN Failed to register uploaded object key=5r49846c1p0jhayn5vw69j6zxj5m5b5c.ls error="server returned 404: 404 page not found\n"14182026/10/25 19:18:05 INFO Received push request method=POST path=/api/pushes14192026/10/25 19:18:05 INFO Completed push id=2 objects=3 duration=16.346591ms14202026/10/25 19:18:05 INFO Upload complete. (73ms)1421=== NAME TestClientIntegration1422 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)1423 client_integration_test.go:389: Decompressed .ls content (49 bytes):1424 {"version":1,"root":{"type":"regular","size":39}}1425=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1426=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1427=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1428=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1429=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1430=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1431=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1432=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1433=== CONT TestPinProtectsFromGC1434--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.28s)1435=== CONT TestCompleteMultipartUnregistered14362026/10/25 19:18:06 INFO Received push request method=POST path=/api/pushes14372026/10/25 19:18:06 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14382026/10/25 19:18:06 INFO Received complete push request method=POST path=/api/pushes/3/complete14392026/10/25 19:18:06 WARN Failed to register uploaded object key=5r49846c1p0jhayn5vw69j6zxj5m5b5c.ls error="server returned 404: 404 page not found\n"14402026/10/25 19:18:06 INFO Completed push id=3 objects=3 duration=2.665259ms14412026/10/25 19:18:06 INFO Upload complete. (54ms)1442=== NAME TestClientIntegration1443 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)1444 client_integration_test.go:405: Decompressed .ls content (49 bytes):1445 {"version":1,"root":{"type":"regular","size":39}}1446=== NAME TestOrphanedObjectsGC1447 orphaned_objects_gc_test.go:287: GC Test Summary:1448 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1449 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1450 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1451 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1452 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects14532026/10/25 19:18:06 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1454--- PASS: TestOrphanedObjectsGC (0.83s)1455=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1456--- PASS: TestReadProxyNarinfo (1.72s)1457=== CONT TestService_verifyS3Integrity1458--- PASS: TestReadProxyRangeRequest (0.43s)1459=== CONT TestService_cleanupPendingClosuresHandler14602026/10/25 19:18:06 INFO Received uploads request method=POST path=/api/pending_closures14612026/10/25 19:18:06 INFO Received push request method=POST path=/api/pushes14622026/10/25 19:18:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14632026/10/25 19:18:06 INFO Uploading p6dvvmwyxaz7qv2j47pylp34sw7k69w9-lost-commit.txt (152B)1464--- PASS: TestCacheStatsHandler (0.34s)1465=== CONT TestClientSharedPathCommittedMidPush1466--- PASS: TestReadRedirectUsesPublicS3URL (0.52s)1467=== CONT TestService_createPendingClosureHandler14682026/10/25 19:18:06 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"14692026/10/25 19:18:06 INFO Received create pin request method=POST path=/api/pins/deploy14702026/10/25 19:18:06 WARN Failed to register uploaded object key=p6dvvmwyxaz7qv2j47pylp34sw7k69w9.ls error="server returned 404: 404 page not found\n"14712026/10/25 19:18:06 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign14722026/10/25 19:18:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14732026/10/25 19:18:06 INFO Signed narinfos id=4 count=114742026/10/25 19:18:06 INFO Uploading 1 narinfos14752026/10/25 19:18:06 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst14762026/10/25 19:18:06 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo14772026/10/25 19:18:06 WARN Failed to register uploaded object key=p6dvvmwyxaz7qv2j47pylp34sw7k69w9.narinfo error="server returned 404: 404 page not found\n"14782026/10/25 19:18:06 INFO Received complete push request method=POST path=/api/pushes/4/complete1479=== CONT TestUploadHandlersRejectOversizedBody1480--- PASS: TestCompleteMultipartUnregistered (0.26s)14812026/10/25 19:18:06 INFO Completed push id=4 objects=3 duration=18.579881ms14822026/10/25 19:18:06 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:33901/api/pushes/4/complete\": EOF" url=http://127.0.0.1:33901/api/pushes/4/complete1483--- PASS: TestCreatePinRejectsBadInput (1.23s)1484=== CONT TestClientMultipleUploads1485--- PASS: TestReadProxyConditionalGet (0.50s)1486=== CONT TestUploadHandlersRejectInvalidKeys1487=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1488=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1489=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1490=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1491=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1492=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1493=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1494=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1495=== CONT TestPendingClosureWriteTimeout1496=== RUN TestPendingClosureWriteTimeout/empty1497=== PAUSE TestPendingClosureWriteTimeout/empty1498=== RUN TestPendingClosureWriteTimeout/400_objects1499=== PAUSE TestPendingClosureWriteTimeout/400_objects1500=== RUN TestPendingClosureWriteTimeout/670k_objects1501=== PAUSE TestPendingClosureWriteTimeout/670k_objects1502=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1503=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1504=== CONT TestProxyWriteTimeout1505=== RUN TestProxyWriteTimeout/narinfo1506=== PAUSE TestProxyWriteTimeout/narinfo1507=== RUN TestProxyWriteTimeout/1_GiB_nar1508=== PAUSE TestProxyWriteTimeout/1_GiB_nar1509=== RUN TestProxyWriteTimeout/10_GiB_nar1510=== PAUSE TestProxyWriteTimeout/10_GiB_nar1511=== RUN TestProxyWriteTimeout/unknown_size1512=== PAUSE TestProxyWriteTimeout/unknown_size1513=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1514=== NAME TestPinProtectsFromGC1515 client_integration_test.go:867: Pinned store path: /build/TestPinProtectsFromGC1401026748/001/store/gws10id2bnlwwd9chaa4548kq72qjz4g-pinned-file.txt1516 client_integration_test.go:868: Unpinned store path: /build/TestPinProtectsFromGC1401026748/001/store/dgpm7ipr6b4sd6nl8sy7ff1h3bfjckxi-unpinned-file.txt15172026/10/25 19:18:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1518--- PASS: TestPushWaitsForSweepHoldingRow (0.74s)1519=== CONT TestObjectStatsTrigger15202026/10/25 19:18:06 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLjVlMGQ5NDgwLWI1MWYtNGU1Zi04M2RkLTViYWU1YzhmMmZhNHgxNzkyOTU1ODg1NzI4Njg3Mzgy parts=1015212026/10/25 19:18:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15222026/10/25 19:18:06 INFO Received complete push request method=POST path=/api/pushes/4/complete15232026/10/25 19:18:06 INFO Received cleanup request method=DELETE path=/api/pending_closures15242026-10-25 19:18:06.386 UTC [568] ERROR: Push does not exist: id=415252026-10-25 19:18:06.386 UTC [568] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE15262026-10-25 19:18:06.386 UTC [568] STATEMENT: -- name: CommitPush :one1527 SELECT commit_push($1::bigint)::bigint1528 15292026/10/25 19:18:06 WARN Push not found id=415302026/10/25 19:18:06 INFO Aborted multipart uploads count=0 kept=015312026/10/25 19:18:06 INFO Received push request method=POST path=/api/pushes15322026/10/25 19:18:06 INFO Received uploads request method=POST path=/api/pending_closures15332026/10/25 19:18:06 INFO Upload complete. (206ms)1534=== NAME TestClientIntegration1535 client_integration_test.go:435: Retrieved narinfo from S3:1536 StorePath: /build/TestClientIntegration2455808795/002/store/p6dvvmwyxaz7qv2j47pylp34sw7k69w9-lost-commit.txt1537 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1538 Compression: zstd1539 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1540 NarSize: 1521541 References: 1542 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl15432026/10/25 19:18:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1544 client_integration_test.go:438: Testing garbage collection...15452026/10/25 19:18:06 INFO Uploading gws10id2bnlwwd9chaa4548kq72qjz4g-pinned-file.txt (128B)15462026/10/25 19:18:06 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLmFmNDA2NzM0LWJkZjYtNDlkMS1hYjQ5LWI5NTkyN2QxZmRlOHgxNzkyOTU1ODg1NzUyNjUyNjcw parts=1215472026/10/25 19:18:06 INFO Received uploads request method=POST path=/api/pending_closures1548--- PASS: TestReadRedirectKeepsNarinfoProxied (0.59s)1549=== CONT TestParseSize1550--- PASS: TestParseSize (0.00s)1551=== CONT TestService_Rustfstest15522026/10/25 19:18:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15532026/10/25 19:18:06 INFO Received cleanup request method=DELETE path=/api/pending_closures15542026/10/25 19:18:06 INFO Aborted multipart uploads count=1 kept=015552026/10/25 19:18:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15562026/10/25 19:18:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15572026-10-25 19:18:06.410 UTC [1182] ERROR: Closure does not exist: id=115582026-10-25 19:18:06.410 UTC [1182] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE15592026-10-25 19:18:06.410 UTC [1182] STATEMENT: -- name: CommitPendingClosure :one1560 SELECT commit_pending_closure($1::bigint)::bigint1561 15622026/10/25 19:18:06 INFO Received uploads request method=POST path=/api/pending_closures15632026/10/25 19:18:06 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15642026/10/25 19:18:06 INFO Received uploads request method=POST path=/api/pending_closures15652026/10/25 19:18:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15662026/10/25 19:18:06 WARN Failed to register uploaded object key=gws10id2bnlwwd9chaa4548kq72qjz4g.ls error="server returned 404: 404 page not found\n"15672026/10/25 19:18:06 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLjVhYzRmYzQ1LTdlN2QtNDg4NC1iMzY5LWM2MGVjZDVjMTE2MXgxNzkyOTU1ODg1NzczODQzMDQw parts=1015682026/10/25 19:18:06 INFO Signed narinfos id=1 count=115692026/10/25 19:18:06 INFO Uploading 1 narinfos1570=== CONT TestPendingClosureFailureAbortsItsUploads1571--- PASS: TestService_cleanupPendingClosuresHandler (0.25s)15722026/10/25 19:18:06 INFO lead: released remote=192.0.2.1:123415732026/10/25 19:18:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures15742026/10/25 19:18:06 INFO Garbage collection started15752026/10/25 19:18:06 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLjM4OGRmZTViLTk4MTAtNDgyOS1iMDIyLThjOTdiZmNhYjk5MngxNzkyOTU1ODg1NzgzMDg0Njk1 parts=1015762026/10/25 19:18:06 INFO Aborted multipart uploads count=0 kept=015772026/10/25 19:18:06 INFO Received complete push request method=POST path=/api/pushes/1/complete15782026/10/25 19:18:06 WARN Failed to register uploaded object key=gws10id2bnlwwd9chaa4548kq72qjz4g.narinfo error="server returned 404: 404 page not found\n"15792026/10/25 19:18:06 WARN Force mode enabled - objects will be deleted immediately without grace period1580--- PASS: TestLeadEndsOnShutdown (1.68s)1581=== CONT TestCompleteMultipartUpload_ErrorButObjectExists15822026/10/25 19:18:06 INFO Completed push id=1 objects=3 duration=6.158117ms15832026/10/25 19:18:06 INFO Upload complete. (102ms)15842026/10/25 19:18:06 INFO Received uploads request method=POST path=/api/pending_closures15852026/10/25 19:18:06 INFO Received uploads request method=POST path=/api/pending_closures15862026/10/25 19:18:06 INFO Received uploads request method=POST path=/api/pending_closures15872026/10/25 19:18:06 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=015882026/10/25 19:18:06 INFO Vacuumed table table=pending_closures15892026/10/25 19:18:06 INFO Received uploads request method=POST path=/api/pending_closures15902026/10/25 19:18:06 INFO Vacuumed table table=pending_objects15912026/10/25 19:18:06 INFO Vacuumed table table=multipart_uploads15922026/10/25 19:18:06 INFO Vacuumed table table=closures15932026/10/25 19:18:06 INFO Received push request method=POST path=/api/pushes15942026/10/25 19:18:06 INFO Vacuumed table table=objects15952026/10/25 19:18:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15962026/10/25 19:18:06 INFO Uploading dgpm7ipr6b4sd6nl8sy7ff1h3bfjckxi-unpinned-file.txt (128B)1597=== NAME TestClientMultipleUploads1598 client_integration_test.go:480: Created store path 0: /build/TestClientMultipleUploads2243550394/001/store/9jkyqibpbqvfc2cd3a0zvzlv1m970ff8-test-file-0.txt15992026/10/25 19:18:06 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16002026/10/25 19:18:06 WARN Failed to register uploaded object key=dgpm7ipr6b4sd6nl8sy7ff1h3bfjckxi.ls error="server returned 404: 404 page not found\n"16012026/10/25 19:18:06 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16022026/10/25 19:18:06 INFO Signed narinfos id=2 count=116032026/10/25 19:18:06 INFO Uploading 1 narinfos1604=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1605--- PASS: TestObjectStatsTrigger (0.23s)1606=== NAME TestClientMultipleUploads1607 client_integration_test.go:480: Created store path 1: /build/TestClientMultipleUploads2243550394/001/store/np68slb6z0w8bhpdq6k6qccpl284la6r-test-file-1.txt16082026/10/25 19:18:06 INFO Received complete push request method=POST path=/api/pushes/2/complete16092026/10/25 19:18:06 WARN Failed to register uploaded object key=dgpm7ipr6b4sd6nl8sy7ff1h3bfjckxi.narinfo error="server returned 404: 404 page not found\n"16102026/10/25 19:18:06 INFO Completed push id=2 objects=3 duration=2.298079ms16112026/10/25 19:18:06 INFO Upload complete. (88ms)16122026/10/25 19:18:06 INFO Received uploads request method=POST path=/api/pending_closures1613=== CONT TestPush_CompleteCommitsEveryRoot1614--- PASS: TestService_Rustfstest (0.21s)16152026/10/25 19:18:06 INFO lead: released remote=192.0.2.1:123416162026/10/25 19:18:06 INFO Received uploads request method=POST path=/api/pending_closures16172026/10/25 19:18:06 INFO Received push request method=POST path=/api/pushes16182026/10/25 19:18:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures16192026/10/25 19:18:06 INFO Garbage collection started1620=== NAME TestClientMultipleUploads1621 client_integration_test.go:480: Created store path 2: /build/TestClientMultipleUploads2243550394/001/store/266wk96hlw3h5j0hv18c810mh4r876zz-test-file-2.txt16222026/10/25 19:18:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16232026/10/25 19:18:06 INFO Aborted multipart uploads count=0 kept=016242026/10/25 19:18:06 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16252026/10/25 19:18:06 INFO Uploading 4q3gql8msz22d254wrb50bfwy85pzbz3-shared-dep (136B)16262026/10/25 19:18:06 INFO Uploading rgigv0075a66z86j6nfhsz6lpy8rck0z-top (224B)16272026/10/25 19:18:06 WARN Force mode enabled - objects will be deleted immediately without grace period1628=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT1629--- PASS: TestConnectSerialisesConcurrentMigrations (1.13s)1630--- PASS: TestPendingClosureFailureAbortsItsUploads (0.23s)1631=== CONT TestPendingCleanupUsesOneCutoff16322026/10/25 19:18:06 INFO lead: acquired remote=192.0.2.1:123416332026/10/25 19:18:06 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16342026/10/25 19:18:06 WARN Failed to register uploaded object key=nar/1q5wg0lm2r9zz0nwjd8vqvrq0vwsz5iwrdvgqz9jfxzvxgbf51nv.nar.zst error="server returned 404: 404 page not found\n"16352026/10/25 19:18:06 WARN Failed to register uploaded object key=4q3gql8msz22d254wrb50bfwy85pzbz3.ls error="server returned 404: 404 page not found\n"16362026/10/25 19:18:06 WARN Failed to register uploaded object key=rgigv0075a66z86j6nfhsz6lpy8rck0z.ls error="server returned 404: 404 page not found\n"16372026/10/25 19:18:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16382026/10/25 19:18:06 INFO Signed narinfos id=1 count=216392026/10/25 19:18:06 INFO Uploading 2 narinfos1640=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1641--- PASS: TestDeleteClosuresRacingPins (1.60s)16422026/10/25 19:18:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16432026/10/25 19:18:06 INFO Received complete push request method=POST path=/api/pushes/1/complete16442026/10/25 19:18:06 WARN Failed to register uploaded object key=rgigv0075a66z86j6nfhsz6lpy8rck0z.narinfo error="server returned 404: 404 page not found\n"16452026/10/25 19:18:06 WARN Failed to register uploaded object key=4q3gql8msz22d254wrb50bfwy85pzbz3.narinfo error="server returned 404: 404 page not found\n"16462026/10/25 19:18:06 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=016472026/10/25 19:18:06 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLjgzMDE0N2E5LTBlN2ItNDJjNS05ZGNlLTE4N2UyNTIzYzkzNHgxNzkyOTU1ODg2NjQ2NjQ2MzU116482026/10/25 19:18:06 INFO Vacuumed table table=pending_closures16492026/10/25 19:18:06 INFO Completed push id=1 objects=6 duration=9.168106ms16502026/10/25 19:18:06 INFO Upload complete. (147ms)1651=== NAME TestClientSharedPathCommittedMidPush1652 client_integration_test.go:816: Retrieved narinfo from S3:1653 StorePath: /build/TestClientSharedPathCommittedMidPush1749596760/001/store/4q3gql8msz22d254wrb50bfwy85pzbz3-shared-dep1654 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1655 Compression: zstd1656 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821657 NarSize: 1361658 References: 1659 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n16602026/10/25 19:18:06 INFO Vacuumed table table=pending_objects16612026/10/25 19:18:06 INFO Vacuumed table table=multipart_uploads16622026/10/25 19:18:06 INFO Vacuumed table table=closures1663 client_integration_test.go:816: Retrieved narinfo from S3:1664 StorePath: /build/TestClientSharedPathCommittedMidPush1749596760/001/store/rgigv0075a66z86j6nfhsz6lpy8rck0z-top1665 URL: nar/1q5wg0lm2r9zz0nwjd8vqvrq0vwsz5iwrdvgqz9jfxzvxgbf51nv.nar.zst1666 Compression: zstd1667 NarHash: sha256:1q5wg0lm2r9zz0nwjd8vqvrq0vwsz5iwrdvgqz9jfxzvxgbf51nv1668 NarSize: 2241669 References: /build/TestClientSharedPathCommittedMidPush1749596760/001/store/4q3gql8msz22d254wrb50bfwy85pzbz3-shared-dep1670 CA: text:sha256:0mmf2aa7plv07k59fx4rhc99nvbjx3dysiam4ja2qn5l5m5hpxvr16712026/10/25 19:18:06 INFO Vacuumed table table=objects16722026/10/25 19:18:06 INFO Received push request method=POST path=/api/pushes16732026/10/25 19:18:06 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16742026/10/25 19:18:06 INFO Uploading 9jkyqibpbqvfc2cd3a0zvzlv1m970ff8-test-file-0.txt (160B)16752026/10/25 19:18:06 INFO Uploading 266wk96hlw3h5j0hv18c810mh4r876zz-test-file-2.txt (160B)16762026/10/25 19:18:06 INFO Uploading np68slb6z0w8bhpdq6k6qccpl284la6r-test-file-1.txt (160B)1677--- PASS: TestClientSharedPathCommittedMidPush (0.51s)1678=== CONT TestPush_CompleteWaitsForCleanupOfThePush16792026/10/25 19:18:06 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16802026/10/25 19:18:06 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16812026/10/25 19:18:06 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16822026/10/25 19:18:06 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16832026/10/25 19:18:06 WARN mTLS auth: bound subjects configured but subject DN unavailable16842026/10/25 19:18:06 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"16852026/10/25 19:18:06 WARN Failed to register uploaded object key=9jkyqibpbqvfc2cd3a0zvzlv1m970ff8.ls error="server returned 404: 404 page not found\n"16862026/10/25 19:18:06 WARN Failed to register uploaded object key=np68slb6z0w8bhpdq6k6qccpl284la6r.ls error="server returned 404: 404 page not found\n"16872026/10/25 19:18:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16882026/10/25 19:18:06 WARN Failed to register uploaded object key=266wk96hlw3h5j0hv18c810mh4r876zz.ls error="server returned 404: 404 page not found\n"16892026/10/25 19:18:06 INFO Signed narinfos id=1 count=316902026/10/25 19:18:06 INFO Uploading 3 narinfos1691--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.20s)1692=== CONT TestPush_RejectsBadRequests16932026/10/25 19:18:06 INFO Received complete push request method=POST path=/api/pushes/1/complete16942026/10/25 19:18:06 WARN Failed to register uploaded object key=9jkyqibpbqvfc2cd3a0zvzlv1m970ff8.narinfo error="server returned 404: 404 page not found\n"16952026/10/25 19:18:06 WARN Failed to register uploaded object key=266wk96hlw3h5j0hv18c810mh4r876zz.narinfo error="server returned 404: 404 page not found\n"16962026/10/25 19:18:06 WARN Failed to register uploaded object key=np68slb6z0w8bhpdq6k6qccpl284la6r.narinfo error="server returned 404: 404 page not found\n"16972026/10/25 19:18:06 INFO Completed push id=1 objects=9 duration=13.145813ms16982026/10/25 19:18:06 INFO Upload complete. (113ms)1699=== NAME TestClientMultipleUploads1700 client_integration_test.go:491: Uploaded 3 paths in 145.714887ms17012026/10/25 19:18:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17022026/10/25 19:18:06 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLjU1MmNlZmE1LTRkYjMtNDQ0Zi04NzQzLTlhNTViMjA4NTI1MXgxNzkyOTU1ODg2MjE0MTA1MzIw parts=121703=== CONT TestService_RequireScope_OIDC1704--- PASS: TestClientMultipleUploads (0.52s)17052026/10/25 19:18:06 INFO Received uploads request method=POST path=/api/pending_closures17062026/10/25 19:18:06 INFO Received push request method=POST path=/api/pushes1707--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.94s)1708=== CONT TestClientCADerivations17092026/10/25 19:18:06 INFO Received uploads request method=POST path=/api/pending_closures17102026/10/25 19:18:06 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLjgzMDE0N2E5LTBlN2ItNDJjNS05ZGNlLTE4N2UyNTIzYzkzNHgxNzkyOTU1ODg2NjQ2NjQ2MzU1 error="Delete \"http://localhost:40715/bucket75/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLjgzMDE0N2E5LTBlN2ItNDJjNS05ZGNlLTE4N2UyNTIzYzkzNHgxNzkyOTU1ODg2NjQ2NjQ2MzU1\": injected: abort refused"17112026/10/25 19:18:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17122026/10/25 19:18:06 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLjgzMDE0N2E5LTBlN2ItNDJjNS05ZGNlLTE4N2UyNTIzYzkzNHgxNzkyOTU1ODg2NjQ2NjQ2MzU117132026/10/25 19:18:06 INFO Received uploads request method=POST path=/api/pending_closures17142026/10/25 19:18:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34517/oidc17152026/10/25 19:18:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17162026/10/25 19:18:06 INFO Received uploads request method=POST path=/api/pending_closures17172026/10/25 19:18:06 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLjgzMDE0N2E5LTBlN2ItNDJjNS05ZGNlLTE4N2UyNTIzYzkzNHgxNzkyOTU1ODg2NjQ2NjQ2MzU1 parts=117182026/10/25 19:18:06 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLmVhMmViZjY4LWMyZjEtNDc3Ny05ODZlLTIwNDA5YmU3YzliZHgxNzkyOTU1ODg1NzMwMzc4NTkx parts=1017192026/10/25 19:18:06 INFO Received complete push request method=POST path=/api/pushes/1/complete17202026/10/25 19:18:06 INFO Received cleanup request method=DELETE path=/api/pending_closures17212026/10/25 19:18:06 INFO Completed push id=1 objects=4 duration=6.775226ms17222026/10/25 19:18:06 INFO Received uploads request method=POST path=/api/pending_closures17232026/10/25 19:18:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1724=== CONT TestService_ReadScope_PublicByDefault1725--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.43s)1726=== CONT TestGCTaskStore_PhaseUpdates1727--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.23s)1728=== CONT TestMultipartCleanup1729--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)17302026/10/25 19:18:06 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLmNhMTEzMTQ2LTQyMDEtNDIxMy04ZDkxLWQ4MzZjMjNhYmQxYXgxNzkyOTU1ODg1NzgyODU1NTU1 parts=1017312026/10/25 19:18:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1732--- PASS: TestPush_RepeatedRootCommitsOnce (1.52s)1733=== CONT TestGCTaskStore_Fail1734--- PASS: TestGCTaskStore_Fail (0.00s)1735=== CONT TestService_NativeMTLS17362026/10/25 19:18:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17372026/10/25 19:18:06 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLjUxZmM5OWZkLTZhMzItNDVmNy04Y2Y2LWQxOTQ2YjQ1MzQ5ZngxNzkyOTU1ODg1NzczMTM2MTAw parts=101738--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.24s)17392026/10/25 19:18:06 INFO Received complete push request method=POST path=/api/pushes/1/complete1740=== CONT TestMetricsInventory17412026/10/25 19:18:06 INFO Completed push id=1 objects=4 duration=6.214787ms17422026/10/25 19:18:06 INFO Received push request method=POST path=/api/pushes17432026/10/25 19:18:06 INFO Received push request method=POST path=/api/pushes17442026/10/25 19:18:06 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLjYxMTE5ZGFjLWJmNjQtNGM1ZC1hODg5LTc1NTkyYjA2NmVhMXgxNzkyOTU1ODg2NDIwNDU0MDU4 parts=1017452026/10/25 19:18:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17462026/10/25 19:18:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1747--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.78s)1748=== CONT TestMetricsCommit1749=== RUN TestPush_RejectsBadRequests/no_roots17502026/10/25 19:18:06 INFO Completed upload id=1 objects=2 duration=18.61801ms1751=== PAUSE TestPush_RejectsBadRequests/no_roots1752=== RUN TestPush_RejectsBadRequests/no_objects1753=== PAUSE TestPush_RejectsBadRequests/no_objects1754=== RUN TestPush_RejectsBadRequests/bad_root1755=== PAUSE TestPush_RejectsBadRequests/bad_root1756=== RUN TestPush_RejectsBadRequests/root_not_in_objects1757=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1758=== CONT TestCreatePendingClosureRejectsOversizedNAR17592026/10/25 19:18:06 INFO Received uploads request method=POST path=/api/pending_closures1760--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1761=== CONT TestCommitRacingPendingCleanupKeepsObjects17622026/10/25 19:18:06 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLmIyNzM0ZWU5LTMxZGMtNGVlYy1hYTRiLTg5Njk1M2FjMjVhOXgxNzkyOTU1ODg2NDIzNTA3MzI2 error="Get \"http://127.0.0.1:1/bucket48/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"17632026/10/25 19:18:06 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLmNiODdkNDMxLWM0Y2QtNDBmOS1hMzg2LTQwZDU0ZGIzMzhlMXgxNzkyOTU1ODg2NDA2NTg5MjA0 parts=1217642026/10/25 19:18:06 INFO Received cleanup request method=DELETE path=/api/pending_closures17652026/10/25 19:18:06 INFO Aborted multipart uploads count=1 kept=017662026/10/25 19:18:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17672026/10/25 19:18:06 INFO Received uploads request method=POST path=/api/pending_closures17682026/10/25 19:18:06 INFO Received uploads request method=POST path=/api/pending_closures17692026/10/25 19:18:06 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLjI1NzBmNjA1LWZhNDEtNGQ3Ni1hNDBiLWY1ZmZiYjExYmQxN3gxNzkyOTU1ODg2NDY2NzQ2OTc0 parts=1017702026/10/25 19:18:06 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo17712026/10/25 19:18:06 WARN Found objects in DB but missing from S3, will re-upload count=11772--- PASS: TestRedundantMultipartUpload (1.57s)1773=== CONT TestCacheConfigHandlerMaxNarSize17742026/10/25 19:18:06 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1775--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)17762026/10/25 19:18:06 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete1777=== CONT TestSweepRechecksPendingAfterLocking17782026/10/25 19:18:06 INFO Completed upload id=3 objects=2 duration=2.002409ms17792026/10/25 19:18:06 INFO Completed upload id=1 objects=2 duration=3.873998ms17802026/10/25 19:18:06 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000017812026/10/25 19:18:06 INFO Received uploads request method=POST path=/api/pending_closures17822026/10/25 19:18:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures1783--- PASS: TestService_verifyS3Integrity (0.83s)1784=== CONT TestNARDeduplicationMetadataUploadBug17852026/10/25 19:18:07 INFO Aborted multipart uploads count=0 kept=017862026/10/25 19:18:07 INFO Aborted multipart uploads count=0 kept=017872026/10/25 19:18:07 WARN Force mode enabled - objects will be deleted immediately without grace period17882026/10/25 19:18:07 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=017892026/10/25 19:18:07 INFO Vacuumed table table=pending_closures17902026/10/25 19:18:07 INFO Vacuumed table table=pending_objects17912026/10/25 19:18:07 INFO Vacuumed table table=multipart_uploads17922026/10/25 19:18:07 INFO Vacuumed table table=closures1793=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1794=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure17952026/10/25 19:18:07 INFO Vacuumed table table=objects1796=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1797=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1798=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1799=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1800=== CONT TestGCTaskStore_DeduplicateSameParams1801=== CONT TestService_readinessHandler1802--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)18032026/10/25 19:18:07 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001804--- PASS: TestService_createPendingClosureHandler (0.82s)1805=== CONT TestRegisterCompletedObjectNeedsPendingRow18062026/10/25 19:18:07 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=01807=== RUN TestService_RequireScope_OIDC/builder_may_write1808=== PAUSE TestService_RequireScope_OIDC/builder_may_write1809=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1810=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1811=== RUN TestService_RequireScope_OIDC/ops_may_admin1812=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1813=== RUN TestService_RequireScope_OIDC/ops_may_not_write1814=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1815=== RUN TestService_RequireScope_OIDC/reader_may_not_write1816=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1817=== RUN TestService_RequireScope_OIDC/static_token_may_admin1818=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1819=== RUN TestService_RequireScope_OIDC/static_token_may_write1820=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1821=== RUN TestService_RequireScope_OIDC/reader_may_read1822=== PAUSE TestService_RequireScope_OIDC/reader_may_read1823=== RUN TestService_RequireScope_OIDC/writer_implies_read1824=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1825=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1826=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1827=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1828=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1829=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1830=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1831=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1832=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1833=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1834=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1835=== CONT TestReadRedirectNar18362026/10/25 19:18:07 INFO Vacuumed table table=pending_closures18372026/10/25 19:18:07 INFO Vacuumed table table=pending_objects18382026/10/25 19:18:07 INFO Vacuumed table table=multipart_uploads1839--- PASS: TestService_ReadScope_PublicByDefault (0.21s)1840=== CONT TestReadProxyDisabled18412026/10/25 19:18:07 INFO Vacuumed table table=closures18422026/10/25 19:18:07 INFO Vacuumed table table=objects18432026/10/25 19:18:07 INFO Received uploads request method=POST path=/api/pending_closures1844=== NAME TestClientCADerivations1845 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations257422244/001/store/lgylaxacpjdba136scj0dj2y0rlfdyyh-ca-test18462026/10/25 19:18:07 WARN mTLS auth: subject not in bound subjects subject="CN=reader"18472026/10/25 19:18:07 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1848--- PASS: TestService_NativeMTLS (0.23s)1849=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1850=== NAME TestClientCADerivations1851 client_ca_test.go:139: Found 1 dependencies (including self)18522026/10/25 19:18:07 INFO Received push request method=POST path=/api/pushes18532026/10/25 19:18:07 INFO Aborted multipart uploads count=0 kept=01854--- PASS: TestMetricsInventory (0.29s)1855=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18562026/10/25 19:18:07 WARN Force mode enabled - objects will be deleted immediately without grace period18572026/10/25 19:18:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18582026/10/25 19:18:07 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=018592026/10/25 19:18:07 INFO Vacuumed table table=pending_closures18602026/10/25 19:18:07 INFO Vacuumed table table=pending_objects18612026/10/25 19:18:07 INFO Vacuumed table table=multipart_uploads18622026/10/25 19:18:07 INFO Vacuumed table table=closures18632026/10/25 19:18:07 INFO Vacuumed table table=objects18642026/10/25 19:18:07 INFO Received cleanup request method=DELETE path=/api/pending_closures18652026/10/25 19:18:07 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket86/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""18662026/10/25 19:18:07 INFO Aborted multipart uploads count=0 kept=118672026/10/25 19:18:07 INFO Aborted multipart uploads count=0 kept=018682026/10/25 19:18:07 WARN Force mode enabled - objects will be deleted immediately without grace period18692026/10/25 19:18:07 INFO Received push request method=POST path=/api/pushes18702026/10/25 19:18:07 INFO Received cleanup request method=DELETE path=/api/pending_closures18712026/10/25 19:18:07 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLjhkMjQyM2Q1LWY5ZjktNGQ0MS04NjFlLWM3MzkwMGI0MTE0M3gxNzkyOTU1ODg2ODIwMDM3NDE4 parts=1018722026/10/25 19:18:07 INFO Aborted multipart uploads count=1 kept=018732026/10/25 19:18:07 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18742026/10/25 19:18:07 INFO Uploading lgylaxacpjdba136scj0dj2y0rlfdyyh-ca-test (144B)18752026/10/25 19:18:07 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=01876--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.29s)1877=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh18782026/10/25 19:18:07 INFO Vacuumed table table=pending_closures18792026/10/25 19:18:07 INFO Vacuumed table table=pending_objects18802026/10/25 19:18:07 INFO Vacuumed table table=multipart_uploads18812026/10/25 19:18:07 INFO Vacuumed table table=closures18822026/10/25 19:18:07 INFO Vacuumed table table=objects1883--- PASS: TestMultipartCleanup (0.37s)1884=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale18852026/10/25 19:18:07 WARN Failed to register uploaded object key=log/5kjrmjjgqgkjsxw5sw7fiqj12zr4x0n6-ca-test.drv error="server returned 404: 404 page not found\n"18862026/10/25 19:18:07 WARN readiness check failed error="closed pool"18872026/10/25 19:18:07 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18882026/10/25 19:18:07 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18892026/10/25 19:18:07 WARN Failed to register uploaded object key=lgylaxacpjdba136scj0dj2y0rlfdyyh.ls error="server returned 404: 404 page not found\n"18902026/10/25 19:18:07 INFO Signed narinfos id=1 count=118912026/10/25 19:18:07 INFO Uploading 1 narinfos1892=== CONT TestParseSingleRange/malformed_no_dash1893--- PASS: TestService_readinessHandler (0.23s)1894=== CONT TestParseSingleRange/malformed_end_before_start1895=== CONT TestParseSingleRange/start_far_past_EOF1896=== CONT TestParseSingleRange/suffix_exceeds_size1897=== CONT TestParseSingleRange/multi-range_ignored1898=== CONT TestParseSingleRange/none1899=== CONT TestParseSingleRange/closed1900=== CONT TestParseSingleRange/single_byte1901=== CONT TestParseSingleRange/suffix1902=== CONT TestParseSingleRange/end_clamped_to_size1903=== CONT TestParseSingleRange/malformed_both_empty1904=== CONT TestParseSingleRange/start_past_EOF1905=== CONT TestParseSingleRange/open-ended1906=== CONT TestParseSingleRange/unknown_unit1907=== CONT TestIsValidCachePath/nar_zst1908--- PASS: TestParseSingleRange (0.01s)1909 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1910 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1911 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1912 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1913 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1914 --- PASS: TestParseSingleRange/none (0.00s)1915 --- PASS: TestParseSingleRange/closed (0.00s)1916 --- PASS: TestParseSingleRange/single_byte (0.00s)1917 --- PASS: TestParseSingleRange/suffix (0.00s)1918 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1919 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1920 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1921 --- PASS: TestParseSingleRange/open-ended (0.00s)1922 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1923=== CONT TestIsValidCachePath/short_hash1924=== CONT TestIsValidCachePath/nix-cache-info1925=== CONT TestIsValidCachePath/leading_slash19262026/10/25 19:18:07 INFO Received complete push request method=POST path=/api/pushes/1/complete1927=== CONT TestIsValidCachePath/empty1928=== CONT TestIsValidCachePath/invalid_char_u19292026/10/25 19:18:07 WARN Failed to register uploaded object key=lgylaxacpjdba136scj0dj2y0rlfdyyh.narinfo error="server returned 404: 404 page not found\n"1930=== CONT TestIsValidCachePath/invalid_char_e1931=== CONT TestIsValidCachePath/traversal_in_middle1932=== NAME TestNARDeduplicationMetadataUploadBug1933 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2668330409/001/store/xa6sspym4rxdlzkqvkwcc85a9zjld41v-file1.txt1934=== CONT TestIsValidCachePath/wrong_extension1935=== CONT TestIsValidCachePath/ls1936=== CONT TestIsValidCachePath/traversal_parent1937=== CONT TestIsValidCachePath/realisation1938=== CONT TestIsValidCachePath/nar_bz21939=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1940=== CONT TestIsValidCachePath/narinfo1941=== CONT TestIsValidCachePath/random_path1942=== CONT TestIsValidCachePath/index.html1943=== CONT TestIsValidCachePath/log1944=== CONT TestIsValidCachePath/nar_uncompressed1945=== CONT TestIsValidCachePath/nar_xz1946=== CONT TestResolveDBConnectionString/file_when_flag_empty1947--- PASS: TestIsValidCachePath (0.01s)1948 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1949 --- PASS: TestIsValidCachePath/short_hash (0.00s)1950 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1951 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1952 --- PASS: TestIsValidCachePath/empty (0.00s)1953 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1954 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1955 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1956 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1957 --- PASS: TestIsValidCachePath/ls (0.00s)1958 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1959 --- PASS: TestIsValidCachePath/realisation (0.00s)1960 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1961 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1962 --- PASS: TestIsValidCachePath/narinfo (0.00s)1963 --- PASS: TestIsValidCachePath/random_path (0.00s)1964 --- PASS: TestIsValidCachePath/index.html (0.00s)1965 --- PASS: TestIsValidCachePath/log (0.00s)1966 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1967 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1968=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1969=== CONT TestResolveDBConnectionString/nothing_configured1970=== CONT TestResolveDBConnectionString/missing_file_is_an_error1971=== CONT TestResolveDBConnectionString/flag_wins1972=== CONT TestClientErrorHandling/InvalidStorePath1973--- PASS: TestResolveDBConnectionString (0.00s)1974 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1975 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1976 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1977 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1978 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)19792026/10/25 19:18:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19802026/10/25 19:18:07 INFO Completed push id=1 objects=4 duration=10.665495ms19812026/10/25 19:18:07 INFO Upload complete. (120ms)1982=== NAME TestClientCADerivations1983 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations257422244/001/store/lgylaxacpjdba136scj0dj2y0rlfdyyh-ca-test1984 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1985 Compression: zstd1986 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1987 NarSize: 1441988 References: 1989 Deriver: /build/TestClientCADerivations257422244/001/store/5kjrmjjgqgkjsxw5sw7fiqj12zr4x0n6-ca-test.drv1990 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1991 client_ca_test.go:185: Checking for realisation files in S3...19922026/10/25 19:18:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19932026/10/25 19:18:07 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLjExYWY4MDE0LTZhZDItNGM4ZS05ZDQ4LWIwYjM3ZjgwOTZmN3gxNzkyOTU1ODg1NzgzMTQ1ODA1 parts=1019942026/10/25 19:18:07 INFO Received push request method=POST path=/api/pushes19952026/10/25 19:18:07 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19962026/10/25 19:18:07 INFO Uploading xa6sspym4rxdlzkqvkwcc85a9zjld41v-file1.txt (160B)19972026/10/25 19:18:07 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"19982026/10/25 19:18:07 WARN Failed to register uploaded object key=xa6sspym4rxdlzkqvkwcc85a9zjld41v.ls error="server returned 404: 404 page not found\n"19992026/10/25 19:18:07 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20002026/10/25 19:18:07 INFO Signed narinfos id=1 count=120012026/10/25 19:18:07 INFO Uploading 1 narinfos2002 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2003 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2004--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.32s)2005--- PASS: TestSweepRechecksPendingAfterLocking (0.39s)2006=== CONT TestClientErrorHandling/InvalidAuthToken2007=== CONT TestClientErrorHandling/ServerNotAvailable20082026/10/25 19:18:07 INFO Received complete push request method=POST path=/api/pushes/1/complete20092026/10/25 19:18:07 WARN Failed to register uploaded object key=xa6sspym4rxdlzkqvkwcc85a9zjld41v.narinfo error="server returned 404: 404 page not found\n"20102026/10/25 19:18:07 INFO Completed push id=1 objects=3 duration=4.267438ms20112026/10/25 19:18:07 INFO Upload complete. (84ms)20122026/10/25 19:18:07 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLjQ1MzNhYTc4LTM0ODMtNDljMS05NjNlLTI2NGM0Njk5YjRiM3gxNzkyOTU1ODg2OTI5NTY3MzM0 parts=102013=== NAME TestNARDeduplicationMetadataUploadBug2014 metadata_upload_test.go:54: Retrieved narinfo from S3:2015 StorePath: /build/TestNARDeduplicationMetadataUploadBug2668330409/001/store/xa6sspym4rxdlzkqvkwcc85a9zjld41v-file1.txt2016 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2017 Compression: zstd2018 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2019 NarSize: 1602020 References: 2021 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2022 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)2023 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):2024 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}2025--- PASS: TestReadProxyDisabled (0.31s)2026=== CONT TestIsValidUploadKey/narinfo2027=== CONT TestIsValidUploadKey/realisation2028=== CONT TestIsValidUploadKey/unknown_type2029=== CONT TestIsValidUploadKey/empty_key2030=== CONT TestIsValidUploadKey/absolute2031=== CONT TestIsValidUploadKey/build_log_equals2032=== CONT TestIsValidUploadKey/index.html2033=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2034=== CONT TestIsValidUploadKey/nix-cache-info2035=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2036=== CONT TestIsValidUploadKey/traversal2037=== CONT TestIsValidUploadKey/nar_zst2038=== CONT TestIsValidUploadKey/build_log2039=== CONT TestIsValidUploadKey/nar_plain2040=== CONT TestIsValidUploadKey/listing2041=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2042=== CONT TestIsValidUploadKey/realisation_plus_in_output2043=== CONT TestIsValidUploadKey/build_log_home-manager_file2044=== CONT TestIsValidUploadKey/build_log_question_mark2045=== CONT TestIsValidUploadKey/traversal_nar2046=== CONT TestIsValidUploadKey/nar_xz2047=== CONT TestIsValidUploadKey/build_log_plus_in_name2048--- PASS: TestIsValidUploadKey (0.01s)2049 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2050 --- PASS: TestIsValidUploadKey/realisation (0.00s)2051 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2052 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2053 --- PASS: TestIsValidUploadKey/absolute (0.00s)2054 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2055 --- PASS: TestIsValidUploadKey/index.html (0.00s)2056 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2057 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2058 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2059 --- PASS: TestIsValidUploadKey/traversal (0.00s)2060 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2061 --- PASS: TestIsValidUploadKey/build_log (0.00s)2062 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2063 --- PASS: TestIsValidUploadKey/listing (0.00s)2064 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2065 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2066 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2067 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2068 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2069 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2070 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2071=== CONT TestCacheConfigHandler/no_signing_keys2072=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2073=== CONT TestCacheConfigHandler/no_cache_url_configured2074=== CONT TestCacheConfigHandler/full_config,_no_issuer2075=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true2076--- PASS: TestCacheConfigHandler (0.00s)2077 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2078 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2079 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2080 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2081=== NAME TestNARDeduplicationMetadataUploadBug2082 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2668330409/001/store/frmq87v7nzsy90zncrkvys6l56gvyzs2-file2.txt2083--- PASS: TestReadRedirectNar (0.37s)2084=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false20852026/10/25 19:18:07 INFO Received uploads request method=POST path=/api/pending_closures2086=== NAME TestClientCADerivations2087 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2088 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2089 error: binary cache 's3://bucket83?endpoint=http://localhost:40715®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations257422244/001/store'2090 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 120912026/10/25 19:18:07 INFO Aborted multipart uploads count=0 kept=020922026/10/25 19:18:07 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20932026/10/25 19:18:07 WARN Force mode enabled - objects will be deleted immediately without grace period2094=== CONT TestServerTLSConfig/missing_CA_file2095--- PASS: TestClientCADerivations (0.65s)2096=== CONT TestServerTLSConfig/not_a_PEM_file2097=== CONT TestServerTLSConfig/no_client_CA2098--- PASS: TestServerTLSConfig (0.00s)2099 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2100 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2101 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2102=== CONT TestGCEndsOnShutdown/before_the_run21032026/10/25 19:18:07 INFO Received uploads request method=POST path=/api/pending_closures21042026/10/25 19:18:07 INFO Received push request method=POST path=/api/pushes21052026/10/25 19:18:07 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21062026/10/25 19:18:07 INFO Aborted multipart uploads count=0 kept=021072026/10/25 19:18:07 WARN Failed to register uploaded object key=frmq87v7nzsy90zncrkvys6l56gvyzs2.ls error="server returned 404: 404 page not found\n"21082026/10/25 19:18:07 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign21092026/10/25 19:18:07 INFO Signed narinfos id=2 count=121102026/10/25 19:18:07 WARN Force mode enabled - objects will be deleted immediately without grace period21112026/10/25 19:18:07 INFO Uploading 1 narinfos21122026/10/25 19:18:07 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=021132026/10/25 19:18:07 INFO Vacuumed table table=pending_closures21142026/10/25 19:18:07 INFO Vacuumed table table=pending_objects21152026/10/25 19:18:07 INFO Vacuumed table table=multipart_uploads21162026/10/25 19:18:07 INFO Vacuumed table table=closures21172026/10/25 19:18:07 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=021182026/10/25 19:18:07 INFO Vacuumed table table=pending_closures21192026/10/25 19:18:07 INFO Vacuumed table table=objects21202026/10/25 19:18:07 INFO Received complete push request method=POST path=/api/pushes/2/complete21212026/10/25 19:18:07 WARN Failed to register uploaded object key=frmq87v7nzsy90zncrkvys6l56gvyzs2.narinfo error="server returned 404: 404 page not found\n"21222026/10/25 19:18:07 INFO Vacuumed table table=pending_objects21232026/10/25 19:18:07 INFO Vacuumed table table=multipart_uploads21242026/10/25 19:18:07 INFO Vacuumed table table=closures21252026/10/25 19:18:07 INFO Completed push id=2 objects=3 duration=1.8301ms21262026/10/25 19:18:07 INFO Upload complete. (55ms)2127=== NAME TestNARDeduplicationMetadataUploadBug2128 metadata_upload_test.go:76: Retrieved narinfo from S3:2129 StorePath: /build/TestNARDeduplicationMetadataUploadBug2668330409/001/store/frmq87v7nzsy90zncrkvys6l56gvyzs2-file2.txt2130 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2131 Compression: zstd2132 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2133 NarSize: 1602134 References: 2135 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf21362026/10/25 19:18:07 INFO Vacuumed table table=objects21372026/10/25 19:18:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2138 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2139 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2140 {"version":1,"root":{"type":"regular","size":44}}21412026/10/25 19:18:07 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLjRmYWYyMWQzLWJjZjktNDQ4OS04Y2QyLWU1MmQxOGRhYjhiNHgxNzkyOTU1ODg2OTMxNTA5OTUz parts=102142=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete2143--- PASS: TestNARDeduplicationMetadataUploadBug (0.54s)2144=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark21452026/10/25 19:18:07 INFO Received complete push request method=POST path=/api/pushes/2/complete21462026/10/25 19:18:07 INFO Completed push id=2 objects=4 duration=2.591599ms2147=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2148--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2149 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.35s)2150 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.42s)2151=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected21522026/10/25 19:18:07 WARN Authentication failed token_preview=eyJhbGciOi...ukySsxbDxQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2153=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2154=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected21552026/10/25 19:18:07 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]2156=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info21572026/10/25 19:18:07 INFO Received uploads request method=POST path=/2158=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key21592026/10/25 19:18:07 INFO Received request for more parts method=POST path=/2160=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal21612026/10/25 19:18:07 INFO Received uploads request method=POST path=/2162=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key21632026/10/25 19:18:07 INFO Received complete multipart upload request method=POST path=/2164=== CONT TestPendingClosureWriteTimeout/670k_objects2165--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2166 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2167 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2168 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2169 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2170=== CONT TestPendingClosureWriteTimeout/400_objects2171=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline21722026/10/25 19:18:07 WARN Request failed, retrying attempt=2 backoff=208.786013ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2173--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.10s)2174=== CONT TestPendingClosureWriteTimeout/empty2175=== CONT TestProxyWriteTimeout/10_GiB_nar2176=== CONT TestProxyWriteTimeout/unknown_size2177=== CONT TestProxyWriteTimeout/1_GiB_nar2178=== CONT TestProxyWriteTimeout/narinfo2179=== CONT TestPush_RejectsBadRequests/bad_root2180--- PASS: TestProxyWriteTimeout (0.00s)2181 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2182 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2183 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2184 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)21852026/10/25 19:18:07 INFO Received push request method=POST path=/api/pushes2186=== CONT TestPush_RejectsBadRequests/root_not_in_objects21872026/10/25 19:18:07 INFO Received push request method=POST path=/api/pushes2188=== CONT TestPush_RejectsBadRequests/no_objects21892026/10/25 19:18:07 INFO Received push request method=POST path=/api/pushes2190=== CONT TestPush_RejectsBadRequests/no_roots21912026/10/25 19:18:07 INFO Received push request method=POST path=/api/pushes2192=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure21932026/10/25 19:18:07 INFO Received uploads request method=POST path=/2194=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts21952026/10/25 19:18:07 INFO Received request for more parts method=POST path=/2196--- PASS: TestService_AuthMiddleware_OIDC (0.45s)2197 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2198 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2199 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2200 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)22012026/10/25 19:18:07 INFO Received uploads request method=POST path=/api/pending_closures2202--- PASS: TestPush_RejectsBadRequests (0.21s)2203 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2204 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2205 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2206 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)22072026-10-25 19:18:07.602 UTC [178] LOG: checkpoints are occurring too frequently (9 seconds apart)22082026-10-25 19:18:07.602 UTC [178] HINT: Consider increasing the configuration parameter "max_wal_size".22092026-10-25 19:18:07.602 UTC [178] LOG: checkpoint starting: wal22102026/10/25 19:18:07 INFO Received uploads request method=POST path=/api/pending_closures22112026/10/25 19:18:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22122026/10/25 19:18:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22132026/10/25 19:18:07 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22142026/10/25 19:18:07 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLjU3Yzc1NTE3LTc4NDgtNGUzMC04YWNmLTJiNGYzMGE4YmQzOHgxNzkyOTU1ODg2ODE5OTcyMTQ4 parts=1022152026/10/25 19:18:07 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLmU0ZjY0OWMzLWFiM2MtNGRiYy1iOWE4LThmYTRiZjYxYjQxYXgxNzkyOTU1ODg3MTkzMjc3MDAy parts=1022162026/10/25 19:18:07 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2217=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart22182026/10/25 19:18:07 INFO Received complete multipart upload request method=POST path=/2219=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2220=== CONT TestService_RequireScope_OIDC/static_token_may_write2221=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read22222026/10/25 19:18:07 WARN Authentication failed token_preview=wrong token_length=5 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2223=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2224=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2225=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2226=== CONT TestService_RequireScope_OIDC/writer_implies_read2227=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2228=== CONT TestService_RequireScope_OIDC/reader_may_not_write2229=== CONT TestService_RequireScope_OIDC/static_token_may_admin2230=== CONT TestService_RequireScope_OIDC/reader_may_read2231=== CONT TestService_RequireScope_OIDC/ops_may_not_write2232=== CONT TestService_RequireScope_OIDC/ops_may_admin2233=== CONT TestService_RequireScope_OIDC/builder_may_write22342026-10-25 19:18:07.695 UTC [1782] ERROR: Push does not exist: id=122352026-10-25 19:18:07.695 UTC [1782] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE22362026-10-25 19:18:07.695 UTC [1782] STATEMENT: SELECT commit_push($1)22372026/10/25 19:18:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2238--- PASS: TestService_RequireScope_OIDC (0.28s)2239 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2240 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2241 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2242 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2243 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2244 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2245 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2246 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2247 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2248 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2249 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2250 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2251 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2252 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2253--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.98s)22542026/10/25 19:18:07 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLjVmZjJkNTc1LTkzMWEtNDZmZi04YmYwLTBjMjEwYzBmNGE0NXgxNzkyOTU1ODg1NzgyODI5MTc1 parts=1022552026/10/25 19:18:07 INFO Aborted multipart uploads count=0 kept=022562026/10/25 19:18:07 WARN Force mode enabled - objects will be deleted immediately without grace period22572026/10/25 19:18:07 INFO Received uploads request method=POST path=/api/pending_closures2258=== NAME TestOrphanedObjectsGCStressTest2259 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains22602026/10/25 19:18:07 INFO Aborted multipart uploads count=0 kept=022612026/10/25 19:18:07 WARN Force mode enabled - objects will be deleted immediately without grace period22622026/10/25 19:18:07 INFO lead: released remote=192.0.2.1:123422632026/10/25 19:18:07 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:40715/bucket108/?delete=\": context canceled"22642026/10/25 19:18:07 WARN Request failed, retrying attempt=3 backoff=405.512481ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2265 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion2266--- PASS: TestGCEndsOnShutdown (0.00s)2267 --- PASS: TestGCEndsOnShutdown/before_the_run (0.21s)2268 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.21s)2269 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.25s)2270--- PASS: TestLeadElectsOneAndHandsOver (2.98s)2271--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2272 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.78s)2273 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.78s)22742026/10/25 19:18:08 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLmJjMWVlZGFlLTMxNmItNGQwYi1hMzUwLWQzMjQ2YTc5ZmMxNHgxNzkyOTU1ODg3NTg5MTA2Mzg1 error="Access Denied"22752026/10/25 19:18:08 WARN keeping failed pending closure for cleanup to retry the abort id=122762026/10/25 19:18:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22772026/10/25 19:18:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22782026/10/25 19:18:08 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLjZjZTYwOWY0LTQ3ODQtNDUyNC1iMWM0LTAzNzQ4MTlmOTUzMngxNzkyOTU1ODg3MTkyMTcwMjgz parts=1022792026/10/25 19:18:08 INFO Received complete push request method=POST path=/api/pushes/1/complete22802026/10/25 19:18:08 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLmY5MzdiZDQwLTI2OTUtNGIwOC1iMTg1LTQ2YzhiM2ZiOTBmY3gxNzkyOTU1ODg2ODE5MDg3OTc5 parts=1022812026/10/25 19:18:08 INFO Completed push id=1 objects=4 duration=5.471977ms22822026/10/25 19:18:08 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22832026/10/25 19:18:08 INFO Completed upload id=2 objects=2 duration=1.466049ms2284--- PASS: TestPendingClosureFailureTracksEveryUpload (0.00s)2285 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (0.71s)2286 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (0.71s)22872026/10/25 19:18:08 INFO Received complete push request method=POST path=/api/pushes/1/complete22882026/10/25 19:18:08 INFO Completed push id=1 objects=6 duration=6.531127ms22892026/10/25 19:18:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22902026/10/25 19:18:08 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLjdiYjhjY2UwLTJhY2UtNGZkYi1iZTMyLWNmYTczYWY4ZDU5MXgxNzkyOTU1ODg1NzgzMDY5NjU1 parts=1022912026/10/25 19:18:08 WARN Request failed, retrying attempt=4 backoff=762.881203ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2292--- PASS: TestPush_CompleteCommitsEveryRoot (1.57s)2293--- PASS: TestMetricsCommit (1.26s)22942026/10/25 19:18:08 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02295=== NAME TestClientIntegration2296 client_integration_test.go:445: Objects in database after GC:2297 client_integration_test.go:445: Successfully deleted all objects with GC --force2298--- PASS: TestClientIntegration (3.17s)2299--- PASS: TestPendingClosureWriteTimeout (0.00s)2300 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2301 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2302 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2303 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.00s)23042026/10/25 19:18:08 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=023052026/10/25 19:18:08 INFO Received create pin request method=POST path=/api/pins/myapp23062026/10/25 19:18:08 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1401026748/001/store/gws10id2bnlwwd9chaa4548kq72qjz4g-pinned-file.txt narinfo_key=gws10id2bnlwwd9chaa4548kq72qjz4g.narinfo23072026/10/25 19:18:08 INFO Starting cleanup of old closures method=DELETE path=/api/closures23082026/10/25 19:18:08 INFO Garbage collection started23092026/10/25 19:18:08 INFO Aborted multipart uploads count=0 kept=023102026/10/25 19:18:08 WARN Force mode enabled - objects will be deleted immediately without grace period23112026/10/25 19:18:08 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=023122026/10/25 19:18:08 INFO Vacuumed table table=pending_closures23132026/10/25 19:18:08 INFO Vacuumed table table=pending_objects23142026/10/25 19:18:08 INFO Vacuumed table table=multipart_uploads23152026/10/25 19:18:08 INFO Vacuumed table table=closures23162026/10/25 19:18:08 INFO Vacuumed table table=objects23172026/10/25 19:18:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23182026/10/25 19:18:08 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=MmYzZmEzYTAtNTM1OC00MmE1LWIzZWQtYWYyMDg3NzVhNmIyLjYzMjY1MTI5LTc1MDctNGU0Yy05M2EzLTZhYWUyZjMyMDcxNngxNzkyOTU1ODg1NzgyMTgyODU2 parts=1023192026-10-25 19:18:08.751 UTC [955] ERROR: could not obtain lock on row in relation "closures"23202026-10-25 19:18:08.751 UTC [955] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23212026-10-25 19:18:08.751 UTC [955] ERROR: could not obtain lock on row in relation "closures"23222026-10-25 19:18:08.751 UTC [955] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23232026-10-25 19:18:08.752 UTC [955] ERROR: could not obtain lock on row in relation "closures"23242026-10-25 19:18:08.752 UTC [955] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23252026-10-25 19:18:08.753 UTC [955] ERROR: could not obtain lock on row in relation "closures"23262026-10-25 19:18:08.753 UTC [955] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23272026-10-25 19:18:08.753 UTC [955] ERROR: could not obtain lock on row in relation "closures"23282026-10-25 19:18:08.753 UTC [955] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT2329--- PASS: TestPush_RootsAreLockedInByteOrder (3.29s)23302026/10/25 19:18:08 WARN Request failed, retrying attempt=5 backoff=1.703977873s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2331=== NAME TestOrphanedObjectsGCStressTest2332 orphaned_objects_gc_test.go:503: Stress test completed successfully:2333 orphaned_objects_gc_test.go:504: - Active objects preserved: 202334 orphaned_objects_gc_test.go:505: - Objects deleted: 2102335 orphaned_objects_gc_test.go:506: - Total GC'd: 2102336--- PASS: TestOrphanedObjectsGCStressTest (3.87s)2337--- PASS: TestConnectWaitsForAPeerMigration (5.18s)2338--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.69s)2339=== NAME TestPinProtectsFromGC2340 client_integration_test.go:976: Pin successfully protected closure from garbage collection23412026/10/25 19:18:10 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2342--- PASS: TestPinProtectsFromGC (4.71s)23432026/10/25 19:18:10 WARN Request failed, retrying attempt=2 backoff=187.584547ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23442026/10/25 19:18:10 WARN Request failed, retrying attempt=3 backoff=391.53881ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23452026/10/25 19:18:11 WARN Rate limiter enabled after throttle name=s3-test rate=523462026/10/25 19:18:11 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2347=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2348 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102349 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002350--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.71s)23512026/10/25 19:18:11 WARN Request failed, retrying attempt=4 backoff=877.299048ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23522026/10/25 19:18:12 WARN Request failed, retrying attempt=5 backoff=1.711009368s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23532026/10/25 19:18:12 INFO Aborted multipart uploads count=1 kept=023542026/10/25 19:18:12 INFO Received cleanup request method=DELETE path=/api/pending_closures23552026/10/25 19:18:12 INFO Aborted multipart uploads count=1 kept=02356--- PASS: TestPendingCleanupUsesOneCutoff (6.26s)2357--- PASS: TestUploadHandlersRejectOversizedBody (0.78s)2358 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.47s)2359 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.47s)2360 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (6.12s)23612026/10/25 19:18:13 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"23622026/10/25 19:18:13 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23632026/10/25 19:18:14 WARN Request failed, retrying attempt=2 backoff=186.186964ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23642026/10/25 19:18:14 WARN Request failed, retrying attempt=3 backoff=409.725236ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23652026/10/25 19:18:14 WARN Request failed, retrying attempt=4 backoff=840.556683ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23662026/10/25 19:18:15 WARN Request failed, retrying attempt=5 backoff=1.756653966s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23672026/10/25 19:18:17 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23682026/10/25 19:18:17 WARN Request failed, retrying attempt=2 backoff=211.179881ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23692026/10/25 19:18:17 WARN Request failed, retrying attempt=3 backoff=388.82487ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23702026/10/25 19:18:17 WARN Request failed, retrying attempt=4 backoff=817.922718ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23712026/10/25 19:18:18 WARN Request failed, retrying attempt=5 backoff=1.604950539s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2372--- PASS: TestClientErrorHandling (0.00s)2373 --- PASS: TestClientErrorHandling/InvalidStorePath (0.29s)2374 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.29s)2375 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.04s)2376PASS2377{"timestamp":"2026-10-25T19:18:20.419930362Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:50914","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(143)"}23782026-10-25 19:18:20.749 UTC [173] LOG: received smart shutdown request23792026-10-25 19:18:20.753 UTC [173] LOG: background worker "logical replication launcher" (PID 183) exited with exit code 123802026-10-25 19:18:22.388 UTC [178] LOG: checkpoint complete: wrote 9406 buffers (57.4%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=13.344 s, sync=1.370 s, total=14.786 s; sync files=37078, longest=0.002 s, average=0.001 s; distance=533612 kB, estimate=533612 kB; lsn=0/229D3930, redo lsn=0/2208107023812026-10-25 19:18:22.390 UTC [178] LOG: shutting down23822026-10-25 19:18:22.391 UTC [178] LOG: checkpoint starting: shutdown immediate23832026-10-25 19:18:22.527 UTC [178] LOG: checkpoint complete: wrote 953 buffers (5.8%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.020 s, sync=0.113 s, total=0.137 s; sync files=429, longest=0.001 s, average=0.001 s; distance=9546 kB, estimate=481206 kB; lsn=0/229D39A8, redo lsn=0/229D39A823842026-10-25 19:18:22.616 UTC [173] LOG: database system is shut down2385Running OIDC tests...2386=== RUN TestAudienceForIssuer2387=== PAUSE TestAudienceForIssuer2388=== RUN TestHTTPClientForHasTimeouts2389=== PAUSE TestHTTPClientForHasTimeouts2390=== RUN TestGlobMatch2391=== PAUSE TestGlobMatch2392=== RUN TestValidateToken_ValidToken2393=== PAUSE TestValidateToken_ValidToken2394=== RUN TestValidateToken_WrongAudience2395=== PAUSE TestValidateToken_WrongAudience2396=== RUN TestValidateToken_Expired2397=== PAUSE TestValidateToken_Expired2398=== RUN TestValidateToken_BoundClaimsMismatch2399=== PAUSE TestValidateToken_BoundClaimsMismatch2400=== RUN TestValidateToken_BoundSubjectMismatch2401=== PAUSE TestValidateToken_BoundSubjectMismatch2402=== RUN TestValidateToken_MultipleProviders2403=== PAUSE TestValidateToken_MultipleProviders2404=== RUN TestValidateToken_NoMatchingProvider2405=== PAUSE TestValidateToken_NoMatchingProvider2406=== RUN TestValidateToken_KubernetesServiceAccount2407=== PAUSE TestValidateToken_KubernetesServiceAccount2408=== RUN TestNewValidator_KubernetesRequiresCA2409=== PAUSE TestNewValidator_KubernetesRequiresCA2410=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2411=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2412=== RUN TestPins_ReservedForMatchingRule2413=== PAUSE TestPins_ReservedForMatchingRule2414=== RUN TestPins_TopLevelShorthand2415=== PAUSE TestPins_TopLevelShorthand2416=== RUN TestPins_ConfigValidation2417=== PAUSE TestPins_ConfigValidation2418=== RUN TestScopes_LegacyProviderDefaultsToWrite2419=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2420=== RUN TestScopes_Rules2421=== PAUSE TestScopes_Rules2422=== RUN TestScopes_ConfigValidation2423=== PAUSE TestScopes_ConfigValidation2424=== CONT TestAudienceForIssuer2425=== CONT TestValidateToken_WrongAudience2426=== CONT TestPins_TopLevelShorthand2427=== CONT TestValidateToken_KubernetesServiceAccount2428=== CONT TestScopes_Rules2429=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2430=== CONT TestNewValidator_KubernetesRequiresCA2431=== CONT TestPins_ReservedForMatchingRule2432=== CONT TestValidateToken_ValidToken2433=== CONT TestValidateToken_BoundClaimsMismatch2434=== CONT TestHTTPClientForHasTimeouts2435=== CONT TestValidateToken_BoundSubjectMismatch2436=== CONT TestValidateToken_NoMatchingProvider2437=== CONT TestScopes_LegacyProviderDefaultsToWrite2438=== CONT TestScopes_ConfigValidation2439--- PASS: TestAudienceForIssuer (0.00s)2440=== CONT TestValidateToken_MultipleProviders2441=== CONT TestGlobMatch2442=== CONT TestPins_ConfigValidation2443=== CONT TestValidateToken_Expired2444=== RUN TestGlobMatch/foo_foo2445=== PAUSE TestGlobMatch/foo_foo2446=== RUN TestGlobMatch/foo_bar2447=== PAUSE TestGlobMatch/foo_bar2448=== RUN TestGlobMatch/*_2449=== PAUSE TestGlobMatch/*_2450=== RUN TestGlobMatch/*_anything2451=== PAUSE TestGlobMatch/*_anything2452=== RUN TestGlobMatch/foo*_foo2453=== PAUSE TestGlobMatch/foo*_foo2454=== RUN TestGlobMatch/foo*_foobar2455=== PAUSE TestGlobMatch/foo*_foobar2456=== RUN TestGlobMatch/foo*_bar2457=== PAUSE TestGlobMatch/foo*_bar2458=== RUN TestGlobMatch/*bar_bar2459=== PAUSE TestGlobMatch/*bar_bar2460=== RUN TestGlobMatch/*bar_foobar2461=== PAUSE TestGlobMatch/*bar_foobar2462=== RUN TestGlobMatch/*bar_foo2463=== PAUSE TestGlobMatch/*bar_foo2464=== RUN TestGlobMatch/foo*bar_foobar2465--- PASS: TestScopes_ConfigValidation (0.00s)2466=== PAUSE TestGlobMatch/foo*bar_foobar2467=== RUN TestGlobMatch/foo*bar_foo123bar2468=== PAUSE TestGlobMatch/foo*bar_foo123bar2469=== RUN TestGlobMatch/foo*bar_foobarbaz2470=== PAUSE TestGlobMatch/foo*bar_foobarbaz2471=== RUN TestGlobMatch/*/*_foo/bar2472=== PAUSE TestGlobMatch/*/*_foo/bar2473=== RUN TestGlobMatch/*/*_foo2474=== PAUSE TestGlobMatch/*/*_foo2475=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2476=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2477=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02478=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02479=== RUN TestGlobMatch/refs/*/main_refs/heads/main2480=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2481--- PASS: TestPins_ConfigValidation (0.00s)2482=== RUN TestGlobMatch/fo?_foo2483=== PAUSE TestGlobMatch/fo?_foo2484=== RUN TestGlobMatch/fo?_fo2485=== PAUSE TestGlobMatch/fo?_fo2486=== RUN TestGlobMatch/fo?_fooo2487=== PAUSE TestGlobMatch/fo?_fooo2488=== RUN TestGlobMatch/?oo_foo2489=== PAUSE TestGlobMatch/?oo_foo2490=== RUN TestGlobMatch/?oo_boo2491=== PAUSE TestGlobMatch/?oo_boo2492=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2493=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2494=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2495=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2496=== CONT TestGlobMatch/foo_foo2497=== CONT TestGlobMatch/fo?_fooo2498=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2499=== CONT TestGlobMatch/foo*bar_foo123bar2500=== CONT TestGlobMatch/fo?_fo2501=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2502=== CONT TestGlobMatch/?oo_boo2503=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02504=== CONT TestGlobMatch/*_2505=== CONT TestGlobMatch/?oo_foo2506=== CONT TestGlobMatch/foo*bar_foobar2507=== CONT TestGlobMatch/fo?_foo2508=== CONT TestGlobMatch/*bar_bar2509=== CONT TestGlobMatch/*bar_foobar2510=== CONT TestGlobMatch/*/*_foo/bar2511=== CONT TestGlobMatch/foo*bar_foobarbaz2512=== CONT TestGlobMatch/*_anything2513=== CONT TestGlobMatch/foo*_bar2514=== CONT TestGlobMatch/refs/*/main_refs/heads/main2515=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2516=== CONT TestGlobMatch/foo*_foobar2517=== CONT TestGlobMatch/*bar_foo2518=== CONT TestGlobMatch/foo_bar2519=== CONT TestGlobMatch/*/*_foo2520=== CONT TestGlobMatch/foo*_foo2521--- PASS: TestGlobMatch (0.00s)2522 --- PASS: TestGlobMatch/foo_foo (0.00s)2523 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2524 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2525 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2526 --- PASS: TestGlobMatch/fo?_fo (0.00s)2527 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2528 --- PASS: TestGlobMatch/?oo_boo (0.00s)2529 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2530 --- PASS: TestGlobMatch/*_ (0.00s)2531 --- PASS: TestGlobMatch/?oo_foo (0.00s)2532 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2533 --- PASS: TestGlobMatch/fo?_foo (0.00s)2534 --- PASS: TestGlobMatch/*bar_bar (0.00s)2535 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2536 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2537 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2538 --- PASS: TestGlobMatch/*_anything (0.00s)2539 --- PASS: TestGlobMatch/foo*_bar (0.00s)2540 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2541 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2542 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2543 --- PASS: TestGlobMatch/*bar_foo (0.00s)2544 --- PASS: TestGlobMatch/foo_bar (0.00s)2545 --- PASS: TestGlobMatch/*/*_foo (0.00s)2546 --- PASS: TestGlobMatch/foo*_foo (0.00s)25472026/10/25 19:18:25 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12325482026/10/25 19:18:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44145/oidc2549--- PASS: TestValidateToken_BoundSubjectMismatch (0.02s)2550--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.03s)25512026/10/25 19:18:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44335/oidc2552--- PASS: TestValidateToken_BoundClaimsMismatch (0.03s)25532026/10/25 19:18:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34033/oidc25542026/10/25 19:18:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46289/oidc2555--- PASS: TestPins_ReservedForMatchingRule (0.06s)2556--- PASS: TestScopes_Rules (0.06s)25572026/10/25 19:18:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44429/oidc25582026/10/25 19:18:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38247/oidc2559--- PASS: TestValidateToken_WrongAudience (0.07s)2560--- PASS: TestValidateToken_ValidToken (0.07s)25612026/10/25 19:18:25 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:3899925622026/10/25 19:18:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34959/oidc2563--- PASS: TestValidateToken_KubernetesServiceAccount (0.09s)25642026/10/25 19:18:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40153/oidc2565--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.09s)2566--- PASS: TestValidateToken_Expired (0.09s)25672026/10/25 19:18:25 http: TLS handshake error from 127.0.0.1:38674: remote error: tls: bad certificate2568--- PASS: TestNewValidator_KubernetesRequiresCA (0.11s)25692026/10/25 19:18:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42573/oidc2570--- PASS: TestPins_TopLevelShorthand (0.13s)25712026/10/25 19:18:25 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41415/oidc2572--- PASS: TestValidateToken_NoMatchingProvider (0.16s)2573--- PASS: TestHTTPClientForHasTimeouts (0.20s)25742026/10/25 19:18:25 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:40981/oidc25752026/10/25 19:18:25 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:46693/oidc2576--- PASS: TestValidateToken_MultipleProviders (0.21s)2577PASS2578Running hook tests...2579=== RUN TestSendPathsEmpty2580=== PAUSE TestSendPathsEmpty2581=== RUN TestQueueEnqueueAndFetch2582=== PAUSE TestQueueEnqueueAndFetch2583=== RUN TestQueueDeduplication2584=== PAUSE TestQueueDeduplication2585=== RUN TestQueueRemove2586=== PAUSE TestQueueRemove2587=== RUN TestQueueFetchBatchLimit2588=== PAUSE TestQueueFetchBatchLimit2589=== RUN TestQueueRetryMovesToBack2590=== PAUSE TestQueueRetryMovesToBack2591=== RUN TestQueueFetchRemoveLifecycle2592=== PAUSE TestQueueFetchRemoveLifecycle2593=== RUN TestQueueConcurrentWriters2594=== PAUSE TestQueueConcurrentWriters2595=== RUN TestQueueEnqueueWaitsOutSlowWriter2596=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2597=== RUN TestQueueRemoveLargeClosure2598=== PAUSE TestQueueRemoveLargeClosure2599=== RUN TestServerClientIntegration2600--- PASS: TestServerClientIntegration (0.00s)2601=== RUN TestServerQueueError26022026/10/25 19:18:26 ERROR Failed to queue paths error="permission denied" count=12603--- PASS: TestServerQueueError (0.00s)2604=== RUN TestServerRefusesOversizedAndNonStoreRequests2605=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2606=== RUN TestGetListenerSocketActivation2607 server_test.go:309: === RUN TestGetListenerSocketActivation2608 --- PASS: TestGetListenerSocketActivation (0.00s)2609 PASS2610 2611--- PASS: TestGetListenerSocketActivation (1.02s)2612=== RUN TestServerStalledClientDoesNotBlockShutdown2613=== PAUSE TestServerStalledClientDoesNotBlockShutdown2614=== RUN TestServerBacksOffOnAcceptErrors2615=== PAUSE TestServerBacksOffOnAcceptErrors2616=== RUN TestDrainIsolatesPoisonPath2617=== PAUSE TestDrainIsolatesPoisonPath2618=== RUN TestRunNotBlockedByPoisonHead2619=== PAUSE TestRunNotBlockedByPoisonHead2620=== RUN TestDrainGivesUpWhenServerDown2621=== PAUSE TestDrainGivesUpWhenServerDown2622=== RUN TestFailedPathPrunedByLaterClosure2623=== PAUSE TestFailedPathPrunedByLaterClosure2624=== RUN TestWorkerUploadsAndRemoves2625=== PAUSE TestWorkerUploadsAndRemoves2626=== RUN TestWorkerSkipsGCdPaths2627=== PAUSE TestWorkerSkipsGCdPaths2628=== RUN TestWorkerPrunesClosureDeps2629=== PAUSE TestWorkerPrunesClosureDeps2630=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2631=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2632=== RUN TestDrainTimeout2633=== PAUSE TestDrainTimeout2634=== RUN TestDrainTimeoutDuringIsolation2635=== PAUSE TestDrainTimeoutDuringIsolation2636=== RUN TestShutdownFinishesInFlightPush2637=== PAUSE TestShutdownFinishesInFlightPush2638=== RUN TestWorkerRemoveFailureIsNotProgress2639=== PAUSE TestWorkerRemoveFailureIsNotProgress2640=== RUN TestWorkerKeepsPathItCannotStat2641=== PAUSE TestWorkerKeepsPathItCannotStat2642=== CONT TestSendPathsEmpty2643=== CONT TestDrainIsolatesPoisonPath2644=== CONT TestWorkerPrunesClosureDeps2645=== CONT TestWorkerKeepsPathItCannotStat2646=== CONT TestShutdownFinishesInFlightPush2647=== CONT TestDrainTimeoutDuringIsolation2648=== CONT TestWorkerRemoveFailureIsNotProgress2649=== CONT TestDrainTimeout2650=== CONT TestServerRefusesOversizedAndNonStoreRequests2651=== CONT TestQueueFetchRemoveLifecycle2652=== CONT TestServerStalledClientDoesNotBlockShutdown2653=== CONT TestServerBacksOffOnAcceptErrors2654=== CONT TestQueueConcurrentWriters26552026/10/25 19:18:27 ERROR Accept failed error="too many open files"2656=== CONT TestQueueEnqueueWaitsOutSlowWriter2657=== CONT TestQueueRemove2658=== CONT TestQueueEnqueueAndFetch26592026/10/25 19:18:27 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2660=== CONT TestQueueRetryMovesToBack2661=== CONT TestQueueRemoveLargeClosure2662=== CONT TestQueueFetchBatchLimit2663=== CONT TestFailedPathPrunedByLaterClosure2664=== CONT TestQueueDeduplication2665--- PASS: TestSendPathsEmpty (0.00s)26662026/10/25 19:18:27 ERROR Refusing path outside the store path=/nix/store store=/nix/store2667=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2668=== CONT TestWorkerSkipsGCdPaths2669=== CONT TestDrainGivesUpWhenServerDown26702026/10/25 19:18:27 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store2671=== CONT TestWorkerUploadsAndRemoves2672=== RUN TestShutdownFinishesInFlightPush/completes2673=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2674=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path26752026/10/25 19:18:27 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store2676=== PAUSE TestShutdownFinishesInFlightPush/completes2677=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2678=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2679=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2680=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2681=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2682=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2683=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline26842026/10/25 19:18:27 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store2685=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2686=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2687=== CONT TestRunNotBlockedByPoisonHead2688=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2689=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2690=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short26912026/10/25 19:18:27 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26922026/10/25 19:18:27 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26932026/10/25 19:18:27 ERROR Accept failed error="too many open files"26942026/10/25 19:18:27 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store26952026/10/25 19:18:27 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store26962026/10/25 19:18:27 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store26972026/10/25 19:18:27 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store26982026/10/25 19:18:27 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store26992026/10/25 19:18:27 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store27002026/10/25 19:18:27 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store27012026/10/25 19:18:27 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store27022026/10/25 19:18:27 ERROR Failed to decode request error="unexpected EOF"2703--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2704=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout27052026/10/25 19:18:27 ERROR Accept failed error="too many open files"27062026/10/25 19:18:27 ERROR Accept failed error="too many open files"27072026/10/25 19:18:27 INFO Upload queue status pending=227082026/10/25 19:18:27 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2713113234/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2713113234/002/locked/aaa: permission denied"27092026/10/25 19:18:27 INFO Uploading batch count=127102026/10/25 19:18:27 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2713113234/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2713113234/002/locked/aaa: permission denied"27112026/10/25 19:18:27 INFO Upload queue status pending=227122026/10/25 19:18:27 INFO Uploading batch count=227132026/10/25 19:18:27 INFO Uploading batch count=227142026/10/25 19:18:27 INFO Uploading batch count=427152026/10/25 19:18:27 ERROR Upload failed error="upload failed" count=427162026/10/25 19:18:27 INFO Uploading batch count=427172026/10/25 19:18:27 INFO Uploading batch count=127182026/10/25 19:18:27 ERROR Upload failed error="upload failed" count=127192026/10/25 19:18:27 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2713113234/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2713113234/002/locked/aaa: permission denied"27202026/10/25 19:18:27 ERROR Upload failed error="upload failed" count=427212026/10/25 19:18:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath482363363/002/bbb2722--- PASS: TestQueueEnqueueAndFetch (0.05s)27232026/10/25 19:18:27 INFO Upload queue status pending=22724=== CONT TestShutdownFinishesInFlightPush/completes27252026/10/25 19:18:27 INFO Uploading batch count=227262026/10/25 19:18:27 ERROR Upload failed error="upload failed" count=227272026/10/25 19:18:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown363432513/002/a27282026/10/25 19:18:27 INFO Uploading batch count=227292026/10/25 19:18:27 ERROR Drain finished with paths left in queue remaining=127302026/10/25 19:18:27 INFO Uploading batch count=12731--- PASS: TestQueueRetryMovesToBack (0.05s)2732=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27332026/10/25 19:18:27 INFO Upload queue status pending=227342026/10/25 19:18:27 INFO Upload queue status pending=32735--- PASS: TestQueueFetchBatchLimit (0.06s)2736=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths27372026/10/25 19:18:27 INFO Uploading batch count=227382026/10/25 19:18:27 INFO Upload queue status pending=32739=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch27402026/10/25 19:18:27 INFO Uploading batch count=12741--- PASS: TestQueueFetchRemoveLifecycle (0.06s)27422026/10/25 19:18:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown363432513/002/b27432026/10/25 19:18:27 ERROR Upload failed error="upload failed" count=127442026/10/25 19:18:27 INFO Uploading batch count=427452026/10/25 19:18:27 ERROR Upload failed error="upload failed" count=427462026/10/25 19:18:27 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2331912507/002/nonexistent27472026/10/25 19:18:27 INFO Uploading batch count=127482026/10/25 19:18:27 INFO Uploading batch count=127492026/10/25 19:18:27 ERROR Upload failed error="upload failed" count=12750--- PASS: TestQueueRemove (0.06s)27512026/10/25 19:18:27 INFO Uploading batch count=227522026/10/25 19:18:27 INFO Uploading batch count=227532026/10/25 19:18:27 ERROR Upload failed error="upload failed" count=227542026/10/25 19:18:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown363432513/002/c2755--- PASS: TestQueueDeduplication (0.06s)2756--- PASS: TestWorkerKeepsPathItCannotStat (0.07s)27572026/10/25 19:18:27 INFO Uploading batch count=127582026/10/25 19:18:27 ERROR Upload failed error="upload failed" count=127592026/10/25 19:18:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown363432513/002/d27602026/10/25 19:18:27 INFO Uploading batch count=12761--- PASS: TestWorkerPrunesClosureDeps (0.07s)27622026/10/25 19:18:27 ERROR Upload failed error="upload failed" count=127632026/10/25 19:18:27 ERROR Drain finished with paths left in queue remaining=127642026/10/25 19:18:27 INFO Uploading batch count=227652026/10/25 19:18:27 ERROR Upload failed error="upload failed" count=227662026/10/25 19:18:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown363432513/002/e27672026/10/25 19:18:27 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown363432513/002/f2768--- PASS: TestFailedPathPrunedByLaterClosure (0.07s)2769--- PASS: TestDrainIsolatesPoisonPath (0.07s)27702026/10/25 19:18:27 INFO Upload queue status pending=227712026/10/25 19:18:27 ERROR Drain finished with paths left in queue remaining=1027722026/10/25 19:18:27 INFO Uploading batch count=22773--- PASS: TestDrainGivesUpWhenServerDown (0.07s)27742026/10/25 19:18:27 ERROR Accept failed error="too many open files"2775--- PASS: TestWorkerUploadsAndRemoves (0.07s)2776--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.08s)2777--- PASS: TestWorkerSkipsGCdPaths (0.08s)27782026/10/25 19:18:27 INFO Uploading batch count=227792026/10/25 19:18:27 ERROR Upload failed error="upload failed" count=227802026/10/25 19:18:27 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127812026/10/25 19:18:27 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127822026/10/25 19:18:27 INFO Uploading batch count=227832026/10/25 19:18:27 ERROR Upload failed error="upload failed" count=227842026/10/25 19:18:27 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path2769837604/001/nonexistent27852026/10/25 19:18:27 INFO Uploading batch count=227862026/10/25 19:18:27 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127872026/10/25 19:18:27 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127882026/10/25 19:18:27 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127892026/10/25 19:18:27 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path2769837604/001/nonexistent27902026/10/25 19:18:27 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227912026/10/25 19:18:27 INFO Uploading batch count=227922026/10/25 19:18:27 ERROR Upload failed error="upload failed" count=227932026/10/25 19:18:27 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127942026/10/25 19:18:27 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127952026/10/25 19:18:27 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127962026/10/25 19:18:27 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path2769837604/001/nonexistent27972026/10/25 19:18:27 ERROR Drain finished with paths left in queue remaining=227982026/10/25 19:18:27 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127992026/10/25 19:18:27 INFO Uploading batch count=228002026/10/25 19:18:27 ERROR Drain finished with paths left in queue remaining=128012026/10/25 19:18:27 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228022026/10/25 19:18:27 INFO Uploading batch count=228032026/10/25 19:18:27 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228042026/10/25 19:18:27 ERROR Drain finished with paths left in queue remaining=22805--- PASS: TestWorkerRemoveFailureIsNotProgress (0.01s)2806 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.03s)2807 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.03s)2808 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.03s)28092026/10/25 19:18:27 ERROR Accept failed error="too many open files"28102026/10/25 19:18:28 ERROR Failed to decode request error="read unix /build/hook1129119058/test.sock->@: i/o timeout"28112026/10/25 19:18:28 ERROR Failed to write response error="write unix /build/hook1129119058/test.sock->@: i/o timeout"2812--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)28132026/10/25 19:18:28 ERROR Upload failed error="context canceled" count=228142026/10/25 19:18:28 ERROR Drain finished with paths left in queue remaining=428152026/10/25 19:18:28 ERROR Drain finished with paths left in queue remaining=428162026/10/25 19:18:28 ERROR Upload failed error="context canceled" count=228172026/10/25 19:18:28 ERROR Drain finished with paths left in queue remaining=22818--- PASS: TestDrainTimeout (0.25s)2819--- PASS: TestShutdownFinishesInFlightPush (0.01s)2820 --- PASS: TestShutdownFinishesInFlightPush/completes (0.12s)2821 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.24s)28222026/10/25 19:18:28 ERROR Accept failed error="too many open files"28232026/10/25 19:18:28 ERROR Drain finished with paths left in queue remaining=32824--- PASS: TestDrainTimeoutDuringIsolation (0.01s)2825 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.25s)2826 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.36s)2827--- PASS: TestQueueConcurrentWriters (0.52s)28282026/10/25 19:18:28 ERROR Accept failed error="too many open files"2829--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)28302026/10/25 19:18:28 INFO Uploading batch count=128312026/10/25 19:18:28 INFO Uploading batch count=128322026/10/25 19:18:28 INFO Uploading batch count=128332026/10/25 19:18:28 ERROR Upload failed error="upload failed" count=128342026/10/25 19:18:28 INFO Uploading batch count=128352026/10/25 19:18:28 ERROR Upload failed error="upload failed" count=128362026/10/25 19:18:28 INFO Uploading batch count=128372026/10/25 19:18:28 ERROR Upload failed error="upload failed" count=128382026/10/25 19:18:28 INFO Uploading batch count=128392026/10/25 19:18:28 ERROR Upload failed error="upload failed" count=128402026/10/25 19:18:28 ERROR Drain finished with paths left in queue remaining=12841--- PASS: TestRunNotBlockedByPoisonHead (1.08s)2842--- PASS: TestQueueRemoveLargeClosure (1.34s)2843--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.05s)2844PASS2845Running signing tests...2846=== RUN TestExternalSigner2847=== PAUSE TestExternalSigner2848=== RUN TestExternalSignerWrongPublicKey2849=== PAUSE TestExternalSignerWrongPublicKey2850=== RUN TestExternalSignerErrors2851=== PAUSE TestExternalSignerErrors2852=== RUN TestExternalSignerRestartsAfterCrash2853=== PAUSE TestExternalSignerRestartsAfterCrash2854=== RUN TestExternalSignerProgramErrorKeepsProcess2855=== PAUSE TestExternalSignerProgramErrorKeepsProcess2856=== RUN TestExternalSignerClose2857=== PAUSE TestExternalSignerClose2858=== RUN TestExternalSignerRejectsInvalidPublicKey2859=== PAUSE TestExternalSignerRejectsInvalidPublicKey2860=== RUN TestExternalSignerCancellation2861=== PAUSE TestExternalSignerCancellation2862=== RUN TestGenerateFingerprint2863=== PAUSE TestGenerateFingerprint2864=== RUN TestParseSigningKey2865=== PAUSE TestParseSigningKey2866=== RUN TestSign2867=== PAUSE TestSign2868=== RUN TestSignBatch2869=== PAUSE TestSignBatch2870=== RUN TestNilKeyPublicKey2871=== PAUSE TestNilKeyPublicKey2872=== RUN TestSignErrors2873=== PAUSE TestSignErrors2874=== CONT TestExternalSigner2875=== CONT TestExternalSignerCancellation2876=== CONT TestExternalSignerRestartsAfterCrash2877=== CONT TestExternalSignerRejectsInvalidPublicKey2878=== CONT TestExternalSignerClose2879=== CONT TestExternalSignerWrongPublicKey2880=== CONT TestExternalSignerErrors2881=== RUN TestExternalSignerErrors/null_signatures2882=== CONT TestSign2883=== CONT TestParseSigningKey2884=== CONT TestGenerateFingerprint2885=== CONT TestSignErrors2886=== CONT TestNilKeyPublicKey2887=== CONT TestExternalSignerProgramErrorKeepsProcess2888=== CONT TestSignBatch2889=== RUN TestExternalSignerRejectsInvalidPublicKey/#002890=== PAUSE TestExternalSignerErrors/null_signatures2891=== RUN TestExternalSignerErrors/wrong_signatures_shape2892=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2893=== RUN TestParseSigningKey/valid_32-byte_key2894=== RUN TestExternalSignerErrors/too_few_signatures2895=== PAUSE TestExternalSignerErrors/too_few_signatures2896=== PAUSE TestParseSigningKey/valid_32-byte_key2897--- PASS: TestNilKeyPublicKey (0.00s)2898=== RUN TestExternalSignerErrors/wrong_shape2899=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2900=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002901=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2902=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2903=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2904=== RUN TestGenerateFingerprint/basic_with_references2905=== RUN TestParseSigningKey/no_colon2906=== PAUSE TestParseSigningKey/no_colon2907=== PAUSE TestExternalSignerErrors/wrong_shape2908=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2909=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2910=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2911=== RUN TestExternalSignerErrors/missing_signatures2912=== PAUSE TestGenerateFingerprint/basic_with_references2913=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2914=== PAUSE TestExternalSignerErrors/missing_signatures2915=== RUN TestGenerateFingerprint/no_references2916=== RUN TestParseSigningKey/empty_name2917=== PAUSE TestParseSigningKey/empty_name2918=== PAUSE TestGenerateFingerprint/no_references2919=== RUN TestSignErrors/nil_key2920=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2921=== RUN TestExternalSignerErrors/missing_signature_name2922=== RUN TestParseSigningKey/invalid_base642923=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2924--- PASS: TestSign (0.00s)2925=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2926=== PAUSE TestSignErrors/nil_key2927=== PAUSE TestExternalSignerErrors/missing_signature_name2928=== PAUSE TestParseSigningKey/invalid_base642929=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2930=== RUN TestParseSigningKey/wrong_length2931--- PASS: TestExternalSignerClose (0.00s)2932=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2933=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2934=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2935=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2936=== CONT TestExternalSignerRejectsInvalidPublicKey/#002937=== RUN TestSignErrors/nil_narinfo2938=== RUN TestExternalSignerErrors/wrong_signature_name2939=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2940=== PAUSE TestParseSigningKey/wrong_length2941--- PASS: TestExternalSignerWrongPublicKey (0.00s)2942=== PAUSE TestSignErrors/nil_narinfo2943=== PAUSE TestExternalSignerErrors/wrong_signature_name2944=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2945=== RUN TestExternalSignerErrors/program_error2946=== PAUSE TestExternalSignerErrors/program_error2947=== CONT TestParseSigningKey/empty_name2948=== CONT TestParseSigningKey/wrong_length2949=== CONT TestParseSigningKey/invalid_base642950=== CONT TestParseSigningKey/valid_32-byte_key2951=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2952=== CONT TestParseSigningKey/no_colon2953--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2954 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2955 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2956 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2957 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2958 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2959=== RUN TestSignErrors/invalid_narinfo2960=== RUN TestExternalSignerErrors/exit_on_request2961=== RUN TestGenerateFingerprint/invalid_nar_hash_length2962=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2963--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2964=== PAUSE TestSignErrors/invalid_narinfo2965=== RUN TestSignErrors/canceled2966=== PAUSE TestSignErrors/canceled2967--- PASS: TestParseSigningKey (0.00s)2968 --- PASS: TestParseSigningKey/empty_name (0.00s)2969 --- PASS: TestParseSigningKey/wrong_length (0.00s)2970 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2971 --- PASS: TestParseSigningKey/no_colon (0.00s)2972 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2973 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2974=== RUN TestGenerateFingerprint/invalid_store_path_prefix2975=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2976=== PAUSE TestExternalSignerErrors/exit_on_request2977=== CONT TestSignErrors/nil_key2978=== CONT TestSignErrors/canceled2979=== CONT TestSignErrors/nil_narinfo2980=== CONT TestSignErrors/invalid_narinfo2981=== RUN TestGenerateFingerprint/invalid_reference_prefix2982=== RUN TestExternalSignerErrors/invalid_signature_base642983=== PAUSE TestExternalSignerErrors/invalid_signature_base642984--- PASS: TestSignErrors (0.01s)2985 --- PASS: TestSignErrors/nil_key (0.00s)2986 --- PASS: TestSignErrors/canceled (0.00s)2987 --- PASS: TestSignErrors/nil_narinfo (0.00s)2988 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2989=== RUN TestExternalSignerErrors/wrong_signature_length2990=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2991=== PAUSE TestExternalSignerErrors/wrong_signature_length2992=== CONT TestGenerateFingerprint/basic_with_references2993=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2994=== CONT TestGenerateFingerprint/invalid_nar_hash_length2995=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2996=== CONT TestGenerateFingerprint/invalid_reference_prefix2997=== CONT TestGenerateFingerprint/no_references2998=== CONT TestGenerateFingerprint/invalid_store_path_prefix2999=== RUN TestExternalSignerErrors/unrequested_key3000--- PASS: TestGenerateFingerprint (0.01s)3001 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)3002 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)3003 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)3004 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)3005 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)3006 --- PASS: TestGenerateFingerprint/no_references (0.00s)3007 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)3008=== PAUSE TestExternalSignerErrors/unrequested_key3009=== RUN TestExternalSignerErrors/exit_at_startup3010=== PAUSE TestExternalSignerErrors/exit_at_startup3011=== RUN TestExternalSignerErrors/invalid_JSON3012=== PAUSE TestExternalSignerErrors/invalid_JSON3013=== RUN TestExternalSignerErrors/null3014=== PAUSE TestExternalSignerErrors/null3015=== RUN TestExternalSignerErrors/wrong_id3016=== PAUSE TestExternalSignerErrors/wrong_id3017=== CONT TestExternalSignerErrors/null_signatures3018=== CONT TestExternalSignerErrors/missing_signatures3019=== CONT TestExternalSignerErrors/program_error3020=== CONT TestExternalSignerErrors/null3021=== CONT TestExternalSignerErrors/wrong_signature_length3022=== CONT TestExternalSignerErrors/unrequested_key3023=== CONT TestExternalSignerErrors/invalid_signature_base643024=== CONT TestExternalSignerErrors/invalid_JSON3025=== CONT TestExternalSignerErrors/wrong_id3026=== CONT TestExternalSignerErrors/wrong_shape3027=== CONT TestExternalSignerErrors/exit_at_startup3028=== CONT TestExternalSignerErrors/too_few_signatures3029=== CONT TestExternalSignerErrors/exit_on_request3030=== CONT TestExternalSignerErrors/missing_signature_name3031=== CONT TestExternalSignerErrors/wrong_signatures_shape3032=== CONT TestExternalSignerErrors/wrong_signature_name3033--- PASS: TestSignBatch (0.01s)3034--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)3035--- PASS: TestExternalSigner (0.01s)3036--- PASS: TestExternalSignerErrors (0.01s)3037 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)3038 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)3039 --- PASS: TestExternalSignerErrors/program_error (0.00s)3040 --- PASS: TestExternalSignerErrors/null (0.01s)3041 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)3042 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)3043 --- PASS: TestExternalSignerErrors/wrong_id (0.00s)3044 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.00s)3045 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)3046 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)3047 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)3048 --- PASS: TestExternalSignerErrors/too_few_signatures (0.00s)3049 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)3050 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)3051 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.00s)3052 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)3053--- PASS: TestExternalSignerCancellation (0.02s)3054PASS3055Running OpenBao signer tests...3056=== RUN TestSign3057=== PAUSE TestSign3058=== RUN TestSignErrors3059=== PAUSE TestSignErrors3060=== RUN TestServe3061=== PAUSE TestServe3062=== RUN TestServeRejectsGarbage3063=== PAUSE TestServeRejectsGarbage3064=== CONT TestSign3065=== CONT TestServe3066=== CONT TestSignErrors3067=== CONT TestServeRejectsGarbage3068=== RUN TestSignErrors/invalid_base643069--- PASS: TestServeRejectsGarbage (0.00s)3070=== PAUSE TestSignErrors/invalid_base643071=== RUN TestSignErrors/http_error3072--- PASS: TestServe (0.00s)3073=== PAUSE TestSignErrors/http_error3074=== RUN TestSignErrors/invalid_json3075=== PAUSE TestSignErrors/invalid_json3076=== RUN TestSignErrors/no_prefix3077=== PAUSE TestSignErrors/no_prefix3078=== CONT TestSignErrors/no_prefix3079=== CONT TestSignErrors/invalid_base643080=== CONT TestSignErrors/http_error3081=== CONT TestSignErrors/invalid_json3082--- PASS: TestSign (0.01s)3083--- PASS: TestSignErrors (0.00s)3084 --- PASS: TestSignErrors/no_prefix (0.00s)3085 --- PASS: TestSignErrors/invalid_json (0.00s)3086 --- PASS: TestSignErrors/http_error (0.00s)3087 --- PASS: TestSignErrors/invalid_base64 (0.00s)3088PASS3089Running niks3-hook command tests...3090=== RUN TestServeSecondSignalEndsDrain3091=== PAUSE TestServeSecondSignalEndsDrain3092=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown3093=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown3094=== CONT TestServeSecondSignalEndsDrain3095=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown3096--- PASS: TestServeSecondSignalEndsDrain (0.08s)30972026/10/25 19:18:37 INFO Upload queue status pending=130982026/10/25 19:18:37 INFO Uploading batch count=13099--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.12s)3100PASS3101Running rate limiter tests...3102=== RUN TestAdaptiveRateLimiter_ThreadSafety3103=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3104=== CONT TestAdaptiveRateLimiter_ThreadSafety31052026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=7031062026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=4931072026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=34.331082026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=24.00999999999999831092026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=16.80731102026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=11.76489999999999931112026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=8.2354331122026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=5.76480099999999931132026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531142026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531152026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531162026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531172026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531182026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531192026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531202026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531212026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531222026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531232026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531242026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531252026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=5.12435000000000131262026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531272026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531282026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531292026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531302026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531312026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531322026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531332026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=5.12435000000000131342026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531352026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531362026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531372026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531382026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531392026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531402026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531412026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531422026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=13.29124417541344831432026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=9.30387092278941331442026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=6.51270964595258831452026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531462026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531472026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531482026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531492026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531502026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531512026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531522026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531532026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531542026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531552026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531562026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531572026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531582026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531592026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531602026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531612026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531622026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531632026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531642026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531652026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531662026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531672026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531682026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531692026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531702026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531712026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531722026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531732026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531742026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531752026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531762026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531772026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531782026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531792026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531802026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531812026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=8.25281691850000431822026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=5.77697184295000331832026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531842026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531852026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531862026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531872026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531882026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531892026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531902026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531912026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531922026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531932026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531942026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=5.12435000000000131952026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531962026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531972026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531982026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=531992026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=532002026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=532012026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=532022026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=532032026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=532042026/10/25 19:18:38 WARN Rate limiter backed off name=test rate=53205--- PASS: TestAdaptiveRateLimiter_ThreadSafety (3.99s)3206PASS