niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #401
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure18=== PAUSE TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure19=== RUN TestUploadMultipart_PartsInParallel20=== PAUSE TestUploadMultipart_PartsInParallel21=== RUN TestUploadMultipart_ProducerErrorIsNotEOF22=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF23=== RUN TestUploadMultipart_FailedPartBufferNotReused24=== PAUSE TestUploadMultipart_FailedPartBufferNotReused25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestUploadMultipart_SupersededByPeer28=== PAUSE TestUploadMultipart_SupersededByPeer29=== RUN TestDumpPathCaseHackMatchesNix30--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)31=== RUN TestDumpPathCaseHackCollision32--- PASS: TestDumpPathCaseHackCollision (0.00s)33=== RUN TestSupersededNARStillUploadsListing34=== PAUSE TestSupersededNARStillUploadsListing35=== RUN TestTruncatedNARDumpIsNotCompleted36=== PAUSE TestTruncatedNARDumpIsNotCompleted37=== RUN TestDumpPathMatchesNix38=== PAUSE TestDumpPathMatchesNix39=== RUN TestDumpPathSingleFile40=== PAUSE TestDumpPathSingleFile41=== RUN TestDumpPathWriterError42=== PAUSE TestDumpPathWriterError43=== RUN TestDumpPathWriterErrorStopsReading44 nar_test.go:289: read 114 of 32768000 bytes45--- PASS: TestDumpPathWriterErrorStopsReading (0.70s)46=== RUN TestEncodeNixBase3247=== PAUSE TestEncodeNixBase3248=== RUN TestEncodeNixBase32WithRealHash49=== PAUSE TestEncodeNixBase32WithRealHash50=== RUN TestConvertHashToNix3251=== PAUSE TestConvertHashToNix3252=== RUN TestGetStorePathHash53=== PAUSE TestGetStorePathHash54=== RUN TestPathInfoHashCompatibility55=== PAUSE TestPathInfoHashCompatibility56=== RUN TestParsePathInfoJSON57=== PAUSE TestParsePathInfoJSON58=== RUN TestParsePathInfoJSONMultiplePaths59=== PAUSE TestParsePathInfoJSONMultiplePaths60=== RUN TestPathInfoCACompatibility61=== PAUSE TestPathInfoCACompatibility62=== RUN TestUploadPendingObjectsStopsStartingAfterFailure63--- PASS: TestUploadPendingObjectsStopsStartingAfterFailure (0.02s)64=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent65=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent66=== RUN TestCompletePendingClosure_NotFoundWithoutKey67=== PAUSE TestCompletePendingClosure_NotFoundWithoutKey68=== RUN TestRateLimiterFeedback69=== PAUSE TestRateLimiterFeedback70=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess71=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess72=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer73=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer74=== RUN TestResolveStorePath75=== PAUSE TestResolveStorePath76=== RUN TestDoWithRetry_BodyReplayedViaGetBody77=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody78=== RUN TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade79=== PAUSE TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade80=== RUN TestRetryTimeoutOutlastsMaxRetries81=== PAUSE TestRetryTimeoutOutlastsMaxRetries82=== RUN TestDoWithRetry_FinalResponseBodyReadable83=== PAUSE TestDoWithRetry_FinalResponseBodyReadable84=== RUN TestShellSplit85=== PAUSE TestShellSplit86=== RUN TestShellSplitErrors87=== PAUSE TestShellSplitErrors88=== RUN TestStreamPushReportsEveryPath89=== PAUSE TestStreamPushReportsEveryPath90=== RUN TestStreamPushBatchesUnderLoad91=== PAUSE TestStreamPushBatchesUnderLoad92=== RUN TestStreamPushIsolatesFailures93=== PAUSE TestStreamPushIsolatesFailures94=== RUN TestStreamPushGivesUpOnDeadServer95=== PAUSE TestStreamPushGivesUpOnDeadServer96=== RUN TestStreamPushRequestLine97=== PAUSE TestStreamPushRequestLine98=== RUN TestStreamPushReportsSignatures99=== PAUSE TestStreamPushReportsSignatures100=== RUN TestStreamPushReportsSkippedPaths101=== PAUSE TestStreamPushReportsSkippedPaths102=== RUN TestClientSignaturesByStorePath103=== PAUSE TestClientSignaturesByStorePath104=== RUN TestStreamPushStopsWhenCanceled105=== PAUSE TestStreamPushStopsWhenCanceled106=== RUN TestStreamPushStopsOnCancel107=== PAUSE TestStreamPushStopsOnCancel108=== RUN TestSetClientTLS109=== PAUSE TestSetClientTLS110=== RUN TestSetClientTLSDoesNotMutateDefaultTransport111=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport112=== RUN TestSetClientTLSErrors113=== PAUSE TestSetClientTLSErrors114=== RUN TestStaticToken115=== PAUSE TestStaticToken116=== RUN TestFileTokenReadsAndCaches117=== PAUSE TestFileTokenReadsAndCaches118=== RUN TestFileTokenMissing119=== PAUSE TestFileTokenMissing120=== RUN TestFileTokenEmpty121=== PAUSE TestFileTokenEmpty122=== RUN TestScriptTokenNoExpiryRerunsEveryCall123=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall124=== RUN TestScriptTokenCachesUntilRefresh125=== PAUSE TestScriptTokenCachesUntilRefresh126=== RUN TestScriptTokenEmptyToken127=== PAUSE TestScriptTokenEmptyToken128=== RUN TestScriptTokenBadJSON129=== PAUSE TestScriptTokenBadJSON130=== RUN TestScriptTokenScriptFails131=== PAUSE TestScriptTokenScriptFails132=== RUN TestScriptTokenEmptyCommand133=== PAUSE TestScriptTokenEmptyCommand134=== RUN TestScriptTokenDoesNotWaitForItsChildren135=== PAUSE TestScriptTokenDoesNotWaitForItsChildren136=== CONT TestSetClientTLS137=== CONT TestRateLimiterFeedback138=== RUN TestRateLimiterFeedback/429_enables_limiter139=== CONT TestDoWithRetry_BodyReplayedViaGetBody140=== CONT TestUploadMultipart_FailedPartBufferNotReused141=== CONT TestUploadMultipart_ProducerErrorIsNotEOF142=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry143=== CONT TestScriptTokenCachesUntilRefresh144=== CONT TestStreamPushStopsOnCancel145=== CONT TestScriptTokenEmptyCommand146=== RUN TestStreamPushStopsOnCancel/waiting_for_input147=== CONT TestParsePathInfoJSON148=== CONT TestScriptTokenScriptFails149=== CONT TestConvertHashToNix32150=== CONT TestEncodeNixBase32WithRealHash151=== CONT TestUploadMultipart_PartsInParallel152=== CONT TestShellSplit153=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer154=== CONT TestTruncatedNARDumpIsNotCompleted155=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure156=== CONT TestDoServerRequestAttachesToken157=== CONT TestUploadMultipart_SupersededByPeer158=== PAUSE TestRateLimiterFeedback/429_enables_limiter159=== CONT TestDoWithRetry_FinalResponseBodyReadable160=== CONT TestPathInfoHashCompatibility161=== CONT TestDumpPathSingleFile162=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent163=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part164=== CONT TestScriptTokenBadJSON165--- PASS: TestScriptTokenEmptyCommand (0.00s)166=== RUN TestConvertHashToNix32/SRI_format_to_Nix32167=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input168=== RUN TestParsePathInfoJSON/Nix_format169=== CONT TestGetStorePathHash170=== CONT TestRetryTimeoutOutlastsMaxRetries171=== RUN TestUploadMultipart_SupersededByPeer/exists172=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier173=== RUN TestRateLimiterFeedback/503_enables_limiter174=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)175=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part176--- PASS: TestEncodeNixBase32WithRealHash (0.00s)177=== RUN TestSetClientTLS/rejects_connection_without_client_cert178=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32179=== PAUSE TestParsePathInfoJSON/Nix_format180=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot181=== RUN TestParsePathInfoJSON/Lix_format182=== CONT TestScriptTokenDoesNotWaitForItsChildren183=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs184=== CONT TestEncodeNixBase32185=== RUN TestGetStorePathHash/valid_store_path186=== PAUSE TestUploadMultipart_SupersededByPeer/exists187--- PASS: TestShellSplit (0.00s)188=== RUN TestConvertHashToNix32/already_Nix32_format189=== PAUSE TestRateLimiterFeedback/503_enables_limiter190=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary191=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)192=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier193=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert194=== PAUSE TestParsePathInfoJSON/Lix_format195=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot196=== RUN TestEncodeNixBase32/test_string_hash197=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot198=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs199=== RUN TestUploadMultipart_SupersededByPeer/missing200=== PAUSE TestGetStorePathHash/valid_store_path201--- PASS: TestScriptTokenScriptFails (0.24s)202=== RUN TestGetStorePathHash/basename_without_hyphen_should_error203=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error204=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error205--- PASS: TestScriptTokenBadJSON (0.24s)206=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter207=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary208=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter209=== CONT TestScriptTokenEmptyToken210=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon211=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up212=== RUN TestParsePathInfoJSON/empty_input213=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up214=== PAUSE TestParsePathInfoJSON/empty_input215=== CONT TestCaseHackSuffix216=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot217=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA218=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout219=== PAUSE TestUploadMultipart_SupersededByPeer/missing220=== PAUSE TestConvertHashToNix32/already_Nix32_format221=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error222=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica223=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter224=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter225=== CONT TestCompletePendingClosure_NotFoundWithoutKey226=== CONT TestClientSignaturesByStorePath227--- PASS: TestDoServerRequestAttachesToken (0.24s)228=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon229=== PAUSE TestEncodeNixBase32/test_string_hash230=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier231=== CONT TestResolveStorePath232=== RUN TestParsePathInfoJSON/whitespace_only233=== PAUSE TestParsePathInfoJSON/whitespace_only234=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot235=== RUN TestParsePathInfoJSON/invalid_JSON236=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA237=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout238=== RUN TestConvertHashToNix32/invalid_format239=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error240--- PASS: TestClientSignaturesByStorePath (0.00s)241=== CONT TestDumpPathWriterError242=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI243=== RUN TestEncodeNixBase32/empty_input244=== PAUSE TestEncodeNixBase32/empty_input245=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier246=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot247=== RUN TestSetClientTLS/preserves_debug_logging_transport248=== PAUSE TestSetClientTLS/preserves_debug_logging_transport249=== CONT TestSetClientTLSDoesNotMutateDefaultTransport250=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot251=== CONT TestStreamPushGivesUpOnDeadServer252=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot253=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken254=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error255=== PAUSE TestParsePathInfoJSON/invalid_JSON256--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.24s)257=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun258=== CONT TestStreamPushStopsWhenCanceled259=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI260=== CONT TestRegisterUploadedObjectReusesConnections261=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512262=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512263=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess264=== CONT TestStreamPushRequestLine265=== CONT TestFilterOversizedClosures266=== CONT TestDumpPathMatchesNix267=== PAUSE TestConvertHashToNix32/invalid_format268=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken269=== CONT TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade270=== RUN TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0271=== CONT TestParsePathInfoJSONMultiplePaths272--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.25s)273=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths274=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths275=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths276--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.25s)277--- PASS: TestResolveStorePath (0.00s)278=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths279=== PAUSE TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0280=== RUN TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=5281=== PAUSE TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=5282=== CONT TestStreamPushReportsSkippedPaths283=== CONT TestPartSizeForNAR284=== RUN TestPartSizeForNAR/zero_stays_at_minimum285=== CONT TestStreamPushReportsSignatures286--- PASS: TestStreamPushStopsWhenCanceled (0.00s)287=== CONT TestFileTokenMissing288--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)289--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)290=== CONT TestSetClientTLSErrors291=== CONT TestSupersededNARStillUploadsListing292=== RUN TestSupersededNARStillUploadsListing/small_NAR293--- PASS: TestFileTokenMissing (0.00s)294=== PAUSE TestSupersededNARStillUploadsListing/small_NAR295--- PASS: TestScriptTokenEmptyToken (0.00s)296=== RUN TestSupersededNARStillUploadsListing/dump_cut_short297=== RUN TestFilterOversizedClosures/no_limit_keeps_everything298--- PASS: TestStreamPushReportsSkippedPaths (0.00s)299=== CONT TestFileTokenEmpty300=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything301=== CONT TestStaticToken302--- PASS: TestStaticToken (0.00s)303=== CONT TestFileTokenReadsAndCaches304--- PASS: TestFileTokenEmpty (0.00s)305=== CONT TestStreamPushIsolatesFailures306--- PASS: TestFileTokenReadsAndCaches (0.00s)307=== CONT TestScriptTokenNoExpiryRerunsEveryCall308--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)309--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)310--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.00s)311--- PASS: TestScriptTokenCachesUntilRefresh (0.25s)312=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum313=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client314=== CONT TestPathInfoCACompatibility315=== RUN TestPathInfoCACompatibility/null_ca_field316=== PAUSE TestPathInfoCACompatibility/null_ca_field317=== RUN TestPathInfoCACompatibility/old_string_format_-_text318=== RUN TestPartSizeForNAR/small_stays_at_minimum319=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped320=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text321=== PAUSE TestPartSizeForNAR/small_stays_at_minimum322=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client323=== CONT TestStreamPushReportsEveryPath324--- PASS: TestStreamPushReportsSignatures (0.00s)325=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped326=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short327=== RUN TestSetClientTLSErrors/missing_cert_file328=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client329=== PAUSE TestSetClientTLSErrors/missing_cert_file330=== RUN TestFilterOversizedClosures/all_closures_skipped331=== CONT TestShellSplitErrors332=== PAUSE TestFilterOversizedClosures/all_closures_skipped333=== RUN TestSetClientTLSErrors/missing_key_file334=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part335=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary336=== CONT TestUploadMultipart_SupersededByPeer/missing337=== CONT TestStreamPushBatchesUnderLoad338=== RUN TestStreamPushBatchesUnderLoad/together339--- PASS: TestShellSplitErrors (0.00s)340--- PASS: TestStreamPushIsolatesFailures (0.00s)341=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum342--- PASS: TestStreamPushReportsEveryPath (0.00s)343=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails344=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client345=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive346=== PAUSE TestSetClientTLSErrors/missing_key_file347=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails348=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive349=== RUN TestPathInfoCACompatibility/new_structured_format_-_text350=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text351=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method352=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum353=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter354=== RUN TestSetClientTLSErrors/missing_ca_file355=== CONT TestRateLimiterFeedback/429_enables_limiter356=== CONT TestUploadMultipart_SupersededByPeer/exists357=== PAUSE TestSetClientTLSErrors/missing_ca_file358=== RUN TestSetClientTLSErrors/invalid_ca_file359=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts360=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts361=== RUN TestPartSizeForNAR/1_TiB362=== PAUSE TestStreamPushBatchesUnderLoad/together363=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time364=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time365=== PAUSE TestPartSizeForNAR/1_TiB366=== PAUSE TestSetClientTLSErrors/invalid_ca_file367=== RUN TestPartSizeForNAR/5_TiB_S3_max_object368=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object369=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method370=== RUN TestPartSizeForNAR/capped_at_5_GiB371=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter372=== CONT TestRateLimiterFeedback/503_enables_limiter373=== PAUSE TestPartSizeForNAR/capped_at_5_GiB374=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout375=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs376=== CONT TestEncodeNixBase32/empty_input377=== CONT TestSetClientTLS/preserves_debug_logging_transport378=== CONT TestEncodeNixBase32/test_string_hash379--- PASS: TestEncodeNixBase32 (0.00s)380 --- PASS: TestEncodeNixBase32/empty_input (0.00s)381 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)382=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA383=== CONT TestSetClientTLS/rejects_connection_without_client_cert384=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error385=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error386=== CONT TestGetStorePathHash/basename_without_hyphen_should_error387=== CONT TestGetStorePathHash/valid_store_path388=== CONT TestParsePathInfoJSON/Nix_format389--- PASS: TestUploadMultipart_SupersededByPeer (0.24s)390 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)391 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)392=== CONT TestParsePathInfoJSON/invalid_JSON393--- PASS: TestGetStorePathHash (0.01s)394 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)395 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)396 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)397 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)398=== CONT TestParsePathInfoJSON/Lix_format399=== CONT TestParsePathInfoJSON/empty_input400=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)401--- PASS: TestRateLimiterFeedback (0.25s)402 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)403 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)404 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)405 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)406=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI407=== CONT TestParsePathInfoJSON/whitespace_only408=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon409--- PASS: TestParsePathInfoJSON (0.25s)410 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)411 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)412 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)413 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)414 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)415=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512416=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot417=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot418=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot419--- PASS: TestPathInfoHashCompatibility (0.24s)420 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)421 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)422 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)423 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)424--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)425=== CONT TestStreamPushStopsOnCancel/waiting_for_input426--- PASS: TestDumpPathSingleFile (0.27s)427=== CONT TestConvertHashToNix32/SRI_format_to_Nix32428=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken429=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot430--- PASS: TestCaseHackSuffix (0.03s)431=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths432=== CONT TestConvertHashToNix32/invalid_format433=== CONT TestConvertHashToNix32/already_Nix32_format434--- PASS: TestConvertHashToNix32 (0.25s)435 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)436 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)437 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)438=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths439=== CONT TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=5440--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)441 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)442 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)443=== CONT TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0444=== CONT TestFilterOversizedClosures/no_limit_keeps_everything445--- PASS: TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade (0.00s)446 --- PASS: TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=5 (0.00s)447 --- PASS: TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0 (0.00s)448=== CONT TestFilterOversizedClosures/all_closures_skipped449=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped450=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails451--- PASS: TestFilterOversizedClosures (0.01s)452 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)453 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)454 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)455=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up456--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.28s)457=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client458=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client459=== CONT TestSupersededNARStillUploadsListing/small_NAR460=== CONT TestSupersededNARStillUploadsListing/dump_cut_short461=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier462=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier463=== CONT TestStreamPushBatchesUnderLoad/together464=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time465=== CONT TestSetClientTLSErrors/missing_cert_file466=== CONT TestSetClientTLSErrors/missing_ca_file467=== CONT TestPathInfoCACompatibility/null_ca_field468=== CONT TestSetClientTLSErrors/missing_key_file469=== CONT TestSetClientTLSErrors/invalid_ca_file470=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum471=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts472--- PASS: TestStreamPushBatchesUnderLoad (0.00s)473 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)474 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)475=== CONT TestPartSizeForNAR/capped_at_5_GiB476=== CONT TestPartSizeForNAR/5_TiB_S3_max_object477=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method478=== CONT TestPathInfoCACompatibility/old_string_format_-_text479=== CONT TestPathInfoCACompatibility/new_structured_format_-_text480=== CONT TestPartSizeForNAR/1_TiB481=== CONT TestPartSizeForNAR/zero_stays_at_minimum482--- PASS: TestSetClientTLSErrors (0.01s)483 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)484 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)485 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)486 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)487=== CONT TestPartSizeForNAR/small_stays_at_minimum488=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive489--- PASS: TestStreamPushStopsOnCancel (0.25s)490 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.18s)491 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.18s)492 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.17s)493 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.18s)494 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.19s)495 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.18s)496--- PASS: TestPathInfoCACompatibility (0.01s)497 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)498 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)499 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)500 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)501 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)502--- PASS: TestPartSizeForNAR (0.01s)503 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)504 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)505 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)506 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)507 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)508 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)509 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)510--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.25s)511 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.00s)512 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.17s)513 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.00s)514 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.01s)515 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.17s)516--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.22s)517--- PASS: TestDumpPathWriterError (0.22s)518--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.24s)519 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.24s)520 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.46s)521--- PASS: TestSetClientTLS (0.25s)522 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)523 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)524 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.48s)525--- PASS: TestRegisterUploadedObjectReusesConnections (0.53s)526--- PASS: TestDumpPathMatchesNix (0.53s)527--- PASS: TestStreamPushRequestLine (0.57s)528--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)529--- PASS: TestUploadMultipart_PartsInParallel (1.35s)530--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.42s)531--- PASS: TestSupersededNARStillUploadsListing (0.01s)532 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.18s)533 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.04s)534 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.05s)535--- PASS: TestTruncatedNARDumpIsNotCompleted (1.54s)536--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (2.00s)537--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.00s)538 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.00s)539 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.20s)540PASS541Running server tests...542The files belonging to this database system will be owned by user "nixbld".543This user must also own the server process.544545The database cluster will be initialized with locale "C".546The default database encoding has accordingly been set to "SQL_ASCII".547The default text search configuration will be set to "english".548549Data page checksums are enabled.550551creating directory /build/postgres3764348244/data ... ok552creating subdirectories ... ok553selecting dynamic shared memory implementation ... posix554selecting default "max_connections" ... 100555selecting default "shared_buffers" ... 128MB556selecting default time zone ... UTC557creating configuration files ... ok558running bootstrap script ... ok559performing post-bootstrap initialization ... ok560syncing data to disk ... ok561562initdb: warning: enabling "trust" authentication for local connections563initdb: 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.564565Success. You can now start the database server using:566567 pg_ctl -D /build/postgres3764348244/data -l logfile start568569/build/postgres3764348244:5432 - no response5702026-10-08 21:39:58.589 UTC [173] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5712026-10-08 21:39:58.590 UTC [173] LOG: listening on Unix socket "/build/postgres3764348244/.s.PGSQL.5432"5722026-10-08 21:39:58.594 UTC [180] LOG: database system was shut down at 2026-10-08 21:39:58 UTC5732026-10-08 21:39:58.598 UTC [173] LOG: database system is ready to accept connections574/build/postgres3764348244:5432 - accepting connections575{"timestamp":"2026-10-08T21:39:58.796044439Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"23ff2cce-40a5-4f2b-a963-639a8bc3ab09","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(204)"}576=== RUN TestService_AuthMiddleware577=== PAUSE TestService_AuthMiddleware578=== RUN TestService_AuthMiddleware_MTLSProxyHeader579=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader580=== RUN TestService_AuthMiddleware_MTLSBoundSubjects581=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects582=== RUN TestService_ReadAuthMiddleware583=== PAUSE TestService_ReadAuthMiddleware584=== RUN TestService_AuthMiddleware_OIDC585=== PAUSE TestService_AuthMiddleware_OIDC586=== RUN TestService_RequireScope_OIDC587=== PAUSE TestService_RequireScope_OIDC588=== RUN TestService_ReadScope_PublicByDefault589=== PAUSE TestService_ReadScope_PublicByDefault590=== RUN TestCacheConfigHandler591=== PAUSE TestCacheConfigHandler592=== RUN TestCacheStatsHandler593=== PAUSE TestCacheStatsHandler594=== RUN TestClientCADerivations595=== PAUSE TestClientCADerivations596=== RUN TestClientErrorHandling597=== PAUSE TestClientErrorHandling598=== RUN TestClientIntegration599=== PAUSE TestClientIntegration600=== RUN TestClientMultipleUploads601=== PAUSE TestClientMultipleUploads602=== RUN TestClientWithDependencies603=== PAUSE TestClientWithDependencies604=== RUN TestClientSharedPathCommittedMidPush605=== PAUSE TestClientSharedPathCommittedMidPush606=== RUN TestPinProtectsFromGC607=== PAUSE TestPinProtectsFromGC608=== RUN TestClientPushesUseOnePush609=== PAUSE TestClientPushesUseOnePush610=== RUN TestClientFallsBackToClosures611=== PAUSE TestClientFallsBackToClosures612=== RUN TestDeleteClosuresRacingPins613=== PAUSE TestDeleteClosuresRacingPins614=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock615=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock616=== RUN TestResolveDBConnectionString617=== PAUSE TestResolveDBConnectionString618=== RUN TestConnectWaitsForAPeerMigration619=== PAUSE TestConnectWaitsForAPeerMigration620=== RUN TestConnectSerialisesConcurrentMigrations621=== PAUSE TestConnectSerialisesConcurrentMigrations622=== RUN TestLeadElectsOneAndHandsOver623=== PAUSE TestLeadElectsOneAndHandsOver624=== RUN TestLeadIncumbentWinsAfterRestart6252026/10/08 21:39:59 INFO lead: acquired remote=192.0.2.1:12346262026/10/08 21:39:59 INFO lead: released remote=192.0.2.1:12346272026/10/08 21:39:59 INFO lead: acquired remote=192.0.2.1:12346282026/10/08 21:40:00 INFO lead: released remote=192.0.2.1:1234629--- PASS: TestLeadIncumbentWinsAfterRestart (1.91s)630=== RUN TestLeadIncumbentAnnouncesAtOnce631=== PAUSE TestLeadIncumbentAnnouncesAtOnce632=== RUN TestLeadEndsOnShutdown633=== PAUSE TestLeadEndsOnShutdown634=== RUN TestLeadEndsWhenItsConnectionHangs6352026/10/08 21:40:00 INFO lead: acquired remote=192.0.2.1:12346362026-10-08 21:40:02.348 UTC [431] FATAL: terminating connection due to administrator command6372026/10/08 21:40:02 INFO lead: acquired remote=192.0.2.1:12346382026/10/08 21:40:03 WARN lead: lock connection lost error="timeout: context deadline exceeded"6392026/10/08 21:40:03 INFO lead: released remote=192.0.2.1:12346402026/10/08 21:40:03 INFO lead: released remote=192.0.2.1:1234641--- PASS: TestLeadEndsWhenItsConnectionHangs (2.95s)642=== RUN TestGCAdvisoryLockBlocksConcurrentRun643=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun644=== RUN TestGCBugBareHashReferences645=== PAUSE TestGCBugBareHashReferences646=== RUN TestGCMetrics647=== PAUSE TestGCMetrics648=== RUN TestPushDedupSurvivesConcurrentGC649=== PAUSE TestPushDedupSurvivesConcurrentGC650=== RUN TestDeduplicatedObjectsRecordedAsPending651=== PAUSE TestDeduplicatedObjectsRecordedAsPending652=== RUN TestGCSweepSkipsPendingObjects653=== PAUSE TestGCSweepSkipsPendingObjects654=== RUN TestTombstonedObjectOfferedWithoutWaiting655=== PAUSE TestTombstonedObjectOfferedWithoutWaiting656=== RUN TestGCSweepDeliversEachKeyOnce657=== PAUSE TestGCSweepDeliversEachKeyOnce658=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection659=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection660=== RUN TestForceGCDuringPushOffersSweptObject661=== PAUSE TestForceGCDuringPushOffersSweptObject662=== RUN TestFailedS3DeleteKeepsTombstone663=== PAUSE TestFailedS3DeleteKeepsTombstone664=== RUN TestSweepSkipsRowsLockedByPush665=== PAUSE TestSweepSkipsRowsLockedByPush666=== RUN TestRegisterCompletedObjectNeedsPendingRow667=== PAUSE TestRegisterCompletedObjectNeedsPendingRow668=== RUN TestGetExistingObjectsLocksRows669=== PAUSE TestGetExistingObjectsLocksRows670=== RUN TestSweepRechecksPendingAfterLocking671=== PAUSE TestSweepRechecksPendingAfterLocking672=== RUN TestPushWaitsForSweepHoldingRow673=== PAUSE TestPushWaitsForSweepHoldingRow674=== RUN TestCommitRacingPendingCleanupKeepsObjects675=== PAUSE TestCommitRacingPendingCleanupKeepsObjects676=== RUN TestGCEndsOnShutdown677=== PAUSE TestGCEndsOnShutdown678=== RUN TestGCTaskStore_StartNew679=== PAUSE TestGCTaskStore_StartNew680=== RUN TestGCTaskStore_DeduplicateSameParams681=== PAUSE TestGCTaskStore_DeduplicateSameParams682=== RUN TestGCTaskStore_ConflictDifferentParams683=== PAUSE TestGCTaskStore_ConflictDifferentParams684=== RUN TestGCTaskStore_GetEmpty685=== PAUSE TestGCTaskStore_GetEmpty686=== RUN TestGCTaskStore_GetReturnsLatest687=== PAUSE TestGCTaskStore_GetReturnsLatest688=== RUN TestGCTaskStore_CompletedAllowsNewTask689=== PAUSE TestGCTaskStore_CompletedAllowsNewTask690=== RUN TestGCTaskStore_PhaseUpdates691=== PAUSE TestGCTaskStore_PhaseUpdates692=== RUN TestGCTaskStore_Fail693=== PAUSE TestGCTaskStore_Fail694=== RUN TestGracefulShutdownDrainsInflight695=== PAUSE TestGracefulShutdownDrainsInflight696=== RUN TestService_healthCheckHandler697=== PAUSE TestService_healthCheckHandler698=== RUN TestService_readinessHandler699=== PAUSE TestService_readinessHandler700=== RUN TestGenerateLandingPage701=== PAUSE TestGenerateLandingPage702=== RUN TestCacheConfigHandlerMaxNarSize703=== PAUSE TestCacheConfigHandlerMaxNarSize704=== RUN TestCreatePendingClosureRejectsOversizedNAR705=== PAUSE TestCreatePendingClosureRejectsOversizedNAR706=== RUN TestNARDeduplicationMetadataUploadBug707=== PAUSE TestNARDeduplicationMetadataUploadBug708=== RUN TestMetricsInventory709=== PAUSE TestMetricsInventory710=== RUN TestMetricsCommit711=== PAUSE TestMetricsCommit712=== RUN TestService_NativeMTLS713=== PAUSE TestService_NativeMTLS714=== RUN TestServerTLSConfig715=== PAUSE TestServerTLSConfig716=== RUN TestMultipartCleanup717=== PAUSE TestMultipartCleanup718=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded719=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded720=== RUN TestPendingCleanupUsesOneCutoff721=== PAUSE TestPendingCleanupUsesOneCutoff722=== RUN TestPendingClosureFailureTracksEveryUpload723=== PAUSE TestPendingClosureFailureTracksEveryUpload724=== RUN TestPendingClosureFailureAbortsItsUploads725=== PAUSE TestPendingClosureFailureAbortsItsUploads726=== RUN TestObjectStatsTrigger727=== PAUSE TestObjectStatsTrigger728=== RUN TestObjectStatsLargeCommit729=== PAUSE TestObjectStatsLargeCommit730=== RUN TestReconnectLeavesObjectsUnlocked731=== PAUSE TestReconnectLeavesObjectsUnlocked732=== RUN TestOrphanedObjectsGC733=== PAUSE TestOrphanedObjectsGC734=== RUN TestOrphanedObjectsGCStressTest735=== PAUSE TestOrphanedObjectsGCStressTest736=== RUN TestCreatePin_ReservedPins737=== PAUSE TestCreatePin_ReservedPins738=== RUN TestConcurrentPinUpdatesAgree739=== PAUSE TestConcurrentPinUpdatesAgree740=== RUN TestCreatePinRejectsBadInput741=== PAUSE TestCreatePinRejectsBadInput742=== RUN TestDeletePinKeepsRowWhenS3Fails743=== PAUSE TestDeletePinKeepsRowWhenS3Fails744=== RUN TestPresentReportsOnlyClosureRoots745=== PAUSE TestPresentReportsOnlyClosureRoots746=== RUN TestPresentRefreshesOnlyStaleClosures747=== PAUSE TestPresentRefreshesOnlyStaleClosures748=== RUN TestPresentNotReportedWhileGCDeletesClosure749=== PAUSE TestPresentNotReportedWhileGCDeletesClosure750=== RUN TestParseSingleRange751=== PAUSE TestParseSingleRange752=== RUN TestProxyHeadersOnlyTrustedOnSocket7532026/10/08 21:40:03 INFO Starting HTTP server address=proxy.sock7542026/10/08 21:40:03 INFO Starting HTTP server address=127.0.0.1:402457552026/10/08 21:40:03 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7562026/10/08 21:40:03 INFO Shutdown signal received, draining in-flight requests timeout=10s757--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.13s)758=== RUN TestIsValidCachePath759=== PAUSE TestIsValidCachePath760=== RUN TestReadProxyNarinfo761=== PAUSE TestReadProxyNarinfo762=== RUN TestReadProxyNarinfoAlreadyDecompressed763=== PAUSE TestReadProxyNarinfoAlreadyDecompressed764=== RUN TestReadProxyContentNegotiation765=== PAUSE TestReadProxyContentNegotiation766=== RUN TestReadProxyNarStreaming767=== PAUSE TestReadProxyNarStreaming768=== RUN TestReadProxy404769=== PAUSE TestReadProxy404770=== RUN TestReadProxyInvalidPath771=== PAUSE TestReadProxyInvalidPath772=== RUN TestReadProxyHead773=== PAUSE TestReadProxyHead774=== RUN TestReadProxyOutlastsServerWriteTimeout775=== PAUSE TestReadProxyOutlastsServerWriteTimeout776=== RUN TestReadProxyConditionalGet777=== PAUSE TestReadProxyConditionalGet778=== RUN TestReadProxyRootRedirectsToIndexHTML779=== PAUSE TestReadProxyRootRedirectsToIndexHTML780=== RUN TestReadProxyDisabled781=== PAUSE TestReadProxyDisabled782=== RUN TestReadRedirectNar783=== PAUSE TestReadRedirectNar784=== RUN TestReadRedirectKeepsNarinfoProxied785=== PAUSE TestReadRedirectKeepsNarinfoProxied786=== RUN TestReadProxyRangeRequest787=== PAUSE TestReadProxyRangeRequest788=== RUN TestReadRedirectUsesPublicS3URL789=== PAUSE TestReadRedirectUsesPublicS3URL790=== RUN TestPush_OverlappingRootsStoreOneRowPerKey791=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey792=== RUN TestPush_CompleteCommitsEveryRoot793=== PAUSE TestPush_CompleteCommitsEveryRoot794=== RUN TestPush_RepeatedRootCommitsOnce795=== PAUSE TestPush_RepeatedRootCommitsOnce796=== RUN TestPush_CompleteWaitsForCleanupOfThePush797=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush798=== RUN TestPush_RootsAreLockedInByteOrder799=== PAUSE TestPush_RootsAreLockedInByteOrder800=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit801=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit802=== RUN TestPush_RejectsBadRequests803=== PAUSE TestPush_RejectsBadRequests804=== RUN TestPush_SignsNarinfosOfItsPendingObjects805=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects806=== RUN TestRedundantMultipartUpload807=== PAUSE TestRedundantMultipartUpload808=== RUN TestCompleteMultipartUpload_ErrorButObjectExists809=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists810=== RUN TestCompletedNarNotReofferedAcrossClosures811=== PAUSE TestCompletedNarNotReofferedAcrossClosures812=== RUN TestPresignedUploadRegisteredBeforeCommit813=== PAUSE TestPresignedUploadRegisteredBeforeCommit814=== RUN TestService_Rustfstest815=== PAUSE TestService_Rustfstest816=== RUN TestParseSize817=== PAUSE TestParseSize818=== RUN TestSkippedUploadsHandler819=== PAUSE TestSkippedUploadsHandler820=== RUN TestSystemdListenerNotActivated821--- PASS: TestSystemdListenerNotActivated (0.00s)822=== RUN TestWatchdogBeatsWhenHealthy823--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)824=== RUN TestWatchdogSkipsWhenUnhealthy8252026/10/08 21:40:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8262026/10/08 21:40:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8272026/10/08 21:40:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8282026/10/08 21:40:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8292026/10/08 21:40:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8302026/10/08 21:40:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8312026/10/08 21:40:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8322026/10/08 21:40:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8332026/10/08 21:40:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8342026/10/08 21:40:04 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"835--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)836=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle837=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle838=== RUN TestProxyWriteTimeout839=== PAUSE TestProxyWriteTimeout840=== RUN TestPendingClosureWriteTimeout841=== PAUSE TestPendingClosureWriteTimeout842=== RUN TestIsValidUploadKey843=== PAUSE TestIsValidUploadKey844=== RUN TestUploadHandlersRejectInvalidKeys845=== PAUSE TestUploadHandlersRejectInvalidKeys846=== RUN TestUploadHandlersRejectOversizedBody847=== PAUSE TestUploadHandlersRejectOversizedBody848=== RUN TestService_cleanupPendingClosuresHandler849=== PAUSE TestService_cleanupPendingClosuresHandler850=== RUN TestService_createPendingClosureHandler851=== PAUSE TestService_createPendingClosureHandler852=== RUN TestService_verifyS3Integrity853=== PAUSE TestService_verifyS3Integrity854=== RUN TestCompleteMultipartUnregistered855=== PAUSE TestCompleteMultipartUnregistered856=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT857=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT858=== CONT TestParseSize859=== CONT TestGCTaskStore_Fail860=== CONT TestCompleteMultipartUpload_ErrorButObjectExists861=== CONT TestGCTaskStore_StartNew862=== CONT TestGCTaskStore_ConflictDifferentParams863--- PASS: TestParseSize (0.00s)864=== CONT TestService_AuthMiddleware_MTLSProxyHeader865=== CONT TestService_Rustfstest866=== CONT TestService_healthCheckHandler867=== CONT TestService_readinessHandler868=== CONT TestPush_CompleteWaitsForCleanupOfThePush869=== CONT TestLeadEndsOnShutdown870=== CONT TestGCTaskStore_PhaseUpdates871=== CONT TestGCTaskStore_GetReturnsLatest872=== CONT TestReadProxyOutlastsServerWriteTimeout873=== CONT TestGCTaskStore_GetEmpty874=== CONT TestGCTaskStore_CompletedAllowsNewTask875=== CONT TestDeletePinKeepsRowWhenS3Fails876=== CONT TestGracefulShutdownDrainsInflight877=== CONT TestUploadHandlersRejectOversizedBody878=== CONT TestLeadElectsOneAndHandsOver879=== CONT TestCompletedNarNotReofferedAcrossClosures880=== CONT TestRedundantMultipartUpload881=== CONT TestGCAdvisoryLockBlocksConcurrentRun8822026/10/08 21:40:04 INFO Starting HTTP server address=127.0.0.1:35227883=== CONT TestService_verifyS3Integrity884=== CONT TestService_createPendingClosureHandler885=== CONT TestGenerateLandingPage886=== CONT TestPresignedUploadRegisteredBeforeCommit887--- PASS: TestGCTaskStore_StartNew (0.00s)888=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit889--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)890--- PASS: TestGCTaskStore_Fail (0.00s)891--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)892--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)893--- PASS: TestGCTaskStore_GetEmpty (0.00s)894--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)8952026/10/08 21:40:04 INFO Shutdown signal received, draining in-flight requests timeout=10s896=== CONT TestPush_RepeatedRootCommitsOnce897=== CONT TestCreatePinRejectsBadInput898=== CONT TestCreatePin_ReservedPins899=== CONT TestReadProxy404900--- PASS: TestGenerateLandingPage (0.02s)901=== CONT TestReadRedirectNar902=== CONT TestForceGCDuringPushOffersSweptObject903--- PASS: TestGracefulShutdownDrainsInflight (0.07s)904=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows905=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows906=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check907=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check908=== CONT TestReadProxyDisabled9092026/10/08 21:40:04 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41151/oidc9102026/10/08 21:40:04 WARN readiness check failed error="closed pool"911--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.28s)912=== CONT TestTombstonedObjectOfferedWithoutWaiting913--- PASS: TestService_readinessHandler (0.29s)914=== CONT TestNARDeduplicationMetadataUploadBug9152026/10/08 21:40:04 INFO Received uploads request method=POST path=/api/pending_closures9162026/10/08 21:40:04 INFO lead: acquired remote=192.0.2.1:1234917=== CONT TestGCSweepSkipsPendingObjects918--- PASS: TestService_healthCheckHandler (0.34s)9192026/10/08 21:40:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9202026/10/08 21:40:04 INFO Received create pin request method=POST path=/api/pins/app9212026/10/08 21:40:04 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLmI1NmM3NDk1LWZhOWUtNDU4My1hYTViLWVmYmI3YzkxODk4ZHgxNzkxNDk1NjA0NDMwNDYwODY09222026/10/08 21:40:04 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo9232026/10/08 21:40:04 INFO Received delete pin request method=DELETE path=/api/pins/app9242026/10/08 21:40:04 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLmI1NmM3NDk1LWZhOWUtNDU4My1hYTViLWVmYmI3YzkxODk4ZHgxNzkxNDk1NjA0NDMwNDYwODY0 error="Delete \"http://localhost:43647/bucket6/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLmI1NmM3NDk1LWZhOWUtNDU4My1hYTViLWVmYmI3YzkxODk4ZHgxNzkxNDk1NjA0NDMwNDYwODY0\": injected: abort refused"9252026/10/08 21:40:04 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket9/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"9262026/10/08 21:40:04 INFO Received delete pin request method=DELETE path=/api/pins/app9272026/10/08 21:40:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9282026/10/08 21:40:04 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLmI1NmM3NDk1LWZhOWUtNDU4My1hYTViLWVmYmI3YzkxODk4ZHgxNzkxNDk1NjA0NDMwNDYwODY09292026/10/08 21:40:04 INFO Deleted pin name=app9302026/10/08 21:40:04 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLmI1NmM3NDk1LWZhOWUtNDU4My1hYTViLWVmYmI3YzkxODk4ZHgxNzkxNDk1NjA0NDMwNDYwODY0 parts=1931=== CONT TestService_ReadAuthMiddleware932--- PASS: TestService_Rustfstest (0.38s)933--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.38s)934=== CONT TestService_NativeMTLS9352026/10/08 21:40:04 INFO Received uploads request method=POST path=/api/pending_closures936--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.39s)937=== CONT TestServerTLSConfig938=== RUN TestServerTLSConfig/no_client_CA939=== PAUSE TestServerTLSConfig/no_client_CA940=== RUN TestServerTLSConfig/missing_CA_file941=== PAUSE TestServerTLSConfig/missing_CA_file942=== RUN TestServerTLSConfig/not_a_PEM_file943=== PAUSE TestServerTLSConfig/not_a_PEM_file944=== CONT TestMetricsInventory9452026/10/08 21:40:04 INFO Received uploads request method=POST path=/api/pending_closures9462026/10/08 21:40:04 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9472026/10/08 21:40:04 INFO Received uploads request method=POST path=/api/pending_closures948--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.44s)949=== CONT TestPush_OverlappingRootsStoreOneRowPerKey9502026/10/08 21:40:04 INFO lead: acquired remote=192.0.2.1:1234951=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure952=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure953=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart954=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart955=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts956=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts957=== CONT TestSweepRechecksPendingAfterLocking9582026/10/08 21:40:04 INFO Received uploads request method=POST path=/api/pending_closures9592026/10/08 21:40:04 INFO Received uploads request method=POST path=/api/pending_closures9602026/10/08 21:40:04 INFO Received create pin request method=POST path=/api/pins/deploy9612026/10/08 21:40:04 INFO Received create pin request method=POST path=/api/pins/deploy9622026/10/08 21:40:04 INFO Received create pin request method=POST path=/api/pins/deploy9632026/10/08 21:40:04 INFO Received create pin request method=POST path=/api/pins/deploy9642026/10/08 21:40:04 INFO Received create pin request method=POST path=/api/pins/deploy9652026/10/08 21:40:04 INFO Received create pin request method=POST path=/api/pins/deploy9662026/10/08 21:40:04 INFO Received create pin request method=POST path=/api/pins/deploy9672026/10/08 21:40:04 INFO Received create pin request method=POST path=/api/pins/deploy9682026/10/08 21:40:04 INFO Received create pin request method=POST path=/api/pins/deploy969--- PASS: TestReadProxyDisabled (0.51s)970=== CONT TestPush_RejectsBadRequests9712026/10/08 21:40:04 INFO Received push request method=POST path=/api/pushes9722026/10/08 21:40:04 INFO Received uploads request method=POST path=/api/pending_closures9732026/10/08 21:40:04 INFO Received uploads request method=POST path=/api/pending_closures9742026/10/08 21:40:04 INFO Received uploads request method=POST path=/api/pending_closures9752026/10/08 21:40:04 INFO Received uploads request method=POST path=/api/pending_closures9762026/10/08 21:40:04 INFO Received push request method=POST path=/api/pushes9772026/10/08 21:40:04 INFO Received push request method=POST path=/api/pushes9782026/10/08 21:40:04 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9792026/10/08 21:40:04 WARN Refused reserved pin name=worker-x86_64-linux9802026/10/08 21:40:04 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9812026/10/08 21:40:04 INFO Received create pin request method=POST path=/api/pins/my-app9822026/10/08 21:40:04 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux983=== CONT TestLeadIncumbentAnnouncesAtOnce984--- PASS: TestReadRedirectNar (0.71s)9852026/10/08 21:40:04 INFO Received uploads request method=POST path=/api/pending_closures986--- PASS: TestCreatePin_ReservedPins (0.75s)987=== CONT TestCompleteMultipartUnregistered988--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.50s)989=== CONT TestPush_SignsNarinfosOfItsPendingObjects9902026/10/08 21:40:04 INFO Received uploads request method=POST path=/api/pending_closures9912026/10/08 21:40:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete992=== NAME TestNARDeduplicationMetadataUploadBug993 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug960680638/001/store/vnsjn35zllnb7ypbk6nj4k7gi8j37awp-file1.txt9942026/10/08 21:40:04 INFO Aborted multipart uploads count=0 kept=09952026/10/08 21:40:04 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLjBmNmEzMWYwLTQxMTUtNDU5NC04YWI5LWFmYTdjM2VmZDA1YXgxNzkxNDk1NjA0NTIzMjc1ODI4 parts=109962026/10/08 21:40:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9972026/10/08 21:40:04 INFO Completed upload id=1 objects=2 duration=3.652572ms9982026/10/08 21:40:04 WARN Force mode enabled - objects will be deleted immediately without grace period9992026/10/08 21:40:04 WARN Rate limiter enabled after throttle name=s3-test rate=510002026/10/08 21:40:04 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."1001--- PASS: TestService_ReadAuthMiddleware (0.45s)1002=== CONT TestService_cleanupPendingClosuresHandler10032026/10/08 21:40:04 INFO Received uploads request method=POST path=/api/pending_closures10042026/10/08 21:40:04 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010052026/10/08 21:40:04 INFO Vacuumed table table=pending_closures10062026/10/08 21:40:04 INFO Received uploads request method=POST path=/api/pending_closures10072026/10/08 21:40:04 INFO Vacuumed table table=pending_objects10082026/10/08 21:40:04 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10092026/10/08 21:40:04 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10102026/10/08 21:40:04 INFO Vacuumed table table=multipart_uploads10112026/10/08 21:40:04 INFO Vacuumed table table=closures10122026/10/08 21:40:04 INFO Vacuumed table table=objects10132026/10/08 21:40:04 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10142026/10/08 21:40:04 WARN Found objects in DB but missing from S3, will re-upload count=110152026/10/08 21:40:04 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete10162026/10/08 21:40:04 INFO Completed upload id=3 objects=2 duration=1.968197ms1017--- PASS: TestService_NativeMTLS (0.48s)1018=== CONT TestConnectSerialisesConcurrentMigrations1019--- PASS: TestGCSweepSkipsPendingObjects (0.53s)1020=== CONT TestConnectWaitsForAPeerMigration1021=== CONT TestReconnectLeavesObjectsUnlocked1022--- PASS: TestService_verifyS3Integrity (0.87s)10232026/10/08 21:40:05 INFO Received push request method=POST path=/api/pushes10242026/10/08 21:40:05 INFO Received push request method=POST path=/api/pushes10252026/10/08 21:40:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10262026/10/08 21:40:05 INFO Uploading vnsjn35zllnb7ypbk6nj4k7gi8j37awp-file1.txt (160B)10272026/10/08 21:40:05 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"10282026/10/08 21:40:05 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"10292026/10/08 21:40:05 WARN Failed to register uploaded object key=vnsjn35zllnb7ypbk6nj4k7gi8j37awp.ls error="server returned 404: 404 page not found\n"10302026/10/08 21:40:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10312026/10/08 21:40:05 INFO Signed narinfos id=1 count=110322026/10/08 21:40:05 INFO Uploading 1 narinfos1033--- PASS: TestMetricsInventory (0.55s)1034=== CONT TestPush_RootsAreLockedInByteOrder10352026/10/08 21:40:05 INFO Received complete push request method=POST path=/api/pushes/1/complete10362026/10/08 21:40:05 WARN Failed to register uploaded object key=vnsjn35zllnb7ypbk6nj4k7gi8j37awp.narinfo error="server returned 404: 404 page not found\n"10372026/10/08 21:40:05 INFO Completed push id=1 objects=3 duration=5.004624ms10382026/10/08 21:40:05 INFO Upload complete. (101ms)1039--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.51s)1040=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1041=== NAME TestNARDeduplicationMetadataUploadBug1042 metadata_upload_test.go:54: Retrieved narinfo from S3:1043 StorePath: /build/TestNARDeduplicationMetadataUploadBug960680638/001/store/vnsjn35zllnb7ypbk6nj4k7gi8j37awp-file1.txt1044 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1045 Compression: zstd1046 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1047 NarSize: 1601048 References: 10492026/10/08 21:40:05 INFO Aborted multipart uploads count=0 kept=01050 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf10512026-10-08 21:40:05.087 UTC [685] ERROR: duplicate key value violates unique constraint "pg_class_relname_nsp_index"10522026-10-08 21:40:05.087 UTC [685] DETAIL: Key (relname, relnamespace)=(goose_db_version_id_seq, 2200) already exists.10532026-10-08 21:40:05.087 UTC [685] STATEMENT: CREATE TABLE goose_db_version (1054 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1055 version_id bigint NOT NULL,1056 is_applied boolean NOT NULL,1057 tstamp timestamp NOT NULL DEFAULT now()1058 )1059--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.95s)1060=== CONT TestPresentRefreshesOnlyStaleClosures1061=== NAME TestNARDeduplicationMetadataUploadBug1062 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1063 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1064 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}10652026/10/08 21:40:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10662026/10/08 21:40:05 WARN Force mode enabled - objects will be deleted immediately without grace period1067=== RUN TestPush_RejectsBadRequests/no_roots1068=== PAUSE TestPush_RejectsBadRequests/no_roots1069=== RUN TestPush_RejectsBadRequests/no_objects1070=== PAUSE TestPush_RejectsBadRequests/no_objects1071=== RUN TestPush_RejectsBadRequests/bad_root1072=== PAUSE TestPush_RejectsBadRequests/bad_root1073=== RUN TestPush_RejectsBadRequests/root_not_in_objects1074=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1075=== CONT TestConcurrentPinUpdatesAgree10762026/10/08 21:40:05 WARN Rate limiter backed off name=s3-test rate=510772026/10/08 21:40:05 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."10782026/10/08 21:40:05 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=01079=== NAME TestNARDeduplicationMetadataUploadBug1080 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug960680638/001/store/cjw97d3647nvfzhgyclw8n4njlj81aw0-file2.txt10812026/10/08 21:40:05 INFO Vacuumed table table=pending_closures10822026/10/08 21:40:05 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLjZkNzMxZjE1LTIxMDctNDVjMC1iYjlmLTc1OWNjZTIwNDlmMXgxNzkxNDk1NjA0NjAxNjk3MTAz parts=1210832026/10/08 21:40:05 INFO Vacuumed table table=pending_objects10842026/10/08 21:40:05 INFO Vacuumed table table=multipart_uploads10852026/10/08 21:40:05 INFO Received uploads request method=POST path=/api/pending_closures10862026/10/08 21:40:05 INFO Vacuumed table table=closures10872026/10/08 21:40:05 INFO Vacuumed table table=objects10882026/10/08 21:40:05 INFO lead: acquired remote=192.0.2.1:123410892026/10/08 21:40:05 INFO lead: released remote=192.0.2.1:123410902026/10/08 21:40:05 INFO Received uploads request method=POST path=/api/pending_closures10912026/10/08 21:40:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1092--- PASS: TestReadProxy404 (1.01s)1093--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.28s)1094=== CONT TestPush_CompleteCommitsEveryRoot1095=== CONT TestPresentNotReportedWhileGCDeletesClosure1096=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1097=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1098=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1099=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1100=== CONT TestResolveDBConnectionString1101=== RUN TestResolveDBConnectionString/flag_wins1102=== PAUSE TestResolveDBConnectionString/flag_wins1103=== RUN TestResolveDBConnectionString/file_when_flag_empty1104=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1105=== RUN TestResolveDBConnectionString/missing_file_is_an_error1106=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1107=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1108=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1109=== RUN TestResolveDBConnectionString/nothing_configured1110=== PAUSE TestResolveDBConnectionString/nothing_configured1111=== CONT TestClientIntegration11122026/10/08 21:40:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11132026/10/08 21:40:05 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1114=== CONT TestParseSingleRange1115=== RUN TestParseSingleRange/none1116--- PASS: TestSweepRechecksPendingAfterLocking (0.57s)1117=== PAUSE TestParseSingleRange/none1118=== RUN TestParseSingleRange/unknown_unit1119=== PAUSE TestParseSingleRange/unknown_unit1120=== RUN TestParseSingleRange/multi-range_ignored1121=== PAUSE TestParseSingleRange/multi-range_ignored1122=== RUN TestParseSingleRange/malformed_no_dash1123=== PAUSE TestParseSingleRange/malformed_no_dash1124=== RUN TestParseSingleRange/malformed_both_empty1125=== PAUSE TestParseSingleRange/malformed_both_empty1126=== RUN TestParseSingleRange/malformed_end_before_start1127=== PAUSE TestParseSingleRange/malformed_end_before_start1128=== RUN TestParseSingleRange/closed1129=== PAUSE TestParseSingleRange/closed1130=== RUN TestParseSingleRange/open-ended1131=== PAUSE TestParseSingleRange/open-ended1132=== RUN TestParseSingleRange/end_clamped_to_size1133=== PAUSE TestParseSingleRange/end_clamped_to_size1134=== RUN TestParseSingleRange/suffix1135=== PAUSE TestParseSingleRange/suffix1136=== RUN TestParseSingleRange/suffix_exceeds_size1137=== PAUSE TestParseSingleRange/suffix_exceeds_size1138=== RUN TestParseSingleRange/single_byte1139=== PAUSE TestParseSingleRange/single_byte1140=== RUN TestParseSingleRange/start_past_EOF1141=== PAUSE TestParseSingleRange/start_past_EOF1142=== RUN TestParseSingleRange/start_far_past_EOF1143=== PAUSE TestParseSingleRange/start_far_past_EOF1144=== CONT TestService_ReadScope_PublicByDefault11452026/10/08 21:40:05 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLjAzMzE1NDUwLTg3ZWMtNGFkZS05MzQ5LTM2ZmZlYjgwYmJiYXgxNzkxNDk1NjA0NzM3MzU1NjQ3 parts=1011462026/10/08 21:40:05 INFO Received push request method=POST path=/api/pushes1147--- PASS: TestCompleteMultipartUnregistered (0.31s)1148=== CONT TestClientWithDependencies11492026/10/08 21:40:05 INFO Received push request method=POST path=/api/pushes11502026/10/08 21:40:05 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11512026/10/08 21:40:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11522026/10/08 21:40:05 INFO Signed narinfos id=1 count=111532026/10/08 21:40:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11542026/10/08 21:40:05 WARN Failed to register uploaded object key=cjw97d3647nvfzhgyclw8n4njlj81aw0.ls error="server returned 404: 404 page not found\n"11552026/10/08 21:40:05 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11562026/10/08 21:40:05 INFO Signed narinfos id=2 count=111572026/10/08 21:40:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11582026/10/08 21:40:05 INFO Uploading 1 narinfos11592026/10/08 21:40:05 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"11602026/10/08 21:40:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11612026/10/08 21:40:05 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"11622026/10/08 21:40:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11632026/10/08 21:40:05 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=111642026/10/08 21:40:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11652026/10/08 21:40:05 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo11662026/10/08 21:40:05 INFO Received complete push request method=POST path=/api/pushes/2/complete11672026/10/08 21:40:05 WARN Failed to register uploaded object key=cjw97d3647nvfzhgyclw8n4njlj81aw0.narinfo error="server returned 404: 404 page not found\n"11682026/10/08 21:40:05 INFO Completed push id=2 objects=3 duration=2.303ms11692026/10/08 21:40:05 INFO Upload complete. (83ms)11702026/10/08 21:40:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1171=== NAME TestNARDeduplicationMetadataUploadBug1172 metadata_upload_test.go:76: Retrieved narinfo from S3:1173 StorePath: /build/TestNARDeduplicationMetadataUploadBug960680638/001/store/cjw97d3647nvfzhgyclw8n4njlj81aw0-file2.txt1174 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1175 Compression: zstd1176 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1177 NarSize: 1601178 References: 1179 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1180 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1181 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1182 {"version":1,"root":{"type":"regular","size":44}}1183=== CONT TestPresentReportsOnlyClosureRoots1184--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.34s)11852026/10/08 21:40:05 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLjNlYjVlMzIzLTg2NGUtNDcwMS04YWExLTJmMzQyOTcyYzZjMngxNzkxNDk1NjA0Nzc2MTIxNzkx parts=1011862026/10/08 21:40:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11872026/10/08 21:40:05 INFO Completed upload id=1 objects=2 duration=3.843714ms11882026/10/08 21:40:05 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011892026/10/08 21:40:05 INFO Received uploads request method=POST path=/api/pending_closures11902026/10/08 21:40:05 INFO Received cleanup request method=DELETE path=/api/pending_closures1191--- PASS: TestNARDeduplicationMetadataUploadBug (0.86s)1192=== CONT TestOrphanedObjectsGC11932026/10/08 21:40:05 INFO Starting cleanup of old closures method=DELETE path=/api/closures11942026/10/08 21:40:05 INFO Aborted multipart uploads count=0 kept=011952026/10/08 21:40:05 INFO Received uploads request method=POST path=/api/pending_closures11962026/10/08 21:40:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11972026/10/08 21:40:05 INFO Aborted multipart uploads count=0 kept=01198--- PASS: TestReconnectLeavesObjectsUnlocked (0.29s)1199=== CONT TestOrphanedObjectsGCStressTest12002026/10/08 21:40:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12012026/10/08 21:40:05 INFO Received cleanup request method=DELETE path=/api/pending_closures12022026/10/08 21:40:05 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012032026/10/08 21:40:05 INFO Aborted multipart uploads count=1 kept=012042026/10/08 21:40:05 INFO Vacuumed table table=pending_closures12052026/10/08 21:40:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12062026-10-08 21:40:05.307 UTC [664] ERROR: Closure does not exist: id=112072026-10-08 21:40:05.307 UTC [664] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE12082026-10-08 21:40:05.307 UTC [664] STATEMENT: -- name: CommitPendingClosure :one1209 SELECT commit_pending_closure($1::bigint)::bigint1210 12112026/10/08 21:40:05 INFO Vacuumed table table=pending_objects12122026/10/08 21:40:05 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLmU2YmZiZjIwLTMwZTAtNDkyOS04ODMxLTYzOWI2OTVhZDRiZHgxNzkxNDk1NjA0Nzk3MTE1MTk3 parts=1012132026/10/08 21:40:05 INFO Vacuumed table table=multipart_uploads12142026/10/08 21:40:05 INFO Vacuumed table table=closures12152026/10/08 21:40:05 INFO Vacuumed table table=objects12162026/10/08 21:40:05 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLjA5ODYyZGIyLTg1ZjctNDhlMy04YmQ5LWUzYTMzYWUyOTkyM3gxNzkxNDk1NjA0NzU0MDE5Nzk1 parts=121217--- PASS: TestService_cleanupPendingClosuresHandler (0.37s)1218=== CONT TestCacheStatsHandler12192026/10/08 21:40:05 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012202026/10/08 21:40:05 INFO Received uploads request method=POST path=/api/pending_closures12212026/10/08 21:40:05 INFO Received push request method=POST path=/api/pushes12222026/10/08 21:40:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1223--- PASS: TestService_createPendingClosureHandler (1.22s)1224=== CONT TestReadProxyInvalidPath12252026/10/08 21:40:05 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLjYzYzIxMjc3LTI0NjUtNDVjZS1hN2ViLTc2MDM1MDQzNTA4NXgxNzkxNDk1NjA0ODIzODAyNDk0 parts=101226=== CONT TestObjectStatsLargeCommit1227--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.23s)12282026/10/08 21:40:05 INFO Received create pin request method=POST path=/api/pins/app12292026/10/08 21:40:05 INFO Received create pin request method=POST path=/api/pins/app12302026/10/08 21:40:05 INFO Received push request method=POST path=/api/pushes1231=== CONT TestClientFallsBackToClosures1232=== CONT TestReadRedirectUsesPublicS3URL1233--- PASS: TestService_ReadScope_PublicByDefault (0.29s)1234--- PASS: TestPresentRefreshesOnlyStaleClosures (0.36s)12352026-10-08 21:40:05.482 UTC [749] ERROR: Push does not exist: id=112362026-10-08 21:40:05.482 UTC [749] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE12372026-10-08 21:40:05.482 UTC [749] STATEMENT: SELECT commit_push($1)12382026/10/08 21:40:05 INFO lead: released remote=192.0.2.1:12341239--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.37s)1240=== CONT TestClientPushesUseOnePush1241=== NAME TestClientIntegration1242 client_integration_test.go:334: Created store path: /build/TestClientIntegration2187512516/002/store/y3225hqjxdn7kcwpcklcqj5i18w364v8-test-file.txt12432026/10/08 21:40:05 INFO Received create pin request method=POST path=/api/pins/deploy1244=== CONT TestReadRedirectKeepsNarinfoProxied1245--- PASS: TestLeadEndsOnShutdown (1.38s)12462026/10/08 21:40:05 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo1247=== CONT TestPinProtectsFromGC1248--- PASS: TestPresentReportsOnlyClosureRoots (0.30s)1249--- PASS: TestCreatePinRejectsBadInput (1.41s)1250=== CONT TestReadProxyNarStreaming1251=== NAME TestClientWithDependencies1252 client_integration_test.go:735: Built derivation: /build/TestClientWithDependencies2825375673/001/store/hxmwwa32pb077zidmj509wmz6s8048ay-test-script12532026/10/08 21:40:05 INFO Received push request method=POST path=/api/pushes12542026/10/08 21:40:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12552026/10/08 21:40:05 INFO Uploading y3225hqjxdn7kcwpcklcqj5i18w364v8-test-file.txt (152B)12562026/10/08 21:40:05 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"1257 client_integration_test.go:737: Found 1 dependencies (including self)12582026/10/08 21:40:05 WARN Failed to register uploaded object key=y3225hqjxdn7kcwpcklcqj5i18w364v8.ls error="server returned 404: 404 page not found\n"12592026/10/08 21:40:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12602026/10/08 21:40:05 INFO Signed narinfos id=1 count=112612026/10/08 21:40:05 INFO Uploading 1 narinfos1262--- PASS: TestCacheStatsHandler (0.29s)1263=== CONT TestReadProxyConditionalGet12642026/10/08 21:40:05 INFO Received complete push request method=POST path=/api/pushes/1/complete12652026/10/08 21:40:05 WARN Failed to register uploaded object key=y3225hqjxdn7kcwpcklcqj5i18w364v8.narinfo error="server returned 404: 404 page not found\n"12662026/10/08 21:40:05 INFO Completed push id=1 objects=3 duration=7.472287ms12672026/10/08 21:40:05 INFO Upload complete. (88ms)1268--- PASS: TestReadProxyInvalidPath (0.28s)1269=== CONT TestReadProxyContentNegotiation12702026/10/08 21:40:05 INFO All 1 paths already cached1271=== NAME TestClientIntegration1272 client_integration_test.go:360: Retrieved narinfo from S3:1273 StorePath: /build/TestClientIntegration2187512516/002/store/y3225hqjxdn7kcwpcklcqj5i18w364v8-test-file.txt1274 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1275 Compression: zstd1276 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11277 NarSize: 1521278 References: 1279 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11280 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)1281 client_integration_test.go:361: Decompressed .ls content (64 bytes):1282 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}12832026/10/08 21:40:05 INFO Received push request method=POST path=/api/pushes12842026/10/08 21:40:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12852026/10/08 21:40:05 INFO Uploading hxmwwa32pb077zidmj509wmz6s8048ay-test-script (136B)12862026/10/08 21:40:05 WARN Failed to register uploaded object key=log/6kd4jlimw2z86v2dw91pkq79yz6l3bn6-test-script.drv error="server returned 404: 404 page not found\n"12872026/10/08 21:40:05 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"12882026/10/08 21:40:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12892026/10/08 21:40:05 WARN Failed to register uploaded object key=hxmwwa32pb077zidmj509wmz6s8048ay.ls error="server returned 404: 404 page not found\n"12902026/10/08 21:40:05 INFO Signed narinfos id=1 count=112912026/10/08 21:40:05 INFO Uploading 1 narinfos12922026/10/08 21:40:05 INFO Received complete push request method=POST path=/api/pushes/1/complete12932026/10/08 21:40:05 WARN Failed to register uploaded object key=hxmwwa32pb077zidmj509wmz6s8048ay.narinfo error="server returned 404: 404 page not found\n"12942026/10/08 21:40:05 INFO Completed push id=1 objects=4 duration=6.284296ms12952026/10/08 21:40:05 INFO Upload complete. (83ms)12962026/10/08 21:40:05 INFO Aborted multipart uploads count=0 kept=012972026/10/08 21:40:05 WARN Force mode enabled - objects will be deleted immediately without grace period12982026/10/08 21:40:05 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012992026/10/08 21:40:05 INFO Received push request method=POST path=/api/pushes13002026/10/08 21:40:05 INFO Vacuumed table table=pending_closures13012026/10/08 21:40:05 INFO Vacuumed table table=pending_objects13022026/10/08 21:40:05 INFO Vacuumed table table=multipart_uploads13032026/10/08 21:40:05 INFO Object in database but missing from S3 key=y3225hqjxdn7kcwpcklcqj5i18w364v8.ls13042026/10/08 21:40:05 WARN Found objects in DB but missing from S3, will re-upload count=113052026/10/08 21:40:05 INFO Vacuumed table table=closures13062026/10/08 21:40:05 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13072026/10/08 21:40:05 INFO Vacuumed table table=objects1308=== NAME TestClientWithDependencies1309 client_integration_test.go:753: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2825375673/001/store) requires matching store prefix13102026/10/08 21:40:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13112026/10/08 21:40:05 INFO Received complete push request method=POST path=/api/pushes/2/complete13122026/10/08 21:40:05 WARN Failed to register uploaded object key=y3225hqjxdn7kcwpcklcqj5i18w364v8.ls error="server returned 404: 404 page not found\n"13132026/10/08 21:40:05 INFO Completed push id=2 objects=3 duration=2.496263ms13142026/10/08 21:40:05 INFO Upload complete. (56ms)1315=== NAME TestClientIntegration1316 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)1317 client_integration_test.go:389: Decompressed .ls content (49 bytes):1318 {"version":1,"root":{"type":"regular","size":39}}13192026/10/08 21:40:05 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLjdjYzdkN2Q4LWU4MWYtNDU3ZC1hMDIwLTJhNmExYmUxMDQ4MngxNzkxNDk1NjA1MTU3NDE4NDU0 error="Get \"http://127.0.0.1:1/bucket15/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"13202026/10/08 21:40:05 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLmRiNGVmMjQ5LTRjMWMtNDg3Ny1iNGQ3LTAyNjBjZDkyMDdmM3gxNzkxNDk1NjA1MTMzNTU0NTAy parts=121321--- PASS: TestClientWithDependencies (0.60s)1322=== CONT TestClientMultipleUploads13232026/10/08 21:40:05 INFO Received cleanup request method=DELETE path=/api/pending_closures1324--- PASS: TestReadProxyNarStreaming (0.25s)1325=== CONT TestReadProxyNarinfoAlreadyDecompressed13262026/10/08 21:40:05 INFO Aborted multipart uploads count=1 kept=013272026/10/08 21:40:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13282026/10/08 21:40:05 INFO lead: released remote=192.0.2.1:123413292026/10/08 21:40:05 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLmE5YjUwZDRmLTQzMDQtNDNjOS05ZjFmLWY3OTMxZTQ5ZWRhMHgxNzkxNDk1NjA0Nzk4MzgxMDI4 parts=1013302026/10/08 21:40:05 INFO Received complete push request method=POST path=/api/pushes/1/complete1331=== CONT TestService_RequireScope_OIDC1332--- PASS: TestRedundantMultipartUpload (1.70s)13332026/10/08 21:40:05 INFO Completed push id=1 objects=4 duration=7.354426ms1334--- PASS: TestReadRedirectUsesPublicS3URL (0.40s)1335=== CONT TestDeleteClosuresRacingPins1336--- PASS: TestReadRedirectKeepsNarinfoProxied (0.33s)1337=== CONT TestObjectStatsTrigger13382026/10/08 21:40:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1339--- PASS: TestPush_RepeatedRootCommitsOnce (1.72s)1340=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT1341=== NAME TestPinProtectsFromGC1342 client_integration_test.go:867: Pinned store path: /build/TestPinProtectsFromGC3413165290/001/store/nmllifxn781jwdqsknrjkmx0mmxjgsb9-pinned-file.txt1343 client_integration_test.go:868: Unpinned store path: /build/TestPinProtectsFromGC3413165290/001/store/7ih0wz6wjym0n7r2wxkwxan4byxiw6s0-unpinned-file.txt13442026/10/08 21:40:05 INFO Received push request method=POST path=/api/pushes13452026/10/08 21:40:05 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLjM1MDliMTRjLTdiM2UtNDA2Zi1hZDg3LWVlZjgyYWU1Njg5ZngxNzkxNDk1NjA0ODI1MjI1NTA2 parts=1013462026/10/08 21:40:05 INFO Received complete push request method=POST path=/api/pushes/1/complete13472026/10/08 21:40:05 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13482026/10/08 21:40:05 INFO lead: acquired remote=192.0.2.1:123413492026/10/08 21:40:05 INFO Completed push id=1 objects=4 duration=7.464946ms13502026/10/08 21:40:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13512026/10/08 21:40:05 INFO Received push request method=POST path=/api/pushes13522026/10/08 21:40:05 INFO Received complete push request method=POST path=/api/pushes/3/complete13532026/10/08 21:40:05 WARN Failed to register uploaded object key=y3225hqjxdn7kcwpcklcqj5i18w364v8.ls error="server returned 404: 404 page not found\n"13542026/10/08 21:40:05 INFO Completed push id=3 objects=3 duration=2.430881ms13552026/10/08 21:40:05 INFO Upload complete. (60ms)1356=== NAME TestClientIntegration1357 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)1358 client_integration_test.go:405: Decompressed .ls content (49 bytes):1359 {"version":1,"root":{"type":"regular","size":39}}13602026/10/08 21:40:05 INFO Received uploads request method=POST path=/api/pending_closures13612026/10/08 21:40:05 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo1362=== NAME TestOrphanedObjectsGC1363 orphaned_objects_gc_test.go:287: GC Test Summary:1364 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1365 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1366 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1367 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1368 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects13692026/10/08 21:40:05 INFO Received uploads request method=POST path=/api/pending_closures13702026/10/08 21:40:05 INFO Received push request method=POST path=/api/pushes1371=== CONT TestCacheConfigHandler1372--- PASS: TestReadProxyConditionalGet (0.29s)1373=== RUN TestCacheConfigHandler/full_config,_no_issuer1374=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1375=== RUN TestCacheConfigHandler/no_cache_url_configured1376=== PAUSE TestCacheConfigHandler/no_cache_url_configured1377=== RUN TestCacheConfigHandler/no_signing_keys1378=== PAUSE TestCacheConfigHandler/no_signing_keys1379=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1380=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1381=== CONT TestReadProxyNarinfo13822026/10/08 21:40:05 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo13832026/10/08 21:40:05 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLjcwMmUzZDU0LTAxMjMtNDQyZS04ZGExLTc2YzFkYjdjNDdkN3gxNzkxNDk1NjA1MzQ0MjM2OTEx parts=1013842026/10/08 21:40:05 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13852026/10/08 21:40:05 INFO Uploading yhsxyfirybkxy0gymzh011ipy77r35qh-shared-dep (136B)13862026/10/08 21:40:05 INFO Uploading n4yy6dw93zj9s93fsdndn7vins4yvahc-a (216B)1387--- PASS: TestOrphanedObjectsGC (0.64s)1388=== CONT TestService_AuthMiddleware_OIDC13892026/10/08 21:40:05 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13902026/10/08 21:40:05 INFO Uploading yqv48c7n6fvk4ik2m37kf39p0q0mjwd7-shared-dep (136B)13912026/10/08 21:40:05 INFO Uploading zkmgxvrmf1gkihjv7z4v96l8dn2mgg1j-b (216B)13922026/10/08 21:40:05 WARN Failed to register uploaded object key=8f13jshs2d1frkglkanq9fd8sz00m0l7.ls error="server returned 404: 404 page not found\n"13932026/10/08 21:40:05 WARN Failed to register uploaded object key=nar/0zl1hp5ily1xp950asj3fj6f6vyjfs4yzz8nrsg5j1qnrm6gr5r0.nar.zst error="server returned 404: 404 page not found\n"13942026/10/08 21:40:05 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13952026/10/08 21:40:05 WARN Failed to register uploaded object key=75x0zg91rkzxnxd1b4fivlak0yc2q5xs.ls error="server returned 404: 404 page not found\n"13962026/10/08 21:40:05 WARN Failed to register uploaded object key=n4yy6dw93zj9s93fsdndn7vins4yvahc.ls error="server returned 404: 404 page not found\n"13972026/10/08 21:40:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13982026/10/08 21:40:05 WARN Failed to register uploaded object key=yhsxyfirybkxy0gymzh011ipy77r35qh.ls error="server returned 404: 404 page not found\n"13992026/10/08 21:40:05 WARN Failed to register uploaded object key=nar/04rf31d22cr20yrlzyapkzk5q872qpv0886dy55bgvwwn4f1j93x.nar.zst error="server returned 404: 404 page not found\n"14002026/10/08 21:40:05 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14012026/10/08 21:40:05 INFO Signed narinfos id=1 count=214022026/10/08 21:40:05 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14032026/10/08 21:40:05 INFO Signed narinfos id=2 count=214042026/10/08 21:40:05 WARN Failed to register uploaded object key=yqv48c7n6fvk4ik2m37kf39p0q0mjwd7.ls error="server returned 404: 404 page not found\n"14052026/10/08 21:40:05 INFO Uploading 4 narinfos14062026/10/08 21:40:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1407--- PASS: TestConcurrentPinUpdatesAgree (0.83s)14082026/10/08 21:40:05 WARN Failed to register uploaded object key=zkmgxvrmf1gkihjv7z4v96l8dn2mgg1j.ls error="server returned 404: 404 page not found\n"1409=== CONT TestPendingClosureWriteTimeout1410=== RUN TestPendingClosureWriteTimeout/empty1411=== PAUSE TestPendingClosureWriteTimeout/empty1412=== RUN TestPendingClosureWriteTimeout/400_objects1413=== PAUSE TestPendingClosureWriteTimeout/400_objects1414=== RUN TestPendingClosureWriteTimeout/670k_objects1415=== PAUSE TestPendingClosureWriteTimeout/670k_objects1416=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1417=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1418=== CONT TestClientErrorHandling1419=== RUN TestClientErrorHandling/InvalidStorePath1420=== PAUSE TestClientErrorHandling/InvalidStorePath1421=== RUN TestClientErrorHandling/InvalidAuthToken1422=== PAUSE TestClientErrorHandling/InvalidAuthToken1423=== RUN TestClientErrorHandling/ServerNotAvailable1424=== PAUSE TestClientErrorHandling/ServerNotAvailable1425=== CONT TestIsValidCachePath1426=== RUN TestIsValidCachePath/narinfo14272026/10/08 21:40:05 INFO Signed narinfos id=1 count=31428=== PAUSE TestIsValidCachePath/narinfo1429=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1430=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1431=== RUN TestIsValidCachePath/nar_zst1432=== PAUSE TestIsValidCachePath/nar_zst1433=== RUN TestIsValidCachePath/nar_xz1434=== PAUSE TestIsValidCachePath/nar_xz1435=== RUN TestIsValidCachePath/nar_bz21436=== PAUSE TestIsValidCachePath/nar_bz21437=== RUN TestIsValidCachePath/nar_uncompressed14382026/10/08 21:40:05 INFO Uploading 3 narinfos1439=== PAUSE TestIsValidCachePath/nar_uncompressed1440=== RUN TestIsValidCachePath/ls1441=== PAUSE TestIsValidCachePath/ls1442=== RUN TestIsValidCachePath/log1443=== PAUSE TestIsValidCachePath/log1444=== RUN TestIsValidCachePath/realisation1445=== PAUSE TestIsValidCachePath/realisation1446=== RUN TestIsValidCachePath/nix-cache-info1447=== PAUSE TestIsValidCachePath/nix-cache-info1448=== RUN TestIsValidCachePath/index.html1449=== PAUSE TestIsValidCachePath/index.html1450=== RUN TestIsValidCachePath/traversal_parent1451=== PAUSE TestIsValidCachePath/traversal_parent1452=== RUN TestIsValidCachePath/traversal_in_middle1453=== PAUSE TestIsValidCachePath/traversal_in_middle1454=== RUN TestIsValidCachePath/invalid_char_e1455=== PAUSE TestIsValidCachePath/invalid_char_e1456=== RUN TestIsValidCachePath/invalid_char_u1457=== PAUSE TestIsValidCachePath/invalid_char_u1458=== RUN TestIsValidCachePath/random_path1459=== PAUSE TestIsValidCachePath/random_path1460=== RUN TestIsValidCachePath/empty1461=== PAUSE TestIsValidCachePath/empty1462=== RUN TestIsValidCachePath/leading_slash1463=== PAUSE TestIsValidCachePath/leading_slash1464=== RUN TestIsValidCachePath/wrong_extension1465=== PAUSE TestIsValidCachePath/wrong_extension1466=== RUN TestIsValidCachePath/short_hash1467=== PAUSE TestIsValidCachePath/short_hash1468=== CONT TestReadProxyRootRedirectsToIndexHTML14692026/10/08 21:40:05 INFO Received push request method=POST path=/api/pushes14702026/10/08 21:40:05 WARN Failed to register uploaded object key=yhsxyfirybkxy0gymzh011ipy77r35qh.narinfo error="server returned 404: 404 page not found\n"14712026/10/08 21:40:05 WARN Failed to register uploaded object key=8f13jshs2d1frkglkanq9fd8sz00m0l7.narinfo error="server returned 404: 404 page not found\n"14722026/10/08 21:40:05 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14732026/10/08 21:40:05 WARN Failed to register uploaded object key=n4yy6dw93zj9s93fsdndn7vins4yvahc.narinfo error="server returned 404: 404 page not found\n"14742026/10/08 21:40:05 WARN Failed to register uploaded object key=yhsxyfirybkxy0gymzh011ipy77r35qh.narinfo error="server returned 404: 404 page not found\n"14752026/10/08 21:40:05 WARN Failed to register uploaded object key=75x0zg91rkzxnxd1b4fivlak0yc2q5xs.narinfo error="server returned 404: 404 page not found\n"14762026/10/08 21:40:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14772026/10/08 21:40:05 INFO Uploading nmllifxn781jwdqsknrjkmx0mmxjgsb9-pinned-file.txt (128B)14782026/10/08 21:40:05 INFO Received complete push request method=POST path=/api/pushes/1/complete14792026/10/08 21:40:05 WARN Failed to register uploaded object key=yqv48c7n6fvk4ik2m37kf39p0q0mjwd7.narinfo error="server returned 404: 404 page not found\n"14802026/10/08 21:40:05 WARN Failed to register uploaded object key=zkmgxvrmf1gkihjv7z4v96l8dn2mgg1j.narinfo error="server returned 404: 404 page not found\n"14812026/10/08 21:40:05 INFO Completed upload id=2 objects=6 duration=6.503298ms14822026/10/08 21:40:05 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14832026/10/08 21:40:05 INFO Completed push id=1 objects=8 duration=6.358977ms14842026/10/08 21:40:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14852026/10/08 21:40:05 INFO Upload complete. (91ms)14862026/10/08 21:40:05 INFO Completed upload id=1 objects=6 duration=3.496371ms14872026/10/08 21:40:05 INFO Upload complete. (111ms)14882026/10/08 21:40:05 INFO Aborted multipart uploads count=0 kept=01489=== NAME TestClientPushesUseOnePush1490 client_pushes_test.go:97: Retrieved narinfo from S3:1491 StorePath: /build/TestClientPushesUseOnePush4149985621/001/store/yqv48c7n6fvk4ik2m37kf39p0q0mjwd7-shared-dep1492 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1493 Compression: zstd1494 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821495 NarSize: 1361496 References: 1497 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n14982026/10/08 21:40:05 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14992026/10/08 21:40:05 WARN Failed to register uploaded object key=nmllifxn781jwdqsknrjkmx0mmxjgsb9.ls error="server returned 404: 404 page not found\n"1500=== NAME TestClientFallsBackToClosures15012026/10/08 21:40:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1502 client_pushes_test.go:112: Retrieved narinfo from S3:1503 StorePath: /build/TestClientFallsBackToClosures3544748110/001/store/yhsxyfirybkxy0gymzh011ipy77r35qh-shared-dep1504 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1505 Compression: zstd1506 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821507 NarSize: 1361508 References: 1509 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n15102026/10/08 21:40:05 INFO Signed narinfos id=1 count=115112026/10/08 21:40:05 INFO Uploading 1 narinfos1512=== NAME TestClientPushesUseOnePush1513 client_pushes_test.go:97: Retrieved narinfo from S3:1514 StorePath: /build/TestClientPushesUseOnePush4149985621/001/store/75x0zg91rkzxnxd1b4fivlak0yc2q5xs-a1515 URL: nar/04rf31d22cr20yrlzyapkzk5q872qpv0886dy55bgvwwn4f1j93x.nar.zst1516 Compression: zstd1517 NarHash: sha256:04rf31d22cr20yrlzyapkzk5q872qpv0886dy55bgvwwn4f1j93x1518 NarSize: 2161519 References: /build/TestClientPushesUseOnePush4149985621/001/store/yqv48c7n6fvk4ik2m37kf39p0q0mjwd7-shared-dep1520 CA: text:sha256:0n7mkngb9l1687ikka67w51igm5vx7pjr4xhzqpfr98w2lwhiam215212026/10/08 21:40:05 WARN Force mode enabled - objects will be deleted immediately without grace period1522=== NAME TestClientFallsBackToClosures1523 client_pushes_test.go:112: Retrieved narinfo from S3:1524 StorePath: /build/TestClientFallsBackToClosures3544748110/001/store/n4yy6dw93zj9s93fsdndn7vins4yvahc-a1525 URL: nar/0zl1hp5ily1xp950asj3fj6f6vyjfs4yzz8nrsg5j1qnrm6gr5r0.nar.zst1526 Compression: zstd1527 NarHash: sha256:0zl1hp5ily1xp950asj3fj6f6vyjfs4yzz8nrsg5j1qnrm6gr5r01528 NarSize: 2161529 References: /build/TestClientFallsBackToClosures3544748110/001/store/yhsxyfirybkxy0gymzh011ipy77r35qh-shared-dep1530 CA: text:sha256:1kvp8rpiam0g48lscbvb5bl2z5xzddwrmn85yqpvf2gj44mqzfcw15312026/10/08 21:40:05 INFO Received complete push request method=POST path=/api/pushes/1/complete15322026/10/08 21:40:05 WARN Failed to register uploaded object key=nmllifxn781jwdqsknrjkmx0mmxjgsb9.narinfo error="server returned 404: 404 page not found\n"15332026/10/08 21:40:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39129/oidc1534=== NAME TestClientPushesUseOnePush1535 client_pushes_test.go:97: Retrieved narinfo from S3:1536 StorePath: /build/TestClientPushesUseOnePush4149985621/001/store/zkmgxvrmf1gkihjv7z4v96l8dn2mgg1j-b1537 URL: nar/04rf31d22cr20yrlzyapkzk5q872qpv0886dy55bgvwwn4f1j93x.nar.zst1538 Compression: zstd1539 NarHash: sha256:04rf31d22cr20yrlzyapkzk5q872qpv0886dy55bgvwwn4f1j93x1540 NarSize: 2161541 References: /build/TestClientPushesUseOnePush4149985621/001/store/yqv48c7n6fvk4ik2m37kf39p0q0mjwd7-shared-dep1542 CA: text:sha256:0n7mkngb9l1687ikka67w51igm5vx7pjr4xhzqpfr98w2lwhiam21543=== NAME TestClientFallsBackToClosures1544 client_pushes_test.go:112: Retrieved narinfo from S3:1545 StorePath: /build/TestClientFallsBackToClosures3544748110/001/store/8f13jshs2d1frkglkanq9fd8sz00m0l7-b1546 URL: nar/0zl1hp5ily1xp950asj3fj6f6vyjfs4yzz8nrsg5j1qnrm6gr5r0.nar.zst1547 Compression: zstd1548 NarHash: sha256:0zl1hp5ily1xp950asj3fj6f6vyjfs4yzz8nrsg5j1qnrm6gr5r01549 NarSize: 2161550 References: /build/TestClientFallsBackToClosures3544748110/001/store/yhsxyfirybkxy0gymzh011ipy77r35qh-shared-dep1551 CA: text:sha256:1kvp8rpiam0g48lscbvb5bl2z5xzddwrmn85yqpvf2gj44mqzfcw15522026/10/08 21:40:05 INFO Completed push id=1 objects=3 duration=6.230415ms15532026/10/08 21:40:05 INFO Upload complete. (85ms)15542026/10/08 21:40:05 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLjc0OTNlOTk3LTMzMDctNDBjMC05NmExLTA1MGM4NTcyN2M0ZngxNzkxNDk1NjA1NDQyNzczNjI1 parts=1015552026/10/08 21:40:05 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=015562026/10/08 21:40:05 INFO Vacuumed table table=pending_closures15572026/10/08 21:40:05 INFO Vacuumed table table=pending_objects15582026/10/08 21:40:05 INFO Vacuumed table table=multipart_uploads15592026/10/08 21:40:05 INFO Received push request method=POST path=/api/pushes15602026/10/08 21:40:05 INFO Vacuumed table table=closures15612026/10/08 21:40:05 INFO Vacuumed table table=objects15622026/10/08 21:40:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15632026/10/08 21:40:06 INFO Uploading aqxwphd683cmalq3j4rm0wpmyq6vj1ww-lost-commit.txt (152B)15642026/10/08 21:40:06 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"1565=== NAME TestClientMultipleUploads1566 client_integration_test.go:480: Created store path 0: /build/TestClientMultipleUploads110020385/001/store/gl5mn4c6xy55v8p8dbgn7vafp9qpqfjv-test-file-0.txt1567=== CONT TestSkippedUploadsHandler1568--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.23s)15692026/10/08 21:40:06 WARN Failed to register uploaded object key=aqxwphd683cmalq3j4rm0wpmyq6vj1ww.ls error="server returned 404: 404 page not found\n"15702026/10/08 21:40:06 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign15712026/10/08 21:40:06 INFO Signed narinfos id=4 count=115722026/10/08 21:40:06 INFO Uploading 1 narinfos15732026/10/08 21:40:06 INFO Client skipped oversized paths paths=3 nar_bytes=500000000015742026/10/08 21:40:06 INFO Received complete push request method=POST path=/api/pushes/4/complete15752026/10/08 21:40:06 WARN Failed to register uploaded object key=aqxwphd683cmalq3j4rm0wpmyq6vj1ww.narinfo error="server returned 404: 404 page not found\n"15762026/10/08 21:40:06 INFO Completed push id=4 objects=3 duration=3.285469ms15772026/10/08 21:40:06 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:46175/api/pushes/4/complete\": EOF" url=http://127.0.0.1:46175/api/pushes/4/complete1578--- PASS: TestClientPushesUseOnePush (0.55s)1579=== CONT TestReadProxyHead1580--- PASS: TestClientFallsBackToClosures (0.60s)1581=== CONT TestClientSharedPathCommittedMidPush15822026/10/08 21:40:06 INFO Received push request method=POST path=/api/pushes1583=== NAME TestClientMultipleUploads1584 client_integration_test.go:480: Created store path 1: /build/TestClientMultipleUploads110020385/001/store/ywzs36c8yf6kmy453k7vwnc777z6413n-test-file-1.txt1585--- PASS: TestSkippedUploadsHandler (0.04s)1586=== CONT TestClientCADerivations15872026/10/08 21:40:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15882026/10/08 21:40:06 INFO Uploading 7ih0wz6wjym0n7r2wxkwxan4byxiw6s0-unpinned-file.txt (128B)15892026/10/08 21:40:06 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15902026/10/08 21:40:06 WARN Failed to register uploaded object key=7ih0wz6wjym0n7r2wxkwxan4byxiw6s0.ls error="server returned 404: 404 page not found\n"15912026/10/08 21:40:06 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15922026/10/08 21:40:06 INFO Signed narinfos id=2 count=115932026/10/08 21:40:06 INFO Uploading 1 narinfos15942026/10/08 21:40:06 INFO Received complete push request method=POST path=/api/pushes/2/complete15952026/10/08 21:40:06 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34581/oidc15962026/10/08 21:40:06 WARN Failed to register uploaded object key=7ih0wz6wjym0n7r2wxkwxan4byxiw6s0.narinfo error="server returned 404: 404 page not found\n"15972026/10/08 21:40:06 INFO Completed push id=2 objects=3 duration=2.477602ms1598=== NAME TestClientMultipleUploads1599 client_integration_test.go:480: Created store path 2: /build/TestClientMultipleUploads110020385/001/store/wzwz77kf03q9k266z6p4b1jvpn88c7c8-test-file-2.txt16002026/10/08 21:40:06 INFO Upload complete. (81ms)1601=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1602--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.02s)16032026/10/08 21:40:06 INFO Received uploads request method=POST path=/api/pending_closures1604--- PASS: TestConnectSerialisesConcurrentMigrations (1.12s)1605=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1606--- PASS: TestObjectStatsTrigger (0.27s)1607=== CONT TestUploadHandlersRejectInvalidKeys1608=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1609=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1610=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1611=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1612=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1613=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1614=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1615=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1616=== CONT TestReadProxyRangeRequest16172026/10/08 21:40:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures1618=== CONT TestIsValidUploadKey1619--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.28s)1620=== RUN TestIsValidUploadKey/narinfo1621=== PAUSE TestIsValidUploadKey/narinfo1622=== RUN TestIsValidUploadKey/nar_zst1623=== PAUSE TestIsValidUploadKey/nar_zst1624=== RUN TestIsValidUploadKey/nar_xz1625=== PAUSE TestIsValidUploadKey/nar_xz1626=== RUN TestIsValidUploadKey/nar_plain1627=== PAUSE TestIsValidUploadKey/nar_plain16282026/10/08 21:40:06 INFO Garbage collection started1629=== RUN TestIsValidUploadKey/listing1630=== PAUSE TestIsValidUploadKey/listing1631=== RUN TestIsValidUploadKey/build_log1632=== PAUSE TestIsValidUploadKey/build_log1633=== RUN TestIsValidUploadKey/build_log_home-manager_file1634=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1635=== RUN TestIsValidUploadKey/build_log_plus_in_name1636=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1637=== RUN TestIsValidUploadKey/build_log_question_mark1638=== PAUSE TestIsValidUploadKey/build_log_question_mark1639=== RUN TestIsValidUploadKey/build_log_equals1640=== PAUSE TestIsValidUploadKey/build_log_equals1641=== RUN TestIsValidUploadKey/realisation1642=== PAUSE TestIsValidUploadKey/realisation1643=== RUN TestIsValidUploadKey/realisation_plus_in_output1644=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1645=== RUN TestIsValidUploadKey/nix-cache-info1646=== PAUSE TestIsValidUploadKey/nix-cache-info1647=== RUN TestIsValidUploadKey/index.html1648=== PAUSE TestIsValidUploadKey/index.html1649=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1650=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1651=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1652=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1653=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1654=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1655=== RUN TestIsValidUploadKey/traversal1656=== PAUSE TestIsValidUploadKey/traversal1657=== RUN TestIsValidUploadKey/traversal_nar1658=== PAUSE TestIsValidUploadKey/traversal_nar1659=== RUN TestIsValidUploadKey/absolute1660=== PAUSE TestIsValidUploadKey/absolute1661=== RUN TestIsValidUploadKey/empty_key1662=== PAUSE TestIsValidUploadKey/empty_key1663=== RUN TestIsValidUploadKey/unknown_type1664=== PAUSE TestIsValidUploadKey/unknown_type1665=== CONT TestGCEndsOnShutdown1666=== RUN TestGCEndsOnShutdown/before_the_run1667=== PAUSE TestGCEndsOnShutdown/before_the_run1668=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1669=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1670=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1671=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1672=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle16732026/10/08 21:40:06 INFO Received complete push request method=POST path=/api/pushes/4/complete16742026-10-08 21:40:06.142 UTC [772] ERROR: Push does not exist: id=416752026-10-08 21:40:06.142 UTC [772] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE16762026-10-08 21:40:06.142 UTC [772] STATEMENT: -- name: CommitPush :one1677 SELECT commit_push($1::bigint)::bigint1678 16792026/10/08 21:40:06 WARN Push not found id=416802026/10/08 21:40:06 INFO Upload complete. (185ms)1681=== NAME TestClientIntegration1682 client_integration_test.go:435: Retrieved narinfo from S3:1683 StorePath: /build/TestClientIntegration2187512516/002/store/aqxwphd683cmalq3j4rm0wpmyq6vj1ww-lost-commit.txt1684 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1685 Compression: zstd1686 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1687 NarSize: 1521688 References: 1689 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl16902026/10/08 21:40:06 INFO Aborted multipart uploads count=0 kept=01691 client_integration_test.go:438: Testing garbage collection...16922026/10/08 21:40:06 WARN Force mode enabled - objects will be deleted immediately without grace period16932026/10/08 21:40:06 INFO Received push request method=POST path=/api/pushes1694--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.24s)1695=== CONT TestService_AuthMiddleware16962026/10/08 21:40:06 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16972026/10/08 21:40:06 INFO Uploading gl5mn4c6xy55v8p8dbgn7vafp9qpqfjv-test-file-0.txt (160B)16982026/10/08 21:40:06 INFO Uploading ywzs36c8yf6kmy453k7vwnc777z6413n-test-file-1.txt (160B)16992026/10/08 21:40:06 INFO Uploading wzwz77kf03q9k266z6p4b1jvpn88c7c8-test-file-2.txt (160B)17002026/10/08 21:40:06 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=017012026/10/08 21:40:06 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"17022026/10/08 21:40:06 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"17032026/10/08 21:40:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures17042026/10/08 21:40:06 INFO Vacuumed table table=pending_closures17052026/10/08 21:40:06 WARN Failed to register uploaded object key=gl5mn4c6xy55v8p8dbgn7vafp9qpqfjv.ls error="server returned 404: 404 page not found\n"17062026/10/08 21:40:06 INFO Garbage collection started17072026/10/08 21:40:06 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"17082026/10/08 21:40:06 INFO Vacuumed table table=pending_objects17092026/10/08 21:40:06 INFO Vacuumed table table=multipart_uploads17102026/10/08 21:40:06 WARN Failed to register uploaded object key=ywzs36c8yf6kmy453k7vwnc777z6413n.ls error="server returned 404: 404 page not found\n"17112026/10/08 21:40:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17122026/10/08 21:40:06 WARN Failed to register uploaded object key=wzwz77kf03q9k266z6p4b1jvpn88c7c8.ls error="server returned 404: 404 page not found\n"17132026/10/08 21:40:06 INFO Signed narinfos id=1 count=317142026/10/08 21:40:06 INFO Vacuumed table table=closures17152026/10/08 21:40:06 INFO Uploading 3 narinfos17162026/10/08 21:40:06 INFO Vacuumed table table=objects17172026/10/08 21:40:06 INFO Aborted multipart uploads count=0 kept=017182026/10/08 21:40:06 WARN Failed to register uploaded object key=gl5mn4c6xy55v8p8dbgn7vafp9qpqfjv.narinfo error="server returned 404: 404 page not found\n"1719=== RUN TestService_RequireScope_OIDC/builder_may_write1720=== PAUSE TestService_RequireScope_OIDC/builder_may_write1721=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1722=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1723=== RUN TestService_RequireScope_OIDC/ops_may_admin1724=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1725=== RUN TestService_RequireScope_OIDC/ops_may_not_write1726=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1727=== RUN TestService_RequireScope_OIDC/reader_may_not_write1728=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1729=== RUN TestService_RequireScope_OIDC/static_token_may_admin1730=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1731=== RUN TestService_RequireScope_OIDC/static_token_may_write1732=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1733=== RUN TestService_RequireScope_OIDC/reader_may_read1734=== PAUSE TestService_RequireScope_OIDC/reader_may_read1735=== RUN TestService_RequireScope_OIDC/writer_implies_read1736=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1737=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1738=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1739=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1740=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1741=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1742=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1743=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1744=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1745=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1746=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1747=== CONT TestGCTaskStore_DeduplicateSameParams1748--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1749=== CONT TestGetExistingObjectsLocksRows17502026/10/08 21:40:06 WARN Failed to register uploaded object key=wzwz77kf03q9k266z6p4b1jvpn88c7c8.narinfo error="server returned 404: 404 page not found\n"17512026/10/08 21:40:06 INFO Received complete push request method=POST path=/api/pushes/1/complete17522026/10/08 21:40:06 WARN Failed to register uploaded object key=ywzs36c8yf6kmy453k7vwnc777z6413n.narinfo error="server returned 404: 404 page not found\n"17532026/10/08 21:40:06 WARN Force mode enabled - objects will be deleted immediately without grace period17542026/10/08 21:40:06 INFO Completed push id=1 objects=9 duration=7.774789ms17552026/10/08 21:40:06 INFO Upload complete. (99ms)1756=== NAME TestClientMultipleUploads1757 client_integration_test.go:491: Uploaded 3 paths in 130.397916ms17582026/10/08 21:40:06 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=2 objects-marked-for-deletion=6 objects-deleted-after-grace-period=6 objects-failed-to-delete=017592026/10/08 21:40:06 INFO Vacuumed table table=pending_closures17602026/10/08 21:40:06 INFO Vacuumed table table=pending_objects17612026/10/08 21:40:06 INFO Vacuumed table table=multipart_uploads17622026/10/08 21:40:06 INFO Vacuumed table table=closures17632026/10/08 21:40:06 INFO Vacuumed table table=objects1764--- PASS: TestClientMultipleUploads (0.48s)1765=== CONT TestMultipartCleanup1766--- PASS: TestReadProxyContentNegotiation (0.66s)1767=== CONT TestPendingCleanupUsesOneCutoff17682026/10/08 21:40:06 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17692026/10/08 21:40:06 WARN mTLS auth: bound subjects configured but subject DN unavailable17702026/10/08 21:40:06 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1771=== NAME TestClientCADerivations1772 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1235149216/001/store/6mbv3v5jwx0y0idzazd5bx7gqjipx6vg-ca-test1773=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1774=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1775=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1776=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1777=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1778=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1779=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1780=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1781=== CONT TestCommitRacingPendingCleanupKeepsObjects1782=== CONT TestGCSweepDeliversEachKeyOnce1783--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.25s)17842026/10/08 21:40:06 INFO Received uploads request method=POST path=/api/pending_closures1785=== NAME TestClientCADerivations1786 client_ca_test.go:139: Found 1 dependencies (including self)17872026/10/08 21:40:06 INFO Received uploads request method=POST path=/api/pending_closures1788--- PASS: TestReadProxyHead (0.38s)1789=== CONT TestPushWaitsForSweepHoldingRow17902026/10/08 21:40:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17912026/10/08 21:40:06 INFO Received push request method=POST path=/api/pushes17922026/10/08 21:40:06 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"17932026/10/08 21:40:06 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)17942026/10/08 21:40:06 INFO Uploading 1vv7w0hjn8bnp2b5mi69ip72746vjf3z-shared-dep (136B)17952026/10/08 21:40:06 INFO Uploading yix2kgycfj765wb1yjfsy91kf6yk504i-top (224B)17962026/10/08 21:40:06 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLmU2MWFiYjY1LTY4Y2QtNDI1NS04YTBiLWMzZTI4ZGIxN2E3YXgxNzkxNDk1NjA1MzQ0MzE2OTcx parts=101797=== CONT TestPendingClosureFailureAbortsItsUploads1798--- PASS: TestReadProxyRangeRequest (0.34s)17992026/10/08 21:40:06 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18002026/10/08 21:40:06 WARN Failed to register uploaded object key=nar/0s1d1yk00ah6iw7b54b8ijp9k1r6vr5myyqby11z7pvkx0aqx0ng.nar.zst error="server returned 404: 404 page not found\n"1801--- PASS: TestService_AuthMiddleware (0.28s)1802=== CONT TestDeduplicatedObjectsRecordedAsPending18032026/10/08 21:40:06 WARN Failed to register uploaded object key=1vv7w0hjn8bnp2b5mi69ip72746vjf3z.ls error="server returned 404: 404 page not found\n"18042026/10/08 21:40:06 WARN Failed to register uploaded object key=yix2kgycfj765wb1yjfsy91kf6yk504i.ls error="server returned 404: 404 page not found\n"18052026/10/08 21:40:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18062026/10/08 21:40:06 INFO Signed narinfos id=1 count=218072026/10/08 21:40:06 INFO Uploading 2 narinfos18082026/10/08 21:40:06 INFO Received complete push request method=POST path=/api/pushes/1/complete18092026/10/08 21:40:06 WARN Failed to register uploaded object key=yix2kgycfj765wb1yjfsy91kf6yk504i.narinfo error="server returned 404: 404 page not found\n"18102026/10/08 21:40:06 WARN Failed to register uploaded object key=1vv7w0hjn8bnp2b5mi69ip72746vjf3z.narinfo error="server returned 404: 404 page not found\n"18112026/10/08 21:40:06 INFO Received push request method=POST path=/api/pushes18122026/10/08 21:40:06 INFO Completed push id=1 objects=6 duration=6.992682ms18132026/10/08 21:40:06 INFO Upload complete. (93ms)1814=== NAME TestClientSharedPathCommittedMidPush1815 client_integration_test.go:816: Retrieved narinfo from S3:1816 StorePath: /build/TestClientSharedPathCommittedMidPush2788257218/001/store/1vv7w0hjn8bnp2b5mi69ip72746vjf3z-shared-dep1817 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1818 Compression: zstd1819 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821820 NarSize: 1361821 References: 1822 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n18232026/10/08 21:40:06 INFO Received uploads request method=POST path=/api/pending_closures18242026/10/08 21:40:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18252026/10/08 21:40:06 INFO Uploading 6mbv3v5jwx0y0idzazd5bx7gqjipx6vg-ca-test (144B)18262026/10/08 21:40:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1827 client_integration_test.go:816: Retrieved narinfo from S3:1828 StorePath: /build/TestClientSharedPathCommittedMidPush2788257218/001/store/yix2kgycfj765wb1yjfsy91kf6yk504i-top1829 URL: nar/0s1d1yk00ah6iw7b54b8ijp9k1r6vr5myyqby11z7pvkx0aqx0ng.nar.zst1830 Compression: zstd1831 NarHash: sha256:0s1d1yk00ah6iw7b54b8ijp9k1r6vr5myyqby11z7pvkx0aqx0ng1832 NarSize: 2241833 References: /build/TestClientSharedPathCommittedMidPush2788257218/001/store/1vv7w0hjn8bnp2b5mi69ip72746vjf3z-shared-dep1834 CA: text:sha256:1kls434pxhbfzzlymbj1ziw1hl09ig6z1idhvpx0a6d8v6913xjc18352026/10/08 21:40:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18362026/10/08 21:40:06 WARN Failed to register uploaded object key=log/krr461k53jq8naq24ahicsm2xnishl5s-ca-test.drv error="server returned 404: 404 page not found\n"18372026/10/08 21:40:06 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"1838--- PASS: TestGetExistingObjectsLocksRows (0.30s)1839=== CONT TestMetricsCommit18402026/10/08 21:40:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18412026/10/08 21:40:06 WARN Failed to register uploaded object key=6mbv3v5jwx0y0idzazd5bx7gqjipx6vg.ls error="server returned 404: 404 page not found\n"18422026/10/08 21:40:06 INFO Signed narinfos id=1 count=118432026/10/08 21:40:06 INFO Uploading 1 narinfos18442026/10/08 21:40:06 INFO Received uploads request method=POST path=/api/pending_closures18452026/10/08 21:40:06 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLjQ1OGUyY2ZkLTNjMjgtNDg0Yi1iMTY4LWNmZGFkOWNlNWI1NHgxNzkxNDk1NjA1NDQzMDM2ODI3 parts=1018462026/10/08 21:40:06 INFO Received complete push request method=POST path=/api/pushes/1/complete18472026/10/08 21:40:06 WARN Failed to register uploaded object key=6mbv3v5jwx0y0idzazd5bx7gqjipx6vg.narinfo error="server returned 404: 404 page not found\n"18482026/10/08 21:40:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1849=== CONT TestGCBugBareHashReferences1850--- PASS: TestClientSharedPathCommittedMidPush (0.48s)18512026/10/08 21:40:06 INFO Completed push id=1 objects=4 duration=7.291525ms18522026/10/08 21:40:06 INFO Upload complete. (114ms)18532026/10/08 21:40:06 INFO Received uploads request method=POST path=/api/pending_closures1854=== NAME TestClientCADerivations1855 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1235149216/001/store/6mbv3v5jwx0y0idzazd5bx7gqjipx6vg-ca-test1856 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1857 Compression: zstd1858 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1859 NarSize: 1441860 References: 1861 Deriver: /build/TestClientCADerivations1235149216/001/store/krr461k53jq8naq24ahicsm2xnishl5s-ca-test.drv1862 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1863 client_ca_test.go:185: Checking for realisation files in S3...1864 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1865 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache18662026/10/08 21:40:06 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLmJhNWFjNmY2LWQ0OWUtNGQ3ZS05Yjg0LTM1Y2I3YWRkZWRlOHgxNzkxNDk1NjA1ODg1ODU2ODk2 parts=1018672026/10/08 21:40:06 INFO Received complete push request method=POST path=/api/pushes/2/complete18682026/10/08 21:40:06 INFO Completed push id=2 objects=4 duration=3.758213ms18692026/10/08 21:40:06 INFO Received cleanup request method=DELETE path=/api/pending_closures1870--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.44s)1871=== CONT TestCacheConfigHandlerMaxNarSize1872--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1873=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded18742026/10/08 21:40:06 INFO Aborted multipart uploads count=0 kept=018752026/10/08 21:40:06 INFO Aborted multipart uploads count=0 kept=018762026/10/08 21:40:06 WARN Force mode enabled - objects will be deleted immediately without grace period18772026/10/08 21:40:06 WARN Force mode enabled - objects will be deleted immediately without grace period18782026/10/08 21:40:06 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=018792026/10/08 21:40:06 INFO Vacuumed table table=pending_closures18802026/10/08 21:40:06 INFO Vacuumed table table=pending_objects1881=== CONT TestGCMetrics1882--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.49s)18832026/10/08 21:40:06 INFO Vacuumed table table=multipart_uploads18842026/10/08 21:40:06 INFO Vacuumed table table=closures18852026/10/08 21:40:06 INFO Vacuumed table table=objects18862026/10/08 21:40:06 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=018872026/10/08 21:40:06 INFO Received uploads request method=POST path=/api/pending_closures18882026/10/08 21:40:06 INFO Vacuumed table table=pending_closures18892026/10/08 21:40:06 INFO Vacuumed table table=pending_objects18902026/10/08 21:40:06 INFO Vacuumed table table=multipart_uploads18912026/10/08 21:40:06 INFO Vacuumed table table=closures18922026/10/08 21:40:06 INFO Received cleanup request method=DELETE path=/api/pending_closures18932026/10/08 21:40:06 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket82/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""18942026/10/08 21:40:06 INFO Aborted multipart uploads count=0 kept=118952026/10/08 21:40:06 INFO Vacuumed table table=objects18962026/10/08 21:40:06 INFO Received uploads request method=POST path=/api/pending_closures18972026/10/08 21:40:06 INFO Received cleanup request method=DELETE path=/api/pending_closures18982026/10/08 21:40:06 INFO Aborted multipart uploads count=1 kept=01899=== NAME TestClientCADerivations1900 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1901 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1902 error: binary cache 's3://bucket72?endpoint=http://localhost:43647®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1235149216/001/store'1903 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11904=== CONT TestCreatePendingClosureRejectsOversizedNAR1905--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.29s)19062026/10/08 21:40:06 INFO Received uploads request method=POST path=/api/pending_closures1907--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1908=== CONT TestFailedS3DeleteKeepsTombstone1909--- PASS: TestGCSweepDeliversEachKeyOnce (0.29s)1910=== CONT TestPushDedupSurvivesConcurrentGC1911--- PASS: TestMultipartCleanup (0.38s)1912=== CONT TestRegisterCompletedObjectNeedsPendingRow19132026/10/08 21:40:06 INFO Received uploads request method=POST path=/api/pending_closures1914--- PASS: TestClientCADerivations (0.60s)1915=== CONT TestProxyWriteTimeout1916=== RUN TestProxyWriteTimeout/narinfo1917=== PAUSE TestProxyWriteTimeout/narinfo1918=== RUN TestProxyWriteTimeout/1_GiB_nar1919=== PAUSE TestProxyWriteTimeout/1_GiB_nar1920=== RUN TestProxyWriteTimeout/10_GiB_nar1921=== PAUSE TestProxyWriteTimeout/10_GiB_nar1922=== RUN TestProxyWriteTimeout/unknown_size1923=== PAUSE TestProxyWriteTimeout/unknown_size1924=== CONT TestSweepSkipsRowsLockedByPush1925--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.22s)1926=== CONT TestPendingClosureFailureTracksEveryUpload1927=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1928=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1929=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1930=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1931=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1932=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1933--- PASS: TestPendingClosureFailureAbortsItsUploads (0.22s)19342026/10/08 21:40:06 INFO Received push request method=POST path=/api/pushes19352026/10/08 21:40:06 INFO Received uploads request method=POST path=/api/pending_closures19362026/10/08 21:40:06 INFO Aborted multipart uploads count=0 kept=019372026/10/08 21:40:06 WARN Force mode enabled - objects will be deleted immediately without grace period1938--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.24s)1939=== CONT TestServerTLSConfig/no_client_CA1940=== CONT TestServerTLSConfig/not_a_PEM_file1941=== CONT TestServerTLSConfig/missing_CA_file1942=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart1943--- PASS: TestServerTLSConfig (0.00s)1944 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1945 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1946 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)19472026/10/08 21:40:06 INFO Received complete multipart upload request method=POST path=/19482026/10/08 21:40:06 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=019492026/10/08 21:40:06 INFO Vacuumed table table=pending_closures19502026/10/08 21:40:06 INFO Vacuumed table table=pending_objects19512026/10/08 21:40:06 INFO Vacuumed table table=multipart_uploads19522026/10/08 21:40:06 INFO Vacuumed table table=closures19532026/10/08 21:40:06 INFO Vacuumed table table=objects19542026/10/08 21:40:06 INFO Received uploads request method=POST path=/api/pending_closures19552026/10/08 21:40:06 INFO Received uploads request method=POST path=/api/pending_closures1956--- PASS: TestGCMetrics (0.26s)1957=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19582026/10/08 21:40:06 INFO Received request for more parts method=POST path=/1959--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.27s)1960=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19612026/10/08 21:40:06 INFO Received uploads request method=POST path=/19622026/10/08 21:40:06 INFO Aborted multipart uploads count=0 kept=01963--- PASS: TestObjectStatsLargeCommit (1.57s)1964=== CONT TestPush_RejectsBadRequests/no_objects19652026/10/08 21:40:06 INFO Received push request method=POST path=/api/pushes19662026/10/08 21:40:06 INFO Aborted multipart uploads count=0 kept=01967=== CONT TestPush_RejectsBadRequests/no_roots19682026/10/08 21:40:06 INFO Received push request method=POST path=/api/pushes1969=== CONT TestPush_RejectsBadRequests/bad_root19702026/10/08 21:40:06 INFO Received push request method=POST path=/api/pushes1971=== CONT TestPush_RejectsBadRequests/root_not_in_objects19722026/10/08 21:40:06 INFO Received push request method=POST path=/api/pushes1973=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh19742026/10/08 21:40:06 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=019752026/10/08 21:40:06 INFO Vacuumed table table=pending_closures19762026/10/08 21:40:06 WARN Force mode enabled - objects will be deleted immediately without grace period19772026/10/08 21:40:06 INFO Vacuumed table table=pending_objects19782026/10/08 21:40:06 INFO Vacuumed table table=multipart_uploads19792026/10/08 21:40:06 INFO Aborted multipart uploads count=0 kept=019802026/10/08 21:40:06 INFO Vacuumed table table=closures19812026/10/08 21:40:06 INFO Vacuumed table table=objects19822026/10/08 21:40:06 INFO Received uploads request method=POST path=/api/pending_closures19832026/10/08 21:40:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19842026/10/08 21:40:06 WARN Force mode enabled - objects will be deleted immediately without grace period19852026/10/08 21:40:06 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."19862026/10/08 21:40:06 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."19872026/10/08 21:40:06 INFO Aborted multipart uploads count=0 kept=019882026/10/08 21:40:06 WARN Force mode enabled - objects will be deleted immediately without grace period19892026/10/08 21:40:06 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=01990--- PASS: TestPush_RejectsBadRequests (0.40s)1991 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1992 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1993 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1994 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)19952026/10/08 21:40:06 INFO Vacuumed table table=pending_closures19962026/10/08 21:40:06 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=019972026/10/08 21:40:06 INFO Vacuumed table table=pending_objects19982026/10/08 21:40:06 INFO Vacuumed table table=multipart_uploads19992026/10/08 21:40:06 INFO Vacuumed table table=closures20002026/10/08 21:40:06 INFO Vacuumed table table=pending_closures20012026/10/08 21:40:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20022026/10/08 21:40:06 INFO Vacuumed table table=objects20032026/10/08 21:40:06 INFO Vacuumed table table=pending_objects20042026/10/08 21:40:06 INFO Vacuumed table table=multipart_uploads20052026/10/08 21:40:06 INFO Aborted multipart uploads count=0 kept=020062026/10/08 21:40:06 INFO Vacuumed table table=closures20072026/10/08 21:40:06 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLmFjMDIyMGQ4LTMzZGMtNDcyOS05NmQxLTJlNGZlNGQ3OTI2ZngxNzkxNDk1NjA1NDQxOTM5MzM3 parts=1020082026/10/08 21:40:06 INFO Vacuumed table table=objects20092026/10/08 21:40:06 INFO Aborted multipart uploads count=0 kept=020102026/10/08 21:40:06 WARN Force mode enabled - objects will be deleted immediately without grace period20112026/10/08 21:40:06 WARN Force mode enabled - objects will be deleted immediately without grace period2012=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale20132026/10/08 21:40:06 INFO Received uploads request method=POST path=/api/pending_closures2014--- PASS: TestFailedS3DeleteKeepsTombstone (0.33s)20152026/10/08 21:40:06 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLmU0NTk2OTRiLTE2OTItNGI4MS04ZmU2LWYzYmU3ZDMzZTdiZngxNzkxNDk1NjA1MzQzMTQxOTgx parts=1020162026/10/08 21:40:06 INFO Received complete push request method=POST path=/api/pushes/1/complete20172026/10/08 21:40:06 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=02018--- PASS: TestGCBugBareHashReferences (0.44s)2019=== CONT TestResolveDBConnectionString/flag_wins2020=== CONT TestResolveDBConnectionString/nothing_configured2021=== CONT TestResolveDBConnectionString/missing_file_is_an_error2022=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2023=== CONT TestResolveDBConnectionString/file_when_flag_empty2024=== CONT TestParseSingleRange/none2025=== CONT TestParseSingleRange/start_far_past_EOF2026=== CONT TestParseSingleRange/closed2027=== CONT TestParseSingleRange/start_past_EOF2028=== CONT TestParseSingleRange/single_byte2029--- PASS: TestResolveDBConnectionString (0.00s)2030 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2031 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2032 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2033 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2034 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2035=== CONT TestParseSingleRange/suffix_exceeds_size2036=== CONT TestParseSingleRange/suffix2037=== CONT TestParseSingleRange/end_clamped_to_size2038=== CONT TestParseSingleRange/open-ended2039=== CONT TestParseSingleRange/multi-range_ignored2040=== CONT TestParseSingleRange/malformed_no_dash20412026/10/08 21:40:06 INFO Vacuumed table table=pending_closures2042=== CONT TestParseSingleRange/unknown_unit2043=== CONT TestParseSingleRange/malformed_end_before_start2044=== CONT TestParseSingleRange/malformed_both_empty2045=== CONT TestCacheConfigHandler/no_signing_keys2046--- PASS: TestParseSingleRange (0.00s)2047 --- PASS: TestParseSingleRange/none (0.00s)2048 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2049 --- PASS: TestParseSingleRange/closed (0.00s)2050 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2051 --- PASS: TestParseSingleRange/single_byte (0.00s)2052 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2053 --- PASS: TestParseSingleRange/suffix (0.00s)2054 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2055 --- PASS: TestParseSingleRange/open-ended (0.00s)2056 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2057 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2058 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2059 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2060 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2061=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2062=== CONT TestCacheConfigHandler/full_config,_no_issuer2063=== CONT TestCacheConfigHandler/no_cache_url_configured2064=== CONT TestPendingClosureWriteTimeout/400_objects2065=== CONT TestPendingClosureWriteTimeout/670k_objects2066--- PASS: TestCacheConfigHandler (0.00s)2067 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2068 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2069 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2070 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)20712026/10/08 21:40:06 INFO Vacuumed table table=pending_objects2072=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline20732026/10/08 21:40:06 INFO Vacuumed table table=multipart_uploads20742026/10/08 21:40:06 INFO Vacuumed table table=closures20752026/10/08 21:40:06 INFO Vacuumed table table=objects20762026/10/08 21:40:06 INFO Aborted multipart uploads count=0 kept=020772026/10/08 21:40:06 INFO Completed push id=1 objects=6 duration=9.175242ms20782026/10/08 21:40:06 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=020792026/10/08 21:40:06 INFO Vacuumed table table=pending_closures20802026/10/08 21:40:06 INFO Vacuumed table table=pending_objects20812026/10/08 21:40:06 INFO Vacuumed table table=multipart_uploads20822026/10/08 21:40:06 INFO Vacuumed table table=closures2083--- PASS: TestPushDedupSurvivesConcurrentGC (0.34s)2084=== CONT TestPendingClosureWriteTimeout/empty2085=== CONT TestClientErrorHandling/InvalidStorePath20862026/10/08 21:40:06 WARN Force mode enabled - objects will be deleted immediately without grace period20872026/10/08 21:40:06 INFO lead: released remote=192.0.2.1:123420882026/10/08 21:40:06 INFO Vacuumed table table=objects20892026/10/08 21:40:06 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=020902026/10/08 21:40:07 INFO Vacuumed table table=pending_closures20912026/10/08 21:40:07 INFO Vacuumed table table=pending_objects20922026/10/08 21:40:07 INFO Vacuumed table table=multipart_uploads20932026/10/08 21:40:07 INFO Vacuumed table table=closures2094--- PASS: TestSweepSkipsRowsLockedByPush (0.34s)2095=== CONT TestClientErrorHandling/ServerNotAvailable2096--- PASS: TestPush_CompleteCommitsEveryRoot (1.85s)2097=== CONT TestClientErrorHandling/InvalidAuthToken2098--- PASS: TestLeadElectsOneAndHandsOver (2.87s)2099=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2100=== CONT TestIsValidCachePath/short_hash2101=== CONT TestIsValidCachePath/nix-cache-info2102=== CONT TestIsValidCachePath/wrong_extension2103=== CONT TestIsValidCachePath/leading_slash2104=== CONT TestIsValidCachePath/empty2105=== CONT TestIsValidCachePath/invalid_char_u2106=== CONT TestIsValidCachePath/random_path21072026-10-08 21:40:07.006 UTC [178] LOG: checkpoints are occurring too frequently (9 seconds apart)21082026-10-08 21:40:07.006 UTC [178] HINT: Consider increasing the configuration parameter "max_wal_size".2109=== CONT TestIsValidCachePath/invalid_char_e21102026-10-08 21:40:07.006 UTC [178] LOG: checkpoint starting: wal2111=== CONT TestIsValidCachePath/traversal_in_middle2112=== CONT TestIsValidCachePath/traversal_parent2113=== CONT TestIsValidCachePath/ls2114=== CONT TestIsValidCachePath/index.html2115=== CONT TestIsValidCachePath/log2116=== CONT TestIsValidCachePath/nar_zst2117=== CONT TestIsValidCachePath/realisation2118=== CONT TestIsValidCachePath/nar_uncompressed2119=== CONT TestIsValidCachePath/nar_xz2120=== CONT TestIsValidCachePath/nar_bz22121=== CONT TestIsValidCachePath/narinfo2122--- PASS: TestIsValidCachePath (0.00s)2123 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2124 --- PASS: TestIsValidCachePath/short_hash (0.00s)2125 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2126 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2127 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2128 --- PASS: TestIsValidCachePath/empty (0.00s)2129 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2130 --- PASS: TestIsValidCachePath/random_path (0.00s)2131 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2132 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2133 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2134 --- PASS: TestIsValidCachePath/ls (0.00s)2135 --- PASS: TestIsValidCachePath/index.html (0.00s)2136 --- PASS: TestIsValidCachePath/log (0.00s)2137 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2138 --- PASS: TestIsValidCachePath/realisation (0.00s)2139 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2140 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2141 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2142 --- PASS: TestIsValidCachePath/narinfo (0.00s)2143=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info21442026/10/08 21:40:07 INFO Received uploads request method=POST path=/2145=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal21462026/10/08 21:40:07 INFO Received uploads request method=POST path=/2147=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key21482026/10/08 21:40:07 INFO Received complete multipart upload request method=POST path=/2149=== CONT TestIsValidUploadKey/empty_key2150=== CONT TestIsValidUploadKey/nar_xz2151=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key2152=== CONT TestIsValidUploadKey/realisation_plus_in_output21532026/10/08 21:40:07 INFO Received request for more parts method=POST path=/2154=== CONT TestIsValidUploadKey/absolute2155=== CONT TestIsValidUploadKey/realisation2156=== CONT TestIsValidUploadKey/unknown_type2157=== CONT TestIsValidUploadKey/build_log_plus_in_name2158--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2159 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2160 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2161 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2162 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2163=== CONT TestIsValidUploadKey/build_log_home-manager_file2164=== CONT TestIsValidUploadKey/build_log_equals2165=== CONT TestIsValidUploadKey/build_log_question_mark2166=== CONT TestIsValidUploadKey/build_log2167=== CONT TestIsValidUploadKey/nar_plain2168=== CONT TestIsValidUploadKey/listing2169=== CONT TestIsValidUploadKey/narinfo2170=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2171=== CONT TestIsValidUploadKey/index.html2172=== CONT TestIsValidUploadKey/traversal_nar2173=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2174=== CONT TestIsValidUploadKey/traversal2175=== CONT TestIsValidUploadKey/nix-cache-info2176=== CONT TestIsValidUploadKey/nar_zst2177=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2178=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete2179=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark2180--- PASS: TestIsValidUploadKey (0.00s)2181 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2182 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2183 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2184 --- PASS: TestIsValidUploadKey/absolute (0.00s)2185 --- PASS: TestIsValidUploadKey/realisation (0.00s)2186 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2187 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2188 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2189 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2190 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2191 --- PASS: TestIsValidUploadKey/build_log (0.00s)2192 --- PASS: TestIsValidUploadKey/listing (0.00s)2193 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2194 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2195 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2196 --- PASS: TestIsValidUploadKey/index.html (0.00s)2197 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2198 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2199 --- PASS: TestIsValidUploadKey/traversal (0.00s)2200 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2201 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2202 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)22032026/10/08 21:40:07 INFO Vacuumed table table=objects2204=== CONT TestGCEndsOnShutdown/before_the_run2205--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2206 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.33s)2207 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.38s)22082026/10/08 21:40:07 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22092026/10/08 21:40:07 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>2210--- PASS: TestPushWaitsForSweepHoldingRow (0.73s)2211=== CONT TestService_RequireScope_OIDC/builder_may_write2212=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2213=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read22142026/10/08 21:40:07 WARN Authentication failed token_preview=wrong token_length=5 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2215=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2216=== CONT TestService_RequireScope_OIDC/reader_may_not_write2217=== CONT TestService_RequireScope_OIDC/static_token_may_write2218=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2219=== CONT TestService_RequireScope_OIDC/static_token_may_admin2220=== CONT TestService_RequireScope_OIDC/writer_implies_read2221=== CONT TestService_RequireScope_OIDC/ops_may_admin2222=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2223=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2224--- PASS: TestReadProxyNarinfo (1.26s)2225=== CONT TestService_RequireScope_OIDC/reader_may_read2226=== CONT TestService_RequireScope_OIDC/ops_may_not_write2227=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2228=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2229=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token22302026/10/08 21:40:07 WARN Request failed, retrying attempt=2 backoff=188.349346ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22312026/10/08 21:40:07 WARN Authentication failed token_preview=eyJhbGciOi...FOr_CGVXUA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2232=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2233=== CONT TestProxyWriteTimeout/narinfo2234=== CONT TestProxyWriteTimeout/10_GiB_nar22352026/10/08 21:40:07 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2236=== CONT TestProxyWriteTimeout/unknown_size2237=== CONT TestProxyWriteTimeout/1_GiB_nar2238=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true2239=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false2240--- PASS: TestProxyWriteTimeout (0.00s)2241 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2242 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2243 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2244 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2245--- PASS: TestService_RequireScope_OIDC (0.41s)2246 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2247 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2248 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2249 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2250 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2251 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2252 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2253 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2254 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2255 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2256 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2257 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2258 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2259 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2260--- PASS: TestService_AuthMiddleware_OIDC (0.46s)2261 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2262 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2263 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)2264 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)22652026/10/08 21:40:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22662026/10/08 21:40:07 INFO Received uploads request method=POST path=/api/pending_closures22672026/10/08 21:40:07 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLmQ0NmFlZjNkLTBmMzctNDBmMC1iODY3LTVmOTMyNDZhZTgzN3gxNzkxNDk1NjA2Njk4MDc5MTgx parts=1022682026/10/08 21:40:07 INFO Aborted multipart uploads count=0 kept=022692026/10/08 21:40:07 WARN Force mode enabled - objects will be deleted immediately without grace period22702026/10/08 21:40:07 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22712026/10/08 21:40:07 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:43647/bucket104/?delete=\": context canceled"22722026/10/08 21:40:07 INFO Aborted multipart uploads count=0 kept=022732026/10/08 21:40:07 WARN Force mode enabled - objects will be deleted immediately without grace period22742026-10-08 21:40:07.348 UTC [2138] ERROR: canceling statement due to user request22752026-10-08 21:40:07.348 UTC [2138] CONTEXT: PL/pgSQL function object_stats_update() line 16 at RETURN22762026-10-08 21:40:07.348 UTC [2138] STATEMENT: -- name: MarkStaleObjects :execrows2277 WITH RECURSIVE ct AS (2278 SELECT timezone('UTC', now()) AS now2279 ),2280 closure_reach AS (2281 -- Start with all closure keys2282 SELECT o.key, o.refs2283 FROM objects o2284 INNER JOIN closures c ON o.key = c.key2285 UNION2286 -- Recursively add all referenced objects2287 SELECT o.key, o.refs2288 FROM objects o2289 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2290 ),2291 reachable_objects AS (2292 SELECT DISTINCT key FROM closure_reach2293 ),2294 stale_objects AS (2295 SELECT o.key2296 FROM objects AS o, ct2297 WHERE2298 NOT EXISTS (2299 SELECT 12300 FROM reachable_objects ro2301 WHERE ro.key = o.key2302 )2303 AND NOT EXISTS (2304 SELECT 12305 FROM pending_objects AS po2306 WHERE po.key = o.key2307 )2308 AND o.deleted_at IS NULL -- Only mark fresh objects2309 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2310 FOR UPDATE2311 )2312 UPDATE objects2313 SET2314 deleted_at = ct.now,2315 first_deleted_at = COALESCE(first_deleted_at, ct.now)2316 FROM stale_objects, ct2317 WHERE objects.key = stale_objects.key2318 23192026/10/08 21:40:07 INFO Received uploads request method=POST path=/api/pending_closures23202026/10/08 21:40:07 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"23212026/10/08 21:40:07 WARN Request failed, retrying attempt=3 backoff=371.636583ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23222026/10/08 21:40:07 INFO Received uploads request method=POST path=/api/pending_closures2323--- PASS: TestGCEndsOnShutdown (0.00s)2324 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.33s)2325 --- PASS: TestGCEndsOnShutdown/before_the_run (0.31s)2326 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.37s)2327=== NAME TestOrphanedObjectsGCStressTest2328 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2329 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion23302026/10/08 21:40:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2331--- PASS: TestDeleteClosuresRacingPins (1.63s)23322026/10/08 21:40:07 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLjkwZTNlNjMzLWU0YzEtNGZlYS05MjVlLTczNDk3ZWY1MDVkNHgxNzkxNDk1NjA1MzQ0MzU3Mzky parts=1023332026/10/08 21:40:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23342026/10/08 21:40:07 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLmJmZjQ5MGQ3LTI1YTUtNDM2MC1hYWZjLTM0Y2M0NWU4MDNiYXgxNzkxNDk1NjA2Njk4ODk4NDI5 parts=1023352026/10/08 21:40:07 INFO Received complete push request method=POST path=/api/pushes/1/complete23362026/10/08 21:40:07 INFO Completed push id=1 objects=4 duration=3.951375ms23372026/10/08 21:40:07 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete23382026/10/08 21:40:07 INFO Completed upload id=2 objects=2 duration=912.348µs2339=== NAME TestOrphanedObjectsGCStressTest2340 orphaned_objects_gc_test.go:503: Stress test completed successfully:2341 orphaned_objects_gc_test.go:504: - Active objects preserved: 202342 orphaned_objects_gc_test.go:505: - Objects deleted: 2102343 orphaned_objects_gc_test.go:506: - Total GC'd: 2102344--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2345 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.77s)2346 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.76s)23472026/10/08 21:40:07 WARN Request failed, retrying attempt=4 backoff=828.814617ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2348--- PASS: TestMetricsCommit (1.23s)2349--- PASS: TestOrphanedObjectsGCStressTest (2.46s)23502026/10/08 21:40:07 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLjkwNzZmYTc4LTE5OTktNGZlNy1hMjdhLTY4ZGZiZjc3MTA5OXgxNzkxNDk1NjA3Mzc4NzI4NjIw error="Access Denied"23512026/10/08 21:40:07 WARN keeping failed pending closure for cleanup to retry the abort id=12352--- PASS: TestPendingClosureFailureTracksEveryUpload (0.00s)2353 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (0.72s)2354 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (0.72s)23552026/10/08 21:40:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23562026/10/08 21:40:07 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLmFmNmY3OTYxLWYwMmMtNDMzMi1iYjFmLTM4MzRjMDE5ZGNiNHgxNzkxNDk1NjA1MzQ0Mzg0NDcy parts=102357--- PASS: TestPendingClosureWriteTimeout (0.00s)2358 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2359 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2360 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2361 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.07s)23622026/10/08 21:40:08 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=023632026/10/08 21:40:08 INFO Received create pin request method=POST path=/api/pins/myapp23642026/10/08 21:40:08 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3413165290/001/store/nmllifxn781jwdqsknrjkmx0mmxjgsb9-pinned-file.txt narinfo_key=nmllifxn781jwdqsknrjkmx0mmxjgsb9.narinfo23652026/10/08 21:40:08 INFO Starting cleanup of old closures method=DELETE path=/api/closures23662026/10/08 21:40:08 INFO Garbage collection started23672026/10/08 21:40:08 INFO Aborted multipart uploads count=0 kept=023682026/10/08 21:40:08 WARN Force mode enabled - objects will be deleted immediately without grace period23692026/10/08 21:40:08 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=023702026/10/08 21:40:08 INFO Vacuumed table table=pending_closures23712026/10/08 21:40:08 INFO Vacuumed table table=pending_objects23722026/10/08 21:40:08 INFO Vacuumed table table=multipart_uploads23732026/10/08 21:40:08 INFO Vacuumed table table=closures23742026/10/08 21:40:08 INFO Vacuumed table table=objects23752026/10/08 21:40:08 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02376=== NAME TestClientIntegration2377 client_integration_test.go:445: Objects in database after GC:2378 client_integration_test.go:445: Successfully deleted all objects with GC --force2379--- PASS: TestClientIntegration (3.07s)23802026/10/08 21:40:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23812026/10/08 21:40:08 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=MDUyMGVlYmYtMzE3Ny00YTEyLWE0OTctNDIwNTMwMzEzODAyLmJjY2MxYjA4LTM2NDItNDgxNS1iZWNjLTcyM2M3ZjI5MDhmNngxNzkxNDk1NjA1MzQ0Mjk4ODEx parts=1023822026-10-08 21:40:08.396 UTC [793] ERROR: could not obtain lock on row in relation "closures"23832026-10-08 21:40:08.396 UTC [793] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23842026-10-08 21:40:08.396 UTC [793] ERROR: could not obtain lock on row in relation "closures"23852026-10-08 21:40:08.396 UTC [793] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23862026-10-08 21:40:08.397 UTC [793] ERROR: could not obtain lock on row in relation "closures"23872026-10-08 21:40:08.397 UTC [793] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23882026-10-08 21:40:08.397 UTC [793] ERROR: could not obtain lock on row in relation "closures"23892026-10-08 21:40:08.397 UTC [793] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23902026-10-08 21:40:08.397 UTC [793] ERROR: could not obtain lock on row in relation "closures"23912026-10-08 21:40:08.397 UTC [793] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT2392--- PASS: TestPush_RootsAreLockedInByteOrder (3.35s)23932026/10/08 21:40:08 WARN Request failed, retrying attempt=5 backoff=1.723793502s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2394--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.84s)23952026/10/08 21:40:09 WARN Rate limiter enabled after throttle name=s3-test rate=523962026/10/08 21:40:09 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2397=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2398 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102399 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002400--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.18s)2401=== NAME TestPinProtectsFromGC2402 client_integration_test.go:976: Pin successfully protected closure from garbage collection2403--- PASS: TestConnectWaitsForAPeerMigration (5.16s)2404--- PASS: TestPinProtectsFromGC (4.63s)24052026/10/08 21:40:10 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24062026/10/08 21:40:10 WARN Request failed, retrying attempt=2 backoff=201.161131ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24072026/10/08 21:40:10 WARN Request failed, retrying attempt=3 backoff=383.876979ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24082026/10/08 21:40:11 WARN Request failed, retrying attempt=4 backoff=843.198706ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24092026/10/08 21:40:11 WARN Request failed, retrying attempt=5 backoff=1.621603106s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24102026/10/08 21:40:12 INFO Aborted multipart uploads count=1 kept=024112026/10/08 21:40:12 INFO Received cleanup request method=DELETE path=/api/pending_closures24122026/10/08 21:40:12 INFO Aborted multipart uploads count=1 kept=02413--- PASS: TestPendingCleanupUsesOneCutoff (6.30s)24142026/10/08 21:40:13 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"24152026/10/08 21:40:13 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24162026/10/08 21:40:13 WARN Request failed, retrying attempt=2 backoff=209.188131ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24172026/10/08 21:40:13 WARN Request failed, retrying attempt=3 backoff=390.014802ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24182026/10/08 21:40:14 WARN Request failed, retrying attempt=4 backoff=803.813921ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24192026/10/08 21:40:14 WARN Request failed, retrying attempt=5 backoff=1.634008392s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24202026/10/08 21:40:16 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24212026/10/08 21:40:16 WARN Request failed, retrying attempt=2 backoff=211.152629ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24222026/10/08 21:40:16 WARN Request failed, retrying attempt=3 backoff=414.430318ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24232026/10/08 21:40:17 WARN Request failed, retrying attempt=4 backoff=862.957417ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24242026/10/08 21:40:18 WARN Request failed, retrying attempt=5 backoff=1.471066134s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2425--- PASS: TestClientErrorHandling (0.00s)2426 --- PASS: TestClientErrorHandling/InvalidStorePath (0.34s)2427 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.38s)2428 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.70s)2429--- PASS: TestUploadHandlersRejectOversizedBody (0.46s)2430 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.91s)2431 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.98s)2432 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (14.03s)2433PASS2434{"timestamp":"2026-10-08T21:40:20.955752368Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:57432","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(198)"}2435{"timestamp":"2026-10-08T21:40:20.955753508Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:57630","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(197)"}2436{"timestamp":"2026-10-08T21:40:20.95600371Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:58068","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(199)"}24372026-10-08 21:40:21.319 UTC [173] LOG: received smart shutdown request24382026-10-08 21:40:21.324 UTC [173] LOG: background worker "logical replication launcher" (PID 183) exited with exit code 124392026-10-08 21:40:21.937 UTC [178] LOG: checkpoint complete: wrote 5220 buffers (31.9%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=14.400 s, sync=0.491 s, total=14.932 s; sync files=37079, longest=0.007 s, average=0.001 s; distance=533902 kB, estimate=533902 kB; lsn=0/24EBC3F8, redo lsn=0/220C956824402026-10-08 21:40:21.942 UTC [178] LOG: shutting down24412026-10-08 21:40:21.942 UTC [178] LOG: checkpoint starting: shutdown immediate24422026-10-08 21:40:22.137 UTC [178] LOG: checkpoint complete: wrote 5253 buffers (32.1%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 2 recycled; write=0.074 s, sync=0.117 s, total=0.196 s; sync files=1611, longest=0.007 s, average=0.001 s; distance=47051 kB, estimate=485217 kB; lsn=0/24EBC470, redo lsn=0/24EBC47024432026-10-08 21:40:22.218 UTC [173] LOG: database system is shut down2444Running OIDC tests...2445=== RUN TestAudienceForIssuer2446=== PAUSE TestAudienceForIssuer2447=== RUN TestHTTPClientForHasTimeouts2448=== PAUSE TestHTTPClientForHasTimeouts2449=== RUN TestGlobMatch2450=== PAUSE TestGlobMatch2451=== RUN TestValidateToken_ValidToken2452=== PAUSE TestValidateToken_ValidToken2453=== RUN TestValidateToken_WrongAudience2454=== PAUSE TestValidateToken_WrongAudience2455=== RUN TestValidateToken_Expired2456=== PAUSE TestValidateToken_Expired2457=== RUN TestValidateToken_BoundClaimsMismatch2458=== PAUSE TestValidateToken_BoundClaimsMismatch2459=== RUN TestValidateToken_BoundSubjectMismatch2460=== PAUSE TestValidateToken_BoundSubjectMismatch2461=== RUN TestValidateToken_MultipleProviders2462=== PAUSE TestValidateToken_MultipleProviders2463=== RUN TestValidateToken_NoMatchingProvider2464=== PAUSE TestValidateToken_NoMatchingProvider2465=== RUN TestValidateToken_KubernetesServiceAccount2466=== PAUSE TestValidateToken_KubernetesServiceAccount2467=== RUN TestNewValidator_KubernetesRequiresCA2468=== PAUSE TestNewValidator_KubernetesRequiresCA2469=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2470=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2471=== RUN TestPins_ReservedForMatchingRule2472=== PAUSE TestPins_ReservedForMatchingRule2473=== RUN TestPins_TopLevelShorthand2474=== PAUSE TestPins_TopLevelShorthand2475=== RUN TestPins_ConfigValidation2476=== PAUSE TestPins_ConfigValidation2477=== RUN TestScopes_LegacyProviderDefaultsToWrite2478=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2479=== RUN TestScopes_Rules2480=== PAUSE TestScopes_Rules2481=== RUN TestScopes_ConfigValidation2482=== PAUSE TestScopes_ConfigValidation2483=== CONT TestAudienceForIssuer2484=== CONT TestValidateToken_Expired2485=== CONT TestValidateToken_KubernetesServiceAccount2486=== CONT TestScopes_ConfigValidation2487=== CONT TestScopes_Rules2488=== CONT TestScopes_LegacyProviderDefaultsToWrite2489=== CONT TestPins_ConfigValidation2490=== CONT TestPins_TopLevelShorthand2491=== CONT TestPins_ReservedForMatchingRule2492=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2493=== CONT TestNewValidator_KubernetesRequiresCA2494=== CONT TestValidateToken_MultipleProviders2495=== CONT TestGlobMatch2496=== RUN TestGlobMatch/foo_foo2497=== PAUSE TestGlobMatch/foo_foo2498=== RUN TestGlobMatch/foo_bar2499=== PAUSE TestGlobMatch/foo_bar2500=== CONT TestValidateToken_ValidToken2501=== CONT TestValidateToken_WrongAudience2502=== CONT TestHTTPClientForHasTimeouts2503=== CONT TestValidateToken_BoundClaimsMismatch2504=== CONT TestValidateToken_NoMatchingProvider2505--- PASS: TestAudienceForIssuer (0.00s)2506--- PASS: TestScopes_ConfigValidation (0.00s)2507=== CONT TestValidateToken_BoundSubjectMismatch2508--- PASS: TestPins_ConfigValidation (0.00s)2509=== RUN TestGlobMatch/*_2510=== PAUSE TestGlobMatch/*_2511=== RUN TestGlobMatch/*_anything2512=== PAUSE TestGlobMatch/*_anything2513=== RUN TestGlobMatch/foo*_foo2514=== PAUSE TestGlobMatch/foo*_foo2515=== RUN TestGlobMatch/foo*_foobar2516=== PAUSE TestGlobMatch/foo*_foobar2517=== RUN TestGlobMatch/foo*_bar2518=== PAUSE TestGlobMatch/foo*_bar2519=== RUN TestGlobMatch/*bar_bar2520=== PAUSE TestGlobMatch/*bar_bar2521=== RUN TestGlobMatch/*bar_foobar2522=== PAUSE TestGlobMatch/*bar_foobar2523=== RUN TestGlobMatch/*bar_foo2524=== PAUSE TestGlobMatch/*bar_foo2525=== RUN TestGlobMatch/foo*bar_foobar2526=== PAUSE TestGlobMatch/foo*bar_foobar2527=== RUN TestGlobMatch/foo*bar_foo123bar2528=== PAUSE TestGlobMatch/foo*bar_foo123bar2529=== RUN TestGlobMatch/foo*bar_foobarbaz2530=== PAUSE TestGlobMatch/foo*bar_foobarbaz2531=== RUN TestGlobMatch/*/*_foo/bar2532=== PAUSE TestGlobMatch/*/*_foo/bar2533=== RUN TestGlobMatch/*/*_foo2534=== PAUSE TestGlobMatch/*/*_foo2535=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2536=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2537=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02538=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02539=== RUN TestGlobMatch/refs/*/main_refs/heads/main2540=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2541=== RUN TestGlobMatch/fo?_foo2542=== PAUSE TestGlobMatch/fo?_foo2543=== RUN TestGlobMatch/fo?_fo2544=== PAUSE TestGlobMatch/fo?_fo2545=== RUN TestGlobMatch/fo?_fooo2546=== PAUSE TestGlobMatch/fo?_fooo2547=== RUN TestGlobMatch/?oo_foo2548=== PAUSE TestGlobMatch/?oo_foo2549=== RUN TestGlobMatch/?oo_boo2550=== PAUSE TestGlobMatch/?oo_boo2551=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2552=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2553=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2554=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2555=== CONT TestGlobMatch/*_2556=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2557=== CONT TestGlobMatch/foo*bar_foo123bar2558=== CONT TestGlobMatch/foo*_bar2559=== CONT TestGlobMatch/?oo_boo2560=== CONT TestGlobMatch/fo?_fo2561=== CONT TestGlobMatch/*bar_bar2562=== CONT TestGlobMatch/fo?_foo2563=== CONT TestGlobMatch/foo*_foobar2564=== CONT TestGlobMatch/foo*bar_foobar2565=== CONT TestGlobMatch/*_anything2566=== CONT TestGlobMatch/foo*bar_foobarbaz2567=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2568=== CONT TestGlobMatch/*bar_foo2569=== CONT TestGlobMatch/?oo_foo2570=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2571=== CONT TestGlobMatch/*/*_foo2572=== CONT TestGlobMatch/fo?_fooo2573=== CONT TestGlobMatch/*bar_foobar2574=== CONT TestGlobMatch/refs/*/main_refs/heads/main2575=== CONT TestGlobMatch/foo_bar2576=== CONT TestGlobMatch/foo*_foo2577=== CONT TestGlobMatch/*/*_foo/bar2578=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02579=== CONT TestGlobMatch/foo_foo2580--- PASS: TestGlobMatch (0.01s)2581 --- PASS: TestGlobMatch/*_ (0.00s)2582 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2583 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2584 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2585 --- PASS: TestGlobMatch/foo*_bar (0.00s)2586 --- PASS: TestGlobMatch/*bar_bar (0.00s)2587 --- PASS: TestGlobMatch/?oo_foo (0.00s)2588 --- PASS: TestGlobMatch/*bar_foo (0.00s)2589 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2590 --- PASS: TestGlobMatch/?oo_boo (0.00s)2591 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2592 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2593 --- PASS: TestGlobMatch/*_anything (0.00s)2594 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2595 --- PASS: TestGlobMatch/fo?_foo (0.00s)2596 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2597 --- PASS: TestGlobMatch/fo?_fo (0.00s)2598 --- PASS: TestGlobMatch/foo_bar (0.00s)2599 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2600 --- PASS: TestGlobMatch/foo*_foo (0.00s)2601 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2602 --- PASS: TestGlobMatch/foo_foo (0.00s)2603 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2604 --- PASS: TestGlobMatch/*/*_foo (0.00s)2605 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)26062026/10/08 21:40:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37977/oidc2607--- PASS: TestValidateToken_ValidToken (0.08s)26082026/10/08 21:40:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41259/oidc2609--- PASS: TestPins_TopLevelShorthand (0.12s)26102026/10/08 21:40:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44743/oidc26112026/10/08 21:40:25 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232612--- PASS: TestValidateToken_Expired (0.13s)26132026/10/08 21:40:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40165/oidc2614--- PASS: TestValidateToken_WrongAudience (0.13s)2615--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.15s)26162026/10/08 21:40:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33555/oidc26172026/10/08 21:40:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42151/oidc2618--- PASS: TestValidateToken_BoundSubjectMismatch (0.16s)26192026/10/08 21:40:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39569/oidc2620--- PASS: TestPins_ReservedForMatchingRule (0.17s)2621--- PASS: TestValidateToken_BoundClaimsMismatch (0.18s)26222026/10/08 21:40:25 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33473/oidc2623--- PASS: TestValidateToken_NoMatchingProvider (0.20s)2624--- PASS: TestHTTPClientForHasTimeouts (0.20s)26252026/10/08 21:40:25 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46559/oidc26262026/10/08 21:40:25 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:46403/oidc2627--- PASS: TestValidateToken_MultipleProviders (0.25s)26282026/10/08 21:40:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44643/oidc2629--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.29s)26302026/10/08 21:40:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41623/oidc2631--- PASS: TestScopes_Rules (0.38s)26322026/10/08 21:40:25 http: TLS handshake error from 127.0.0.1:55774: remote error: tls: bad certificate2633--- PASS: TestNewValidator_KubernetesRequiresCA (0.39s)26342026/10/08 21:40:25 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:457832635--- PASS: TestValidateToken_KubernetesServiceAccount (0.43s)2636PASS2637Running hook tests...2638=== RUN TestSendPathsEmpty2639=== PAUSE TestSendPathsEmpty2640=== RUN TestQueueEnqueueAndFetch2641=== PAUSE TestQueueEnqueueAndFetch2642=== RUN TestQueueDeduplication2643=== PAUSE TestQueueDeduplication2644=== RUN TestQueueRemove2645=== PAUSE TestQueueRemove2646=== RUN TestQueueFetchBatchLimit2647=== PAUSE TestQueueFetchBatchLimit2648=== RUN TestQueueRetryMovesToBack2649=== PAUSE TestQueueRetryMovesToBack2650=== RUN TestQueueFetchRemoveLifecycle2651=== PAUSE TestQueueFetchRemoveLifecycle2652=== RUN TestQueueConcurrentWriters2653=== PAUSE TestQueueConcurrentWriters2654=== RUN TestQueueEnqueueWaitsOutSlowWriter2655=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2656=== RUN TestQueueRemoveLargeClosure2657=== PAUSE TestQueueRemoveLargeClosure2658=== RUN TestServerClientIntegration2659--- PASS: TestServerClientIntegration (0.00s)2660=== RUN TestServerQueueError26612026/10/08 21:40:26 ERROR Failed to queue paths error="permission denied" count=12662--- PASS: TestServerQueueError (0.00s)2663=== RUN TestServerRefusesOversizedAndNonStoreRequests2664=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2665=== RUN TestGetListenerSocketActivation2666 server_test.go:329: === RUN TestGetListenerSocketActivation2667 --- PASS: TestGetListenerSocketActivation (0.00s)2668 PASS2669 2670--- PASS: TestGetListenerSocketActivation (1.02s)2671=== RUN TestServerStalledClientDoesNotBlockShutdown2672=== PAUSE TestServerStalledClientDoesNotBlockShutdown2673=== RUN TestServerBacksOffOnAcceptErrors2674=== PAUSE TestServerBacksOffOnAcceptErrors2675=== RUN TestDrainIsolatesPoisonPath2676=== PAUSE TestDrainIsolatesPoisonPath2677=== RUN TestRunNotBlockedByPoisonHead2678=== PAUSE TestRunNotBlockedByPoisonHead2679=== RUN TestDrainGivesUpWhenServerDown2680=== PAUSE TestDrainGivesUpWhenServerDown2681=== RUN TestFailedPathPrunedByLaterClosure2682=== PAUSE TestFailedPathPrunedByLaterClosure2683=== RUN TestWorkerUploadsAndRemoves2684=== PAUSE TestWorkerUploadsAndRemoves2685=== RUN TestWorkerSkipsGCdPaths2686=== PAUSE TestWorkerSkipsGCdPaths2687=== RUN TestWorkerPrunesClosureDeps2688=== PAUSE TestWorkerPrunesClosureDeps2689=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2690=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2691=== RUN TestDrainTimeout2692=== PAUSE TestDrainTimeout2693=== RUN TestDrainTimeoutDuringIsolation2694=== PAUSE TestDrainTimeoutDuringIsolation2695=== RUN TestShutdownFinishesInFlightPush2696=== PAUSE TestShutdownFinishesInFlightPush2697=== RUN TestWorkerRemoveFailureIsNotProgress2698=== PAUSE TestWorkerRemoveFailureIsNotProgress2699=== RUN TestWorkerKeepsPathItCannotStat2700=== PAUSE TestWorkerKeepsPathItCannotStat2701=== CONT TestSendPathsEmpty2702=== CONT TestServerBacksOffOnAcceptErrors2703=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2704=== CONT TestWorkerKeepsPathItCannotStat2705=== CONT TestShutdownFinishesInFlightPush27062026/10/08 21:40:27 ERROR Accept failed error="too many open files"2707=== CONT TestWorkerRemoveFailureIsNotProgress2708=== CONT TestDrainTimeoutDuringIsolation2709=== CONT TestDrainTimeout2710=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2711=== CONT TestWorkerSkipsGCdPaths2712=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2713=== CONT TestQueueFetchRemoveLifecycle2714=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2715=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2716=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2717=== CONT TestServerRefusesOversizedAndNonStoreRequests2718=== CONT TestFailedPathPrunedByLaterClosure2719=== CONT TestDrainIsolatesPoisonPath2720=== CONT TestWorkerPrunesClosureDeps2721=== CONT TestQueueEnqueueWaitsOutSlowWriter2722=== CONT TestServerStalledClientDoesNotBlockShutdown2723=== CONT TestQueueRetryMovesToBack2724=== CONT TestQueueConcurrentWriters2725=== CONT TestDrainGivesUpWhenServerDown2726=== CONT TestRunNotBlockedByPoisonHead2727=== CONT TestQueueRemoveLargeClosure27282026/10/08 21:40:27 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2729=== CONT TestQueueEnqueueAndFetch2730=== CONT TestQueueDeduplication2731=== CONT TestWorkerUploadsAndRemoves2732=== CONT TestQueueRemove2733--- PASS: TestSendPathsEmpty (0.00s)2734=== RUN TestShutdownFinishesInFlightPush/completes2735=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2736=== PAUSE TestShutdownFinishesInFlightPush/completes2737=== CONT TestQueueFetchBatchLimit2738=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2739=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2740=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout27412026/10/08 21:40:27 ERROR Refusing path outside the store path=/nix/store store=/nix/store2742=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2743=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short2744=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2745=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2746=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline27472026/10/08 21:40:27 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store27482026/10/08 21:40:27 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store27492026/10/08 21:40:27 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store27502026/10/08 21:40:27 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27512026/10/08 21:40:27 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27522026/10/08 21:40:27 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store27532026/10/08 21:40:27 ERROR Accept failed error="too many open files"27542026/10/08 21:40:27 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store27552026/10/08 21:40:27 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store27562026/10/08 21:40:27 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store27572026/10/08 21:40:27 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store27582026/10/08 21:40:27 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store27592026/10/08 21:40:27 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store27602026/10/08 21:40:27 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store27612026/10/08 21:40:27 ERROR Failed to decode request error="unexpected EOF"2762--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2763=== CONT TestShutdownFinishesInFlightPush/completes27642026/10/08 21:40:27 ERROR Accept failed error="too many open files"27652026/10/08 21:40:27 ERROR Accept failed error="too many open files"27662026/10/08 21:40:27 INFO Upload queue status pending=327672026/10/08 21:40:27 INFO Upload queue status pending=227682026/10/08 21:40:27 INFO Uploading batch count=227692026/10/08 21:40:27 INFO Uploading batch count=227702026/10/08 21:40:27 INFO Uploading batch count=427712026/10/08 21:40:27 ERROR Upload failed error="upload failed" count=427722026/10/08 21:40:27 INFO Uploading batch count=127732026/10/08 21:40:27 ERROR Upload failed error="upload failed" count=127742026/10/08 21:40:27 INFO Upload queue status pending=227752026/10/08 21:40:27 INFO Uploading batch count=127762026/10/08 21:40:27 INFO Upload queue status pending=227772026/10/08 21:40:27 INFO Uploading batch count=427782026/10/08 21:40:27 ERROR Upload failed error="upload failed" count=427792026/10/08 21:40:28 INFO Uploading batch count=427802026/10/08 21:40:28 ERROR Upload failed error="upload failed" count=427812026/10/08 21:40:28 INFO Uploading batch count=227822026/10/08 21:40:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1289361493/002/bbb27832026/10/08 21:40:28 INFO Upload queue status pending=227842026/10/08 21:40:28 ERROR Accept failed error="too many open files"2785=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2786=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths2787--- PASS: TestQueueFetchRemoveLifecycle (0.08s)27882026/10/08 21:40:28 INFO Upload queue status pending=32789--- PASS: TestQueueRetryMovesToBack (0.08s)27902026/10/08 21:40:28 INFO Uploading batch count=127912026/10/08 21:40:28 ERROR Upload failed error="upload failed" count=127922026/10/08 21:40:28 INFO Uploading batch count=227932026/10/08 21:40:28 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2278938926/002/nonexistent2794--- PASS: TestQueueEnqueueAndFetch (0.08s)2795=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch2796--- PASS: TestQueueFetchBatchLimit (0.08s)2797=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27982026/10/08 21:40:28 INFO Uploading batch count=22799--- PASS: TestQueueRemove (0.08s)28002026/10/08 21:40:28 INFO Uploading batch count=128012026/10/08 21:40:28 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2322372948/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2322372948/002/locked/aaa: permission denied"28022026/10/08 21:40:28 INFO Uploading batch count=128032026/10/08 21:40:28 ERROR Upload failed error="upload failed" count=128042026/10/08 21:40:28 INFO Uploading batch count=228052026/10/08 21:40:28 ERROR Upload failed error="upload failed" count=228062026/10/08 21:40:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1263309162/002/a28072026/10/08 21:40:28 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2322372948/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2322372948/002/locked/aaa: permission denied"28082026/10/08 21:40:28 INFO Uploading batch count=12809--- PASS: TestQueueDeduplication (0.08s)28102026/10/08 21:40:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1263309162/002/b28112026/10/08 21:40:28 INFO Uploading batch count=128122026/10/08 21:40:28 ERROR Upload failed error="upload failed" count=128132026/10/08 21:40:28 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2322372948/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2322372948/002/locked/aaa: permission denied"28142026/10/08 21:40:28 INFO Uploading batch count=128152026/10/08 21:40:28 ERROR Upload failed error="upload failed" count=128162026/10/08 21:40:28 INFO Uploading batch count=228172026/10/08 21:40:28 ERROR Upload failed error="upload failed" count=228182026/10/08 21:40:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1263309162/002/c2819--- PASS: TestWorkerUploadsAndRemoves (0.09s)28202026/10/08 21:40:28 ERROR Drain finished with paths left in queue remaining=128212026/10/08 21:40:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1263309162/002/d28222026/10/08 21:40:28 ERROR Drain finished with paths left in queue remaining=12823--- PASS: TestFailedPathPrunedByLaterClosure (0.10s)2824--- PASS: TestWorkerPrunesClosureDeps (0.10s)28252026/10/08 21:40:28 INFO Uploading batch count=228262026/10/08 21:40:28 ERROR Upload failed error="upload failed" count=228272026/10/08 21:40:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1263309162/002/e2828--- PASS: TestDrainIsolatesPoisonPath (0.10s)28292026/10/08 21:40:28 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1263309162/002/f2830--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.10s)2831--- PASS: TestWorkerKeepsPathItCannotStat (0.10s)28322026/10/08 21:40:28 INFO Upload queue status pending=22833--- PASS: TestWorkerSkipsGCdPaths (0.10s)28342026/10/08 21:40:28 INFO Uploading batch count=228352026/10/08 21:40:28 ERROR Drain finished with paths left in queue remaining=102836--- PASS: TestDrainGivesUpWhenServerDown (0.11s)28372026/10/08 21:40:28 INFO Uploading batch count=228382026/10/08 21:40:28 ERROR Upload failed error="upload failed" count=228392026/10/08 21:40:28 INFO Uploading batch count=228402026/10/08 21:40:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128412026/10/08 21:40:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228422026/10/08 21:40:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128432026/10/08 21:40:28 INFO Uploading batch count=228442026/10/08 21:40:28 INFO Uploading batch count=228452026/10/08 21:40:28 ERROR Upload failed error="upload failed" count=228462026/10/08 21:40:28 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path1617760449/001/nonexistent28472026/10/08 21:40:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228482026/10/08 21:40:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128492026/10/08 21:40:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128502026/10/08 21:40:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128512026/10/08 21:40:28 INFO Uploading batch count=228522026/10/08 21:40:28 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path1617760449/001/nonexistent28532026/10/08 21:40:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228542026/10/08 21:40:28 INFO Uploading batch count=228552026/10/08 21:40:28 ERROR Upload failed error="upload failed" count=228562026/10/08 21:40:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128572026/10/08 21:40:28 ERROR Drain finished with paths left in queue remaining=228582026/10/08 21:40:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128592026/10/08 21:40:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128602026/10/08 21:40:28 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path1617760449/001/nonexistent28612026/10/08 21:40:28 ERROR Drain finished with paths left in queue remaining=228622026/10/08 21:40:28 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128632026/10/08 21:40:28 ERROR Drain finished with paths left in queue remaining=12864--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2865 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.05s)2866 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.05s)2867 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.05s)28682026/10/08 21:40:28 ERROR Accept failed error="too many open files"28692026/10/08 21:40:28 ERROR Failed to decode request error="read unix /build/hook3389187396/test.sock->@: i/o timeout"28702026/10/08 21:40:28 ERROR Failed to write response error="write unix /build/hook3389187396/test.sock->@: i/o timeout"2871--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)28722026/10/08 21:40:28 ERROR Upload failed error="context canceled" count=228732026/10/08 21:40:28 ERROR Drain finished with paths left in queue remaining=428742026/10/08 21:40:28 ERROR Drain finished with paths left in queue remaining=42875--- PASS: TestDrainTimeout (0.27s)28762026/10/08 21:40:28 ERROR Upload failed error="context canceled" count=228772026/10/08 21:40:28 ERROR Drain finished with paths left in queue remaining=22878--- PASS: TestShutdownFinishesInFlightPush (0.00s)2879 --- PASS: TestShutdownFinishesInFlightPush/completes (0.17s)2880 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.23s)28812026/10/08 21:40:28 ERROR Accept failed error="too many open files"28822026/10/08 21:40:28 ERROR Drain finished with paths left in queue remaining=32883--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2884 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.26s)2885 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.38s)2886--- PASS: TestQueueConcurrentWriters (0.51s)28872026/10/08 21:40:28 ERROR Accept failed error="too many open files"2888--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)28892026/10/08 21:40:28 INFO Uploading batch count=128902026/10/08 21:40:29 INFO Uploading batch count=128912026/10/08 21:40:29 INFO Uploading batch count=128922026/10/08 21:40:29 ERROR Upload failed error="upload failed" count=128932026/10/08 21:40:29 INFO Uploading batch count=128942026/10/08 21:40:29 ERROR Upload failed error="upload failed" count=128952026/10/08 21:40:29 INFO Uploading batch count=128962026/10/08 21:40:29 ERROR Upload failed error="upload failed" count=128972026/10/08 21:40:29 INFO Uploading batch count=128982026/10/08 21:40:29 ERROR Upload failed error="upload failed" count=128992026/10/08 21:40:29 ERROR Drain finished with paths left in queue remaining=12900--- PASS: TestRunNotBlockedByPoisonHead (1.11s)2901--- PASS: TestQueueRemoveLargeClosure (2.76s)2902--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.06s)2903PASS2904Running signing tests...2905=== RUN TestExternalSigner2906=== PAUSE TestExternalSigner2907=== RUN TestExternalSignerWrongPublicKey2908=== PAUSE TestExternalSignerWrongPublicKey2909=== RUN TestExternalSignerErrors2910=== PAUSE TestExternalSignerErrors2911=== RUN TestExternalSignerRestartsAfterCrash2912=== PAUSE TestExternalSignerRestartsAfterCrash2913=== RUN TestExternalSignerProgramErrorKeepsProcess2914=== PAUSE TestExternalSignerProgramErrorKeepsProcess2915=== RUN TestExternalSignerClose2916=== PAUSE TestExternalSignerClose2917=== RUN TestExternalSignerRejectsInvalidPublicKey2918=== PAUSE TestExternalSignerRejectsInvalidPublicKey2919=== RUN TestExternalSignerCancellation2920=== PAUSE TestExternalSignerCancellation2921=== RUN TestGenerateFingerprint2922=== PAUSE TestGenerateFingerprint2923=== RUN TestParseSigningKey2924=== PAUSE TestParseSigningKey2925=== RUN TestSign2926=== PAUSE TestSign2927=== RUN TestSignBatch2928=== PAUSE TestSignBatch2929=== RUN TestNilKeyPublicKey2930=== PAUSE TestNilKeyPublicKey2931=== RUN TestSignErrors2932=== PAUSE TestSignErrors2933=== CONT TestExternalSignerRestartsAfterCrash2934=== CONT TestExternalSignerCancellation2935=== CONT TestGenerateFingerprint2936=== RUN TestGenerateFingerprint/basic_with_references2937=== CONT TestSignBatch2938=== CONT TestSignErrors2939=== CONT TestNilKeyPublicKey2940--- PASS: TestNilKeyPublicKey (0.00s)2941=== CONT TestExternalSignerClose2942=== CONT TestExternalSignerRejectsInvalidPublicKey2943=== RUN TestExternalSignerRejectsInvalidPublicKey/#002944=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002945=== CONT TestExternalSignerProgramErrorKeepsProcess2946=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2947=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2948=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2949=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2950=== CONT TestSign2951=== CONT TestExternalSignerWrongPublicKey2952=== CONT TestExternalSignerErrors2953=== RUN TestExternalSignerErrors/wrong_signature_length2954=== CONT TestParseSigningKey2955=== RUN TestParseSigningKey/valid_32-byte_key2956=== PAUSE TestExternalSignerErrors/wrong_signature_length2957=== CONT TestExternalSigner2958=== PAUSE TestGenerateFingerprint/basic_with_references2959=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2960=== PAUSE TestParseSigningKey/valid_32-byte_key2961=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2962=== RUN TestGenerateFingerprint/no_references2963=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2964=== RUN TestExternalSignerErrors/null2965=== RUN TestParseSigningKey/no_colon2966=== PAUSE TestExternalSignerErrors/null2967=== RUN TestExternalSignerErrors/missing_signatures2968=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2969=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2970=== PAUSE TestGenerateFingerprint/no_references2971=== PAUSE TestExternalSignerErrors/missing_signatures2972=== PAUSE TestParseSigningKey/no_colon2973=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2974=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2975=== RUN TestExternalSignerErrors/too_few_signatures2976=== RUN TestParseSigningKey/empty_name2977=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2978=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2979=== PAUSE TestParseSigningKey/empty_name2980=== CONT TestExternalSignerRejectsInvalidPublicKey/#002981=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2982=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2983=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2984=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2985=== PAUSE TestExternalSignerErrors/too_few_signatures2986=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2987--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2988 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2989 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2990 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2991 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2992 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2993=== RUN TestGenerateFingerprint/invalid_nar_hash_length2994=== RUN TestExternalSignerErrors/missing_signature_name2995=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2996--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2997=== PAUSE TestExternalSignerErrors/missing_signature_name2998=== RUN TestParseSigningKey/invalid_base642999=== PAUSE TestParseSigningKey/invalid_base643000=== RUN TestGenerateFingerprint/invalid_store_path_prefix3001=== RUN TestExternalSignerErrors/exit_on_request3002=== RUN TestParseSigningKey/wrong_length3003=== PAUSE TestExternalSignerErrors/exit_on_request3004=== PAUSE TestParseSigningKey/wrong_length3005=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix3006=== RUN TestExternalSignerErrors/invalid_signature_base643007=== PAUSE TestExternalSignerErrors/invalid_signature_base643008=== CONT TestParseSigningKey/valid_32-byte_key3009=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name3010=== RUN TestGenerateFingerprint/invalid_reference_prefix3011=== CONT TestParseSigningKey/no_colon3012=== CONT TestParseSigningKey/invalid_base643013=== CONT TestParseSigningKey/empty_name3014=== CONT TestParseSigningKey/wrong_length3015=== RUN TestExternalSignerErrors/program_error3016=== PAUSE TestExternalSignerErrors/program_error3017=== RUN TestExternalSignerErrors/exit_at_startup3018=== PAUSE TestGenerateFingerprint/invalid_reference_prefix3019=== PAUSE TestExternalSignerErrors/exit_at_startup3020=== CONT TestGenerateFingerprint/basic_with_references3021=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix3022=== CONT TestGenerateFingerprint/invalid_store_path_prefix3023=== RUN TestExternalSignerErrors/invalid_JSON3024=== CONT TestGenerateFingerprint/invalid_reference_prefix3025=== CONT TestGenerateFingerprint/no_references3026=== CONT TestGenerateFingerprint/unsorted_references_get_sorted3027=== CONT TestGenerateFingerprint/invalid_nar_hash_length3028=== PAUSE TestExternalSignerErrors/invalid_JSON3029=== RUN TestExternalSignerErrors/wrong_shape3030=== PAUSE TestExternalSignerErrors/wrong_shape3031=== RUN TestExternalSignerErrors/wrong_signatures_shape3032--- PASS: TestGenerateFingerprint (0.01s)3033 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)3034 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)3035 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)3036 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)3037 --- PASS: TestGenerateFingerprint/no_references (0.00s)3038 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)3039 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)3040=== PAUSE TestExternalSignerErrors/wrong_signatures_shape3041=== RUN TestExternalSignerErrors/wrong_signature_name3042=== PAUSE TestExternalSignerErrors/wrong_signature_name3043=== RUN TestExternalSignerErrors/wrong_id3044=== PAUSE TestExternalSignerErrors/wrong_id3045=== RUN TestExternalSignerErrors/null_signatures3046=== PAUSE TestExternalSignerErrors/null_signatures3047=== RUN TestExternalSignerErrors/unrequested_key3048=== PAUSE TestExternalSignerErrors/unrequested_key3049=== CONT TestExternalSignerErrors/wrong_signature_length3050=== CONT TestExternalSignerErrors/program_error3051=== CONT TestExternalSignerErrors/wrong_signature_name3052=== CONT TestExternalSignerErrors/too_few_signatures3053=== CONT TestExternalSignerErrors/exit_on_request3054=== CONT TestExternalSignerErrors/null3055=== CONT TestExternalSignerErrors/missing_signature_name3056=== CONT TestExternalSignerErrors/missing_signatures3057=== CONT TestExternalSignerErrors/null_signatures3058=== CONT TestExternalSignerErrors/unrequested_key3059=== CONT TestExternalSignerErrors/wrong_shape3060--- PASS: TestExternalSignerWrongPublicKey (0.01s)3061=== CONT TestExternalSignerErrors/exit_at_startup3062=== CONT TestExternalSignerErrors/invalid_signature_base643063=== CONT TestExternalSignerErrors/wrong_id3064=== CONT TestExternalSignerErrors/wrong_signatures_shape3065=== CONT TestExternalSignerErrors/invalid_JSON3066--- PASS: TestExternalSignerClose (0.01s)3067--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)3068=== RUN TestSignErrors/nil_key3069=== PAUSE TestSignErrors/nil_key3070=== RUN TestSignErrors/nil_narinfo3071=== PAUSE TestSignErrors/nil_narinfo3072=== RUN TestSignErrors/invalid_narinfo3073--- PASS: TestParseSigningKey (0.00s)3074 --- PASS: TestParseSigningKey/no_colon (0.00s)3075 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)3076 --- PASS: TestParseSigningKey/empty_name (0.00s)3077 --- PASS: TestParseSigningKey/wrong_length (0.00s)3078 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.01s)3079 --- PASS: TestParseSigningKey/valid_32-byte_key (0.01s)3080=== PAUSE TestSignErrors/invalid_narinfo3081--- PASS: TestExternalSignerErrors (0.00s)3082 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)3083 --- PASS: TestExternalSignerErrors/program_error (0.01s)3084 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)3085 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)3086 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)3087 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)3088 --- PASS: TestExternalSignerErrors/null (0.01s)3089 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)3090 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)3091 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)3092 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)3093 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)3094 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)3095 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)3096 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)3097 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)3098=== RUN TestSignErrors/canceled3099=== PAUSE TestSignErrors/canceled3100=== CONT TestSignErrors/nil_narinfo3101=== CONT TestSignErrors/invalid_narinfo3102=== CONT TestSignErrors/canceled3103=== CONT TestSignErrors/nil_key3104--- PASS: TestSignErrors (0.02s)3105 --- PASS: TestSignErrors/nil_narinfo (0.00s)3106 --- PASS: TestSignErrors/invalid_narinfo (0.00s)3107 --- PASS: TestSignErrors/canceled (0.00s)3108 --- PASS: TestSignErrors/nil_key (0.00s)3109--- PASS: TestSign (0.02s)3110--- PASS: TestExternalSigner (0.02s)3111--- PASS: TestExternalSignerCancellation (0.02s)3112--- PASS: TestSignBatch (0.03s)3113PASS3114Running OpenBao signer tests...3115=== RUN TestSign3116=== PAUSE TestSign3117=== RUN TestSignErrors3118=== PAUSE TestSignErrors3119=== RUN TestServe3120=== PAUSE TestServe3121=== RUN TestServeRejectsGarbage3122=== PAUSE TestServeRejectsGarbage3123=== CONT TestSign3124=== CONT TestServe3125=== CONT TestServeRejectsGarbage3126=== CONT TestSignErrors3127--- PASS: TestServeRejectsGarbage (0.00s)3128=== RUN TestSignErrors/http_error3129=== PAUSE TestSignErrors/http_error3130=== RUN TestSignErrors/invalid_json3131=== PAUSE TestSignErrors/invalid_json3132=== RUN TestSignErrors/no_prefix3133=== PAUSE TestSignErrors/no_prefix3134=== RUN TestSignErrors/invalid_base643135=== PAUSE TestSignErrors/invalid_base643136=== CONT TestSignErrors/invalid_json3137=== CONT TestSignErrors/no_prefix3138--- PASS: TestServe (0.00s)3139=== CONT TestSignErrors/http_error3140=== CONT TestSignErrors/invalid_base643141--- PASS: TestSign (0.01s)3142--- PASS: TestSignErrors (0.00s)3143 --- PASS: TestSignErrors/no_prefix (0.00s)3144 --- PASS: TestSignErrors/invalid_json (0.00s)3145 --- PASS: TestSignErrors/http_error (0.00s)3146 --- PASS: TestSignErrors/invalid_base64 (0.00s)3147PASS3148Running niks3-hook command tests...3149=== RUN TestServeSecondSignalEndsDrain3150=== PAUSE TestServeSecondSignalEndsDrain3151=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown3152=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown3153=== CONT TestServeSecondSignalEndsDrain3154=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown3155--- PASS: TestServeSecondSignalEndsDrain (0.08s)31562026/10/08 21:40:37 INFO Upload queue status pending=131572026/10/08 21:40:37 INFO Uploading batch count=13158--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.13s)3159PASS3160Running rate limiter tests...3161=== RUN TestAdaptiveRateLimiter_ThreadSafety3162=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3163=== CONT TestAdaptiveRateLimiter_ThreadSafety31642026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=102.4870000000000531652026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=71.7409000000000231662026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=50.2186300000000131672026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=35.1530410000000131682026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=24.60712870000000431692026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=17.22499009000000231702026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=12.05749306331712026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=8.440245144131722026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=5.9081716008731732026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531742026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531752026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531762026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531772026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531782026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531792026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531802026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531812026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531822026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531832026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531842026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531852026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531862026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531872026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531882026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531892026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531902026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531912026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531922026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531932026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531942026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531952026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531962026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531972026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531982026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=531992026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532002026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532012026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532022026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532032026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532042026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532052026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532062026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532072026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532082026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532092026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532102026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532112026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532122026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532132026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532142026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532152026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532162026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=5.12435000000000132172026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532182026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532192026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532202026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532212026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532222026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532232026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532242026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532252026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532262026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532272026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532282026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532292026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532302026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532312026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532322026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=6.82050985000000232332026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532342026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532352026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532362026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532372026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532382026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532392026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532402026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532412026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532422026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532432026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532442026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532452026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532462026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532472026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532482026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532492026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532502026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532512026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532522026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532532026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=6.82050985000000232542026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532552026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532562026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532572026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532582026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532592026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532602026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532612026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532622026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=532632026/10/08 21:40:38 WARN Rate limiter backed off name=test rate=53264--- PASS: TestAdaptiveRateLimiter_ThreadSafety (1.96s)3265PASS