niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #448
· 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_FailedPartBufferNotReused22=== PAUSE TestUploadMultipart_FailedPartBufferNotReused23=== RUN TestUploadMultipart_ProducerErrorIsNotEOF24=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestUploadMultipart_SupersededByPeer28=== PAUSE TestUploadMultipart_SupersededByPeer29=== RUN TestDumpPathCaseHackMatchesNix30--- PASS: TestDumpPathCaseHackMatchesNix (0.09s)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.56s)46=== RUN TestEncodeNixBase3247=== PAUSE TestEncodeNixBase3248=== RUN TestEncodeNixBase32WithRealHash49=== PAUSE TestEncodeNixBase32WithRealHash50=== RUN TestConvertHashToNix3251=== PAUSE TestConvertHashToNix3252=== RUN TestGetStorePathHash53=== PAUSE TestGetStorePathHash54=== RUN TestPathInfoHashCompatibility55=== PAUSE TestPathInfoHashCompatibility56=== RUN TestParsePathInfoJSON57=== PAUSE TestParsePathInfoJSON58=== RUN TestParsePathInfoJSONMultiplePaths59=== PAUSE TestParsePathInfoJSONMultiplePaths60=== RUN TestPathInfoCACompatibility61=== PAUSE TestPathInfoCACompatibility62=== RUN TestUploadPendingObjectsStopsStartingAfterFailure63--- PASS: TestUploadPendingObjectsStopsStartingAfterFailure (0.02s)64=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent65=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent66=== RUN TestCompletePendingClosure_NotFoundWithoutKey67=== PAUSE TestCompletePendingClosure_NotFoundWithoutKey68=== RUN TestRateLimiterFeedback69=== PAUSE TestRateLimiterFeedback70=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess71=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess72=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer73=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer74=== RUN TestResolveStorePath75=== PAUSE TestResolveStorePath76=== RUN TestDoWithRetry_BodyReplayedViaGetBody77=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody78=== RUN TestRetryTimeoutOutlastsMaxRetries79=== PAUSE TestRetryTimeoutOutlastsMaxRetries80=== RUN TestDoWithRetry_FinalResponseBodyReadable81=== PAUSE TestDoWithRetry_FinalResponseBodyReadable82=== RUN TestShellSplit83=== PAUSE TestShellSplit84=== RUN TestShellSplitErrors85=== PAUSE TestShellSplitErrors86=== RUN TestStreamPushReportsEveryPath87=== PAUSE TestStreamPushReportsEveryPath88=== RUN TestStreamPushBatchesUnderLoad89=== PAUSE TestStreamPushBatchesUnderLoad90=== RUN TestStreamPushIsolatesFailures91=== PAUSE TestStreamPushIsolatesFailures92=== RUN TestStreamPushGivesUpOnDeadServer93=== PAUSE TestStreamPushGivesUpOnDeadServer94=== RUN TestStreamPushRequestLine95=== PAUSE TestStreamPushRequestLine96=== RUN TestStreamPushReportsSignatures97=== PAUSE TestStreamPushReportsSignatures98=== RUN TestStreamPushReportsSkippedPaths99=== PAUSE TestStreamPushReportsSkippedPaths100=== RUN TestClientSignaturesByStorePath101=== PAUSE TestClientSignaturesByStorePath102=== RUN TestStreamPushStopsWhenCanceled103=== PAUSE TestStreamPushStopsWhenCanceled104=== RUN TestStreamPushStopsOnCancel105=== PAUSE TestStreamPushStopsOnCancel106=== RUN TestStreamPushStartsNothingOnSlotFreedByCancel107=== PAUSE TestStreamPushStartsNothingOnSlotFreedByCancel108=== 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 TestSetClientTLSDoesNotMutateDefaultTransport137=== CONT TestScriptTokenNoExpiryRerunsEveryCall138=== CONT TestShellSplit139=== CONT TestParsePathInfoJSON140--- PASS: TestShellSplit (0.00s)141=== RUN TestParsePathInfoJSON/Nix_format142=== CONT TestUploadMultipart_ProducerErrorIsNotEOF143=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part144=== CONT TestUploadMultipart_PartsInParallel145=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess146=== CONT TestScriptTokenDoesNotWaitForItsChildren147=== CONT TestStaticToken148=== CONT TestScriptTokenEmptyToken149=== CONT TestSupersededNARStillUploadsListing150--- PASS: TestStaticToken (0.00s)151=== CONT TestScriptTokenScriptFails152=== CONT TestScriptTokenEmptyCommand153--- PASS: TestScriptTokenEmptyCommand (0.00s)154=== CONT TestStreamPushStopsWhenCanceled155=== CONT TestStreamPushGivesUpOnDeadServer156=== CONT TestUploadMultipart_FailedPartBufferNotReused157=== CONT TestEncodeNixBase32158=== CONT TestTruncatedNARDumpIsNotCompleted159=== CONT TestFileTokenEmpty160=== CONT TestStreamPushIsolatesFailures161=== CONT TestShellSplitErrors162=== CONT TestCaseHackSuffix163=== CONT TestDoServerRequestAttachesToken164=== CONT TestParsePathInfoJSONMultiplePaths165=== CONT TestPathInfoHashCompatibility166=== PAUSE TestParsePathInfoJSON/Nix_format167=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part168=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs169=== CONT TestClientSignaturesByStorePath170=== RUN TestSupersededNARStillUploadsListing/small_NAR171=== CONT TestStreamPushStopsOnCancel172=== RUN TestEncodeNixBase32/test_string_hash173=== CONT TestFileTokenReadsAndCaches174--- PASS: TestStreamPushStopsWhenCanceled (0.00s)175=== CONT TestStreamPushReportsSkippedPaths176=== CONT TestScriptTokenBadJSON177=== CONT TestStreamPushRequestLine178=== CONT TestPathInfoCACompatibility179=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths180=== CONT TestResolveStorePath181=== CONT TestDumpPathSingleFile182=== CONT TestStreamPushBatchesUnderLoad183=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false184=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths185=== CONT TestStreamPushReportsSignatures186=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure187=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths188=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)189=== RUN TestParsePathInfoJSON/Lix_format190=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary191=== PAUSE TestParsePathInfoJSON/Lix_format192=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false193=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs194=== CONT TestConvertHashToNix32195=== PAUSE TestSupersededNARStillUploadsListing/small_NAR196=== PAUSE TestEncodeNixBase32/test_string_hash197=== CONT TestEncodeNixBase32WithRealHash198=== RUN TestStreamPushStopsOnCancel/waiting_for_input199=== RUN TestPathInfoCACompatibility/null_ca_field200--- PASS: TestStreamPushReportsSkippedPaths (0.00s)201=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths202=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout203--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.26s)204=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)205=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary206=== RUN TestParsePathInfoJSON/empty_input207=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true208=== CONT TestDumpPathMatchesNix209=== RUN TestConvertHashToNix32/SRI_format_to_Nix32210=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input211=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32212=== RUN TestSupersededNARStillUploadsListing/dump_cut_short213=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short214=== RUN TestEncodeNixBase32/empty_input215=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails216=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails217=== PAUSE TestEncodeNixBase32/empty_input218=== CONT TestFilterOversizedClosures219=== CONT TestDoWithRetry_BodyReplayedViaGetBody220=== RUN TestFilterOversizedClosures/no_limit_keeps_everything221=== CONT TestPartSizeForNAR222=== RUN TestPartSizeForNAR/zero_stays_at_minimum223=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything224=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout225--- PASS: TestFileTokenReadsAndCaches (0.00s)226=== CONT TestUploadMultipart_SupersededByPeer227=== RUN TestUploadMultipart_SupersededByPeer/exists228=== PAUSE TestPathInfoCACompatibility/null_ca_field229=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true230=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon231=== RUN TestPathInfoCACompatibility/old_string_format_-_text232=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon233=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text234=== CONT TestScriptTokenCachesUntilRefresh235=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive236=== CONT TestRateLimiterFeedback237=== RUN TestRateLimiterFeedback/429_enables_limiter238=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot239=== CONT TestStreamPushReportsEveryPath240=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot241=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer242=== CONT TestDumpPathWriterError243=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum244=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped245=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped246=== CONT TestStreamPushStartsNothingOnSlotFreedByCancel247=== CONT TestFileTokenMissing248--- PASS: TestFileTokenEmpty (0.00s)249=== PAUSE TestUploadMultipart_SupersededByPeer/exists250=== RUN TestFilterOversizedClosures/all_closures_skipped251=== PAUSE TestParsePathInfoJSON/empty_input252=== PAUSE TestFilterOversizedClosures/all_closures_skipped253=== RUN TestParsePathInfoJSON/whitespace_only254=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica255=== RUN TestConvertHashToNix32/already_Nix32_format256=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive257=== PAUSE TestRateLimiterFeedback/429_enables_limiter258=== RUN TestPathInfoCACompatibility/new_structured_format_-_text259=== RUN TestRateLimiterFeedback/503_enables_limiter260=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text261=== PAUSE TestRateLimiterFeedback/503_enables_limiter262=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method263=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method264=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot265=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter266=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter267=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot268=== RUN TestPartSizeForNAR/small_stays_at_minimum269=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter270--- PASS: TestShellSplitErrors (0.00s)271--- PASS: TestClientSignaturesByStorePath (0.00s)272=== RUN TestUploadMultipart_SupersededByPeer/missing273=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI274=== PAUSE TestParsePathInfoJSON/whitespace_only275=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI276=== PAUSE TestConvertHashToNix32/already_Nix32_format277=== RUN TestConvertHashToNix32/invalid_format278=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun279=== PAUSE TestConvertHashToNix32/invalid_format280=== CONT TestCompletePendingClosure_NotFoundWithoutKey281=== CONT TestDoWithRetry_FinalResponseBodyReadable282=== PAUSE TestPartSizeForNAR/small_stays_at_minimum283=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum284=== CONT TestRegisterUploadedObjectReusesConnections285=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot286=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter287--- PASS: TestStreamPushIsolatesFailures (0.24s)288=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot289=== PAUSE TestUploadMultipart_SupersededByPeer/missing290=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum291=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot292=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot293=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken294=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken295=== CONT TestSetClientTLS296=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry297=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512298=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512299=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts300=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts301=== RUN TestPartSizeForNAR/1_TiB302=== PAUSE TestPartSizeForNAR/1_TiB303--- PASS: TestScriptTokenEmptyToken (0.24s)304=== CONT TestRetryTimeoutOutlastsMaxRetries305=== RUN TestPartSizeForNAR/5_TiB_S3_max_object306=== RUN TestParsePathInfoJSON/invalid_JSON307=== CONT TestGetStorePathHash308=== RUN TestGetStorePathHash/valid_store_path309--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.26s)310=== CONT TestSetClientTLSErrors311=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object312=== RUN TestPartSizeForNAR/capped_at_5_GiB313=== PAUSE TestPartSizeForNAR/capped_at_5_GiB314=== PAUSE TestParsePathInfoJSON/invalid_JSON315=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent316=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier317=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths318=== PAUSE TestGetStorePathHash/valid_store_path319=== RUN TestGetStorePathHash/basename_without_hyphen_should_error320=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error321=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error322=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error323--- PASS: TestStreamPushGivesUpOnDeadServer (0.24s)324=== RUN TestSetClientTLSErrors/missing_cert_file325=== PAUSE TestSetClientTLSErrors/missing_cert_file326=== RUN TestSetClientTLSErrors/missing_key_file327=== PAUSE TestSetClientTLSErrors/missing_key_file328=== RUN TestSetClientTLSErrors/missing_ca_file329=== PAUSE TestSetClientTLSErrors/missing_ca_file330=== RUN TestSetClientTLSErrors/invalid_ca_file331=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths332=== PAUSE TestSetClientTLSErrors/invalid_ca_file333=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary334=== CONT TestSupersededNARStillUploadsListing/small_NAR335=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails336=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier337=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part338=== CONT TestSupersededNARStillUploadsListing/dump_cut_short339=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error340--- PASS: TestScriptTokenScriptFails (0.00s)341--- PASS: TestResolveStorePath (0.00s)342--- PASS: TestDoServerRequestAttachesToken (0.00s)343--- PASS: TestEncodeNixBase32WithRealHash (0.00s)344--- PASS: TestScriptTokenBadJSON (0.00s)345--- PASS: TestStreamPushReportsSignatures (0.00s)346--- PASS: TestStreamPushReportsEveryPath (0.00s)347--- PASS: TestFileTokenMissing (0.00s)348--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)349--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.00s)350--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)351--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)352--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)353--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)354 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)355 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)356=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up357=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up358=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier359--- PASS: TestCaseHackSuffix (0.33s)360=== CONT TestEncodeNixBase32/test_string_hash361=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier362=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client363=== RUN TestSetClientTLS/rejects_connection_without_client_cert364=== CONT TestEncodeNixBase32/empty_input365=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout366--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.32s)367=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client368=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs369=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client370=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client371=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true372=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert373=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA374=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA375=== RUN TestSetClientTLS/preserves_debug_logging_transport376=== PAUSE TestSetClientTLS/preserves_debug_logging_transport377--- PASS: TestEncodeNixBase32 (0.25s)378 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)379 --- PASS: TestEncodeNixBase32/empty_input (0.00s)380=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false381=== CONT TestFilterOversizedClosures/no_limit_keeps_everything382=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped383=== CONT TestFilterOversizedClosures/all_closures_skipped384=== CONT TestPathInfoCACompatibility/null_ca_field385--- PASS: TestFilterOversizedClosures (0.00s)386 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)387 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)388 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)389=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method390=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive391=== CONT TestPathInfoCACompatibility/new_structured_format_-_text392=== CONT TestPathInfoCACompatibility/old_string_format_-_text393=== CONT TestConvertHashToNix32/invalid_format394--- PASS: TestStreamPushBatchesUnderLoad (0.00s)395 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)396 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)397=== CONT TestConvertHashToNix32/already_Nix32_format398=== CONT TestConvertHashToNix32/SRI_format_to_Nix32399=== CONT TestRateLimiterFeedback/503_enables_limiter400=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter401--- PASS: TestPathInfoCACompatibility (0.01s)402 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)403 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)404 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)405 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)406 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)407=== CONT TestUploadMultipart_SupersededByPeer/exists408--- PASS: TestDumpPathSingleFile (0.34s)409--- PASS: TestConvertHashToNix32 (0.00s)410 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)411 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)412 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)413=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error414=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter415=== CONT TestRateLimiterFeedback/429_enables_limiter416=== CONT TestUploadMultipart_SupersededByPeer/missing417=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken418=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon419=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512420=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI421--- PASS: TestRateLimiterFeedback (0.00s)422 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)423 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)424 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)425 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)426=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot427=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)428=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot429--- PASS: TestPathInfoHashCompatibility (0.01s)430 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)431 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)432 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)433 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)434=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot435--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)436 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)437 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)438=== CONT TestPartSizeForNAR/zero_stays_at_minimum439--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.33s)440=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot441=== CONT TestSetClientTLSErrors/missing_cert_file442=== CONT TestSetClientTLSErrors/invalid_ca_file443=== CONT TestParsePathInfoJSON/Nix_format444=== CONT TestPartSizeForNAR/5_TiB_S3_max_object445=== CONT TestPartSizeForNAR/capped_at_5_GiB446=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts447=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum448=== CONT TestPartSizeForNAR/1_TiB449=== CONT TestPartSizeForNAR/small_stays_at_minimum450=== CONT TestSetClientTLSErrors/missing_key_file451=== CONT TestSetClientTLSErrors/missing_ca_file452=== CONT TestParsePathInfoJSON/invalid_JSON453=== CONT TestParsePathInfoJSON/whitespace_only454=== CONT TestParsePathInfoJSON/empty_input455=== CONT TestParsePathInfoJSON/Lix_format456--- PASS: TestPartSizeForNAR (0.01s)457 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)458 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)459 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)460 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)461 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)462 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)463 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)464=== CONT TestStreamPushStopsOnCancel/waiting_for_input465--- PASS: TestParsePathInfoJSON (0.27s)466 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)467 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)468 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)469 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)470 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)471=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up472--- PASS: TestSetClientTLSErrors (0.00s)473 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)474 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)475 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)476 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)477=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client478=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client479=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier480=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier481=== CONT TestSetClientTLS/rejects_connection_without_client_cert482--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.32s)483 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.00s)484 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.00s)485 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.00s)486 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.00s)487 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.00s)488--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.36s)489=== CONT TestSetClientTLS/preserves_debug_logging_transport490--- PASS: TestDumpPathWriterError (0.38s)491=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA492=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error493=== CONT TestGetStorePathHash/basename_without_hyphen_should_error494=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error495=== CONT TestGetStorePathHash/valid_store_path496--- PASS: TestGetStorePathHash (0.33s)497 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)498 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)499 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)500 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)501--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.26s)502 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.38s)503 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.38s)504--- PASS: TestStreamPushStopsOnCancel (0.01s)505 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.05s)506 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.05s)507 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.05s)508 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.05s)509 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)510 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.05s)511--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.40s)512--- PASS: TestStreamPushStartsNothingOnSlotFreedByCancel (0.41s)513--- PASS: TestSetClientTLS (0.32s)514 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)515 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)516 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.09s)517--- PASS: TestRegisterUploadedObjectReusesConnections (0.46s)518--- PASS: TestDumpPathMatchesNix (0.47s)519--- PASS: TestStreamPushRequestLine (0.52s)520--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.06s)521--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)522--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.29s)523--- PASS: TestUploadMultipart_PartsInParallel (1.31s)524--- PASS: TestSupersededNARStillUploadsListing (0.25s)525 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.33s)526 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.33s)527 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.14s)528--- PASS: TestTruncatedNARDumpIsNotCompleted (1.40s)529--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.26s)530 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.01s)531 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.20s)532PASS533Running server tests...534The files belonging to this database system will be owned by user "nixbld".535This user must also own the server process.536537The database cluster will be initialized with locale "C".538The default database encoding has accordingly been set to "SQL_ASCII".539The default text search configuration will be set to "english".540541Data page checksums are enabled.542543creating directory /build/postgres4134566529/data ... ok544creating subdirectories ... ok545selecting dynamic shared memory implementation ... posix546selecting default "max_connections" ... 100547selecting default "shared_buffers" ... 128MB548selecting default time zone ... UTC549creating configuration files ... ok550running bootstrap script ... ok551performing post-bootstrap initialization ... ok552syncing data to disk ... ok553554initdb: warning: enabling "trust" authentication for local connections555initdb: 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.556557Success. You can now start the database server using:558559 pg_ctl -D /build/postgres4134566529/data -l logfile start560561/build/postgres4134566529:5432 - no response5622026-10-29 01:21:43.388 UTC [169] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5632026-10-29 01:21:43.388 UTC [169] LOG: listening on Unix socket "/build/postgres4134566529/.s.PGSQL.5432"5642026-10-29 01:21:43.393 UTC [176] LOG: database system was shut down at 2026-10-29 01:21:43 UTC5652026-10-29 01:21:43.397 UTC [169] LOG: database system is ready to accept connections566/build/postgres4134566529:5432 - accepting connections567{"timestamp":"2026-10-29T01:21:49.763064757Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"b5c3958a-22d4-4605-b719-3f3e0a7ba0b8","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":1,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(196)"}568=== RUN TestService_AuthMiddleware569=== PAUSE TestService_AuthMiddleware570=== RUN TestService_AuthMiddleware_MTLSProxyHeader571=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader572=== RUN TestService_AuthMiddleware_MTLSBoundSubjects573=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects574=== RUN TestService_ReadAuthMiddleware575=== PAUSE TestService_ReadAuthMiddleware576=== RUN TestService_AuthMiddleware_OIDC577=== PAUSE TestService_AuthMiddleware_OIDC578=== RUN TestService_RequireScope_OIDC579=== PAUSE TestService_RequireScope_OIDC580=== RUN TestService_ReadScope_PublicByDefault581=== PAUSE TestService_ReadScope_PublicByDefault582=== RUN TestCacheConfigHandler583=== PAUSE TestCacheConfigHandler584=== RUN TestCacheStatsHandler585=== PAUSE TestCacheStatsHandler586=== RUN TestClientCADerivations587=== PAUSE TestClientCADerivations588=== RUN TestClientErrorHandling589=== PAUSE TestClientErrorHandling590=== RUN TestClientIntegration591=== PAUSE TestClientIntegration592=== RUN TestClientMultipleUploads593=== PAUSE TestClientMultipleUploads594=== RUN TestClientWithDependencies595=== PAUSE TestClientWithDependencies596=== RUN TestClientSharedPathCommittedMidPush597=== PAUSE TestClientSharedPathCommittedMidPush598=== RUN TestPinProtectsFromGC599=== PAUSE TestPinProtectsFromGC600=== RUN TestClientPushesUseOnePush601=== PAUSE TestClientPushesUseOnePush602=== RUN TestClientFallsBackToClosures603=== PAUSE TestClientFallsBackToClosures604=== RUN TestDeleteClosuresRacingPins605=== PAUSE TestDeleteClosuresRacingPins606=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock607=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock608=== RUN TestResolveDBConnectionString609=== PAUSE TestResolveDBConnectionString610=== RUN TestConnectWaitsForAPeerMigration611=== PAUSE TestConnectWaitsForAPeerMigration612=== RUN TestConnectSerialisesConcurrentMigrations613=== PAUSE TestConnectSerialisesConcurrentMigrations614=== RUN TestLeadElectsOneAndHandsOver615=== PAUSE TestLeadElectsOneAndHandsOver616=== RUN TestLeadIncumbentWinsAfterRestart6172026/10/29 01:21:50 INFO lead: acquired remote=192.0.2.1:12346182026/10/29 01:21:50 INFO lead: released remote=192.0.2.1:12346192026/10/29 01:21:50 INFO lead: acquired remote=192.0.2.1:12346202026/10/29 01:21:51 INFO lead: released remote=192.0.2.1:1234621--- PASS: TestLeadIncumbentWinsAfterRestart (1.94s)622=== RUN TestLeadIncumbentAnnouncesAtOnce623=== PAUSE TestLeadIncumbentAnnouncesAtOnce624=== RUN TestLeadEndsOnShutdown625=== PAUSE TestLeadEndsOnShutdown626=== RUN TestLeadEndsWhenItsConnectionHangs6272026/10/29 01:21:51 INFO lead: acquired remote=192.0.2.1:12346282026-10-29 01:21:53.347 UTC [428] FATAL: terminating connection due to administrator command6292026/10/29 01:21:53 INFO lead: acquired remote=192.0.2.1:12346302026/10/29 01:21:54 WARN lead: lock connection lost error="timeout: context deadline exceeded"6312026/10/29 01:21:54 INFO lead: released remote=192.0.2.1:12346322026/10/29 01:21:54 INFO lead: released remote=192.0.2.1:1234633--- PASS: TestLeadEndsWhenItsConnectionHangs (2.95s)634=== RUN TestGCAdvisoryLockBlocksConcurrentRun635=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun636=== RUN TestGCBugBareHashReferences637=== PAUSE TestGCBugBareHashReferences638=== RUN TestGCMetrics639=== PAUSE TestGCMetrics640=== RUN TestPushDedupSurvivesConcurrentGC641=== PAUSE TestPushDedupSurvivesConcurrentGC642=== RUN TestDeduplicatedObjectsRecordedAsPending643=== PAUSE TestDeduplicatedObjectsRecordedAsPending644=== RUN TestGCSweepSkipsPendingObjects645=== PAUSE TestGCSweepSkipsPendingObjects646=== RUN TestTombstonedObjectOfferedWithoutWaiting647=== PAUSE TestTombstonedObjectOfferedWithoutWaiting648=== RUN TestGCSweepDeliversEachKeyOnce649=== PAUSE TestGCSweepDeliversEachKeyOnce650=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection651=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection652=== RUN TestForceGCDuringPushOffersSweptObject653=== PAUSE TestForceGCDuringPushOffersSweptObject654=== RUN TestFailedS3DeleteKeepsTombstone655=== PAUSE TestFailedS3DeleteKeepsTombstone656=== RUN TestSweepSkipsRowsLockedByPush657=== PAUSE TestSweepSkipsRowsLockedByPush658=== RUN TestRegisterCompletedObjectNeedsPendingRow659=== PAUSE TestRegisterCompletedObjectNeedsPendingRow660=== RUN TestGetExistingObjectsLocksRows661=== PAUSE TestGetExistingObjectsLocksRows662=== RUN TestSweepRechecksPendingAfterLocking663=== PAUSE TestSweepRechecksPendingAfterLocking664=== RUN TestPushWaitsForSweepHoldingRow665=== PAUSE TestPushWaitsForSweepHoldingRow666=== RUN TestCommitRacingPendingCleanupKeepsObjects667=== PAUSE TestCommitRacingPendingCleanupKeepsObjects668=== RUN TestGCEndsOnShutdown669=== PAUSE TestGCEndsOnShutdown670=== RUN TestGCTaskStore_StartNew671=== PAUSE TestGCTaskStore_StartNew672=== RUN TestGCTaskStore_DeduplicateSameParams673=== PAUSE TestGCTaskStore_DeduplicateSameParams674=== RUN TestGCTaskStore_ConflictDifferentParams675=== PAUSE TestGCTaskStore_ConflictDifferentParams676=== RUN TestGCTaskStore_GetEmpty677=== PAUSE TestGCTaskStore_GetEmpty678=== RUN TestGCTaskStore_GetReturnsLatest679=== PAUSE TestGCTaskStore_GetReturnsLatest680=== RUN TestGCTaskStore_CompletedAllowsNewTask681=== PAUSE TestGCTaskStore_CompletedAllowsNewTask682=== RUN TestGCTaskStore_PhaseUpdates683=== PAUSE TestGCTaskStore_PhaseUpdates684=== RUN TestGCTaskStore_Fail685=== PAUSE TestGCTaskStore_Fail686=== RUN TestGracefulShutdownDrainsInflight687=== PAUSE TestGracefulShutdownDrainsInflight688=== RUN TestService_healthCheckHandler689=== PAUSE TestService_healthCheckHandler690=== RUN TestService_readinessHandler691=== PAUSE TestService_readinessHandler692=== RUN TestGenerateLandingPage693=== PAUSE TestGenerateLandingPage694=== RUN TestChildrenInheritRaisedFileLimit695=== PAUSE TestChildrenInheritRaisedFileLimit696=== RUN TestCacheConfigHandlerMaxNarSize697=== PAUSE TestCacheConfigHandlerMaxNarSize698=== RUN TestCreatePendingClosureRejectsOversizedNAR699=== PAUSE TestCreatePendingClosureRejectsOversizedNAR700=== RUN TestNARDeduplicationMetadataUploadBug701=== PAUSE TestNARDeduplicationMetadataUploadBug702=== RUN TestMetricsInventory703=== PAUSE TestMetricsInventory704=== RUN TestMetricsCommit705=== PAUSE TestMetricsCommit706=== RUN TestService_NativeMTLS707=== PAUSE TestService_NativeMTLS708=== RUN TestServerTLSConfig709=== PAUSE TestServerTLSConfig710=== RUN TestMultipartCleanup711=== PAUSE TestMultipartCleanup712=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded713=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded714=== RUN TestPendingCleanupUsesOneCutoff715=== PAUSE TestPendingCleanupUsesOneCutoff716=== RUN TestPendingClosureFailureTracksEveryUpload717=== PAUSE TestPendingClosureFailureTracksEveryUpload718=== RUN TestPendingClosureFailureAbortsItsUploads719=== PAUSE TestPendingClosureFailureAbortsItsUploads720=== RUN TestObjectStatsTrigger721=== PAUSE TestObjectStatsTrigger722=== RUN TestObjectStatsUpdatedOncePerCommit723=== PAUSE TestObjectStatsUpdatedOncePerCommit724=== RUN TestReconnectLeavesObjectsUnlocked725=== PAUSE TestReconnectLeavesObjectsUnlocked726=== RUN TestOrphanedObjectsGC727=== PAUSE TestOrphanedObjectsGC728=== RUN TestOrphanedObjectsGCStressTest729=== PAUSE TestOrphanedObjectsGCStressTest730=== RUN TestCreatePin_ReservedPins731=== PAUSE TestCreatePin_ReservedPins732=== RUN TestConcurrentPinUpdatesAgree733=== PAUSE TestConcurrentPinUpdatesAgree734=== RUN TestCreatePinRejectsBadInput735=== PAUSE TestCreatePinRejectsBadInput736=== RUN TestDeletePinKeepsRowWhenS3Fails737=== PAUSE TestDeletePinKeepsRowWhenS3Fails738=== RUN TestPresentReportsOnlyClosureRoots739=== PAUSE TestPresentReportsOnlyClosureRoots740=== RUN TestPresentRefreshesOnlyStaleClosures741=== PAUSE TestPresentRefreshesOnlyStaleClosures742=== RUN TestPresentNotReportedWhileGCDeletesClosure743=== PAUSE TestPresentNotReportedWhileGCDeletesClosure744=== RUN TestParseSingleRange745=== PAUSE TestParseSingleRange746=== RUN TestProxyHeadersOnlyTrustedOnSocket7472026/10/29 01:21:54 INFO Starting HTTP server address=127.0.0.1:451317482026/10/29 01:21:54 INFO Starting HTTP server address=proxy.sock7492026/10/29 01:21:54 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7502026/10/29 01:21:54 INFO Shutdown signal received, draining in-flight requests timeout=10s751--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.15s)752=== RUN TestIsValidCachePath753=== PAUSE TestIsValidCachePath754=== RUN TestReadProxyNarinfo755=== PAUSE TestReadProxyNarinfo756=== RUN TestReadProxyNarinfoAlreadyDecompressed757=== PAUSE TestReadProxyNarinfoAlreadyDecompressed758=== RUN TestReadProxyContentNegotiation759=== PAUSE TestReadProxyContentNegotiation760=== RUN TestReadProxyNarStreaming761=== PAUSE TestReadProxyNarStreaming762=== RUN TestReadProxy404And429763=== PAUSE TestReadProxy404And429764=== RUN TestReadProxyInvalidPath765=== PAUSE TestReadProxyInvalidPath766=== RUN TestReadProxyHead767=== PAUSE TestReadProxyHead768=== RUN TestReadProxyOutlastsServerWriteTimeout769=== PAUSE TestReadProxyOutlastsServerWriteTimeout770=== RUN TestReadProxyConditionalGet771=== PAUSE TestReadProxyConditionalGet772=== RUN TestReadProxyRootRedirectsToIndexHTML773=== PAUSE TestReadProxyRootRedirectsToIndexHTML774=== RUN TestReadProxyDisabled775=== PAUSE TestReadProxyDisabled776=== RUN TestReadRedirectNar777=== PAUSE TestReadRedirectNar778=== RUN TestReadRedirectKeepsNarinfoProxied779=== PAUSE TestReadRedirectKeepsNarinfoProxied780=== RUN TestReadProxyRangeRequest781=== PAUSE TestReadProxyRangeRequest782=== RUN TestReadRedirectUsesPublicS3URL783=== PAUSE TestReadRedirectUsesPublicS3URL784=== RUN TestPush_OverlappingRootsStoreOneRowPerKey785=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey786=== RUN TestPush_CompleteCommitsEveryRoot787=== PAUSE TestPush_CompleteCommitsEveryRoot788=== RUN TestPush_RepeatedRootCommitsOnce789=== PAUSE TestPush_RepeatedRootCommitsOnce790=== RUN TestPush_CompleteWaitsForCleanupOfThePush791=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush792=== RUN TestPush_RootsAreLockedInByteOrder793=== PAUSE TestPush_RootsAreLockedInByteOrder794=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit795=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit796=== RUN TestPush_RejectsBadRequests797=== PAUSE TestPush_RejectsBadRequests798=== RUN TestPush_SignsNarinfosOfItsPendingObjects799=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects800=== RUN TestRedundantMultipartUpload801=== PAUSE TestRedundantMultipartUpload802=== RUN TestCompleteMultipartUpload_ErrorButObjectExists803=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists804=== RUN TestCompletedNarNotReofferedAcrossClosures805=== PAUSE TestCompletedNarNotReofferedAcrossClosures806=== RUN TestPresignedUploadRegisteredBeforeCommit807=== PAUSE TestPresignedUploadRegisteredBeforeCommit808=== RUN TestService_Rustfstest809=== PAUSE TestService_Rustfstest810=== RUN TestParseSize811=== PAUSE TestParseSize812=== RUN TestSkippedUploadsHandler813=== PAUSE TestSkippedUploadsHandler814=== RUN TestSystemdListenerNotActivated815--- PASS: TestSystemdListenerNotActivated (0.00s)816=== RUN TestWatchdogBeatsWhenHealthy817--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)818=== RUN TestWatchdogSkipsWhenUnhealthy8192026/10/29 01:21:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8202026/10/29 01:21:54 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8212026/10/29 01:21:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8222026/10/29 01:21:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8232026/10/29 01:21:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8242026/10/29 01:21:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8252026/10/29 01:21:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8262026/10/29 01:21:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8272026/10/29 01:21:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8282026/10/29 01:21:55 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"829--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)830=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle831=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle832=== RUN TestProxyWriteTimeout833=== PAUSE TestProxyWriteTimeout834=== RUN TestPendingClosureWriteTimeout835=== PAUSE TestPendingClosureWriteTimeout836=== RUN TestIsValidUploadKey837=== PAUSE TestIsValidUploadKey838=== RUN TestUploadHandlersRejectInvalidKeys839=== PAUSE TestUploadHandlersRejectInvalidKeys840=== RUN TestUploadHandlersRejectOversizedBody841=== PAUSE TestUploadHandlersRejectOversizedBody842=== RUN TestService_cleanupPendingClosuresHandler843=== PAUSE TestService_cleanupPendingClosuresHandler844=== RUN TestService_createPendingClosureHandler845=== PAUSE TestService_createPendingClosureHandler846=== RUN TestService_verifyS3Integrity847=== PAUSE TestService_verifyS3Integrity848=== RUN TestCompleteMultipartUnregistered849=== PAUSE TestCompleteMultipartUnregistered850=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT851=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT852=== CONT TestPresignedUploadRegisteredBeforeCommit853=== CONT TestCompleteMultipartUpload_ErrorButObjectExists854=== CONT TestReadProxyNarStreaming855=== CONT TestPresentNotReportedWhileGCDeletesClosure856=== CONT TestOrphanedObjectsGCStressTest857=== CONT TestReconnectLeavesObjectsUnlocked858=== CONT TestCompletedNarNotReofferedAcrossClosures859=== CONT TestPresentRefreshesOnlyStaleClosures860=== CONT TestPresentReportsOnlyClosureRoots861=== CONT TestDeletePinKeepsRowWhenS3Fails862=== CONT TestReadRedirectNar863=== CONT TestCreatePinRejectsBadInput864=== CONT TestReadProxyRootRedirectsToIndexHTML865=== CONT TestCreatePin_ReservedPins866=== CONT TestIsValidUploadKey867=== RUN TestIsValidUploadKey/narinfo868=== PAUSE TestIsValidUploadKey/narinfo869=== CONT TestReadProxyInvalidPath870=== RUN TestIsValidUploadKey/nar_zst871=== PAUSE TestIsValidUploadKey/nar_zst872=== RUN TestIsValidUploadKey/nar_xz873=== PAUSE TestIsValidUploadKey/nar_xz874=== RUN TestIsValidUploadKey/nar_plain875=== PAUSE TestIsValidUploadKey/nar_plain876=== RUN TestIsValidUploadKey/listing877=== PAUSE TestIsValidUploadKey/listing878=== RUN TestIsValidUploadKey/build_log879=== PAUSE TestIsValidUploadKey/build_log880=== RUN TestIsValidUploadKey/build_log_home-manager_file881=== PAUSE TestIsValidUploadKey/build_log_home-manager_file882=== RUN TestIsValidUploadKey/build_log_plus_in_name883=== PAUSE TestIsValidUploadKey/build_log_plus_in_name884=== RUN TestIsValidUploadKey/build_log_question_mark885=== PAUSE TestIsValidUploadKey/build_log_question_mark886=== RUN TestIsValidUploadKey/build_log_equals887=== PAUSE TestIsValidUploadKey/build_log_equals888=== RUN TestIsValidUploadKey/realisation889=== PAUSE TestIsValidUploadKey/realisation890=== RUN TestIsValidUploadKey/realisation_plus_in_output891=== PAUSE TestIsValidUploadKey/realisation_plus_in_output892=== RUN TestIsValidUploadKey/nix-cache-info893=== PAUSE TestIsValidUploadKey/nix-cache-info894=== RUN TestIsValidUploadKey/index.html895=== PAUSE TestIsValidUploadKey/index.html896=== RUN TestIsValidUploadKey/narinfo_key,_nar_type897=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type898=== RUN TestIsValidUploadKey/nar_key,_narinfo_type899=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type900=== RUN TestIsValidUploadKey/listing_key,_narinfo_type901=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type902=== RUN TestIsValidUploadKey/traversal903=== PAUSE TestIsValidUploadKey/traversal904=== RUN TestIsValidUploadKey/traversal_nar905=== PAUSE TestIsValidUploadKey/traversal_nar906=== RUN TestIsValidUploadKey/absolute907=== PAUSE TestIsValidUploadKey/absolute908=== RUN TestIsValidUploadKey/empty_key909=== PAUSE TestIsValidUploadKey/empty_key910=== RUN TestIsValidUploadKey/unknown_type911=== PAUSE TestIsValidUploadKey/unknown_type912=== CONT TestClientSharedPathCommittedMidPush913=== CONT TestOrphanedObjectsGC914=== CONT TestCompleteMultipartUnregistered915=== CONT TestReadProxyOutlastsServerWriteTimeout916=== CONT TestService_verifyS3Integrity917=== CONT TestReadProxy404And429918=== CONT TestService_createPendingClosureHandler919=== CONT TestObjectStatsTrigger920=== CONT TestService_AuthMiddleware_MTLSProxyHeader921=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale922=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale923=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh924=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh925=== CONT TestService_cleanupPendingClosuresHandler9262026/10/29 01:21:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46055/oidc9272026/10/29 01:21:56 INFO Received uploads request method=POST path=/api/pending_closures9282026/10/29 01:21:56 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9292026/10/29 01:21:56 INFO Received uploads request method=POST path=/api/pending_closures9302026/10/29 01:21:57 INFO Received create pin request method=POST path=/api/pins/app9312026/10/29 01:21:57 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo9322026/10/29 01:21:57 INFO Received delete pin request method=DELETE path=/api/pins/app9332026/10/29 01:21:57 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket6/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"9342026/10/29 01:21:57 INFO Received delete pin request method=DELETE path=/api/pins/app935--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.88s)936=== CONT TestClientMultipleUploads937--- PASS: TestReadRedirectNar (1.87s)938=== CONT TestUploadHandlersRejectInvalidKeys939=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info940=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info941=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal942=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal943=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key944=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key945=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key946=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key947=== CONT TestService_RequireScope_OIDC948=== CONT TestObjectStatsUpdatedOncePerCommit949--- PASS: TestReadProxyInvalidPath (1.88s)9502026/10/29 01:21:57 INFO Deleted pin name=app951--- PASS: TestDeletePinKeepsRowWhenS3Fails (1.91s)952=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT9532026/10/29 01:21:57 INFO Received uploads request method=POST path=/api/pending_closures954--- PASS: TestPresentRefreshesOnlyStaleClosures (1.93s)955=== CONT TestService_AuthMiddleware_MTLSBoundSubjects9562026/10/29 01:21:57 INFO Received uploads request method=POST path=/api/pending_closures9572026/10/29 01:21:57 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45479/oidc9582026/10/29 01:21:57 INFO Received create pin request method=POST path=/api/pins/deploy9592026/10/29 01:21:57 INFO Received create pin request method=POST path=/api/pins/deploy9602026/10/29 01:21:57 INFO Received create pin request method=POST path=/api/pins/deploy9612026/10/29 01:21:57 INFO Received create pin request method=POST path=/api/pins/deploy9622026/10/29 01:21:57 INFO Received create pin request method=POST path=/api/pins/deploy9632026/10/29 01:21:57 INFO Received create pin request method=POST path=/api/pins/deploy9642026/10/29 01:21:57 INFO Received create pin request method=POST path=/api/pins/deploy9652026/10/29 01:21:57 INFO Received create pin request method=POST path=/api/pins/deploy9662026/10/29 01:21:57 INFO Received create pin request method=POST path=/api/pins/deploy967=== CONT TestClientPushesUseOnePush968--- PASS: TestReconnectLeavesObjectsUnlocked (2.06s)969--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.06s)970=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle971--- PASS: TestReadProxyNarStreaming (2.10s)972=== CONT TestProxyWriteTimeout973=== RUN TestProxyWriteTimeout/narinfo974=== PAUSE TestProxyWriteTimeout/narinfo975=== RUN TestProxyWriteTimeout/1_GiB_nar976=== PAUSE TestProxyWriteTimeout/1_GiB_nar977=== RUN TestProxyWriteTimeout/10_GiB_nar978=== PAUSE TestProxyWriteTimeout/10_GiB_nar979=== RUN TestProxyWriteTimeout/unknown_size980=== PAUSE TestProxyWriteTimeout/unknown_size981=== CONT TestMetricsCommit982=== CONT TestReadProxyNarinfo983--- PASS: TestPresentReportsOnlyClosureRoots (2.15s)9842026/10/29 01:21:57 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9852026/10/29 01:21:57 WARN Refused reserved pin name=worker-x86_64-linux9862026/10/29 01:21:57 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9872026/10/29 01:21:57 INFO Received create pin request method=POST path=/api/pins/my-app9882026/10/29 01:21:57 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9892026/10/29 01:21:57 INFO Received uploads request method=POST path=/api/pending_closures990--- PASS: TestCreatePin_ReservedPins (2.19s)991=== CONT TestGracefulShutdownDrainsInflight9922026/10/29 01:21:57 INFO Starting HTTP server address=127.0.0.1:436699932026/10/29 01:21:57 INFO Shutdown signal received, draining in-flight requests timeout=10s994=== CONT TestGCTaskStore_GetReturnsLatest995--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (1.30s)996=== CONT TestGCTaskStore_Fail997--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)998=== CONT TestCacheConfigHandlerMaxNarSize999--- PASS: TestGCTaskStore_Fail (0.00s)1000--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1001=== CONT TestPush_RejectsBadRequests10022026/10/29 01:21:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1003=== CONT TestLeadIncumbentAnnouncesAtOnce1004--- PASS: TestGracefulShutdownDrainsInflight (0.07s)10052026/10/29 01:21:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10062026/10/29 01:21:57 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst10072026/10/29 01:21:57 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLjRhZjQ5MGZkLTllYTMtNDcwZC1hYTBhLTUyMjkzOTI1MWU2NHgxNzkzMjM2OTE3MTAxNzI0NTQx1008=== CONT TestRedundantMultipartUpload1009--- PASS: TestCompleteMultipartUnregistered (2.27s)10102026/10/29 01:21:57 INFO Received uploads request method=POST path=/api/pending_closures10112026/10/29 01:21:57 INFO Received uploads request method=POST path=/api/pending_closures10122026/10/29 01:21:57 INFO Received uploads request method=POST path=/api/pending_closures10132026/10/29 01:21:57 INFO Received cleanup request method=DELETE path=/api/pending_closures10142026/10/29 01:21:57 INFO Aborted multipart uploads count=0 kept=010152026/10/29 01:21:57 INFO Received uploads request method=POST path=/api/pending_closures1016--- PASS: TestObjectStatsTrigger (1.46s)1017=== CONT TestPushWaitsForSweepHoldingRow10182026/10/29 01:21:57 INFO Received cleanup request method=DELETE path=/api/pending_closures10192026/10/29 01:21:57 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLjRhZjQ5MGZkLTllYTMtNDcwZC1hYTBhLTUyMjkzOTI1MWU2NHgxNzkzMjM2OTE3MTAxNzI0NTQx error="Delete \"http://localhost:42795/bucket11/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLjRhZjQ5MGZkLTllYTMtNDcwZC1hYTBhLTUyMjkzOTI1MWU2NHgxNzkzMjM2OTE3MTAxNzI0NTQx\": injected: abort refused"10202026/10/29 01:21:57 INFO Aborted multipart uploads count=1 kept=010212026/10/29 01:21:57 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10222026-10-29 01:21:57.531 UTC [518] ERROR: Closure does not exist: id=110232026-10-29 01:21:57.531 UTC [518] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE10242026-10-29 01:21:57.531 UTC [518] STATEMENT: -- name: CommitPendingClosure :one1025 SELECT commit_pending_closure($1::bigint)::bigint1026 10272026/10/29 01:21:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10282026/10/29 01:21:57 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLjRhZjQ5MGZkLTllYTMtNDcwZC1hYTBhLTUyMjkzOTI1MWU2NHgxNzkzMjM2OTE3MTAxNzI0NTQx10292026/10/29 01:21:57 ERROR Failed to register completed object error="get pending object \"nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst\": context canceled" object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst10302026/10/29 01:21:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10312026/10/29 01:21:57 INFO Received uploads request method=POST path=/api/pending_closures10322026/10/29 01:21:57 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified multipart upload does not exist. The upload ID may be invalid, or the upload may have been aborted or completed." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLjRhZjQ5MGZkLTllYTMtNDcwZC1hYTBhLTUyMjkzOTI1MWU2NHgxNzkzMjM2OTE3MTAxNzI0NTQx1033=== CONT TestGCTaskStore_ConflictDifferentParams1034--- PASS: TestService_cleanupPendingClosuresHandler (1.44s)1035=== CONT TestRegisterCompletedObjectNeedsPendingRow1036--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)10372026/10/29 01:21:57 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLjRhZjQ5MGZkLTllYTMtNDcwZC1hYTBhLTUyMjkzOTI1MWU2NHgxNzkzMjM2OTE3MTAxNzI0NTQx parts=11038=== CONT TestSweepSkipsRowsLockedByPush1039--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.53s)1040=== CONT TestGCSweepSkipsPendingObjects1041--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.46s)10422026/10/29 01:21:57 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"10432026/10/29 01:21:57 WARN mTLS auth: bound subjects configured but subject DN unavailable10442026/10/29 01:21:57 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1045=== CONT TestGCBugBareHashReferences1046--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.55s)1047=== CONT TestPushDedupSurvivesConcurrentGC1048--- PASS: TestObjectStatsUpdatedOncePerCommit (0.62s)1049=== RUN TestService_RequireScope_OIDC/builder_may_write1050=== PAUSE TestService_RequireScope_OIDC/builder_may_write1051=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1052=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1053=== RUN TestService_RequireScope_OIDC/ops_may_admin1054=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1055=== RUN TestService_RequireScope_OIDC/ops_may_not_write1056=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1057=== RUN TestService_RequireScope_OIDC/reader_may_not_write1058=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1059=== RUN TestService_RequireScope_OIDC/static_token_may_admin1060=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1061=== RUN TestService_RequireScope_OIDC/static_token_may_write1062=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1063=== RUN TestService_RequireScope_OIDC/reader_may_read1064=== PAUSE TestService_RequireScope_OIDC/reader_may_read1065=== RUN TestService_RequireScope_OIDC/writer_implies_read1066=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1067=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1068=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1069=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1070=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1071=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1072=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1073=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1074=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1075=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1076=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1077=== CONT TestReadRedirectKeepsNarinfoProxied10782026/10/29 01:21:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10792026/10/29 01:21:57 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLmE3YjAxMjM3LTRkMzMtNDNjYS1iZDI1LTg2ZGE4YTUzZmQ2NHgxNzkzMjM2OTE3MDgzNjg0Njk1 parts=1210802026/10/29 01:21:57 INFO Received uploads request method=POST path=/api/pending_closures10812026/10/29 01:21:57 WARN Rate limiter enabled after throttle name=s3-test rate=510822026/10/29 01:21:57 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."1083--- PASS: TestCompletedNarNotReofferedAcrossClosures (2.63s)1084=== CONT TestPush_RepeatedRootCommitsOnce10852026/10/29 01:21:57 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10862026/10/29 01:21:57 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLmMyNGFkZmRkLWNkMDktNDM1Zi1hNGQ0LTgzMDljMGI3NTcyNHgxNzkzMjM2OTE3MzI5OTE2Nzk4 parts=1010872026/10/29 01:21:57 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10882026/10/29 01:21:57 INFO Completed upload id=1 objects=2 duration=2.501204ms10892026/10/29 01:21:57 INFO Received uploads request method=POST path=/api/pending_closures10902026/10/29 01:21:57 INFO Received uploads request method=POST path=/api/pending_closures10912026/10/29 01:21:57 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10922026/10/29 01:21:57 WARN Found objects in DB but missing from S3, will re-upload count=110932026/10/29 01:21:57 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete10942026/10/29 01:21:57 INFO Completed upload id=3 objects=2 duration=1.543694ms1095--- PASS: TestService_verifyS3Integrity (1.86s)1096=== CONT TestService_ReadScope_PublicByDefault10972026/10/29 01:21:57 WARN Rate limiter backed off name=s3-test rate=510982026/10/29 01:21:57 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."1099--- PASS: TestReadProxy404And429 (1.93s)1100=== CONT TestClientCADerivations11012026/10/29 01:21:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11022026/10/29 01:21:58 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLjRiM2JjNGNhLWJjODEtNDU5ZC1iYTExLWZlOWNhZjYzYjhmMHgxNzkzMjM2OTE3NDQ2ODM2ODEz parts=1011032026/10/29 01:21:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11042026/10/29 01:21:58 INFO Completed upload id=1 objects=2 duration=4.238698ms11052026/10/29 01:21:58 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011062026/10/29 01:21:58 INFO Received uploads request method=POST path=/api/pending_closures11072026/10/29 01:21:58 INFO Starting cleanup of old closures method=DELETE path=/api/closures11082026/10/29 01:21:58 INFO Aborted multipart uploads count=0 kept=011092026/10/29 01:21:58 INFO Received create pin request method=POST path=/api/pins/deploy11102026/10/29 01:21:58 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo1111=== CONT TestReadProxyConditionalGet1112--- PASS: TestCreatePinRejectsBadInput (2.93s)11132026/10/29 01:21:58 INFO Received push request method=POST path=/api/pushes11142026/10/29 01:21:58 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011152026/10/29 01:21:58 INFO Vacuumed table table=pending_closures11162026/10/29 01:21:58 INFO Vacuumed table table=pending_objects1117=== NAME TestClientMultipleUploads1118 client_integration_test.go:467: Created store path 0: /build/TestClientMultipleUploads2353798630/001/store/24nnpvyayj8mh7j26sap09ixkmvqij4p-test-file-0.txt11192026/10/29 01:21:58 INFO Vacuumed table table=multipart_uploads11202026/10/29 01:21:58 INFO Vacuumed table table=closures11212026/10/29 01:21:58 INFO Vacuumed table table=objects1122 client_integration_test.go:467: Created store path 1: /build/TestClientMultipleUploads2353798630/001/store/khwkqnqh3jz1l4qk6v661aqf3abf5nwn-test-file-1.txt11232026/10/29 01:21:58 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011242026/10/29 01:21:58 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)11252026/10/29 01:21:58 INFO Uploading yfz5wgq2wqaj1dpnbyzqgxwrkcya1jyk-shared-dep (136B)11262026/10/29 01:21:58 INFO Uploading 8i4bjmw3x5qnmhjkxiwwfihh67yryg08-top (224B)1127=== NAME TestOrphanedObjectsGC1128 orphaned_objects_gc_test.go:287: GC Test Summary:1129 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1130 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1131 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1132 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1133 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects11342026/10/29 01:21:58 WARN Failed to register uploaded object key=nar/13vzxklvlf126xik61q4ai9vjgfn44irb4glpdac4bi4nds2v60v.nar.zst error="server returned 404: 404 page not found\n"11352026/10/29 01:21:58 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1136=== CONT TestPinProtectsFromGC11372026/10/29 01:21:58 WARN Failed to register uploaded object key=8i4bjmw3x5qnmhjkxiwwfihh67yryg08.ls error="server returned 404: 404 page not found\n"1138--- PASS: TestService_createPendingClosureHandler (2.74s)11392026/10/29 01:21:58 WARN Failed to register uploaded object key=yfz5wgq2wqaj1dpnbyzqgxwrkcya1jyk.ls error="server returned 404: 404 page not found\n"11402026/10/29 01:21:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11412026/10/29 01:21:58 INFO Signed narinfos id=1 count=211422026/10/29 01:21:58 INFO Uploading 2 narinfos11432026/10/29 01:21:58 WARN Failed to register uploaded object key=8i4bjmw3x5qnmhjkxiwwfihh67yryg08.narinfo error="server returned 404: 404 page not found\n"1144--- PASS: TestOrphanedObjectsGC (3.67s)1145=== CONT TestGCSweepDeliversEachKeyOnce11462026/10/29 01:21:58 INFO Received complete push request method=POST path=/api/pushes/1/complete11472026/10/29 01:21:58 WARN Failed to register uploaded object key=yfz5wgq2wqaj1dpnbyzqgxwrkcya1jyk.narinfo error="server returned 404: 404 page not found\n"1148=== NAME TestClientMultipleUploads1149 client_integration_test.go:467: Created store path 2: /build/TestClientMultipleUploads2353798630/001/store/ll7yx3qkvgsm9h15pg33qjz5lnjkwbl3-test-file-2.txt11502026/10/29 01:21:58 INFO Completed push id=1 objects=6 duration=9.143504ms11512026/10/29 01:21:58 INFO Upload complete. (1.601s)1152=== NAME TestClientSharedPathCommittedMidPush1153 client_integration_test.go:803: Retrieved narinfo from S3:1154 StorePath: /build/TestClientSharedPathCommittedMidPush711322350/001/store/yfz5wgq2wqaj1dpnbyzqgxwrkcya1jyk-shared-dep1155 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1156 Compression: zstd1157 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821158 NarSize: 1361159 References: 1160 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1161 client_integration_test.go:803: Retrieved narinfo from S3:1162 StorePath: /build/TestClientSharedPathCommittedMidPush711322350/001/store/8i4bjmw3x5qnmhjkxiwwfihh67yryg08-top1163 URL: nar/13vzxklvlf126xik61q4ai9vjgfn44irb4glpdac4bi4nds2v60v.nar.zst1164 Compression: zstd1165 NarHash: sha256:13vzxklvlf126xik61q4ai9vjgfn44irb4glpdac4bi4nds2v60v1166 NarSize: 2241167 References: /build/TestClientSharedPathCommittedMidPush711322350/001/store/yfz5wgq2wqaj1dpnbyzqgxwrkcya1jyk-shared-dep1168 CA: text:sha256:03qql8dyik8f6xvdfqnnm2gc16i2jv567vlgw8xl45srpgpi5mxj11692026/10/29 01:21:58 INFO Received push request method=POST path=/api/pushes1170=== CONT TestGetExistingObjectsLocksRows1171--- PASS: TestClientSharedPathCommittedMidPush (3.73s)11722026/10/29 01:21:58 INFO Received uploads request method=POST path=/api/pending_closures11732026/10/29 01:21:58 INFO Received push request method=POST path=/api/pushes11742026/10/29 01:21:58 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)11752026/10/29 01:21:58 INFO Uploading ll7yx3qkvgsm9h15pg33qjz5lnjkwbl3-test-file-2.txt (160B)11762026/10/29 01:21:58 INFO Uploading 24nnpvyayj8mh7j26sap09ixkmvqij4p-test-file-0.txt (160B)11772026/10/29 01:21:58 INFO Uploading khwkqnqh3jz1l4qk6v661aqf3abf5nwn-test-file-1.txt (160B)11782026/10/29 01:21:58 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"11792026/10/29 01:21:58 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"11802026/10/29 01:21:58 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"11812026/10/29 01:21:58 WARN Failed to register uploaded object key=ll7yx3qkvgsm9h15pg33qjz5lnjkwbl3.ls error="server returned 404: 404 page not found\n"11822026/10/29 01:21:58 WARN Failed to register uploaded object key=24nnpvyayj8mh7j26sap09ixkmvqij4p.ls error="server returned 404: 404 page not found\n"11832026/10/29 01:21:58 WARN Failed to register uploaded object key=khwkqnqh3jz1l4qk6v661aqf3abf5nwn.ls error="server returned 404: 404 page not found\n"11842026/10/29 01:21:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11852026/10/29 01:21:58 INFO Signed narinfos id=1 count=311862026/10/29 01:21:58 INFO Uploading 3 narinfos11872026/10/29 01:21:58 WARN Failed to register uploaded object key=24nnpvyayj8mh7j26sap09ixkmvqij4p.narinfo error="server returned 404: 404 page not found\n"11882026/10/29 01:21:58 INFO Received complete push request method=POST path=/api/pushes/1/complete11892026/10/29 01:21:58 WARN Failed to register uploaded object key=ll7yx3qkvgsm9h15pg33qjz5lnjkwbl3.narinfo error="server returned 404: 404 page not found\n"11902026/10/29 01:21:58 WARN Failed to register uploaded object key=khwkqnqh3jz1l4qk6v661aqf3abf5nwn.narinfo error="server returned 404: 404 page not found\n"11912026/10/29 01:21:58 INFO Completed push id=1 objects=9 duration=7.850512ms11922026/10/29 01:21:58 INFO Upload complete. (108ms)1193=== NAME TestClientMultipleUploads1194 client_integration_test.go:478: Uploaded 3 paths in 156.426697ms11952026/10/29 01:21:58 INFO Received uploads request method=POST path=/api/pending_closures11962026/10/29 01:21:58 INFO Aborted multipart uploads count=0 kept=011972026/10/29 01:21:59 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=011982026/10/29 01:21:59 INFO Vacuumed table table=pending_closures11992026/10/29 01:21:59 INFO Vacuumed table table=pending_objects12002026/10/29 01:21:59 INFO Vacuumed table table=multipart_uploads12012026/10/29 01:21:59 INFO Vacuumed table table=closures12022026/10/29 01:21:59 INFO Vacuumed table table=objects12032026/10/29 01:21:59 INFO Aborted multipart uploads count=0 kept=01204=== NAME TestClientCADerivations1205 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3363129338/001/store/xxjw0dk2zc9q7zy68vaw1y0vs7pwdh57-ca-test12062026/10/29 01:21:59 WARN Force mode enabled - objects will be deleted immediately without grace period12072026/10/29 01:21:59 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012082026/10/29 01:21:59 INFO Vacuumed table table=pending_closures12092026/10/29 01:21:59 INFO Vacuumed table table=pending_objects12102026/10/29 01:21:59 INFO Vacuumed table table=multipart_uploads12112026/10/29 01:21:59 INFO Vacuumed table table=closures12122026/10/29 01:21:59 INFO Vacuumed table table=objects1213=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1214--- PASS: TestClientMultipleUploads (2.02s)12152026/10/29 01:21:59 INFO Received uploads request method=POST path=/api/pending_closures1216--- PASS: TestPushDedupSurvivesConcurrentGC (1.41s)1217=== CONT TestClientIntegration12182026/10/29 01:21:59 INFO Aborted multipart uploads count=0 kept=01219=== NAME TestClientCADerivations1220 client_ca_test.go:139: Found 1 dependencies (including self)1221--- PASS: TestService_ReadScope_PublicByDefault (1.15s)1222=== CONT TestPendingClosureFailureAbortsItsUploads1223=== CONT TestConcurrentPinUpdatesAgree1224--- PASS: TestReadProxyConditionalGet (1.00s)12252026/10/29 01:21:59 WARN Force mode enabled - objects will be deleted immediately without grace period12262026/10/29 01:21:59 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012272026/10/29 01:21:59 INFO Vacuumed table table=pending_closures12282026/10/29 01:21:59 INFO Vacuumed table table=pending_objects12292026/10/29 01:21:59 INFO Vacuumed table table=multipart_uploads12302026/10/29 01:21:59 INFO Vacuumed table table=closures12312026/10/29 01:21:59 INFO Vacuumed table table=objects1232=== RUN TestPush_RejectsBadRequests/bad_root1233=== PAUSE TestPush_RejectsBadRequests/bad_root1234=== RUN TestPush_RejectsBadRequests/root_not_in_objects1235=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1236=== RUN TestPush_RejectsBadRequests/no_roots1237=== PAUSE TestPush_RejectsBadRequests/no_roots1238=== RUN TestPush_RejectsBadRequests/no_objects1239=== PAUSE TestPush_RejectsBadRequests/no_objects1240=== CONT TestService_ReadAuthMiddleware12412026/10/29 01:21:59 INFO Aborted multipart uploads count=0 kept=012422026/10/29 01:21:59 WARN Force mode enabled - objects will be deleted immediately without grace period12432026/10/29 01:21:59 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=012442026/10/29 01:21:59 INFO Vacuumed table table=pending_closures12452026/10/29 01:21:59 INFO Vacuumed table table=pending_objects12462026/10/29 01:21:59 INFO Vacuumed table table=multipart_uploads12472026/10/29 01:21:59 INFO Vacuumed table table=closures1248--- PASS: TestGCSweepSkipsPendingObjects (1.53s)1249=== CONT TestService_AuthMiddleware_OIDC1250--- PASS: TestReadRedirectKeepsNarinfoProxied (1.45s)1251=== CONT TestPendingCleanupUsesOneCutoff12522026/10/29 01:21:59 INFO lead: acquired remote=192.0.2.1:123412532026/10/29 01:21:59 INFO lead: released remote=192.0.2.1:123412542026/10/29 01:21:59 INFO Vacuumed table table=objects12552026/10/29 01:21:59 INFO Aborted multipart uploads count=0 kept=01256=== CONT TestForceGCDuringPushOffersSweptObject1257=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1258--- PASS: TestLeadIncumbentAnnouncesAtOnce (1.75s)1259=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1260=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1261=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1262=== CONT TestIsValidCachePath1263=== RUN TestIsValidCachePath/narinfo1264=== PAUSE TestIsValidCachePath/narinfo1265=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1266=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1267=== RUN TestIsValidCachePath/nar_zst1268=== PAUSE TestIsValidCachePath/nar_zst1269=== RUN TestIsValidCachePath/nar_xz1270=== PAUSE TestIsValidCachePath/nar_xz1271=== RUN TestIsValidCachePath/nar_bz21272=== PAUSE TestIsValidCachePath/nar_bz21273=== RUN TestIsValidCachePath/nar_uncompressed1274=== PAUSE TestIsValidCachePath/nar_uncompressed1275=== RUN TestIsValidCachePath/ls1276=== PAUSE TestIsValidCachePath/ls1277=== RUN TestIsValidCachePath/log1278=== PAUSE TestIsValidCachePath/log1279=== RUN TestIsValidCachePath/realisation1280=== PAUSE TestIsValidCachePath/realisation1281=== RUN TestIsValidCachePath/nix-cache-info1282=== PAUSE TestIsValidCachePath/nix-cache-info1283=== RUN TestIsValidCachePath/index.html1284=== PAUSE TestIsValidCachePath/index.html1285=== RUN TestIsValidCachePath/traversal_parent1286=== PAUSE TestIsValidCachePath/traversal_parent1287=== RUN TestIsValidCachePath/traversal_in_middle1288=== PAUSE TestIsValidCachePath/traversal_in_middle1289=== RUN TestIsValidCachePath/invalid_char_e1290=== PAUSE TestIsValidCachePath/invalid_char_e1291=== RUN TestIsValidCachePath/invalid_char_u1292=== PAUSE TestIsValidCachePath/invalid_char_u1293=== RUN TestIsValidCachePath/random_path1294=== PAUSE TestIsValidCachePath/random_path1295=== RUN TestIsValidCachePath/empty1296=== PAUSE TestIsValidCachePath/empty1297=== RUN TestIsValidCachePath/leading_slash1298=== PAUSE TestIsValidCachePath/leading_slash1299=== RUN TestIsValidCachePath/wrong_extension1300=== PAUSE TestIsValidCachePath/wrong_extension1301=== RUN TestIsValidCachePath/short_hash1302=== PAUSE TestIsValidCachePath/short_hash1303=== CONT TestService_AuthMiddleware13042026/10/29 01:21:59 INFO Received uploads request method=POST path=/api/pending_closures13052026/10/29 01:21:59 INFO Received uploads request method=POST path=/api/pending_closures1306--- PASS: TestRegisterCompletedObjectNeedsPendingRow (1.71s)1307=== CONT TestPendingClosureFailureTracksEveryUpload1308=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1309=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1310=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1311=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1312=== CONT TestReadProxyContentNegotiation13132026/10/29 01:21:59 INFO Received push request method=POST path=/api/pushes13142026/10/29 01:21:59 INFO Received uploads request method=POST path=/api/pending_closures13152026/10/29 01:21:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33461/oidc1316=== NAME TestOrphanedObjectsGCStressTest1317 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains13182026/10/29 01:21:59 INFO Aborted multipart uploads count=0 kept=01319--- PASS: TestGetExistingObjectsLocksRows (0.55s)1320=== CONT TestMultipartCleanup13212026/10/29 01:21:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13222026/10/29 01:21:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1323--- PASS: TestPushWaitsForSweepHoldingRow (2.02s)1324=== CONT TestService_Rustfstest13252026/10/29 01:21:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13262026/10/29 01:21:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13272026/10/29 01:21:59 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLjc5OWRmNDM2LTU4N2ItNDdiMi04YjBkLTNmMThjYjA5NDZhYngxNzkzMjM2OTE5MjIwNjg3ODM1 parts=1213282026/10/29 01:21:59 INFO Received uploads request method=POST path=/api/pending_closures13292026/10/29 01:21:59 INFO Received uploads request method=POST path=/api/pending_closures13302026/10/29 01:22:00 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1331=== CONT TestServerTLSConfig1332=== RUN TestServerTLSConfig/no_client_CA1333--- PASS: TestReadProxyNarinfo (2.87s)1334=== PAUSE TestServerTLSConfig/no_client_CA1335=== RUN TestServerTLSConfig/missing_CA_file1336=== PAUSE TestServerTLSConfig/missing_CA_file1337=== RUN TestServerTLSConfig/not_a_PEM_file1338=== PAUSE TestServerTLSConfig/not_a_PEM_file1339=== CONT TestUploadHandlersRejectOversizedBody13402026/10/29 01:22:00 WARN Force mode enabled - objects will be deleted immediately without grace period13412026/10/29 01:22:00 WARN Force mode enabled - objects will be deleted immediately without grace period13422026/10/29 01:22:00 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLjk3NTE5NmJkLTU1YjktNDUxOS1iYzc3LTEzY2RkOTNhMjhhMHgxNzkzMjM2OTE5MzA0NDc3MDA1 parts=1013432026/10/29 01:22:00 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLjVhMTkyNmU5LTRlNGQtNDNjMS1iNGNhLTkyOTEyNjhkNDZiMHgxNzkzMjM2OTE4ODY5MDk4NTI0 parts=101344=== NAME TestOrphanedObjectsGCStressTest1345 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion1346--- PASS: TestGCBugBareHashReferences (2.67s)1347=== CONT TestGCTaskStore_CompletedAllowsNewTask1348--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1349=== CONT TestService_NativeMTLS13502026/10/29 01:22:00 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=013512026/10/29 01:22:00 INFO Vacuumed table table=pending_closures13522026/10/29 01:22:00 INFO Vacuumed table table=pending_objects13532026/10/29 01:22:00 INFO Vacuumed table table=multipart_uploads13542026/10/29 01:22:00 INFO Vacuumed table table=closures13552026/10/29 01:22:00 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=013562026/10/29 01:22:00 INFO Vacuumed table table=objects13572026/10/29 01:22:00 INFO Vacuumed table table=pending_closures13582026/10/29 01:22:00 INFO Vacuumed table table=pending_objects13592026/10/29 01:22:00 INFO Vacuumed table table=multipart_uploads13602026/10/29 01:22:00 INFO Vacuumed table table=closures13612026/10/29 01:22:00 INFO Vacuumed table table=objects1362=== NAME TestPinProtectsFromGC1363 client_integration_test.go:854: Pinned store path: /build/TestPinProtectsFromGC2129473580/001/store/snvsqsjfflqczhy7j0s9pdjx176631vf-pinned-file.txt1364 client_integration_test.go:855: Unpinned store path: /build/TestPinProtectsFromGC2129473580/001/store/fqkxr68q4d8jclzk5ha841aw1id471a2-unpinned-file.txt1365--- PASS: TestSweepSkipsRowsLockedByPush (2.76s)1366=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1367--- PASS: TestGCSweepDeliversEachKeyOnce (1.53s)1368=== CONT TestReadProxyNarinfoAlreadyDecompressed13692026/10/29 01:22:00 INFO Received push request method=POST path=/api/pushes13702026/10/29 01:22:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13712026/10/29 01:22:00 INFO Uploading xxjw0dk2zc9q7zy68vaw1y0vs7pwdh57-ca-test (144B)13722026/10/29 01:22:00 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13732026/10/29 01:22:00 WARN Failed to register uploaded object key=log/7d10k3j0w7liqzf03k8l0001l9f1pgyz-ca-test.drv error="server returned 404: 404 page not found\n"13742026/10/29 01:22:00 WARN Failed to register uploaded object key=xxjw0dk2zc9q7zy68vaw1y0vs7pwdh57.ls error="server returned 404: 404 page not found\n"13752026/10/29 01:22:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13762026/10/29 01:22:00 INFO Signed narinfos id=1 count=113772026/10/29 01:22:00 INFO Uploading 1 narinfos13782026/10/29 01:22:00 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"13792026/10/29 01:22:00 INFO Received push request method=POST path=/api/pushes13802026/10/29 01:22:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13812026/10/29 01:22:00 INFO Uploading snvsqsjfflqczhy7j0s9pdjx176631vf-pinned-file.txt (128B)13822026/10/29 01:22:00 INFO Received complete push request method=POST path=/api/pushes/1/complete13832026/10/29 01:22:00 WARN Failed to register uploaded object key=xxjw0dk2zc9q7zy68vaw1y0vs7pwdh57.narinfo error="server returned 404: 404 page not found\n"13842026/10/29 01:22:00 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"1385--- PASS: TestService_AuthMiddleware (1.30s)1386=== CONT TestParseSingleRange1387=== RUN TestParseSingleRange/none1388=== PAUSE TestParseSingleRange/none1389=== RUN TestParseSingleRange/unknown_unit1390=== PAUSE TestParseSingleRange/unknown_unit1391=== RUN TestParseSingleRange/multi-range_ignored1392=== PAUSE TestParseSingleRange/multi-range_ignored1393=== RUN TestParseSingleRange/malformed_no_dash1394=== PAUSE TestParseSingleRange/malformed_no_dash1395=== RUN TestParseSingleRange/malformed_both_empty1396=== PAUSE TestParseSingleRange/malformed_both_empty1397=== RUN TestParseSingleRange/malformed_end_before_start1398=== PAUSE TestParseSingleRange/malformed_end_before_start1399=== RUN TestParseSingleRange/closed1400=== PAUSE TestParseSingleRange/closed1401=== RUN TestParseSingleRange/open-ended1402=== PAUSE TestParseSingleRange/open-ended1403=== RUN TestParseSingleRange/end_clamped_to_size1404=== PAUSE TestParseSingleRange/end_clamped_to_size14052026/10/29 01:22:00 WARN Failed to register uploaded object key=snvsqsjfflqczhy7j0s9pdjx176631vf.ls error="server returned 404: 404 page not found\n"1406=== RUN TestParseSingleRange/suffix1407=== PAUSE TestParseSingleRange/suffix1408=== RUN TestParseSingleRange/suffix_exceeds_size1409=== PAUSE TestParseSingleRange/suffix_exceeds_size14102026/10/29 01:22:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1411=== RUN TestParseSingleRange/single_byte1412=== PAUSE TestParseSingleRange/single_byte1413=== RUN TestParseSingleRange/start_past_EOF1414=== PAUSE TestParseSingleRange/start_past_EOF1415=== RUN TestParseSingleRange/start_far_past_EOF1416=== PAUSE TestParseSingleRange/start_far_past_EOF1417=== CONT TestGenerateLandingPage14182026/10/29 01:22:00 INFO Signed narinfos id=1 count=114192026/10/29 01:22:00 INFO Uploading 1 narinfos14202026/10/29 01:22:00 INFO Completed push id=1 objects=4 duration=8.079534ms14212026/10/29 01:22:00 INFO Upload complete. (1.331s)14222026/10/29 01:22:00 INFO Received complete push request method=POST path=/api/pushes/1/complete14232026/10/29 01:22:00 WARN Failed to register uploaded object key=snvsqsjfflqczhy7j0s9pdjx176631vf.narinfo error="server returned 404: 404 page not found\n"1424=== NAME TestClientCADerivations1425 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3363129338/001/store/xxjw0dk2zc9q7zy68vaw1y0vs7pwdh57-ca-test1426 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1427 Compression: zstd1428 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1429 NarSize: 1441430 References: 1431 Deriver: /build/TestClientCADerivations3363129338/001/store/7d10k3j0w7liqzf03k8l0001l9f1pgyz-ca-test.drv1432 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1433 client_ca_test.go:185: Checking for realisation files in S3...14342026/10/29 01:22:00 INFO Completed push id=1 objects=3 duration=6.406938ms14352026/10/29 01:22:00 INFO Upload complete. (90ms)1436 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1437 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1438--- PASS: TestService_ReadAuthMiddleware (1.37s)1439=== CONT TestGCTaskStore_PhaseUpdates1440--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1441=== CONT TestService_healthCheckHandler1442=== CONT TestService_readinessHandler1443--- PASS: TestGenerateLandingPage (0.02s)14442026/10/29 01:22:00 INFO Received push request method=POST path=/api/pushes1445--- PASS: TestService_Rustfstest (0.98s)1446=== CONT TestMetricsInventory14472026/10/29 01:22:00 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14482026/10/29 01:22:00 INFO Uploading 1mli4hpvymhcag23n563gpxp9i6j0g6a-a (216B)14492026/10/29 01:22:00 INFO Uploading fsximymlcnqphvxfab6d71lzbvgw1441-shared-dep (136B)14502026/10/29 01:22:00 WARN Failed to register uploaded object key=lpkprjc2l41hc6ai02y2dpmqfwyf4sdg.ls error="server returned 404: 404 page not found\n"14512026/10/29 01:22:00 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14522026/10/29 01:22:00 INFO Received uploads request method=POST path=/api/pending_closures14532026/10/29 01:22:00 WARN Failed to register uploaded object key=nar/0d0k4cmvigaph7rsvc376bavixc77vmdfbmr8fv1adaz9kpa4cvc.nar.zst error="server returned 404: 404 page not found\n"14542026/10/29 01:22:00 WARN Failed to register uploaded object key=1mli4hpvymhcag23n563gpxp9i6j0g6a.ls error="server returned 404: 404 page not found\n"14552026/10/29 01:22:00 WARN Failed to register uploaded object key=fsximymlcnqphvxfab6d71lzbvgw1441.ls error="server returned 404: 404 page not found\n"14562026/10/29 01:22:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14572026/10/29 01:22:00 INFO Signed narinfos id=1 count=314582026/10/29 01:22:00 INFO Uploading 3 narinfos14592026/10/29 01:22:00 WARN Failed to register uploaded object key=fsximymlcnqphvxfab6d71lzbvgw1441.narinfo error="server returned 404: 404 page not found\n"14602026/10/29 01:22:00 WARN Failed to register uploaded object key=lpkprjc2l41hc6ai02y2dpmqfwyf4sdg.narinfo error="server returned 404: 404 page not found\n"14612026/10/29 01:22:00 INFO Received complete push request method=POST path=/api/pushes/1/complete14622026/10/29 01:22:00 WARN Failed to register uploaded object key=1mli4hpvymhcag23n563gpxp9i6j0g6a.narinfo error="server returned 404: 404 page not found\n"14632026/10/29 01:22:00 INFO Completed push id=1 objects=8 duration=7.854352ms14642026/10/29 01:22:00 INFO Upload complete. (130ms)1465=== NAME TestClientPushesUseOnePush1466 client_pushes_test.go:97: Retrieved narinfo from S3:1467 StorePath: /build/TestClientPushesUseOnePush3552005823/001/store/fsximymlcnqphvxfab6d71lzbvgw1441-shared-dep1468 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1469 Compression: zstd1470 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821471 NarSize: 1361472 References: 1473 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1474 client_pushes_test.go:97: Retrieved narinfo from S3:1475 StorePath: /build/TestClientPushesUseOnePush3552005823/001/store/1mli4hpvymhcag23n563gpxp9i6j0g6a-a1476 URL: nar/0d0k4cmvigaph7rsvc376bavixc77vmdfbmr8fv1adaz9kpa4cvc.nar.zst1477 Compression: zstd1478 NarHash: sha256:0d0k4cmvigaph7rsvc376bavixc77vmdfbmr8fv1adaz9kpa4cvc1479 NarSize: 2161480 References: /build/TestClientPushesUseOnePush3552005823/001/store/fsximymlcnqphvxfab6d71lzbvgw1441-shared-dep1481 CA: text:sha256:1r44mpiwv9088ca5a3s9mpcbj4i010aq1jal36pch66hcaz6vg221482 client_pushes_test.go:97: Retrieved narinfo from S3:1483 StorePath: /build/TestClientPushesUseOnePush3552005823/001/store/lpkprjc2l41hc6ai02y2dpmqfwyf4sdg-b1484 URL: nar/0d0k4cmvigaph7rsvc376bavixc77vmdfbmr8fv1adaz9kpa4cvc.nar.zst1485 Compression: zstd1486 NarHash: sha256:0d0k4cmvigaph7rsvc376bavixc77vmdfbmr8fv1adaz9kpa4cvc1487 NarSize: 2161488 References: /build/TestClientPushesUseOnePush3552005823/001/store/fsximymlcnqphvxfab6d71lzbvgw1441-shared-dep1489 CA: text:sha256:1r44mpiwv9088ca5a3s9mpcbj4i010aq1jal36pch66hcaz6vg2214902026/10/29 01:22:00 INFO Received create pin request method=POST path=/api/pins/app1491--- PASS: TestPendingClosureFailureAbortsItsUploads (1.53s)1492=== CONT TestSkippedUploadsHandler14932026/10/29 01:22:00 INFO Client skipped oversized paths paths=3 nar_bytes=500000000014942026/10/29 01:22:00 INFO Received create pin request method=POST path=/api/pins/app1495--- PASS: TestClientPushesUseOnePush (3.43s)1496=== CONT TestCacheStatsHandler1497=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1498=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1499=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1500=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1501=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1502=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1503=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1504=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1505=== CONT TestPendingClosureWriteTimeout1506=== RUN TestPendingClosureWriteTimeout/empty1507=== PAUSE TestPendingClosureWriteTimeout/empty1508=== RUN TestPendingClosureWriteTimeout/400_objects1509=== PAUSE TestPendingClosureWriteTimeout/400_objects1510=== RUN TestPendingClosureWriteTimeout/670k_objects1511=== PAUSE TestPendingClosureWriteTimeout/670k_objects1512=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1513=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1514=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1515=== CONT TestCommitRacingPendingCleanupKeepsObjects1516--- PASS: TestSkippedUploadsHandler (0.04s)15172026/10/29 01:22:00 INFO Received uploads request method=POST path=/api/pending_closures15182026/10/29 01:22:00 INFO Received uploads request method=POST path=/api/pending_closures15192026/10/29 01:22:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15202026/10/29 01:22:00 INFO Received cleanup request method=DELETE path=/api/pending_closures15212026/10/29 01:22:00 INFO Received uploads request method=POST path=/api/pending_closures15222026/10/29 01:22:00 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLmE4M2UwZWI1LTRjN2EtNDZhMi1hN2IwLWNiOTNkNTFlYWM0Y3gxNzkzMjM2OTE5OTczMzI0MTMy error="Get \"http://127.0.0.1:1/bucket46/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"15232026/10/29 01:22:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLjEyNmEyNTM1LTY1YWYtNDg4Mi04YWU0LTI0Yjk1MmE1MjVjMngxNzkzMjM2OTE5OTQ1NDU2NTM2 parts=1215242026/10/29 01:22:00 INFO Received cleanup request method=DELETE path=/api/pending_closures15252026/10/29 01:22:00 INFO Aborted multipart uploads count=1 kept=015262026/10/29 01:22:00 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15272026/10/29 01:22:00 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1528=== CONT TestParseSize1529--- PASS: TestRedundantMultipartUpload (3.37s)1530--- PASS: TestParseSize (0.00s)1531=== CONT TestNARDeduplicationMetadataUploadBug1532--- PASS: TestService_NativeMTLS (0.51s)1533=== CONT TestCreatePendingClosureRejectsOversizedNAR15342026/10/29 01:22:00 INFO Received uploads request method=POST path=/api/pending_closures1535--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1536=== CONT TestGCTaskStore_GetEmpty1537--- PASS: TestGCTaskStore_GetEmpty (0.00s)1538=== CONT TestSweepRechecksPendingAfterLocking15392026/10/29 01:22:00 INFO Received uploads request method=POST path=/api/pending_closures1540=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1541=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1542=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1543=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1544=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1545=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1546=== CONT TestGCTaskStore_DeduplicateSameParams1547--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1548=== CONT TestTombstonedObjectOfferedWithoutWaiting1549=== CONT TestChildrenInheritRaisedFileLimit1550--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.49s)1551--- PASS: TestChildrenInheritRaisedFileLimit (0.00s)1552=== CONT TestCacheConfigHandler1553=== RUN TestCacheConfigHandler/full_config,_no_issuer1554=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1555=== RUN TestCacheConfigHandler/no_cache_url_configured1556=== PAUSE TestCacheConfigHandler/no_cache_url_configured1557=== RUN TestCacheConfigHandler/no_signing_keys1558=== PAUSE TestCacheConfigHandler/no_signing_keys1559=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1560=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1561=== CONT TestPush_SignsNarinfosOfItsPendingObjects15622026/10/29 01:22:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15632026/10/29 01:22:00 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLjdhMmQ0ZGQwLWVmZjUtNGZkOS04YWFmLTQ5NmZlMzEyMDBmM3gxNzkzMjM2OTE4ODY4MzM4NTc3 parts=1015642026/10/29 01:22:00 INFO Received complete push request method=POST path=/api/pushes/1/complete15652026/10/29 01:22:00 INFO Received cleanup request method=DELETE path=/api/pending_closures1566--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.53s)1567=== CONT TestResolveDBConnectionString1568=== RUN TestResolveDBConnectionString/flag_wins1569=== PAUSE TestResolveDBConnectionString/flag_wins1570=== RUN TestResolveDBConnectionString/file_when_flag_empty1571=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1572=== RUN TestResolveDBConnectionString/missing_file_is_an_error1573=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1574=== RUN TestResolveDBConnectionString/PGHOST_allows_empty15752026/10/29 01:22:00 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket64/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""1576=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty15772026/10/29 01:22:00 INFO Aborted multipart uploads count=0 kept=11578=== RUN TestResolveDBConnectionString/nothing_configured1579=== PAUSE TestResolveDBConnectionString/nothing_configured1580=== CONT TestDeduplicatedObjectsRecordedAsPending15812026/10/29 01:22:00 INFO Completed push id=1 objects=4 duration=15.582823ms15822026/10/29 01:22:00 INFO Received cleanup request method=DELETE path=/api/pending_closures15832026/10/29 01:22:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15842026/10/29 01:22:00 INFO Aborted multipart uploads count=1 kept=01585--- PASS: TestPush_RepeatedRootCommitsOnce (3.13s)1586=== CONT TestConnectSerialisesConcurrentMigrations15872026/10/29 01:22:00 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLmYyODg0MDAxLTE3MzQtNDlkZC05NjI1LTI3ZDg1NzZjY2ZmMngxNzkzMjM2OTE5MzA2MjE5ODgx parts=1015882026/10/29 01:22:00 INFO Received complete push request method=POST path=/api/pushes/1/complete15892026/10/29 01:22:00 INFO Completed push id=1 objects=4 duration=7.61583ms1590--- PASS: TestMultipartCleanup (1.49s)1591=== CONT TestDeleteClosuresRacingPins15922026/10/29 01:22:00 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15932026/10/29 01:22:00 INFO Completed upload id=2 objects=2 duration=2.371341ms1594=== CONT TestFailedS3DeleteKeepsTombstone1595--- PASS: TestMetricsCommit (3.75s)15962026/10/29 01:22:01 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo1597=== CONT TestGCAdvisoryLockBlocksConcurrentRun1598--- PASS: TestReadProxyContentNegotiation (1.87s)15992026/10/29 01:22:01 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo1600=== CONT TestConnectWaitsForAPeerMigration1601--- PASS: TestConcurrentPinUpdatesAgree (2.08s)1602=== NAME TestOrphanedObjectsGCStressTest1603 orphaned_objects_gc_test.go:503: Stress test completed successfully:1604 orphaned_objects_gc_test.go:504: - Active objects preserved: 201605 orphaned_objects_gc_test.go:505: - Objects deleted: 2101606 orphaned_objects_gc_test.go:506: - Total GC'd: 2101607--- PASS: TestOrphanedObjectsGCStressTest (6.25s)1608=== CONT TestLeadElectsOneAndHandsOver16092026-10-29 01:22:01.557 UTC [1240] ERROR: duplicate key value violates unique constraint "pg_type_typname_nsp_index"16102026-10-29 01:22:01.557 UTC [1240] DETAIL: Key (typname, typnamespace)=(goose_db_version, 2200) already exists.16112026-10-29 01:22:01.557 UTC [1240] STATEMENT: CREATE TABLE goose_db_version (1612 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1613 version_id bigint NOT NULL,1614 is_applied boolean NOT NULL,1615 tstamp timestamp NOT NULL DEFAULT now()1616 )1617=== NAME TestClientIntegration1618 client_integration_test.go:331: Created store path: /build/TestClientIntegration351051131/002/store/syfl03mgswx25llkj0i4grk23i1ryrn5-test-file.txt1619--- PASS: TestReadProxyOutlastsServerWriteTimeout (6.46s)1620=== CONT TestGCMetrics16212026/10/29 01:22:01 INFO Received push request method=POST path=/api/pushes16222026/10/29 01:22:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16232026/10/29 01:22:01 INFO Signed narinfos id=1 count=116242026/10/29 01:22:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16252026/10/29 01:22:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16262026/10/29 01:22:01 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"16272026/10/29 01:22:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16282026/10/29 01:22:01 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"16292026/10/29 01:22:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16302026/10/29 01:22:01 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=116312026/10/29 01:22:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16322026/10/29 01:22:01 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo16332026/10/29 01:22:01 INFO Aborted multipart uploads count=0 kept=01634=== CONT TestPush_RootsAreLockedInByteOrder1635--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.96s)16362026/10/29 01:22:01 INFO Received uploads request method=POST path=/api/pending_closures16372026/10/29 01:22:01 INFO Received uploads request method=POST path=/api/pending_closures1638--- PASS: TestTombstonedObjectOfferedWithoutWaiting (1.02s)1639=== CONT TestReadProxyRangeRequest16402026/10/29 01:22:01 INFO Received uploads request method=POST path=/api/pending_closures16412026/10/29 01:22:01 INFO Aborted multipart uploads count=0 kept=01642--- PASS: TestDeduplicatedObjectsRecordedAsPending (1.02s)1643=== CONT TestGCTaskStore_StartNew1644=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1645--- PASS: TestGCTaskStore_StartNew (0.00s)16462026/10/29 01:22:01 WARN readiness check failed error="closed pool"1647--- PASS: TestService_readinessHandler (1.46s)1648=== CONT TestReadProxyDisabled16492026/10/29 01:22:01 INFO lead: acquired remote=192.0.2.1:12341650=== CONT TestPush_CompleteCommitsEveryRoot1651--- PASS: TestMetricsInventory (1.45s)16522026/10/29 01:22:01 INFO Received uploads request method=POST path=/api/pending_closures1653=== CONT TestGCEndsOnShutdown1654=== RUN TestGCEndsOnShutdown/before_the_run1655--- PASS: TestService_healthCheckHandler (1.53s)1656=== PAUSE TestGCEndsOnShutdown/before_the_run1657=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1658=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1659=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1660=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1661=== CONT TestLeadEndsOnShutdown16622026/10/29 01:22:02 INFO Aborted multipart uploads count=0 kept=01663--- PASS: TestCacheStatsHandler (1.48s)1664=== CONT TestReadProxyHead1665--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (1.56s)1666=== CONT TestPush_CompleteWaitsForCleanupOfThePush1667--- PASS: TestConnectSerialisesConcurrentMigrations (1.66s)1668=== CONT TestClientWithDependencies16692026/10/29 01:22:02 WARN Force mode enabled - objects will be deleted immediately without grace period16702026/10/29 01:22:02 WARN Force mode enabled - objects will be deleted immediately without grace period16712026/10/29 01:22:02 WARN Force mode enabled - objects will be deleted immediately without grace period16722026/10/29 01:22:02 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016732026/10/29 01:22:02 INFO Vacuumed table table=pending_closures1674=== NAME TestNARDeduplicationMetadataUploadBug1675 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3907936445/001/store/dnwmmd7z0jsvc1d9cpn1fbqgfqd8v8v0-file1.txt16762026/10/29 01:22:02 INFO Received push request method=POST path=/api/pushes16772026/10/29 01:22:02 INFO Vacuumed table table=pending_objects16782026/10/29 01:22:02 INFO Vacuumed table table=multipart_uploads16792026/10/29 01:22:02 INFO Vacuumed table table=closures16802026/10/29 01:22:02 INFO Vacuumed table table=objects16812026/10/29 01:22:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16822026/10/29 01:22:02 INFO Uploading fqkxr68q4d8jclzk5ha841aw1id471a2-unpinned-file.txt (128B)16832026/10/29 01:22:02 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."16842026/10/29 01:22:02 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."16852026/10/29 01:22:02 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016862026/10/29 01:22:02 INFO Vacuumed table table=pending_closures16872026/10/29 01:22:02 INFO Vacuumed table table=pending_objects16882026/10/29 01:22:02 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16892026/10/29 01:22:02 INFO Vacuumed table table=multipart_uploads16902026/10/29 01:22:02 INFO Vacuumed table table=closures16912026/10/29 01:22:02 WARN Failed to register uploaded object key=fqkxr68q4d8jclzk5ha841aw1id471a2.ls error="server returned 404: 404 page not found\n"16922026/10/29 01:22:02 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16932026/10/29 01:22:02 INFO Vacuumed table table=objects16942026/10/29 01:22:02 INFO Signed narinfos id=2 count=116952026/10/29 01:22:02 INFO Uploading 1 narinfos1696=== CONT TestClientFallsBackToClosures1697--- PASS: TestFailedS3DeleteKeepsTombstone (1.67s)16982026/10/29 01:22:02 INFO Received complete push request method=POST path=/api/pushes/2/complete16992026/10/29 01:22:02 WARN Failed to register uploaded object key=fqkxr68q4d8jclzk5ha841aw1id471a2.narinfo error="server returned 404: 404 page not found\n"17002026/10/29 01:22:02 INFO Completed push id=2 objects=3 duration=3.413711ms17012026/10/29 01:22:02 INFO Upload complete. (1.121s)1702=== CONT TestClientErrorHandling1703=== RUN TestClientErrorHandling/InvalidStorePath1704--- PASS: TestSweepRechecksPendingAfterLocking (1.87s)1705=== PAUSE TestClientErrorHandling/InvalidStorePath1706=== RUN TestClientErrorHandling/InvalidAuthToken1707=== PAUSE TestClientErrorHandling/InvalidAuthToken1708=== RUN TestClientErrorHandling/ServerNotAvailable1709=== PAUSE TestClientErrorHandling/ServerNotAvailable1710=== CONT TestPush_OverlappingRootsStoreOneRowPerKey17112026/10/29 01:22:02 INFO Received push request method=POST path=/api/pushes1712--- PASS: TestReadProxyRangeRequest (0.89s)1713=== CONT TestReadRedirectUsesPublicS3URL17142026/10/29 01:22:02 INFO Received push request method=POST path=/api/pushes17152026/10/29 01:22:02 INFO Received push request method=POST path=/api/pushes17162026/10/29 01:22:02 INFO Received push request method=POST path=/api/pushes17172026/10/29 01:22:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17182026/10/29 01:22:02 INFO Uploading syfl03mgswx25llkj0i4grk23i1ryrn5-test-file.txt (152B)17192026/10/29 01:22:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures17202026/10/29 01:22:02 INFO Garbage collection started1721=== CONT TestIsValidUploadKey/narinfo1722--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (3.78s)1723=== CONT TestIsValidUploadKey/realisation1724=== CONT TestIsValidUploadKey/empty_key1725=== CONT TestIsValidUploadKey/absolute1726=== CONT TestIsValidUploadKey/unknown_type1727=== CONT TestIsValidUploadKey/traversal_nar1728=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1729=== CONT TestIsValidUploadKey/traversal1730=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1731=== CONT TestIsValidUploadKey/index.html1732=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1733=== CONT TestIsValidUploadKey/nix-cache-info1734=== CONT TestIsValidUploadKey/build_log_equals1735=== CONT TestIsValidUploadKey/realisation_plus_in_output1736=== CONT TestIsValidUploadKey/build_log_question_mark1737=== CONT TestIsValidUploadKey/build_log_plus_in_name1738=== CONT TestIsValidUploadKey/build_log_home-manager_file1739=== CONT TestIsValidUploadKey/nar_xz1740=== CONT TestIsValidUploadKey/listing1741=== CONT TestIsValidUploadKey/nar_plain1742=== CONT TestIsValidUploadKey/nar_zst1743=== CONT TestIsValidUploadKey/build_log1744=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1745--- PASS: TestIsValidUploadKey (0.00s)1746 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1747 --- PASS: TestIsValidUploadKey/realisation (0.00s)1748 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1749 --- PASS: TestIsValidUploadKey/absolute (0.00s)1750 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1751 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1752 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1753 --- PASS: TestIsValidUploadKey/traversal (0.00s)1754 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1755 --- PASS: TestIsValidUploadKey/index.html (0.00s)1756 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1757 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1758 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1759 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1760 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1761 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1762 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1763 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1764 --- PASS: TestIsValidUploadKey/listing (0.00s)1765 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1766 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1767 --- PASS: TestIsValidUploadKey/build_log (0.00s)17682026/10/29 01:22:02 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17692026/10/29 01:22:02 INFO Aborted multipart uploads count=0 kept=017702026/10/29 01:22:02 WARN Failed to register uploaded object key=syfl03mgswx25llkj0i4grk23i1ryrn5.ls error="server returned 404: 404 page not found\n"17712026/10/29 01:22:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17722026/10/29 01:22:02 INFO Signed narinfos id=1 count=117732026/10/29 01:22:02 INFO Uploading 1 narinfos1774--- PASS: TestCommitRacingPendingCleanupKeepsObjects (2.19s)1775=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale17762026/10/29 01:22:02 WARN Force mode enabled - objects will be deleted immediately without grace period17772026/10/29 01:22:02 INFO Received complete push request method=POST path=/api/pushes/1/complete17782026/10/29 01:22:02 WARN Failed to register uploaded object key=syfl03mgswx25llkj0i4grk23i1ryrn5.narinfo error="server returned 404: 404 page not found\n"17792026/10/29 01:22:02 INFO Received push request method=POST path=/api/pushes17802026/10/29 01:22:02 INFO Completed push id=1 objects=3 duration=9.405866ms17812026/10/29 01:22:02 INFO Upload complete. (244ms)17822026/10/29 01:22:02 INFO Received push request method=POST path=/api/pushes17832026/10/29 01:22:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17842026/10/29 01:22:02 INFO Uploading dnwmmd7z0jsvc1d9cpn1fbqgfqd8v8v0-file1.txt (160B)17852026/10/29 01:22:02 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"17862026/10/29 01:22:02 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=017872026/10/29 01:22:02 WARN Failed to register uploaded object key=dnwmmd7z0jsvc1d9cpn1fbqgfqd8v8v0.ls error="server returned 404: 404 page not found\n"17882026/10/29 01:22:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17892026/10/29 01:22:02 INFO Signed narinfos id=1 count=117902026/10/29 01:22:02 INFO Vacuumed table table=pending_closures17912026/10/29 01:22:02 INFO Uploading 1 narinfos17922026/10/29 01:22:02 INFO Vacuumed table table=pending_objects17932026/10/29 01:22:02 INFO Vacuumed table table=multipart_uploads17942026/10/29 01:22:02 INFO Received complete push request method=POST path=/api/pushes/1/complete17952026/10/29 01:22:02 WARN Failed to register uploaded object key=dnwmmd7z0jsvc1d9cpn1fbqgfqd8v8v0.narinfo error="server returned 404: 404 page not found\n"17962026/10/29 01:22:02 INFO Vacuumed table table=closures17972026/10/29 01:22:02 INFO Vacuumed table table=objects17982026/10/29 01:22:02 INFO Completed push id=1 objects=3 duration=7.253507ms17992026/10/29 01:22:02 INFO Upload complete. (111ms)1800=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1801--- PASS: TestReadProxyDisabled (0.97s)18022026/10/29 01:22:02 INFO Received uploads request method=POST path=/1803=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18042026/10/29 01:22:02 INFO Received uploads request method=POST path=/1805=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18062026/10/29 01:22:02 INFO Received complete multipart upload request method=POST path=/1807=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18082026/10/29 01:22:02 INFO Received request for more parts method=POST path=/1809=== CONT TestProxyWriteTimeout/1_GiB_nar1810--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1811 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1812 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1813 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1814 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1815=== CONT TestProxyWriteTimeout/10_GiB_nar1816=== CONT TestProxyWriteTimeout/unknown_size1817=== CONT TestProxyWriteTimeout/narinfo1818=== CONT TestService_RequireScope_OIDC/builder_may_write1819=== NAME TestNARDeduplicationMetadataUploadBug1820 metadata_upload_test.go:54: Retrieved narinfo from S3:1821 StorePath: /build/TestNARDeduplicationMetadataUploadBug3907936445/001/store/dnwmmd7z0jsvc1d9cpn1fbqgfqd8v8v0-file1.txt1822 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1823 Compression: zstd1824 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1825 NarSize: 1601826 References: 1827 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1828--- PASS: TestProxyWriteTimeout (0.00s)1829 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1830 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1831 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1832 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1833=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1834=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18352026/10/29 01:22:02 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]1836=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1837=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1838=== CONT TestService_RequireScope_OIDC/static_token_may_admin1839=== CONT TestService_RequireScope_OIDC/writer_implies_read1840=== CONT TestService_RequireScope_OIDC/reader_may_read1841=== CONT TestService_RequireScope_OIDC/reader_may_not_write1842=== NAME TestNARDeduplicationMetadataUploadBug1843 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1844=== CONT TestService_RequireScope_OIDC/static_token_may_write1845=== NAME TestNARDeduplicationMetadataUploadBug1846 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1847 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1848=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1849=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1850=== CONT TestService_RequireScope_OIDC/ops_may_not_write18512026/10/29 01:22:02 INFO Aborted multipart uploads count=0 kept=01852=== CONT TestService_RequireScope_OIDC/ops_may_admin1853=== CONT TestPush_RejectsBadRequests/root_not_in_objects18542026/10/29 01:22:02 INFO Received push request method=POST path=/api/pushes1855=== CONT TestPush_RejectsBadRequests/bad_root18562026/10/29 01:22:02 INFO Received push request method=POST path=/api/pushes1857=== CONT TestPush_RejectsBadRequests/no_objects18582026/10/29 01:22:02 INFO Received push request method=POST path=/api/pushes1859=== CONT TestPush_RejectsBadRequests/no_roots18602026/10/29 01:22:02 INFO Received push request method=POST path=/api/pushes1861=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18622026/10/29 01:22:02 WARN Force mode enabled - objects will be deleted immediately without grace period18632026/10/29 01:22:02 INFO All 1 paths already cached1864=== NAME TestClientIntegration1865 client_integration_test.go:357: Retrieved narinfo from S3:1866 StorePath: /build/TestClientIntegration351051131/002/store/syfl03mgswx25llkj0i4grk23i1ryrn5-test-file.txt1867 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1868 Compression: zstd1869 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11870 NarSize: 1521871 References: 1872 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk118732026/10/29 01:22:02 INFO lead: acquired remote=192.0.2.1:123418742026/10/29 01:22:02 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=018752026/10/29 01:22:02 INFO Vacuumed table table=pending_closures18762026/10/29 01:22:02 INFO Vacuumed table table=pending_objects18772026/10/29 01:22:02 INFO Vacuumed table table=multipart_uploads18782026/10/29 01:22:02 INFO Vacuumed table table=closures18792026/10/29 01:22:02 INFO Vacuumed table table=objects1880 client_integration_test.go:358: Retrieved .ls file from S3 (compressed size: 77 bytes)1881 client_integration_test.go:358: Decompressed .ls content (64 bytes):1882 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1883--- PASS: TestPush_RejectsBadRequests (1.78s)1884 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1885 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1886 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1887 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1888=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1889--- PASS: TestReadProxyHead (0.85s)18902026/10/29 01:22:02 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"1891=== NAME TestNARDeduplicationMetadataUploadBug1892 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3907936445/001/store/vjxhwsw4hclmk35w6klrq2sr60mqf686-file2.txt1893=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1894--- PASS: TestGCMetrics (1.31s)1895=== CONT TestIsValidCachePath/index.html1896=== CONT TestIsValidCachePath/short_hash1897=== CONT TestIsValidCachePath/wrong_extension1898=== CONT TestIsValidCachePath/leading_slash1899=== CONT TestIsValidCachePath/empty1900=== CONT TestIsValidCachePath/invalid_char_u1901=== CONT TestIsValidCachePath/invalid_char_e1902=== CONT TestIsValidCachePath/traversal_in_middle1903=== CONT TestIsValidCachePath/random_path1904=== CONT TestIsValidCachePath/traversal_parent1905=== CONT TestIsValidCachePath/nar_bz21906=== CONT TestIsValidCachePath/realisation1907=== CONT TestIsValidCachePath/log1908=== CONT TestIsValidCachePath/nix-cache-info1909=== CONT TestIsValidCachePath/ls1910=== CONT TestIsValidCachePath/nar_zst1911--- PASS: TestService_RequireScope_OIDC (0.77s)1912 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1913 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1914 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1915 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1916 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1917 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1918 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1919 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1920 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1921 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1922 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1923 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1924 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1925 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1926=== CONT TestIsValidCachePath/nar_xz1927=== CONT TestIsValidCachePath/narinfo1928=== CONT TestIsValidCachePath/nar_uncompressed1929=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1930--- PASS: TestIsValidCachePath (0.00s)1931 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1932 --- PASS: TestIsValidCachePath/index.html (0.00s)1933 --- PASS: TestIsValidCachePath/short_hash (0.00s)1934 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1935 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1936 --- PASS: TestIsValidCachePath/empty (0.00s)1937 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1938 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1939 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1940 --- PASS: TestIsValidCachePath/random_path (0.00s)1941 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1942 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1943 --- PASS: TestIsValidCachePath/realisation (0.00s)1944 --- PASS: TestIsValidCachePath/log (0.00s)1945 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1946 --- PASS: TestIsValidCachePath/ls (0.00s)1947 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1948 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1949 --- PASS: TestIsValidCachePath/narinfo (0.00s)1950 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1951--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (1.96s)1952=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false19532026/10/29 01:22:03 INFO Received push request method=POST path=/api/pushes19542026/10/29 01:22:03 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19552026/10/29 01:22:03 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign19562026/10/29 01:22:03 WARN Failed to register uploaded object key=vjxhwsw4hclmk35w6klrq2sr60mqf686.ls error="server returned 404: 404 page not found\n"19572026/10/29 01:22:03 INFO Signed narinfos id=2 count=119582026/10/29 01:22:03 INFO Uploading 1 narinfos19592026/10/29 01:22:03 INFO Received complete push request method=POST path=/api/pushes/2/complete19602026/10/29 01:22:03 INFO Received push request method=POST path=/api/pushes19612026/10/29 01:22:03 WARN Failed to register uploaded object key=vjxhwsw4hclmk35w6klrq2sr60mqf686.narinfo error="server returned 404: 404 page not found\n"19622026/10/29 01:22:03 INFO Completed push id=2 objects=3 duration=2.781986ms19632026/10/29 01:22:03 INFO Upload complete. (128ms)1964=== NAME TestNARDeduplicationMetadataUploadBug1965 metadata_upload_test.go:76: Retrieved narinfo from S3:1966 StorePath: /build/TestNARDeduplicationMetadataUploadBug3907936445/001/store/vjxhwsw4hclmk35w6klrq2sr60mqf686-file2.txt1967 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1968 Compression: zstd1969 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1970 NarSize: 1601971 References: 1972 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1973 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1974 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1975 {"version":1,"root":{"type":"regular","size":44}}1976=== CONT TestServerTLSConfig/no_client_CA1977--- PASS: TestNARDeduplicationMetadataUploadBug (2.39s)1978=== CONT TestServerTLSConfig/not_a_PEM_file1979=== CONT TestServerTLSConfig/missing_CA_file1980=== CONT TestParseSingleRange/none1981--- PASS: TestServerTLSConfig (0.00s)1982 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1983 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1984 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1985=== CONT TestParseSingleRange/start_far_past_EOF1986=== CONT TestParseSingleRange/single_byte19872026/10/29 01:22:03 INFO lead: released remote=192.0.2.1:12341988=== CONT TestParseSingleRange/malformed_end_before_start1989=== CONT TestParseSingleRange/end_clamped_to_size1990=== CONT TestParseSingleRange/start_past_EOF1991=== CONT TestParseSingleRange/malformed_both_empty1992=== CONT TestParseSingleRange/suffix1993=== CONT TestParseSingleRange/unknown_unit1994=== CONT TestParseSingleRange/malformed_no_dash1995=== CONT TestParseSingleRange/suffix_exceeds_size1996=== CONT TestParseSingleRange/closed1997=== CONT TestParseSingleRange/open-ended1998=== CONT TestParseSingleRange/multi-range_ignored1999=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2000--- PASS: TestParseSingleRange (0.00s)2001 --- PASS: TestParseSingleRange/none (0.00s)2002 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2003 --- PASS: TestParseSingleRange/single_byte (0.00s)2004 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2005 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2006 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2007 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2008 --- PASS: TestParseSingleRange/suffix (0.00s)2009 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2010 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2011 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2012 --- PASS: TestParseSingleRange/closed (0.00s)2013 --- PASS: TestParseSingleRange/open-ended (0.00s)2014 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2015=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2016--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.52s)2017=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20182026/10/29 01:22:03 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2019=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token20202026/10/29 01:22:03 WARN Authentication failed token_preview=eyJhbGciOi...C35tPiTHrA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2021=== CONT TestPendingClosureWriteTimeout/670k_objects2022=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline2023=== CONT TestPendingClosureWriteTimeout/400_objects2024=== CONT TestPendingClosureWriteTimeout/empty2025=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure20262026/10/29 01:22:03 INFO Received uploads request method=POST path=/2027--- PASS: TestService_AuthMiddleware_OIDC (1.54s)2028 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2029 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2030 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)2031 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)20322026/10/29 01:22:03 INFO lead: acquired remote=192.0.2.1:123420332026/10/29 01:22:03 INFO Received uploads request method=POST path=/api/pending_closures20342026/10/29 01:22:03 INFO Aborted multipart uploads count=0 kept=020352026/10/29 01:22:03 INFO Received uploads request method=POST path=/api/pending_closures20362026/10/29 01:22:03 INFO Aborted multipart uploads count=0 kept=020372026/10/29 01:22:03 INFO Received uploads request method=POST path=/api/pending_closures2038--- PASS: TestReadRedirectUsesPublicS3URL (0.57s)2039=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart20402026/10/29 01:22:03 INFO Received complete multipart upload request method=POST path=/20412026/10/29 01:22:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20422026/10/29 01:22:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20432026/10/29 01:22:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20442026/10/29 01:22:03 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLjIwYTU5NWQzLWQ0ZjMtNDkzMS1iZTIxLWNlY2U1ZWMwNjNhM3gxNzkzMjM2OTIyODEzNjczMzU1 parts=1020452026/10/29 01:22:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20462026/10/29 01:22:03 WARN Force mode enabled - objects will be deleted immediately without grace period20472026/10/29 01:22:03 WARN Force mode enabled - objects will be deleted immediately without grace period20482026/10/29 01:22:03 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020492026/10/29 01:22:03 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLjI3MWUwNjcxLWI1YTAtNDNiOC1hNGVmLTBlMDNjMzgxNzAxYngxNzkzMjM2OTIyNzQ4Mzc0ODc1 parts=1020502026/10/29 01:22:03 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLmNlOTY2MzU2LWMxMTAtNDViYy1hMDdlLTViOTA2ZTNmYmM2ZngxNzkzMjM2OTIyODc1NzkzODg2 parts=1020512026/10/29 01:22:03 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLjA5N2FiZmVjLWZhNWYtNDRlNy1iNGVhLTcwMjY5MTZiZmU1MXgxNzkzMjM2OTIyNzc2Njc0Nzc1 parts=1020522026/10/29 01:22:03 INFO Vacuumed table table=pending_closures20532026/10/29 01:22:03 INFO Vacuumed table table=pending_objects20542026/10/29 01:22:03 INFO Vacuumed table table=multipart_uploads20552026/10/29 01:22:03 INFO Vacuumed table table=closures20562026/10/29 01:22:03 INFO Vacuumed table table=objects20572026/10/29 01:22:03 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=020582026/10/29 01:22:03 INFO Vacuumed table table=pending_closures20592026/10/29 01:22:03 INFO Vacuumed table table=pending_objects20602026/10/29 01:22:03 INFO Vacuumed table table=multipart_uploads20612026/10/29 01:22:03 INFO Vacuumed table table=closures20622026/10/29 01:22:03 INFO Vacuumed table table=objects2063=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts20642026/10/29 01:22:03 INFO Received request for more parts method=POST path=/20652026/10/29 01:22:03 INFO Received uploads request method=POST path=/api/pending_closures2066=== NAME TestClientCADerivations2067 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2068 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2069 error: binary cache 's3://bucket35?endpoint=http://localhost:42795®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3363129338/001/store'2070 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12071=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2072--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2073 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.72s)2074 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.71s)2075=== CONT TestCacheConfigHandler/no_signing_keys2076=== CONT TestCacheConfigHandler/no_cache_url_configured2077=== CONT TestCacheConfigHandler/full_config,_no_issuer2078=== CONT TestResolveDBConnectionString/flag_wins2079--- PASS: TestCacheConfigHandler (0.00s)2080 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2081 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2082 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2083 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2084=== CONT TestResolveDBConnectionString/nothing_configured2085=== CONT TestResolveDBConnectionString/missing_file_is_an_error2086=== CONT TestResolveDBConnectionString/file_when_flag_empty2087=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2088=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete2089--- PASS: TestResolveDBConnectionString (0.00s)2090 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2091 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2092 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2093 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2094 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)20952026/10/29 01:22:03 INFO Received push request method=POST path=/api/pushes20962026/10/29 01:22:03 INFO Received uploads request method=POST path=/api/pending_closures20972026/10/29 01:22:03 INFO Object in database but missing from S3 key=syfl03mgswx25llkj0i4grk23i1ryrn5.ls20982026/10/29 01:22:03 WARN Found objects in DB but missing from S3, will re-upload count=120992026/10/29 01:22:03 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21002026-10-29 01:22:03.708 UTC [1719] ERROR: Push does not exist: id=121012026-10-29 01:22:03.708 UTC [1719] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE21022026-10-29 01:22:03.708 UTC [1719] STATEMENT: SELECT commit_push($1)2103=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark21042026/10/29 01:22:03 INFO Received complete push request method=POST path=/api/pushes/2/complete2105--- PASS: TestClientCADerivations (5.72s)21062026/10/29 01:22:03 WARN Failed to register uploaded object key=syfl03mgswx25llkj0i4grk23i1ryrn5.ls error="server returned 404: 404 page not found\n"21072026/10/29 01:22:03 INFO Completed push id=2 objects=3 duration=3.785835ms21082026/10/29 01:22:03 INFO Upload complete. (627ms)2109=== NAME TestClientIntegration2110 client_integration_test.go:375: Retrieved .ls file from S3 (compressed size: 62 bytes)2111 client_integration_test.go:375: Decompressed .ls content (49 bytes):2112 {"version":1,"root":{"type":"regular","size":39}}2113=== CONT TestGCEndsOnShutdown/before_the_run2114--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.53s)2115=== CONT TestClientErrorHandling/InvalidAuthToken2116=== CONT TestClientErrorHandling/ServerNotAvailable2117--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.97s)2118 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.91s)2119 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.93s)21202026/10/29 01:22:03 INFO Received push request method=POST path=/api/pushes21212026/10/29 01:22:03 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLmE4NjA0OGZhLTdiZmItNGZjMy1iZTYxLWMzM2JkOTE5ODNmMXgxNzkzMjM2OTIzMzE4OTM0MTc4 error="Access Denied"21222026/10/29 01:22:03 WARN keeping failed pending closure for cleanup to retry the abort id=121232026/10/29 01:22:03 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21242026/10/29 01:22:03 INFO Received complete push request method=POST path=/api/pushes/3/complete21252026/10/29 01:22:03 WARN Failed to register uploaded object key=syfl03mgswx25llkj0i4grk23i1ryrn5.ls error="server returned 404: 404 page not found\n"21262026/10/29 01:22:03 INFO Completed push id=3 objects=3 duration=3.047688ms21272026/10/29 01:22:03 INFO Upload complete. (62ms)2128=== NAME TestClientIntegration2129 client_integration_test.go:392: Retrieved .ls file from S3 (compressed size: 62 bytes)2130 client_integration_test.go:392: Decompressed .ls content (49 bytes):2131 {"version":1,"root":{"type":"regular","size":39}}2132=== NAME TestClientWithDependencies2133 client_integration_test.go:722: Built derivation: /build/TestClientWithDependencies300917435/001/store/hgpmvz6g7mkgiklnpr4lac8mpz5z3mv8-test-script2134=== CONT TestClientErrorHandling/InvalidStorePath21352026/10/29 01:22:03 INFO Received uploads request method=POST path=/api/pending_closures21362026/10/29 01:22:03 INFO Received uploads request method=POST path=/api/pending_closures21372026/10/29 01:22:03 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)21382026/10/29 01:22:03 INFO Uploading 9vls8g80fp3xhzny4wh3f1kpjhdc1pi4-shared-dep (136B)21392026/10/29 01:22:03 INFO Uploading sr11kn0zaag8h0hpvmy5433ymk6bqsqq-b (216B)21402026/10/29 01:22:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"21412026/10/29 01:22:03 WARN Failed to register uploaded object key=rc2wdg9d36hd2axy3smi7wmks3f87xnz.ls error="server returned 404: 404 page not found\n"21422026/10/29 01:22:03 WARN Failed to register uploaded object key=nar/0pj2r01q1lc5pjgn1iz408mcdijr0cxh9yk90xh72zw8826w55fk.nar.zst error="server returned 404: 404 page not found\n"21432026/10/29 01:22:03 WARN Failed to register uploaded object key=9vls8g80fp3xhzny4wh3f1kpjhdc1pi4.ls error="server returned 404: 404 page not found\n"21442026/10/29 01:22:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21452026/10/29 01:22:03 WARN Failed to register uploaded object key=sr11kn0zaag8h0hpvmy5433ymk6bqsqq.ls error="server returned 404: 404 page not found\n"21462026/10/29 01:22:03 INFO Signed narinfos id=2 count=221472026/10/29 01:22:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21482026/10/29 01:22:03 INFO Signed narinfos id=1 count=221492026/10/29 01:22:03 INFO Uploading 4 narinfos21502026/10/29 01:22:03 INFO Aborted multipart uploads count=0 kept=021512026/10/29 01:22:03 WARN Failed to register uploaded object key=9vls8g80fp3xhzny4wh3f1kpjhdc1pi4.narinfo error="server returned 404: 404 page not found\n"21522026/10/29 01:22:03 WARN Failed to register uploaded object key=sr11kn0zaag8h0hpvmy5433ymk6bqsqq.narinfo error="server returned 404: 404 page not found\n"21532026/10/29 01:22:03 WARN Failed to register uploaded object key=rc2wdg9d36hd2axy3smi7wmks3f87xnz.narinfo error="server returned 404: 404 page not found\n"21542026/10/29 01:22:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21552026/10/29 01:22:03 WARN Failed to register uploaded object key=9vls8g80fp3xhzny4wh3f1kpjhdc1pi4.narinfo error="server returned 404: 404 page not found\n"21562026/10/29 01:22:03 INFO Completed upload id=1 objects=6 duration=8.196775ms21572026/10/29 01:22:03 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21582026/10/29 01:22:03 INFO Completed upload id=2 objects=6 duration=1.303272ms21592026/10/29 01:22:03 INFO Upload complete. (138ms)2160=== NAME TestClientFallsBackToClosures2161 client_pushes_test.go:112: Retrieved narinfo from S3:2162 StorePath: /build/TestClientFallsBackToClosures3897201810/001/store/9vls8g80fp3xhzny4wh3f1kpjhdc1pi4-shared-dep2163 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2164 Compression: zstd2165 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822166 NarSize: 1362167 References: 2168 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2169 client_pushes_test.go:112: Retrieved narinfo from S3:2170 StorePath: /build/TestClientFallsBackToClosures3897201810/001/store/rc2wdg9d36hd2axy3smi7wmks3f87xnz-a2171 URL: nar/0pj2r01q1lc5pjgn1iz408mcdijr0cxh9yk90xh72zw8826w55fk.nar.zst2172 Compression: zstd2173 NarHash: sha256:0pj2r01q1lc5pjgn1iz408mcdijr0cxh9yk90xh72zw8826w55fk2174 NarSize: 2162175 References: /build/TestClientFallsBackToClosures3897201810/001/store/9vls8g80fp3xhzny4wh3f1kpjhdc1pi4-shared-dep2176 CA: text:sha256:1k28kgqhini7sgbwzqlc5x7a2rxr5g6ziz4m2xk1aciaclrh5glm2177 client_pushes_test.go:112: Retrieved narinfo from S3:2178 StorePath: /build/TestClientFallsBackToClosures3897201810/001/store/sr11kn0zaag8h0hpvmy5433ymk6bqsqq-b2179 URL: nar/0pj2r01q1lc5pjgn1iz408mcdijr0cxh9yk90xh72zw8826w55fk.nar.zst2180 Compression: zstd2181 NarHash: sha256:0pj2r01q1lc5pjgn1iz408mcdijr0cxh9yk90xh72zw8826w55fk2182 NarSize: 2162183 References: /build/TestClientFallsBackToClosures3897201810/001/store/9vls8g80fp3xhzny4wh3f1kpjhdc1pi4-shared-dep2184 CA: text:sha256:1k28kgqhini7sgbwzqlc5x7a2rxr5g6ziz4m2xk1aciaclrh5glm21852026/10/29 01:22:03 INFO Aborted multipart uploads count=0 kept=021862026/10/29 01:22:03 INFO lead: released remote=192.0.2.1:12342187--- PASS: TestClientFallsBackToClosures (1.32s)2188--- PASS: TestLeadEndsOnShutdown (2.01s)21892026/10/29 01:22:04 WARN Rate limiter enabled after throttle name=s3-test rate=521902026/10/29 01:22:04 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2191=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2192 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102193 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002194--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.85s)21952026/10/29 01:22:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21962026/10/29 01:22:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21972026/10/29 01:22:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21982026/10/29 01:22:04 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLmJlYjhjMjIxLWVmY2MtNDYwMy1iYmZhLTgzMzc1MzNjMGRjZXgxNzkzMjM2OTIyNzQ4MTY5ODEz parts=1021992026/10/29 01:22:04 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLmMxNzc1OGY0LWUxZjEtNGY3Yy1iMDRjLWVkNzI5OGYxZjIyZHgxNzkzMjM2OTIyNzc0NzYxODU3 parts=1022002026/10/29 01:22:04 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLjk4Y2UwNzFkLWQyOTAtNGY0My1hMTQyLWRiNmM1OGI4MTljNHgxNzkzMjM2OTIyODc1NzU0NzI1 parts=1022012026/10/29 01:22:04 INFO Received complete push request method=POST path=/api/pushes/1/complete22022026/10/29 01:22:04 INFO Completed push id=1 objects=4 duration=4.698263ms22032026/10/29 01:22:04 INFO Received push request method=POST path=/api/pushes2204--- PASS: TestPendingClosureFailureTracksEveryUpload (0.00s)2205 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (0.82s)2206 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (1.15s)22072026/10/29 01:22:04 INFO Aborted multipart uploads count=0 kept=022082026/10/29 01:22:04 WARN Force mode enabled - objects will be deleted immediately without grace period22092026/10/29 01:22:04 INFO lead: released remote=192.0.2.1:12342210--- PASS: TestLeadElectsOneAndHandsOver (2.93s)2211--- PASS: TestPendingClosureWriteTimeout (0.00s)2212 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2213 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2214 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2215 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.29s)22162026/10/29 01:22:04 WARN Force mode enabled - objects will be deleted immediately without grace period22172026-10-29 01:22:04.577 UTC [174] LOG: checkpoints are occurring too frequently (21 seconds apart)22182026-10-29 01:22:04.577 UTC [174] HINT: Consider increasing the configuration parameter "max_wal_size".22192026-10-29 01:22:04.577 UTC [174] LOG: checkpoint starting: wal22202026/10/29 01:22:04 WARN Force mode enabled - objects will be deleted immediately without grace period2221=== NAME TestClientWithDependencies2222 client_integration_test.go:724: Found 1 dependencies (including self)22232026/10/29 01:22:04 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/present22242026/10/29 01:22:04 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:42795/bucket104/?delete=\": context canceled"22252026-10-29 01:22:04.590 UTC [1958] ERROR: canceling statement due to user request22262026-10-29 01:22:04.590 UTC [1958] STATEMENT: -- name: MarkStaleObjects :execrows2227 WITH RECURSIVE ct AS (2228 SELECT timezone('UTC', now()) AS now2229 ),2230 closure_reach AS (2231 -- Start with all closure keys2232 SELECT o.key, o.refs2233 FROM objects o2234 INNER JOIN closures c ON o.key = c.key2235 UNION2236 -- Recursively add all referenced objects2237 SELECT o.key, o.refs2238 FROM objects o2239 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2240 ),2241 reachable_objects AS (2242 SELECT DISTINCT key FROM closure_reach2243 ),2244 stale_objects AS (2245 SELECT o.key2246 FROM objects AS o, ct2247 WHERE2248 NOT EXISTS (2249 SELECT 12250 FROM reachable_objects ro2251 WHERE ro.key = o.key2252 )2253 AND NOT EXISTS (2254 SELECT 12255 FROM pending_objects AS po2256 WHERE po.key = o.key2257 )2258 AND o.deleted_at IS NULL -- Only mark fresh objects2259 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2260 FOR UPDATE2261 )2262 UPDATE objects2263 SET2264 deleted_at = ct.now,2265 first_deleted_at = COALESCE(first_deleted_at, ct.now)2266 FROM stale_objects, ct2267 WHERE objects.key = stale_objects.key2268 2269--- PASS: TestGCEndsOnShutdown (0.00s)2270 --- PASS: TestGCEndsOnShutdown/before_the_run (0.28s)2271 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.93s)2272 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.90s)22732026/10/29 01:22:04 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=022742026/10/29 01:22:04 INFO Vacuumed table table=pending_closures22752026/10/29 01:22:04 INFO Vacuumed table table=pending_objects22762026/10/29 01:22:04 INFO Vacuumed table table=multipart_uploads22772026/10/29 01:22:04 INFO Vacuumed table table=closures22782026/10/29 01:22:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22792026/10/29 01:22:04 INFO Vacuumed table table=objects22802026/10/29 01:22:04 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLjk1Nzc0NmNkLTkxYmQtNGUwZC04MTA0LTI4Mjk5YjdkMjU1ZXgxNzkzMjM2OTIyNzQ3NTgyNDY3 parts=1022812026/10/29 01:22:04 INFO Received complete push request method=POST path=/api/pushes/1/complete22822026/10/29 01:22:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22832026/10/29 01:22:04 INFO Completed push id=1 objects=6 duration=4.871944ms22842026/10/29 01:22:04 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLjVhN2YxYjc0LTAxMzMtNDllZS1iYmI1LWQ3MDQzODlhY2RiNHgxNzkzMjM2OTIyODc1NzM2MDg1 parts=1022852026/10/29 01:22:04 INFO Received push request method=POST path=/api/pushes22862026/10/29 01:22:04 INFO Received push request method=POST path=/api/pushes22872026/10/29 01:22:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22882026/10/29 01:22:04 INFO Uploading c3wbj11cc26hqkagbz7fn6agwzmn9cnq-lost-commit.txt (152B)22892026/10/29 01:22:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22902026/10/29 01:22:04 WARN Request failed, retrying attempt=2 backoff=191.695823ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22912026/10/29 01:22:04 INFO Uploading hgpmvz6g7mkgiklnpr4lac8mpz5z3mv8-test-script (136B)2292--- PASS: TestPush_CompleteCommitsEveryRoot (2.73s)22932026/10/29 01:22:04 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"22942026/10/29 01:22:04 WARN Failed to register uploaded object key=log/xkf5l2pg26lnrq0shppjr3nr6v3mvqs3-test-script.drv error="server returned 404: 404 page not found\n"22952026/10/29 01:22:04 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"22962026/10/29 01:22:04 WARN Failed to register uploaded object key=c3wbj11cc26hqkagbz7fn6agwzmn9cnq.ls error="server returned 404: 404 page not found\n"22972026/10/29 01:22:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22982026/10/29 01:22:04 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign22992026/10/29 01:22:04 WARN Failed to register uploaded object key=hgpmvz6g7mkgiklnpr4lac8mpz5z3mv8.ls error="server returned 404: 404 page not found\n"23002026/10/29 01:22:04 INFO Signed narinfos id=4 count=123012026/10/29 01:22:04 INFO Signed narinfos id=1 count=123022026/10/29 01:22:04 INFO Uploading 1 narinfos23032026/10/29 01:22:04 INFO Uploading 1 narinfos23042026/10/29 01:22:04 INFO Received complete push request method=POST path=/api/pushes/1/complete23052026/10/29 01:22:04 INFO Received complete push request method=POST path=/api/pushes/4/complete23062026/10/29 01:22:04 WARN Failed to register uploaded object key=hgpmvz6g7mkgiklnpr4lac8mpz5z3mv8.narinfo error="server returned 404: 404 page not found\n"23072026/10/29 01:22:04 WARN Failed to register uploaded object key=c3wbj11cc26hqkagbz7fn6agwzmn9cnq.narinfo error="server returned 404: 404 page not found\n"23082026/10/29 01:22:04 INFO Completed push id=4 objects=3 duration=2.756926ms23092026/10/29 01:22:04 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:37891/api/pushes/4/complete\": EOF" url=http://127.0.0.1:37891/api/pushes/4/complete23102026/10/29 01:22:04 INFO Completed push id=1 objects=4 duration=6.623061ms23112026/10/29 01:22:04 INFO Upload complete. (89ms)23122026/10/29 01:22:04 INFO Aborted multipart uploads count=0 kept=023132026/10/29 01:22:04 WARN Force mode enabled - objects will be deleted immediately without grace period23142026/10/29 01:22:04 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"23152026/10/29 01:22: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=023162026/10/29 01:22:04 INFO Vacuumed table table=pending_closures23172026/10/29 01:22:04 INFO Vacuumed table table=pending_objects23182026/10/29 01:22:04 INFO Vacuumed table table=multipart_uploads23192026/10/29 01:22:04 INFO Vacuumed table table=closures23202026/10/29 01:22:04 INFO Vacuumed table table=objects2321=== NAME TestClientWithDependencies2322 client_integration_test.go:740: Skipping nix copy test - isolated store (/build/TestClientWithDependencies300917435/001/store) requires matching store prefix2323--- PASS: TestClientWithDependencies (2.21s)23242026/10/29 01:22:04 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"23252026/10/29 01:22:04 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=023262026/10/29 01:22:04 INFO Received complete push request method=POST path=/api/pushes/4/complete23272026/10/29 01:22:04 INFO Received create pin request method=POST path=/api/pins/myapp23282026-10-29 01:22:04.820 UTC [914] ERROR: Push does not exist: id=423292026-10-29 01:22:04.820 UTC [914] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE23302026-10-29 01:22:04.820 UTC [914] STATEMENT: -- name: CommitPush :one2331 SELECT commit_push($1::bigint)::bigint2332 23332026/10/29 01:22:04 WARN Push not found id=423342026/10/29 01:22:04 INFO Upload complete. (200ms)2335=== NAME TestClientIntegration2336 client_integration_test.go:422: Retrieved narinfo from S3:2337 StorePath: /build/TestClientIntegration351051131/002/store/c3wbj11cc26hqkagbz7fn6agwzmn9cnq-lost-commit.txt2338 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst2339 Compression: zstd2340 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2341 NarSize: 1522342 References: 2343 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl23442026/10/29 01:22:04 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2129473580/001/store/snvsqsjfflqczhy7j0s9pdjx176631vf-pinned-file.txt narinfo_key=snvsqsjfflqczhy7j0s9pdjx176631vf.narinfo2345 client_integration_test.go:425: Testing garbage collection...23462026/10/29 01:22:04 INFO Starting cleanup of old closures method=DELETE path=/api/closures23472026/10/29 01:22:04 INFO Garbage collection started23482026/10/29 01:22:04 INFO Aborted multipart uploads count=0 kept=023492026/10/29 01:22:04 WARN Force mode enabled - objects will be deleted immediately without grace period23502026/10/29 01:22: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=023512026/10/29 01:22:04 INFO Vacuumed table table=pending_closures23522026/10/29 01:22:04 INFO Vacuumed table table=pending_objects23532026/10/29 01:22:04 INFO Vacuumed table table=multipart_uploads23542026/10/29 01:22:04 INFO Vacuumed table table=closures23552026/10/29 01:22:04 INFO Vacuumed table table=objects23562026/10/29 01:22:04 WARN Request failed, retrying attempt=3 backoff=380.836477ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2357--- PASS: TestDeleteClosuresRacingPins (4.14s)23582026/10/29 01:22:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23592026/10/29 01:22:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23602026/10/29 01:22:05 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLjFmYjE3M2UxLWM2OGMtNGJiNi1iMTEyLTNjYWYyMjM5OGFiZHgxNzkzMjM2OTIyODc1Nzk1NTQ2 parts=1023612026/10/29 01:22:05 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLmNjNjIyMjBjLTY4ZjQtNGZjNy04MDNkLTVjMzZhYzBmYWE2NngxNzkzMjM2OTI0MTY3NTA2NTc3 parts=1023622026/10/29 01:22:05 INFO Received complete push request method=POST path=/api/pushes/2/complete23632026/10/29 01:22:05 INFO Completed push id=2 objects=4 duration=2.385902ms2364--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.31s)23652026/10/29 01:22:05 WARN Request failed, retrying attempt=4 backoff=739.275062ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23662026/10/29 01:22:05 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23672026/10/29 01:22:05 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLmQ1MWRmNDY4LTViNWEtNDFkNS04YjFlLTRlOTYwYTM2NWRhM3gxNzkzMjM2OTIyODc0NDk4NzM0 parts=1023682026/10/29 01:22:05 INFO Starting cleanup of old closures method=DELETE path=/api/closures23692026/10/29 01:22:05 INFO Garbage collection started23702026/10/29 01:22:05 INFO Aborted multipart uploads count=0 kept=023712026/10/29 01:22:05 WARN Force mode enabled - objects will be deleted immediately without grace period23722026/10/29 01:22:05 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=023732026/10/29 01:22:05 INFO Vacuumed table table=pending_closures23742026/10/29 01:22:05 INFO Vacuumed table table=pending_objects23752026/10/29 01:22:05 INFO Vacuumed table table=multipart_uploads23762026/10/29 01:22:05 INFO Vacuumed table table=closures23772026/10/29 01:22:05 INFO Vacuumed table table=objects23782026/10/29 01:22:06 WARN Request failed, retrying attempt=5 backoff=1.750222432s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23792026/10/29 01:22:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23802026/10/29 01:22:06 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MWI5ZTU1YjctZmQ1ZS00NGVlLTliZGUtNThlNDkwNGUwZjkzLmIxOWRkNDc2LWZiZGUtNDY2MS1hYTU1LWIzN2YwZjdhMzAxYngxNzkzMjM2OTIyODc1NjkyMDY1 parts=1023812026-10-29 01:22:06.167 UTC [1582] ERROR: could not obtain lock on row in relation "closures"23822026-10-29 01:22:06.167 UTC [1582] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23832026-10-29 01:22:06.168 UTC [1582] ERROR: could not obtain lock on row in relation "closures"23842026-10-29 01:22:06.168 UTC [1582] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23852026-10-29 01:22:06.168 UTC [1582] ERROR: could not obtain lock on row in relation "closures"23862026-10-29 01:22:06.168 UTC [1582] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23872026-10-29 01:22:06.168 UTC [1582] ERROR: could not obtain lock on row in relation "closures"23882026-10-29 01:22:06.168 UTC [1582] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23892026-10-29 01:22:06.169 UTC [1582] ERROR: could not obtain lock on row in relation "closures"23902026-10-29 01:22:06.169 UTC [1582] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT2391--- PASS: TestPush_RootsAreLockedInByteOrder (4.39s)2392--- PASS: TestConnectWaitsForAPeerMigration (5.15s)23932026/10/29 01:22:06 INFO Aborted multipart uploads count=1 kept=023942026/10/29 01:22:06 INFO Received cleanup request method=DELETE path=/api/pending_closures23952026/10/29 01:22:06 INFO Aborted multipart uploads count=1 kept=02396--- PASS: TestPendingCleanupUsesOneCutoff (7.68s)2397=== NAME TestPinProtectsFromGC2398 client_integration_test.go:963: Pin successfully protected closure from garbage collection2399--- PASS: TestPinProtectsFromGC (8.06s)24002026/10/29 01:22:07 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02401=== NAME TestClientIntegration2402 client_integration_test.go:432: Objects in database after GC:2403 client_integration_test.go:432: Successfully deleted all objects with GC --force2404--- PASS: TestClientIntegration (8.71s)24052026/10/29 01:22:07 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/29 01:22:07 WARN Request failed, retrying attempt=2 backoff=191.494356ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24072026/10/29 01:22:08 WARN Request failed, retrying attempt=3 backoff=432.877823ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24082026/10/29 01:22:08 WARN Request failed, retrying attempt=4 backoff=746.955238ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24092026/10/29 01:22:09 WARN Request failed, retrying attempt=5 backoff=1.458414392s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24102026/10/29 01:22:10 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"24112026/10/29 01:22: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-config24122026/10/29 01:22:10 WARN Request failed, retrying attempt=2 backoff=217.828958ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24132026/10/29 01:22:11 WARN Request failed, retrying attempt=3 backoff=409.345372ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24142026/10/29 01:22:11 WARN Request failed, retrying attempt=4 backoff=773.752144ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24152026/10/29 01:22:12 WARN Request failed, retrying attempt=5 backoff=1.459622758s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24162026/10/29 01:22:13 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_closures24172026/10/29 01:22:13 WARN Request failed, retrying attempt=2 backoff=200.208715ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24182026/10/29 01:22:14 WARN Request failed, retrying attempt=3 backoff=433.813799ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24192026/10/29 01:22:14 WARN Request failed, retrying attempt=4 backoff=800.213442ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24202026/10/29 01:22:15 WARN Request failed, retrying attempt=5 backoff=1.482745885s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2421--- PASS: TestUploadHandlersRejectOversizedBody (0.68s)2422 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.85s)2423 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.97s)2424 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (13.35s)2425--- PASS: TestClientErrorHandling (0.00s)2426 --- PASS: TestClientErrorHandling/InvalidStorePath (0.88s)2427 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.08s)2428 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.97s)2429PASS2430{"timestamp":"2026-10-29T01:22:16.740714384Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:52140","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(202)"}2431{"timestamp":"2026-10-29T01:22:16.740801325Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:51708","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(203)"}2432{"timestamp":"2026-10-29T01:22:16.741073147Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:53372","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(204)"}2433{"timestamp":"2026-10-29T01:22:16.741189048Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:53536","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(207)"}24342026-10-29 01:22:17.032 UTC [169] LOG: received smart shutdown request24352026-10-29 01:22:17.036 UTC [169] LOG: background worker "logical replication launcher" (PID 179) exited with exit code 124362026-10-29 01:22:17.901 UTC [174] LOG: checkpoint complete: wrote 10173 buffers (62.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=12.623 s, sync=0.656 s, total=13.325 s; sync files=37079, longest=0.002 s, average=0.001 s; distance=533427 kB, estimate=533427 kB; lsn=0/229EF8E0, redo lsn=0/22052C5024372026-10-29 01:22:17.906 UTC [174] LOG: shutting down24382026-10-29 01:22:17.906 UTC [174] LOG: checkpoint starting: shutdown immediate24392026-10-29 01:22:17.926 UTC [174] LOG: checkpoint complete: wrote 224 buffers (1.4%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.005 s, sync=0.013 s, total=0.020 s; sync files=140, longest=0.001 s, average=0.001 s; distance=9843 kB, estimate=481069 kB; lsn=0/229EF958, redo lsn=0/229EF95824402026-10-29 01:22:17.997 UTC [169] LOG: database system is shut down2441Running OIDC tests...2442=== RUN TestAudienceForIssuer2443=== PAUSE TestAudienceForIssuer2444=== RUN TestHTTPClientForHasTimeouts2445=== PAUSE TestHTTPClientForHasTimeouts2446=== RUN TestGlobMatch2447=== PAUSE TestGlobMatch2448=== RUN TestValidateToken_ValidToken2449=== PAUSE TestValidateToken_ValidToken2450=== RUN TestValidateToken_WrongAudience2451=== PAUSE TestValidateToken_WrongAudience2452=== RUN TestValidateToken_Expired2453=== PAUSE TestValidateToken_Expired2454=== RUN TestValidateToken_BoundClaimsMismatch2455=== PAUSE TestValidateToken_BoundClaimsMismatch2456=== RUN TestValidateToken_BoundSubjectMismatch2457=== PAUSE TestValidateToken_BoundSubjectMismatch2458=== RUN TestValidateToken_MultipleProviders2459=== PAUSE TestValidateToken_MultipleProviders2460=== RUN TestValidateToken_NoMatchingProvider2461=== PAUSE TestValidateToken_NoMatchingProvider2462=== RUN TestValidateToken_KubernetesServiceAccount2463=== PAUSE TestValidateToken_KubernetesServiceAccount2464=== RUN TestNewValidator_KubernetesRequiresCA2465=== PAUSE TestNewValidator_KubernetesRequiresCA2466=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2467=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2468=== RUN TestPins_ReservedForMatchingRule2469=== PAUSE TestPins_ReservedForMatchingRule2470=== RUN TestPins_TopLevelShorthand2471=== PAUSE TestPins_TopLevelShorthand2472=== RUN TestPins_ConfigValidation2473=== PAUSE TestPins_ConfigValidation2474=== RUN TestScopes_LegacyProviderDefaultsToWrite2475=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2476=== RUN TestScopes_Rules2477=== PAUSE TestScopes_Rules2478=== RUN TestScopes_ConfigValidation2479=== PAUSE TestScopes_ConfigValidation2480=== CONT TestHTTPClientForHasTimeouts2481=== CONT TestValidateToken_BoundClaimsMismatch2482=== CONT TestNewValidator_KubernetesRequiresCA2483=== CONT TestValidateToken_NoMatchingProvider2484=== CONT TestValidateToken_BoundSubjectMismatch2485=== CONT TestScopes_ConfigValidation2486=== CONT TestScopes_LegacyProviderDefaultsToWrite2487=== CONT TestPins_ConfigValidation2488=== CONT TestPins_TopLevelShorthand2489=== CONT TestPins_ReservedForMatchingRule2490=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2491=== CONT TestScopes_Rules2492=== CONT TestValidateToken_KubernetesServiceAccount2493=== CONT TestValidateToken_ValidToken2494--- PASS: TestScopes_ConfigValidation (0.00s)2495=== CONT TestValidateToken_WrongAudience2496=== CONT TestGlobMatch2497=== CONT TestValidateToken_MultipleProviders2498=== CONT TestAudienceForIssuer2499=== CONT TestValidateToken_Expired2500--- PASS: TestPins_ConfigValidation (0.00s)2501=== RUN TestGlobMatch/foo_foo2502--- PASS: TestAudienceForIssuer (0.00s)2503=== PAUSE TestGlobMatch/foo_foo2504=== RUN TestGlobMatch/foo_bar2505=== PAUSE TestGlobMatch/foo_bar2506=== RUN TestGlobMatch/*_2507=== PAUSE TestGlobMatch/*_2508=== RUN TestGlobMatch/*_anything2509=== PAUSE TestGlobMatch/*_anything2510=== RUN TestGlobMatch/foo*_foo2511=== PAUSE TestGlobMatch/foo*_foo2512=== RUN TestGlobMatch/foo*_foobar2513=== PAUSE TestGlobMatch/foo*_foobar2514=== RUN TestGlobMatch/foo*_bar2515=== PAUSE TestGlobMatch/foo*_bar2516=== RUN TestGlobMatch/*bar_bar2517=== PAUSE TestGlobMatch/*bar_bar2518=== RUN TestGlobMatch/*bar_foobar2519=== PAUSE TestGlobMatch/*bar_foobar2520=== RUN TestGlobMatch/*bar_foo2521=== PAUSE TestGlobMatch/*bar_foo2522=== RUN TestGlobMatch/foo*bar_foobar2523=== PAUSE TestGlobMatch/foo*bar_foobar2524=== RUN TestGlobMatch/foo*bar_foo123bar2525=== PAUSE TestGlobMatch/foo*bar_foo123bar2526=== RUN TestGlobMatch/foo*bar_foobarbaz2527=== PAUSE TestGlobMatch/foo*bar_foobarbaz2528=== RUN TestGlobMatch/*/*_foo/bar2529=== PAUSE TestGlobMatch/*/*_foo/bar2530=== RUN TestGlobMatch/*/*_foo2531=== PAUSE TestGlobMatch/*/*_foo2532=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2533=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2534=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02535=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02536=== RUN TestGlobMatch/refs/*/main_refs/heads/main2537=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2538=== RUN TestGlobMatch/fo?_foo2539=== PAUSE TestGlobMatch/fo?_foo2540=== RUN TestGlobMatch/fo?_fo2541=== PAUSE TestGlobMatch/fo?_fo2542=== RUN TestGlobMatch/fo?_fooo2543=== PAUSE TestGlobMatch/fo?_fooo2544=== RUN TestGlobMatch/?oo_foo2545=== PAUSE TestGlobMatch/?oo_foo2546=== RUN TestGlobMatch/?oo_boo2547=== PAUSE TestGlobMatch/?oo_boo2548=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2549=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2550=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2551=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2552=== CONT TestGlobMatch/foo_bar2553=== CONT TestGlobMatch/*/*_foo2554=== CONT TestGlobMatch/*bar_bar2555=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2556=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2557=== CONT TestGlobMatch/foo*bar_foobarbaz2558=== CONT TestGlobMatch/fo?_fo2559=== CONT TestGlobMatch/foo*bar_foo123bar2560=== CONT TestGlobMatch/fo?_foo2561=== CONT TestGlobMatch/*/*_foo/bar2562=== CONT TestGlobMatch/*bar_foo2563=== CONT TestGlobMatch/*bar_foobar2564=== CONT TestGlobMatch/foo*bar_foobar2565=== CONT TestGlobMatch/foo*_bar2566=== CONT TestGlobMatch/foo*_foobar2567=== CONT TestGlobMatch/fo?_fooo2568=== CONT TestGlobMatch/*_anything2569=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2570=== CONT TestGlobMatch/?oo_boo2571=== CONT TestGlobMatch/?oo_foo2572=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02573=== CONT TestGlobMatch/refs/*/main_refs/heads/main2574=== CONT TestGlobMatch/foo*_foo2575=== CONT TestGlobMatch/*_2576=== CONT TestGlobMatch/foo_foo2577--- PASS: TestGlobMatch (0.00s)2578 --- PASS: TestGlobMatch/foo_bar (0.00s)2579 --- PASS: TestGlobMatch/*/*_foo (0.00s)2580 --- PASS: TestGlobMatch/*bar_bar (0.00s)2581 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2582 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2583 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2584 --- PASS: TestGlobMatch/fo?_fo (0.00s)2585 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2586 --- PASS: TestGlobMatch/fo?_foo (0.00s)2587 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2588 --- PASS: TestGlobMatch/*bar_foo (0.00s)2589 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2590 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2591 --- PASS: TestGlobMatch/foo*_bar (0.00s)2592 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2593 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2594 --- PASS: TestGlobMatch/*_anything (0.00s)2595 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2596 --- PASS: TestGlobMatch/?oo_foo (0.00s)2597 --- PASS: TestGlobMatch/?oo_boo (0.00s)2598 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2599 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2600 --- PASS: TestGlobMatch/foo*_foo (0.00s)2601 --- PASS: TestGlobMatch/*_ (0.00s)2602 --- PASS: TestGlobMatch/foo_foo (0.00s)26032026/10/29 01:22:21 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12326042026/10/29 01:22:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33269/oidc2605--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.12s)2606--- PASS: TestValidateToken_ValidToken (0.12s)26072026/10/29 01:22:21 http: TLS handshake error from 127.0.0.1:54664: remote error: tls: bad certificate2608--- PASS: TestNewValidator_KubernetesRequiresCA (0.13s)26092026/10/29 01:22:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46419/oidc2610--- PASS: TestValidateToken_WrongAudience (0.15s)26112026/10/29 01:22:21 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:40233/oidc26122026/10/29 01:22:21 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:37297/oidc26132026/10/29 01:22:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33229/oidc2614--- PASS: TestValidateToken_MultipleProviders (0.16s)26152026/10/29 01:22:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35441/oidc2616--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.17s)2617--- PASS: TestScopes_Rules (0.18s)26182026/10/29 01:22:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34697/oidc2619--- PASS: TestPins_ReservedForMatchingRule (0.20s)26202026/10/29 01:22:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35803/oidc2621--- PASS: TestPins_TopLevelShorthand (0.20s)26222026/10/29 01:22:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41033/oidc26232026/10/29 01:22:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34513/oidc2624--- PASS: TestValidateToken_BoundSubjectMismatch (0.26s)2625--- PASS: TestValidateToken_BoundClaimsMismatch (0.26s)26262026/10/29 01:22:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42331/oidc2627--- PASS: TestValidateToken_Expired (0.28s)2628--- PASS: TestHTTPClientForHasTimeouts (0.41s)26292026/10/29 01:22:21 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:359212630--- PASS: TestValidateToken_KubernetesServiceAccount (0.49s)26312026/10/29 01:22:21 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:40659/oidc2632--- PASS: TestValidateToken_NoMatchingProvider (0.61s)2633PASS2634Running hook tests...2635=== RUN TestSendPathsEmpty2636=== PAUSE TestSendPathsEmpty2637=== RUN TestQueueEnqueueAndFetch2638=== PAUSE TestQueueEnqueueAndFetch2639=== RUN TestQueueDeduplication2640=== PAUSE TestQueueDeduplication2641=== RUN TestQueueRemove2642=== PAUSE TestQueueRemove2643=== RUN TestQueueFetchBatchLimit2644=== PAUSE TestQueueFetchBatchLimit2645=== RUN TestQueueRetryMovesToBack2646=== PAUSE TestQueueRetryMovesToBack2647=== RUN TestQueueFetchRemoveLifecycle2648=== PAUSE TestQueueFetchRemoveLifecycle2649=== RUN TestQueueConcurrentWriters2650=== PAUSE TestQueueConcurrentWriters2651=== RUN TestQueueRemoveLargeClosure2652=== PAUSE TestQueueRemoveLargeClosure2653=== RUN TestServerClientIntegration2654--- PASS: TestServerClientIntegration (0.00s)2655=== RUN TestServerQueueError26562026/10/29 01:22:22 ERROR Failed to queue paths error="permission denied" count=12657--- PASS: TestServerQueueError (0.00s)2658=== RUN TestServerRefusesOversizedAndNonStoreRequests2659=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2660=== RUN TestGetListenerSocketActivation2661 server_test.go:309: === RUN TestGetListenerSocketActivation2662 --- PASS: TestGetListenerSocketActivation (0.00s)2663 PASS2664 2665--- PASS: TestGetListenerSocketActivation (1.02s)2666=== RUN TestServerStalledClientDoesNotBlockShutdown2667=== PAUSE TestServerStalledClientDoesNotBlockShutdown2668=== RUN TestServerBacksOffOnAcceptErrors2669=== PAUSE TestServerBacksOffOnAcceptErrors2670=== RUN TestDrainIsolatesPoisonPath2671=== PAUSE TestDrainIsolatesPoisonPath2672=== RUN TestRunNotBlockedByPoisonHead2673=== PAUSE TestRunNotBlockedByPoisonHead2674=== RUN TestDrainGivesUpWhenServerDown2675=== PAUSE TestDrainGivesUpWhenServerDown2676=== RUN TestFailedPathPrunedByLaterClosure2677=== PAUSE TestFailedPathPrunedByLaterClosure2678=== RUN TestWorkerUploadsAndRemoves2679=== PAUSE TestWorkerUploadsAndRemoves2680=== RUN TestWorkerSkipsGCdPaths2681=== PAUSE TestWorkerSkipsGCdPaths2682=== RUN TestWorkerPrunesClosureDeps2683=== PAUSE TestWorkerPrunesClosureDeps2684=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2685=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2686=== RUN TestDrainTimeout2687=== PAUSE TestDrainTimeout2688=== RUN TestDrainTimeoutDuringIsolation2689=== PAUSE TestDrainTimeoutDuringIsolation2690=== RUN TestShutdownFinishesInFlightPush2691=== PAUSE TestShutdownFinishesInFlightPush2692=== RUN TestWorkerRemoveFailureIsNotProgress2693=== PAUSE TestWorkerRemoveFailureIsNotProgress2694=== RUN TestWorkerKeepsPathItCannotStat2695=== PAUSE TestWorkerKeepsPathItCannotStat2696=== CONT TestSendPathsEmpty2697=== CONT TestWorkerRemoveFailureIsNotProgress2698=== CONT TestQueueRemoveLargeClosure2699=== CONT TestQueueConcurrentWriters2700=== CONT TestWorkerPrunesClosureDeps2701=== CONT TestWorkerKeepsPathItCannotStat2702=== CONT TestRunNotBlockedByPoisonHead2703=== CONT TestDrainIsolatesPoisonPath2704=== CONT TestServerBacksOffOnAcceptErrors2705=== CONT TestQueueRemove27062026/10/29 01:22:23 ERROR Accept failed error="too many open files"2707=== CONT TestQueueFetchBatchLimit2708=== CONT TestServerStalledClientDoesNotBlockShutdown2709=== CONT TestQueueRetryMovesToBack2710=== CONT TestServerRefusesOversizedAndNonStoreRequests2711=== CONT TestQueueDeduplication2712=== CONT TestQueueEnqueueAndFetch2713=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2714=== CONT TestDrainTimeout2715=== CONT TestQueueFetchRemoveLifecycle27162026/10/29 01:22:23 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2717=== CONT TestDrainTimeoutDuringIsolation2718=== CONT TestShutdownFinishesInFlightPush2719--- PASS: TestSendPathsEmpty (0.00s)2720=== CONT TestWorkerUploadsAndRemoves2721=== CONT TestWorkerSkipsGCdPaths2722=== CONT TestFailedPathPrunedByLaterClosure2723=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2724=== CONT TestDrainGivesUpWhenServerDown2725=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path27262026/10/29 01:22:23 ERROR Refusing path outside the store path=/nix/store store=/nix/store2727=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2728=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2729=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2730=== RUN TestShutdownFinishesInFlightPush/completes2731=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2732=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2733=== PAUSE TestShutdownFinishesInFlightPush/completes2734=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2735=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2736=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2737=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout27382026/10/29 01:22:23 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store2739=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path2740=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths2741=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2742=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch27432026/10/29 01:22:23 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store27442026/10/29 01:22:23 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store27452026/10/29 01:22:23 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27462026/10/29 01:22:23 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27472026/10/29 01:22:23 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store27482026/10/29 01:22:23 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store27492026/10/29 01:22:23 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store27502026/10/29 01:22:23 ERROR Accept failed error="too many open files"27512026/10/29 01:22:23 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store27522026/10/29 01:22:23 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store27532026/10/29 01:22:23 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store27542026/10/29 01:22:23 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store27552026/10/29 01:22:23 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store27562026/10/29 01:22:23 ERROR Failed to decode request error="unexpected EOF"2757--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2758=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline27592026/10/29 01:22:23 ERROR Accept failed error="too many open files"27602026/10/29 01:22:23 ERROR Accept failed error="too many open files"27612026/10/29 01:22:23 INFO Upload queue status pending=227622026/10/29 01:22:23 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat679470556/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat679470556/002/locked/aaa: permission denied"27632026/10/29 01:22:23 INFO Uploading batch count=427642026/10/29 01:22:23 ERROR Upload failed error="upload failed" count=427652026/10/29 01:22:23 INFO Upload queue status pending=327662026/10/29 01:22:23 INFO Uploading batch count=127672026/10/29 01:22:23 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath363831157/002/bbb27682026/10/29 01:22:23 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2357176582/002/nonexistent27692026/10/29 01:22:23 INFO Upload queue status pending=227702026/10/29 01:22:23 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat679470556/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat679470556/002/locked/aaa: permission denied"27712026/10/29 01:22:23 INFO Uploading batch count=227722026/10/29 01:22:23 INFO Uploading batch count=227732026/10/29 01:22:23 INFO Uploading batch count=227742026/10/29 01:22:23 INFO Upload queue status pending=227752026/10/29 01:22:23 INFO Uploading batch count=22776--- PASS: TestQueueEnqueueAndFetch (0.07s)2777=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short27782026/10/29 01:22:23 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat679470556/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat679470556/002/locked/aaa: permission denied"2779=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout27802026/10/29 01:22:23 INFO Uploading batch count=227812026/10/29 01:22:23 ERROR Upload failed error="upload failed" count=227822026/10/29 01:22:23 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1998921401/002/a2783--- PASS: TestQueueRemove (0.07s)27842026/10/29 01:22:23 INFO Uploading batch count=127852026/10/29 01:22:23 ERROR Upload failed error="upload failed" count=127862026/10/29 01:22:23 INFO Uploading batch count=127872026/10/29 01:22:23 ERROR Upload failed error="upload failed" count=127882026/10/29 01:22:23 INFO Upload queue status pending=327892026/10/29 01:22:23 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1998921401/002/b27902026/10/29 01:22:23 INFO Uploading batch count=127912026/10/29 01:22:23 ERROR Upload failed error="upload failed" count=127922026/10/29 01:22:23 INFO Uploading batch count=427932026/10/29 01:22:23 ERROR Upload failed error="upload failed" count=427942026/10/29 01:22:23 ERROR Drain finished with paths left in queue remaining=12795--- PASS: TestQueueFetchBatchLimit (0.08s)2796=== CONT TestShutdownFinishesInFlightPush/completes27972026/10/29 01:22:23 INFO Uploading batch count=127982026/10/29 01:22:23 ERROR Upload failed error="upload failed" count=127992026/10/29 01:22:23 ERROR Accept failed error="too many open files"28002026/10/29 01:22:23 INFO Uploading batch count=12801--- PASS: TestQueueRetryMovesToBack (0.08s)28022026/10/29 01:22:23 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path3057028285/001/nonexistent28032026/10/29 01:22:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=12804--- PASS: TestWorkerPrunesClosureDeps (0.08s)28052026/10/29 01:22:23 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path3057028285/001/nonexistent28062026/10/29 01:22:23 INFO Uploading batch count=228072026/10/29 01:22:23 ERROR Upload failed error="upload failed" count=228082026/10/29 01:22:23 INFO Uploading batch count=12809--- PASS: TestQueueFetchRemoveLifecycle (0.08s)28102026/10/29 01:22:23 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1998921401/002/c28112026/10/29 01:22:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128122026/10/29 01:22:23 INFO Uploading batch count=128132026/10/29 01:22:23 ERROR Upload failed error="upload failed" count=12814--- PASS: TestQueueDeduplication (0.08s)28152026/10/29 01:22:23 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path3057028285/001/nonexistent2816--- PASS: TestWorkerSkipsGCdPaths (0.08s)28172026/10/29 01:22:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128182026/10/29 01:22:23 ERROR Drain finished with paths left in queue remaining=128192026/10/29 01:22:23 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1998921401/002/d28202026/10/29 01:22:23 INFO Uploading batch count=228212026/10/29 01:22:23 ERROR Upload failed error="upload failed" count=228222026/10/29 01:22:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128232026/10/29 01:22:23 INFO Uploading batch count=228242026/10/29 01:22:23 ERROR Drain finished with paths left in queue remaining=128252026/10/29 01:22:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128262026/10/29 01:22:23 INFO Uploading batch count=228272026/10/29 01:22:23 ERROR Upload failed error="upload failed" count=228282026/10/29 01:22:23 INFO Uploading batch count=228292026/10/29 01:22:23 ERROR Upload failed error="upload failed" count=228302026/10/29 01:22:23 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1998921401/002/e2831--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.09s)28322026/10/29 01:22:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228332026/10/29 01:22:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=12834--- PASS: TestFailedPathPrunedByLaterClosure (0.09s)28352026/10/29 01:22:23 INFO Uploading batch count=22836--- PASS: TestWorkerKeepsPathItCannotStat (0.09s)28372026/10/29 01:22:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228382026/10/29 01:22:23 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1998921401/002/f2839--- PASS: TestWorkerUploadsAndRemoves (0.09s)28402026/10/29 01:22:23 INFO Uploading batch count=228412026/10/29 01:22:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128422026/10/29 01:22:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228432026/10/29 01:22:23 ERROR Drain finished with paths left in queue remaining=228442026/10/29 01:22:23 INFO Uploading batch count=42845--- PASS: TestDrainIsolatesPoisonPath (0.10s)28462026/10/29 01:22:23 ERROR Upload failed error="upload failed" count=428472026/10/29 01:22:23 INFO Uploading batch count=228482026/10/29 01:22:23 ERROR Upload failed error="upload failed" count=228492026/10/29 01:22:23 ERROR Drain finished with paths left in queue remaining=1028502026/10/29 01:22:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128512026/10/29 01:22:23 INFO Upload queue status pending=228522026/10/29 01:22:23 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128532026/10/29 01:22:23 ERROR Drain finished with paths left in queue remaining=228542026/10/29 01:22:23 INFO Uploading batch count=22855--- PASS: TestDrainGivesUpWhenServerDown (0.10s)2856--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2857 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.09s)2858 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.09s)2859 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.10s)28602026/10/29 01:22:23 INFO Upload queue status pending=228612026/10/29 01:22:23 INFO Uploading batch count=228622026/10/29 01:22:24 ERROR Accept failed error="too many open files"28632026/10/29 01:22:24 ERROR Failed to decode request error="read unix /build/hook636149460/test.sock->@: i/o timeout"28642026/10/29 01:22:24 ERROR Failed to write response error="write unix /build/hook636149460/test.sock->@: i/o timeout"2865--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)28662026/10/29 01:22:24 ERROR Upload failed error="context canceled" count=228672026/10/29 01:22:24 ERROR Drain finished with paths left in queue remaining=42868--- PASS: TestDrainTimeout (0.27s)28692026/10/29 01:22:24 ERROR Drain finished with paths left in queue remaining=428702026/10/29 01:22:24 ERROR Upload failed error="context canceled" count=228712026/10/29 01:22:24 ERROR Drain finished with paths left in queue remaining=22872--- PASS: TestShutdownFinishesInFlightPush (0.00s)2873 --- PASS: TestShutdownFinishesInFlightPush/completes (0.13s)2874 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.23s)28752026/10/29 01:22:24 ERROR Accept failed error="too many open files"28762026/10/29 01:22:24 ERROR Drain finished with paths left in queue remaining=32877--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2878 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.23s)2879 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.37s)2880--- PASS: TestQueueConcurrentWriters (0.48s)28812026/10/29 01:22:24 ERROR Accept failed error="too many open files"2882--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)28832026/10/29 01:22:24 INFO Uploading batch count=128842026/10/29 01:22:24 INFO Uploading batch count=128852026/10/29 01:22:24 INFO Uploading batch count=128862026/10/29 01:22:24 ERROR Upload failed error="upload failed" count=128872026/10/29 01:22:24 INFO Uploading batch count=128882026/10/29 01:22:24 ERROR Upload failed error="upload failed" count=128892026/10/29 01:22:24 INFO Uploading batch count=128902026/10/29 01:22:24 ERROR Upload failed error="upload failed" count=128912026/10/29 01:22:24 INFO Uploading batch count=128922026/10/29 01:22:24 ERROR Upload failed error="upload failed" count=128932026/10/29 01:22:24 ERROR Drain finished with paths left in queue remaining=12894--- PASS: TestRunNotBlockedByPoisonHead (1.10s)2895--- PASS: TestQueueRemoveLargeClosure (2.41s)2896PASS2897Running signing tests...2898=== RUN TestExternalSigner2899=== PAUSE TestExternalSigner2900=== RUN TestExternalSignerWrongPublicKey2901=== PAUSE TestExternalSignerWrongPublicKey2902=== RUN TestExternalSignerErrors2903=== PAUSE TestExternalSignerErrors2904=== RUN TestExternalSignerRestartsAfterCrash2905=== PAUSE TestExternalSignerRestartsAfterCrash2906=== RUN TestExternalSignerProgramErrorKeepsProcess2907=== PAUSE TestExternalSignerProgramErrorKeepsProcess2908=== RUN TestExternalSignerClose2909=== PAUSE TestExternalSignerClose2910=== RUN TestExternalSignerRejectsInvalidPublicKey2911=== PAUSE TestExternalSignerRejectsInvalidPublicKey2912=== RUN TestExternalSignerCancellation2913=== PAUSE TestExternalSignerCancellation2914=== RUN TestGenerateFingerprint2915=== PAUSE TestGenerateFingerprint2916=== RUN TestParseSigningKey2917=== PAUSE TestParseSigningKey2918=== RUN TestSign2919=== PAUSE TestSign2920=== RUN TestSignBatch2921=== PAUSE TestSignBatch2922=== RUN TestNilKeyPublicKey2923=== PAUSE TestNilKeyPublicKey2924=== RUN TestSignErrors2925=== PAUSE TestSignErrors2926=== CONT TestExternalSigner2927=== CONT TestNilKeyPublicKey2928=== CONT TestParseSigningKey2929--- PASS: TestNilKeyPublicKey (0.00s)2930=== CONT TestSignErrors2931=== RUN TestParseSigningKey/valid_32-byte_key2932=== CONT TestSignBatch2933=== CONT TestGenerateFingerprint2934=== CONT TestExternalSignerProgramErrorKeepsProcess2935=== RUN TestGenerateFingerprint/basic_with_references2936=== PAUSE TestGenerateFingerprint/basic_with_references2937=== CONT TestExternalSignerClose2938=== CONT TestExternalSignerRejectsInvalidPublicKey2939=== CONT TestExternalSignerCancellation2940=== CONT TestSign2941=== CONT TestExternalSignerWrongPublicKey2942=== CONT TestExternalSignerRestartsAfterCrash2943=== CONT TestExternalSignerErrors2944=== PAUSE TestParseSigningKey/valid_32-byte_key2945=== RUN TestGenerateFingerprint/no_references2946=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2947=== PAUSE TestGenerateFingerprint/no_references2948=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2949=== RUN TestExternalSignerRejectsInvalidPublicKey/#002950=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2951=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2952=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002953=== RUN TestParseSigningKey/no_colon2954=== RUN TestExternalSignerErrors/exit_on_request2955=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2956=== PAUSE TestParseSigningKey/no_colon2957=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2958=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2959=== RUN TestGenerateFingerprint/invalid_nar_hash_length2960=== PAUSE TestExternalSignerErrors/exit_on_request2961=== RUN TestExternalSignerErrors/too_few_signatures2962=== PAUSE TestExternalSignerErrors/too_few_signatures2963=== RUN TestParseSigningKey/empty_name2964=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2965=== RUN TestGenerateFingerprint/invalid_store_path_prefix2966=== RUN TestExternalSignerErrors/wrong_signature_name2967=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2968=== PAUSE TestParseSigningKey/empty_name2969=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2970=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2971=== RUN TestGenerateFingerprint/invalid_reference_prefix2972=== RUN TestParseSigningKey/invalid_base642973=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2974=== PAUSE TestExternalSignerErrors/wrong_signature_name2975=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2976=== RUN TestExternalSignerErrors/program_error2977=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2978=== CONT TestGenerateFingerprint/no_references2979=== CONT TestGenerateFingerprint/invalid_nar_hash_length2980=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2981=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2982=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2983=== PAUSE TestExternalSignerErrors/program_error2984=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2985=== RUN TestExternalSignerErrors/invalid_JSON2986=== CONT TestGenerateFingerprint/invalid_store_path_prefix2987=== PAUSE TestParseSigningKey/invalid_base642988=== RUN TestParseSigningKey/wrong_length2989=== CONT TestGenerateFingerprint/basic_with_references2990=== PAUSE TestParseSigningKey/wrong_length2991=== CONT TestGenerateFingerprint/invalid_reference_prefix2992=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2993=== CONT TestExternalSignerRejectsInvalidPublicKey/#002994=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2995--- PASS: TestGenerateFingerprint (0.00s)2996 --- PASS: TestGenerateFingerprint/no_references (0.00s)2997 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2998 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2999 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)3000 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)3001 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)3002 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)3003=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=3004=== CONT TestParseSigningKey/valid_32-byte_key3005=== CONT TestParseSigningKey/wrong_length3006=== CONT TestParseSigningKey/invalid_base643007--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)3008=== CONT TestParseSigningKey/no_colon3009=== CONT TestParseSigningKey/empty_name3010=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name3011=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!3012=== PAUSE TestExternalSignerErrors/invalid_JSON3013=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==3014=== RUN TestExternalSignerErrors/wrong_id3015=== PAUSE TestExternalSignerErrors/wrong_id3016=== RUN TestExternalSignerErrors/unrequested_key3017--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)3018 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)3019 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)3020 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)3021 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)3022 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)3023=== PAUSE TestExternalSignerErrors/unrequested_key3024=== RUN TestExternalSignerErrors/wrong_signature_length3025=== PAUSE TestExternalSignerErrors/wrong_signature_length3026=== RUN TestExternalSignerErrors/missing_signatures3027=== PAUSE TestExternalSignerErrors/missing_signatures3028=== RUN TestExternalSignerErrors/null_signatures3029=== PAUSE TestExternalSignerErrors/null_signatures3030=== RUN TestExternalSignerErrors/wrong_signatures_shape3031=== PAUSE TestExternalSignerErrors/wrong_signatures_shape3032=== RUN TestExternalSignerErrors/exit_at_startup3033=== PAUSE TestExternalSignerErrors/exit_at_startup3034=== RUN TestExternalSignerErrors/wrong_shape3035=== PAUSE TestExternalSignerErrors/wrong_shape3036=== RUN TestExternalSignerErrors/null3037=== PAUSE TestExternalSignerErrors/null3038=== RUN TestExternalSignerErrors/missing_signature_name3039=== PAUSE TestExternalSignerErrors/missing_signature_name3040=== RUN TestExternalSignerErrors/invalid_signature_base643041=== PAUSE TestExternalSignerErrors/invalid_signature_base643042=== CONT TestExternalSignerErrors/wrong_signature_name3043=== CONT TestExternalSignerErrors/wrong_signature_length3044=== CONT TestExternalSignerErrors/null_signatures3045=== CONT TestExternalSignerErrors/wrong_signatures_shape3046=== CONT TestExternalSignerErrors/exit_at_startup3047=== CONT TestExternalSignerErrors/wrong_shape3048=== CONT TestExternalSignerErrors/missing_signatures3049=== CONT TestExternalSignerErrors/invalid_signature_base643050=== CONT TestExternalSignerErrors/missing_signature_name3051=== CONT TestExternalSignerErrors/null3052=== CONT TestExternalSignerErrors/wrong_id3053=== CONT TestExternalSignerErrors/program_error3054=== CONT TestExternalSignerErrors/exit_on_request3055=== CONT TestExternalSignerErrors/invalid_JSON3056--- PASS: TestExternalSignerClose (0.01s)3057--- PASS: TestExternalSignerWrongPublicKey (0.01s)3058=== CONT TestExternalSignerErrors/too_few_signatures3059=== CONT TestExternalSignerErrors/unrequested_key3060--- PASS: TestExternalSignerErrors (0.00s)3061 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)3062 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.00s)3063 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)3064 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)3065 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)3066 --- PASS: TestExternalSignerErrors/null (0.01s)3067 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)3068 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)3069 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)3070 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)3071 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)3072 --- PASS: TestExternalSignerErrors/program_error (0.01s)3073 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)3074 --- PASS: TestExternalSignerErrors/unrequested_key (0.00s)3075 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)3076 --- PASS: TestExternalSignerErrors/too_few_signatures (0.00s)3077--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)3078=== RUN TestSignErrors/nil_key3079=== PAUSE TestSignErrors/nil_key3080=== RUN TestSignErrors/nil_narinfo3081=== PAUSE TestSignErrors/nil_narinfo3082=== RUN TestSignErrors/invalid_narinfo3083=== PAUSE TestSignErrors/invalid_narinfo3084=== RUN TestSignErrors/canceled3085=== PAUSE TestSignErrors/canceled3086--- PASS: TestParseSigningKey (0.00s)3087 --- PASS: TestParseSigningKey/wrong_length (0.00s)3088 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)3089 --- PASS: TestParseSigningKey/no_colon (0.00s)3090 --- PASS: TestParseSigningKey/empty_name (0.00s)3091 --- PASS: TestParseSigningKey/valid_32-byte_key (0.01s)3092 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.01s)3093=== CONT TestSignErrors/invalid_narinfo3094=== CONT TestSignErrors/nil_key3095=== CONT TestSignErrors/nil_narinfo3096=== CONT TestSignErrors/canceled3097--- PASS: TestSignErrors (0.02s)3098 --- PASS: TestSignErrors/invalid_narinfo (0.00s)3099 --- PASS: TestSignErrors/nil_key (0.00s)3100 --- PASS: TestSignErrors/nil_narinfo (0.00s)3101 --- PASS: TestSignErrors/canceled (0.00s)3102--- PASS: TestSign (0.02s)3103--- PASS: TestExternalSigner (0.03s)3104--- PASS: TestExternalSignerCancellation (0.02s)3105--- PASS: TestSignBatch (0.03s)3106PASS3107Running OpenBao signer tests...3108=== RUN TestSign3109=== PAUSE TestSign3110=== RUN TestSignErrors3111=== PAUSE TestSignErrors3112=== RUN TestServe3113=== PAUSE TestServe3114=== RUN TestServeRejectsGarbage3115=== PAUSE TestServeRejectsGarbage3116=== CONT TestServe3117=== CONT TestSignErrors3118=== CONT TestServeRejectsGarbage3119=== CONT TestSign3120=== RUN TestSignErrors/invalid_base643121--- PASS: TestServeRejectsGarbage (0.00s)3122=== PAUSE TestSignErrors/invalid_base643123=== RUN TestSignErrors/http_error3124=== PAUSE TestSignErrors/http_error3125--- PASS: TestServe (0.00s)3126=== RUN TestSignErrors/invalid_json3127=== PAUSE TestSignErrors/invalid_json3128=== RUN TestSignErrors/no_prefix3129=== PAUSE TestSignErrors/no_prefix3130=== CONT TestSignErrors/http_error3131=== CONT TestSignErrors/invalid_json3132=== CONT TestSignErrors/no_prefix3133=== CONT TestSignErrors/invalid_base643134--- PASS: TestSign (0.01s)3135--- PASS: TestSignErrors (0.00s)3136 --- PASS: TestSignErrors/http_error (0.01s)3137 --- PASS: TestSignErrors/invalid_json (0.01s)3138 --- PASS: TestSignErrors/no_prefix (0.01s)3139 --- PASS: TestSignErrors/invalid_base64 (0.01s)3140PASS3141Running niks3-hook command tests...3142=== RUN TestServeSecondSignalEndsDrain3143=== PAUSE TestServeSecondSignalEndsDrain3144=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown3145=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown3146=== CONT TestServeSecondSignalEndsDrain3147=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown3148--- PASS: TestServeSecondSignalEndsDrain (0.07s)31492026/10/29 01:22:29 INFO Upload queue status pending=131502026/10/29 01:22:29 INFO Uploading batch count=13151--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.13s)3152PASS3153Running rate limiter tests...3154=== RUN TestAdaptiveRateLimiter_ThreadSafety3155=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3156=== CONT TestAdaptiveRateLimiter_ThreadSafety31572026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=93.1700000000000331582026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=65.2190000000000231592026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=45.65330000000001631602026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=31.9573100000000131612026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=22.37011700000000831622026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=15.65908190000000431632026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=10.96135733000000231642026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=7.67295013100000131652026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=5.371065091731662026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531672026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531682026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531692026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531702026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531712026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531722026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531732026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531742026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531752026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531762026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531772026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531782026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531792026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531802026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531812026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531822026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531832026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531842026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531852026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531862026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531872026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531882026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531892026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531902026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531912026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531922026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531932026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531942026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531952026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531962026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531972026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531982026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=531992026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532002026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532012026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=5.12435000000000132022026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532032026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532042026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532052026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532062026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532072026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532082026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532092026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532102026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532112026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532122026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532132026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532142026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532152026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532162026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=6.82050985000000232172026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532182026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532192026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532202026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532212026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532222026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532232026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532242026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532252026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532262026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532272026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532282026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532292026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532302026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532312026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532322026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532332026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532342026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532352026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532362026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532372026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532382026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532392026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=8.25281691850000432402026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=5.77697184295000332412026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532422026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532432026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532442026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532452026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532462026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532472026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532482026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532492026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532502026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532512026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532522026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532532026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=5.63678500000000132542026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532552026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=532562026/10/29 01:22:30 WARN Rate limiter backed off name=test rate=53257--- PASS: TestAdaptiveRateLimiter_ThreadSafety (3.55s)3258PASS