niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #412
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure18=== PAUSE TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure19=== RUN TestUploadMultipart_PartsInParallel20=== PAUSE TestUploadMultipart_PartsInParallel21=== RUN TestUploadMultipart_ProducerErrorIsNotEOF22=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF23=== RUN TestUploadMultipart_FailedPartBufferNotReused24=== PAUSE TestUploadMultipart_FailedPartBufferNotReused25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestUploadMultipart_SupersededByPeer28=== PAUSE TestUploadMultipart_SupersededByPeer29=== RUN TestDumpPathCaseHackMatchesNix30--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)31=== RUN TestDumpPathCaseHackCollision32--- PASS: TestDumpPathCaseHackCollision (0.00s)33=== RUN TestSupersededNARStillUploadsListing34=== PAUSE TestSupersededNARStillUploadsListing35=== RUN TestTruncatedNARDumpIsNotCompleted36=== PAUSE TestTruncatedNARDumpIsNotCompleted37=== RUN TestDumpPathMatchesNix38=== PAUSE TestDumpPathMatchesNix39=== RUN TestDumpPathSingleFile40=== PAUSE TestDumpPathSingleFile41=== RUN TestDumpPathWriterError42=== PAUSE TestDumpPathWriterError43=== RUN TestDumpPathWriterErrorStopsReading44 nar_test.go:289: read 114 of 32768000 bytes45--- PASS: TestDumpPathWriterErrorStopsReading (0.65s)46=== RUN TestEncodeNixBase3247=== PAUSE TestEncodeNixBase3248=== RUN TestEncodeNixBase32WithRealHash49=== PAUSE TestEncodeNixBase32WithRealHash50=== RUN TestConvertHashToNix3251=== PAUSE TestConvertHashToNix3252=== RUN TestGetStorePathHash53=== PAUSE TestGetStorePathHash54=== RUN TestPathInfoHashCompatibility55=== PAUSE TestPathInfoHashCompatibility56=== RUN TestParsePathInfoJSON57=== PAUSE TestParsePathInfoJSON58=== RUN TestParsePathInfoJSONMultiplePaths59=== PAUSE TestParsePathInfoJSONMultiplePaths60=== RUN TestPathInfoCACompatibility61=== PAUSE TestPathInfoCACompatibility62=== RUN TestUploadPendingObjectsStopsStartingAfterFailure63--- PASS: TestUploadPendingObjectsStopsStartingAfterFailure (0.02s)64=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent65=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent66=== RUN TestCompletePendingClosure_NotFoundWithoutKey67=== PAUSE TestCompletePendingClosure_NotFoundWithoutKey68=== RUN TestRateLimiterFeedback69=== PAUSE TestRateLimiterFeedback70=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess71=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess72=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer73=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer74=== RUN TestResolveStorePath75=== PAUSE TestResolveStorePath76=== RUN TestDoWithRetry_BodyReplayedViaGetBody77=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody78=== RUN 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 TestDoServerRequestAttachesToken135=== CONT TestScriptTokenEmptyCommand136=== CONT TestEncodeNixBase32137=== CONT TestUploadMultipart_SupersededByPeer138=== CONT TestFilterOversizedClosures139=== CONT TestCompletePendingClosure_NotFoundWithoutKey140=== RUN TestUploadMultipart_SupersededByPeer/exists141=== CONT TestParsePathInfoJSONMultiplePaths142=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths143=== CONT TestScriptTokenDoesNotWaitForItsChildren144=== CONT TestScriptTokenScriptFails145=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs146=== CONT TestDoWithRetry_FinalResponseBodyReadable147=== CONT TestSetClientTLSDoesNotMutateDefaultTransport148=== CONT TestPathInfoCACompatibility149=== CONT TestStreamPushReportsEveryPath150=== RUN TestPathInfoCACompatibility/null_ca_field151=== PAUSE TestPathInfoCACompatibility/null_ca_field152=== CONT TestParsePathInfoJSON153=== CONT TestRetryTimeoutOutlastsMaxRetries154=== CONT TestUploadMultipart_PartsInParallel155=== CONT TestResolveStorePath156=== CONT TestClientSignaturesByStorePath157=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent158=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier159=== CONT TestCaseHackSuffix160=== CONT TestStaticToken161=== CONT TestScriptTokenCachesUntilRefresh162=== CONT TestDumpPathMatchesNix163=== CONT TestScriptTokenEmptyToken164=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure165=== CONT TestFileTokenMissing166=== CONT TestFileTokenEmpty167=== CONT TestStreamPushIsolatesFailures168=== CONT TestSetClientTLSErrors169=== RUN TestEncodeNixBase32/test_string_hash170--- PASS: TestScriptTokenEmptyCommand (0.00s)171--- PASS: TestScriptTokenScriptFails (0.01s)172=== RUN TestFilterOversizedClosures/no_limit_keeps_everything173=== PAUSE TestUploadMultipart_SupersededByPeer/exists174--- PASS: TestFileTokenMissing (1.45s)175=== CONT TestShellSplit176=== RUN TestUploadMultipart_SupersededByPeer/missing177--- PASS: TestClientSignaturesByStorePath (0.00s)178=== PAUSE TestEncodeNixBase32/test_string_hash179=== PAUSE TestUploadMultipart_SupersededByPeer/missing180=== RUN TestEncodeNixBase32/empty_input181=== CONT TestUploadMultipart_FailedPartBufferNotReused182--- PASS: TestResolveStorePath (0.00s)183--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.02s)184=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs185=== RUN TestPathInfoCACompatibility/old_string_format_-_text186=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout187--- PASS: TestStreamPushReportsEveryPath (0.02s)188--- PASS: TestDoServerRequestAttachesToken (0.02s)189=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout190--- PASS: TestStaticToken (0.00s)191--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.02s)192=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer193--- PASS: TestFileTokenEmpty (1.45s)194=== PAUSE TestEncodeNixBase32/empty_input195=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text196=== RUN TestParsePathInfoJSON/Nix_format197=== CONT TestPartSizeForNAR198=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica199=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier200=== CONT TestDoWithRetry_BodyReplayedViaGetBody201=== CONT TestScriptTokenBadJSON202=== CONT TestUploadMultipart_ProducerErrorIsNotEOF203=== CONT TestStreamPushStopsWhenCanceled204=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything205=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths206=== CONT TestStreamPushReportsSignatures207=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive208--- PASS: TestShellSplit (0.04s)209=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess210=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive211--- PASS: TestCaseHackSuffix (1.49s)212=== PAUSE TestParsePathInfoJSON/Nix_format213=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up214=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part215=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up216=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped217=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier218=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped219=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths220=== RUN TestFilterOversizedClosures/all_closures_skipped221=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier222=== CONT TestConvertHashToNix32223=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client224=== CONT TestRateLimiterFeedback225=== CONT TestEncodeNixBase32WithRealHash226=== CONT TestGetStorePathHash227=== RUN TestPathInfoCACompatibility/new_structured_format_-_text228=== RUN TestPartSizeForNAR/zero_stays_at_minimum229=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text230=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum231--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (1.52s)232=== RUN TestParsePathInfoJSON/Lix_format233=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part234=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths235=== PAUSE TestFilterOversizedClosures/all_closures_skipped236=== CONT TestStreamPushReportsSkippedPaths237=== RUN TestConvertHashToNix32/SRI_format_to_Nix32238=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client239=== RUN TestSetClientTLSErrors/missing_cert_file240=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client241=== PAUSE TestSetClientTLSErrors/missing_cert_file242=== RUN TestRateLimiterFeedback/429_enables_limiter243=== CONT TestStreamPushStopsOnCancel244=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client245=== RUN TestGetStorePathHash/valid_store_path246=== CONT TestSetClientTLS247=== PAUSE TestGetStorePathHash/valid_store_path248=== PAUSE TestRateLimiterFeedback/429_enables_limiter249=== CONT TestStreamPushGivesUpOnDeadServer250=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method251--- PASS: TestStreamPushIsolatesFailures (1.50s)252=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method253=== RUN TestPartSizeForNAR/small_stays_at_minimum254=== PAUSE TestParsePathInfoJSON/Lix_format255=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary256=== RUN TestParsePathInfoJSON/empty_input257=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary258=== PAUSE TestParsePathInfoJSON/empty_input259=== CONT TestFileTokenReadsAndCaches260=== CONT TestDumpPathSingleFile261=== CONT TestStreamPushBatchesUnderLoad262=== RUN TestStreamPushBatchesUnderLoad/together263=== RUN TestParsePathInfoJSON/whitespace_only264=== CONT TestTruncatedNARDumpIsNotCompleted265=== PAUSE TestParsePathInfoJSON/whitespace_only266=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32267=== CONT TestScriptTokenNoExpiryRerunsEveryCall268=== RUN TestSetClientTLSErrors/missing_key_file269=== RUN TestStreamPushStopsOnCancel/waiting_for_input270=== PAUSE TestSetClientTLSErrors/missing_key_file271=== RUN TestGetStorePathHash/basename_without_hyphen_should_error272=== RUN TestRateLimiterFeedback/503_enables_limiter273--- PASS: TestScriptTokenEmptyToken (1.50s)274=== PAUSE TestRateLimiterFeedback/503_enables_limiter275=== CONT TestStreamPushRequestLine276=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter277=== PAUSE TestPartSizeForNAR/small_stays_at_minimum278=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter279=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum280=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum281=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter282=== RUN TestParsePathInfoJSON/invalid_JSON283=== CONT TestDumpPathWriterError284=== CONT TestRegisterUploadedObjectReusesConnections285=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter286=== PAUSE TestParsePathInfoJSON/invalid_JSON287=== CONT TestShellSplitErrors288=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input289=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot290=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry291=== RUN TestConvertHashToNix32/already_Nix32_format292=== PAUSE TestConvertHashToNix32/already_Nix32_format293=== RUN TestConvertHashToNix32/invalid_format294=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error295=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error296--- PASS: TestStreamPushStopsWhenCanceled (0.00s)297=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error298=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error299=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error300=== CONT TestPathInfoHashCompatibility301=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)302=== PAUSE TestStreamPushBatchesUnderLoad/together303=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts304--- PASS: TestScriptTokenCachesUntilRefresh (1.50s)305=== CONT TestSupersededNARStillUploadsListing306=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts307=== RUN TestPartSizeForNAR/1_TiB308--- PASS: TestStreamPushReportsSignatures (0.00s)309=== RUN TestSupersededNARStillUploadsListing/small_NAR310=== PAUSE TestSupersededNARStillUploadsListing/small_NAR311=== RUN TestSupersededNARStillUploadsListing/dump_cut_short312--- PASS: TestEncodeNixBase32WithRealHash (0.00s)313--- PASS: TestStreamPushReportsSkippedPaths (0.00s)314=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)315=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon316=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short317=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun318=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon319=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI320=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI321=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512322=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512323=== CONT TestUploadMultipart_SupersededByPeer/exists324=== RUN TestSetClientTLSErrors/missing_ca_file325=== PAUSE TestSetClientTLSErrors/missing_ca_file326=== CONT TestUploadMultipart_SupersededByPeer/missing327=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot328=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails329=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails330=== PAUSE TestConvertHashToNix32/invalid_format331=== RUN TestSetClientTLSErrors/invalid_ca_file332=== PAUSE TestPartSizeForNAR/1_TiB333=== RUN TestPartSizeForNAR/5_TiB_S3_max_object334=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout335=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object336=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot337=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot338=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot339=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot340--- PASS: TestScriptTokenBadJSON (0.00s)341--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.10s)342=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time343=== CONT TestEncodeNixBase32/empty_input344=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs345=== CONT TestFilterOversizedClosures/no_limit_keeps_everything346=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths347=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot348=== CONT TestFilterOversizedClosures/all_closures_skipped349=== RUN TestPartSizeForNAR/capped_at_5_GiB350=== PAUSE TestPartSizeForNAR/capped_at_5_GiB351=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped352=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot353=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken354=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken355=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths356--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)357--- PASS: TestFileTokenReadsAndCaches (0.00s)358--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)359--- PASS: TestParsePathInfoJSONMultiplePaths (1.52s)360 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)361 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)362--- PASS: TestShellSplitErrors (0.00s)363=== PAUSE TestSetClientTLSErrors/invalid_ca_file364--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)365=== RUN TestSetClientTLS/rejects_connection_without_client_cert366=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert367=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA368=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time369=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier370=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client371=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA372=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier373=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive374=== CONT TestPathInfoCACompatibility/new_structured_format_-_text375=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method376=== CONT TestPathInfoCACompatibility/old_string_format_-_text377=== CONT TestPathInfoCACompatibility/null_ca_field378=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part379=== CONT TestRateLimiterFeedback/429_enables_limiter380=== RUN TestSetClientTLS/preserves_debug_logging_transport381=== PAUSE TestSetClientTLS/preserves_debug_logging_transport382=== CONT TestParsePathInfoJSON/Nix_format383=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up384=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter385=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary386=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client387--- PASS: TestDumpPathSingleFile (0.07s)388=== CONT TestEncodeNixBase32/test_string_hash389--- PASS: TestFilterOversizedClosures (1.52s)390 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)391 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)392 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)393=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter394=== CONT TestParsePathInfoJSON/invalid_JSON395=== CONT TestGetStorePathHash/valid_store_path396--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.24s)397=== CONT TestRateLimiterFeedback/503_enables_limiter398=== CONT TestGetStorePathHash/basename_without_hyphen_should_error399--- PASS: TestUploadMultipart_SupersededByPeer (1.48s)400 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.24s)401 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.24s)402=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error403=== CONT TestParsePathInfoJSON/empty_input404=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error405=== CONT TestParsePathInfoJSON/Lix_format406=== CONT TestParsePathInfoJSON/whitespace_only407=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon408=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI409=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512410--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (1.78s)411=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)412=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails413--- PASS: TestEncodeNixBase32 (1.51s)414 --- PASS: TestEncodeNixBase32/empty_input (0.00s)415 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)416=== CONT TestPartSizeForNAR/small_stays_at_minimum417=== CONT TestConvertHashToNix32/already_Nix32_format418=== CONT TestConvertHashToNix32/SRI_format_to_Nix32419--- PASS: TestPathInfoCACompatibility (1.52s)420 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)421 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)422 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)423 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)424 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)425=== CONT TestPartSizeForNAR/5_TiB_S3_max_object426=== CONT TestConvertHashToNix32/invalid_format427=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot428--- PASS: TestGetStorePathHash (0.03s)429 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)430 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)431 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)432 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)433=== CONT TestPartSizeForNAR/1_TiB434--- PASS: TestParsePathInfoJSON (1.53s)435 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)436 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)437 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)438 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)439 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)440=== CONT TestPartSizeForNAR/capped_at_5_GiB441--- PASS: TestConvertHashToNix32 (0.07s)442 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)443 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)444 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)445=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum446=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts447=== CONT TestSupersededNARStillUploadsListing/dump_cut_short448--- PASS: TestPathInfoHashCompatibility (0.00s)449 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)450 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)451 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)452 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)453=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken454=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot455--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (1.51s)456 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.18s)457 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.01s)458 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.01s)459 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.00s)460 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.01s)461=== CONT TestPartSizeForNAR/zero_stays_at_minimum462=== CONT TestStreamPushStopsOnCancel/waiting_for_input463--- PASS: TestRateLimiterFeedback (0.01s)464 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)465 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)466 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)467 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)468=== CONT TestSetClientTLSErrors/invalid_ca_file469--- PASS: TestPartSizeForNAR (0.11s)470 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)471 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)472 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)473 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)474 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)475 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)476 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)477=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot478=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot479=== CONT TestSetClientTLSErrors/missing_ca_file480=== CONT TestSetClientTLSErrors/missing_key_file481=== CONT TestSetClientTLSErrors/missing_cert_file482=== CONT TestSupersededNARStillUploadsListing/small_NAR483--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.28s)484=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time485--- PASS: TestSetClientTLSErrors (1.60s)486 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)487 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)488 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)489 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)490=== CONT TestStreamPushBatchesUnderLoad/together491=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA492--- PASS: TestStreamPushBatchesUnderLoad (0.10s)493 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)494 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)495=== CONT TestSetClientTLS/preserves_debug_logging_transport496--- PASS: TestRetryTimeoutOutlastsMaxRetries (1.82s)497=== CONT TestSetClientTLS/rejects_connection_without_client_cert498--- PASS: TestStreamPushStopsOnCancel (0.10s)499 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.27s)500 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.27s)501 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.27s)502 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.27s)503 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.27s)504 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.27s)505--- PASS: TestDumpPathWriterError (0.56s)506--- PASS: TestSetClientTLS (0.27s)507 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.27s)508 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.27s)509 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.09s)510--- PASS: TestRegisterUploadedObjectReusesConnections (0.67s)511--- PASS: TestDumpPathMatchesNix (2.20s)512--- PASS: TestStreamPushRequestLine (0.70s)513--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.00s)514 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.41s)515 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.43s)516--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.03s)517--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)518--- PASS: TestUploadMultipart_PartsInParallel (2.86s)519--- PASS: TestTruncatedNARDumpIsNotCompleted (1.35s)520--- PASS: TestSupersededNARStillUploadsListing (0.06s)521 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.27s)522 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.27s)523 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.10s)524--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.46s)525--- PASS: TestScriptTokenDoesNotWaitForItsChildren (1.48s)526 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.02s)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/postgres1069859081/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/postgres1069859081/data -l logfile start556557/build/postgres1069859081:5432 - no response5582026-10-11 06:51:00.948 UTC [170] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5592026-10-11 06:51:00.948 UTC [170] LOG: listening on Unix socket "/build/postgres1069859081/.s.PGSQL.5432"5602026-10-11 06:51:00.952 UTC [177] LOG: database system was shut down at 2026-10-11 06:51:00 UTC5612026-10-11 06:51:00.956 UTC [170] LOG: database system is ready to accept connections562/build/postgres1069859081: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/11 06:51:05 INFO lead: acquired remote=192.0.2.1:12346132026/10/11 06:51:06 INFO lead: released remote=192.0.2.1:12346142026/10/11 06:51:06 INFO lead: acquired remote=192.0.2.1:12346152026/10/11 06:51:07 INFO lead: released remote=192.0.2.1:1234616--- PASS: TestLeadIncumbentWinsAfterRestart (3.33s)617=== RUN TestLeadIncumbentAnnouncesAtOnce618=== PAUSE TestLeadIncumbentAnnouncesAtOnce619=== RUN TestLeadEndsOnShutdown620=== PAUSE TestLeadEndsOnShutdown621=== RUN TestLeadEndsWhenItsConnectionHangs6222026/10/11 06:51:07 INFO lead: acquired remote=192.0.2.1:12346232026-10-11 06:51:09.024 UTC [428] FATAL: terminating connection due to administrator command6242026/10/11 06:51:09 INFO lead: acquired remote=192.0.2.1:12346252026/10/11 06:51:10 WARN lead: lock connection lost error="timeout: context deadline exceeded"6262026/10/11 06:51:10 INFO lead: released remote=192.0.2.1:12346272026/10/11 06:51:10 INFO lead: released remote=192.0.2.1:1234628--- PASS: TestLeadEndsWhenItsConnectionHangs (2.97s)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 TestObjectStatsLargeCommit718=== PAUSE TestObjectStatsLargeCommit719=== 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/11 06:51:10 INFO Starting HTTP server address=127.0.0.1:328137432026/10/11 06:51:10 INFO Starting HTTP server address=proxy.sock7442026/10/11 06:51:10 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7452026/10/11 06:51:10 INFO Shutdown signal received, draining in-flight requests timeout=10s746--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.16s)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/11 06:51:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8152026/10/11 06:51:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8162026/10/11 06:51:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8172026/10/11 06:51:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8182026/10/11 06:51:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8192026/10/11 06:51:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8202026/10/11 06:51:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8212026/10/11 06:51:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8222026/10/11 06:51:10 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8232026/10/11 06:51:10 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 TestProxyWriteTimeout848=== CONT TestOrphanedObjectsGCStressTest849=== CONT TestPresignedUploadRegisteredBeforeCommit850=== CONT TestService_NativeMTLS851=== CONT TestMetricsCommit852=== CONT TestParseSize853=== CONT TestNARDeduplicationMetadataUploadBug854=== CONT TestService_Rustfstest855=== CONT TestMetricsInventory856=== CONT TestReadProxyNarinfoAlreadyDecompressed857=== CONT TestCreatePendingClosureRejectsOversizedNAR858=== CONT TestReadProxyContentNegotiation859=== CONT TestChildrenInheritRaisedFileLimit860=== CONT TestCacheConfigHandlerMaxNarSize861=== CONT TestCompletedNarNotReofferedAcrossClosures8622026/10/11 06:51:10 INFO Received uploads request method=POST path=/api/pending_closures863=== CONT TestReadProxyRangeRequest864=== CONT TestService_readinessHandler865=== CONT TestPendingClosureFailureTracksEveryUpload866=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false867=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false868=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true869=== CONT TestObjectStatsTrigger870=== CONT TestReadProxyConditionalGet871=== CONT TestLeadIncumbentAnnouncesAtOnce872=== CONT TestPendingClosureFailureAbortsItsUploads873=== CONT TestGracefulShutdownDrainsInflight874=== CONT TestReadRedirectNar8752026/10/11 06:51:10 INFO Starting HTTP server address=127.0.0.1:37903876=== CONT TestLeadEndsOnShutdown8772026/10/11 06:51:10 INFO Shutdown signal received, draining in-flight requests timeout=10s878=== RUN TestProxyWriteTimeout/narinfo879=== CONT TestService_AuthMiddleware_MTLSBoundSubjects880=== PAUSE TestProxyWriteTimeout/narinfo881--- PASS: TestParseSize (0.00s)882=== CONT TestReadProxyRootRedirectsToIndexHTML883=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true884=== CONT TestReadProxyDisabled885=== RUN TestProxyWriteTimeout/1_GiB_nar886=== PAUSE TestProxyWriteTimeout/1_GiB_nar887--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)888=== CONT TestReadProxyOutlastsServerWriteTimeout889=== RUN TestProxyWriteTimeout/10_GiB_nar890=== PAUSE TestProxyWriteTimeout/10_GiB_nar891=== RUN TestProxyWriteTimeout/unknown_size892=== PAUSE TestProxyWriteTimeout/unknown_size893=== CONT TestCompleteMultipartUnregistered894--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)895--- PASS: TestChildrenInheritRaisedFileLimit (0.00s)896=== CONT TestRegisterCompletedObjectNeedsPendingRow897--- PASS: TestGracefulShutdownDrainsInflight (0.92s)8982026/10/11 06:51:11 WARN mTLS auth: subject not in bound subjects subject="CN=reader"8992026/10/11 06:51:11 WARN mTLS auth: subject not in bound subjects subject="CN=reader"9002026/10/11 06:51:11 INFO Received uploads request method=POST path=/api/pending_closures901=== CONT TestGCTaskStore_ConflictDifferentParams902--- PASS: TestService_NativeMTLS (1.06s)903=== CONT TestService_createPendingClosureHandler904--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)9052026/10/11 06:51:11 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9062026/10/11 06:51:11 INFO Received uploads request method=POST path=/api/pending_closures907--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.10s)908=== CONT TestClientSharedPathCommittedMidPush909--- PASS: TestReadProxyDisabled (1.04s)910=== CONT TestPush_OverlappingRootsStoreOneRowPerKey9112026/10/11 06:51:11 INFO lead: acquired remote=192.0.2.1:1234912=== CONT TestGCTaskStore_StartNew913=== CONT TestService_verifyS3Integrity914--- PASS: TestMetricsInventory (1.12s)915--- PASS: TestGCTaskStore_StartNew (0.00s)916--- PASS: TestService_Rustfstest (1.13s)917=== CONT TestService_ReadScope_PublicByDefault9182026/10/11 06:51:11 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"9192026/10/11 06:51:11 WARN mTLS auth: bound subjects configured but subject DN unavailable9202026/10/11 06:51:11 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"921--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.14s)922=== CONT TestService_AuthMiddleware_MTLSProxyHeader9232026/10/11 06:51:12 INFO Received uploads request method=POST path=/api/pending_closures924=== CONT TestOrphanedObjectsGC925--- PASS: TestObjectStatsTrigger (1.20s)9262026/10/11 06:51:12 WARN readiness check failed error="closed pool"927=== CONT TestIsValidCachePath928--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.19s)929=== RUN TestIsValidCachePath/narinfo930=== PAUSE TestIsValidCachePath/narinfo931=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars932=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars933=== RUN TestIsValidCachePath/nar_zst934=== PAUSE TestIsValidCachePath/nar_zst935=== RUN TestIsValidCachePath/nar_xz936=== PAUSE TestIsValidCachePath/nar_xz937=== RUN TestIsValidCachePath/nar_bz2938=== PAUSE TestIsValidCachePath/nar_bz2939=== RUN TestIsValidCachePath/nar_uncompressed940=== PAUSE TestIsValidCachePath/nar_uncompressed941=== RUN TestIsValidCachePath/ls942=== PAUSE TestIsValidCachePath/ls943=== RUN TestIsValidCachePath/log944=== PAUSE TestIsValidCachePath/log945=== RUN TestIsValidCachePath/realisation946=== PAUSE TestIsValidCachePath/realisation947=== RUN TestIsValidCachePath/nix-cache-info948=== PAUSE TestIsValidCachePath/nix-cache-info949=== RUN TestIsValidCachePath/index.html950=== PAUSE TestIsValidCachePath/index.html951=== RUN TestIsValidCachePath/traversal_parent952=== PAUSE TestIsValidCachePath/traversal_parent953=== RUN TestIsValidCachePath/traversal_in_middle954=== PAUSE TestIsValidCachePath/traversal_in_middle955=== RUN TestIsValidCachePath/invalid_char_e956=== PAUSE TestIsValidCachePath/invalid_char_e957=== RUN TestIsValidCachePath/invalid_char_u958=== PAUSE TestIsValidCachePath/invalid_char_u959=== RUN TestIsValidCachePath/random_path960=== PAUSE TestIsValidCachePath/random_path961=== RUN TestIsValidCachePath/empty962=== PAUSE TestIsValidCachePath/empty963=== RUN TestIsValidCachePath/leading_slash964=== PAUSE TestIsValidCachePath/leading_slash965=== RUN TestIsValidCachePath/wrong_extension966=== PAUSE TestIsValidCachePath/wrong_extension967=== RUN TestIsValidCachePath/short_hash968=== PAUSE TestIsValidCachePath/short_hash969=== CONT TestCompleteMultipartUpload_ErrorButObjectExists9702026/10/11 06:51:12 INFO lead: acquired remote=192.0.2.1:12349712026/10/11 06:51:12 INFO lead: released remote=192.0.2.1:1234972--- PASS: TestService_readinessHandler (1.26s)973=== CONT TestSweepRechecksPendingAfterLocking974=== CONT TestConnectWaitsForAPeerMigration975--- PASS: TestLeadIncumbentAnnouncesAtOnce (1.28s)976=== CONT TestPush_RejectsBadRequests977--- PASS: TestReadRedirectNar (1.32s)9782026/10/11 06:51:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9792026/10/11 06:51:12 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst980=== CONT TestReconnectLeavesObjectsUnlocked981--- PASS: TestCompleteMultipartUnregistered (1.27s)9822026/10/11 06:51:12 INFO Received uploads request method=POST path=/api/pending_closures9832026/10/11 06:51:12 INFO Received push request method=POST path=/api/pushes984--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.46s)985=== CONT TestObjectStatsLargeCommit986--- PASS: TestPendingClosureFailureAbortsItsUploads (1.46s)987=== CONT TestReadRedirectKeepsNarinfoProxied988=== CONT TestService_healthCheckHandler989--- PASS: TestReadProxyRangeRequest (1.51s)990=== CONT TestPush_SignsNarinfosOfItsPendingObjects991--- PASS: TestReadProxyConditionalGet (1.53s)9922026/10/11 06:51:12 INFO Received uploads request method=POST path=/api/pending_closures9932026/10/11 06:51:12 INFO Received uploads request method=POST path=/api/pending_closures9942026/10/11 06:51:12 INFO Received uploads request method=POST path=/api/pending_closures9952026/10/11 06:51:12 INFO Received push request method=POST path=/api/pushes9962026/10/11 06:51:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9972026/10/11 06:51:12 INFO Signed narinfos id=1 count=19982026/10/11 06:51:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9992026/10/11 06:51:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10002026/10/11 06:51:12 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10012026/10/11 06:51:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10022026/10/11 06:51:12 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10032026/10/11 06:51:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10042026/10/11 06:51:12 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110052026/10/11 06:51:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10062026/10/11 06:51:12 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1007=== CONT TestGenerateLandingPage1008--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.90s)1009--- PASS: TestReadProxyContentNegotiation (1.82s)1010=== CONT TestPendingCleanupUsesOneCutoff1011=== CONT TestTombstonedObjectOfferedWithoutWaiting1012--- PASS: TestGenerateLandingPage (0.01s)1013--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.31s)1014=== CONT TestLeadElectsOneAndHandsOver10152026/10/11 06:51:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10162026/10/11 06:51:12 INFO Received uploads request method=POST path=/api/pending_closures10172026/10/11 06:51:12 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLjA2NjE3ZTFkLTRlZDAtNDE3Yi1iNDBjLWIwNzY3NGRiOWQ3MXgxNzkxNzAxNDcyMDU4NzY4MDYw parts=1210182026/10/11 06:51:12 INFO Received uploads request method=POST path=/api/pending_closures1019--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.92s)1020=== CONT TestMultipartCleanup1021=== NAME TestNARDeduplicationMetadataUploadBug1022 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2941709702/001/store/j50143axyd5i7bjbq6nq0p2ypcirbnq0-file1.txt1023--- PASS: TestReconnectLeavesObjectsUnlocked (0.62s)1024=== CONT TestServerTLSConfig1025=== RUN TestServerTLSConfig/no_client_CA1026=== PAUSE TestServerTLSConfig/no_client_CA1027=== RUN TestServerTLSConfig/missing_CA_file1028=== PAUSE TestServerTLSConfig/missing_CA_file1029=== RUN TestServerTLSConfig/not_a_PEM_file1030=== PAUSE TestServerTLSConfig/not_a_PEM_file1031=== CONT TestRedundantMultipartUpload10322026/10/11 06:51:12 INFO Aborted multipart uploads count=0 kept=010332026/10/11 06:51:12 INFO Received uploads request method=POST path=/api/pending_closures10342026/10/11 06:51:12 WARN Force mode enabled - objects will be deleted immediately without grace period1035=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1036--- PASS: TestReadRedirectKeepsNarinfoProxied (0.56s)10372026/10/11 06:51:12 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010382026/10/11 06:51:12 INFO Vacuumed table table=pending_closures10392026/10/11 06:51:12 INFO Vacuumed table table=pending_objects10402026/10/11 06:51:12 INFO Vacuumed table table=multipart_uploads10412026/10/11 06:51:12 INFO Vacuumed table table=closures10422026/10/11 06:51:12 INFO Vacuumed table table=objects1043=== CONT TestPush_RootsAreLockedInByteOrder1044--- PASS: TestService_healthCheckHandler (0.53s)10452026/10/11 06:51:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1046--- PASS: TestSweepRechecksPendingAfterLocking (0.79s)1047=== CONT TestResolveDBConnectionString1048=== RUN TestResolveDBConnectionString/flag_wins1049=== PAUSE TestResolveDBConnectionString/flag_wins1050=== RUN TestResolveDBConnectionString/file_when_flag_empty1051=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1052=== RUN TestResolveDBConnectionString/missing_file_is_an_error1053=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1054=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1055=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1056=== RUN TestResolveDBConnectionString/nothing_configured1057=== PAUSE TestResolveDBConnectionString/nothing_configured1058=== CONT TestReadProxyNarStreaming1059--- PASS: TestService_ReadScope_PublicByDefault (0.94s)1060=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock10612026/10/11 06:51:12 INFO Received push request method=POST path=/api/pushes10622026/10/11 06:51:12 INFO Received push request method=POST path=/api/pushes10632026/10/11 06:51:12 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10642026/10/11 06:51:12 INFO Uploading j50143axyd5i7bjbq6nq0p2ypcirbnq0-file1.txt (160B)10652026/10/11 06:51:12 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLmUyMjVkODIwLTRhN2MtNGY1Zi1iNzA0LTUxMTY5ODA1Yjg1MHgxNzkxNzAxNDcyMzA0OTY5MzAy parts=101066=== RUN TestPush_RejectsBadRequests/no_roots1067=== PAUSE TestPush_RejectsBadRequests/no_roots1068=== RUN TestPush_RejectsBadRequests/no_objects1069=== PAUSE TestPush_RejectsBadRequests/no_objects1070=== RUN TestPush_RejectsBadRequests/bad_root1071=== PAUSE TestPush_RejectsBadRequests/bad_root1072=== RUN TestPush_RejectsBadRequests/root_not_in_objects1073=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1074=== CONT TestGetExistingObjectsLocksRows10752026/10/11 06:51:12 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"10762026/10/11 06:51:12 WARN Failed to register uploaded object key=j50143axyd5i7bjbq6nq0p2ypcirbnq0.ls error="server returned 404: 404 page not found\n"10772026/10/11 06:51:12 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10782026/10/11 06:51:12 INFO Signed narinfos id=1 count=110792026/10/11 06:51:12 INFO Uploading 1 narinfos10802026/10/11 06:51:12 INFO Received complete push request method=POST path=/api/pushes/1/complete10812026/10/11 06:51:12 WARN Failed to register uploaded object key=j50143axyd5i7bjbq6nq0p2ypcirbnq0.narinfo error="server returned 404: 404 page not found\n"10822026/10/11 06:51:12 INFO Completed push id=1 objects=3 duration=6.7791ms10832026/10/11 06:51:12 INFO Upload complete. (91ms)1084=== NAME TestNARDeduplicationMetadataUploadBug1085 metadata_upload_test.go:54: Retrieved narinfo from S3:1086 StorePath: /build/TestNARDeduplicationMetadataUploadBug2941709702/001/store/j50143axyd5i7bjbq6nq0p2ypcirbnq0-file1.txt1087 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1088 Compression: zstd1089 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1090 NarSize: 1601091 References: 1092 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1093--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (1.03s)1094=== CONT TestReadProxyHead1095=== NAME TestNARDeduplicationMetadataUploadBug1096 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1097 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1098 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}10992026/10/11 06:51:12 INFO lead: released remote=192.0.2.1:12341100=== CONT TestDeleteClosuresRacingPins1101--- PASS: TestLeadEndsOnShutdown (2.16s)1102=== NAME TestNARDeduplicationMetadataUploadBug1103 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2941709702/001/store/yhlvzy4xi121y25rv03db7f09l185gy3-file2.txt11042026/10/11 06:51:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11052026/10/11 06:51:13 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLjI5YjM4NWFmLTIyNjctNGRmOC1iYTkyLThjZTIxYjQyMjc2NXgxNzkxNzAxNDcyNzE2MzU2MTI41106--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.06s)1107=== CONT TestIsValidUploadKey1108=== RUN TestIsValidUploadKey/narinfo1109=== PAUSE TestIsValidUploadKey/narinfo1110=== RUN TestIsValidUploadKey/nar_zst1111=== PAUSE TestIsValidUploadKey/nar_zst1112=== RUN TestIsValidUploadKey/nar_xz1113=== PAUSE TestIsValidUploadKey/nar_xz1114=== RUN TestIsValidUploadKey/nar_plain1115=== PAUSE TestIsValidUploadKey/nar_plain1116=== RUN TestIsValidUploadKey/listing1117=== PAUSE TestIsValidUploadKey/listing1118=== RUN TestIsValidUploadKey/build_log1119=== PAUSE TestIsValidUploadKey/build_log1120=== RUN TestIsValidUploadKey/build_log_home-manager_file1121=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1122=== RUN TestIsValidUploadKey/build_log_plus_in_name1123=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1124=== RUN TestIsValidUploadKey/build_log_question_mark1125=== PAUSE TestIsValidUploadKey/build_log_question_mark1126=== RUN TestIsValidUploadKey/build_log_equals1127=== PAUSE TestIsValidUploadKey/build_log_equals1128=== RUN TestIsValidUploadKey/realisation1129=== PAUSE TestIsValidUploadKey/realisation1130=== RUN TestIsValidUploadKey/realisation_plus_in_output1131=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1132=== RUN TestIsValidUploadKey/nix-cache-info1133=== PAUSE TestIsValidUploadKey/nix-cache-info1134=== RUN TestIsValidUploadKey/index.html1135=== PAUSE TestIsValidUploadKey/index.html1136=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1137=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1138=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1139=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1140=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1141=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1142=== RUN TestIsValidUploadKey/traversal1143=== PAUSE TestIsValidUploadKey/traversal1144=== RUN TestIsValidUploadKey/traversal_nar1145=== PAUSE TestIsValidUploadKey/traversal_nar1146=== RUN TestIsValidUploadKey/absolute1147=== PAUSE TestIsValidUploadKey/absolute1148=== RUN TestIsValidUploadKey/empty_key1149=== PAUSE TestIsValidUploadKey/empty_key1150=== RUN TestIsValidUploadKey/unknown_type1151=== PAUSE TestIsValidUploadKey/unknown_type1152=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit11532026/10/11 06:51:13 INFO lead: acquired remote=192.0.2.1:123411542026/10/11 06:51:13 INFO Received uploads request method=POST path=/api/pending_closures11552026/10/11 06:51:13 INFO Received uploads request method=POST path=/api/pending_closures11562026/10/11 06:51:13 INFO Received uploads request method=POST path=/api/pending_closures11572026/10/11 06:51:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11582026/10/11 06:51:13 INFO Received cleanup request method=DELETE path=/api/pending_closures11592026/10/11 06:51:13 INFO Received uploads request method=POST path=/api/pending_closures11602026/10/11 06:51:13 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLjI5YjM4NWFmLTIyNjctNGRmOC1iYTkyLThjZTIxYjQyMjc2NXgxNzkxNzAxNDcyNzE2MzU2MTI4 error="Delete \"http://localhost:37235/bucket30/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLjI5YjM4NWFmLTIyNjctNGRmOC1iYTkyLThjZTIxYjQyMjc2NXgxNzkxNzAxNDcyNzE2MzU2MTI4\": injected: abort refused"11612026/10/11 06:51:13 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLjVjOTJjNGQ2LTBkOGYtNGE1MC1iZDczLWUxNDFhZDU5NjVlM3gxNzkxNzAxNDcyNjI0NTYxOTU0 parts=1011622026/10/11 06:51:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11632026/10/11 06:51:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11642026/10/11 06:51:13 INFO Completed upload id=1 objects=2 duration=3.645352ms1165--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.48s)1166=== CONT TestFailedS3DeleteKeepsTombstone11672026/10/11 06:51:13 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011682026/10/11 06:51:13 INFO Received uploads request method=POST path=/api/pending_closures11692026/10/11 06:51:13 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLjI5YjM4NWFmLTIyNjctNGRmOC1iYTkyLThjZTIxYjQyMjc2NXgxNzkxNzAxNDcyNzE2MzU2MTI411702026/10/11 06:51:13 INFO Starting cleanup of old closures method=DELETE path=/api/closures11712026/10/11 06:51:13 INFO Received uploads request method=POST path=/api/pending_closures11722026/10/11 06:51:13 INFO Aborted multipart uploads count=0 kept=011732026/10/11 06:51:13 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLjI5YjM4NWFmLTIyNjctNGRmOC1iYTkyLThjZTIxYjQyMjc2NXgxNzkxNzAxNDcyNzE2MzU2MTI4 parts=111742026/10/11 06:51:13 INFO Received uploads request method=POST path=/api/pending_closures11752026/10/11 06:51:13 INFO Received push request method=POST path=/api/pushes1176=== CONT TestGCTaskStore_CompletedAllowsNewTask1177--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.10s)1178=== CONT TestClientFallsBackToClosures1179--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)11802026/10/11 06:51:13 INFO Received uploads request method=POST path=/api/pending_closures11812026/10/11 06:51:13 INFO Received cleanup request method=DELETE path=/api/pending_closures11822026/10/11 06:51:13 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket46/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11832026/10/11 06:51:13 INFO Aborted multipart uploads count=0 kept=11184=== CONT TestForceGCDuringPushOffersSweptObject1185--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.41s)1186=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1187=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1188=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1189=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1190=== CONT TestSweepSkipsRowsLockedByPush11912026/10/11 06:51:13 INFO Received cleanup request method=DELETE path=/api/pending_closures11922026/10/11 06:51:13 INFO Aborted multipart uploads count=1 kept=01193=== CONT TestGCTaskStore_PhaseUpdates1194--- PASS: TestReadProxyNarStreaming (0.38s)1195=== CONT TestGCTaskStore_Fail1196--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1197--- PASS: TestGCTaskStore_Fail (0.00s)1198=== CONT TestPush_RepeatedRootCommitsOnce1199--- PASS: TestMultipartCleanup (0.54s)1200=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT12012026/10/11 06:51:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12022026/10/11 06:51:13 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=012032026/10/11 06:51:13 INFO Vacuumed table table=pending_closures12042026/10/11 06:51:13 INFO Vacuumed table table=pending_objects12052026/10/11 06:51:13 INFO Vacuumed table table=multipart_uploads12062026/10/11 06:51:13 INFO Vacuumed table table=closures12072026/10/11 06:51:13 INFO Vacuumed table table=objects12082026/10/11 06:51:13 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLjE1NmFlMGYzLWZhZjktNDIyZi05ZWQ2LWM3MGQzZjI5ZGZhMngxNzkxNzAxNDcyODUyMDM1OTMw parts=1012092026/10/11 06:51:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12102026/10/11 06:51:13 INFO Completed upload id=1 objects=2 duration=3.322029ms1211=== NAME TestOrphanedObjectsGC1212 orphaned_objects_gc_test.go:287: GC Test Summary:1213 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1214 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1215 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)12162026/10/11 06:51:13 INFO Received uploads request method=POST path=/api/pending_closures1217 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1218 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects12192026/10/11 06:51:13 INFO Received uploads request method=POST path=/api/pending_closures12202026/10/11 06:51:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12212026/10/11 06:51:13 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012222026/10/11 06:51:13 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo12232026/10/11 06:51:13 WARN Found objects in DB but missing from S3, will re-upload count=112242026/10/11 06:51:13 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete12252026/10/11 06:51:13 INFO Completed upload id=3 objects=2 duration=1.802376ms12262026/10/11 06:51:13 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLjE2ZDI3ZmUyLWFhNmEtNGNjZS1iZDkzLTM3NDVlOGZlZGJiMXgxNzkxNzAxNDcyMzAzNzkzMjcy parts=1012272026/10/11 06:51:13 INFO Received complete push request method=POST path=/api/pushes/1/complete1228--- PASS: TestOrphanedObjectsGC (1.43s)1229=== CONT TestReadProxy4041230--- PASS: TestService_createPendingClosureHandler (1.59s)1231=== CONT TestConnectSerialisesConcurrentMigrations12322026/10/11 06:51:13 INFO Completed push id=1 objects=4 duration=6.811621ms12332026/10/11 06:51:13 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12342026/10/11 06:51:13 INFO Completed upload id=2 objects=2 duration=1.333612ms1235--- PASS: TestService_verifyS3Integrity (1.54s)1236=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1237=== CONT TestUploadHandlersRejectInvalidKeys1238--- PASS: TestMetricsCommit (2.70s)1239=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1240=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1241=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1242=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1243=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1244=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1245=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1246=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1247=== CONT TestGCSweepSkipsPendingObjects12482026/10/11 06:51:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12492026/10/11 06:51:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12502026/10/11 06:51:13 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLjM3ZGI5YzQwLWYzYTMtNGZjOC04MTlkLTYwNzZhMjM3YTFiMHgxNzkxNzAxNDczMTc5MTUwNTI5 parts=1212512026/10/11 06:51:13 INFO Received uploads request method=POST path=/api/pending_closures12522026/10/11 06:51:13 INFO Received uploads request method=POST path=/api/pending_closures12532026-10-11 06:51:14.083 UTC [844] ERROR: duplicate key value violates unique constraint "pg_type_typname_nsp_index"12542026-10-11 06:51:14.083 UTC [844] DETAIL: Key (typname, typnamespace)=(goose_db_version, 2200) already exists.12552026-10-11 06:51:14.083 UTC [844] STATEMENT: CREATE TABLE goose_db_version (1256 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1257 version_id bigint NOT NULL,1258 is_applied boolean NOT NULL,1259 tstamp timestamp NOT NULL DEFAULT now()1260 )12612026/10/11 06:51:14 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLjczZTM0ODBjLWYxMGYtNDg2ZC04NGUyLTM2NGUwODZmMmVkMXgxNzkxNzAxNDczMjA2MjcxNjY5 parts=1012622026/10/11 06:51:14 INFO Received push request method=POST path=/api/pushes12632026/10/11 06:51:14 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12642026/10/11 06:51:14 WARN Failed to register uploaded object key=yhlvzy4xi121y25rv03db7f09l185gy3.ls error="server returned 404: 404 page not found\n"12652026/10/11 06:51:14 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12662026/10/11 06:51:14 INFO Signed narinfos id=2 count=112672026/10/11 06:51:14 INFO Uploading 1 narinfos12682026/10/11 06:51:14 INFO Received complete push request method=POST path=/api/pushes/2/complete12692026/10/11 06:51:14 WARN Failed to register uploaded object key=yhlvzy4xi121y25rv03db7f09l185gy3.narinfo error="server returned 404: 404 page not found\n"12702026/10/11 06:51:14 INFO Completed push id=2 objects=3 duration=18.190301ms12712026/10/11 06:51:14 INFO Upload complete. (1.09s)12722026/10/11 06:51:14 INFO Received push request method=POST path=/api/pushes1273=== NAME TestNARDeduplicationMetadataUploadBug1274 metadata_upload_test.go:76: Retrieved narinfo from S3:1275 StorePath: /build/TestNARDeduplicationMetadataUploadBug2941709702/001/store/yhlvzy4xi121y25rv03db7f09l185gy3-file2.txt1276 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1277 Compression: zstd1278 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1279 NarSize: 1601280 References: 1281 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1282 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1283 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1284 {"version":1,"root":{"type":"regular","size":44}}12852026/10/11 06:51:14 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)12862026/10/11 06:51:14 INFO Uploading snd4nry3gz29c0bwril7d1rk2k19nf0c-shared-dep (136B)12872026/10/11 06:51:14 INFO Uploading 4plrxqpmlc6jgk5nm6dgnwzhadmn14py-top (224B)12882026/10/11 06:51:14 WARN Failed to register uploaded object key=nar/1n66qk4v6gba03mpxb8f79xhc1ld8zzx8gg6fq3rpb43xzwrvrcn.nar.zst error="server returned 404: 404 page not found\n"12892026/10/11 06:51:14 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12902026/10/11 06:51:14 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12912026/10/11 06:51:14 WARN Failed to register uploaded object key=4plrxqpmlc6jgk5nm6dgnwzhadmn14py.ls error="server returned 404: 404 page not found\n"12922026/10/11 06:51:14 WARN Failed to register uploaded object key=snd4nry3gz29c0bwril7d1rk2k19nf0c.ls error="server returned 404: 404 page not found\n"1293--- PASS: TestNARDeduplicationMetadataUploadBug (3.41s)1294=== CONT TestPushWaitsForSweepHoldingRow12952026/10/11 06:51:14 INFO Signed narinfos id=1 count=212962026/10/11 06:51:14 INFO Uploading 2 narinfos1297--- PASS: TestGetExistingObjectsLocksRows (1.31s)1298=== CONT TestDeduplicatedObjectsRecordedAsPending12992026/10/11 06:51:14 INFO Received complete push request method=POST path=/api/pushes/1/complete13002026/10/11 06:51:14 WARN Failed to register uploaded object key=snd4nry3gz29c0bwril7d1rk2k19nf0c.narinfo error="server returned 404: 404 page not found\n"13012026/10/11 06:51:14 WARN Failed to register uploaded object key=4plrxqpmlc6jgk5nm6dgnwzhadmn14py.narinfo error="server returned 404: 404 page not found\n"13022026/10/11 06:51:14 INFO Completed push id=1 objects=6 duration=14.595049ms13032026/10/11 06:51:14 INFO Upload complete. (189ms)1304=== NAME TestClientSharedPathCommittedMidPush1305 client_integration_test.go:816: Retrieved narinfo from S3:1306 StorePath: /build/TestClientSharedPathCommittedMidPush1676978983/001/store/snd4nry3gz29c0bwril7d1rk2k19nf0c-shared-dep1307 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1308 Compression: zstd1309 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821310 NarSize: 1361311 References: 1312 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1313 client_integration_test.go:816: Retrieved narinfo from S3:1314 StorePath: /build/TestClientSharedPathCommittedMidPush1676978983/001/store/4plrxqpmlc6jgk5nm6dgnwzhadmn14py-top1315 URL: nar/1n66qk4v6gba03mpxb8f79xhc1ld8zzx8gg6fq3rpb43xzwrvrcn.nar.zst1316 Compression: zstd1317 NarHash: sha256:1n66qk4v6gba03mpxb8f79xhc1ld8zzx8gg6fq3rpb43xzwrvrcn1318 NarSize: 2241319 References: /build/TestClientSharedPathCommittedMidPush1676978983/001/store/snd4nry3gz29c0bwril7d1rk2k19nf0c-shared-dep1320 CA: text:sha256:0wl54lw6r8c8zvs7bzhn8vi352gix2vwqlbp4z8zffq2nfklvhc51321--- PASS: TestClientSharedPathCommittedMidPush (2.39s)1322=== CONT TestPushDedupSurvivesConcurrentGC13232026/10/11 06:51:14 INFO Aborted multipart uploads count=0 kept=013242026/10/11 06:51:14 INFO Received push request method=POST path=/api/pushes13252026/10/11 06:51:14 WARN Force mode enabled - objects will be deleted immediately without grace period13262026/10/11 06:51:14 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=013272026/10/11 06:51:14 INFO Vacuumed table table=pending_closures13282026/10/11 06:51:14 INFO Vacuumed table table=pending_objects13292026/10/11 06:51:14 INFO Vacuumed table table=multipart_uploads13302026/10/11 06:51:14 INFO Vacuumed table table=closures13312026/10/11 06:51:14 INFO lead: released remote=192.0.2.1:123413322026/10/11 06:51:14 INFO Vacuumed table table=objects13332026/10/11 06:51:14 INFO Received push request method=POST path=/api/pushes13342026/10/11 06:51:14 INFO Aborted multipart uploads count=0 kept=013352026/10/11 06:51:14 WARN Force mode enabled - objects will be deleted immediately without grace period13362026/10/11 06:51:14 INFO lead: acquired remote=192.0.2.1:123413372026/10/11 06:51:14 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=013382026/10/11 06:51:14 INFO Vacuumed table table=pending_closures13392026/10/11 06:51:14 INFO Vacuumed table table=pending_objects13402026/10/11 06:51:14 INFO Vacuumed table table=multipart_uploads13412026/10/11 06:51:14 INFO Vacuumed table table=closures13422026/10/11 06:51:14 INFO Vacuumed table table=objects13432026/10/11 06:51:14 INFO Received uploads request method=POST path=/api/pending_closures1344--- PASS: TestSweepSkipsRowsLockedByPush (1.17s)1345=== CONT TestUploadHandlersRejectOversizedBody13462026/10/11 06:51:14 INFO Received uploads request method=POST path=/api/pending_closures1347--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.18s)1348=== CONT TestGCSweepDeliversEachKeyOnce13492026/10/11 06:51:14 INFO Received uploads request method=POST path=/api/pending_closures13502026/10/11 06:51:14 INFO Received uploads request method=POST path=/api/pending_closures13512026/10/11 06:51:14 INFO Aborted multipart uploads count=0 kept=013522026/10/11 06:51:14 INFO Received uploads request method=POST path=/api/pending_closures1353--- PASS: TestReadProxyHead (1.60s)1354=== CONT TestService_cleanupPendingClosuresHandler13552026/10/11 06:51:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13562026/10/11 06:51:14 INFO Received uploads request method=POST path=/api/pending_closures13572026/10/11 06:51:14 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLjU1MmZkYmU1LTA4NWMtNGU2Ni1hZTEwLTUxNGE5MzIyNzUwYXgxNzkxNzAxNDczODY1Nzg2OTE2 error="Get \"http://127.0.0.1:1/bucket47/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"13582026/10/11 06:51:14 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLmY0MWE0Y2ViLTA4ZTQtNDU1Yy05MmQ5LWNhZTg4MTUzYjlkYXgxNzkxNzAxNDczODUxNjQ1MzUx parts=1213592026/10/11 06:51:14 INFO Aborted multipart uploads count=0 kept=013602026/10/11 06:51:14 INFO Received cleanup request method=DELETE path=/api/pending_closures1361--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.36s)1362=== CONT TestClientPushesUseOnePush13632026/10/11 06:51:14 INFO Aborted multipart uploads count=1 kept=01364=== CONT TestReadRedirectUsesPublicS3URL1365--- PASS: TestRedundantMultipartUpload (1.82s)1366=== NAME TestOrphanedObjectsGCStressTest1367 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains13682026/10/11 06:51:14 WARN Rate limiter enabled after throttle name=s3-test rate=513692026/10/11 06:51:14 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."13702026/10/11 06:51:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1371--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (1.21s)1372=== CONT TestGCTaskStore_GetEmpty1373=== CONT TestGCMetrics1374--- PASS: TestGCTaskStore_GetEmpty (0.00s)13752026/10/11 06:51:14 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLjc0NThkNzc2LTQ5ZjMtNDU3OC1hMjA1LTA2ZWU0ZDQ3MjFlM3gxNzkxNzAxNDczMjA2NDc0NzUx parts=1013762026/10/11 06:51:14 WARN Rate limiter backed off name=s3-test rate=513772026/10/11 06:51:14 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."1378--- PASS: TestReadProxy404 (1.27s)1379=== CONT TestReadProxyInvalidPath1380=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1381=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1382=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1383=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1384=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1385=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1386=== CONT TestCommitRacingPendingCleanupKeepsObjects13872026/10/11 06:51:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1388--- PASS: TestReadProxyInvalidPath (0.21s)1389=== CONT TestClientWithDependencies13902026/10/11 06:51:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13912026/10/11 06:51:15 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLjI3YWNhZjlmLWJlNzUtNDY2Mi04ZjM0LWJiNTk4ZGM0YmRiY3gxNzkxNzAxNDc0MzU3NDQ4NjUz parts=1013922026/10/11 06:51:15 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLmVkNjI0ZGVjLWU0ODEtNGY3OC05NzI4LWIxYjVkNmE3ZDFjN3gxNzkxNzAxNDc0MzgxMjMwNDQ0 parts=101393--- PASS: TestPushWaitsForSweepHoldingRow (0.83s)1394=== CONT TestPush_CompleteCommitsEveryRoot1395=== CONT TestGCTaskStore_DeduplicateSameParams1396--- PASS: TestConnectSerialisesConcurrentMigrations (1.61s)1397=== CONT TestPresentNotReportedWhileGCDeletesClosure1398=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1399--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1400=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1401=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1402=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1403=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle14042026/10/11 06:51:15 INFO Aborted multipart uploads count=0 kept=014052026/10/11 06:51:15 WARN Force mode enabled - objects will be deleted immediately without grace period14062026/10/11 06:51:15 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=014072026/10/11 06:51:15 INFO Vacuumed table table=pending_closures14082026/10/11 06:51:15 INFO Vacuumed table table=pending_objects14092026/10/11 06:51:15 INFO Vacuumed table table=multipart_uploads14102026/10/11 06:51:15 INFO Vacuumed table table=closures14112026/10/11 06:51:15 INFO Vacuumed table table=objects1412=== CONT TestPresentRefreshesOnlyStaleClosures1413--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.36s)1414=== NAME TestClientWithDependencies1415 client_integration_test.go:735: Built derivation: /build/TestClientWithDependencies2013310189/001/store/0a5rdr2f2kzfw8b5qww2kvj0dshhsk71-test-script14162026/10/11 06:51:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14172026/10/11 06:51:15 INFO Received uploads request method=POST path=/api/pending_closures14182026/10/11 06:51:15 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLmM1NGRkYTk4LTNiYjAtNGM0ZS04NmQ0LWJlYjAyNDAwOWJkMHgxNzkxNzAxNDczMjA1OTg5MzY3 parts=101419 client_integration_test.go:737: Found 1 dependencies (including self)14202026/10/11 06:51:15 INFO Received push request method=POST path=/api/pushes14212026/10/11 06:51:15 WARN Force mode enabled - objects will be deleted immediately without grace period14222026/10/11 06:51:15 WARN Force mode enabled - objects will be deleted immediately without grace period14232026/10/11 06:51:15 INFO Received uploads request method=POST path=/api/pending_closures14242026/10/11 06:51:15 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=014252026/10/11 06:51:15 INFO Vacuumed table table=pending_closures1426=== NAME TestOrphanedObjectsGCStressTest1427 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion14282026/10/11 06:51:15 INFO Vacuumed table table=pending_objects14292026/10/11 06:51:15 INFO Vacuumed table table=multipart_uploads14302026/10/11 06:51:15 INFO Vacuumed table table=closures14312026/10/11 06:51:15 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."14322026/10/11 06:51:15 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."14332026/10/11 06:51:15 INFO Vacuumed table table=objects14342026/10/11 06:51:15 INFO Received uploads request method=POST path=/api/pending_closures1435--- PASS: TestFailedS3DeleteKeepsTombstone (2.21s)1436=== CONT TestService_RequireScope_OIDC14372026/10/11 06:51:15 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14382026/10/11 06:51:15 INFO Uploading va945jhidyl0np98xcjwyjb0n49wsmf7-b (216B)14392026/10/11 06:51:15 INFO Uploading spm63mrxi27rpq3nimmgmpibpvcvsrn6-shared-dep (136B)1440=== CONT TestGCEndsOnShutdown1441=== RUN TestGCEndsOnShutdown/before_the_run1442--- PASS: TestGCSweepSkipsPendingObjects (1.84s)1443=== PAUSE TestGCEndsOnShutdown/before_the_run1444=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1445=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1446=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1447=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1448=== CONT TestClientIntegration14492026/10/11 06:51:15 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14502026/10/11 06:51:15 WARN Failed to register uploaded object key=spm63mrxi27rpq3nimmgmpibpvcvsrn6.ls error="server returned 404: 404 page not found\n"14512026/10/11 06:51:15 WARN Failed to register uploaded object key=fm88xy28grch3n5h6h3h617hxws94yb2.ls error="server returned 404: 404 page not found\n"14522026/10/11 06:51:15 WARN Failed to register uploaded object key=nar/08d6qg5pjk106syrdj82p83gmazh3wn2mpjbn4qnmcvir4bn84q4.nar.zst error="server returned 404: 404 page not found\n"14532026/10/11 06:51:15 WARN Failed to register uploaded object key=va945jhidyl0np98xcjwyjb0n49wsmf7.ls error="server returned 404: 404 page not found\n"14542026/10/11 06:51:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14552026/10/11 06:51:15 INFO Signed narinfos id=1 count=214562026/10/11 06:51:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14572026/10/11 06:51:15 INFO Signed narinfos id=2 count=214582026/10/11 06:51:15 INFO Uploading 4 narinfos14592026/10/11 06:51:15 WARN Failed to register uploaded object key=va945jhidyl0np98xcjwyjb0n49wsmf7.narinfo error="server returned 404: 404 page not found\n"14602026/10/11 06:51:15 WARN Failed to register uploaded object key=spm63mrxi27rpq3nimmgmpibpvcvsrn6.narinfo error="server returned 404: 404 page not found\n"14612026/10/11 06:51:15 WARN Failed to register uploaded object key=fm88xy28grch3n5h6h3h617hxws94yb2.narinfo error="server returned 404: 404 page not found\n"14622026/10/11 06:51:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14632026/10/11 06:51:15 INFO Aborted multipart uploads count=0 kept=01464--- PASS: TestPresentRefreshesOnlyStaleClosures (0.26s)14652026/10/11 06:51:15 WARN Failed to register uploaded object key=spm63mrxi27rpq3nimmgmpibpvcvsrn6.narinfo error="server returned 404: 404 page not found\n"1466=== CONT TestPendingClosureWriteTimeout1467=== RUN TestPendingClosureWriteTimeout/empty1468=== PAUSE TestPendingClosureWriteTimeout/empty1469=== RUN TestPendingClosureWriteTimeout/400_objects1470=== PAUSE TestPendingClosureWriteTimeout/400_objects1471=== RUN TestPendingClosureWriteTimeout/670k_objects1472=== PAUSE TestPendingClosureWriteTimeout/670k_objects1473=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1474=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1475=== CONT TestClientMultipleUploads14762026/10/11 06:51:15 INFO Completed upload id=1 objects=6 duration=10.566694ms14772026/10/11 06:51:15 WARN Force mode enabled - objects will be deleted immediately without grace period14782026/10/11 06:51:15 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14792026/10/11 06:51:15 INFO Completed upload id=2 objects=6 duration=2.202519ms14802026/10/11 06:51:15 INFO Upload complete. (1.118s)14812026/10/11 06:51:15 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=01482=== NAME TestClientFallsBackToClosures1483 client_pushes_test.go:112: Retrieved narinfo from S3:1484 StorePath: /build/TestClientFallsBackToClosures1964123214/001/store/spm63mrxi27rpq3nimmgmpibpvcvsrn6-shared-dep1485 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1486 Compression: zstd1487 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821488 NarSize: 1361489 References: 1490 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n14912026/10/11 06:51:15 INFO lead: released remote=192.0.2.1:123414922026/10/11 06:51:15 INFO Vacuumed table table=pending_closures14932026/10/11 06:51:15 INFO Vacuumed table table=pending_objects14942026/10/11 06:51:15 INFO Vacuumed table table=multipart_uploads14952026/10/11 06:51:15 INFO Vacuumed table table=closures14962026/10/11 06:51:15 INFO Vacuumed table table=objects1497 client_pushes_test.go:112: Retrieved narinfo from S3:1498 StorePath: /build/TestClientFallsBackToClosures1964123214/001/store/fm88xy28grch3n5h6h3h617hxws94yb2-a1499 URL: nar/08d6qg5pjk106syrdj82p83gmazh3wn2mpjbn4qnmcvir4bn84q4.nar.zst1500 Compression: zstd1501 NarHash: sha256:08d6qg5pjk106syrdj82p83gmazh3wn2mpjbn4qnmcvir4bn84q41502 NarSize: 2161503 References: /build/TestClientFallsBackToClosures1964123214/001/store/spm63mrxi27rpq3nimmgmpibpvcvsrn6-shared-dep1504 CA: text:sha256:0i87md9agn61z79a8yhb8pc4pddn04ly2lr1mdbnxq4z7aq5zn6i1505 client_pushes_test.go:112: Retrieved narinfo from S3:1506 StorePath: /build/TestClientFallsBackToClosures1964123214/001/store/va945jhidyl0np98xcjwyjb0n49wsmf7-b1507 URL: nar/08d6qg5pjk106syrdj82p83gmazh3wn2mpjbn4qnmcvir4bn84q4.nar.zst1508 Compression: zstd1509 NarHash: sha256:08d6qg5pjk106syrdj82p83gmazh3wn2mpjbn4qnmcvir4bn84q41510 NarSize: 2161511 References: /build/TestClientFallsBackToClosures1964123214/001/store/spm63mrxi27rpq3nimmgmpibpvcvsrn6-shared-dep1512 CA: text:sha256:0i87md9agn61z79a8yhb8pc4pddn04ly2lr1mdbnxq4z7aq5zn6i15132026/10/11 06:51:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1514--- PASS: TestLeadElectsOneAndHandsOver (2.81s)1515=== CONT TestPush_CompleteWaitsForCleanupOfThePush15162026/10/11 06:51:15 INFO Received push request method=POST path=/api/pushes15172026/10/11 06:51:15 INFO Aborted multipart uploads count=0 kept=015182026/10/11 06:51:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15192026/10/11 06:51:15 INFO Uploading 0a5rdr2f2kzfw8b5qww2kvj0dshhsk71-test-script (136B)1520=== CONT TestPresentReportsOnlyClosureRoots1521--- PASS: TestClientFallsBackToClosures (2.32s)15222026/10/11 06:51:15 WARN Failed to register uploaded object key=log/qqqclivvfjih625kp400q4ljw2rl64zz-test-script.drv error="server returned 404: 404 page not found\n"15232026/10/11 06:51:15 WARN Force mode enabled - objects will be deleted immediately without grace period15242026/10/11 06:51:15 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"1525=== CONT TestGCAdvisoryLockBlocksConcurrentRun1526--- PASS: TestGCMetrics (0.81s)15272026/10/11 06:51:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15282026/10/11 06:51:15 WARN Failed to register uploaded object key=0a5rdr2f2kzfw8b5qww2kvj0dshhsk71.ls error="server returned 404: 404 page not found\n"15292026/10/11 06:51:15 INFO Signed narinfos id=1 count=115302026/10/11 06:51:15 INFO Uploading 1 narinfos15312026/10/11 06:51:15 INFO Received complete push request method=POST path=/api/pushes/1/complete15322026/10/11 06:51:15 WARN Failed to register uploaded object key=0a5rdr2f2kzfw8b5qww2kvj0dshhsk71.narinfo error="server returned 404: 404 page not found\n"15332026/10/11 06:51:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15342026/10/11 06:51:15 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=015352026/10/11 06:51:15 INFO Completed push id=1 objects=4 duration=9.647585ms15362026/10/11 06:51:15 INFO Upload complete. (140ms)15372026/10/11 06:51:15 INFO Vacuumed table table=pending_closures15382026/10/11 06:51:15 INFO Vacuumed table table=pending_objects15392026/10/11 06:51:15 INFO Vacuumed table table=multipart_uploads15402026/10/11 06:51:15 INFO Vacuumed table table=closures15412026/10/11 06:51:15 INFO Vacuumed table table=objects15422026/10/11 06:51:15 INFO Aborted multipart uploads count=0 kept=015432026/10/11 06:51:15 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLjk4NmQ4NjMzLTlkOTMtNDZiZi1hMzIyLWNlMGRlZDEyYzk4MXgxNzkxNzAxNDc0MzU1MjA1MTM0 parts=1015442026/10/11 06:51:15 INFO Received complete push request method=POST path=/api/pushes/1/complete15452026/10/11 06:51:15 WARN Force mode enabled - objects will be deleted immediately without grace period1546--- PASS: TestGCSweepDeliversEachKeyOnce (1.10s)1547=== CONT TestGCBugBareHashReferences15482026/10/11 06:51:15 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=015492026/10/11 06:51:15 INFO Completed push id=1 objects=4 duration=9.087041ms15502026/10/11 06:51:15 INFO Received push request method=POST path=/api/pushes15512026/10/11 06:51:15 INFO Vacuumed table table=pending_closures15522026/10/11 06:51:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15532026/10/11 06:51:15 INFO Vacuumed table table=pending_objects15542026/10/11 06:51:15 INFO Vacuumed table table=multipart_uploads15552026/10/11 06:51:15 INFO Vacuumed table table=closures15562026/10/11 06:51:15 INFO Vacuumed table table=objects1557=== NAME TestClientWithDependencies1558 client_integration_test.go:753: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2013310189/001/store) requires matching store prefix15592026/10/11 06:51:15 INFO Received uploads request method=POST path=/api/pending_closures1560=== CONT TestGCTaskStore_GetReturnsLatest1561--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (2.73s)1562=== CONT TestClientErrorHandling1563--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1564=== RUN TestClientErrorHandling/InvalidStorePath1565=== PAUSE TestClientErrorHandling/InvalidStorePath1566=== RUN TestClientErrorHandling/InvalidAuthToken1567=== PAUSE TestClientErrorHandling/InvalidAuthToken1568=== RUN TestClientErrorHandling/ServerNotAvailable1569=== PAUSE TestClientErrorHandling/ServerNotAvailable1570=== CONT TestParseSingleRange1571=== RUN TestParseSingleRange/none1572=== PAUSE TestParseSingleRange/none1573=== RUN TestParseSingleRange/unknown_unit1574=== PAUSE TestParseSingleRange/unknown_unit1575=== RUN TestParseSingleRange/multi-range_ignored1576=== PAUSE TestParseSingleRange/multi-range_ignored1577=== RUN TestParseSingleRange/malformed_no_dash1578=== PAUSE TestParseSingleRange/malformed_no_dash1579=== RUN TestParseSingleRange/malformed_both_empty1580=== PAUSE TestParseSingleRange/malformed_both_empty1581=== RUN TestParseSingleRange/malformed_end_before_start1582=== PAUSE TestParseSingleRange/malformed_end_before_start1583=== RUN TestParseSingleRange/closed1584=== PAUSE TestParseSingleRange/closed1585=== RUN TestParseSingleRange/open-ended1586=== PAUSE TestParseSingleRange/open-ended1587=== RUN TestParseSingleRange/end_clamped_to_size1588=== PAUSE TestParseSingleRange/end_clamped_to_size1589=== RUN TestParseSingleRange/suffix1590=== PAUSE TestParseSingleRange/suffix1591=== RUN TestParseSingleRange/suffix_exceeds_size1592=== PAUSE TestParseSingleRange/suffix_exceeds_size1593=== RUN TestParseSingleRange/single_byte1594=== PAUSE TestParseSingleRange/single_byte1595=== RUN TestParseSingleRange/start_past_EOF1596=== PAUSE TestParseSingleRange/start_past_EOF1597=== RUN TestParseSingleRange/start_far_past_EOF1598=== PAUSE TestParseSingleRange/start_far_past_EOF1599=== CONT TestCacheStatsHandler1600--- PASS: TestClientWithDependencies (0.68s)1601=== CONT TestConcurrentPinUpdatesAgree16022026/10/11 06:51:15 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLjk2MzJlOTRmLTUzYzItNGFkMS05NmMxLTg1ZWQyNzc1MGZkOXgxNzkxNzAxNDc0MzgxNzkyOTA5 parts=1016032026/10/11 06:51:15 INFO Received complete push request method=POST path=/api/pushes/1/complete16042026/10/11 06:51:15 INFO Received cleanup request method=DELETE path=/api/pending_closures16052026/10/11 06:51:15 INFO Completed push id=1 objects=4 duration=8.286234ms16062026/10/11 06:51:15 INFO Aborted multipart uploads count=0 kept=016072026/10/11 06:51:15 INFO Received uploads request method=POST path=/api/pending_closures1608--- PASS: TestReadRedirectUsesPublicS3URL (1.04s)1609=== CONT TestPinProtectsFromGC16102026/10/11 06:51:15 INFO Aborted multipart uploads count=0 kept=01611--- PASS: TestPush_RepeatedRootCommitsOnce (2.42s)1612=== CONT TestCacheConfigHandler1613=== RUN TestCacheConfigHandler/full_config,_no_issuer1614=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1615=== RUN TestCacheConfigHandler/no_cache_url_configured1616=== PAUSE TestCacheConfigHandler/no_cache_url_configured1617=== RUN TestCacheConfigHandler/no_signing_keys1618=== PAUSE TestCacheConfigHandler/no_signing_keys1619=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1620=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1621=== CONT TestReadProxyNarinfo16222026/10/11 06:51:15 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40205/oidc16232026/10/11 06:51:15 INFO Received cleanup request method=DELETE path=/api/pending_closures1624=== NAME TestOrphanedObjectsGCStressTest1625 orphaned_objects_gc_test.go:503: Stress test completed successfully:1626 orphaned_objects_gc_test.go:504: - Active objects preserved: 201627 orphaned_objects_gc_test.go:505: - Objects deleted: 2101628 orphaned_objects_gc_test.go:506: - Total GC'd: 21016292026/10/11 06:51:15 INFO Aborted multipart uploads count=1 kept=016302026/10/11 06:51:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16312026-10-11 06:51:15.721 UTC [1031] ERROR: Closure does not exist: id=116322026-10-11 06:51:15.721 UTC [1031] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE16332026-10-11 06:51:15.721 UTC [1031] STATEMENT: -- name: CommitPendingClosure :one1634 SELECT commit_pending_closure($1::bigint)::bigint1635 16362026/10/11 06:51:15 INFO Aborted multipart uploads count=0 kept=016372026/10/11 06:51:15 WARN Force mode enabled - objects will be deleted immediately without grace period1638--- PASS: TestService_cleanupPendingClosuresHandler (1.16s)1639=== CONT TestService_ReadAuthMiddleware1640--- PASS: TestOrphanedObjectsGCStressTest (4.92s)1641=== CONT TestCreatePinRejectsBadInput16422026/10/11 06:51:15 INFO Received push request method=POST path=/api/pushes1643--- PASS: TestPresentReportsOnlyClosureRoots (0.35s)1644=== CONT TestService_AuthMiddleware_OIDC16452026/10/11 06:51:15 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16462026/10/11 06:51:16 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLjdmNWI5YjdiLTRmMTktNGQ4ZS1hOTY3LWE3NzZmZTRjYTgzZHgxNzkxNzAxNDczMjA2MzkzNzEx parts=1016472026/10/11 06:51:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1648=== CONT TestDeletePinKeepsRowWhenS3Fails1649--- PASS: TestObjectStatsLargeCommit (3.72s)16502026/10/11 06:51:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43347/oidc16512026/10/11 06:51:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16522026/10/11 06:51:16 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLjQ1MWYxYThiLWQyNDEtNDc0YS04YWRmLTNmNWM2MmE0OWU0MngxNzkxNzAxNDc1Nzg5MDY1MjIy parts=1016532026/10/11 06:51:16 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLmRhODg2NDBlLTM0NWQtNDgwOC1iN2Y0LThkZGZiOTZkNzBhMngxNzkxNzAxNDc1MzMzODY2MDA4 parts=1016542026/10/11 06:51:16 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=01655=== NAME TestClientMultipleUploads1656 client_integration_test.go:480: Created store path 0: /build/TestClientMultipleUploads1747657803/001/store/y1q7v5py4na09sisw6xpliyis51vn6jw-test-file-0.txt16572026/10/11 06:51:16 INFO Vacuumed table table=pending_closures1658=== NAME TestClientIntegration1659 client_integration_test.go:334: Created store path: /build/TestClientIntegration1694034200/002/store/2vqmv2inqf9x896zvdahnxsb2ljlj508-test-file.txt16602026/10/11 06:51:16 INFO Vacuumed table table=pending_objects16612026/10/11 06:51:16 INFO Vacuumed table table=multipart_uploads16622026/10/11 06:51:16 INFO Vacuumed table table=closures16632026/10/11 06:51:16 INFO Vacuumed table table=objects16642026/10/11 06:51:16 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=016652026/10/11 06:51:16 INFO Vacuumed table table=pending_closures16662026/10/11 06:51:16 INFO Vacuumed table table=pending_objects16672026/10/11 06:51:16 INFO Vacuumed table table=multipart_uploads16682026/10/11 06:51:16 INFO Vacuumed table table=closures16692026/10/11 06:51:16 INFO Vacuumed table table=objects16702026/10/11 06:51:16 INFO Aborted multipart uploads count=0 kept=016712026/10/11 06:51:16 WARN Force mode enabled - objects will be deleted immediately without grace period16722026/10/11 06:51:16 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=016732026/10/11 06:51:16 INFO Vacuumed table table=pending_closures16742026/10/11 06:51:16 INFO Vacuumed table table=pending_objects16752026/10/11 06:51:16 INFO Vacuumed table table=multipart_uploads16762026/10/11 06:51:16 INFO Vacuumed table table=closures16772026/10/11 06:51:16 INFO Vacuumed table table=objects1678=== CONT TestCreatePin_ReservedPins1679--- PASS: TestPushDedupSurvivesConcurrentGC (2.04s)1680=== NAME TestClientMultipleUploads1681 client_integration_test.go:480: Created store path 1: /build/TestClientMultipleUploads1747657803/001/store/anh9mql6sx2ps7zp6rrsy12chm80f6ax-test-file-1.txt1682--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.46s)1683=== CONT TestClientCADerivations16842026/10/11 06:51:16 INFO Received push request method=POST path=/api/pushes16852026/10/11 06:51:16 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"1686=== NAME TestClientMultipleUploads1687 client_integration_test.go:480: Created store path 2: /build/TestClientMultipleUploads1747657803/001/store/2782cyyj7ncd4r0jw8ybaqrq8r7ya0dp-test-file-2.txt16882026/10/11 06:51:16 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16892026/10/11 06:51:16 INFO Uploading j7a8zkgpimb7gbs8p7807nbf8f4gqip1-a (208B)16902026/10/11 06:51:16 INFO Uploading fwdih8ji0q3gdffr20sc65fk4r4yhx9b-shared-dep (136B)16912026/10/11 06:51:16 WARN Failed to register uploaded object key=nar/01kzxz7mx55gp0k8gw7z8qa0hxjdid4796bacx5xrfm4587qpxzg.nar.zst error="server returned 404: 404 page not found\n"16922026/10/11 06:51:16 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16932026/10/11 06:51:16 WARN Failed to register uploaded object key=a6dzig1bmx8ghwkasapqzfmxprrf7l3i.ls error="server returned 404: 404 page not found\n"16942026/10/11 06:51:16 WARN Failed to register uploaded object key=j7a8zkgpimb7gbs8p7807nbf8f4gqip1.ls error="server returned 404: 404 page not found\n"16952026/10/11 06:51:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16962026/10/11 06:51:16 WARN Failed to register uploaded object key=fwdih8ji0q3gdffr20sc65fk4r4yhx9b.ls error="server returned 404: 404 page not found\n"16972026/10/11 06:51:16 INFO Signed narinfos id=1 count=316982026/10/11 06:51:16 INFO Uploading 3 narinfos1699--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.91s)1700=== CONT TestService_AuthMiddleware17012026/10/11 06:51:16 INFO Received push request method=POST path=/api/pushes17022026/10/11 06:51:16 WARN Failed to register uploaded object key=fwdih8ji0q3gdffr20sc65fk4r4yhx9b.narinfo error="server returned 404: 404 page not found\n"17032026/10/11 06:51:16 INFO Received create pin request method=POST path=/api/pins/app17042026/10/11 06:51:16 WARN Failed to register uploaded object key=a6dzig1bmx8ghwkasapqzfmxprrf7l3i.narinfo error="server returned 404: 404 page not found\n"17052026/10/11 06:51:16 INFO Received complete push request method=POST path=/api/pushes/1/complete17062026/10/11 06:51:16 WARN Failed to register uploaded object key=j7a8zkgpimb7gbs8p7807nbf8f4gqip1.narinfo error="server returned 404: 404 page not found\n"17072026/10/11 06:51:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17082026/10/11 06:51:16 INFO Uploading 2vqmv2inqf9x896zvdahnxsb2ljlj508-test-file.txt (152B)17092026/10/11 06:51:16 INFO Completed push id=1 objects=8 duration=15.575518ms17102026/10/11 06:51:16 INFO Upload complete. (150ms)17112026/10/11 06:51:16 INFO Received create pin request method=POST path=/api/pins/app1712=== NAME TestClientPushesUseOnePush1713 client_pushes_test.go:97: Retrieved narinfo from S3:1714 StorePath: /build/TestClientPushesUseOnePush807858972/001/store/fwdih8ji0q3gdffr20sc65fk4r4yhx9b-shared-dep1715 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1716 Compression: zstd1717 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821718 NarSize: 1361719 References: 1720 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1721 client_pushes_test.go:97: Retrieved narinfo from S3:1722 StorePath: /build/TestClientPushesUseOnePush807858972/001/store/j7a8zkgpimb7gbs8p7807nbf8f4gqip1-a1723 URL: nar/01kzxz7mx55gp0k8gw7z8qa0hxjdid4796bacx5xrfm4587qpxzg.nar.zst1724 Compression: zstd1725 NarHash: sha256:01kzxz7mx55gp0k8gw7z8qa0hxjdid4796bacx5xrfm4587qpxzg1726 NarSize: 2081727 References: /build/TestClientPushesUseOnePush807858972/001/store/fwdih8ji0q3gdffr20sc65fk4r4yhx9b-shared-dep1728 CA: text:sha256:17lj5c89ysrmn5kmks39livasynkr1jqylflxlmzw630923h2pkw17292026/10/11 06:51:16 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17302026/10/11 06:51:16 WARN Failed to register uploaded object key=2vqmv2inqf9x896zvdahnxsb2ljlj508.ls error="server returned 404: 404 page not found\n"17312026/10/11 06:51:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17322026/10/11 06:51:16 INFO Signed narinfos id=1 count=11733 client_pushes_test.go:97: Retrieved narinfo from S3:1734 StorePath: /build/TestClientPushesUseOnePush807858972/001/store/a6dzig1bmx8ghwkasapqzfmxprrf7l3i-b1735 URL: nar/01kzxz7mx55gp0k8gw7z8qa0hxjdid4796bacx5xrfm4587qpxzg.nar.zst1736 Compression: zstd1737 NarHash: sha256:01kzxz7mx55gp0k8gw7z8qa0hxjdid4796bacx5xrfm4587qpxzg1738 NarSize: 2081739 References: /build/TestClientPushesUseOnePush807858972/001/store/fwdih8ji0q3gdffr20sc65fk4r4yhx9b-shared-dep1740 CA: text:sha256:17lj5c89ysrmn5kmks39livasynkr1jqylflxlmzw630923h2pkw17412026/10/11 06:51:16 INFO Uploading 1 narinfos17422026/10/11 06:51:16 INFO Received complete push request method=POST path=/api/pushes/1/complete17432026/10/11 06:51:16 WARN Failed to register uploaded object key=2vqmv2inqf9x896zvdahnxsb2ljlj508.narinfo error="server returned 404: 404 page not found\n"17442026/10/11 06:51:16 INFO Completed push id=1 objects=3 duration=7.390006ms17452026/10/11 06:51:16 INFO Upload complete. (179ms)1746=== RUN TestService_RequireScope_OIDC/builder_may_write1747=== PAUSE TestService_RequireScope_OIDC/builder_may_write1748=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1749=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1750=== RUN TestService_RequireScope_OIDC/ops_may_admin1751=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1752=== RUN TestService_RequireScope_OIDC/ops_may_not_write1753=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1754=== RUN TestService_RequireScope_OIDC/reader_may_not_write1755=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1756=== RUN TestService_RequireScope_OIDC/static_token_may_admin1757=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1758=== RUN TestService_RequireScope_OIDC/static_token_may_write1759=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1760=== RUN TestService_RequireScope_OIDC/reader_may_read1761=== PAUSE TestService_RequireScope_OIDC/reader_may_read1762=== RUN TestService_RequireScope_OIDC/writer_implies_read1763=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1764=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1765=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1766=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1767=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1768=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1769=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1770=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1771=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1772=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1773=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1774=== CONT TestSkippedUploadsHandler17752026/10/11 06:51:16 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001776--- PASS: TestClientPushesUseOnePush (1.91s)1777=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1778=== NAME TestPinProtectsFromGC1779 client_integration_test.go:867: Pinned store path: /build/TestPinProtectsFromGC1432667089/001/store/qrdjq5bn0dg955kp23lw1y0ynbxmnq9n-pinned-file.txt1780 client_integration_test.go:868: Unpinned store path: /build/TestPinProtectsFromGC1432667089/001/store/z4prvv5xr3ipivkpc8cp26j0c5y99z9i-unpinned-file.txt17812026/10/11 06:51:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36787/oidc1782--- PASS: TestSkippedUploadsHandler (0.03s)1783=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true17842026/10/11 06:51:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17852026/10/11 06:51:16 INFO Received push request method=POST path=/api/pushes17862026-10-11 06:51:16.567 UTC [1308] ERROR: Push does not exist: id=117872026-10-11 06:51:16.567 UTC [1308] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE17882026-10-11 06:51:16.567 UTC [1308] STATEMENT: SELECT commit_push($1)17892026/10/11 06:51:16 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)17902026/10/11 06:51:16 INFO Uploading y1q7v5py4na09sisw6xpliyis51vn6jw-test-file-0.txt (160B)17912026/10/11 06:51:16 INFO Uploading 2782cyyj7ncd4r0jw8ybaqrq8r7ya0dp-test-file-2.txt (160B)17922026/10/11 06:51:16 INFO Uploading anh9mql6sx2ps7zp6rrsy12chm80f6ax-test-file-1.txt (160B)17932026/10/11 06:51:16 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLjE1NWMxY2I3LTNlN2ItNDlhOS1iMjNiLTRjZjEyMTllMzVlZHgxNzkxNzAxNDczMjA2MzMwMTUw parts=1017942026/10/11 06:51:16 WARN Failed to register uploaded object key=y1q7v5py4na09sisw6xpliyis51vn6jw.ls error="server returned 404: 404 page not found\n"17952026/10/11 06:51:16 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"1796--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.09s)1797=== CONT TestProxyWriteTimeout/narinfo1798=== CONT TestProxyWriteTimeout/unknown_size1799=== CONT TestProxyWriteTimeout/10_GiB_nar1800=== CONT TestProxyWriteTimeout/1_GiB_nar18012026/10/11 06:51:16 INFO All 1 paths already cached1802=== CONT TestIsValidCachePath/narinfo1803--- PASS: TestProxyWriteTimeout (0.11s)1804 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1805 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1806 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1807 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1808=== CONT TestIsValidCachePath/leading_slash1809=== CONT TestIsValidCachePath/empty1810=== CONT TestIsValidCachePath/invalid_char_u1811=== CONT TestIsValidCachePath/short_hash18122026/10/11 06:51:16 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"1813=== CONT TestIsValidCachePath/realisation1814=== CONT TestIsValidCachePath/random_path1815=== CONT TestIsValidCachePath/log1816=== CONT TestIsValidCachePath/nar_xz1817=== CONT TestIsValidCachePath/traversal_parent18182026/10/11 06:51:16 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"1819=== CONT TestIsValidCachePath/ls1820=== CONT TestIsValidCachePath/wrong_extension1821=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1822=== CONT TestIsValidCachePath/nar_uncompressed1823=== NAME TestClientIntegration1824 client_integration_test.go:360: Retrieved narinfo from S3:1825 StorePath: /build/TestClientIntegration1694034200/002/store/2vqmv2inqf9x896zvdahnxsb2ljlj508-test-file.txt1826 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1827 Compression: zstd1828 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11829 NarSize: 1521830 References: 1831 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11832=== CONT TestIsValidCachePath/invalid_char_e1833=== CONT TestIsValidCachePath/nar_bz218342026/10/11 06:51:16 WARN Failed to register uploaded object key=2782cyyj7ncd4r0jw8ybaqrq8r7ya0dp.ls error="server returned 404: 404 page not found\n"1835=== CONT TestIsValidCachePath/nar_zst1836=== CONT TestIsValidCachePath/index.html1837=== CONT TestIsValidCachePath/nix-cache-info1838=== CONT TestIsValidCachePath/traversal_in_middle1839=== CONT TestServerTLSConfig/no_client_CA1840=== CONT TestServerTLSConfig/missing_CA_file1841--- PASS: TestIsValidCachePath (0.00s)1842 --- PASS: TestIsValidCachePath/narinfo (0.00s)1843 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1844 --- PASS: TestIsValidCachePath/empty (0.00s)1845 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1846 --- PASS: TestIsValidCachePath/short_hash (0.00s)1847 --- PASS: TestIsValidCachePath/realisation (0.00s)1848 --- PASS: TestIsValidCachePath/random_path (0.00s)1849 --- PASS: TestIsValidCachePath/log (0.00s)1850 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1851 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1852 --- PASS: TestIsValidCachePath/ls (0.00s)1853 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1854 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1855 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1856 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1857 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1858 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1859 --- PASS: TestIsValidCachePath/index.html (0.00s)1860 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1861 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1862=== CONT TestServerTLSConfig/not_a_PEM_file1863=== CONT TestResolveDBConnectionString/missing_file_is_an_error1864--- PASS: TestServerTLSConfig (0.00s)1865 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1866 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1867 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1868=== CONT TestResolveDBConnectionString/file_when_flag_empty1869=== CONT TestResolveDBConnectionString/flag_wins1870=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1871=== CONT TestResolveDBConnectionString/nothing_configured1872=== CONT TestPush_RejectsBadRequests/no_objects18732026/10/11 06:51:16 INFO Received push request method=POST path=/api/pushes1874--- PASS: TestResolveDBConnectionString (0.00s)1875 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1876 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1877 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1878 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1879 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1880=== CONT TestPush_RejectsBadRequests/root_not_in_objects18812026/10/11 06:51:16 INFO Received push request method=POST path=/api/pushes18822026/10/11 06:51:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1883=== CONT TestPush_RejectsBadRequests/bad_root18842026/10/11 06:51:16 INFO Received push request method=POST path=/api/pushes18852026/10/11 06:51:16 WARN Failed to register uploaded object key=anh9mql6sx2ps7zp6rrsy12chm80f6ax.ls error="server returned 404: 404 page not found\n"1886=== CONT TestPush_RejectsBadRequests/no_roots18872026/10/11 06:51:16 INFO Received push request method=POST path=/api/pushes18882026/10/11 06:51:16 INFO Signed narinfos id=1 count=31889=== CONT TestIsValidUploadKey/narinfo1890=== CONT TestIsValidUploadKey/realisation1891=== CONT TestIsValidUploadKey/empty_key1892=== CONT TestIsValidUploadKey/absolute1893=== CONT TestIsValidUploadKey/traversal18942026/10/11 06:51:16 INFO Uploading 3 narinfos1895=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1896=== CONT TestIsValidUploadKey/index.html1897=== CONT TestIsValidUploadKey/traversal_nar1898=== NAME TestClientIntegration1899 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)1900=== CONT TestIsValidUploadKey/build_log1901=== NAME TestClientIntegration1902 client_integration_test.go:361: Decompressed .ls content (64 bytes):1903 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1904=== CONT TestIsValidUploadKey/nar_xz1905=== CONT TestIsValidUploadKey/unknown_type1906=== CONT TestIsValidUploadKey/nix-cache-info1907=== CONT TestIsValidUploadKey/build_log_question_mark1908=== CONT TestIsValidUploadKey/listing1909=== CONT TestIsValidUploadKey/nar_zst1910=== CONT TestIsValidUploadKey/build_log_equals1911=== CONT TestIsValidUploadKey/nar_plain1912=== CONT TestIsValidUploadKey/build_log_plus_in_name1913=== CONT TestIsValidUploadKey/realisation_plus_in_output1914=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1915=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1916=== CONT TestIsValidUploadKey/build_log_home-manager_file1917=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1918--- PASS: TestIsValidUploadKey (0.00s)1919 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1920 --- PASS: TestIsValidUploadKey/realisation (0.00s)1921 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1922 --- PASS: TestIsValidUploadKey/absolute (0.00s)1923 --- PASS: TestIsValidUploadKey/traversal (0.00s)1924 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1925 --- PASS: TestIsValidUploadKey/index.html (0.00s)1926 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1927 --- PASS: TestIsValidUploadKey/build_log (0.00s)1928 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1929 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1930 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1931 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1932 --- PASS: TestIsValidUploadKey/listing (0.00s)1933 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1934 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1935 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1936 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1937 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1938 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1939 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1940 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)19412026/10/11 06:51:16 WARN Failed to register uploaded object key=anh9mql6sx2ps7zp6rrsy12chm80f6ax.narinfo error="server returned 404: 404 page not found\n"19422026/10/11 06:51:16 WARN Failed to register uploaded object key=y1q7v5py4na09sisw6xpliyis51vn6jw.narinfo error="server returned 404: 404 page not found\n"19432026/10/11 06:51:16 INFO Received complete push request method=POST path=/api/pushes/1/complete19442026/10/11 06:51:16 WARN Failed to register uploaded object key=2782cyyj7ncd4r0jw8ybaqrq8r7ya0dp.narinfo error="server returned 404: 404 page not found\n"1945=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1946--- PASS: TestService_ReadAuthMiddleware (0.87s)19472026/10/11 06:51:16 INFO Completed push id=1 objects=9 duration=5.814812ms19482026/10/11 06:51:16 INFO Upload complete. (136ms)1949=== NAME TestClientMultipleUploads1950 client_integration_test.go:491: Uploaded 3 paths in 213.318551ms1951--- PASS: TestPush_RejectsBadRequests (0.79s)1952 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1953 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1954 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1955 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)19562026/10/11 06:51:16 INFO Received create pin request method=POST path=/api/pins/deploy19572026/10/11 06:51:16 INFO Received create pin request method=POST path=/api/pins/deploy19582026/10/11 06:51:16 INFO Received create pin request method=POST path=/api/pins/deploy19592026/10/11 06:51:16 INFO Received create pin request method=POST path=/api/pins/deploy19602026/10/11 06:51:16 INFO Received create pin request method=POST path=/api/pins/deploy19612026/10/11 06:51:16 INFO Received create pin request method=POST path=/api/pins/deploy19622026/10/11 06:51:16 INFO Received create pin request method=POST path=/api/pins/deploy19632026/10/11 06:51:16 INFO Received create pin request method=POST path=/api/pins/deploy1964=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1965--- PASS: TestCacheStatsHandler (1.01s)19662026/10/11 06:51:16 INFO Received request for more parts method=POST path=/1967=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19682026/10/11 06:51:16 INFO Received uploads request method=POST path=/1969=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1970=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19712026/10/11 06:51:16 INFO Received complete multipart upload request method=POST path=/1972--- PASS: TestClientMultipleUploads (1.20s)19732026/10/11 06:51:16 INFO Received uploads request method=POST path=/1974=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts1975=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19762026/10/11 06:51:16 INFO Received request for more parts method=POST path=/1977--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1978 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1979 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1980 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1981 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)19822026/10/11 06:51:16 INFO Received complete multipart upload request method=POST path=/19832026/10/11 06:51:16 INFO Received create pin request method=POST path=/api/pins/app19842026/10/11 06:51:16 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo19852026/10/11 06:51:16 INFO Received delete pin request method=DELETE path=/api/pins/app19862026/10/11 06:51:16 INFO Received push request method=POST path=/api/pushes19872026/10/11 06:51:16 INFO Received create pin request method=POST path=/api/pins/deploy1988=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1989=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1990=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1991=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1992=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1993=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1994=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1995=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured19962026/10/11 06:51:16 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket92/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"1997=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19982026/10/11 06:51:16 INFO Received uploads request method=POST path=/19992026/10/11 06:51:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20002026/10/11 06:51:16 INFO Uploading qrdjq5bn0dg955kp23lw1y0ynbxmnq9n-pinned-file.txt (128B)20012026/10/11 06:51:16 INFO Received delete pin request method=DELETE path=/api/pins/app20022026-10-11 06:51:16.713 UTC [175] LOG: checkpoints are occurring too frequently (16 seconds apart)20032026-10-11 06:51:16.713 UTC [175] HINT: Consider increasing the configuration parameter "max_wal_size".20042026-10-11 06:51:16.713 UTC [175] LOG: checkpoint starting: wal20052026/10/11 06:51:16 INFO Deleted pin name=app20062026/10/11 06:51:16 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"20072026/10/11 06:51:16 INFO Received push request method=POST path=/api/pushes20082026/10/11 06:51:16 WARN Failed to register uploaded object key=qrdjq5bn0dg955kp23lw1y0ynbxmnq9n.ls error="server returned 404: 404 page not found\n"20092026/10/11 06:51:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20102026/10/11 06:51:16 INFO Signed narinfos id=1 count=120112026/10/11 06:51:16 INFO Uploading 1 narinfos2012=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh2013--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.71s)20142026/10/11 06:51:16 INFO Object in database but missing from S3 key=2vqmv2inqf9x896zvdahnxsb2ljlj508.ls20152026/10/11 06:51:16 WARN Found objects in DB but missing from S3, will re-upload count=120162026/10/11 06:51:16 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)20172026/10/11 06:51:16 INFO Received complete push request method=POST path=/api/pushes/1/complete20182026/10/11 06:51:16 WARN Failed to register uploaded object key=qrdjq5bn0dg955kp23lw1y0ynbxmnq9n.narinfo error="server returned 404: 404 page not found\n"20192026/10/11 06:51:16 INFO Received complete push request method=POST path=/api/pushes/2/complete20202026/10/11 06:51:16 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"20212026/10/11 06:51:16 WARN Failed to register uploaded object key=2vqmv2inqf9x896zvdahnxsb2ljlj508.ls error="server returned 404: 404 page not found\n"20222026/10/11 06:51:16 INFO Completed push id=1 objects=3 duration=7.150703ms20232026/10/11 06:51:16 INFO Completed push id=2 objects=3 duration=2.779665ms20242026/10/11 06:51:16 INFO Upload complete. (146ms)20252026/10/11 06:51:16 INFO Upload complete. (76ms)2026=== NAME TestClientIntegration2027 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)2028 client_integration_test.go:389: Decompressed .ls content (49 bytes):2029 {"version":1,"root":{"type":"regular","size":39}}2030--- PASS: TestService_AuthMiddleware (0.33s)2031=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale20322026/10/11 06:51:16 INFO Received uploads request method=POST path=/api/pending_closures20332026/10/11 06:51:16 INFO Received uploads request method=POST path=/api/pending_closures20342026/10/11 06:51:16 INFO Received uploads request method=POST path=/api/pending_closures20352026/10/11 06:51:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20362026/10/11 06:51:16 INFO Received push request method=POST path=/api/pushes2037--- PASS: TestGCBugBareHashReferences (1.27s)2038=== CONT TestGCEndsOnShutdown/before_the_run20392026/10/11 06:51:16 INFO Received push request method=POST path=/api/pushes20402026/10/11 06:51:16 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)20412026/10/11 06:51:16 INFO Aborted multipart uploads count=0 kept=020422026/10/11 06:51:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20432026/10/11 06:51:16 INFO Uploading z4prvv5xr3ipivkpc8cp26j0c5y99z9i-unpinned-file.txt (128B)20442026/10/11 06:51:16 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20452026/10/11 06:51:16 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLjZmN2EyZTBhLTgwNzEtNDU3Ni05M2M5LWQzY2VlN2E1NTUzOHgxNzkxNzAxNDc1MzMzNjU3MDA2 parts=1020462026/10/11 06:51:16 INFO Received complete push request method=POST path=/api/pushes/3/complete20472026/10/11 06:51:16 WARN Failed to register uploaded object key=2vqmv2inqf9x896zvdahnxsb2ljlj508.ls error="server returned 404: 404 page not found\n"2048=== NAME TestClientCADerivations2049 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3748511648/001/store/cqlkl91bhv5q19z6vb334m823p4nvnqy-ca-test20502026/10/11 06:51:16 INFO Completed push id=3 objects=3 duration=2.625603ms20512026/10/11 06:51:16 INFO Upload complete. (63ms)2052=== NAME TestClientIntegration2053 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)2054 client_integration_test.go:405: Decompressed .ls content (49 bytes):2055 {"version":1,"root":{"type":"regular","size":39}}20562026/10/11 06:51:16 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"20572026/10/11 06:51:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux20582026/10/11 06:51:16 WARN Refused reserved pin name=worker-x86_64-linux20592026/10/11 06:51:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux20602026/10/11 06:51:16 WARN Failed to register uploaded object key=z4prvv5xr3ipivkpc8cp26j0c5y99z9i.ls error="server returned 404: 404 page not found\n"20612026/10/11 06:51:16 INFO Received create pin request method=POST path=/api/pins/my-app20622026/10/11 06:51:16 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign20632026/10/11 06:51:16 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux20642026/10/11 06:51:16 INFO Signed narinfos id=2 count=120652026/10/11 06:51:16 INFO Uploading 1 narinfos20662026/10/11 06:51:16 INFO Received complete push request method=POST path=/api/pushes/2/complete20672026/10/11 06:51:16 WARN Failed to register uploaded object key=z4prvv5xr3ipivkpc8cp26j0c5y99z9i.narinfo error="server returned 404: 404 page not found\n"20682026/10/11 06:51:16 INFO Completed push id=2 objects=3 duration=2.580703ms20692026/10/11 06:51:16 INFO Upload complete. (92ms)20702026/10/11 06:51:16 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLjI1ZDIyZjg3LWU2ZmItNGU1Yy1iODAzLTdmZjliNGI5YjQ2NXgxNzkxNzAxNDc1NjU4Mjk3NjA0 parts=1020712026/10/11 06:51:16 INFO Received complete push request method=POST path=/api/pushes/2/complete20722026/10/11 06:51:16 INFO Received uploads request method=POST path=/api/pending_closures2073=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete2074--- PASS: TestCreatePin_ReservedPins (0.54s)20752026/10/11 06:51:16 INFO Completed push id=2 objects=4 duration=4.954624ms20762026/10/11 06:51:16 INFO Aborted multipart uploads count=0 kept=02077=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark2078--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.85s)20792026/10/11 06:51:16 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo20802026/10/11 06:51:17 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo2081=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline2082--- PASS: TestConcurrentPinUpdatesAgree (1.39s)20832026/10/11 06:51:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20842026/10/11 06:51:17 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLjAwM2JhMGYyLTFmOWItNDc0ZC1iNjA1LTgwY2RkYmJhNGVmOHgxNzkxNzAxNDczMjA1MzYxMTAx parts=1020852026-10-11 06:51:17.143 UTC [810] ERROR: could not obtain lock on row in relation "closures"20862026-10-11 06:51:17.143 UTC [810] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT20872026-10-11 06:51:17.144 UTC [810] ERROR: could not obtain lock on row in relation "closures"20882026-10-11 06:51:17.144 UTC [810] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT20892026-10-11 06:51:17.145 UTC [810] ERROR: could not obtain lock on row in relation "closures"20902026-10-11 06:51:17.145 UTC [810] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT20912026-10-11 06:51:17.145 UTC [810] ERROR: could not obtain lock on row in relation "closures"20922026-10-11 06:51:17.145 UTC [810] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT20932026-10-11 06:51:17.146 UTC [810] ERROR: could not obtain lock on row in relation "closures"20942026-10-11 06:51:17.146 UTC [810] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT20952026/10/11 06:51:17 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLmFiMTBlZDZkLTRlZTItNDQzNC05ODVmLWNkZGJkMTY1YWFlYXgxNzkxNzAxNDc2NzkxOTkyNDEy error="Access Denied"20962026/10/11 06:51:17 WARN keeping failed pending closure for cleanup to retry the abort id=12097=== CONT TestPendingClosureWriteTimeout/400_objects2098=== CONT TestPendingClosureWriteTimeout/670k_objects2099=== CONT TestPendingClosureWriteTimeout/empty2100=== CONT TestClientErrorHandling/InvalidAuthToken21012026/10/11 06:51:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2102=== CONT TestClientErrorHandling/InvalidStorePath2103--- PASS: TestPendingClosureFailureTracksEveryUpload (0.05s)2104 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (0.77s)2105 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (0.82s)21062026/10/11 06:51:17 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=OWFjZGU2OTItYzBlYi00OTllLTk2YjItMWE4NTM0ZmM5ZGVmLjA2MmY5YzNiLTliZmEtNGZlZi04ZjdhLTA4NDQ2OWUxMmE1YXgxNzkxNzAxNDc1MzMzMDEzNjYx parts=1021072026/10/11 06:51:17 INFO Received complete push request method=POST path=/api/pushes/1/complete21082026/10/11 06:51:17 INFO Completed push id=1 objects=6 duration=7.843169ms2109--- PASS: TestPush_CompleteCommitsEveryRoot (2.30s)2110=== CONT TestClientErrorHandling/ServerNotAvailable21112026/10/11 06:51:17 WARN Force mode enabled - objects will be deleted immediately without grace period21122026/10/11 06:51:17 WARN Force mode enabled - objects will be deleted immediately without grace period2113=== CONT TestParseSingleRange/unknown_unit2114=== CONT TestParseSingleRange/start_far_past_EOF2115=== CONT TestParseSingleRange/open-ended2116=== CONT TestParseSingleRange/single_byte2117=== CONT TestParseSingleRange/start_past_EOF2118=== CONT TestParseSingleRange/suffix_exceeds_size2119=== CONT TestParseSingleRange/closed2120=== CONT TestParseSingleRange/suffix2121=== CONT TestParseSingleRange/malformed_end_before_start2122=== CONT TestParseSingleRange/multi-range_ignored2123=== CONT TestParseSingleRange/malformed_both_empty2124=== CONT TestParseSingleRange/none2125=== CONT TestParseSingleRange/malformed_no_dash2126=== CONT TestParseSingleRange/end_clamped_to_size2127=== CONT TestCacheConfigHandler/no_signing_keys2128=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2129--- PASS: TestParseSingleRange (0.00s)2130 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2131 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2132 --- PASS: TestParseSingleRange/open-ended (0.00s)2133 --- PASS: TestParseSingleRange/single_byte (0.00s)2134 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2135 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2136 --- PASS: TestParseSingleRange/closed (0.00s)2137 --- PASS: TestParseSingleRange/suffix (0.00s)2138 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2139 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2140 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2141 --- PASS: TestParseSingleRange/none (0.00s)2142 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2143 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2144=== CONT TestCacheConfigHandler/no_cache_url_configured2145=== CONT TestCacheConfigHandler/full_config,_no_issuer2146=== CONT TestService_RequireScope_OIDC/ops_may_not_write2147--- PASS: TestCacheConfigHandler (0.00s)2148 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2149 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2150 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2151 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2152=== NAME TestClientCADerivations2153 client_ca_test.go:139: Found 1 dependencies (including self)21542026/10/11 06:51:17 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=021552026/10/11 06:51:17 INFO Vacuumed table table=pending_closures21562026/10/11 06:51:17 INFO Vacuumed table table=pending_objects21572026/10/11 06:51:17 INFO Vacuumed table table=multipart_uploads21582026/10/11 06:51:17 INFO Vacuumed table table=closures21592026/10/11 06:51:17 INFO Vacuumed table table=objects2160=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2161=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read21622026/10/11 06:51:17 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]2163=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2164=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2165=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2166=== CONT TestService_RequireScope_OIDC/reader_may_read2167=== CONT TestService_RequireScope_OIDC/writer_implies_read2168=== CONT TestService_RequireScope_OIDC/static_token_may_write2169=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2170=== CONT TestService_RequireScope_OIDC/builder_may_write2171=== CONT TestService_RequireScope_OIDC/static_token_may_admin2172=== CONT TestService_RequireScope_OIDC/reader_may_not_write2173=== CONT TestService_RequireScope_OIDC/ops_may_admin21742026/10/11 06:51:17 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=02175=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured21762026/10/11 06:51:17 INFO Vacuumed table table=pending_closures2177=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected21782026/10/11 06:51:17 INFO Vacuumed table table=pending_objects21792026/10/11 06:51:17 INFO Vacuumed table table=multipart_uploads21802026/10/11 06:51:17 INFO Vacuumed table table=closures2181=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected21822026/10/11 06:51:17 INFO Vacuumed table table=objects2183--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2184 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.70s)2185 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.80s)21862026/10/11 06:51:17 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]2187=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token21882026/10/11 06:51:17 WARN Authentication failed token_preview=eyJhbGciOi...C7ggBaSb3w token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2189--- PASS: TestPush_RootsAreLockedInByteOrder (4.68s)21902026/10/11 06:51:17 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>2191--- PASS: TestService_RequireScope_OIDC (1.18s)2192 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.10s)2193 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2194 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2195 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2196 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2197 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2198 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2199 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2200 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2201 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2202 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2203 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2204 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2205 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2206--- PASS: TestService_AuthMiddleware_OIDC (0.85s)2207 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2208 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2209 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2210 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)2211--- PASS: TestReadProxyNarinfo (1.89s)2212--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2213 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.98s)2214 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.99s)2215--- PASS: TestConnectWaitsForAPeerMigration (5.48s)22162026/10/11 06:51:17 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/present22172026/10/11 06:51:17 INFO Starting cleanup of old closures method=DELETE path=/api/closures22182026/10/11 06:51:17 INFO Garbage collection started22192026/10/11 06:51:17 INFO Aborted multipart uploads count=0 kept=022202026/10/11 06:51:17 INFO Received uploads request method=POST path=/api/pending_closures22212026/10/11 06:51:17 WARN Force mode enabled - objects will be deleted immediately without grace period22222026/10/11 06:51:17 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=022232026/10/11 06:51:17 INFO Vacuumed table table=pending_closures22242026/10/11 06:51:17 INFO Vacuumed table table=pending_objects22252026/10/11 06:51:17 INFO Vacuumed table table=multipart_uploads22262026/10/11 06:51:17 INFO Vacuumed table table=closures22272026/10/11 06:51:17 INFO Vacuumed table table=objects22282026/10/11 06:51:17 INFO Aborted multipart uploads count=0 kept=022292026/10/11 06:51:17 INFO Received create pin request method=POST path=/api/pins/deploy22302026/10/11 06:51:17 INFO Received push request method=POST path=/api/pushes22312026/10/11 06:51:17 WARN Force mode enabled - objects will be deleted immediately without grace period22322026/10/11 06:51:17 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo22332026/10/11 06:51:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22342026/10/11 06:51:17 INFO Uploading dznrxzarcgv0anmlw1iwi0774pj6hrq4-lost-commit.txt (152B)22352026-10-11 06:51:17.686 UTC [1945] ERROR: canceling statement due to user request22362026-10-11 06:51:17.686 UTC [1945] CONTEXT: SQL statement "UPDATE object_stats s2237 SET object_count = s.object_count + n.n - o.n,2238 total_bytes = s.total_bytes + n.bytes - o.bytes2239 FROM (2240 SELECT count(*) AS n, coalesce(sum(size), 0) AS bytes2241 FROM new_rows WHERE deleted_at IS NULL2242 ) AS n,2243 (2244 SELECT count(*) AS n, coalesce(sum(size), 0) AS bytes2245 FROM old_rows WHERE deleted_at IS NULL2246 ) AS o2247 WHERE s.id AND (n.n <> o.n OR n.bytes <> o.bytes)"2248 PL/pgSQL function object_stats_update() line 3 at SQL statement22492026-10-11 06:51:17.686 UTC [1945] STATEMENT: -- name: MarkStaleObjects :execrows2250 WITH RECURSIVE ct AS (2251 SELECT timezone('UTC', now()) AS now2252 ),2253 closure_reach AS (2254 -- Start with all closure keys2255 SELECT o.key, o.refs2256 FROM objects o2257 INNER JOIN closures c ON o.key = c.key2258 UNION2259 -- Recursively add all referenced objects2260 SELECT o.key, o.refs2261 FROM objects o2262 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2263 ),2264 reachable_objects AS (2265 SELECT DISTINCT key FROM closure_reach2266 ),2267 stale_objects AS (2268 SELECT o.key2269 FROM objects AS o, ct2270 WHERE2271 NOT EXISTS (2272 SELECT 12273 FROM reachable_objects ro2274 WHERE ro.key = o.key2275 )2276 AND NOT EXISTS (2277 SELECT 12278 FROM pending_objects AS po2279 WHERE po.key = o.key2280 )2281 AND o.deleted_at IS NULL -- Only mark fresh objects2282 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2283 FOR UPDATE2284 )2285 UPDATE objects2286 SET2287 deleted_at = ct.now,2288 first_deleted_at = COALESCE(first_deleted_at, ct.now)2289 FROM stale_objects, ct2290 WHERE objects.key = stale_objects.key2291 22922026/10/11 06:51:17 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"22932026/10/11 06:51:17 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign22942026/10/11 06:51:17 WARN Failed to register uploaded object key=dznrxzarcgv0anmlw1iwi0774pj6hrq4.ls error="server returned 404: 404 page not found\n"22952026/10/11 06:51:17 INFO Signed narinfos id=4 count=122962026/10/11 06:51:17 INFO Uploading 1 narinfos2297--- PASS: TestCreatePinRejectsBadInput (1.94s)22982026/10/11 06:51:17 INFO Received complete push request method=POST path=/api/pushes/4/complete22992026/10/11 06:51:17 WARN Failed to register uploaded object key=dznrxzarcgv0anmlw1iwi0774pj6hrq4.narinfo error="server returned 404: 404 page not found\n"23002026/10/11 06:51:17 INFO Completed push id=4 objects=3 duration=1.568254ms23012026/10/11 06:51:17 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:32791/api/pushes/4/complete\": EOF" url=http://127.0.0.1:32791/api/pushes/4/complete23022026/10/11 06:51:17 INFO Received push request method=POST path=/api/pushes23032026/10/11 06:51:17 WARN Request failed, retrying attempt=2 backoff=201.782987ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23042026/10/11 06:51:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23052026/10/11 06:51:17 INFO Uploading cqlkl91bhv5q19z6vb334m823p4nvnqy-ca-test (144B)23062026/10/11 06:51:17 INFO Aborted multipart uploads count=0 kept=023072026/10/11 06:51:17 WARN Failed to register uploaded object key=log/3r3jx1rwj93w389dizk7pnsv22lsqwmn-ca-test.drv error="server returned 404: 404 page not found\n"23082026/10/11 06:51:17 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"23092026/10/11 06:51:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23102026/10/11 06:51:17 WARN Failed to register uploaded object key=cqlkl91bhv5q19z6vb334m823p4nvnqy.ls error="server returned 404: 404 page not found\n"23112026/10/11 06:51:17 WARN Force mode enabled - objects will be deleted immediately without grace period23122026/10/11 06:51:17 INFO Signed narinfos id=1 count=123132026/10/11 06:51:17 INFO Uploading 1 narinfos23142026/10/11 06:51:17 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"23152026/10/11 06:51:17 INFO Received complete push request method=POST path=/api/pushes/1/complete23162026/10/11 06:51:17 WARN Failed to register uploaded object key=cqlkl91bhv5q19z6vb334m823p4nvnqy.narinfo error="server returned 404: 404 page not found\n"23172026/10/11 06:51:17 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:37235/bucket108/?delete=\": context canceled"23182026/10/11 06:51:17 INFO Completed push id=1 objects=4 duration=6.009754ms23192026/10/11 06:51:17 INFO Upload complete. (138ms)2320=== NAME TestClientCADerivations2321 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3748511648/001/store/cqlkl91bhv5q19z6vb334m823p4nvnqy-ca-test2322 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2323 Compression: zstd2324 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2325 NarSize: 1442326 References: 2327 Deriver: /build/TestClientCADerivations3748511648/001/store/3r3jx1rwj93w389dizk7pnsv22lsqwmn-ca-test.drv2328 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2329 client_ca_test.go:185: Checking for realisation files in S3...2330 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2331 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2332--- PASS: TestGCEndsOnShutdown (0.00s)2333 --- PASS: TestGCEndsOnShutdown/before_the_run (0.85s)2334 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.79s)2335 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.87s)23362026/10/11 06:51:17 INFO Received complete push request method=POST path=/api/pushes/4/complete23372026-10-11 06:51:17.800 UTC [1150] ERROR: Push does not exist: id=423382026-10-11 06:51:17.800 UTC [1150] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE23392026-10-11 06:51:17.800 UTC [1150] STATEMENT: -- name: CommitPush :one2340 SELECT commit_push($1::bigint)::bigint2341 23422026/10/11 06:51:17 WARN Push not found id=423432026/10/11 06:51:17 INFO Upload complete. (186ms)2344=== NAME TestClientIntegration2345 client_integration_test.go:435: Retrieved narinfo from S3:2346 StorePath: /build/TestClientIntegration1694034200/002/store/dznrxzarcgv0anmlw1iwi0774pj6hrq4-lost-commit.txt2347 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst2348 Compression: zstd2349 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2350 NarSize: 1522351 References: 2352 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2353 client_integration_test.go:438: Testing garbage collection...2354--- PASS: TestDeleteClosuresRacingPins (4.84s)23552026/10/11 06:51:17 WARN Request failed, retrying attempt=3 backoff=378.986243ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23562026/10/11 06:51:18 WARN Request failed, retrying attempt=4 backoff=780.888425ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23572026/10/11 06:51:18 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2358--- PASS: TestPendingClosureWriteTimeout (0.00s)2359 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2360 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2361 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2362 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.43s)23632026/10/11 06:51:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures23642026/10/11 06:51:18 INFO Garbage collection started23652026/10/11 06:51:18 INFO Aborted multipart uploads count=0 kept=023662026/10/11 06:51:18 WARN Force mode enabled - objects will be deleted immediately without grace period23672026/10/11 06:51:18 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=023682026/10/11 06:51:18 INFO Vacuumed table table=pending_closures23692026/10/11 06:51:18 INFO Vacuumed table table=pending_objects23702026/10/11 06:51:18 INFO Vacuumed table table=multipart_uploads23712026/10/11 06:51:18 INFO Vacuumed table table=closures23722026/10/11 06:51:18 INFO Vacuumed table table=objects23732026/10/11 06:51:19 WARN Request failed, retrying attempt=5 backoff=1.674470838s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23742026/10/11 06:51:19 INFO Aborted multipart uploads count=1 kept=023752026/10/11 06:51:19 INFO Received cleanup request method=DELETE path=/api/pending_closures23762026/10/11 06:51:19 INFO Aborted multipart uploads count=1 kept=02377--- PASS: TestPendingCleanupUsesOneCutoff (6.51s)23782026/10/11 06:51:19 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=023792026/10/11 06:51:19 INFO Received create pin request method=POST path=/api/pins/myapp23802026/10/11 06:51:19 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1432667089/001/store/qrdjq5bn0dg955kp23lw1y0ynbxmnq9n-pinned-file.txt narinfo_key=qrdjq5bn0dg955kp23lw1y0ynbxmnq9n.narinfo23812026/10/11 06:51:19 INFO Starting cleanup of old closures method=DELETE path=/api/closures23822026/10/11 06:51:19 INFO Garbage collection started23832026/10/11 06:51:19 INFO Aborted multipart uploads count=0 kept=023842026/10/11 06:51:19 WARN Force mode enabled - objects will be deleted immediately without grace period23852026/10/11 06:51:19 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=023862026/10/11 06:51:19 INFO Vacuumed table table=pending_closures23872026/10/11 06:51:19 INFO Vacuumed table table=pending_objects23882026/10/11 06:51:19 INFO Vacuumed table table=multipart_uploads23892026/10/11 06:51:19 INFO Vacuumed table table=closures23902026/10/11 06:51:19 INFO Vacuumed table table=objects23912026/10/11 06:51:20 WARN Rate limiter enabled after throttle name=s3-test rate=523922026/10/11 06:51:20 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2393=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2394 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102395 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002396--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.95s)2397=== NAME TestClientCADerivations2398 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2399 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2400 error: binary cache 's3://bucket94?endpoint=http://localhost:37235®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3748511648/001/store'2401 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12402--- PASS: TestClientCADerivations (3.74s)24032026/10/11 06:51:20 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02404=== NAME TestClientIntegration2405 client_integration_test.go:445: Objects in database after GC:2406 client_integration_test.go:445: Successfully deleted all objects with GC --force2407--- PASS: TestClientIntegration (5.10s)24082026/10/11 06:51:20 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-config24092026/10/11 06:51:20 WARN Request failed, retrying attempt=2 backoff=218.945015ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24102026/10/11 06:51:21 WARN Request failed, retrying attempt=3 backoff=400.094927ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24112026/10/11 06:51:21 WARN Request failed, retrying attempt=4 backoff=767.888988ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2412=== NAME TestPinProtectsFromGC2413 client_integration_test.go:976: Pin successfully protected closure from garbage collection2414--- PASS: TestPinProtectsFromGC (5.98s)24152026/10/11 06:51:22 WARN Request failed, retrying attempt=5 backoff=1.469759647s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24162026/10/11 06:51:23 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"24172026/10/11 06:51:23 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-config24182026/10/11 06:51:23 WARN Request failed, retrying attempt=2 backoff=209.340112ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24192026/10/11 06:51:24 WARN Request failed, retrying attempt=3 backoff=368.39784ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24202026/10/11 06:51:24 WARN Request failed, retrying attempt=4 backoff=855.219829ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24212026/10/11 06:51:25 WARN Request failed, retrying attempt=5 backoff=1.523478872s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24222026/10/11 06:51:26 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_closures24232026/10/11 06:51:26 WARN Request failed, retrying attempt=2 backoff=210.357936ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24242026/10/11 06:51:27 WARN Request failed, retrying attempt=3 backoff=429.440453ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24252026/10/11 06:51:27 WARN Request failed, retrying attempt=4 backoff=793.501251ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24262026/10/11 06:51:28 WARN Request failed, retrying attempt=5 backoff=1.449934237s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2427--- PASS: TestClientErrorHandling (0.00s)2428 --- PASS: TestClientErrorHandling/InvalidStorePath (0.41s)2429 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.16s)2430 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.43s)2431--- PASS: TestUploadHandlersRejectOversizedBody (0.40s)2432 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.94s)2433 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (1.01s)2434 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (14.15s)2435PASS2436{"timestamp":"2026-10-11T06:51:30.856351619Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:37416","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(209)"}2437{"timestamp":"2026-10-11T06:51:30.856295159Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:37880","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(205)"}24382026-10-11 06:51:31.191 UTC [170] LOG: received smart shutdown request24392026-10-11 06:51:31.194 UTC [170] LOG: background worker "logical replication launcher" (PID 180) exited with exit code 124402026-10-11 06:51:31.548 UTC [175] LOG: checkpoint complete: wrote 4782 buffers (29.2%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=14.560 s, sync=0.238 s, total=14.836 s; sync files=37080, longest=0.005 s, average=0.001 s; distance=533515 kB, estimate=533515 kB; lsn=0/24FFE028, redo lsn=0/22068A1824412026-10-11 06:51:31.552 UTC [175] LOG: shutting down24422026-10-11 06:51:31.552 UTC [175] LOG: checkpoint starting: shutdown immediate24432026-10-11 06:51:31.796 UTC [175] LOG: checkpoint complete: wrote 5270 buffers (32.2%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 2 recycled; write=0.069 s, sync=0.171 s, total=0.245 s; sync files=1621, longest=0.002 s, average=0.001 s; distance=48725 kB, estimate=485036 kB; lsn=0/24FFE0A0, redo lsn=0/24FFE0A024442026-10-11 06:51:31.870 UTC [170] LOG: database system is shut down2445Running OIDC tests...2446=== RUN TestAudienceForIssuer2447=== PAUSE TestAudienceForIssuer2448=== RUN TestHTTPClientForHasTimeouts2449=== PAUSE TestHTTPClientForHasTimeouts2450=== RUN TestGlobMatch2451=== PAUSE TestGlobMatch2452=== RUN TestValidateToken_ValidToken2453=== PAUSE TestValidateToken_ValidToken2454=== RUN TestValidateToken_WrongAudience2455=== PAUSE TestValidateToken_WrongAudience2456=== RUN TestValidateToken_Expired2457=== PAUSE TestValidateToken_Expired2458=== RUN TestValidateToken_BoundClaimsMismatch2459=== PAUSE TestValidateToken_BoundClaimsMismatch2460=== RUN TestValidateToken_BoundSubjectMismatch2461=== PAUSE TestValidateToken_BoundSubjectMismatch2462=== RUN TestValidateToken_MultipleProviders2463=== PAUSE TestValidateToken_MultipleProviders2464=== RUN TestValidateToken_NoMatchingProvider2465=== PAUSE TestValidateToken_NoMatchingProvider2466=== RUN TestValidateToken_KubernetesServiceAccount2467=== PAUSE TestValidateToken_KubernetesServiceAccount2468=== RUN TestNewValidator_KubernetesRequiresCA2469=== PAUSE TestNewValidator_KubernetesRequiresCA2470=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2471=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2472=== RUN TestPins_ReservedForMatchingRule2473=== PAUSE TestPins_ReservedForMatchingRule2474=== RUN TestPins_TopLevelShorthand2475=== PAUSE TestPins_TopLevelShorthand2476=== RUN TestPins_ConfigValidation2477=== PAUSE TestPins_ConfigValidation2478=== RUN TestScopes_LegacyProviderDefaultsToWrite2479=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2480=== RUN TestScopes_Rules2481=== PAUSE TestScopes_Rules2482=== RUN TestScopes_ConfigValidation2483=== PAUSE TestScopes_ConfigValidation2484=== CONT TestValidateToken_WrongAudience2485=== CONT TestValidateToken_Expired2486=== CONT TestNewValidator_KubernetesRequiresCA2487=== CONT TestScopes_ConfigValidation2488=== CONT TestScopes_Rules2489=== CONT TestPins_ConfigValidation2490=== CONT TestPins_TopLevelShorthand2491=== CONT TestPins_ReservedForMatchingRule2492=== CONT TestScopes_LegacyProviderDefaultsToWrite2493=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2494=== CONT TestValidateToken_KubernetesServiceAccount2495=== CONT TestValidateToken_BoundSubjectMismatch2496--- PASS: TestPins_ConfigValidation (0.00s)2497=== CONT TestGlobMatch2498=== RUN TestGlobMatch/foo_foo2499=== PAUSE TestGlobMatch/foo_foo2500=== RUN TestGlobMatch/foo_bar2501=== CONT TestValidateToken_ValidToken2502=== CONT TestHTTPClientForHasTimeouts2503=== CONT TestAudienceForIssuer2504=== CONT TestValidateToken_NoMatchingProvider2505=== CONT TestValidateToken_BoundClaimsMismatch2506=== CONT TestValidateToken_MultipleProviders2507=== PAUSE TestGlobMatch/foo_bar2508--- PASS: TestAudienceForIssuer (0.00s)2509=== RUN TestGlobMatch/*_2510=== PAUSE TestGlobMatch/*_2511=== RUN TestGlobMatch/*_anything2512=== PAUSE TestGlobMatch/*_anything2513=== RUN TestGlobMatch/foo*_foo2514=== PAUSE TestGlobMatch/foo*_foo2515=== RUN TestGlobMatch/foo*_foobar2516=== PAUSE TestGlobMatch/foo*_foobar2517=== RUN TestGlobMatch/foo*_bar2518=== PAUSE TestGlobMatch/foo*_bar2519=== RUN TestGlobMatch/*bar_bar2520=== PAUSE TestGlobMatch/*bar_bar2521=== RUN TestGlobMatch/*bar_foobar2522=== PAUSE TestGlobMatch/*bar_foobar2523=== RUN TestGlobMatch/*bar_foo2524=== PAUSE TestGlobMatch/*bar_foo2525=== RUN TestGlobMatch/foo*bar_foobar2526=== PAUSE TestGlobMatch/foo*bar_foobar2527=== RUN TestGlobMatch/foo*bar_foo123bar2528=== PAUSE TestGlobMatch/foo*bar_foo123bar2529=== RUN TestGlobMatch/foo*bar_foobarbaz2530=== PAUSE TestGlobMatch/foo*bar_foobarbaz2531=== RUN TestGlobMatch/*/*_foo/bar2532=== PAUSE TestGlobMatch/*/*_foo/bar2533=== RUN TestGlobMatch/*/*_foo2534=== PAUSE TestGlobMatch/*/*_foo2535=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2536=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2537=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02538=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02539=== RUN TestGlobMatch/refs/*/main_refs/heads/main2540=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2541=== RUN TestGlobMatch/fo?_foo2542=== PAUSE TestGlobMatch/fo?_foo2543=== RUN TestGlobMatch/fo?_fo2544=== PAUSE TestGlobMatch/fo?_fo2545=== RUN TestGlobMatch/fo?_fooo2546=== PAUSE TestGlobMatch/fo?_fooo2547=== RUN TestGlobMatch/?oo_foo2548=== PAUSE TestGlobMatch/?oo_foo2549=== RUN TestGlobMatch/?oo_boo2550=== PAUSE TestGlobMatch/?oo_boo2551--- PASS: TestScopes_ConfigValidation (0.01s)2552=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2553=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2554=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2555=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2556=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2557=== CONT TestGlobMatch/foo*bar_foobarbaz2558=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2559=== CONT TestGlobMatch/fo?_foo2560=== CONT TestGlobMatch/*bar_bar2561=== CONT TestGlobMatch/foo*_foo2562=== CONT TestGlobMatch/foo_bar2563=== CONT TestGlobMatch/refs/*/main_refs/heads/main2564=== CONT TestGlobMatch/?oo_foo2565=== CONT TestGlobMatch/*bar_foo2566=== CONT TestGlobMatch/*_anything2567=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02568=== CONT TestGlobMatch/*bar_foobar2569=== CONT TestGlobMatch/fo?_fo2570=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2571=== CONT TestGlobMatch/?oo_boo2572=== CONT TestGlobMatch/foo*bar_foo123bar2573=== CONT TestGlobMatch/foo*_bar2574=== CONT TestGlobMatch/foo*_foobar2575=== CONT TestGlobMatch/foo_foo2576=== CONT TestGlobMatch/*/*_foo/bar2577=== CONT TestGlobMatch/foo*bar_foobar2578=== CONT TestGlobMatch/*/*_foo2579=== CONT TestGlobMatch/*_2580=== CONT TestGlobMatch/fo?_fooo2581--- PASS: TestGlobMatch (0.01s)2582 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2583 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2584 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2585 --- PASS: TestGlobMatch/*bar_bar (0.00s)2586 --- PASS: TestGlobMatch/fo?_foo (0.00s)2587 --- PASS: TestGlobMatch/foo*_foo (0.00s)2588 --- PASS: TestGlobMatch/foo_bar (0.00s)2589 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2590 --- PASS: TestGlobMatch/?oo_foo (0.00s)2591 --- PASS: TestGlobMatch/*bar_foo (0.00s)2592 --- PASS: TestGlobMatch/*_anything (0.00s)2593 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2594 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2595 --- PASS: TestGlobMatch/fo?_fo (0.00s)2596 --- PASS: TestGlobMatch/?oo_boo (0.00s)2597 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2598 --- PASS: TestGlobMatch/foo*_bar (0.00s)2599 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2600 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2601 --- PASS: TestGlobMatch/foo_foo (0.00s)2602 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2603 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2604 --- PASS: TestGlobMatch/*/*_foo (0.00s)2605 --- PASS: TestGlobMatch/*_ (0.00s)2606 --- PASS: TestGlobMatch/fo?_fooo (0.00s)26072026/10/11 06:51:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41813/oidc2608--- PASS: TestValidateToken_BoundClaimsMismatch (0.08s)26092026/10/11 06:51:35 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232610--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.13s)26112026/10/11 06:51:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45063/oidc26122026/10/11 06:51:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39995/oidc26132026/10/11 06:51:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39873/oidc26142026/10/11 06:51:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33361/oidc26152026/10/11 06:51:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43399/oidc2616--- PASS: TestValidateToken_Expired (0.18s)2617--- PASS: TestPins_ReservedForMatchingRule (0.18s)2618--- PASS: TestValidateToken_BoundSubjectMismatch (0.17s)2619--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.18s)2620--- PASS: TestValidateToken_WrongAudience (0.18s)26212026/10/11 06:51:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39169/oidc2622--- PASS: TestHTTPClientForHasTimeouts (0.20s)2623--- PASS: TestScopes_Rules (0.21s)26242026/10/11 06:51:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34243/oidc2625--- PASS: TestValidateToken_ValidToken (0.23s)26262026/10/11 06:51:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34625/oidc2627--- PASS: TestPins_TopLevelShorthand (0.25s)26282026/10/11 06:51:35 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34923/oidc26292026/10/11 06:51:35 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:44755/oidc2630--- PASS: TestValidateToken_MultipleProviders (0.36s)26312026/10/11 06:51:35 http: TLS handshake error from 127.0.0.1:48684: remote error: tls: bad certificate2632--- PASS: TestNewValidator_KubernetesRequiresCA (0.39s)26332026/10/11 06:51:35 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:331912634--- PASS: TestValidateToken_KubernetesServiceAccount (0.47s)26352026/10/11 06:51:36 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:38281/oidc2636--- PASS: TestValidateToken_NoMatchingProvider (1.04s)2637PASS2638Running hook tests...2639=== RUN TestSendPathsEmpty2640=== PAUSE TestSendPathsEmpty2641=== RUN TestQueueEnqueueAndFetch2642=== PAUSE TestQueueEnqueueAndFetch2643=== RUN TestQueueDeduplication2644=== PAUSE TestQueueDeduplication2645=== RUN TestQueueRemove2646=== PAUSE TestQueueRemove2647=== RUN TestQueueFetchBatchLimit2648=== PAUSE TestQueueFetchBatchLimit2649=== RUN TestQueueRetryMovesToBack2650=== PAUSE TestQueueRetryMovesToBack2651=== RUN TestQueueFetchRemoveLifecycle2652=== PAUSE TestQueueFetchRemoveLifecycle2653=== RUN TestQueueConcurrentWriters2654=== PAUSE TestQueueConcurrentWriters2655=== RUN TestQueueEnqueueWaitsOutSlowWriter2656=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2657=== RUN TestQueueRemoveLargeClosure2658=== PAUSE TestQueueRemoveLargeClosure2659=== RUN TestServerClientIntegration2660--- PASS: TestServerClientIntegration (0.00s)2661=== RUN TestServerQueueError26622026/10/11 06:51:37 ERROR Failed to queue paths error="permission denied" count=12663--- PASS: TestServerQueueError (0.00s)2664=== RUN TestServerRefusesOversizedAndNonStoreRequests2665=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2666=== RUN TestGetListenerSocketActivation2667 server_test.go:329: === RUN TestGetListenerSocketActivation2668 --- PASS: TestGetListenerSocketActivation (0.00s)2669 PASS2670 2671--- PASS: TestGetListenerSocketActivation (1.02s)2672=== RUN TestServerStalledClientDoesNotBlockShutdown2673=== PAUSE TestServerStalledClientDoesNotBlockShutdown2674=== RUN TestServerBacksOffOnAcceptErrors2675=== PAUSE TestServerBacksOffOnAcceptErrors2676=== RUN TestDrainIsolatesPoisonPath2677=== PAUSE TestDrainIsolatesPoisonPath2678=== RUN TestRunNotBlockedByPoisonHead2679=== PAUSE TestRunNotBlockedByPoisonHead2680=== RUN TestDrainGivesUpWhenServerDown2681=== PAUSE TestDrainGivesUpWhenServerDown2682=== RUN TestFailedPathPrunedByLaterClosure2683=== PAUSE TestFailedPathPrunedByLaterClosure2684=== RUN TestWorkerUploadsAndRemoves2685=== PAUSE TestWorkerUploadsAndRemoves2686=== RUN TestWorkerSkipsGCdPaths2687=== PAUSE TestWorkerSkipsGCdPaths2688=== RUN TestWorkerPrunesClosureDeps2689=== PAUSE TestWorkerPrunesClosureDeps2690=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2691=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2692=== RUN TestDrainTimeout2693=== PAUSE TestDrainTimeout2694=== RUN TestDrainTimeoutDuringIsolation2695=== PAUSE TestDrainTimeoutDuringIsolation2696=== RUN TestShutdownFinishesInFlightPush2697=== PAUSE TestShutdownFinishesInFlightPush2698=== RUN TestWorkerRemoveFailureIsNotProgress2699=== PAUSE TestWorkerRemoveFailureIsNotProgress2700=== RUN TestWorkerKeepsPathItCannotStat2701=== PAUSE TestWorkerKeepsPathItCannotStat2702=== CONT TestSendPathsEmpty2703=== CONT TestDrainIsolatesPoisonPath2704=== CONT TestDrainTimeout2705=== CONT TestFailedPathPrunedByLaterClosure2706=== CONT TestWorkerKeepsPathItCannotStat2707=== CONT TestWorkerSkipsGCdPaths2708=== CONT TestWorkerRemoveFailureIsNotProgress2709=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2710=== CONT TestWorkerPrunesClosureDeps2711=== CONT TestShutdownFinishesInFlightPush2712=== RUN TestShutdownFinishesInFlightPush/completes2713=== CONT TestDrainTimeoutDuringIsolation2714=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2715=== CONT TestDrainGivesUpWhenServerDown2716=== CONT TestWorkerUploadsAndRemoves2717=== CONT TestRunNotBlockedByPoisonHead2718=== CONT TestServerBacksOffOnAcceptErrors2719=== CONT TestQueueRemoveLargeClosure2720=== CONT TestQueueEnqueueWaitsOutSlowWriter2721=== CONT TestServerStalledClientDoesNotBlockShutdown2722=== CONT TestServerRefusesOversizedAndNonStoreRequests2723=== CONT TestQueueConcurrentWriters2724=== CONT TestQueueRemove27252026/10/11 06:51:38 ERROR Accept failed error="too many open files"2726=== CONT TestQueueDeduplication2727--- PASS: TestSendPathsEmpty (0.00s)2728=== CONT TestQueueFetchBatchLimit2729=== CONT TestQueueRetryMovesToBack2730=== CONT TestQueueFetchRemoveLifecycle2731=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2732=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2733=== PAUSE TestShutdownFinishesInFlightPush/completes2734=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch27352026/10/11 06:51:38 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2736=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2737=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2738=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2739=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline27402026/10/11 06:51:38 ERROR Refusing path outside the store path=/nix/store store=/nix/store2741=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2742=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2743=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2744=== CONT TestQueueEnqueueAndFetch2745=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2746=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout27472026/10/11 06:51:38 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store2748=== CONT TestShutdownFinishesInFlightPush/completes27492026/10/11 06:51:38 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store27502026/10/11 06:51:38 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store27512026/10/11 06:51:38 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27522026/10/11 06:51:38 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27532026/10/11 06:51:38 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store27542026/10/11 06:51:38 ERROR Accept failed error="too many open files"27552026/10/11 06:51:38 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store27562026/10/11 06:51:38 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store27572026/10/11 06:51:38 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store27582026/10/11 06:51:38 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store27592026/10/11 06:51:38 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store27602026/10/11 06:51:38 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store27612026/10/11 06:51:38 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store27622026/10/11 06:51:38 ERROR Failed to decode request error="unexpected EOF"2763--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2764=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline27652026/10/11 06:51:38 ERROR Accept failed error="too many open files"27662026/10/11 06:51:38 ERROR Accept failed error="too many open files"27672026/10/11 06:51:38 INFO Upload queue status pending=227682026/10/11 06:51:38 INFO Upload queue status pending=227692026/10/11 06:51:38 INFO Upload queue status pending=227702026/10/11 06:51:38 INFO Uploading batch count=227712026/10/11 06:51:38 INFO Uploading batch count=227722026/10/11 06:51:38 INFO Uploading batch count=227732026/10/11 06:51:38 ERROR Upload failed error="upload failed" count=227742026/10/11 06:51:38 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1081220795/002/a27752026/10/11 06:51:38 INFO Uploading batch count=127762026/10/11 06:51:38 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1081220795/002/b27772026/10/11 06:51:38 INFO Upload queue status pending=327782026/10/11 06:51:38 INFO Uploading batch count=127792026/10/11 06:51:38 ERROR Upload failed error="upload failed" count=127802026/10/11 06:51:38 INFO Uploading batch count=227812026/10/11 06:51:38 ERROR Upload failed error="upload failed" count=227822026/10/11 06:51:38 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1081220795/002/c27832026/10/11 06:51:38 INFO Uploading batch count=227842026/10/11 06:51:38 INFO Uploading batch count=427852026/10/11 06:51:38 ERROR Upload failed error="upload failed" count=427862026/10/11 06:51:38 INFO Upload queue status pending=22787--- PASS: TestQueueRemove (0.06s)2788=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short27892026/10/11 06:51:38 INFO Uploading batch count=22790--- PASS: TestQueueFetchBatchLimit (0.06s)27912026/10/11 06:51:38 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1081220795/002/d2792=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27932026/10/11 06:51:38 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath44638822/002/bbb27942026/10/11 06:51:38 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat916756304/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat916756304/002/locked/aaa: permission denied"27952026/10/11 06:51:38 INFO Upload queue status pending=227962026/10/11 06:51:38 INFO Uploading batch count=227972026/10/11 06:51:38 ERROR Upload failed error="upload failed" count=227982026/10/11 06:51:38 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1081220795/002/e27992026/10/11 06:51:38 INFO Uploading batch count=128002026/10/11 06:51:38 INFO Uploading batch count=228012026/10/11 06:51:38 ERROR Upload failed error="upload failed" count=128022026/10/11 06:51:38 INFO Upload queue status pending=328032026/10/11 06:51:38 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1081220795/002/f28042026/10/11 06:51:38 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat916756304/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat916756304/002/locked/aaa: permission denied"28052026/10/11 06:51:38 INFO Uploading batch count=128062026/10/11 06:51:38 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3080448606/002/nonexistent28072026/10/11 06:51:38 INFO Uploading batch count=428082026/10/11 06:51:38 ERROR Upload failed error="upload failed" count=428092026/10/11 06:51:38 INFO Uploading batch count=12810=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths2811--- PASS: TestQueueDeduplication (0.07s)28122026/10/11 06:51:38 ERROR Upload failed error="upload failed" count=128132026/10/11 06:51:38 ERROR Drain finished with paths left in queue remaining=102814--- PASS: TestQueueFetchRemoveLifecycle (0.07s)2815=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch28162026/10/11 06:51:38 INFO Uploading batch count=228172026/10/11 06:51:38 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat916756304/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat916756304/002/locked/aaa: permission denied"28182026/10/11 06:51:38 ERROR Accept failed error="too many open files"2819--- PASS: TestQueueRetryMovesToBack (0.08s)28202026/10/11 06:51:38 ERROR Drain finished with paths left in queue remaining=128212026/10/11 06:51:38 INFO Uploading batch count=128222026/10/11 06:51:38 INFO Uploading batch count=128232026/10/11 06:51:38 ERROR Upload failed error="upload failed" count=128242026/10/11 06:51:38 INFO Uploading batch count=128252026/10/11 06:51:38 ERROR Upload failed error="upload failed" count=12826--- PASS: TestWorkerUploadsAndRemoves (0.08s)2827--- PASS: TestDrainGivesUpWhenServerDown (0.08s)2828--- PASS: TestQueueEnqueueAndFetch (0.08s)28292026/10/11 06:51:38 ERROR Drain finished with paths left in queue remaining=12830--- PASS: TestFailedPathPrunedByLaterClosure (0.09s)2831--- PASS: TestWorkerPrunesClosureDeps (0.09s)2832--- PASS: TestWorkerKeepsPathItCannotStat (0.09s)2833--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.09s)28342026/10/11 06:51:38 INFO Uploading batch count=428352026/10/11 06:51:38 ERROR Upload failed error="upload failed" count=42836--- PASS: TestDrainIsolatesPoisonPath (0.09s)2837--- PASS: TestWorkerSkipsGCdPaths (0.10s)28382026/10/11 06:51:38 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path447840833/001/nonexistent28392026/10/11 06:51:38 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128402026/10/11 06:51:38 INFO Uploading batch count=228412026/10/11 06:51:38 ERROR Upload failed error="upload failed" count=228422026/10/11 06:51:38 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path447840833/001/nonexistent28432026/10/11 06:51:38 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128442026/10/11 06:51:38 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128452026/10/11 06:51:38 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128462026/10/11 06:51:38 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path447840833/001/nonexistent28472026/10/11 06:51:38 INFO Uploading batch count=228482026/10/11 06:51:38 ERROR Upload failed error="upload failed" count=228492026/10/11 06:51:38 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128502026/10/11 06:51:38 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128512026/10/11 06:51:38 INFO Uploading batch count=228522026/10/11 06:51:38 ERROR Drain finished with paths left in queue remaining=128532026/10/11 06:51:38 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128542026/10/11 06:51:38 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228552026/10/11 06:51:38 INFO Uploading batch count=228562026/10/11 06:51:38 INFO Uploading batch count=228572026/10/11 06:51:38 ERROR Upload failed error="upload failed" count=228582026/10/11 06:51:38 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228592026/10/11 06:51:38 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128602026/10/11 06:51:38 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128612026/10/11 06:51:38 INFO Uploading batch count=228622026/10/11 06:51:38 ERROR Drain finished with paths left in queue remaining=228632026/10/11 06:51:38 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228642026/10/11 06:51:38 ERROR Drain finished with paths left in queue remaining=22865--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2866 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.05s)2867 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.04s)2868 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.04s)28692026/10/11 06:51:38 ERROR Accept failed error="too many open files"28702026/10/11 06:51:38 ERROR Failed to decode request error="read unix /build/hook2707615357/test.sock->@: i/o timeout"28712026/10/11 06:51:38 ERROR Failed to write response error="write unix /build/hook2707615357/test.sock->@: i/o timeout"2872--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)28732026/10/11 06:51:38 ERROR Upload failed error="context canceled" count=228742026/10/11 06:51:38 ERROR Drain finished with paths left in queue remaining=228752026/10/11 06:51:38 ERROR Upload failed error="context canceled" count=228762026/10/11 06:51:38 ERROR Drain finished with paths left in queue remaining=42877--- PASS: TestShutdownFinishesInFlightPush (0.00s)2878 --- PASS: TestShutdownFinishesInFlightPush/completes (0.17s)2879 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.26s)2880--- PASS: TestDrainTimeout (0.26s)28812026/10/11 06:51:38 ERROR Drain finished with paths left in queue remaining=428822026/10/11 06:51:38 ERROR Accept failed error="too many open files"28832026/10/11 06:51:38 ERROR Drain finished with paths left in queue remaining=32884--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2885 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.23s)2886 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.37s)2887--- PASS: TestQueueConcurrentWriters (0.49s)28882026/10/11 06:51:38 ERROR Accept failed error="too many open files"2889--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)28902026/10/11 06:51:39 INFO Uploading batch count=128912026/10/11 06:51:39 INFO Uploading batch count=128922026/10/11 06:51:39 INFO Uploading batch count=128932026/10/11 06:51:39 ERROR Upload failed error="upload failed" count=128942026/10/11 06:51:39 INFO Uploading batch count=128952026/10/11 06:51:39 ERROR Upload failed error="upload failed" count=128962026/10/11 06:51:39 INFO Uploading batch count=128972026/10/11 06:51:39 ERROR Upload failed error="upload failed" count=128982026/10/11 06:51:39 INFO Uploading batch count=128992026/10/11 06:51:39 ERROR Upload failed error="upload failed" count=129002026/10/11 06:51:39 ERROR Drain finished with paths left in queue remaining=12901--- PASS: TestRunNotBlockedByPoisonHead (1.08s)2902--- PASS: TestQueueRemoveLargeClosure (2.91s)2903--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.07s)2904PASS2905Running signing tests...2906=== RUN TestExternalSigner2907=== PAUSE TestExternalSigner2908=== RUN TestExternalSignerWrongPublicKey2909=== PAUSE TestExternalSignerWrongPublicKey2910=== RUN TestExternalSignerErrors2911=== PAUSE TestExternalSignerErrors2912=== RUN TestExternalSignerRestartsAfterCrash2913=== PAUSE TestExternalSignerRestartsAfterCrash2914=== RUN TestExternalSignerProgramErrorKeepsProcess2915=== PAUSE TestExternalSignerProgramErrorKeepsProcess2916=== RUN TestExternalSignerClose2917=== PAUSE TestExternalSignerClose2918=== RUN TestExternalSignerRejectsInvalidPublicKey2919=== PAUSE TestExternalSignerRejectsInvalidPublicKey2920=== RUN TestExternalSignerCancellation2921=== PAUSE TestExternalSignerCancellation2922=== RUN TestGenerateFingerprint2923=== PAUSE TestGenerateFingerprint2924=== RUN TestParseSigningKey2925=== PAUSE TestParseSigningKey2926=== RUN TestSign2927=== PAUSE TestSign2928=== RUN TestSignBatch2929=== PAUSE TestSignBatch2930=== RUN TestNilKeyPublicKey2931=== PAUSE TestNilKeyPublicKey2932=== RUN TestSignErrors2933=== PAUSE TestSignErrors2934=== CONT TestExternalSigner2935=== CONT TestExternalSignerRejectsInvalidPublicKey2936=== RUN TestExternalSignerRejectsInvalidPublicKey/#002937=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002938=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2939=== CONT TestSignBatch2940=== CONT TestSignErrors2941=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2942=== CONT TestNilKeyPublicKey2943=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2944=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2945=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2946--- PASS: TestNilKeyPublicKey (0.00s)2947=== CONT TestExternalSignerRestartsAfterCrash2948=== CONT TestExternalSignerClose2949=== CONT TestExternalSignerProgramErrorKeepsProcess2950=== CONT TestParseSigningKey2951=== RUN TestParseSigningKey/valid_32-byte_key2952=== CONT TestExternalSignerWrongPublicKey2953=== CONT TestExternalSignerCancellation2954=== CONT TestExternalSignerErrors2955=== PAUSE TestParseSigningKey/valid_32-byte_key2956=== CONT TestGenerateFingerprint2957=== CONT TestSign2958=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2959=== RUN TestExternalSignerErrors/wrong_shape2960=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2961=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2962=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2963=== RUN TestGenerateFingerprint/basic_with_references2964=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2965=== PAUSE TestExternalSignerErrors/wrong_shape2966=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2967=== RUN TestExternalSignerErrors/unrequested_key2968=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2969=== CONT TestExternalSignerRejectsInvalidPublicKey/#002970=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2971=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2972=== PAUSE TestGenerateFingerprint/basic_with_references2973=== RUN TestGenerateFingerprint/no_references2974=== PAUSE TestExternalSignerErrors/unrequested_key2975=== RUN TestExternalSignerErrors/program_error2976=== RUN TestParseSigningKey/no_colon2977=== PAUSE TestParseSigningKey/no_colon2978--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2979 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2980 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2981 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2982 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2983 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2984=== PAUSE TestGenerateFingerprint/no_references2985=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2986=== PAUSE TestExternalSignerErrors/program_error2987=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2988=== RUN TestExternalSignerErrors/exit_on_request2989=== RUN TestParseSigningKey/empty_name2990=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2991=== PAUSE TestParseSigningKey/empty_name2992=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2993=== PAUSE TestExternalSignerErrors/exit_on_request2994=== RUN TestParseSigningKey/invalid_base642995=== RUN TestGenerateFingerprint/invalid_nar_hash_length2996=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2997=== PAUSE TestParseSigningKey/invalid_base642998=== RUN TestGenerateFingerprint/invalid_store_path_prefix2999=== RUN TestExternalSignerErrors/missing_signature_name3000=== RUN TestParseSigningKey/wrong_length3001=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix3002=== PAUSE TestExternalSignerErrors/missing_signature_name3003=== RUN TestExternalSignerErrors/wrong_signature_name3004=== PAUSE TestParseSigningKey/wrong_length3005=== PAUSE TestExternalSignerErrors/wrong_signature_name3006=== CONT TestParseSigningKey/invalid_base643007=== RUN TestExternalSignerErrors/wrong_signature_length3008=== CONT TestParseSigningKey/empty_name3009=== CONT TestParseSigningKey/wrong_length3010=== CONT TestParseSigningKey/no_colon3011=== RUN TestGenerateFingerprint/invalid_reference_prefix3012=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name3013=== PAUSE TestGenerateFingerprint/invalid_reference_prefix3014=== CONT TestParseSigningKey/valid_32-byte_key3015=== PAUSE TestExternalSignerErrors/wrong_signature_length3016=== CONT TestGenerateFingerprint/basic_with_references3017=== CONT TestGenerateFingerprint/invalid_nar_hash_length3018=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix3019=== CONT TestGenerateFingerprint/invalid_reference_prefix3020=== CONT TestGenerateFingerprint/invalid_store_path_prefix3021=== CONT TestGenerateFingerprint/no_references3022=== RUN TestExternalSignerErrors/invalid_JSON3023=== PAUSE TestExternalSignerErrors/invalid_JSON3024=== CONT TestGenerateFingerprint/unsorted_references_get_sorted3025--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)3026=== RUN TestExternalSignerErrors/wrong_id3027=== PAUSE TestExternalSignerErrors/wrong_id3028--- PASS: TestGenerateFingerprint (0.00s)3029 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)3030 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)3031 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)3032 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)3033 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)3034 --- PASS: TestGenerateFingerprint/no_references (0.00s)3035 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)3036=== RUN TestExternalSignerErrors/missing_signatures3037=== PAUSE TestExternalSignerErrors/missing_signatures3038=== RUN TestExternalSignerErrors/wrong_signatures_shape3039=== PAUSE TestExternalSignerErrors/wrong_signatures_shape3040=== RUN TestExternalSignerErrors/invalid_signature_base643041=== PAUSE TestExternalSignerErrors/invalid_signature_base643042=== RUN TestExternalSignerErrors/null3043=== PAUSE TestExternalSignerErrors/null3044=== RUN TestExternalSignerErrors/null_signatures3045=== PAUSE TestExternalSignerErrors/null_signatures3046=== RUN TestExternalSignerErrors/too_few_signatures3047=== PAUSE TestExternalSignerErrors/too_few_signatures3048=== RUN TestExternalSignerErrors/exit_at_startup3049=== PAUSE TestExternalSignerErrors/exit_at_startup3050=== CONT TestExternalSignerErrors/unrequested_key3051=== CONT TestExternalSignerErrors/invalid_signature_base643052=== CONT TestExternalSignerErrors/missing_signature_name3053=== CONT TestExternalSignerErrors/wrong_signatures_shape3054=== CONT TestExternalSignerErrors/missing_signatures3055=== CONT TestExternalSignerErrors/null3056=== CONT TestExternalSignerErrors/null_signatures3057=== CONT TestExternalSignerErrors/exit_on_request3058=== CONT TestExternalSignerErrors/too_few_signatures3059=== CONT TestExternalSignerErrors/invalid_JSON3060=== CONT TestExternalSignerErrors/exit_at_startup3061=== CONT TestExternalSignerErrors/wrong_signature_name3062=== CONT TestExternalSignerErrors/wrong_id3063=== CONT TestExternalSignerErrors/program_error3064--- PASS: TestExternalSignerWrongPublicKey (0.01s)3065=== CONT TestExternalSignerErrors/wrong_signature_length3066--- PASS: TestExternalSignerClose (0.01s)3067=== CONT TestExternalSignerErrors/wrong_shape3068--- PASS: TestExternalSignerErrors (0.00s)3069 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)3070 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)3071 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)3072 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)3073 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)3074 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)3075 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)3076 --- PASS: TestExternalSignerErrors/program_error (0.01s)3077 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)3078 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)3079 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)3080 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)3081 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)3082 --- PASS: TestExternalSignerErrors/null (0.01s)3083 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)3084 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.00s)3085--- PASS: TestExternalSignerRestartsAfterCrash (0.02s)3086=== RUN TestSignErrors/nil_key3087=== PAUSE TestSignErrors/nil_key3088=== RUN TestSignErrors/nil_narinfo3089=== PAUSE TestSignErrors/nil_narinfo3090--- PASS: TestParseSigningKey (0.00s)3091 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)3092 --- PASS: TestParseSigningKey/empty_name (0.00s)3093 --- PASS: TestParseSigningKey/wrong_length (0.00s)3094 --- PASS: TestParseSigningKey/no_colon (0.00s)3095 --- PASS: TestParseSigningKey/valid_32-byte_key (0.01s)3096 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.01s)3097=== RUN TestSignErrors/invalid_narinfo3098=== PAUSE TestSignErrors/invalid_narinfo3099=== RUN TestSignErrors/canceled3100=== PAUSE TestSignErrors/canceled3101=== CONT TestSignErrors/invalid_narinfo3102=== CONT TestSignErrors/nil_narinfo3103=== CONT TestSignErrors/nil_key3104=== CONT TestSignErrors/canceled3105--- PASS: TestSignErrors (0.02s)3106 --- PASS: TestSignErrors/invalid_narinfo (0.00s)3107 --- PASS: TestSignErrors/nil_narinfo (0.00s)3108 --- PASS: TestSignErrors/nil_key (0.00s)3109 --- PASS: TestSignErrors/canceled (0.00s)3110--- PASS: TestSign (0.02s)3111--- PASS: TestExternalSigner (0.02s)3112--- PASS: TestExternalSignerCancellation (0.02s)3113--- PASS: TestSignBatch (0.03s)3114PASS3115Running OpenBao signer tests...3116=== RUN TestSign3117=== PAUSE TestSign3118=== RUN TestSignErrors3119=== PAUSE TestSignErrors3120=== RUN TestServe3121=== PAUSE TestServe3122=== RUN TestServeRejectsGarbage3123=== PAUSE TestServeRejectsGarbage3124=== CONT TestSign3125=== CONT TestServe3126=== CONT TestServeRejectsGarbage3127=== CONT TestSignErrors3128=== RUN TestSignErrors/http_error3129--- PASS: TestServeRejectsGarbage (0.00s)3130=== PAUSE TestSignErrors/http_error3131=== RUN TestSignErrors/invalid_json3132=== PAUSE TestSignErrors/invalid_json3133=== RUN TestSignErrors/no_prefix3134=== PAUSE TestSignErrors/no_prefix3135=== RUN TestSignErrors/invalid_base643136=== PAUSE TestSignErrors/invalid_base643137=== CONT TestSignErrors/http_error3138=== CONT TestSignErrors/invalid_base643139--- PASS: TestServe (0.00s)3140=== CONT TestSignErrors/invalid_json3141=== CONT TestSignErrors/no_prefix3142--- PASS: TestSign (0.01s)3143--- PASS: TestSignErrors (0.00s)3144 --- PASS: TestSignErrors/invalid_json (0.00s)3145 --- PASS: TestSignErrors/http_error (0.00s)3146 --- PASS: TestSignErrors/invalid_base64 (0.00s)3147 --- PASS: TestSignErrors/no_prefix (0.00s)3148PASS3149Running niks3-hook command tests...3150=== RUN TestServeSecondSignalEndsDrain3151=== PAUSE TestServeSecondSignalEndsDrain3152=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown3153=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown3154=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown3155=== CONT TestServeSecondSignalEndsDrain3156--- PASS: TestServeSecondSignalEndsDrain (0.07s)31572026/10/11 06:51:47 INFO Upload queue status pending=131582026/10/11 06:51:47 INFO Uploading batch count=13159--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.12s)3160PASS3161Running rate limiter tests...3162=== RUN TestAdaptiveRateLimiter_ThreadSafety3163=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3164=== CONT TestAdaptiveRateLimiter_ThreadSafety31652026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=7031662026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=4931672026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=34.331682026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=24.00999999999999831692026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=16.80731702026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=11.76489999999999931712026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=8.2354331722026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=9.28426965851000231732026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=6.49898876095700131742026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531752026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531762026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531772026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531782026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531792026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531802026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531812026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531822026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531832026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531842026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531852026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531862026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531872026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531882026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531892026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531902026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531912026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531922026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531932026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531942026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531952026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531962026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531972026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531982026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=531992026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532002026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532012026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532022026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532032026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532042026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532052026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532062026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532072026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=7.50256083500000332082026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=5.25179258450000232092026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532102026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532112026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532122026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532132026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532142026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532152026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532162026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532172026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532182026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532192026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532202026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532212026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532222026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532232026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532242026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532252026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532262026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=5.12435000000000132272026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532282026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532292026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532302026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532312026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532322026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532332026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532342026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532352026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532362026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532372026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532382026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532392026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532402026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532412026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532422026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532432026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532442026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532452026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532462026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532472026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532482026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532492026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532502026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532512026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532522026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532532026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532542026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532552026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=5.12435000000000132562026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532572026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532582026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532592026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532602026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532612026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532622026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532632026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=532642026/10/11 06:51:48 WARN Rate limiter backed off name=test rate=53265--- PASS: TestAdaptiveRateLimiter_ThreadSafety (3.20s)3266PASS