niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #390
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure18=== PAUSE TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure19=== RUN TestUploadMultipart_PartsInParallel20=== PAUSE TestUploadMultipart_PartsInParallel21=== RUN TestUploadMultipart_ProducerErrorIsNotEOF22=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF23=== RUN TestUploadMultipart_FailedPartBufferNotReused24=== PAUSE TestUploadMultipart_FailedPartBufferNotReused25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestUploadMultipart_SupersededByPeer28=== PAUSE TestUploadMultipart_SupersededByPeer29=== RUN TestDumpPathCaseHackMatchesNix30--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)31=== RUN TestDumpPathCaseHackCollision32--- PASS: TestDumpPathCaseHackCollision (0.00s)33=== RUN TestSupersededNARStillUploadsListing34=== PAUSE TestSupersededNARStillUploadsListing35=== RUN TestTruncatedNARDumpIsNotCompleted36=== PAUSE TestTruncatedNARDumpIsNotCompleted37=== RUN TestDumpPathMatchesNix38=== PAUSE TestDumpPathMatchesNix39=== RUN TestDumpPathSingleFile40=== PAUSE TestDumpPathSingleFile41=== RUN TestDumpPathWriterError42=== PAUSE TestDumpPathWriterError43=== RUN TestDumpPathWriterErrorStopsReading44 nar_test.go:289: read 114 of 32768000 bytes45--- PASS: TestDumpPathWriterErrorStopsReading (0.60s)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.01s)64=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent65=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent66=== RUN TestCompletePendingClosure_NotFoundWithoutKey67=== PAUSE TestCompletePendingClosure_NotFoundWithoutKey68=== RUN TestRateLimiterFeedback69=== PAUSE TestRateLimiterFeedback70=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess71=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess72=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer73=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer74=== RUN TestResolveStorePath75=== PAUSE TestResolveStorePath76=== RUN TestDoWithRetry_BodyReplayedViaGetBody77=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody78=== RUN TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade79=== PAUSE TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade80=== 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 TestClientSignaturesByStorePath99=== PAUSE TestClientSignaturesByStorePath100=== RUN TestStreamPushStopsOnCancel101=== PAUSE TestStreamPushStopsOnCancel102=== RUN TestSetClientTLS103=== PAUSE TestSetClientTLS104=== RUN TestSetClientTLSDoesNotMutateDefaultTransport105=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport106=== RUN TestSetClientTLSErrors107=== PAUSE TestSetClientTLSErrors108=== RUN TestStaticToken109=== PAUSE TestStaticToken110=== RUN TestFileTokenReadsAndCaches111=== PAUSE TestFileTokenReadsAndCaches112=== RUN TestFileTokenMissing113=== PAUSE TestFileTokenMissing114=== RUN TestFileTokenEmpty115=== PAUSE TestFileTokenEmpty116=== RUN TestScriptTokenNoExpiryRerunsEveryCall117=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall118=== RUN TestScriptTokenCachesUntilRefresh119=== PAUSE TestScriptTokenCachesUntilRefresh120=== RUN TestScriptTokenEmptyToken121=== PAUSE TestScriptTokenEmptyToken122=== RUN TestScriptTokenBadJSON123=== PAUSE TestScriptTokenBadJSON124=== RUN TestScriptTokenScriptFails125=== PAUSE TestScriptTokenScriptFails126=== RUN TestScriptTokenEmptyCommand127=== PAUSE TestScriptTokenEmptyCommand128=== RUN TestScriptTokenDoesNotWaitForItsChildren129=== PAUSE TestScriptTokenDoesNotWaitForItsChildren130=== CONT TestGetStorePathHash131=== CONT TestStreamPushStopsOnCancel132=== CONT TestPathInfoCACompatibility133=== CONT TestStreamPushRequestLine134=== CONT TestDoWithRetry_BodyReplayedViaGetBody135=== CONT TestEncodeNixBase32136=== RUN TestEncodeNixBase32/test_string_hash137=== CONT TestParsePathInfoJSON138=== CONT TestDoServerRequestAttachesToken139=== CONT TestShellSplit140=== CONT TestDoWithRetry_FinalResponseBodyReadable141=== CONT TestScriptTokenDoesNotWaitForItsChildren142--- PASS: TestShellSplit (0.00s)143=== CONT TestScriptTokenScriptFails144=== CONT TestScriptTokenCachesUntilRefresh145=== CONT TestScriptTokenBadJSON146=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer147=== CONT TestFileTokenMissing148=== RUN TestGetStorePathHash/valid_store_path149=== PAUSE TestGetStorePathHash/valid_store_path150=== CONT TestSetClientTLSDoesNotMutateDefaultTransport151=== RUN TestGetStorePathHash/basename_without_hyphen_should_error152=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error153=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error154=== CONT TestResolveStorePath155=== CONT TestScriptTokenEmptyCommand156=== CONT TestStaticToken157=== CONT TestScriptTokenEmptyToken158=== RUN TestStreamPushStopsOnCancel/waiting_for_input159=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry160=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent161=== CONT TestStreamPushGivesUpOnDeadServer162=== CONT TestUploadMultipart_ProducerErrorIsNotEOF163=== RUN TestPathInfoCACompatibility/null_ca_field164=== PAUSE TestEncodeNixBase32/test_string_hash165=== RUN TestParsePathInfoJSON/Nix_format166=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs167=== CONT TestFileTokenEmpty168--- PASS: TestFileTokenMissing (0.00s)169=== CONT TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade170=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error171=== CONT TestSetClientTLSErrors172=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess173=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part174=== PAUSE TestPathInfoCACompatibility/null_ca_field175=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input176=== CONT TestConvertHashToNix32177--- PASS: TestStaticToken (0.00s)178=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs179=== RUN TestEncodeNixBase32/empty_input180=== CONT TestCompletePendingClosure_NotFoundWithoutKey181=== PAUSE TestEncodeNixBase32/empty_input182=== CONT TestScriptTokenNoExpiryRerunsEveryCall183=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier184=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier185=== RUN TestConvertHashToNix32/SRI_format_to_Nix32186=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32187=== CONT TestFileTokenReadsAndCaches188=== CONT TestStreamPushReportsSignatures189=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up190=== CONT TestParsePathInfoJSONMultiplePaths191--- PASS: TestScriptTokenEmptyCommand (0.00s)192=== RUN TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0193=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up194--- PASS: TestScriptTokenScriptFails (0.00s)195=== PAUSE TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0196--- PASS: TestResolveStorePath (0.00s)197--- PASS: TestDoServerRequestAttachesToken (0.01s)198=== CONT TestUploadMultipart_FailedPartBufferNotReused199=== RUN TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=5200=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun201=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot202=== CONT TestRegisterUploadedObjectReusesConnections203=== RUN TestPathInfoCACompatibility/old_string_format_-_text204=== RUN TestSetClientTLSErrors/missing_cert_file205=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot206=== PAUSE TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=5207=== PAUSE TestParsePathInfoJSON/Nix_format208=== CONT TestSupersededNARStillUploadsListing209=== CONT TestClientSignaturesByStorePath210=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error211=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout212=== RUN TestConvertHashToNix32/already_Nix32_format213=== CONT TestPathInfoHashCompatibility214=== CONT TestSetClientTLS215=== CONT TestDumpPathWriterError216--- PASS: TestFileTokenEmpty (0.00s)217=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths218=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier219=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part220=== RUN TestParsePathInfoJSON/Lix_format221=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text222=== CONT TestFilterOversizedClosures223=== PAUSE TestSetClientTLSErrors/missing_cert_file224=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout225=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot226=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary227=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier228=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths229=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot230=== CONT TestDumpPathSingleFile231=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot232=== RUN TestSupersededNARStillUploadsListing/small_NAR233--- PASS: TestScriptTokenEmptyToken (0.00s)234--- PASS: TestScriptTokenBadJSON (0.01s)235=== PAUSE TestConvertHashToNix32/already_Nix32_format236=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)237=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)238=== PAUSE TestParsePathInfoJSON/Lix_format239=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica240=== RUN TestParsePathInfoJSON/empty_input241=== PAUSE TestParsePathInfoJSON/empty_input242=== RUN TestParsePathInfoJSON/whitespace_only243=== PAUSE TestSupersededNARStillUploadsListing/small_NAR244--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)245=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths246=== PAUSE TestParsePathInfoJSON/whitespace_only247=== RUN TestParsePathInfoJSON/invalid_JSON248=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error249=== RUN TestFilterOversizedClosures/no_limit_keeps_everything250=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary251=== CONT TestPartSizeForNAR252=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths253=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon254=== RUN TestSetClientTLS/rejects_connection_without_client_cert255=== RUN TestSetClientTLSErrors/missing_key_file256--- PASS: TestStreamPushReportsSignatures (0.00s)257=== RUN TestSupersededNARStillUploadsListing/dump_cut_short258=== PAUSE TestSetClientTLSErrors/missing_key_file259=== RUN TestSetClientTLSErrors/missing_ca_file260=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short261=== PAUSE TestSetClientTLSErrors/missing_ca_file262=== RUN TestSetClientTLSErrors/invalid_ca_file263=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert264=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA265=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA266=== RUN TestSetClientTLS/preserves_debug_logging_transport267=== PAUSE TestSetClientTLSErrors/invalid_ca_file268=== CONT TestShellSplitErrors269=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails270=== PAUSE TestSetClientTLS/preserves_debug_logging_transport271=== CONT TestDumpPathMatchesNix272=== RUN TestConvertHashToNix32/invalid_format273=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client274=== PAUSE TestParsePathInfoJSON/invalid_JSON275=== CONT TestStreamPushBatchesUnderLoad276=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything277=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive278=== CONT TestStreamPushIsolatesFailures279=== CONT TestEncodeNixBase32WithRealHash280=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon281=== RUN TestPartSizeForNAR/zero_stays_at_minimum282--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)283=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot284=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails285=== CONT TestStreamPushReportsEveryPath286=== PAUSE TestConvertHashToNix32/invalid_format287=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client288=== CONT TestRateLimiterFeedback289=== RUN TestStreamPushBatchesUnderLoad/together290=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped291=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive292=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI293=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot294=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum295--- PASS: TestFileTokenReadsAndCaches (0.00s)296=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure297=== CONT TestUploadMultipart_SupersededByPeer298=== RUN TestUploadMultipart_SupersededByPeer/exists299--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)300=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client301=== RUN TestRateLimiterFeedback/429_enables_limiter302--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)303=== PAUSE TestUploadMultipart_SupersededByPeer/exists304--- PASS: TestStreamPushIsolatesFailures (0.00s)305=== CONT TestCaseHackSuffix306=== PAUSE TestRateLimiterFeedback/429_enables_limiter307=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client308=== CONT TestUploadMultipart_PartsInParallel309=== RUN TestUploadMultipart_SupersededByPeer/missing310=== CONT TestTruncatedNARDumpIsNotCompleted311=== PAUSE TestStreamPushBatchesUnderLoad/together312=== RUN TestPathInfoCACompatibility/new_structured_format_-_text313=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped314=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI315=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot316=== RUN TestPartSizeForNAR/small_stays_at_minimum317=== RUN TestRateLimiterFeedback/503_enables_limiter318--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)319=== PAUSE TestUploadMultipart_SupersededByPeer/missing320=== CONT TestEncodeNixBase32/test_string_hash321=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text322=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time323=== CONT TestEncodeNixBase32/empty_input324=== CONT TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0325=== RUN TestFilterOversizedClosures/all_closures_skipped326=== PAUSE TestFilterOversizedClosures/all_closures_skipped327=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512328=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken329=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512330--- PASS: TestClientSignaturesByStorePath (0.00s)331--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)332=== CONT TestGetStorePathHash/valid_store_path333=== PAUSE TestRateLimiterFeedback/503_enables_limiter334=== PAUSE TestPartSizeForNAR/small_stays_at_minimum335=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths336=== CONT TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=5337=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part338=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum339=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error340=== CONT TestGetStorePathHash/basename_without_hyphen_should_error341=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum342=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time343=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs344=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method345=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout346=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter347=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken348=== CONT TestSetClientTLSErrors/invalid_ca_file349--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.01s)350=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error351=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts352=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts353=== CONT TestSetClientTLSErrors/missing_cert_file354=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary355=== RUN TestPartSizeForNAR/1_TiB356=== PAUSE TestPartSizeForNAR/1_TiB357=== RUN TestPartSizeForNAR/5_TiB_S3_max_object358=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths359=== CONT TestSetClientTLSErrors/missing_key_file360=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method361=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter362--- PASS: TestShellSplitErrors (0.00s)363--- PASS: TestEncodeNixBase32WithRealHash (0.00s)364=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA365=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object366--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.02s)367--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.03s)368=== RUN TestPartSizeForNAR/capped_at_5_GiB369=== CONT TestSetClientTLSErrors/missing_ca_file370=== CONT TestSetClientTLS/rejects_connection_without_client_cert371=== CONT TestParsePathInfoJSON/empty_input372=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter373=== CONT TestSetClientTLS/preserves_debug_logging_transport374=== CONT TestParsePathInfoJSON/Nix_format375=== CONT TestParsePathInfoJSON/invalid_JSON376--- PASS: TestStreamPushReportsEveryPath (0.00s)377=== CONT TestParsePathInfoJSON/whitespace_only378=== PAUSE TestPartSizeForNAR/capped_at_5_GiB379=== CONT TestParsePathInfoJSON/Lix_format380=== CONT TestSupersededNARStillUploadsListing/dump_cut_short381=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails382=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter383=== CONT TestConvertHashToNix32/invalid_format384=== CONT TestConvertHashToNix32/already_Nix32_format385=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up386=== CONT TestConvertHashToNix32/SRI_format_to_Nix32387=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client388=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client389--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.02s)390=== CONT TestSupersededNARStillUploadsListing/small_NAR391--- PASS: TestDumpPathSingleFile (0.27s)392=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier393=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier394--- PASS: TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade (0.01s)395 --- PASS: TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0 (0.00s)396 --- PASS: TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=5 (0.00s)397=== CONT TestUploadMultipart_SupersededByPeer/missing398--- PASS: TestGetStorePathHash (0.02s)399 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)400 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)401 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)402 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)403--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)404 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)405 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.24s)406--- PASS: TestEncodeNixBase32 (0.01s)407 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)408 --- PASS: TestEncodeNixBase32/empty_input (0.00s)409--- PASS: TestConvertHashToNix32 (0.02s)410 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)411 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)412 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)413--- PASS: TestParsePathInfoJSON (0.03s)414 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)415 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)416 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)417 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)418 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)419--- PASS: TestSetClientTLSErrors (0.02s)420 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)421 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)422 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)423 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)424=== CONT TestUploadMultipart_SupersededByPeer/exists425=== CONT TestFilterOversizedClosures/no_limit_keeps_everything426=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)427--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.03s)428 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.01s)429 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.01s)430 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.01s)431 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.00s)432 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.00s)433=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI434=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon435=== CONT TestFilterOversizedClosures/all_closures_skipped436=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512437=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped438=== CONT TestStreamPushBatchesUnderLoad/together439--- PASS: TestFilterOversizedClosures (0.02s)440 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)441 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)442 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)443--- PASS: TestPathInfoHashCompatibility (0.02s)444 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)445 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)446 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)447 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)448=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time449=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot450--- PASS: TestStreamPushBatchesUnderLoad (0.01s)451 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)452 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)453=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken454=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot455=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot456--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)457 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)458 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)459--- PASS: TestCaseHackSuffix (0.29s)460=== CONT TestStreamPushStopsOnCancel/waiting_for_input461=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot462=== CONT TestPathInfoCACompatibility/null_ca_field463=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method464=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive465=== CONT TestPathInfoCACompatibility/new_structured_format_-_text466=== CONT TestPathInfoCACompatibility/old_string_format_-_text467=== CONT TestPartSizeForNAR/small_stays_at_minimum468--- PASS: TestPathInfoCACompatibility (0.28s)469 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)470 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)471 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)472 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)473 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)474=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts475=== CONT TestRateLimiterFeedback/429_enables_limiter476=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter477=== CONT TestRateLimiterFeedback/503_enables_limiter478=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter479=== CONT TestPartSizeForNAR/capped_at_5_GiB480=== CONT TestPartSizeForNAR/1_TiB481=== CONT TestPartSizeForNAR/5_TiB_S3_max_object482--- PASS: TestRateLimiterFeedback (0.27s)483 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)484 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)485 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)486 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)487=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum488=== CONT TestPartSizeForNAR/zero_stays_at_minimum489--- PASS: TestPartSizeForNAR (0.27s)490 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)491 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)492 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)493 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)494 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)495 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)496 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)497--- PASS: TestDumpPathWriterError (0.32s)498--- PASS: TestStreamPushStopsOnCancel (0.04s)499 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.26s)500 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.26s)501 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.26s)502 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.26s)503 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.26s)504 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.26s)505--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.55s)506--- PASS: TestSetClientTLS (0.01s)507 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.03s)508 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.03s)509 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.35s)510--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.02s)511 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.65s)512 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.66s)513--- PASS: TestRegisterUploadedObjectReusesConnections (0.69s)514--- PASS: TestDumpPathMatchesNix (0.68s)515--- PASS: TestStreamPushRequestLine (0.72s)516--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)517--- PASS: TestTruncatedNARDumpIsNotCompleted (1.34s)518--- PASS: TestSupersededNARStillUploadsListing (0.02s)519 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.02s)520 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.02s)521 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.08s)522--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.43s)523--- PASS: TestUploadMultipart_PartsInParallel (1.42s)524--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (2.00s)525--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.02s)526 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.25s)527 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.25s)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/postgres3254993137/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/postgres3254993137/data -l logfile start556557/build/postgres3254993137:5432 - no response5582026-10-06 23:00:50.990 UTC [168] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5592026-10-06 23:00:50.990 UTC [168] LOG: listening on Unix socket "/build/postgres3254993137/.s.PGSQL.5432"5602026-10-06 23:00:50.995 UTC [175] LOG: database system was shut down at 2026-10-06 23:00:50 UTC5612026-10-06 23:00:50.998 UTC [168] LOG: database system is ready to accept connections562/build/postgres3254993137: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/06 23:00:51 INFO lead: acquired remote=192.0.2.1:12346132026/10/06 23:00:52 INFO lead: released remote=192.0.2.1:12346142026/10/06 23:00:52 INFO lead: acquired remote=192.0.2.1:12346152026/10/06 23:00:53 INFO lead: released remote=192.0.2.1:1234616--- PASS: TestLeadIncumbentWinsAfterRestart (1.92s)617=== RUN TestLeadIncumbentAnnouncesAtOnce618=== PAUSE TestLeadIncumbentAnnouncesAtOnce619=== RUN TestLeadEndsOnShutdown620=== PAUSE TestLeadEndsOnShutdown621=== RUN TestLeadEndsWhenItsConnectionHangs6222026/10/06 23:00:53 INFO lead: acquired remote=192.0.2.1:12346232026-10-06 23:00:54.749 UTC [424] FATAL: terminating connection due to administrator command6242026/10/06 23:00:54 INFO lead: acquired remote=192.0.2.1:12346252026/10/06 23:00:55 WARN lead: lock connection lost error="timeout: context deadline exceeded"6262026/10/06 23:00:55 INFO lead: released remote=192.0.2.1:12346272026/10/06 23:00:56 INFO lead: released remote=192.0.2.1:1234628--- PASS: TestLeadEndsWhenItsConnectionHangs (3.15s)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 TestCacheConfigHandlerMaxNarSize690=== PAUSE TestCacheConfigHandlerMaxNarSize691=== RUN TestCreatePendingClosureRejectsOversizedNAR692=== PAUSE TestCreatePendingClosureRejectsOversizedNAR693=== RUN TestNARDeduplicationMetadataUploadBug694=== PAUSE TestNARDeduplicationMetadataUploadBug695=== RUN TestMetricsInventory696=== PAUSE TestMetricsInventory697=== RUN TestService_NativeMTLS698=== PAUSE TestService_NativeMTLS699=== RUN TestServerTLSConfig700=== PAUSE TestServerTLSConfig701=== RUN TestMultipartCleanup702=== PAUSE TestMultipartCleanup703=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded704=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded705=== RUN TestPendingCleanupUsesOneCutoff706=== PAUSE TestPendingCleanupUsesOneCutoff707=== RUN TestPendingClosureFailureTracksEveryUpload708=== PAUSE TestPendingClosureFailureTracksEveryUpload709=== RUN TestPendingClosureFailureAbortsItsUploads710=== PAUSE TestPendingClosureFailureAbortsItsUploads711=== RUN TestObjectStatsTrigger712=== PAUSE TestObjectStatsTrigger713=== RUN TestObjectStatsLargeCommit714=== PAUSE TestObjectStatsLargeCommit715=== RUN TestReconnectLeavesObjectsUnlocked716=== PAUSE TestReconnectLeavesObjectsUnlocked717=== RUN TestOrphanedObjectsGC718=== PAUSE TestOrphanedObjectsGC719=== RUN TestOrphanedObjectsGCStressTest720=== PAUSE TestOrphanedObjectsGCStressTest721=== RUN TestCreatePin_ReservedPins722=== PAUSE TestCreatePin_ReservedPins723=== RUN TestConcurrentPinUpdatesAgree724=== PAUSE TestConcurrentPinUpdatesAgree725=== RUN TestCreatePinRejectsBadInput726=== PAUSE TestCreatePinRejectsBadInput727=== RUN TestDeletePinKeepsRowWhenS3Fails728=== PAUSE TestDeletePinKeepsRowWhenS3Fails729=== RUN TestPresentReportsOnlyClosureRoots730=== PAUSE TestPresentReportsOnlyClosureRoots731=== RUN TestPresentRefreshesOnlyStaleClosures732=== PAUSE TestPresentRefreshesOnlyStaleClosures733=== RUN TestPresentNotReportedWhileGCDeletesClosure734=== PAUSE TestPresentNotReportedWhileGCDeletesClosure735=== RUN TestParseSingleRange736=== PAUSE TestParseSingleRange737=== RUN TestProxyHeadersOnlyTrustedOnSocket738=== PAUSE TestProxyHeadersOnlyTrustedOnSocket739=== RUN TestIsValidCachePath740=== PAUSE TestIsValidCachePath741=== RUN TestReadProxyNarinfo742=== PAUSE TestReadProxyNarinfo743=== RUN TestReadProxyNarinfoAlreadyDecompressed744=== PAUSE TestReadProxyNarinfoAlreadyDecompressed745=== RUN TestReadProxyContentNegotiation746=== PAUSE TestReadProxyContentNegotiation747=== RUN TestReadProxyNarStreaming748=== PAUSE TestReadProxyNarStreaming749=== RUN TestReadProxy404750=== PAUSE TestReadProxy404751=== RUN TestReadProxyInvalidPath752=== PAUSE TestReadProxyInvalidPath753=== RUN TestReadProxyHead754=== PAUSE TestReadProxyHead755=== RUN TestReadProxyOutlastsServerWriteTimeout756=== PAUSE TestReadProxyOutlastsServerWriteTimeout757=== RUN TestReadProxyConditionalGet758=== PAUSE TestReadProxyConditionalGet759=== RUN TestReadProxyRootRedirectsToIndexHTML760=== PAUSE TestReadProxyRootRedirectsToIndexHTML761=== RUN TestReadProxyDisabled762=== PAUSE TestReadProxyDisabled763=== RUN TestReadRedirectNar764=== PAUSE TestReadRedirectNar765=== RUN TestReadRedirectKeepsNarinfoProxied766=== PAUSE TestReadRedirectKeepsNarinfoProxied767=== RUN TestReadProxyRangeRequest768=== PAUSE TestReadProxyRangeRequest769=== RUN TestReadRedirectUsesPublicS3URL770=== PAUSE TestReadRedirectUsesPublicS3URL771=== RUN TestPush_OverlappingRootsStoreOneRowPerKey772=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey773=== RUN TestPush_CompleteCommitsEveryRoot774=== PAUSE TestPush_CompleteCommitsEveryRoot775=== RUN TestPush_RepeatedRootCommitsOnce776=== PAUSE TestPush_RepeatedRootCommitsOnce777=== RUN TestPush_CompleteWaitsForCleanupOfThePush778=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush779=== RUN TestPush_RootsAreLockedInByteOrder780=== PAUSE TestPush_RootsAreLockedInByteOrder781=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit782=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit783=== RUN TestPush_RejectsBadRequests784=== PAUSE TestPush_RejectsBadRequests785=== RUN TestPush_SignsNarinfosOfItsPendingObjects786=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects787=== RUN TestRedundantMultipartUpload788=== PAUSE TestRedundantMultipartUpload789=== RUN TestCompleteMultipartUpload_ErrorButObjectExists790=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists791=== RUN TestCompletedNarNotReofferedAcrossClosures792=== PAUSE TestCompletedNarNotReofferedAcrossClosures793=== RUN TestPresignedUploadRegisteredBeforeCommit794=== PAUSE TestPresignedUploadRegisteredBeforeCommit795=== RUN TestService_Rustfstest796=== PAUSE TestService_Rustfstest797=== RUN TestParseSize798=== PAUSE TestParseSize799=== RUN TestSkippedUploadsHandler800=== PAUSE TestSkippedUploadsHandler801=== RUN TestSystemdListenerNotActivated802--- PASS: TestSystemdListenerNotActivated (0.00s)803=== RUN TestWatchdogBeatsWhenHealthy804--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)805=== RUN TestWatchdogSkipsWhenUnhealthy8062026/10/06 23:00:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8072026/10/06 23:00:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8082026/10/06 23:00:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8092026/10/06 23:00:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8102026/10/06 23:00:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8112026/10/06 23:00:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8122026/10/06 23:00:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8132026/10/06 23:00:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8142026/10/06 23:00:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8152026/10/06 23:00:56 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"816--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)817=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle818=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle819=== RUN TestProxyWriteTimeout820=== PAUSE TestProxyWriteTimeout821=== RUN TestPendingClosureWriteTimeout822=== PAUSE TestPendingClosureWriteTimeout823=== RUN TestIsValidUploadKey824=== PAUSE TestIsValidUploadKey825=== RUN TestUploadHandlersRejectInvalidKeys826=== PAUSE TestUploadHandlersRejectInvalidKeys827=== RUN TestUploadHandlersRejectOversizedBody828=== PAUSE TestUploadHandlersRejectOversizedBody829=== RUN TestService_cleanupPendingClosuresHandler830=== PAUSE TestService_cleanupPendingClosuresHandler831=== RUN TestService_createPendingClosureHandler832=== PAUSE TestService_createPendingClosureHandler833=== RUN TestService_verifyS3Integrity834=== PAUSE TestService_verifyS3Integrity835=== RUN TestCompleteMultipartUnregistered836=== PAUSE TestCompleteMultipartUnregistered837=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT838=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT839=== CONT TestParseSize840=== CONT TestService_NativeMTLS841=== CONT TestPush_SignsNarinfosOfItsPendingObjects842=== CONT TestService_AuthMiddleware843=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded844=== CONT TestReadProxy404845--- PASS: TestParseSize (0.00s)846=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT847=== CONT TestSkippedUploadsHandler848=== CONT TestReadProxyInvalidPath849=== CONT TestReadProxyNarStreaming850=== CONT TestService_Rustfstest851=== CONT TestReadProxyNarinfoAlreadyDecompressed852=== CONT TestPresignedUploadRegisteredBeforeCommit853=== CONT TestReadProxyContentNegotiation854=== CONT TestCompleteMultipartUpload_ErrorButObjectExists855=== CONT TestProxyHeadersOnlyTrustedOnSocket856=== CONT TestGCSweepSkipsPendingObjects857=== CONT TestReadProxyNarinfo858=== CONT TestCacheConfigHandlerMaxNarSize859=== CONT TestPresentRefreshesOnlyStaleClosures860--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)861=== CONT TestGracefulShutdownDrainsInflight862=== CONT TestService_verifyS3Integrity863=== CONT TestPresentReportsOnlyClosureRoots8642026/10/06 23:00:56 INFO Starting HTTP server address=127.0.0.1:35977865=== CONT TestService_readinessHandler866=== CONT TestServerTLSConfig8672026/10/06 23:00:56 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000868=== RUN TestServerTLSConfig/no_client_CA869=== CONT TestCompleteMultipartUnregistered870=== PAUSE TestServerTLSConfig/no_client_CA871=== RUN TestServerTLSConfig/missing_CA_file872=== PAUSE TestServerTLSConfig/missing_CA_file873=== RUN TestServerTLSConfig/not_a_PEM_file874=== PAUSE TestServerTLSConfig/not_a_PEM_file875=== CONT TestGCTaskStore_Fail8762026/10/06 23:00:56 INFO Shutdown signal received, draining in-flight requests timeout=10s877--- PASS: TestGCTaskStore_Fail (0.00s)878=== CONT TestPushDedupSurvivesConcurrentGC879--- PASS: TestSkippedUploadsHandler (0.04s)880=== CONT TestReadProxyRangeRequest881=== CONT TestGCTaskStore_GetReturnsLatest882--- PASS: TestGracefulShutdownDrainsInflight (0.07s)883=== CONT TestGCMetrics884--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)8852026/10/06 23:00:56 INFO Received push request method=POST path=/api/pushes8862026/10/06 23:00:56 INFO Received uploads request method=POST path=/api/pending_closures8872026/10/06 23:00:56 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8882026/10/06 23:00:57 INFO Signed narinfos id=1 count=18892026/10/06 23:00:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8902026/10/06 23:00:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8912026/10/06 23:00:57 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"8922026/10/06 23:00:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8932026/10/06 23:00:57 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"8942026/10/06 23:00:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8952026/10/06 23:00:57 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=18962026/10/06 23:00:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8972026/10/06 23:00:57 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo898--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.43s)899=== CONT TestPush_CompleteWaitsForCleanupOfThePush900=== CONT TestPendingClosureWriteTimeout901=== RUN TestPendingClosureWriteTimeout/empty902--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.43s)903=== PAUSE TestPendingClosureWriteTimeout/empty904=== RUN TestPendingClosureWriteTimeout/400_objects905=== PAUSE TestPendingClosureWriteTimeout/400_objects906=== RUN TestPendingClosureWriteTimeout/670k_objects907=== PAUSE TestPendingClosureWriteTimeout/670k_objects908=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline909=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline910=== CONT TestGCAdvisoryLockBlocksConcurrentRun9112026/10/06 23:00:57 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"912--- PASS: TestReadProxyInvalidPath (0.44s)913=== CONT TestFailedS3DeleteKeepsTombstone914=== CONT TestUploadHandlersRejectOversizedBody915--- PASS: TestService_AuthMiddleware (0.45s)9162026/10/06 23:00:57 WARN mTLS auth: subject not in bound subjects subject="CN=reader"9172026/10/06 23:00:57 WARN mTLS auth: subject not in bound subjects subject="CN=reader"9182026/10/06 23:00:57 INFO Received uploads request method=POST path=/api/pending_closures919--- PASS: TestService_NativeMTLS (0.47s)920=== CONT TestGCSweepDeliversEachKeyOnce9212026/10/06 23:00:57 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9222026/10/06 23:00:57 INFO Received uploads request method=POST path=/api/pending_closures923=== CONT TestConnectSerialisesConcurrentMigrations924--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.52s)925--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.52s)926=== CONT TestCreatePin_ReservedPins9272026/10/06 23:00:57 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket2277147981/001/proxy.sock9282026/10/06 23:00:57 INFO Starting HTTP server address=127.0.0.1:402959292026/10/06 23:00:57 WARN mTLS auth: subject not in bound subjects subject="CN=someone"9302026/10/06 23:00:57 INFO Shutdown signal received, draining in-flight requests timeout=10s931=== CONT TestPendingClosureFailureTracksEveryUpload932=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false933--- PASS: TestReadProxyNarStreaming (0.54s)934=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false935=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true936=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true937=== CONT TestReadRedirectNar938--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.55s)939=== CONT TestClientWithDependencies9402026/10/06 23:00:57 INFO Received uploads request method=POST path=/api/pending_closures9412026-10-06 23:00:57.205 UTC [548] ERROR: duplicate key value violates unique constraint "pg_class_relname_nsp_index"9422026-10-06 23:00:57.205 UTC [548] DETAIL: Key (relname, relnamespace)=(goose_db_version_id_seq, 2200) already exists.9432026-10-06 23:00:57.205 UTC [548] STATEMENT: CREATE TABLE goose_db_version (944 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,945 version_id bigint NOT NULL,946 is_applied boolean NOT NULL,947 tstamp timestamp NOT NULL DEFAULT now()948 )949--- PASS: TestPresentReportsOnlyClosureRoots (0.61s)950=== CONT TestPush_OverlappingRootsStoreOneRowPerKey9512026/10/06 23:00:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9522026/10/06 23:00:57 INFO Received uploads request method=POST path=/api/pending_closures9532026/10/06 23:00:57 INFO Received uploads request method=POST path=/api/pending_closures9542026/10/06 23:00:57 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LjkzNWYxOWMwLTYwNWUtNDdiYy1iMWEyLTUxZTNjMTE5YTEwNngxNzkxMzI3NjU3MTU4Nzk1NDIy9552026/10/06 23:00:57 INFO Received uploads request method=POST path=/api/pending_closures9562026/10/06 23:00:57 INFO Aborted multipart uploads count=0 kept=09572026/10/06 23:00:57 WARN Force mode enabled - objects will be deleted immediately without grace period9582026/10/06 23:00:57 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=09592026/10/06 23:00:57 INFO Vacuumed table table=pending_closures9602026/10/06 23:00:57 INFO Vacuumed table table=pending_objects9612026/10/06 23:00:57 INFO Vacuumed table table=multipart_uploads9622026/10/06 23:00:57 INFO Vacuumed table table=closures9632026/10/06 23:00:57 INFO Vacuumed table table=objects9642026/10/06 23:00:57 WARN Rate limiter enabled after throttle name=s3-test rate=59652026/10/06 23:00:57 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."9662026/10/06 23:00:57 WARN readiness check failed error="closed pool"9672026/10/06 23:00:57 INFO Aborted multipart uploads count=0 kept=0968=== CONT TestUploadHandlersRejectInvalidKeys969--- PASS: TestGCSweepSkipsPendingObjects (0.69s)970=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info971=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info972=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal973=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal974=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key975=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key976=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key977=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key978=== CONT TestConcurrentPinUpdatesAgree979--- PASS: TestService_readinessHandler (0.69s)980=== CONT TestIsValidCachePath981=== RUN TestIsValidCachePath/narinfo982=== PAUSE TestIsValidCachePath/narinfo983=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars984=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars985=== RUN TestIsValidCachePath/nar_zst986=== PAUSE TestIsValidCachePath/nar_zst987=== RUN TestIsValidCachePath/nar_xz988=== PAUSE TestIsValidCachePath/nar_xz989=== RUN TestIsValidCachePath/nar_bz2990=== PAUSE TestIsValidCachePath/nar_bz2991=== RUN TestIsValidCachePath/nar_uncompressed992=== PAUSE TestIsValidCachePath/nar_uncompressed993=== RUN TestIsValidCachePath/ls994=== PAUSE TestIsValidCachePath/ls995=== RUN TestIsValidCachePath/log996=== PAUSE TestIsValidCachePath/log997=== RUN TestIsValidCachePath/realisation998=== PAUSE TestIsValidCachePath/realisation999=== RUN TestIsValidCachePath/nix-cache-info1000=== PAUSE TestIsValidCachePath/nix-cache-info1001=== RUN TestIsValidCachePath/index.html1002=== PAUSE TestIsValidCachePath/index.html1003=== RUN TestIsValidCachePath/traversal_parent1004=== PAUSE TestIsValidCachePath/traversal_parent1005=== RUN TestIsValidCachePath/traversal_in_middle1006=== PAUSE TestIsValidCachePath/traversal_in_middle1007=== RUN TestIsValidCachePath/invalid_char_e1008=== PAUSE TestIsValidCachePath/invalid_char_e1009=== RUN TestIsValidCachePath/invalid_char_u1010=== PAUSE TestIsValidCachePath/invalid_char_u1011=== RUN TestIsValidCachePath/random_path1012=== PAUSE TestIsValidCachePath/random_path1013=== RUN TestIsValidCachePath/empty1014=== PAUSE TestIsValidCachePath/empty1015=== RUN TestIsValidCachePath/leading_slash1016=== PAUSE TestIsValidCachePath/leading_slash1017=== RUN TestIsValidCachePath/wrong_extension1018=== PAUSE TestIsValidCachePath/wrong_extension1019=== RUN TestIsValidCachePath/short_hash1020=== PAUSE TestIsValidCachePath/short_hash1021=== CONT TestGetExistingObjectsLocksRows10222026/10/06 23:00:57 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=010232026/10/06 23:00:57 INFO Vacuumed table table=pending_closures10242026/10/06 23:00:57 INFO Vacuumed table table=pending_objects10252026/10/06 23:00:57 INFO Vacuumed table table=multipart_uploads10262026/10/06 23:00:57 WARN Rate limiter backed off name=s3-test rate=510272026/10/06 23:00:57 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."10282026/10/06 23:00:57 INFO Received uploads request method=POST path=/api/pending_closures10292026/10/06 23:00:57 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LjkzNWYxOWMwLTYwNWUtNDdiYy1iMWEyLTUxZTNjMTE5YTEwNngxNzkxMzI3NjU3MTU4Nzk1NDIy error="Delete \"http://localhost:46681/bucket13/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LjkzNWYxOWMwLTYwNWUtNDdiYy1iMWEyLTUxZTNjMTE5YTEwNngxNzkxMzI3NjU3MTU4Nzk1NDIy\": injected: abort refused"10302026/10/06 23:00:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10312026/10/06 23:00:57 INFO Vacuumed table table=closures10322026/10/06 23:00:57 INFO Vacuumed table table=objects10332026/10/06 23:00:57 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LjkzNWYxOWMwLTYwNWUtNDdiYy1iMWEyLTUxZTNjMTE5YTEwNngxNzkxMzI3NjU3MTU4Nzk1NDIy1034--- PASS: TestReadProxyRangeRequest (0.69s)1035=== CONT TestPush_RepeatedRootCommitsOnce10362026/10/06 23:00:57 INFO Aborted multipart uploads count=0 kept=010372026/10/06 23:00:57 WARN Force mode enabled - objects will be deleted immediately without grace period1038=== CONT TestCompletedNarNotReofferedAcrossClosures1039--- PASS: TestReadProxy404 (0.73s)10402026/10/06 23:00:57 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=010412026/10/06 23:00:57 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LjkzNWYxOWMwLTYwNWUtNDdiYy1iMWEyLTUxZTNjMTE5YTEwNngxNzkxMzI3NjU3MTU4Nzk1NDIy parts=110422026/10/06 23:00:57 INFO Vacuumed table table=pending_closures10432026/10/06 23:00:57 INFO Vacuumed table table=pending_objects10442026/10/06 23:00:57 INFO Vacuumed table table=multipart_uploads10452026/10/06 23:00:57 INFO Vacuumed table table=closures10462026/10/06 23:00:57 INFO Vacuumed table table=objects1047--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.75s)1048=== CONT TestParseSingleRange1049=== RUN TestParseSingleRange/none1050=== PAUSE TestParseSingleRange/none1051=== RUN TestParseSingleRange/unknown_unit1052=== PAUSE TestParseSingleRange/unknown_unit1053=== RUN TestParseSingleRange/multi-range_ignored1054=== PAUSE TestParseSingleRange/multi-range_ignored1055=== RUN TestParseSingleRange/malformed_no_dash1056=== PAUSE TestParseSingleRange/malformed_no_dash1057=== RUN TestParseSingleRange/malformed_both_empty1058=== PAUSE TestParseSingleRange/malformed_both_empty1059=== RUN TestParseSingleRange/malformed_end_before_start1060=== PAUSE TestParseSingleRange/malformed_end_before_start1061=== RUN TestParseSingleRange/closed1062=== PAUSE TestParseSingleRange/closed1063=== RUN TestParseSingleRange/open-ended1064=== PAUSE TestParseSingleRange/open-ended1065=== RUN TestParseSingleRange/end_clamped_to_size1066=== PAUSE TestParseSingleRange/end_clamped_to_size1067=== RUN TestParseSingleRange/suffix1068=== PAUSE TestParseSingleRange/suffix1069=== RUN TestParseSingleRange/suffix_exceeds_size1070=== PAUSE TestParseSingleRange/suffix_exceeds_size1071=== RUN TestParseSingleRange/single_byte1072=== PAUSE TestParseSingleRange/single_byte1073=== RUN TestParseSingleRange/start_past_EOF1074=== PAUSE TestParseSingleRange/start_past_EOF1075=== RUN TestParseSingleRange/start_far_past_EOF1076=== PAUSE TestParseSingleRange/start_far_past_EOF1077=== CONT TestMetricsInventory1078--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.75s)1079=== CONT TestRedundantMultipartUpload10802026/10/06 23:00:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10812026/10/06 23:00:57 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1082--- PASS: TestPushDedupSurvivesConcurrentGC (0.75s)1083=== CONT TestNARDeduplicationMetadataUploadBug1084--- PASS: TestCompleteMultipartUnregistered (0.77s)1085=== CONT TestCreatePendingClosureRejectsOversizedNAR10862026/10/06 23:00:57 INFO Received uploads request method=POST path=/api/pending_closures1087--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1088=== CONT TestGenerateLandingPage1089--- PASS: TestGenerateLandingPage (0.01s)1090=== CONT TestDeletePinKeepsRowWhenS3Fails1091--- PASS: TestService_Rustfstest (0.80s)1092=== CONT TestService_healthCheckHandler1093--- PASS: TestPresentRefreshesOnlyStaleClosures (0.82s)1094=== CONT TestPinProtectsFromGC10952026/10/06 23:00:57 INFO Aborted multipart uploads count=0 kept=010962026/10/06 23:00:57 WARN Force mode enabled - objects will be deleted immediately without grace period10972026/10/06 23:00:57 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=010982026/10/06 23:00:57 INFO Vacuumed table table=pending_closures10992026/10/06 23:00:57 INFO Vacuumed table table=pending_objects11002026/10/06 23:00:57 INFO Vacuumed table table=multipart_uploads11012026/10/06 23:00:57 INFO Vacuumed table table=closures11022026/10/06 23:00:57 INFO Vacuumed table table=objects11032026/10/06 23:00:57 INFO Received uploads request method=POST path=/api/pending_closures11042026/10/06 23:00:57 INFO Received push request method=POST path=/api/pushes1105=== CONT TestService_createPendingClosureHandler1106--- PASS: TestGCMetrics (0.82s)1107=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1108=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1109=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1110=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1111=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1112=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1113=== CONT TestMultipartCleanup11142026/10/06 23:00:57 INFO Aborted multipart uploads count=0 kept=011152026/10/06 23:00:57 WARN Force mode enabled - objects will be deleted immediately without grace period11162026/10/06 23:00:57 INFO Aborted multipart uploads count=0 kept=011172026/10/06 23:00:57 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11182026/10/06 23:00:57 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."11192026/10/06 23:00:57 INFO Received push request method=POST path=/api/pushes11202026/10/06 23:00:57 WARN Force mode enabled - objects will be deleted immediately without grace period1121--- PASS: TestReadRedirectNar (0.47s)1122=== CONT TestService_cleanupPendingClosuresHandler11232026/10/06 23:00:57 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=01124--- PASS: TestFailedS3DeleteKeepsTombstone (0.58s)1125=== CONT TestPresentNotReportedWhileGCDeletesClosure1126=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1127=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1128=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1129=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh11302026/10/06 23:00:57 INFO Vacuumed table table=pending_closures1131=== CONT TestDeduplicatedObjectsRecordedAsPending11322026/10/06 23:00:57 INFO Vacuumed table table=pending_objects11332026/10/06 23:00:57 INFO Vacuumed table table=multipart_uploads11342026/10/06 23:00:57 INFO Received create pin request method=POST path=/api/pins/app11352026/10/06 23:00:57 INFO Vacuumed table table=closures11362026/10/06 23:00:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41079/oidc11372026/10/06 23:00:57 INFO Vacuumed table table=objects11382026/10/06 23:00:57 INFO Received create pin request method=POST path=/api/pins/app1139=== CONT TestGCTaskStore_PhaseUpdates1140--- PASS: TestGCSweepDeliversEachKeyOnce (0.57s)1141=== CONT TestClientPushesUseOnePush1142--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1143--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.43s)1144=== CONT TestPush_RejectsBadRequests11452026/10/06 23:00:57 INFO Received uploads request method=POST path=/api/pending_closures1146=== NAME TestClientWithDependencies1147 client_integration_test.go:735: Built derivation: /build/TestClientWithDependencies970918521/001/store/mg8nknsz4v8vnbim25i6dd6y2sh8nsi1-test-script1148--- PASS: TestGetExistingObjectsLocksRows (0.38s)1149=== CONT TestPush_RootsAreLockedInByteOrder11502026/10/06 23:00:57 INFO Received push request method=POST path=/api/pushes1151=== NAME TestClientWithDependencies1152 client_integration_test.go:737: Found 1 dependencies (including self)1153--- PASS: TestReadProxyContentNegotiation (1.16s)1154=== CONT TestGCTaskStore_GetEmpty1155--- PASS: TestGCTaskStore_GetEmpty (0.00s)1156=== CONT TestGCBugBareHashReferences11572026/10/06 23:00:57 INFO Received uploads request method=POST path=/api/pending_closures11582026/10/06 23:00:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11592026/10/06 23:00:57 INFO Received uploads request method=POST path=/api/pending_closures11602026/10/06 23:00:57 INFO Received create pin request method=POST path=/api/pins/app11612026/10/06 23:00:57 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LjA4ZTBiOWUxLWY4MTAtNDQzNC1iNTBjLTdlZDMzYjk2Mjc4MngxNzkxMzI3NjU3MjQ1MzAxOTQ1 parts=1011622026/10/06 23:00:57 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11632026/10/06 23:00:57 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo11642026/10/06 23:00:57 INFO Received delete pin request method=DELETE path=/api/pins/app1165=== CONT TestGCTaskStore_ConflictDifferentParams1166--- PASS: TestMetricsInventory (0.47s)1167=== CONT TestLeadEndsOnShutdown1168--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)11692026/10/06 23:00:57 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket41/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11702026/10/06 23:00:57 INFO Completed upload id=111712026/10/06 23:00:57 INFO Received delete pin request method=DELETE path=/api/pins/app11722026/10/06 23:00:57 INFO Received uploads request method=POST path=/api/pending_closures11732026/10/06 23:00:57 INFO Received push request method=POST path=/api/pushes11742026/10/06 23:00:57 INFO Deleted pin name=app1175=== NAME TestNARDeduplicationMetadataUploadBug1176 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug722161905/001/store/0xidb40p1zdg0bhdj9fb139qz85hgv3d-file1.txt11772026/10/06 23:00:57 INFO Received uploads request method=POST path=/api/pending_closures11782026/10/06 23:00:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11792026/10/06 23:00:57 INFO Uploading mg8nknsz4v8vnbim25i6dd6y2sh8nsi1-test-script (136B)11802026/10/06 23:00:57 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11812026/10/06 23:00:57 WARN Found objects in DB but missing from S3, will re-upload count=111822026/10/06 23:00:57 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete11832026/10/06 23:00:57 INFO Completed upload id=31184--- PASS: TestService_healthCheckHandler (0.45s)1185=== CONT TestGCTaskStore_DeduplicateSameParams1186--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1187=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1188--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.46s)1189=== CONT TestSweepSkipsRowsLockedByPush11902026/10/06 23:00:57 WARN Failed to register uploaded object key=log/61qz3gg0aq41666gwsm7yg5ap3cfa7nw-test-script.drv error="server returned 404: 404 page not found\n"11912026/10/06 23:00:57 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"11922026/10/06 23:00:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11932026/10/06 23:00:57 WARN Failed to register uploaded object key=mg8nknsz4v8vnbim25i6dd6y2sh8nsi1.ls error="server returned 404: 404 page not found\n"11942026/10/06 23:00:57 INFO Signed narinfos id=1 count=111952026/10/06 23:00:57 INFO Uploading 1 narinfos11962026/10/06 23:00:57 INFO Received complete push request method=POST path=/api/pushes/1/complete11972026/10/06 23:00:57 WARN Failed to register uploaded object key=mg8nknsz4v8vnbim25i6dd6y2sh8nsi1.narinfo error="server returned 404: 404 page not found\n"11982026/10/06 23:00:57 INFO Completed push id=111992026/10/06 23:00:57 INFO Upload complete. (104ms)1200--- PASS: TestService_verifyS3Integrity (1.26s)1201=== CONT TestIsValidUploadKey1202=== RUN TestIsValidUploadKey/narinfo1203=== PAUSE TestIsValidUploadKey/narinfo1204=== RUN TestIsValidUploadKey/nar_zst1205=== PAUSE TestIsValidUploadKey/nar_zst1206=== RUN TestIsValidUploadKey/nar_xz1207=== PAUSE TestIsValidUploadKey/nar_xz1208=== RUN TestIsValidUploadKey/nar_plain1209=== PAUSE TestIsValidUploadKey/nar_plain1210=== RUN TestIsValidUploadKey/listing1211=== PAUSE TestIsValidUploadKey/listing1212=== RUN TestIsValidUploadKey/build_log1213=== PAUSE TestIsValidUploadKey/build_log1214=== RUN TestIsValidUploadKey/build_log_home-manager_file1215=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1216=== RUN TestIsValidUploadKey/build_log_plus_in_name1217=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1218=== RUN TestIsValidUploadKey/build_log_question_mark1219=== PAUSE TestIsValidUploadKey/build_log_question_mark1220=== RUN TestIsValidUploadKey/build_log_equals1221=== PAUSE TestIsValidUploadKey/build_log_equals1222=== RUN TestIsValidUploadKey/realisation1223=== PAUSE TestIsValidUploadKey/realisation1224=== RUN TestIsValidUploadKey/realisation_plus_in_output1225=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1226=== RUN TestIsValidUploadKey/nix-cache-info1227=== PAUSE TestIsValidUploadKey/nix-cache-info1228=== RUN TestIsValidUploadKey/index.html1229=== PAUSE TestIsValidUploadKey/index.html1230=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1231=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1232=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1233=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1234=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1235=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1236=== RUN TestIsValidUploadKey/traversal1237=== PAUSE TestIsValidUploadKey/traversal1238=== RUN TestIsValidUploadKey/traversal_nar1239=== PAUSE TestIsValidUploadKey/traversal_nar1240=== RUN TestIsValidUploadKey/absolute1241=== PAUSE TestIsValidUploadKey/absolute1242=== RUN TestIsValidUploadKey/empty_key1243=== PAUSE TestIsValidUploadKey/empty_key1244=== RUN TestIsValidUploadKey/unknown_type1245=== PAUSE TestIsValidUploadKey/unknown_type1246=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection12472026/10/06 23:00:57 INFO Received uploads request method=POST path=/api/pending_closures12482026/10/06 23:00:57 INFO Received uploads request method=POST path=/api/pending_closures12492026/10/06 23:00:57 INFO Received uploads request method=POST path=/api/pending_closures12502026/10/06 23:00:57 INFO Aborted multipart uploads count=0 kept=012512026/10/06 23:00:57 WARN Force mode enabled - objects will be deleted immediately without grace period12522026/10/06 23:00:57 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=012532026/10/06 23:00:57 INFO Received uploads request method=POST path=/api/pending_closures12542026/10/06 23:00:57 INFO Vacuumed table table=pending_closures12552026/10/06 23:00:57 INFO Vacuumed table table=pending_objects12562026/10/06 23:00:57 INFO Vacuumed table table=multipart_uploads12572026/10/06 23:00:57 INFO Received push request method=POST path=/api/pushes12582026/10/06 23:00:57 INFO Vacuumed table table=closures12592026/10/06 23:00:57 INFO Vacuumed table table=objects1260=== NAME TestClientWithDependencies1261 client_integration_test.go:753: Skipping nix copy test - isolated store (/build/TestClientWithDependencies970918521/001/store) requires matching store prefix12622026/10/06 23:00:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12632026/10/06 23:00:57 INFO Uploading 0xidb40p1zdg0bhdj9fb139qz85hgv3d-file1.txt (160B)12642026/10/06 23:00:57 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12652026/10/06 23:00:57 WARN Failed to register uploaded object key=0xidb40p1zdg0bhdj9fb139qz85hgv3d.ls error="server returned 404: 404 page not found\n"12662026/10/06 23:00:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12672026/10/06 23:00:57 INFO Signed narinfos id=1 count=112682026/10/06 23:00:57 INFO Uploading 1 narinfos12692026/10/06 23:00:57 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"1270--- PASS: TestClientWithDependencies (0.78s)1271=== CONT TestForceGCDuringPushOffersSweptObject1272=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1273=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1274=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1275=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1276=== CONT TestLeadElectsOneAndHandsOver1277=== NAME TestPinProtectsFromGC1278 client_integration_test.go:867: Pinned store path: /build/TestPinProtectsFromGC1716210247/001/store/kvllkvs7kzh4lp9jqiqvwa2nhxfw5b27-pinned-file.txt1279 client_integration_test.go:868: Unpinned store path: /build/TestPinProtectsFromGC1716210247/001/store/8rpy13i4hvpwbfqk79v6mhmficxpw7lx-unpinned-file.txt12802026/10/06 23:00:57 WARN Failed to register uploaded object key=0xidb40p1zdg0bhdj9fb139qz85hgv3d.narinfo error="server returned 404: 404 page not found\n"12812026/10/06 23:00:57 INFO Received complete push request method=POST path=/api/pushes/1/complete12822026/10/06 23:00:57 INFO Completed push id=112832026/10/06 23:00:57 INFO Upload complete. (81ms)1284=== NAME TestNARDeduplicationMetadataUploadBug1285 metadata_upload_test.go:54: Retrieved narinfo from S3:1286 StorePath: /build/TestNARDeduplicationMetadataUploadBug722161905/001/store/0xidb40p1zdg0bhdj9fb139qz85hgv3d-file1.txt1287 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1288 Compression: zstd1289 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1290 NarSize: 1601291 References: 1292 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf12932026/10/06 23:00:57 INFO Received cleanup request method=DELETE path=/api/pending_closures12942026/10/06 23:00:57 INFO Aborted multipart uploads count=0 kept=01295 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1296 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1297 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12982026/10/06 23:00:57 INFO Received uploads request method=POST path=/api/pending_closures1299=== CONT TestPush_CompleteCommitsEveryRoot1300--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.93s)13012026/10/06 23:00:57 INFO Received cleanup request method=DELETE path=/api/pending_closures13022026/10/06 23:00:57 INFO Aborted multipart uploads count=1 kept=013032026/10/06 23:00:57 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13042026-10-06 23:00:57.976 UTC [677] ERROR: Closure does not exist: id=113052026-10-06 23:00:57.976 UTC [677] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE13062026-10-06 23:00:57.976 UTC [677] STATEMENT: -- name: CommitPendingClosure :exec1307 SELECT commit_pending_closure($1::bigint)1308 13092026/10/06 23:00:57 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13102026/10/06 23:00:57 WARN Refused reserved pin name=worker-x86_64-linux13112026/10/06 23:00:57 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13122026/10/06 23:00:57 INFO Received create pin request method=POST path=/api/pins/my-app13132026/10/06 23:00:57 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1314=== NAME TestNARDeduplicationMetadataUploadBug1315 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug722161905/001/store/abgyscwd8pzc40v2g29al102qzxshavp-file2.txt1316=== CONT TestObjectStatsLargeCommit1317--- PASS: TestService_cleanupPendingClosuresHandler (0.39s)13182026/10/06 23:00:58 INFO Received uploads request method=POST path=/api/pending_closures1319--- PASS: TestCreatePin_ReservedPins (0.89s)1320=== CONT TestTombstonedObjectOfferedWithoutWaiting13212026/10/06 23:00:58 INFO Received push request method=POST path=/api/pushes13222026/10/06 23:00:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13232026/10/06 23:00:58 INFO Uploading kvllkvs7kzh4lp9jqiqvwa2nhxfw5b27-pinned-file.txt (128B)13242026/10/06 23:00:58 INFO Received cleanup request method=DELETE path=/api/pending_closures13252026/10/06 23:00:58 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket45/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""13262026/10/06 23:00:58 INFO Aborted multipart uploads count=0 kept=113272026/10/06 23:00:58 INFO Received push request method=POST path=/api/pushes13282026/10/06 23:00:58 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13292026/10/06 23:00:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13302026/10/06 23:00:58 INFO Signed narinfos id=1 count=113312026/10/06 23:00:58 INFO Uploading 1 narinfos1332--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.42s)1333=== CONT TestObjectStatsTrigger13342026/10/06 23:00:58 WARN Failed to register uploaded object key=kvllkvs7kzh4lp9jqiqvwa2nhxfw5b27.ls error="server returned 404: 404 page not found\n"13352026/10/06 23:00:58 INFO Received cleanup request method=DELETE path=/api/pending_closures13362026/10/06 23:00:58 INFO Aborted multipart uploads count=1 kept=013372026/10/06 23:00:58 INFO Received complete push request method=POST path=/api/pushes/1/complete13382026/10/06 23:00:58 WARN Failed to register uploaded object key=kvllkvs7kzh4lp9jqiqvwa2nhxfw5b27.narinfo error="server returned 404: 404 page not found\n"1339=== RUN TestPush_RejectsBadRequests/no_objects1340=== PAUSE TestPush_RejectsBadRequests/no_objects1341=== RUN TestPush_RejectsBadRequests/bad_root1342=== PAUSE TestPush_RejectsBadRequests/bad_root1343=== RUN TestPush_RejectsBadRequests/root_not_in_objects1344=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1345=== RUN TestPush_RejectsBadRequests/no_roots1346=== PAUSE TestPush_RejectsBadRequests/no_roots1347=== CONT TestLeadIncumbentAnnouncesAtOnce13482026/10/06 23:00:58 INFO Completed push id=113492026/10/06 23:00:58 INFO Upload complete. (88ms)13502026/10/06 23:00:58 INFO Received push request method=POST path=/api/pushes1351=== CONT TestService_ReadScope_PublicByDefault1352--- PASS: TestMultipartCleanup (0.52s)13532026/10/06 23:00:58 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13542026/10/06 23:00:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13552026/10/06 23:00:58 WARN Failed to register uploaded object key=abgyscwd8pzc40v2g29al102qzxshavp.ls error="server returned 404: 404 page not found\n"13562026/10/06 23:00:58 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13572026/10/06 23:00:58 INFO Signed narinfos id=2 count=113582026/10/06 23:00:58 INFO Uploading 1 narinfos13592026/10/06 23:00:58 INFO Received complete push request method=POST path=/api/pushes/2/complete13602026/10/06 23:00:58 WARN Failed to register uploaded object key=abgyscwd8pzc40v2g29al102qzxshavp.narinfo error="server returned 404: 404 page not found\n"13612026/10/06 23:00:58 INFO Completed push id=213622026/10/06 23:00:58 INFO Upload complete. (74ms)13632026/10/06 23:00:58 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LjIwNTNhNDBmLWJkYzktNGViYi1iNWQ3LTZmMWQzMDIxOGMwZngxNzkxMzI3NjU3NDk5Mjk2NjA2 parts=101364=== NAME TestNARDeduplicationMetadataUploadBug1365 metadata_upload_test.go:76: Retrieved narinfo from S3:1366 StorePath: /build/TestNARDeduplicationMetadataUploadBug722161905/001/store/abgyscwd8pzc40v2g29al102qzxshavp-file2.txt1367 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1368 Compression: zstd1369 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1370 NarSize: 1601371 References: 1372 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1373 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1374 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1375 {"version":1,"root":{"type":"regular","size":44}}13762026/10/06 23:00:58 INFO Received push request method=POST path=/api/pushes13772026/10/06 23:00:58 INFO lead: acquired remote=192.0.2.1:123413782026/10/06 23:00:58 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo13792026/10/06 23:00:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13802026/10/06 23:00:58 INFO Uploading 8rpy13i4hvpwbfqk79v6mhmficxpw7lx-unpinned-file.txt (128B)13812026/10/06 23:00:58 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo1382--- PASS: TestNARDeduplicationMetadataUploadBug (0.79s)1383=== CONT TestResolveDBConnectionString1384=== RUN TestResolveDBConnectionString/flag_wins1385=== PAUSE TestResolveDBConnectionString/flag_wins1386=== RUN TestResolveDBConnectionString/file_when_flag_empty1387=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1388=== RUN TestResolveDBConnectionString/missing_file_is_an_error1389=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1390=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1391=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1392=== RUN TestResolveDBConnectionString/nothing_configured1393=== PAUSE TestResolveDBConnectionString/nothing_configured1394=== CONT TestCacheConfigHandler1395=== RUN TestCacheConfigHandler/full_config,_no_issuer1396=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1397=== RUN TestCacheConfigHandler/no_cache_url_configured1398=== PAUSE TestCacheConfigHandler/no_cache_url_configured1399=== RUN TestCacheConfigHandler/no_signing_keys1400=== PAUSE TestCacheConfigHandler/no_signing_keys1401=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1402=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1403=== CONT TestOrphanedObjectsGCStressTest14042026/10/06 23:00:58 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14052026/10/06 23:00:58 WARN Failed to register uploaded object key=8rpy13i4hvpwbfqk79v6mhmficxpw7lx.ls error="server returned 404: 404 page not found\n"14062026/10/06 23:00:58 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14072026/10/06 23:00:58 INFO Signed narinfos id=2 count=114082026/10/06 23:00:58 INFO Uploading 1 narinfos14092026/10/06 23:00:58 INFO Received complete push request method=POST path=/api/pushes/2/complete14102026/10/06 23:00:58 WARN Failed to register uploaded object key=8rpy13i4hvpwbfqk79v6mhmficxpw7lx.narinfo error="server returned 404: 404 page not found\n"1411--- PASS: TestConcurrentPinUpdatesAgree (0.87s)1412=== CONT TestService_RequireScope_OIDC14132026/10/06 23:00:58 INFO Completed push id=214142026/10/06 23:00:58 INFO Upload complete. (77ms)14152026/10/06 23:00:58 INFO Aborted multipart uploads count=0 kept=014162026/10/06 23:00:58 INFO Received push request method=POST path=/api/pushes14172026/10/06 23:00:58 WARN Force mode enabled - objects will be deleted immediately without grace period14182026/10/06 23:00:58 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=014192026/10/06 23:00:58 INFO Vacuumed table table=pending_closures14202026/10/06 23:00:58 INFO Vacuumed table table=pending_objects14212026/10/06 23:00:58 INFO Vacuumed table table=multipart_uploads14222026/10/06 23:00:58 INFO Vacuumed table table=closures14232026/10/06 23:00:58 INFO Vacuumed table table=objects14242026/10/06 23:00:58 INFO Aborted multipart uploads count=0 kept=014252026/10/06 23:00:58 INFO Starting cleanup of old closures method=DELETE path=/api/closures14262026/10/06 23:00:58 INFO Garbage collection started14272026/10/06 23:00:58 WARN Force mode enabled - objects will be deleted immediately without grace period14282026/10/06 23:00:58 INFO Received uploads request method=POST path=/api/pending_closures14292026/10/06 23:00:58 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=014302026/10/06 23:00:58 INFO Vacuumed table table=pending_closures14312026/10/06 23:00:58 INFO Vacuumed table table=pending_objects14322026/10/06 23:00:58 INFO Vacuumed table table=multipart_uploads14332026/10/06 23:00:58 INFO Vacuumed table table=closures14342026/10/06 23:00:58 INFO Aborted multipart uploads count=0 kept=014352026/10/06 23:00:58 INFO Vacuumed table table=objects1436--- PASS: TestConnectSerialisesConcurrentMigrations (1.11s)1437=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock14382026/10/06 23:00:58 WARN Force mode enabled - objects will be deleted immediately without grace period14392026/10/06 23:00:58 INFO lead: acquired remote=192.0.2.1:123414402026/10/06 23:00:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1441=== CONT TestService_AuthMiddleware_OIDC1442--- PASS: TestSweepSkipsRowsLockedByPush (0.39s)14432026/10/06 23:00:58 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=014442026/10/06 23:00:58 INFO Vacuumed table table=pending_closures14452026/10/06 23:00:58 INFO Received push request method=POST path=/api/pushes14462026/10/06 23:00:58 INFO Vacuumed table table=pending_objects14472026/10/06 23:00:58 INFO Vacuumed table table=multipart_uploads14482026/10/06 23:00:58 INFO Vacuumed table table=closures14492026/10/06 23:00:58 INFO Vacuumed table table=objects14502026/10/06 23:00:58 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LjQzZmI0MjE3LThkOTUtNGNjMi04OTk1LTFhODdlODI4YzIyMHgxNzkxMzI3NjU3NjkxMDI3Mjk4 parts=1014512026/10/06 23:00:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45265/oidc14522026/10/06 23:00:58 INFO Received push request method=POST path=/api/pushes14532026/10/06 23:00:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14542026/10/06 23:00:58 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14552026/10/06 23:00:58 INFO Uploading 7p64wn86yryy6fzlb79zbgbhsfyrms6g-shared-dep (136B)14562026/10/06 23:00:58 INFO Uploading 5kvvvj8sy2h7zf6nsn26w85l66rzk246-a (216B)14572026/10/06 23:00:58 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14582026/10/06 23:00:58 INFO Received uploads request method=POST path=/api/pending_closures14592026/10/06 23:00:58 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LjkyMzRmNjRkLTYyZDMtNGY0OS05MTQ4LTAzN2U4MTI4MDI1YngxNzkxMzI3NjU3NjY4MzI3Mjc3 parts=1214602026/10/06 23:00:58 WARN Failed to register uploaded object key=gplkbnsgqh5wbj6dibswf8awqrz0qvjr.ls error="server returned 404: 404 page not found\n"14612026/10/06 23:00:58 WARN Failed to register uploaded object key=7p64wn86yryy6fzlb79zbgbhsfyrms6g.ls error="server returned 404: 404 page not found\n"14622026/10/06 23:00:58 INFO Received uploads request method=POST path=/api/pending_closures14632026/10/06 23:00:58 WARN Failed to register uploaded object key=5kvvvj8sy2h7zf6nsn26w85l66rzk246.ls error="server returned 404: 404 page not found\n"14642026/10/06 23:00:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14652026/10/06 23:00:58 WARN Failed to register uploaded object key=nar/1dc2yvk7nyny7cd79zakkmbpg0x7qz1xlfh90m1czyw88np1p1qv.nar.zst error="server returned 404: 404 page not found\n"14662026/10/06 23:00:58 INFO Signed narinfos id=1 count=314672026/10/06 23:00:58 INFO Uploading 3 narinfos14682026/10/06 23:00:58 INFO Received complete push request method=POST path=/api/pushes/1/complete14692026/10/06 23:00:58 WARN Failed to register uploaded object key=5kvvvj8sy2h7zf6nsn26w85l66rzk246.narinfo error="server returned 404: 404 page not found\n"14702026/10/06 23:00:58 WARN Failed to register uploaded object key=7p64wn86yryy6fzlb79zbgbhsfyrms6g.narinfo error="server returned 404: 404 page not found\n"14712026/10/06 23:00:58 WARN Failed to register uploaded object key=gplkbnsgqh5wbj6dibswf8awqrz0qvjr.narinfo error="server returned 404: 404 page not found\n"14722026/10/06 23:00:58 INFO Completed push id=114732026/10/06 23:00:58 INFO Upload complete. (99ms)1474=== CONT TestReconnectLeavesObjectsUnlocked1475--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.33s)1476=== NAME TestClientPushesUseOnePush1477 client_pushes_test.go:97: Retrieved narinfo from S3:1478 StorePath: /build/TestClientPushesUseOnePush3067858625/001/store/7p64wn86yryy6fzlb79zbgbhsfyrms6g-shared-dep1479 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1480 Compression: zstd1481 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821482 NarSize: 1361483 References: 1484 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1485--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.01s)1486=== CONT TestCreatePinRejectsBadInput1487=== NAME TestClientPushesUseOnePush1488 client_pushes_test.go:97: Retrieved narinfo from S3:1489 StorePath: /build/TestClientPushesUseOnePush3067858625/001/store/5kvvvj8sy2h7zf6nsn26w85l66rzk246-a1490 URL: nar/1dc2yvk7nyny7cd79zakkmbpg0x7qz1xlfh90m1czyw88np1p1qv.nar.zst1491 Compression: zstd1492 NarHash: sha256:1dc2yvk7nyny7cd79zakkmbpg0x7qz1xlfh90m1czyw88np1p1qv1493 NarSize: 2161494 References: /build/TestClientPushesUseOnePush3067858625/001/store/7p64wn86yryy6fzlb79zbgbhsfyrms6g-shared-dep1495 CA: text:sha256:1hbj7s43dlczbarzdwy6ppd7zij88b8h61fnsfv65rcy6iqlxkf814962026/10/06 23:00:58 INFO lead: acquired remote=192.0.2.1:123414972026/10/06 23:00:58 INFO lead: released remote=192.0.2.1:123414982026/10/06 23:00:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33099/oidc1499 client_pushes_test.go:97: Retrieved narinfo from S3:1500 StorePath: /build/TestClientPushesUseOnePush3067858625/001/store/gplkbnsgqh5wbj6dibswf8awqrz0qvjr-b1501 URL: nar/1dc2yvk7nyny7cd79zakkmbpg0x7qz1xlfh90m1czyw88np1p1qv.nar.zst1502 Compression: zstd1503 NarHash: sha256:1dc2yvk7nyny7cd79zakkmbpg0x7qz1xlfh90m1czyw88np1p1qv1504 NarSize: 2161505 References: /build/TestClientPushesUseOnePush3067858625/001/store/7p64wn86yryy6fzlb79zbgbhsfyrms6g-shared-dep1506 CA: text:sha256:1hbj7s43dlczbarzdwy6ppd7zij88b8h61fnsfv65rcy6iqlxkf81507=== CONT TestOrphanedObjectsGC1508--- PASS: TestGCBugBareHashReferences (0.60s)1509--- PASS: TestObjectStatsTrigger (0.33s)1510=== CONT TestConnectWaitsForAPeerMigration1511=== CONT TestProxyWriteTimeout1512=== RUN TestProxyWriteTimeout/narinfo1513--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.32s)1514=== PAUSE TestProxyWriteTimeout/narinfo1515=== RUN TestProxyWriteTimeout/1_GiB_nar1516=== PAUSE TestProxyWriteTimeout/1_GiB_nar1517=== RUN TestProxyWriteTimeout/10_GiB_nar1518=== PAUSE TestProxyWriteTimeout/10_GiB_nar1519=== RUN TestProxyWriteTimeout/unknown_size1520=== PAUSE TestProxyWriteTimeout/unknown_size1521=== CONT TestGCTaskStore_StartNew1522=== CONT TestPushWaitsForSweepHoldingRow1523--- PASS: TestGCTaskStore_StartNew (0.00s)15242026/10/06 23:00:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15252026/10/06 23:00:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1526--- PASS: TestClientPushesUseOnePush (0.75s)1527=== CONT TestClientIntegration1528--- PASS: TestService_ReadScope_PublicByDefault (0.33s)1529=== CONT TestDeleteClosuresRacingPins15302026/10/06 23:00:58 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LjIyZGIyOGRhLTkyZTYtNDFmZS1hYTlhLTZhYmU1NTY1NjdhZXgxNzkxMzI3NjU3ODgwOTA2OTkz parts=1015312026/10/06 23:00:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15322026/10/06 23:00:58 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LjY0MjhiOWNhLTY4NjEtNDk4ZS1hOWZiLTMzNTM0YmI4ZGIxOXgxNzkxMzI3NjU3NzkxMTQxMTAx parts=1215332026-10-06 23:00:58.405 UTC [1001] ERROR: Push does not exist: id=115342026-10-06 23:00:58.405 UTC [1001] CONTEXT: PL/pgSQL function commit_push(bigint) line 10 at RAISE15352026-10-06 23:00:58.405 UTC [1001] STATEMENT: SELECT commit_push($1)15362026/10/06 23:00:58 INFO Received uploads request method=POST path=/api/pending_closures15372026/10/06 23:00:58 INFO Completed upload id=115382026/10/06 23:00:58 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000015392026/10/06 23:00:58 INFO Received uploads request method=POST path=/api/pending_closures15402026/10/06 23:00:58 INFO Starting cleanup of old closures method=DELETE path=/api/closures1541=== CONT TestGCEndsOnShutdown1542=== RUN TestGCEndsOnShutdown/before_the_run1543--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.40s)1544=== PAUSE TestGCEndsOnShutdown/before_the_run1545=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1546=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1547=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1548=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1549=== CONT TestGCTaskStore_CompletedAllowsNewTask1550=== CONT TestClientCADerivations1551--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)15522026/10/06 23:00:58 INFO Received uploads request method=POST path=/api/pending_closures1553--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.56s)1554=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle15552026/10/06 23:00:58 INFO Aborted multipart uploads count=0 kept=015562026/10/06 23:00:58 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=01557=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1558=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1559=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1560=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1561=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1562=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1563=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1564=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1565=== CONT TestSweepRechecksPendingAfterLocking15662026/10/06 23:00:58 INFO Vacuumed table table=pending_closures15672026/10/06 23:00:58 INFO Vacuumed table table=pending_objects15682026/10/06 23:00:58 INFO Vacuumed table table=multipart_uploads15692026/10/06 23:00:58 INFO Vacuumed table table=closures15702026/10/06 23:00:58 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>15712026/10/06 23:00:58 INFO Vacuumed table table=objects15722026/10/06 23:00:58 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001573--- PASS: TestReadProxyNarinfo (1.89s)1574=== CONT TestCommitRacingPendingCleanupKeepsObjects1575--- PASS: TestService_createPendingClosureHandler (1.01s)1576=== CONT TestClientErrorHandling1577=== RUN TestClientErrorHandling/InvalidStorePath1578=== PAUSE TestClientErrorHandling/InvalidStorePath1579=== RUN TestClientErrorHandling/InvalidAuthToken1580=== PAUSE TestClientErrorHandling/InvalidAuthToken1581=== RUN TestClientErrorHandling/ServerNotAvailable1582=== PAUSE TestClientErrorHandling/ServerNotAvailable1583=== CONT TestReadRedirectUsesPublicS3URL15842026/10/06 23:00:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15852026/10/06 23:00:58 INFO Received create pin request method=POST path=/api/pins/deploy15862026/10/06 23:00:58 INFO Received create pin request method=POST path=/api/pins/deploy15872026/10/06 23:00:58 INFO Received create pin request method=POST path=/api/pins/deploy15882026/10/06 23:00:58 INFO Received create pin request method=POST path=/api/pins/deploy15892026/10/06 23:00:58 INFO Received create pin request method=POST path=/api/pins/deploy15902026/10/06 23:00:58 INFO Received create pin request method=POST path=/api/pins/deploy15912026/10/06 23:00:58 INFO Received create pin request method=POST path=/api/pins/deploy15922026/10/06 23:00:58 INFO Received create pin request method=POST path=/api/pins/deploy15932026/10/06 23:00:58 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LjVhYzViOTQ3LTFjMzctNGQ4NS1iMmVhLTkzMzhlN2VjYTQ0NXgxNzkxMzI3NjU4MDM5NzU5OTc0 parts=1015942026/10/06 23:00:58 INFO Received create pin request method=POST path=/api/pins/deploy1595=== RUN TestService_RequireScope_OIDC/builder_may_write1596=== PAUSE TestService_RequireScope_OIDC/builder_may_write1597=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1598=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1599=== RUN TestService_RequireScope_OIDC/ops_may_admin1600=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1601=== RUN TestService_RequireScope_OIDC/ops_may_not_write1602=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1603=== RUN TestService_RequireScope_OIDC/reader_may_not_write1604=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1605=== RUN TestService_RequireScope_OIDC/static_token_may_admin1606=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1607=== RUN TestService_RequireScope_OIDC/static_token_may_write1608=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1609=== RUN TestService_RequireScope_OIDC/reader_may_read1610=== PAUSE TestService_RequireScope_OIDC/reader_may_read1611=== RUN TestService_RequireScope_OIDC/writer_implies_read1612=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1613=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1614=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1615=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1616=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1617=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1618=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1619=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1620=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1621=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1622=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1623=== CONT TestPendingClosureFailureAbortsItsUploads1624=== CONT TestPendingCleanupUsesOneCutoff1625--- PASS: TestReconnectLeavesObjectsUnlocked (0.30s)16262026/10/06 23:00:58 INFO Received uploads request method=POST path=/api/pending_closures16272026/10/06 23:00:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16282026/10/06 23:00:58 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LjI3ZDZkYmJjLTZjYjItNGJhNi1hNjM2LTNjY2ViN2Y5ZmZiOXgxNzkxMzI3NjU4MTg3MzE1Mjk2 parts=1016292026/10/06 23:00:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16302026/10/06 23:00:58 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LjE2MmRkYmQ1LWFhYTAtNGNiOC05ZDFmLWNhZTZiMDBiOTI1MHgxNzkxMzI3NjU3NjkwMTE3NDMw parts=1016312026/10/06 23:00:58 INFO Received complete push request method=POST path=/api/pushes/1/complete1632=== NAME TestClientIntegration1633 client_integration_test.go:334: Created store path: /build/TestClientIntegration1300534268/002/store/a69bynr0fgplxll87cjq289brfxr5b0w-test-file.txt16342026/10/06 23:00:58 INFO Received uploads request method=POST path=/api/pending_closures16352026/10/06 23:00:58 INFO Completed push id=116362026/10/06 23:00:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1637--- PASS: TestPush_RepeatedRootCommitsOnce (1.44s)1638=== CONT TestService_ReadAuthMiddleware16392026/10/06 23:00:58 INFO Aborted multipart uploads count=0 kept=016402026/10/06 23:00:58 WARN Force mode enabled - objects will be deleted immediately without grace period16412026/10/06 23:00:58 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LmQwZWI3NmU1LTQ0ODYtNDk4MC1iZGVmLTE2YjI2ZjM0ZDI0MXgxNzkxMzI3NjU4MjY0NTUyMDc3 parts=1016422026/10/06 23:00:58 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=016432026/10/06 23:00:58 INFO Vacuumed table table=pending_closures16442026/10/06 23:00:58 INFO Vacuumed table table=pending_objects16452026/10/06 23:00:58 INFO Vacuumed table table=multipart_uploads1646=== NAME TestClientCADerivations1647 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3211256752/001/store/xya0lr7z0d8j68wsy7rdsxyybp9q9nx7-ca-test16482026/10/06 23:00:58 INFO Vacuumed table table=closures16492026/10/06 23:00:58 INFO Vacuumed table table=objects16502026/10/06 23:00:58 INFO Received push request method=POST path=/api/pushes16512026/10/06 23:00:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16522026/10/06 23:00:58 INFO Uploading a69bynr0fgplxll87cjq289brfxr5b0w-test-file.txt (152B)16532026/10/06 23:00:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1654=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1655--- PASS: TestSweepRechecksPendingAfterLocking (0.38s)16562026/10/06 23:00:58 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16572026/10/06 23:00:58 WARN Failed to register uploaded object key=a69bynr0fgplxll87cjq289brfxr5b0w.ls error="server returned 404: 404 page not found\n"16582026/10/06 23:00:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16592026/10/06 23:00:58 INFO Signed narinfos id=1 count=116602026/10/06 23:00:58 INFO Uploading 1 narinfos16612026/10/06 23:00:58 INFO Received uploads request method=POST path=/api/pending_closures16622026/10/06 23:00:58 INFO Received complete push request method=POST path=/api/pushes/1/complete16632026/10/06 23:00:58 WARN Failed to register uploaded object key=a69bynr0fgplxll87cjq289brfxr5b0w.narinfo error="server returned 404: 404 page not found\n"16642026/10/06 23:00:58 INFO Completed push id=116652026/10/06 23:00:58 INFO Upload complete. (80ms)16662026/10/06 23:00:58 INFO Aborted multipart uploads count=0 kept=016672026/10/06 23:00:58 WARN Force mode enabled - objects will be deleted immediately without grace period16682026/10/06 23:00:58 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=016692026/10/06 23:00:58 INFO Received uploads request method=POST path=/api/pending_closures16702026/10/06 23:00:58 INFO Vacuumed table table=pending_closures1671=== NAME TestClientCADerivations1672 client_ca_test.go:139: Found 1 dependencies (including self)16732026/10/06 23:00:58 INFO Vacuumed table table=pending_objects16742026/10/06 23:00:58 INFO Vacuumed table table=multipart_uploads16752026/10/06 23:00:58 INFO Vacuumed table table=closures16762026/10/06 23:00:58 INFO Vacuumed table table=objects16772026/10/06 23:00:58 INFO All 1 paths already cached1678=== NAME TestClientIntegration1679 client_integration_test.go:360: Retrieved narinfo from S3:1680 StorePath: /build/TestClientIntegration1300534268/002/store/a69bynr0fgplxll87cjq289brfxr5b0w-test-file.txt1681 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1682 Compression: zstd1683 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11684 NarSize: 1521685 References: 1686 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk116872026/10/06 23:00:58 INFO Received uploads request method=POST path=/api/pending_closures1688 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)1689 client_integration_test.go:361: Decompressed .ls content (64 bytes):1690 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1691=== CONT TestClientSharedPathCommittedMidPush1692--- PASS: TestPendingClosureFailureAbortsItsUploads (0.30s)16932026/10/06 23:00:58 INFO Received cleanup request method=DELETE path=/api/pending_closures1694--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.42s)1695=== CONT TestClientMultipleUploads1696--- PASS: TestReadRedirectUsesPublicS3URL (0.42s)1697=== CONT TestRegisterCompletedObjectNeedsPendingRow1698=== NAME TestOrphanedObjectsGC1699 orphaned_objects_gc_test.go:287: GC Test Summary:1700 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1701 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1702 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1703 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1704 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1705--- PASS: TestService_ReadAuthMiddleware (0.19s)1706=== CONT TestService_AuthMiddleware_MTLSProxyHeader17072026/10/06 23:00:58 INFO Received push request method=POST path=/api/pushes1708=== CONT TestReadProxyConditionalGet1709--- PASS: TestOrphanedObjectsGC (0.62s)17102026/10/06 23:00:58 INFO Object in database but missing from S3 key=a69bynr0fgplxll87cjq289brfxr5b0w.ls17112026/10/06 23:00:58 WARN Found objects in DB but missing from S3, will re-upload count=117122026/10/06 23:00:58 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17132026/10/06 23:00:58 INFO Received push request method=POST path=/api/pushes17142026/10/06 23:00:58 INFO Received complete push request method=POST path=/api/pushes/2/complete17152026/10/06 23:00:58 WARN Failed to register uploaded object key=a69bynr0fgplxll87cjq289brfxr5b0w.ls error="server returned 404: 404 page not found\n"17162026/10/06 23:00:58 INFO Completed push id=217172026/10/06 23:00:58 INFO Upload complete. (62ms)17182026/10/06 23:00:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17192026/10/06 23:00:58 INFO Uploading xya0lr7z0d8j68wsy7rdsxyybp9q9nx7-ca-test (144B)1720=== NAME TestClientIntegration1721 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)1722 client_integration_test.go:389: Decompressed .ls content (49 bytes):1723 {"version":1,"root":{"type":"regular","size":39}}17242026/10/06 23:00:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17252026/10/06 23:00:59 WARN Failed to register uploaded object key=log/9ahpcj1mnfmcdg5ig0nr07vy53jws2hn-ca-test.drv error="server returned 404: 404 page not found\n"17262026/10/06 23:00:59 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"17272026/10/06 23:00:59 WARN Failed to register uploaded object key=xya0lr7z0d8j68wsy7rdsxyybp9q9nx7.ls error="server returned 404: 404 page not found\n"17282026/10/06 23:00:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17292026/10/06 23:00:59 INFO Signed narinfos id=1 count=117302026/10/06 23:00:59 INFO Uploading 1 narinfos17312026/10/06 23:00:59 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17322026/10/06 23:00:59 WARN mTLS auth: bound subjects configured but subject DN unavailable17332026/10/06 23:00:59 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"17342026/10/06 23:00:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17352026/10/06 23:00:59 INFO Received complete push request method=POST path=/api/pushes/1/complete17362026/10/06 23:00:59 WARN Failed to register uploaded object key=xya0lr7z0d8j68wsy7rdsxyybp9q9nx7.narinfo error="server returned 404: 404 page not found\n"17372026/10/06 23:00:59 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LjE0MzMzZjIyLWFiYzItNDQ2Yy1iYjNlLTY0ZGU1MmFlZTYyMngxNzkxMzI3NjU4NDM1OTQxOTUw error="Get \"http://127.0.0.1:1/bucket39/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"17382026/10/06 23:00:59 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LmQ2MTRhYzVjLWMyMWYtNGM2OC1hZDc0LTE2YWZhY2QzMDg4NXgxNzkxMzI3NjU4NDIwMTM4ODEw parts=1217392026/10/06 23:00:59 INFO Received cleanup request method=DELETE path=/api/pending_closures17402026/10/06 23:00:59 INFO Completed push id=117412026/10/06 23:00:59 INFO Upload complete. (122ms)17422026/10/06 23:00:59 INFO Aborted multipart uploads count=1 kept=01743--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.21s)1744=== CONT TestReadProxyHead17452026/10/06 23:00:59 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LjhmMjc1N2QxLWI3MzEtNDgwZS04NGM5LTA0YmJiYjQ2MWY4MngxNzkxMzI3NjU4MDM4NzkyNzQ2 parts=101746=== NAME TestClientCADerivations1747 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3211256752/001/store/xya0lr7z0d8j68wsy7rdsxyybp9q9nx7-ca-test1748 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1749 Compression: zstd1750 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1751 NarSize: 1441752 References: 1753 Deriver: /build/TestClientCADerivations3211256752/001/store/9ahpcj1mnfmcdg5ig0nr07vy53jws2hn-ca-test.drv1754 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1755 client_ca_test.go:185: Checking for realisation files in S3...1756 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1757 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1758--- PASS: TestRedundantMultipartUpload (1.71s)1759=== CONT TestClientFallsBackToClosures17602026/10/06 23:00:59 INFO Received push request method=POST path=/api/pushes17612026/10/06 23:00:59 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17622026/10/06 23:00:59 INFO Received complete push request method=POST path=/api/pushes/3/complete17632026/10/06 23:00:59 WARN Failed to register uploaded object key=a69bynr0fgplxll87cjq289brfxr5b0w.ls error="server returned 404: 404 page not found\n"17642026/10/06 23:00:59 INFO Completed push id=317652026/10/06 23:00:59 INFO Upload complete. (63ms)1766=== NAME TestClientIntegration1767 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)1768 client_integration_test.go:405: Decompressed .ls content (49 bytes):1769 {"version":1,"root":{"type":"regular","size":39}}1770--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.19s)1771=== CONT TestCacheStatsHandler17722026/10/06 23:00:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1773=== NAME TestClientCADerivations1774 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1775 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1776 error: binary cache 's3://bucket75?endpoint=http://localhost:46681®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3211256752/001/store'1777 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 117782026/10/06 23:00:59 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LmEzYTRjNWQ2LWQzOGYtNDQxMC1iYTY4LTA4YzU4MTA0ZjEyOXgxNzkxMzI3NjU4MTg2NDQ3NjI4 parts=1017792026/10/06 23:00:59 INFO Received complete push request method=POST path=/api/pushes/1/complete17802026/10/06 23:00:59 INFO Completed push id=117812026/10/06 23:00:59 INFO Received push request method=POST path=/api/pushes1782=== NAME TestClientMultipleUploads1783 client_integration_test.go:480: Created store path 0: /build/TestClientMultipleUploads811540066/001/store/516g5da9sv8di96fkf6b0yjn5c53r2zf-test-file-0.txt1784--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.20s)1785=== CONT TestReadProxyOutlastsServerWriteTimeout1786--- PASS: TestClientCADerivations (0.74s)1787=== CONT TestReadProxyDisabled1788=== CONT TestReadProxyRootRedirectsToIndexHTML1789--- PASS: TestPushWaitsForSweepHoldingRow (0.81s)1790--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.96s)1791=== CONT TestReadRedirectKeepsNarinfoProxied17922026/10/06 23:00:59 INFO lead: released remote=192.0.2.1:12341793=== NAME TestClientMultipleUploads1794 client_integration_test.go:480: Created store path 1: /build/TestClientMultipleUploads811540066/001/store/z3cy61n6cgrk27d0h0qvba1d2yslsk5p-test-file-1.txt1795--- PASS: TestLeadEndsOnShutdown (1.39s)1796=== CONT TestServerTLSConfig/missing_CA_file1797=== CONT TestServerTLSConfig/not_a_PEM_file1798=== CONT TestServerTLSConfig/no_client_CA1799=== CONT TestPendingClosureWriteTimeout/empty1800--- PASS: TestServerTLSConfig (0.00s)1801 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1802 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1803 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1804=== CONT TestPendingClosureWriteTimeout/400_objects1805=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline18062026/10/06 23:00:59 INFO Received push request method=POST path=/api/pushes18072026/10/06 23:00:59 INFO Aborted multipart uploads count=0 kept=018082026/10/06 23:00:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18092026/10/06 23:00:59 INFO Uploading wbgpywn4rqnh4rs0r62qb1pnm7qd730x-lost-commit.txt (152B)18102026/10/06 23:00:59 INFO Received push request method=POST path=/api/pushes1811=== NAME TestClientMultipleUploads1812 client_integration_test.go:480: Created store path 2: /build/TestClientMultipleUploads811540066/001/store/21rissg87d6spkjmkvbdas0wvvxa1nxg-test-file-2.txt18132026/10/06 23:00:59 WARN Force mode enabled - objects will be deleted immediately without grace period18142026/10/06 23:00:59 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"18152026/10/06 23:00:59 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)18162026/10/06 23:00:59 INFO Uploading 3y12izr1axx78hg8a1cvh2mwyg6wb1hr-shared-dep (136B)18172026/10/06 23:00:59 INFO Uploading dmb2xhd55zipdzjhfl54n0b3hq2sqm3r-top (224B)18182026/10/06 23:00:59 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign18192026/10/06 23:00:59 WARN Failed to register uploaded object key=wbgpywn4rqnh4rs0r62qb1pnm7qd730x.ls error="server returned 404: 404 page not found\n"18202026/10/06 23:00:59 INFO Signed narinfos id=4 count=118212026/10/06 23:00:59 INFO Uploading 1 narinfos18222026/10/06 23:00:59 WARN Failed to register uploaded object key=nar/0fgmc82a3nb3jvf6rlld1l5zbs243rk1dx61xwmmm6bdrb9jpd43.nar.zst error="server returned 404: 404 page not found\n"18232026/10/06 23:00:59 WARN Failed to register uploaded object key=dmb2xhd55zipdzjhfl54n0b3hq2sqm3r.ls error="server returned 404: 404 page not found\n"18242026/10/06 23:00:59 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18252026/10/06 23:00:59 INFO Received complete push request method=POST path=/api/pushes/4/complete18262026/10/06 23:00:59 WARN Failed to register uploaded object key=wbgpywn4rqnh4rs0r62qb1pnm7qd730x.narinfo error="server returned 404: 404 page not found\n"18272026/10/06 23:00:59 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=018282026/10/06 23:00:59 WARN Failed to register uploaded object key=3y12izr1axx78hg8a1cvh2mwyg6wb1hr.ls error="server returned 404: 404 page not found\n"18292026/10/06 23:00:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18302026/10/06 23:00:59 INFO Completed push id=418312026/10/06 23:00:59 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://127.0.0.1:38581/api/pushes/4/complete\": EOF" url=http://127.0.0.1:38581/api/pushes/4/complete18322026/10/06 23:00:59 INFO Signed narinfos id=1 count=218332026/10/06 23:00:59 INFO Uploading 2 narinfos18342026/10/06 23:00:59 INFO Vacuumed table table=pending_closures18352026/10/06 23:00:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18362026/10/06 23:00:59 INFO Vacuumed table table=pending_objects18372026/10/06 23:00:59 INFO Vacuumed table table=multipart_uploads18382026/10/06 23:00:59 INFO Vacuumed table table=closures18392026/10/06 23:00:59 INFO Vacuumed table table=objects18402026/10/06 23:00:59 INFO Received complete push request method=POST path=/api/pushes/1/complete18412026/10/06 23:00:59 WARN Failed to register uploaded object key=dmb2xhd55zipdzjhfl54n0b3hq2sqm3r.narinfo error="server returned 404: 404 page not found\n"18422026/10/06 23:00:59 WARN Failed to register uploaded object key=3y12izr1axx78hg8a1cvh2mwyg6wb1hr.narinfo error="server returned 404: 404 page not found\n"18432026/10/06 23:00:59 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LjE4NGE5YWNjLTBhNDMtNGQ3YS1iZTJkLTg1YWQ0YTI1YzA4MngxNzkxMzI3NjU4MjY1NjU0ODA3 parts=1018442026/10/06 23:00:59 INFO Completed push id=118452026/10/06 23:00:59 INFO Upload complete. (93ms)1846=== NAME TestClientSharedPathCommittedMidPush1847 client_integration_test.go:816: Retrieved narinfo from S3:1848 StorePath: /build/TestClientSharedPathCommittedMidPush3431654115/001/store/3y12izr1axx78hg8a1cvh2mwyg6wb1hr-shared-dep1849 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1850 Compression: zstd1851 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821852 NarSize: 1361853 References: 1854 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1855 client_integration_test.go:816: Retrieved narinfo from S3:1856 StorePath: /build/TestClientSharedPathCommittedMidPush3431654115/001/store/dmb2xhd55zipdzjhfl54n0b3hq2sqm3r-top1857 URL: nar/0fgmc82a3nb3jvf6rlld1l5zbs243rk1dx61xwmmm6bdrb9jpd43.nar.zst1858 Compression: zstd1859 NarHash: sha256:0fgmc82a3nb3jvf6rlld1l5zbs243rk1dx61xwmmm6bdrb9jpd431860 NarSize: 2241861 References: /build/TestClientSharedPathCommittedMidPush3431654115/001/store/3y12izr1axx78hg8a1cvh2mwyg6wb1hr-shared-dep1862 CA: text:sha256:0q7zd0b5r7a6wjbc12inmma1bbkm0ks97bf9iinf0qpw93vhcqvr1863--- PASS: TestReadProxyConditionalGet (0.32s)1864=== CONT TestPendingClosureWriteTimeout/670k_objects1865=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true18662026/10/06 23:00:59 INFO Received push request method=POST path=/api/pushes1867--- PASS: TestClientSharedPathCommittedMidPush (0.42s)1868=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false18692026/10/06 23:00:59 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18702026/10/06 23:00:59 INFO Uploading z3cy61n6cgrk27d0h0qvba1d2yslsk5p-test-file-1.txt (160B)18712026/10/06 23:00:59 INFO Uploading 516g5da9sv8di96fkf6b0yjn5c53r2zf-test-file-0.txt (160B)18722026/10/06 23:00:59 INFO Uploading 21rissg87d6spkjmkvbdas0wvvxa1nxg-test-file-2.txt (160B)1873=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1874--- PASS: TestCacheStatsHandler (0.21s)18752026/10/06 23:00:59 INFO Received uploads request method=POST path=/1876=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18772026/10/06 23:00:59 INFO Received uploads request method=POST path=/1878=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18792026/10/06 23:00:59 INFO Received request for more parts method=POST path=/1880=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18812026/10/06 23:00:59 INFO Received complete multipart upload request method=POST path=/1882=== CONT TestIsValidCachePath/narinfo1883--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1884 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1885 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1886 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1887 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1888=== CONT TestIsValidCachePath/wrong_extension1889=== CONT TestIsValidCachePath/leading_slash1890=== CONT TestIsValidCachePath/short_hash1891=== CONT TestIsValidCachePath/nix-cache-info1892=== CONT TestIsValidCachePath/realisation1893=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1894=== CONT TestIsValidCachePath/index.html1895=== CONT TestIsValidCachePath/nar_bz21896=== CONT TestIsValidCachePath/invalid_char_e1897=== CONT TestIsValidCachePath/traversal_in_middle1898=== CONT TestIsValidCachePath/nar_zst1899=== CONT TestIsValidCachePath/ls1900=== CONT TestIsValidCachePath/random_path1901=== CONT TestIsValidCachePath/nar_uncompressed1902=== CONT TestIsValidCachePath/invalid_char_u1903=== CONT TestIsValidCachePath/nar_xz1904=== CONT TestIsValidCachePath/empty1905=== CONT TestIsValidCachePath/log1906=== CONT TestIsValidCachePath/traversal_parent19072026/10/06 23:00:59 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"1908=== CONT TestParseSingleRange/multi-range_ignored1909--- PASS: TestIsValidCachePath (0.00s)1910 --- PASS: TestIsValidCachePath/narinfo (0.00s)1911 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1912 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1913 --- PASS: TestIsValidCachePath/short_hash (0.00s)1914 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1915 --- PASS: TestIsValidCachePath/realisation (0.00s)1916 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1917 --- PASS: TestIsValidCachePath/index.html (0.00s)1918 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1919 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1920 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1921 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1922 --- PASS: TestIsValidCachePath/ls (0.00s)1923 --- PASS: TestIsValidCachePath/random_path (0.00s)1924 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1925 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1926 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1927 --- PASS: TestIsValidCachePath/empty (0.00s)1928 --- PASS: TestIsValidCachePath/log (0.00s)1929 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1930=== CONT TestParseSingleRange/start_far_past_EOF1931=== CONT TestParseSingleRange/start_past_EOF1932=== CONT TestParseSingleRange/open-ended1933=== CONT TestParseSingleRange/end_clamped_to_size1934=== CONT TestParseSingleRange/closed19352026/10/06 23:00:59 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"1936=== CONT TestParseSingleRange/single_byte1937=== CONT TestParseSingleRange/malformed_no_dash1938=== CONT TestParseSingleRange/suffix_exceeds_size1939=== CONT TestParseSingleRange/malformed_both_empty19402026/10/06 23:00:59 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"1941=== CONT TestParseSingleRange/malformed_end_before_start1942=== CONT TestParseSingleRange/suffix1943=== CONT TestParseSingleRange/none1944=== CONT TestParseSingleRange/unknown_unit1945=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure1946--- PASS: TestParseSingleRange (0.00s)1947 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1948 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1949 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1950 --- PASS: TestParseSingleRange/open-ended (0.00s)1951 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1952 --- PASS: TestParseSingleRange/closed (0.00s)1953 --- PASS: TestParseSingleRange/single_byte (0.00s)1954 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1955 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1956 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1957 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1958 --- PASS: TestParseSingleRange/suffix (0.00s)1959 --- PASS: TestParseSingleRange/none (0.00s)1960 --- PASS: TestParseSingleRange/unknown_unit (0.00s)19612026/10/06 23:00:59 INFO Received uploads request method=POST path=/19622026/10/06 23:00:59 WARN Failed to register uploaded object key=516g5da9sv8di96fkf6b0yjn5c53r2zf.ls error="server returned 404: 404 page not found\n"19632026/10/06 23:00:59 WARN Failed to register uploaded object key=21rissg87d6spkjmkvbdas0wvvxa1nxg.ls error="server returned 404: 404 page not found\n"19642026/10/06 23:00:59 WARN Failed to register uploaded object key=z3cy61n6cgrk27d0h0qvba1d2yslsk5p.ls error="server returned 404: 404 page not found\n"19652026/10/06 23:00:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1966--- PASS: TestReadProxyHead (0.30s)1967=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19682026/10/06 23:00:59 INFO Signed narinfos id=1 count=319692026/10/06 23:00:59 INFO Received request for more parts method=POST path=/19702026/10/06 23:00:59 INFO Uploading 3 narinfos19712026/10/06 23:00:59 WARN Failed to register uploaded object key=z3cy61n6cgrk27d0h0qvba1d2yslsk5p.narinfo error="server returned 404: 404 page not found\n"19722026/10/06 23:00:59 WARN Failed to register uploaded object key=516g5da9sv8di96fkf6b0yjn5c53r2zf.narinfo error="server returned 404: 404 page not found\n"19732026/10/06 23:00:59 INFO Received complete push request method=POST path=/api/pushes/1/complete19742026/10/06 23:00:59 WARN Failed to register uploaded object key=21rissg87d6spkjmkvbdas0wvvxa1nxg.narinfo error="server returned 404: 404 page not found\n"19752026/10/06 23:00:59 INFO Received complete push request method=POST path=/api/pushes/4/complete19762026-10-06 23:00:59.357 UTC [1188] ERROR: Push does not exist: id=419772026-10-06 23:00:59.357 UTC [1188] CONTEXT: PL/pgSQL function commit_push(bigint) line 10 at RAISE19782026-10-06 23:00:59.357 UTC [1188] STATEMENT: -- name: CommitPush :exec1979 SELECT commit_push($1::bigint)1980 19812026/10/06 23:00:59 WARN Push not found id=419822026/10/06 23:00:59 INFO Completed push id=119832026/10/06 23:00:59 INFO Upload complete. (95ms)1984=== NAME TestClientMultipleUploads1985 client_integration_test.go:491: Uploaded 3 paths in 131.44594ms19862026/10/06 23:00:59 INFO Upload complete. (176ms)1987=== NAME TestClientIntegration1988 client_integration_test.go:435: Retrieved narinfo from S3:1989 StorePath: /build/TestClientIntegration1300534268/002/store/wbgpywn4rqnh4rs0r62qb1pnm7qd730x-lost-commit.txt1990 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1991 Compression: zstd1992 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1993 NarSize: 1521994 References: 1995 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1996 client_integration_test.go:438: Testing garbage collection...19972026/10/06 23:00:59 INFO Starting cleanup of old closures method=DELETE path=/api/closures19982026/10/06 23:00:59 INFO Garbage collection started19992026/10/06 23:00:59 INFO Aborted multipart uploads count=0 kept=020002026/10/06 23:00:59 WARN Force mode enabled - objects will be deleted immediately without grace period2001--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.25s)2002=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart2003=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh2004--- PASS: TestReadProxyDisabled (0.26s)20052026/10/06 23:00:59 INFO Received complete multipart upload request method=POST path=/2006--- PASS: TestClientMultipleUploads (0.52s)2007=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale20082026/10/06 23:00:59 INFO Received uploads request method=POST path=/api/pending_closures20092026/10/06 23:00:59 INFO Received uploads request method=POST path=/api/pending_closures20102026/10/06 23:00:59 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=020112026/10/06 23:00:59 INFO Vacuumed table table=pending_closures20122026/10/06 23:00:59 INFO Received uploads request method=POST path=/api/pending_closures20132026/10/06 23:00:59 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)20142026/10/06 23:00:59 INFO Uploading 2svvyi2dhkhnpfcbd39517r3icv5fv7r-shared-dep (136B)20152026/10/06 23:00:59 INFO Uploading 68cymqkhyjfsvc10yqg2429s5hw1grsh-a (216B)20162026/10/06 23:00:59 INFO Vacuumed table table=pending_objects20172026/10/06 23:00:59 INFO Vacuumed table table=multipart_uploads20182026/10/06 23:00:59 INFO Vacuumed table table=closures20192026/10/06 23:00:59 INFO Vacuumed table table=objects20202026/10/06 23:00:59 WARN Failed to register uploaded object key=p7g89kl6d9y4zw6lbrws15kr66i0njgw.ls error="server returned 404: 404 page not found\n"20212026/10/06 23:00:59 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20222026/10/06 23:00:59 WARN Failed to register uploaded object key=nar/00kn6w28v976nrj9c35rrsx808f9x18mvwamnpsvxlqvikq8859s.nar.zst error="server returned 404: 404 page not found\n"20232026/10/06 23:00:59 WARN Failed to register uploaded object key=68cymqkhyjfsvc10yqg2429s5hw1grsh.ls error="server returned 404: 404 page not found\n"20242026/10/06 23:00:59 WARN Failed to register uploaded object key=2svvyi2dhkhnpfcbd39517r3icv5fv7r.ls error="server returned 404: 404 page not found\n"20252026/10/06 23:00:59 INFO Received uploads request method=POST path=/api/pending_closures20262026/10/06 23:00:59 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20272026/10/06 23:00:59 INFO lead: released remote=192.0.2.1:123420282026/10/06 23:00:59 INFO Signed narinfos id=1 count=220292026/10/06 23:00:59 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign20302026/10/06 23:00:59 INFO Signed narinfos id=2 count=220312026/10/06 23:00:59 INFO Uploading 4 narinfos20322026/10/06 23:00:59 WARN Failed to register uploaded object key=2svvyi2dhkhnpfcbd39517r3icv5fv7r.narinfo error="server returned 404: 404 page not found\n"20332026/10/06 23:00:59 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20342026/10/06 23:00:59 WARN Failed to register uploaded object key=68cymqkhyjfsvc10yqg2429s5hw1grsh.narinfo error="server returned 404: 404 page not found\n"20352026/10/06 23:00:59 WARN Failed to register uploaded object key=2svvyi2dhkhnpfcbd39517r3icv5fv7r.narinfo error="server returned 404: 404 page not found\n"20362026/10/06 23:00:59 WARN Failed to register uploaded object key=p7g89kl6d9y4zw6lbrws15kr66i0njgw.narinfo error="server returned 404: 404 page not found\n"20372026/10/06 23:00:59 INFO Received uploads request method=POST path=/api/pending_closures20382026/10/06 23:00:59 INFO Completed upload id=220392026/10/06 23:00:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20402026-10-06 23:00:59.499 UTC [173] LOG: checkpoints are occurring too frequently (9 seconds apart)20412026-10-06 23:00:59.499 UTC [173] HINT: Consider increasing the configuration parameter "max_wal_size".20422026-10-06 23:00:59.499 UTC [173] LOG: checkpoint starting: wal20432026/10/06 23:00:59 INFO Received create pin request method=POST path=/api/pins/deploy20442026/10/06 23:00:59 INFO Completed upload id=120452026/10/06 23:00:59 INFO Upload complete. (113ms)2046=== NAME TestClientFallsBackToClosures2047 client_pushes_test.go:112: Retrieved narinfo from S3:2048 StorePath: /build/TestClientFallsBackToClosures3100810716/001/store/2svvyi2dhkhnpfcbd39517r3icv5fv7r-shared-dep2049 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2050 Compression: zstd2051 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822052 NarSize: 1362053 References: 2054 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n20552026/10/06 23:00:59 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo2056 client_pushes_test.go:112: Retrieved narinfo from S3:2057 StorePath: /build/TestClientFallsBackToClosures3100810716/001/store/68cymqkhyjfsvc10yqg2429s5hw1grsh-a2058 URL: nar/00kn6w28v976nrj9c35rrsx808f9x18mvwamnpsvxlqvikq8859s.nar.zst2059 Compression: zstd2060 NarHash: sha256:00kn6w28v976nrj9c35rrsx808f9x18mvwamnpsvxlqvikq8859s2061 NarSize: 2162062 References: /build/TestClientFallsBackToClosures3100810716/001/store/2svvyi2dhkhnpfcbd39517r3icv5fv7r-shared-dep2063 CA: text:sha256:1fpzp10m94yc0hbc84xjdjlkg3jx30q3h96rwkvw5qhyjbm4xqwc2064 client_pushes_test.go:112: Retrieved narinfo from S3:2065 StorePath: /build/TestClientFallsBackToClosures3100810716/001/store/p7g89kl6d9y4zw6lbrws15kr66i0njgw-b2066 URL: nar/00kn6w28v976nrj9c35rrsx808f9x18mvwamnpsvxlqvikq8859s.nar.zst2067 Compression: zstd2068 NarHash: sha256:00kn6w28v976nrj9c35rrsx808f9x18mvwamnpsvxlqvikq8859s2069 NarSize: 2162070 References: /build/TestClientFallsBackToClosures3100810716/001/store/2svvyi2dhkhnpfcbd39517r3icv5fv7r-shared-dep2071 CA: text:sha256:1fpzp10m94yc0hbc84xjdjlkg3jx30q3h96rwkvw5qhyjbm4xqwc20722026/10/06 23:00:59 INFO lead: acquired remote=192.0.2.1:12342073--- PASS: TestCreatePinRejectsBadInput (1.19s)2074=== CONT TestIsValidUploadKey/narinfo2075=== CONT TestIsValidUploadKey/realisation2076=== CONT TestIsValidUploadKey/unknown_type2077=== CONT TestIsValidUploadKey/empty_key2078=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2079=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2080=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2081=== CONT TestIsValidUploadKey/realisation_plus_in_output2082=== CONT TestIsValidUploadKey/nix-cache-info2083=== CONT TestIsValidUploadKey/index.html2084=== CONT TestIsValidUploadKey/build_log2085=== CONT TestIsValidUploadKey/build_log_plus_in_name2086=== CONT TestIsValidUploadKey/build_log_question_mark2087=== CONT TestIsValidUploadKey/traversal_nar2088=== CONT TestIsValidUploadKey/build_log_equals2089=== CONT TestIsValidUploadKey/traversal2090=== CONT TestIsValidUploadKey/build_log_home-manager_file2091=== CONT TestIsValidUploadKey/listing2092=== CONT TestIsValidUploadKey/nar_plain2093=== CONT TestIsValidUploadKey/absolute2094=== CONT TestIsValidUploadKey/nar_zst2095=== CONT TestIsValidUploadKey/nar_xz2096=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows2097--- PASS: TestIsValidUploadKey (0.00s)2098 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2099 --- PASS: TestIsValidUploadKey/realisation (0.00s)2100 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2101 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2102 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2103 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2104 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2105 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2106 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2107 --- PASS: TestIsValidUploadKey/index.html (0.00s)2108 --- PASS: TestIsValidUploadKey/build_log (0.00s)2109 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2110 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2111 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2112 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2113 --- PASS: TestIsValidUploadKey/traversal (0.00s)2114 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2115 --- PASS: TestIsValidUploadKey/listing (0.00s)2116 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2117 --- PASS: TestIsValidUploadKey/absolute (0.00s)2118 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2119 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2120--- PASS: TestReadRedirectKeepsNarinfoProxied (0.37s)2121=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check2122=== CONT TestPush_RejectsBadRequests/no_objects2123--- PASS: TestClientFallsBackToClosures (0.48s)21242026/10/06 23:00:59 INFO Received push request method=POST path=/api/pushes2125=== CONT TestPush_RejectsBadRequests/no_roots21262026/10/06 23:00:59 INFO Received push request method=POST path=/api/pushes2127=== CONT TestPush_RejectsBadRequests/root_not_in_objects21282026/10/06 23:00:59 INFO Received push request method=POST path=/api/pushes2129=== CONT TestPush_RejectsBadRequests/bad_root21302026/10/06 23:00:59 INFO Received push request method=POST path=/api/pushes2131=== CONT TestResolveDBConnectionString/flag_wins2132=== CONT TestResolveDBConnectionString/nothing_configured2133=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2134=== CONT TestResolveDBConnectionString/missing_file_is_an_error2135=== CONT TestResolveDBConnectionString/file_when_flag_empty2136=== CONT TestCacheConfigHandler/no_cache_url_configured2137=== CONT TestCacheConfigHandler/full_config,_no_issuer2138--- PASS: TestResolveDBConnectionString (0.00s)2139 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2140 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2141 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2142 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2143 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2144=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2145=== CONT TestCacheConfigHandler/no_signing_keys2146=== CONT TestProxyWriteTimeout/unknown_size2147--- PASS: TestCacheConfigHandler (0.00s)2148 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2149 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2150 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2151 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2152=== CONT TestProxyWriteTimeout/1_GiB_nar2153=== CONT TestProxyWriteTimeout/10_GiB_nar2154=== CONT TestProxyWriteTimeout/narinfo2155=== CONT TestGCEndsOnShutdown/before_the_run2156--- PASS: TestProxyWriteTimeout (0.00s)2157 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2158 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2159 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2160 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)21612026/10/06 23:00:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21622026/10/06 23:00:59 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LmI5Y2VmMDI3LWQ4ZDMtNDY0ZS04YmM0LTczZjFlYWVmMzQzM3gxNzkxMzI3NjU4MDM5NjE2NjUz parts=102163--- PASS: TestPush_RejectsBadRequests (0.42s)2164 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2165 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2166 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2167 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2168=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark2169--- PASS: TestObjectStatsLargeCommit (1.61s)21702026/10/06 23:00:59 INFO Received uploads request method=POST path=/api/pending_closures21712026/10/06 23:00:59 INFO Aborted multipart uploads count=0 kept=021722026/10/06 23:00:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21732026/10/06 23:00:59 WARN Force mode enabled - objects will be deleted immediately without grace period21742026/10/06 23:00:59 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=021752026/10/06 23:00:59 INFO Vacuumed table table=pending_closures21762026/10/06 23:00:59 INFO Vacuumed table table=pending_objects21772026/10/06 23:00:59 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LjRlNWRlY2U1LTI5YzAtNDJmZC1hZjNlLWRlNGVkYzg2YzVjYngxNzkxMzI3NjU4MjY1NzA0MjQ4 parts=1021782026/10/06 23:00:59 INFO Received complete push request method=POST path=/api/pushes/1/complete21792026/10/06 23:00:59 INFO Vacuumed table table=multipart_uploads21802026/10/06 23:00:59 INFO Vacuumed table table=closures21812026/10/06 23:00:59 INFO Vacuumed table table=objects21822026/10/06 23:00:59 INFO Completed push id=121832026/10/06 23:00:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2184=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete21852026/10/06 23:00:59 INFO Received uploads request method=POST path=/api/pending_closures21862026/10/06 23:00:59 INFO Aborted multipart uploads count=0 kept=021872026/10/06 23:00:59 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LmExOWU0Y2ZkLWY2N2MtNDQ4MS1iYmVkLTIzYjkwOGNkM2IxYngxNzkxMzI3NjU5MTYxNDAwODMw parts=1021882026/10/06 23:00:59 INFO Received complete push request method=POST path=/api/pushes/2/complete21892026/10/06 23:00:59 WARN Force mode enabled - objects will be deleted immediately without grace period21902026/10/06 23:00:59 INFO Completed push id=22191--- PASS: TestPush_CompleteCommitsEveryRoot (1.82s)2192=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected21932026/10/06 23:00:59 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]2194=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2195=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token21962026/10/06 23:00:59 WARN Authentication failed token_preview=eyJhbGciOi...7tYQAnoBPg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2197=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2198=== CONT TestClientErrorHandling/InvalidStorePath2199=== CONT TestClientErrorHandling/ServerNotAvailable22002026/10/06 23:00:59 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=022012026/10/06 23:00:59 INFO Vacuumed table table=pending_closures22022026/10/06 23:00:59 INFO Vacuumed table table=pending_objects22032026/10/06 23:00:59 INFO Vacuumed table table=multipart_uploads22042026/10/06 23:00:59 INFO Vacuumed table table=closures22052026/10/06 23:00:59 INFO Vacuumed table table=objects22062026/10/06 23:00:59 INFO Aborted multipart uploads count=0 kept=02207--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (1.95s)2208=== CONT TestClientErrorHandling/InvalidAuthToken22092026/10/06 23:00:59 WARN Force mode enabled - objects will be deleted immediately without grace period2210--- PASS: TestService_AuthMiddleware_OIDC (0.24s)2211 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2212 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)2213 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2214 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2215=== CONT TestService_RequireScope_OIDC/ops_may_not_write2216--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2217 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.24s)2218 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.30s)2219=== CONT TestService_RequireScope_OIDC/writer_implies_read2220=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2221=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc22222026/10/06 23:00:59 WARN Authentication failed token_preview=wrong token_length=5 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2223=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2224=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2225=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2226=== CONT TestService_RequireScope_OIDC/reader_may_read2227=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2228=== CONT TestService_RequireScope_OIDC/static_token_may_admin2229=== CONT TestService_RequireScope_OIDC/builder_may_write2230=== CONT TestService_RequireScope_OIDC/static_token_may_write2231=== CONT TestService_RequireScope_OIDC/reader_may_not_write2232=== CONT TestService_RequireScope_OIDC/ops_may_admin22332026/10/06 23:00:59 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2234--- PASS: TestService_RequireScope_OIDC (0.46s)2235 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.01s)2236 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2237 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2238 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2239 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2240 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2241 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2242 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2243 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2244 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2245 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2246 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2247 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2248 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)22492026/10/06 23:00:59 INFO Aborted multipart uploads count=0 kept=022502026/10/06 23:00:59 WARN Force mode enabled - objects will be deleted immediately without grace period22512026/10/06 23:00:59 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:46681/bucket105/?delete=\": context canceled"2252--- PASS: TestGCEndsOnShutdown (0.00s)2253 --- PASS: TestGCEndsOnShutdown/before_the_run (0.21s)2254 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.23s)2255 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.20s)22562026/10/06 23:00:59 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=184.848278ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22572026/10/06 23:00:59 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LjczMzNiNDllLTgyNjUtNDFmYS04MWE1LTZiMzAyZDUyNmRhZXgxNzkxMzI3NjU5NDg3Mzc2NzA2 error="Access Denied"22582026/10/06 23:00:59 WARN keeping failed pending closure for cleanup to retry the abort id=122592026/10/06 23:01:00 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22602026/10/06 23:01:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2261--- PASS: TestPendingClosureFailureTracksEveryUpload (0.00s)2262 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (0.72s)2263 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (0.72s)22642026/10/06 23:01:00 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LjQ0MmI1OWE4LTAwOWUtNGFjMC05OGMzLWVkMDAwYTk3NDE0YngxNzkxMzI3NjU4MDM5NzE3NTc0 parts=1022652026/10/06 23:01:00 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2266=== NAME TestOrphanedObjectsGCStressTest2267 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2268 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion22692026/10/06 23:01:00 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=379.130506ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2270--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2271 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.69s)2272 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.73s)2273--- PASS: TestDeleteClosuresRacingPins (1.79s)22742026/10/06 23:01:00 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=022752026/10/06 23:01:00 INFO Received create pin request method=POST path=/api/pins/myapp22762026/10/06 23:01:00 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1716210247/001/store/kvllkvs7kzh4lp9jqiqvwa2nhxfw5b27-pinned-file.txt narinfo_key=kvllkvs7kzh4lp9jqiqvwa2nhxfw5b27.narinfo22772026/10/06 23:01:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures22782026/10/06 23:01:00 INFO Garbage collection started22792026/10/06 23:01:00 INFO Aborted multipart uploads count=0 kept=022802026/10/06 23:01:00 WARN Force mode enabled - objects will be deleted immediately without grace period22812026/10/06 23:01:00 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=022822026/10/06 23:01:00 INFO Vacuumed table table=pending_closures22832026/10/06 23:01:00 INFO Vacuumed table table=pending_objects22842026/10/06 23:01:00 INFO Vacuumed table table=multipart_uploads22852026/10/06 23:01:00 INFO Vacuumed table table=closures22862026/10/06 23:01:00 INFO Vacuumed table table=objects2287--- PASS: TestPendingClosureWriteTimeout (0.00s)2288 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2289 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2290 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2291 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.08s)2292=== NAME TestOrphanedObjectsGCStressTest2293 orphaned_objects_gc_test.go:503: Stress test completed successfully:2294 orphaned_objects_gc_test.go:504: - Active objects preserved: 202295 orphaned_objects_gc_test.go:505: - Objects deleted: 2102296 orphaned_objects_gc_test.go:506: - Total GC'd: 2102297--- PASS: TestOrphanedObjectsGCStressTest (2.28s)22982026/10/06 23:01:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22992026/10/06 23:01:00 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=724.52375ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23002026/10/06 23:01:00 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LmIxMDBkNzlmLWViYTktNDIzNy05MmI5LTlkMmVkZTBjZWJkOXgxNzkxMzI3NjU4MDM5NjgzMDU0 parts=1023012026/10/06 23:01:00 INFO lead: released remote=192.0.2.1:12342302--- PASS: TestLeadElectsOneAndHandsOver (2.67s)23032026/10/06 23:01:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23042026/10/06 23:01:01 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NGFkNzc2MWUtYzAzZC00NjIyLWI0Y2EtYzlhNjAzY2EwNzM2LjA5NzM2NTlhLWZlZGMtNDUyZi1hY2M5LTYyODZmYzM1ZWFiN3gxNzkxMzI3NjU4MDM5NzY1NDU1 parts=1023052026-10-06 23:01:01.023 UTC [954] ERROR: could not obtain lock on row in relation "closures"23062026-10-06 23:01:01.023 UTC [954] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23072026-10-06 23:01:01.024 UTC [954] ERROR: could not obtain lock on row in relation "closures"23082026-10-06 23:01:01.024 UTC [954] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23092026-10-06 23:01:01.024 UTC [954] ERROR: could not obtain lock on row in relation "closures"23102026-10-06 23:01:01.024 UTC [954] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23112026-10-06 23:01:01.025 UTC [954] ERROR: could not obtain lock on row in relation "closures"23122026-10-06 23:01:01.025 UTC [954] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23132026-10-06 23:01:01.025 UTC [954] ERROR: could not obtain lock on row in relation "closures"23142026-10-06 23:01:01.025 UTC [954] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT2315--- PASS: TestPush_RootsAreLockedInByteOrder (3.38s)23162026/10/06 23:01:01 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.749658195s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23172026/10/06 23:01:01 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02318=== NAME TestClientIntegration2319 client_integration_test.go:445: Objects in database after GC:2320 client_integration_test.go:445: Successfully deleted all objects with GC --force2321--- PASS: TestClientIntegration (3.05s)2322=== NAME TestPinProtectsFromGC2323 client_integration_test.go:976: Pin successfully protected closure from garbage collection2324--- PASS: TestPinProtectsFromGC (4.82s)23252026/10/06 23:01:02 WARN Rate limiter enabled after throttle name=s3-test rate=523262026/10/06 23:01:02 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2327=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2328 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102329 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002330--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.17s)23312026/10/06 23:01:03 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23322026/10/06 23:01:03 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=214.297665ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23332026/10/06 23:01:03 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=427.965903ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2334--- PASS: TestConnectWaitsForAPeerMigration (5.17s)2335--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.51s)23362026/10/06 23:01:03 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=835.557409ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23372026/10/06 23:01:04 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.541894679s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23382026/10/06 23:01:04 INFO Aborted multipart uploads count=1 kept=023392026/10/06 23:01:04 INFO Received cleanup request method=DELETE path=/api/pending_closures23402026/10/06 23:01:04 INFO Aborted multipart uploads count=1 kept=02341--- PASS: TestPendingCleanupUsesOneCutoff (6.30s)23422026/10/06 23:01:06 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"23432026/10/06 23:01:06 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23442026/10/06 23:01:06 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.208548ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23452026/10/06 23:01:06 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=412.444144ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23462026/10/06 23:01:06 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=860.981159ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23472026/10/06 23:01:07 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.734577518s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23482026/10/06 23:01:09 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23492026/10/06 23:01:09 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=182.651142ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23502026/10/06 23:01:09 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=429.644424ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23512026/10/06 23:01:10 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=721.122393ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23522026/10/06 23:01:10 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.655611652s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2353--- PASS: TestClientErrorHandling (0.00s)2354 --- PASS: TestClientErrorHandling/InvalidStorePath (0.21s)2355 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.28s)2356 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.82s)2357--- PASS: TestUploadHandlersRejectOversizedBody (0.50s)2358 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.92s)2359 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.86s)2360 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (14.30s)2361PASS2362{"timestamp":"2026-10-06T23:01:13.631929899Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:37820","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(194)"}2363{"timestamp":"2026-10-06T23:01:13.632232162Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:38014","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(201)"}23642026-10-06 23:01:13.975 UTC [168] LOG: received smart shutdown request23652026-10-06 23:01:13.980 UTC [168] LOG: background worker "logical replication launcher" (PID 178) exited with exit code 123662026-10-06 23:01:14.506 UTC [173] LOG: checkpoint complete: wrote 4887 buffers (29.8%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=14.558 s, sync=0.412 s, total=15.007 s; sync files=36743, longest=0.006 s, average=0.001 s; distance=533363 kB, estimate=533363 kB; lsn=0/24B07458, redo lsn=0/22042B1023672026-10-06 23:01:14.509 UTC [173] LOG: shutting down23682026-10-06 23:01:14.510 UTC [173] LOG: checkpoint starting: shutdown immediate23692026-10-06 23:01:14.751 UTC [173] LOG: checkpoint complete: wrote 5278 buffers (32.2%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 2 recycled; write=0.070 s, sync=0.167 s, total=0.242 s; sync files=1604, longest=0.002 s, average=0.001 s; distance=43794 kB, estimate=484406 kB; lsn=0/24B074D0, redo lsn=0/24B074D023702026-10-06 23:01:14.824 UTC [168] LOG: database system is shut down2371Running OIDC tests...2372=== RUN TestAudienceForIssuer2373=== PAUSE TestAudienceForIssuer2374=== RUN TestHTTPClientForHasTimeouts2375=== PAUSE TestHTTPClientForHasTimeouts2376=== RUN TestGlobMatch2377=== PAUSE TestGlobMatch2378=== RUN TestValidateToken_ValidToken2379=== PAUSE TestValidateToken_ValidToken2380=== RUN TestValidateToken_WrongAudience2381=== PAUSE TestValidateToken_WrongAudience2382=== RUN TestValidateToken_Expired2383=== PAUSE TestValidateToken_Expired2384=== RUN TestValidateToken_BoundClaimsMismatch2385=== PAUSE TestValidateToken_BoundClaimsMismatch2386=== RUN TestValidateToken_BoundSubjectMismatch2387=== PAUSE TestValidateToken_BoundSubjectMismatch2388=== RUN TestValidateToken_MultipleProviders2389=== PAUSE TestValidateToken_MultipleProviders2390=== RUN TestValidateToken_NoMatchingProvider2391=== PAUSE TestValidateToken_NoMatchingProvider2392=== RUN TestValidateToken_KubernetesServiceAccount2393=== PAUSE TestValidateToken_KubernetesServiceAccount2394=== RUN TestNewValidator_KubernetesRequiresCA2395=== PAUSE TestNewValidator_KubernetesRequiresCA2396=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2397=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2398=== RUN TestPins_ReservedForMatchingRule2399=== PAUSE TestPins_ReservedForMatchingRule2400=== RUN TestPins_TopLevelShorthand2401=== PAUSE TestPins_TopLevelShorthand2402=== RUN TestPins_ConfigValidation2403=== PAUSE TestPins_ConfigValidation2404=== RUN TestScopes_LegacyProviderDefaultsToWrite2405=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2406=== RUN TestScopes_Rules2407=== PAUSE TestScopes_Rules2408=== RUN TestScopes_ConfigValidation2409=== PAUSE TestScopes_ConfigValidation2410=== CONT TestGlobMatch2411=== CONT TestValidateToken_WrongAudience2412=== CONT TestPins_TopLevelShorthand2413=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2414=== CONT TestPins_ReservedForMatchingRule2415=== RUN TestGlobMatch/foo_foo2416=== PAUSE TestGlobMatch/foo_foo2417=== RUN TestGlobMatch/foo_bar2418=== CONT TestPins_ConfigValidation2419=== PAUSE TestGlobMatch/foo_bar2420=== RUN TestGlobMatch/*_2421=== PAUSE TestGlobMatch/*_2422=== RUN TestGlobMatch/*_anything2423=== CONT TestValidateToken_ValidToken2424=== CONT TestNewValidator_KubernetesRequiresCA2425=== CONT TestValidateToken_Expired2426=== CONT TestHTTPClientForHasTimeouts2427=== CONT TestAudienceForIssuer2428--- PASS: TestAudienceForIssuer (0.00s)2429=== CONT TestScopes_LegacyProviderDefaultsToWrite2430=== CONT TestScopes_ConfigValidation2431=== CONT TestValidateToken_KubernetesServiceAccount2432=== CONT TestScopes_Rules2433--- PASS: TestPins_ConfigValidation (0.00s)2434=== CONT TestValidateToken_MultipleProviders2435=== CONT TestValidateToken_BoundSubjectMismatch2436=== CONT TestValidateToken_NoMatchingProvider2437=== CONT TestValidateToken_BoundClaimsMismatch2438=== PAUSE TestGlobMatch/*_anything2439=== RUN TestGlobMatch/foo*_foo2440=== PAUSE TestGlobMatch/foo*_foo2441--- PASS: TestScopes_ConfigValidation (0.00s)2442=== RUN TestGlobMatch/foo*_foobar2443=== PAUSE TestGlobMatch/foo*_foobar2444=== RUN TestGlobMatch/foo*_bar2445=== PAUSE TestGlobMatch/foo*_bar2446=== RUN TestGlobMatch/*bar_bar2447=== PAUSE TestGlobMatch/*bar_bar2448=== RUN TestGlobMatch/*bar_foobar2449=== PAUSE TestGlobMatch/*bar_foobar2450=== RUN TestGlobMatch/*bar_foo2451=== PAUSE TestGlobMatch/*bar_foo2452=== RUN TestGlobMatch/foo*bar_foobar2453=== PAUSE TestGlobMatch/foo*bar_foobar2454=== RUN TestGlobMatch/foo*bar_foo123bar2455=== PAUSE TestGlobMatch/foo*bar_foo123bar2456=== RUN TestGlobMatch/foo*bar_foobarbaz2457=== PAUSE TestGlobMatch/foo*bar_foobarbaz2458=== RUN TestGlobMatch/*/*_foo/bar2459=== PAUSE TestGlobMatch/*/*_foo/bar2460=== RUN TestGlobMatch/*/*_foo2461=== PAUSE TestGlobMatch/*/*_foo2462=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2463=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2464=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02465=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02466=== RUN TestGlobMatch/refs/*/main_refs/heads/main2467=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2468=== RUN TestGlobMatch/fo?_foo2469=== PAUSE TestGlobMatch/fo?_foo2470=== RUN TestGlobMatch/fo?_fo2471=== PAUSE TestGlobMatch/fo?_fo2472=== RUN TestGlobMatch/fo?_fooo2473=== PAUSE TestGlobMatch/fo?_fooo2474=== RUN TestGlobMatch/?oo_foo2475=== PAUSE TestGlobMatch/?oo_foo2476=== RUN TestGlobMatch/?oo_boo2477=== PAUSE TestGlobMatch/?oo_boo2478=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2479=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2480=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2481=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2482=== CONT TestGlobMatch/foo_bar2483=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02484=== CONT TestGlobMatch/*bar_foo2485=== CONT TestGlobMatch/foo*_foo2486=== CONT TestGlobMatch/*/*_foo2487=== CONT TestGlobMatch/foo*bar_foobar2488=== CONT TestGlobMatch/foo*_foobar2489=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2490=== CONT TestGlobMatch/foo*_bar2491=== CONT TestGlobMatch/*_2492=== CONT TestGlobMatch/foo*bar_foo123bar2493=== CONT TestGlobMatch/*bar_bar2494=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2495=== CONT TestGlobMatch/*bar_foobar2496=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2497=== CONT TestGlobMatch/?oo_boo2498=== CONT TestGlobMatch/foo_foo2499=== CONT TestGlobMatch/?oo_foo2500=== CONT TestGlobMatch/refs/*/main_refs/heads/main2501=== CONT TestGlobMatch/fo?_fooo2502=== CONT TestGlobMatch/*/*_foo/bar2503=== CONT TestGlobMatch/fo?_fo2504=== CONT TestGlobMatch/foo*bar_foobarbaz2505=== CONT TestGlobMatch/*_anything2506=== CONT TestGlobMatch/fo?_foo2507--- PASS: TestGlobMatch (0.01s)2508 --- PASS: TestGlobMatch/foo_bar (0.00s)2509 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2510 --- PASS: TestGlobMatch/*bar_foo (0.00s)2511 --- PASS: TestGlobMatch/foo*_foo (0.00s)2512 --- PASS: TestGlobMatch/*/*_foo (0.00s)2513 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2514 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2515 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2516 --- PASS: TestGlobMatch/foo*_bar (0.00s)2517 --- PASS: TestGlobMatch/*_ (0.00s)2518 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2519 --- PASS: TestGlobMatch/*bar_bar (0.00s)2520 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2521 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2522 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2523 --- PASS: TestGlobMatch/?oo_boo (0.00s)2524 --- PASS: TestGlobMatch/?oo_foo (0.00s)2525 --- PASS: TestGlobMatch/foo_foo (0.00s)2526 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2527 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2528 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2529 --- PASS: TestGlobMatch/fo?_fo (0.00s)2530 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2531 --- PASS: TestGlobMatch/*_anything (0.00s)2532 --- PASS: TestGlobMatch/fo?_foo (0.00s)25332026/10/06 23:01:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40923/oidc25342026/10/06 23:01:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46131/oidc2535--- PASS: TestValidateToken_BoundClaimsMismatch (0.11s)2536--- PASS: TestScopes_Rules (0.12s)25372026/10/06 23:01:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35787/oidc2538--- PASS: TestPins_TopLevelShorthand (0.14s)25392026/10/06 23:01:18 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232540--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.18s)25412026/10/06 23:01:18 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:36683/oidc25422026/10/06 23:01:18 http: TLS handshake error from 127.0.0.1:39596: remote error: tls: bad certificate2543--- PASS: TestNewValidator_KubernetesRequiresCA (0.19s)2544--- PASS: TestValidateToken_NoMatchingProvider (0.18s)2545--- PASS: TestHTTPClientForHasTimeouts (0.20s)25462026/10/06 23:01:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33109/oidc2547--- PASS: TestValidateToken_BoundSubjectMismatch (0.22s)25482026/10/06 23:01:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44933/oidc2549--- PASS: TestValidateToken_ValidToken (0.26s)25502026/10/06 23:01:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41253/oidc2551--- PASS: TestValidateToken_Expired (0.27s)25522026/10/06 23:01:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45453/oidc2553--- PASS: TestPins_ReservedForMatchingRule (0.33s)25542026/10/06 23:01:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38335/oidc2555--- PASS: TestValidateToken_WrongAudience (0.38s)25562026/10/06 23:01:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43211/oidc2557--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.44s)25582026/10/06 23:01:18 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:454052559--- PASS: TestValidateToken_KubernetesServiceAccount (0.48s)25602026/10/06 23:01:18 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:40855/oidc25612026/10/06 23:01:18 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:41663/oidc2562--- PASS: TestValidateToken_MultipleProviders (0.53s)2563PASS2564Running hook tests...2565=== RUN TestSendPathsEmpty2566=== PAUSE TestSendPathsEmpty2567=== RUN TestQueueEnqueueAndFetch2568=== PAUSE TestQueueEnqueueAndFetch2569=== RUN TestQueueDeduplication2570=== PAUSE TestQueueDeduplication2571=== RUN TestQueueRemove2572=== PAUSE TestQueueRemove2573=== RUN TestQueueFetchBatchLimit2574=== PAUSE TestQueueFetchBatchLimit2575=== RUN TestQueueRetryMovesToBack2576=== PAUSE TestQueueRetryMovesToBack2577=== RUN TestQueueFetchRemoveLifecycle2578=== PAUSE TestQueueFetchRemoveLifecycle2579=== RUN TestQueueConcurrentWriters2580=== PAUSE TestQueueConcurrentWriters2581=== RUN TestQueueEnqueueWaitsOutSlowWriter2582=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2583=== RUN TestQueueRemoveLargeClosure2584=== PAUSE TestQueueRemoveLargeClosure2585=== RUN TestServerClientIntegration2586=== PAUSE TestServerClientIntegration2587=== RUN TestServerQueueError2588=== PAUSE TestServerQueueError2589=== RUN TestServerRefusesOversizedAndNonStoreRequests2590=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2591=== RUN TestGetListenerSocketActivation2592 server_test.go:317: === RUN TestGetListenerSocketActivation2593 --- PASS: TestGetListenerSocketActivation (0.00s)2594 PASS2595 2596--- PASS: TestGetListenerSocketActivation (1.02s)2597=== RUN TestServerStalledClientDoesNotBlockShutdown2598=== PAUSE TestServerStalledClientDoesNotBlockShutdown2599=== RUN TestServerBacksOffOnAcceptErrors2600=== PAUSE TestServerBacksOffOnAcceptErrors2601=== RUN TestDrainIsolatesPoisonPath2602=== PAUSE TestDrainIsolatesPoisonPath2603=== RUN TestRunNotBlockedByPoisonHead2604=== PAUSE TestRunNotBlockedByPoisonHead2605=== RUN TestDrainGivesUpWhenServerDown2606=== PAUSE TestDrainGivesUpWhenServerDown2607=== RUN TestFailedPathPrunedByLaterClosure2608=== PAUSE TestFailedPathPrunedByLaterClosure2609=== RUN TestWorkerUploadsAndRemoves2610=== PAUSE TestWorkerUploadsAndRemoves2611=== RUN TestWorkerSkipsGCdPaths2612=== PAUSE TestWorkerSkipsGCdPaths2613=== RUN TestWorkerPrunesClosureDeps2614=== PAUSE TestWorkerPrunesClosureDeps2615=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2616=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2617=== RUN TestDrainTimeout2618=== PAUSE TestDrainTimeout2619=== RUN TestDrainTimeoutDuringIsolation2620=== PAUSE TestDrainTimeoutDuringIsolation2621=== RUN TestShutdownFinishesInFlightPush2622=== PAUSE TestShutdownFinishesInFlightPush2623=== RUN TestWorkerRemoveFailureIsNotProgress2624=== PAUSE TestWorkerRemoveFailureIsNotProgress2625=== RUN TestWorkerKeepsPathItCannotStat2626=== PAUSE TestWorkerKeepsPathItCannotStat2627=== CONT TestSendPathsEmpty2628=== CONT TestWorkerRemoveFailureIsNotProgress2629=== CONT TestQueueFetchRemoveLifecycle2630--- PASS: TestSendPathsEmpty (0.00s)2631=== CONT TestWorkerKeepsPathItCannotStat2632=== CONT TestServerStalledClientDoesNotBlockShutdown2633=== CONT TestQueueConcurrentWriters2634=== CONT TestQueueFetchBatchLimit2635=== CONT TestQueueRemove2636=== CONT TestQueueDeduplication2637=== CONT TestQueueEnqueueAndFetch2638=== CONT TestQueueRetryMovesToBack2639=== CONT TestServerRefusesOversizedAndNonStoreRequests2640=== CONT TestServerQueueError2641=== CONT TestWorkerPrunesClosureDeps2642=== CONT TestShutdownFinishesInFlightPush2643=== RUN TestShutdownFinishesInFlightPush/completes2644=== PAUSE TestShutdownFinishesInFlightPush/completes2645=== CONT TestDrainTimeout2646=== CONT TestDrainTimeoutDuringIsolation2647=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2648=== CONT TestWorkerSkipsGCdPaths26492026/10/06 23:01:20 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2650=== CONT TestFailedPathPrunedByLaterClosure2651=== CONT TestQueueRemoveLargeClosure26522026/10/06 23:01:20 ERROR Failed to queue paths error="permission denied" count=12653=== CONT TestQueueEnqueueWaitsOutSlowWriter2654=== CONT TestRunNotBlockedByPoisonHead2655=== CONT TestWorkerUploadsAndRemoves2656=== CONT TestDrainGivesUpWhenServerDown2657=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2658=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2659=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2660=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2661=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2662=== CONT TestDrainIsolatesPoisonPath2663--- PASS: TestServerQueueError (0.00s)2664=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2665=== CONT TestServerBacksOffOnAcceptErrors2666=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2667=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2668=== CONT TestServerClientIntegration26692026/10/06 23:01:20 ERROR Accept failed error="too many open files"2670=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2671=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2672=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths26732026/10/06 23:01:20 ERROR Refusing path outside the store path=/nix/store store=/nix/store2674=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2675=== CONT TestShutdownFinishesInFlightPush/completes26762026/10/06 23:01:20 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store26772026/10/06 23:01:20 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store2678--- PASS: TestServerClientIntegration (0.00s)26792026/10/06 23:01:20 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store2680=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout26812026/10/06 23:01:20 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26822026/10/06 23:01:20 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26832026/10/06 23:01:20 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store26842026/10/06 23:01:20 ERROR Accept failed error="too many open files"26852026/10/06 23:01:20 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store26862026/10/06 23:01:20 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store26872026/10/06 23:01:20 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store26882026/10/06 23:01:20 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store26892026/10/06 23:01:20 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store26902026/10/06 23:01:20 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store26912026/10/06 23:01:20 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store26922026/10/06 23:01:20 ERROR Failed to decode request error="unexpected EOF"2693--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2694=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short26952026/10/06 23:01:20 ERROR Accept failed error="too many open files"26962026/10/06 23:01:20 ERROR Accept failed error="too many open files"26972026/10/06 23:01:20 INFO Upload queue status pending=326982026/10/06 23:01:20 INFO Upload queue status pending=226992026/10/06 23:01:20 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2973954788/002/nonexistent27002026/10/06 23:01:20 INFO Uploading batch count=227012026/10/06 23:01:20 INFO Upload queue status pending=227022026/10/06 23:01:20 INFO Uploading batch count=22703--- PASS: TestQueueFetchBatchLimit (0.07s)2704=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline27052026/10/06 23:01:20 INFO Uploading batch count=227062026/10/06 23:01:20 INFO Upload queue status pending=227072026/10/06 23:01:20 INFO Uploading batch count=427082026/10/06 23:01:20 ERROR Upload failed error="upload failed" count=427092026/10/06 23:01:20 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2204938439/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2204938439/002/locked/aaa: permission denied"27102026/10/06 23:01:20 INFO Uploading batch count=227112026/10/06 23:01:20 INFO Uploading batch count=127122026/10/06 23:01:20 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath4155352092/002/bbb2713--- PASS: TestQueueEnqueueAndFetch (0.08s)27142026/10/06 23:01:20 INFO Upload queue status pending=22715=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27162026/10/06 23:01:20 INFO Uploading batch count=127172026/10/06 23:01:20 ERROR Upload failed error="upload failed" count=12718--- PASS: TestQueueDeduplication (0.08s)27192026/10/06 23:01:20 INFO Uploading batch count=22720=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths27212026/10/06 23:01:20 INFO Upload queue status pending=227222026/10/06 23:01:20 INFO Upload queue status pending=327232026/10/06 23:01:20 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2204938439/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2204938439/002/locked/aaa: permission denied"27242026/10/06 23:01:20 INFO Uploading batch count=427252026/10/06 23:01:20 ERROR Upload failed error="upload failed" count=427262026/10/06 23:01:20 INFO Uploading batch count=22727=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch2728--- PASS: TestQueueFetchRemoveLifecycle (0.08s)27292026/10/06 23:01:20 ERROR Upload failed error="upload failed" count=227302026/10/06 23:01:20 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown78181432/002/a27312026/10/06 23:01:20 ERROR Accept failed error="too many open files"2732--- PASS: TestQueueRemove (0.08s)27332026/10/06 23:01:20 INFO Uploading batch count=12734--- PASS: TestQueueRetryMovesToBack (0.08s)27352026/10/06 23:01:20 ERROR Upload failed error="upload failed" count=127362026/10/06 23:01:20 INFO Uploading batch count=227372026/10/06 23:01:20 INFO Uploading batch count=127382026/10/06 23:01:20 INFO Uploading batch count=127392026/10/06 23:01:20 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown78181432/002/b27402026/10/06 23:01:20 ERROR Upload failed error="upload failed" count=127412026/10/06 23:01:20 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2204938439/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2204938439/002/locked/aaa: permission denied"27422026/10/06 23:01:20 INFO Uploading batch count=127432026/10/06 23:01:20 ERROR Upload failed error="upload failed" count=127442026/10/06 23:01:20 INFO Uploading batch count=227452026/10/06 23:01:20 ERROR Upload failed error="upload failed" count=227462026/10/06 23:01:20 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown78181432/002/c27472026/10/06 23:01:20 INFO Uploading batch count=127482026/10/06 23:01:20 ERROR Drain finished with paths left in queue remaining=12749--- PASS: TestWorkerSkipsGCdPaths (0.09s)27502026/10/06 23:01:20 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown78181432/002/d27512026/10/06 23:01:20 INFO Uploading batch count=127522026/10/06 23:01:20 ERROR Upload failed error="upload failed" count=127532026/10/06 23:01:20 INFO Uploading batch count=227542026/10/06 23:01:20 ERROR Upload failed error="upload failed" count=227552026/10/06 23:01:20 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown78181432/002/e2756--- PASS: TestWorkerUploadsAndRemoves (0.09s)2757--- PASS: TestWorkerKeepsPathItCannotStat (0.09s)27582026/10/06 23:01:20 ERROR Drain finished with paths left in queue remaining=127592026/10/06 23:01:20 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown78181432/002/f27602026/10/06 23:01:20 INFO Uploading batch count=427612026/10/06 23:01:20 ERROR Upload failed error="upload failed" count=42762--- PASS: TestFailedPathPrunedByLaterClosure (0.10s)2763--- PASS: TestWorkerPrunesClosureDeps (0.10s)27642026/10/06 23:01:20 ERROR Drain finished with paths left in queue remaining=102765--- PASS: TestDrainIsolatesPoisonPath (0.10s)2766--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.10s)2767--- PASS: TestDrainGivesUpWhenServerDown (0.10s)27682026/10/06 23:01:20 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path2634272606/001/nonexistent27692026/10/06 23:01:20 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127702026/10/06 23:01:20 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path2634272606/001/nonexistent27712026/10/06 23:01:20 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127722026/10/06 23:01:20 INFO Uploading batch count=227732026/10/06 23:01:20 ERROR Upload failed error="upload failed" count=227742026/10/06 23:01:20 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path2634272606/001/nonexistent27752026/10/06 23:01:20 INFO Uploading batch count=227762026/10/06 23:01:20 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127772026/10/06 23:01:20 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127782026/10/06 23:01:20 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127792026/10/06 23:01:20 ERROR Drain finished with paths left in queue remaining=127802026/10/06 23:01:20 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227812026/10/06 23:01:20 INFO Uploading batch count=227822026/10/06 23:01:20 ERROR Upload failed error="upload failed" count=227832026/10/06 23:01:20 INFO Uploading batch count=227842026/10/06 23:01:20 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127852026/10/06 23:01:20 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227862026/10/06 23:01:20 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127872026/10/06 23:01:20 INFO Uploading batch count=227882026/10/06 23:01:20 INFO Uploading batch count=227892026/10/06 23:01:20 ERROR Upload failed error="upload failed" count=227902026/10/06 23:01:20 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227912026/10/06 23:01:20 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127922026/10/06 23:01:20 ERROR Drain finished with paths left in queue remaining=227932026/10/06 23:01:20 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127942026/10/06 23:01:20 ERROR Drain finished with paths left in queue remaining=22795--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2796 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.04s)2797 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.04s)2798 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.05s)27992026/10/06 23:01:20 ERROR Accept failed error="too many open files"28002026/10/06 23:01:20 ERROR Failed to decode request error="read unix /build/hook1265051918/test.sock->@: i/o timeout"28012026/10/06 23:01:20 ERROR Failed to write response error="write unix /build/hook1265051918/test.sock->@: i/o timeout"2802--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)28032026/10/06 23:01:20 ERROR Upload failed error="context canceled" count=228042026/10/06 23:01:20 ERROR Drain finished with paths left in queue remaining=42805--- PASS: TestDrainTimeout (0.27s)28062026/10/06 23:01:20 ERROR Drain finished with paths left in queue remaining=428072026/10/06 23:01:20 ERROR Upload failed error="context canceled" count=228082026/10/06 23:01:20 ERROR Drain finished with paths left in queue remaining=22809--- PASS: TestShutdownFinishesInFlightPush (0.00s)2810 --- PASS: TestShutdownFinishesInFlightPush/completes (0.17s)2811 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.28s)28122026/10/06 23:01:20 ERROR Accept failed error="too many open files"28132026/10/06 23:01:20 ERROR Drain finished with paths left in queue remaining=32814--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2815 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.27s)2816 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.33s)2817--- PASS: TestQueueConcurrentWriters (0.51s)28182026/10/06 23:01:21 ERROR Accept failed error="too many open files"2819--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)28202026/10/06 23:01:21 INFO Uploading batch count=128212026/10/06 23:01:21 INFO Uploading batch count=128222026/10/06 23:01:21 INFO Uploading batch count=128232026/10/06 23:01:21 ERROR Upload failed error="upload failed" count=128242026/10/06 23:01:21 INFO Uploading batch count=128252026/10/06 23:01:21 ERROR Upload failed error="upload failed" count=128262026/10/06 23:01:21 INFO Uploading batch count=128272026/10/06 23:01:21 ERROR Upload failed error="upload failed" count=128282026/10/06 23:01:21 INFO Uploading batch count=128292026/10/06 23:01:21 ERROR Upload failed error="upload failed" count=128302026/10/06 23:01:21 ERROR Drain finished with paths left in queue remaining=12831--- PASS: TestRunNotBlockedByPoisonHead (1.12s)2832--- PASS: TestQueueRemoveLargeClosure (2.76s)2833--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.07s)2834PASS2835Running signing tests...2836=== RUN TestExternalSigner2837=== PAUSE TestExternalSigner2838=== RUN TestExternalSignerWrongPublicKey2839=== PAUSE TestExternalSignerWrongPublicKey2840=== RUN TestExternalSignerErrors2841=== PAUSE TestExternalSignerErrors2842=== RUN TestExternalSignerRestartsAfterCrash2843=== PAUSE TestExternalSignerRestartsAfterCrash2844=== RUN TestExternalSignerProgramErrorKeepsProcess2845=== PAUSE TestExternalSignerProgramErrorKeepsProcess2846=== RUN TestExternalSignerClose2847=== PAUSE TestExternalSignerClose2848=== RUN TestExternalSignerRejectsInvalidPublicKey2849=== PAUSE TestExternalSignerRejectsInvalidPublicKey2850=== RUN TestExternalSignerCancellation2851=== PAUSE TestExternalSignerCancellation2852=== RUN TestGenerateFingerprint2853=== PAUSE TestGenerateFingerprint2854=== RUN TestParseSigningKey2855=== PAUSE TestParseSigningKey2856=== RUN TestSign2857=== PAUSE TestSign2858=== RUN TestSignBatch2859=== PAUSE TestSignBatch2860=== RUN TestNilKeyPublicKey2861=== PAUSE TestNilKeyPublicKey2862=== RUN TestSignErrors2863=== PAUSE TestSignErrors2864=== CONT TestExternalSigner2865=== CONT TestGenerateFingerprint2866=== CONT TestExternalSignerRestartsAfterCrash2867=== CONT TestSignErrors2868=== RUN TestGenerateFingerprint/basic_with_references2869=== CONT TestNilKeyPublicKey2870--- PASS: TestNilKeyPublicKey (0.00s)2871=== CONT TestSignBatch2872=== CONT TestParseSigningKey2873=== CONT TestExternalSignerCancellation2874=== RUN TestParseSigningKey/valid_32-byte_key2875=== PAUSE TestParseSigningKey/valid_32-byte_key2876=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2877=== CONT TestSign2878=== CONT TestExternalSignerWrongPublicKey2879=== CONT TestExternalSignerProgramErrorKeepsProcess2880=== CONT TestExternalSignerErrors2881=== CONT TestExternalSignerRejectsInvalidPublicKey2882=== CONT TestExternalSignerClose2883=== PAUSE TestGenerateFingerprint/basic_with_references2884=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2885=== RUN TestExternalSignerRejectsInvalidPublicKey/#002886=== RUN TestGenerateFingerprint/no_references2887=== RUN TestExternalSignerErrors/wrong_shape2888=== RUN TestParseSigningKey/no_colon2889=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002890=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2891=== PAUSE TestParseSigningKey/no_colon2892=== PAUSE TestGenerateFingerprint/no_references2893=== RUN TestParseSigningKey/empty_name2894=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2895=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2896=== PAUSE TestParseSigningKey/empty_name2897=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2898=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2899=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2900=== RUN TestParseSigningKey/invalid_base642901=== PAUSE TestExternalSignerErrors/wrong_shape2902=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2903=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2904=== PAUSE TestParseSigningKey/invalid_base642905=== RUN TestGenerateFingerprint/invalid_nar_hash_length2906=== RUN TestExternalSignerErrors/missing_signatures2907=== RUN TestParseSigningKey/wrong_length2908=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2909=== PAUSE TestParseSigningKey/wrong_length2910=== RUN TestGenerateFingerprint/invalid_store_path_prefix2911=== CONT TestParseSigningKey/valid_32-byte_key2912=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2913=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2914=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2915=== PAUSE TestExternalSignerErrors/missing_signatures2916=== CONT TestParseSigningKey/invalid_base642917=== RUN TestExternalSignerErrors/too_few_signatures2918=== CONT TestParseSigningKey/wrong_length2919=== CONT TestParseSigningKey/empty_name2920=== CONT TestParseSigningKey/no_colon2921=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2922=== RUN TestGenerateFingerprint/invalid_reference_prefix2923=== PAUSE TestExternalSignerErrors/too_few_signatures2924=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2925=== RUN TestExternalSignerErrors/invalid_signature_base642926=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2927=== CONT TestGenerateFingerprint/basic_with_references2928=== CONT TestGenerateFingerprint/invalid_reference_prefix2929=== CONT TestGenerateFingerprint/invalid_store_path_prefix2930=== CONT TestGenerateFingerprint/invalid_nar_hash_length2931=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2932=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2933=== CONT TestGenerateFingerprint/no_references2934=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2935=== PAUSE TestExternalSignerErrors/invalid_signature_base642936=== RUN TestExternalSignerErrors/wrong_signature_length2937=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2938=== PAUSE TestExternalSignerErrors/wrong_signature_length2939--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2940=== RUN TestExternalSignerErrors/program_error2941=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2942=== PAUSE TestExternalSignerErrors/program_error2943=== RUN TestExternalSignerErrors/exit_on_request2944=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2945=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2946=== CONT TestExternalSignerRejectsInvalidPublicKey/#002947--- PASS: TestGenerateFingerprint (0.01s)2948 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2949 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2950 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2951 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2952 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2953 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2954 --- PASS: TestGenerateFingerprint/no_references (0.00s)2955=== PAUSE TestExternalSignerErrors/exit_on_request2956=== RUN TestExternalSignerErrors/null2957=== PAUSE TestExternalSignerErrors/null2958--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2959 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2960 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2961 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2962 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2963 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2964=== RUN TestExternalSignerErrors/null_signatures2965=== PAUSE TestExternalSignerErrors/null_signatures2966=== RUN TestExternalSignerErrors/wrong_signatures_shape2967=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2968=== RUN TestExternalSignerErrors/unrequested_key2969=== PAUSE TestExternalSignerErrors/unrequested_key2970=== RUN TestExternalSignerErrors/wrong_signature_name2971=== PAUSE TestExternalSignerErrors/wrong_signature_name2972=== RUN TestExternalSignerErrors/exit_at_startup2973=== PAUSE TestExternalSignerErrors/exit_at_startup2974=== RUN TestExternalSignerErrors/wrong_id2975=== PAUSE TestExternalSignerErrors/wrong_id2976=== RUN TestExternalSignerErrors/missing_signature_name2977=== PAUSE TestExternalSignerErrors/missing_signature_name2978=== RUN TestExternalSignerErrors/invalid_JSON2979=== PAUSE TestExternalSignerErrors/invalid_JSON2980=== CONT TestExternalSignerErrors/missing_signatures2981=== CONT TestExternalSignerErrors/wrong_signatures_shape2982=== CONT TestExternalSignerErrors/invalid_signature_base642983=== CONT TestExternalSignerErrors/program_error2984=== CONT TestExternalSignerErrors/null2985=== CONT TestExternalSignerErrors/wrong_signature_length2986=== CONT TestExternalSignerErrors/wrong_shape2987=== CONT TestExternalSignerErrors/missing_signature_name2988=== CONT TestExternalSignerErrors/unrequested_key2989=== CONT TestExternalSignerErrors/invalid_JSON2990=== CONT TestExternalSignerErrors/exit_at_startup2991=== CONT TestExternalSignerErrors/wrong_id2992=== CONT TestExternalSignerErrors/too_few_signatures2993=== CONT TestExternalSignerErrors/wrong_signature_name2994=== CONT TestExternalSignerErrors/exit_on_request2995--- PASS: TestExternalSignerClose (0.01s)2996=== CONT TestExternalSignerErrors/null_signatures2997--- PASS: TestExternalSignerWrongPublicKey (0.01s)2998--- PASS: TestExternalSignerErrors (0.00s)2999 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)3000 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.00s)3001 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)3002 --- PASS: TestExternalSignerErrors/null (0.01s)3003 --- PASS: TestExternalSignerErrors/program_error (0.01s)3004 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)3005 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)3006 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)3007 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)3008 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)3009 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)3010 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)3011 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)3012 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)3013 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)3014 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)3015--- PASS: TestExternalSignerRestartsAfterCrash (0.02s)3016=== RUN TestSignErrors/nil_key3017=== PAUSE TestSignErrors/nil_key3018=== RUN TestSignErrors/nil_narinfo3019=== PAUSE TestSignErrors/nil_narinfo3020=== RUN TestSignErrors/invalid_narinfo3021=== PAUSE TestSignErrors/invalid_narinfo3022=== RUN TestSignErrors/canceled3023=== PAUSE TestSignErrors/canceled3024=== CONT TestSignErrors/nil_narinfo3025--- PASS: TestParseSigningKey (0.00s)3026 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)3027 --- PASS: TestParseSigningKey/empty_name (0.00s)3028 --- PASS: TestParseSigningKey/wrong_length (0.00s)3029 --- PASS: TestParseSigningKey/no_colon (0.00s)3030 --- PASS: TestParseSigningKey/valid_32-byte_key (0.01s)3031 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.01s)3032=== CONT TestSignErrors/invalid_narinfo3033=== CONT TestSignErrors/canceled3034=== CONT TestSignErrors/nil_key3035--- PASS: TestSignErrors (0.02s)3036 --- PASS: TestSignErrors/nil_narinfo (0.00s)3037 --- PASS: TestSignErrors/invalid_narinfo (0.00s)3038 --- PASS: TestSignErrors/canceled (0.00s)3039 --- PASS: TestSignErrors/nil_key (0.00s)3040--- PASS: TestSign (0.02s)3041--- PASS: TestExternalSigner (0.02s)3042--- PASS: TestExternalSignerCancellation (0.02s)3043--- PASS: TestSignBatch (0.03s)3044PASS3045Running OpenBao signer tests...3046=== RUN TestSign3047=== PAUSE TestSign3048=== RUN TestSignErrors3049=== PAUSE TestSignErrors3050=== RUN TestServe3051=== PAUSE TestServe3052=== RUN TestServeRejectsGarbage3053=== PAUSE TestServeRejectsGarbage3054=== CONT TestSign3055=== CONT TestSignErrors3056=== RUN TestSignErrors/no_prefix3057=== CONT TestServe3058=== CONT TestServeRejectsGarbage3059=== PAUSE TestSignErrors/no_prefix3060=== RUN TestSignErrors/invalid_base643061--- PASS: TestServeRejectsGarbage (0.00s)3062=== PAUSE TestSignErrors/invalid_base643063=== RUN TestSignErrors/http_error3064=== PAUSE TestSignErrors/http_error3065=== RUN TestSignErrors/invalid_json3066=== PAUSE TestSignErrors/invalid_json3067=== CONT TestSignErrors/invalid_base643068=== CONT TestSignErrors/http_error3069=== CONT TestSignErrors/no_prefix3070--- PASS: TestServe (0.00s)3071=== CONT TestSignErrors/invalid_json3072--- PASS: TestSign (0.01s)3073--- PASS: TestSignErrors (0.00s)3074 --- PASS: TestSignErrors/invalid_base64 (0.00s)3075 --- PASS: TestSignErrors/invalid_json (0.00s)3076 --- PASS: TestSignErrors/http_error (0.00s)3077 --- PASS: TestSignErrors/no_prefix (0.00s)3078PASS3079Running niks3-hook command tests...3080=== RUN TestServeSecondSignalEndsDrain3081=== PAUSE TestServeSecondSignalEndsDrain3082=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown3083=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown3084=== CONT TestServeSecondSignalEndsDrain3085=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown3086--- PASS: TestServeSecondSignalEndsDrain (0.07s)30872026/10/06 23:01:29 INFO Upload queue status pending=130882026/10/06 23:01:29 INFO Uploading batch count=13089--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.13s)3090PASS3091Running rate limiter tests...3092=== RUN TestAdaptiveRateLimiter_ThreadSafety3093=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3094=== CONT TestAdaptiveRateLimiter_ThreadSafety30952026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=84.7000000000000230962026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=59.29000000000000630972026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=41.50330982026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=29.052130992026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=20.3364731002026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=14.23552899999999831012026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=9.96487029999999831022026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=6.97540920999999831032026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531042026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531052026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531062026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531072026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531082026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531092026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531102026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531112026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531122026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531132026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531142026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531152026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531162026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531172026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531182026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531192026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=6.82050985000000231202026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531212026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531222026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531232026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531242026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531252026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531262026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531272026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531282026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531292026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531302026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531312026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531322026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531332026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531342026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531352026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531362026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531372026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531382026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531392026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531402026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531412026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531422026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531432026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531442026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531452026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531462026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531472026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531482026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531492026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531502026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531512026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531522026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531532026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531542026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531552026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531562026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531572026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531582026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531592026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531602026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531612026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531622026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531632026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531642026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531652026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531662026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531672026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531682026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531692026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531702026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531712026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531722026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531732026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531742026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531752026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531762026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531772026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531782026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531792026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531802026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=8.25281691850000431812026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=5.77697184295000331822026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531832026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531842026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531852026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531862026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=5.63678500000000131872026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531882026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=5.63678500000000131892026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531902026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531912026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531922026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531932026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=531942026/10/06 23:01:30 WARN Rate limiter backed off name=test rate=53195--- PASS: TestAdaptiveRateLimiter_ThreadSafety (3.40s)3196PASS