niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #436
· raw
1tribuchet: building on mac022Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure18=== PAUSE TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure19=== RUN TestUploadMultipart_PartsInParallel20=== PAUSE TestUploadMultipart_PartsInParallel21=== RUN TestUploadMultipart_FailedPartBufferNotReused22=== PAUSE TestUploadMultipart_FailedPartBufferNotReused23=== RUN TestUploadMultipart_ProducerErrorIsNotEOF24=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestUploadMultipart_SupersededByPeer28=== PAUSE TestUploadMultipart_SupersededByPeer29=== RUN TestDumpPathCaseHackMatchesNix30--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)31=== RUN TestDumpPathCaseHackCollision32--- PASS: TestDumpPathCaseHackCollision (0.00s)33=== RUN TestSupersededNARStillUploadsListing34=== PAUSE TestSupersededNARStillUploadsListing35=== RUN TestTruncatedNARDumpIsNotCompleted36=== PAUSE TestTruncatedNARDumpIsNotCompleted37=== RUN TestDumpPathMatchesNix38=== PAUSE TestDumpPathMatchesNix39=== RUN TestDumpPathSingleFile40=== PAUSE TestDumpPathSingleFile41=== RUN TestDumpPathWriterError42=== PAUSE TestDumpPathWriterError43=== RUN TestDumpPathWriterErrorStopsReading44 nar_test.go:280: no /proc/self/io: open /proc/self/io: no such file or directory45--- SKIP: TestDumpPathWriterErrorStopsReading (0.42s)46=== RUN TestEncodeNixBase3247=== PAUSE TestEncodeNixBase3248=== RUN TestEncodeNixBase32WithRealHash49=== PAUSE TestEncodeNixBase32WithRealHash50=== RUN TestConvertHashToNix3251=== PAUSE TestConvertHashToNix3252=== RUN TestGetStorePathHash53=== PAUSE TestGetStorePathHash54=== RUN TestPathInfoHashCompatibility55=== PAUSE TestPathInfoHashCompatibility56=== RUN TestParsePathInfoJSON57=== PAUSE TestParsePathInfoJSON58=== RUN TestParsePathInfoJSONMultiplePaths59=== PAUSE TestParsePathInfoJSONMultiplePaths60=== RUN TestPathInfoCACompatibility61=== PAUSE TestPathInfoCACompatibility62=== RUN TestUploadPendingObjectsStopsStartingAfterFailure63--- PASS: TestUploadPendingObjectsStopsStartingAfterFailure (0.01s)64=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent65=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent66=== RUN TestCompletePendingClosure_NotFoundWithoutKey67=== PAUSE TestCompletePendingClosure_NotFoundWithoutKey68=== RUN TestRateLimiterFeedback69=== PAUSE TestRateLimiterFeedback70=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess71=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess72=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer73=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer74=== RUN TestResolveStorePath75=== PAUSE TestResolveStorePath76=== RUN TestDoWithRetry_BodyReplayedViaGetBody77=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody78=== RUN TestRetryTimeoutOutlastsMaxRetries79=== PAUSE TestRetryTimeoutOutlastsMaxRetries80=== RUN TestDoWithRetry_FinalResponseBodyReadable81=== PAUSE TestDoWithRetry_FinalResponseBodyReadable82=== RUN TestShellSplit83=== PAUSE TestShellSplit84=== RUN TestShellSplitErrors85=== PAUSE TestShellSplitErrors86=== RUN TestStreamPushReportsEveryPath87=== PAUSE TestStreamPushReportsEveryPath88=== RUN TestStreamPushBatchesUnderLoad89=== PAUSE TestStreamPushBatchesUnderLoad90=== RUN TestStreamPushIsolatesFailures91=== PAUSE TestStreamPushIsolatesFailures92=== RUN TestStreamPushGivesUpOnDeadServer93=== PAUSE TestStreamPushGivesUpOnDeadServer94=== RUN TestStreamPushRequestLine95=== PAUSE TestStreamPushRequestLine96=== RUN TestStreamPushReportsSignatures97=== PAUSE TestStreamPushReportsSignatures98=== RUN TestStreamPushReportsSkippedPaths99=== PAUSE TestStreamPushReportsSkippedPaths100=== RUN TestClientSignaturesByStorePath101=== PAUSE TestClientSignaturesByStorePath102=== RUN TestStreamPushStopsWhenCanceled103=== PAUSE TestStreamPushStopsWhenCanceled104=== RUN TestStreamPushStopsOnCancel105=== PAUSE TestStreamPushStopsOnCancel106=== RUN TestSetClientTLS107=== PAUSE TestSetClientTLS108=== RUN TestSetClientTLSDoesNotMutateDefaultTransport109=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport110=== RUN TestSetClientTLSErrors111=== PAUSE TestSetClientTLSErrors112=== RUN TestStaticToken113=== PAUSE TestStaticToken114=== RUN TestFileTokenReadsAndCaches115=== PAUSE TestFileTokenReadsAndCaches116=== RUN TestFileTokenMissing117=== PAUSE TestFileTokenMissing118=== RUN TestFileTokenEmpty119=== PAUSE TestFileTokenEmpty120=== RUN TestScriptTokenNoExpiryRerunsEveryCall121=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall122=== RUN TestScriptTokenCachesUntilRefresh123=== PAUSE TestScriptTokenCachesUntilRefresh124=== RUN TestScriptTokenEmptyToken125=== PAUSE TestScriptTokenEmptyToken126=== RUN TestScriptTokenBadJSON127=== PAUSE TestScriptTokenBadJSON128=== RUN TestScriptTokenScriptFails129=== PAUSE TestScriptTokenScriptFails130=== RUN TestScriptTokenEmptyCommand131=== PAUSE TestScriptTokenEmptyCommand132=== RUN TestScriptTokenDoesNotWaitForItsChildren133=== PAUSE TestScriptTokenDoesNotWaitForItsChildren134=== CONT TestShellSplit135=== CONT TestPathInfoHashCompatibility136=== CONT TestStaticToken137=== CONT TestDoServerRequestAttachesToken138=== CONT TestUploadMultipart_FailedPartBufferNotReused139=== CONT TestDumpPathWriterError140=== CONT TestStreamPushReportsSignatures141=== CONT TestShellSplitErrors142=== CONT TestDoWithRetry_FinalResponseBodyReadable143=== CONT TestDoWithRetry_BodyReplayedViaGetBody144=== CONT TestResolveStorePath145=== CONT TestRetryTimeoutOutlastsMaxRetries146=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess147=== CONT TestRateLimiterFeedback148=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer149=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent150=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier151=== CONT TestCompletePendingClosure_NotFoundWithoutKey152=== CONT TestParsePathInfoJSONMultiplePaths153=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths154=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths155=== CONT TestPathInfoCACompatibility156=== CONT TestDumpPathMatchesNix157=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths158=== CONT TestParsePathInfoJSON159=== RUN TestParsePathInfoJSON/Nix_format160=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths161=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun162=== PAUSE TestParsePathInfoJSON/Nix_format163=== RUN TestParsePathInfoJSON/Lix_format164=== CONT TestSetClientTLS165=== CONT TestSetClientTLSDoesNotMutateDefaultTransport166=== PAUSE TestParsePathInfoJSON/Lix_format167=== RUN TestParsePathInfoJSON/empty_input168=== PAUSE TestParsePathInfoJSON/empty_input169=== RUN TestParsePathInfoJSON/whitespace_only170=== CONT TestDumpPathSingleFile171=== PAUSE TestParsePathInfoJSON/whitespace_only172=== CONT TestStreamPushStopsWhenCanceled173=== RUN TestPathInfoCACompatibility/null_ca_field174=== CONT TestFilterOversizedClosures175=== RUN TestFilterOversizedClosures/no_limit_keeps_everything176=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything177=== CONT TestClientSignaturesByStorePath178=== CONT TestStreamPushReportsSkippedPaths179--- PASS: TestShellSplit (0.00s)180=== CONT TestUploadMultipart_SupersededByPeer181=== RUN TestRateLimiterFeedback/429_enables_limiter182=== CONT TestGetStorePathHash183=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier184=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)185=== CONT TestStreamPushStopsOnCancel186=== RUN TestParsePathInfoJSON/invalid_JSON187=== RUN TestGetStorePathHash/valid_store_path188=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped189=== PAUSE TestRateLimiterFeedback/429_enables_limiter190=== RUN TestRateLimiterFeedback/503_enables_limiter191=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up192=== PAUSE TestParsePathInfoJSON/invalid_JSON193=== PAUSE TestGetStorePathHash/valid_store_path194=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry195=== PAUSE TestRateLimiterFeedback/503_enables_limiter196=== CONT TestCaseHackSuffix197=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter198=== PAUSE TestPathInfoCACompatibility/null_ca_field199=== RUN TestPathInfoCACompatibility/old_string_format_-_text200=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text201=== RUN TestUploadMultipart_SupersededByPeer/exists202=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive203=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive204=== RUN TestPathInfoCACompatibility/new_structured_format_-_text205--- PASS: TestStreamPushReportsSkippedPaths (0.00s)206--- PASS: TestStaticToken (0.00s)207=== PAUSE TestUploadMultipart_SupersededByPeer/exists208=== RUN TestUploadMultipart_SupersededByPeer/missing209=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text210=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method211--- PASS: TestShellSplitErrors (0.00s)212--- PASS: TestDoServerRequestAttachesToken (0.00s)213=== CONT TestUploadMultipart_PartsInParallel214=== CONT TestScriptTokenDoesNotWaitForItsChildren215=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs216=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs217=== CONT TestStreamPushRequestLine218=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout219=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped220=== RUN TestFilterOversizedClosures/all_closures_skipped221=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout222=== CONT TestSetClientTLSErrors223=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)224=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up225=== CONT TestTruncatedNARDumpIsNotCompleted226=== RUN TestGetStorePathHash/basename_without_hyphen_should_error227=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter228=== PAUSE TestUploadMultipart_SupersededByPeer/missing229=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method230--- PASS: TestStreamPushReportsSignatures (0.00s)231--- PASS: TestResolveStorePath (0.00s)232=== CONT TestFileTokenReadsAndCaches233=== RUN TestStreamPushStopsOnCancel/waiting_for_input234=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier235=== CONT TestPartSizeForNAR236=== RUN TestPartSizeForNAR/zero_stays_at_minimum237=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum238=== RUN TestPartSizeForNAR/small_stays_at_minimum239=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input240=== CONT TestScriptTokenEmptyToken241=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier242=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client243=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client244=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client245=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon246--- PASS: TestStreamPushStopsWhenCanceled (0.00s)247--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)248--- PASS: TestClientSignaturesByStorePath (0.00s)249=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon250=== PAUSE TestFilterOversizedClosures/all_closures_skipped251=== PAUSE TestPartSizeForNAR/small_stays_at_minimum252=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum253--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)254=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI255--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.00s)256=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI257=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter258=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot259=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter260=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512261=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512262=== CONT TestFileTokenEmpty263=== CONT TestConvertHashToNix32264--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)265=== RUN TestConvertHashToNix32/SRI_format_to_Nix32266=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error267=== CONT TestRegisterUploadedObjectReusesConnections268=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum269=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client270=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot271--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)272=== CONT TestEncodeNixBase32273=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error274=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32275=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts276=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot277=== RUN TestEncodeNixBase32/test_string_hash278=== CONT TestEncodeNixBase32WithRealHash279=== RUN TestConvertHashToNix32/already_Nix32_format280=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot281=== PAUSE TestEncodeNixBase32/test_string_hash282--- PASS: TestEncodeNixBase32WithRealHash (0.00s)283=== RUN TestEncodeNixBase32/empty_input284=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error285=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts286=== PAUSE TestConvertHashToNix32/already_Nix32_format287=== PAUSE TestEncodeNixBase32/empty_input288=== RUN TestConvertHashToNix32/invalid_format289=== RUN TestPartSizeForNAR/1_TiB290=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error291=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot292=== PAUSE TestPartSizeForNAR/1_TiB293=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error294=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot295=== RUN TestPartSizeForNAR/5_TiB_S3_max_object296=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica297=== CONT TestScriptTokenNoExpiryRerunsEveryCall298=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure299=== PAUSE TestConvertHashToNix32/invalid_format300=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot301=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object302=== CONT TestScriptTokenEmptyCommand303=== RUN TestPartSizeForNAR/capped_at_5_GiB304--- PASS: TestScriptTokenEmptyCommand (0.00s)305=== CONT TestScriptTokenScriptFails306=== PAUSE TestPartSizeForNAR/capped_at_5_GiB307=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot308=== CONT TestStreamPushBatchesUnderLoad309=== RUN TestStreamPushBatchesUnderLoad/together310=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken311=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken312=== CONT TestScriptTokenBadJSON313=== PAUSE TestStreamPushBatchesUnderLoad/together314=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time315=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time316=== CONT TestStreamPushGivesUpOnDeadServer317--- PASS: TestFileTokenReadsAndCaches (0.01s)318=== CONT TestStreamPushReportsEveryPath319--- PASS: TestFileTokenEmpty (0.00s)320--- PASS: TestStreamPushReportsEveryPath (0.00s)321=== CONT TestUploadMultipart_ProducerErrorIsNotEOF322=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part323=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part324=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary325=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary326=== CONT TestScriptTokenCachesUntilRefresh327--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)328=== CONT TestStreamPushIsolatesFailures329--- PASS: TestStreamPushIsolatesFailures (0.00s)330=== CONT TestSupersededNARStillUploadsListing331=== CONT TestFileTokenMissing332=== RUN TestSupersededNARStillUploadsListing/small_NAR333=== PAUSE TestSupersededNARStillUploadsListing/small_NAR334=== RUN TestSupersededNARStillUploadsListing/dump_cut_short335=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short336=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails337=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails338=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths339=== RUN TestSetClientTLSErrors/missing_cert_file340=== PAUSE TestSetClientTLSErrors/missing_cert_file341=== RUN TestSetClientTLSErrors/missing_key_file342=== PAUSE TestSetClientTLSErrors/missing_key_file343=== RUN TestSetClientTLSErrors/missing_ca_file344=== PAUSE TestSetClientTLSErrors/missing_ca_file345=== RUN TestSetClientTLSErrors/invalid_ca_file346=== PAUSE TestSetClientTLSErrors/invalid_ca_file347=== CONT TestParsePathInfoJSON/Lix_format348=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths349--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)350 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)351 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)352=== CONT TestParsePathInfoJSON/whitespace_only353=== CONT TestParsePathInfoJSON/invalid_JSON354=== CONT TestParsePathInfoJSON/empty_input355=== CONT TestParsePathInfoJSON/Nix_format356=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout357--- PASS: TestParsePathInfoJSON (0.00s)358 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)359 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)360 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)361 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)362 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)363=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs364--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.02s)365--- PASS: TestFileTokenMissing (0.02s)366=== CONT TestUploadMultipart_SupersededByPeer/exists367=== CONT TestUploadMultipart_SupersededByPeer/missing368--- PASS: TestScriptTokenBadJSON (0.03s)369=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive370=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method371=== CONT TestPathInfoCACompatibility/new_structured_format_-_text372=== CONT TestPathInfoCACompatibility/old_string_format_-_text373=== CONT TestPathInfoCACompatibility/null_ca_field374=== CONT TestFilterOversizedClosures/no_limit_keeps_everything375=== CONT TestFilterOversizedClosures/all_closures_skipped376--- PASS: TestPathInfoCACompatibility (0.00s)377 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)378 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)379 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)380 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)381 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)382=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped383--- PASS: TestFilterOversizedClosures (0.00s)384 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)385 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)386 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)387=== CONT TestRateLimiterFeedback/429_enables_limiter388--- PASS: TestCaseHackSuffix (0.07s)389=== CONT TestRateLimiterFeedback/503_enables_limiter390--- PASS: TestScriptTokenScriptFails (0.07s)391=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter392=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter393--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.08s)394=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon395=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI396=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512397=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)398--- PASS: TestPathInfoHashCompatibility (0.01s)399 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)400 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)401 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)402 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)403=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier404=== RUN TestSetClientTLS/rejects_connection_without_client_cert405=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert406=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA407=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA408=== RUN TestSetClientTLS/preserves_debug_logging_transport409=== PAUSE TestSetClientTLS/preserves_debug_logging_transport410=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client411=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client412=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up413--- PASS: TestScriptTokenEmptyToken (0.09s)414=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier415=== CONT TestEncodeNixBase32/empty_input416=== CONT TestEncodeNixBase32/test_string_hash417=== CONT TestGetStorePathHash/valid_store_path418=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error419--- PASS: TestEncodeNixBase32 (0.00s)420 --- PASS: TestEncodeNixBase32/empty_input (0.00s)421 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)422=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error423=== CONT TestGetStorePathHash/basename_without_hyphen_should_error424=== CONT TestConvertHashToNix32/SRI_format_to_Nix32425=== CONT TestConvertHashToNix32/invalid_format426=== CONT TestConvertHashToNix32/already_Nix32_format427=== CONT TestPartSizeForNAR/zero_stays_at_minimum428--- PASS: TestConvertHashToNix32 (0.00s)429 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)430 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)431 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)432=== CONT TestPartSizeForNAR/1_TiB433=== CONT TestPartSizeForNAR/capped_at_5_GiB434=== CONT TestPartSizeForNAR/5_TiB_S3_max_object435=== CONT TestPartSizeForNAR/small_stays_at_minimum436=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts437=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot438--- PASS: TestGetStorePathHash (0.01s)439 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)440 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)441 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)442 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)443=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum444--- PASS: TestRateLimiterFeedback (0.01s)445 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.04s)446 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.02s)447 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.02s)448 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.02s)449=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot450--- PASS: TestPartSizeForNAR (0.00s)451 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)452 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)453 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)454 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)455 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)456 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)457 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)458--- PASS: TestDumpPathSingleFile (0.11s)459=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken460=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot461--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)462 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.05s)463 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.08s)464=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot465=== CONT TestStreamPushStopsOnCancel/waiting_for_input466--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.14s)467=== CONT TestStreamPushBatchesUnderLoad/together468=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time469=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part470--- PASS: TestStreamPushBatchesUnderLoad (0.00s)471 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)472 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)473=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary474=== CONT TestSupersededNARStillUploadsListing/dump_cut_short475=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails476--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.01s)477 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.05s)478 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.05s)479 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.06s)480 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.07s)481 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.06s)482=== CONT TestSupersededNARStillUploadsListing/small_NAR483=== CONT TestSetClientTLSErrors/missing_cert_file484=== CONT TestSetClientTLSErrors/missing_key_file485=== CONT TestSetClientTLSErrors/missing_ca_file486=== CONT TestSetClientTLSErrors/invalid_ca_file487=== CONT TestSetClientTLS/preserves_debug_logging_transport488--- PASS: TestSetClientTLSErrors (0.01s)489 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)490 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)491 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)492 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)493=== CONT TestSetClientTLS/rejects_connection_without_client_cert494--- PASS: TestScriptTokenCachesUntilRefresh (0.18s)495=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA496--- PASS: TestStreamPushRequestLine (0.21s)497--- PASS: TestStreamPushStopsOnCancel (0.01s)498 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.05s)499 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.06s)500 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.08s)501 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.07s)502 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.06s)503 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.07s)504--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.00s)505 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.06s)506 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.07s)507--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.22s)508--- PASS: TestDumpPathWriterError (0.23s)509--- PASS: TestSetClientTLS (0.09s)510 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.03s)511 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.05s)512 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.05s)513--- PASS: TestDumpPathMatchesNix (0.25s)514--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.27s)515--- PASS: TestRegisterUploadedObjectReusesConnections (0.36s)516--- PASS: TestTruncatedNARDumpIsNotCompleted (0.57s)517--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.74s)518--- PASS: TestUploadMultipart_PartsInParallel (0.76s)519--- PASS: TestSupersededNARStillUploadsListing (0.00s)520 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.06s)521 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.05s)522 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.68s)523--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)524--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)525--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.00s)526 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.12s)527 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.20s)528PASS529Running server tests...530The files belonging to this database system will be owned by user "_tribuchetbld6".531This user must also own the server process.532533The database cluster will be initialized with locale "C".534The default database encoding has accordingly been set to "SQL_ASCII".535The default text search configuration will be set to "english".536537Data page checksums are enabled.538539creating directory /private/var/tb/6/scratch/e3c58ef3d7a98188/build/postgres485264464/data ... ok540creating subdirectories ... ok541selecting dynamic shared memory implementation ... posix542selecting default "max_connections" ... 100543selecting default "shared_buffers" ... 128MB544selecting default time zone ... UTC545creating configuration files ... ok546running bootstrap script ... ok547performing post-bootstrap initialization ... ok548syncing data to disk ... ok549550initdb: warning: enabling "trust" authentication for local connections551initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.552553Success. You can now start the database server using:554555 pg_ctl -D /private/var/tb/6/scratch/e3c58ef3d7a98188/build/postgres485264464/data -l logfile start556557/private/var/tb/6/scratch/e3c58ef3d7a98188/build/postgres485264464:5432 - no response5582026-10-25 19:47:57.506 UTC [62631] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5592026-10-25 19:47:57.506 UTC [62631] LOG: listening on Unix socket "/private/var/tb/6/scratch/e3c58ef3d7a98188/build/postgres485264464/.s.PGSQL.5432"5602026-10-25 19:47:57.509 UTC [62638] LOG: database system was shut down at 2026-10-25 19:47:57 UTC5612026-10-25 19:47:57.510 UTC [62631] LOG: database system is ready to accept connections562/private/var/tb/6/scratch/e3c58ef3d7a98188/build/postgres485264464:5432 - accepting connections563{"timestamp":"2026-10-25T19:47:57.720683Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"7491a77d-a5bc-4699-915b-66ed1a3260aa","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}564=== RUN TestService_AuthMiddleware565=== PAUSE TestService_AuthMiddleware566=== RUN TestService_AuthMiddleware_MTLSProxyHeader567=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader568=== RUN TestService_AuthMiddleware_MTLSBoundSubjects569=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects570=== RUN TestService_ReadAuthMiddleware571=== PAUSE TestService_ReadAuthMiddleware572=== RUN TestService_AuthMiddleware_OIDC573=== PAUSE TestService_AuthMiddleware_OIDC574=== RUN TestService_RequireScope_OIDC575=== PAUSE TestService_RequireScope_OIDC576=== RUN TestService_ReadScope_PublicByDefault577=== PAUSE TestService_ReadScope_PublicByDefault578=== RUN TestCacheConfigHandler579=== PAUSE TestCacheConfigHandler580=== RUN TestCacheStatsHandler581=== PAUSE TestCacheStatsHandler582=== RUN TestClientCADerivations583=== PAUSE TestClientCADerivations584=== RUN TestClientErrorHandling585=== PAUSE TestClientErrorHandling586=== RUN TestClientIntegration587=== PAUSE TestClientIntegration588=== RUN TestClientMultipleUploads589=== PAUSE TestClientMultipleUploads590=== RUN TestClientWithDependencies591=== PAUSE TestClientWithDependencies592=== RUN TestClientSharedPathCommittedMidPush593=== PAUSE TestClientSharedPathCommittedMidPush594=== RUN TestPinProtectsFromGC595=== PAUSE TestPinProtectsFromGC596=== RUN TestClientPushesUseOnePush597=== PAUSE TestClientPushesUseOnePush598=== RUN TestClientFallsBackToClosures599=== PAUSE TestClientFallsBackToClosures600=== RUN TestDeleteClosuresRacingPins601=== PAUSE TestDeleteClosuresRacingPins602=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock603=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock604=== RUN TestResolveDBConnectionString605=== PAUSE TestResolveDBConnectionString606=== RUN TestConnectWaitsForAPeerMigration607=== PAUSE TestConnectWaitsForAPeerMigration608=== RUN TestConnectSerialisesConcurrentMigrations609=== PAUSE TestConnectSerialisesConcurrentMigrations610=== RUN TestLeadElectsOneAndHandsOver611=== PAUSE TestLeadElectsOneAndHandsOver612=== RUN TestLeadIncumbentWinsAfterRestart6132026/10/25 19:47:57 INFO lead: acquired remote=192.0.2.1:12346142026/10/25 19:47:58 INFO lead: released remote=192.0.2.1:12346152026/10/25 19:47:58 INFO lead: acquired remote=192.0.2.1:12346162026/10/25 19:47:59 INFO lead: released remote=192.0.2.1:1234617--- PASS: TestLeadIncumbentWinsAfterRestart (1.93s)618=== RUN TestLeadIncumbentAnnouncesAtOnce619=== PAUSE TestLeadIncumbentAnnouncesAtOnce620=== RUN TestLeadEndsOnShutdown621=== PAUSE TestLeadEndsOnShutdown622=== RUN TestLeadEndsWhenItsConnectionHangs6232026/10/25 19:47:59 INFO lead: acquired remote=192.0.2.1:12346242026-10-25 19:48:01.289 UTC [62683] FATAL: terminating connection due to administrator command6252026/10/25 19:48:01 INFO lead: acquired remote=192.0.2.1:12346262026/10/25 19:48:02 WARN lead: lock connection lost error="timeout: context deadline exceeded"6272026/10/25 19:48:02 INFO lead: released remote=192.0.2.1:12346282026/10/25 19:48:02 INFO lead: released remote=192.0.2.1:1234629--- PASS: TestLeadEndsWhenItsConnectionHangs (2.94s)630=== RUN TestGCAdvisoryLockBlocksConcurrentRun631=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun632=== RUN TestGCBugBareHashReferences633=== PAUSE TestGCBugBareHashReferences634=== RUN TestGCMetrics635=== PAUSE TestGCMetrics636=== RUN TestPushDedupSurvivesConcurrentGC637=== PAUSE TestPushDedupSurvivesConcurrentGC638=== RUN TestDeduplicatedObjectsRecordedAsPending639=== PAUSE TestDeduplicatedObjectsRecordedAsPending640=== RUN TestGCSweepSkipsPendingObjects641=== PAUSE TestGCSweepSkipsPendingObjects642=== RUN TestTombstonedObjectOfferedWithoutWaiting643=== PAUSE TestTombstonedObjectOfferedWithoutWaiting644=== RUN TestGCSweepDeliversEachKeyOnce645=== PAUSE TestGCSweepDeliversEachKeyOnce646=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection647=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection648=== RUN TestForceGCDuringPushOffersSweptObject649=== PAUSE TestForceGCDuringPushOffersSweptObject650=== RUN TestFailedS3DeleteKeepsTombstone651=== PAUSE TestFailedS3DeleteKeepsTombstone652=== RUN TestSweepSkipsRowsLockedByPush653=== PAUSE TestSweepSkipsRowsLockedByPush654=== RUN TestRegisterCompletedObjectNeedsPendingRow655=== PAUSE TestRegisterCompletedObjectNeedsPendingRow656=== RUN TestGetExistingObjectsLocksRows657=== PAUSE TestGetExistingObjectsLocksRows658=== RUN TestSweepRechecksPendingAfterLocking659=== PAUSE TestSweepRechecksPendingAfterLocking660=== RUN TestPushWaitsForSweepHoldingRow661=== PAUSE TestPushWaitsForSweepHoldingRow662=== RUN TestCommitRacingPendingCleanupKeepsObjects663=== PAUSE TestCommitRacingPendingCleanupKeepsObjects664=== RUN TestGCEndsOnShutdown665=== PAUSE TestGCEndsOnShutdown666=== RUN TestGCTaskStore_StartNew667=== PAUSE TestGCTaskStore_StartNew668=== RUN TestGCTaskStore_DeduplicateSameParams669=== PAUSE TestGCTaskStore_DeduplicateSameParams670=== RUN TestGCTaskStore_ConflictDifferentParams671=== PAUSE TestGCTaskStore_ConflictDifferentParams672=== RUN TestGCTaskStore_GetEmpty673=== PAUSE TestGCTaskStore_GetEmpty674=== RUN TestGCTaskStore_GetReturnsLatest675=== PAUSE TestGCTaskStore_GetReturnsLatest676=== RUN TestGCTaskStore_CompletedAllowsNewTask677=== PAUSE TestGCTaskStore_CompletedAllowsNewTask678=== RUN TestGCTaskStore_PhaseUpdates679=== PAUSE TestGCTaskStore_PhaseUpdates680=== RUN TestGCTaskStore_Fail681=== PAUSE TestGCTaskStore_Fail682=== RUN TestGracefulShutdownDrainsInflight683=== PAUSE TestGracefulShutdownDrainsInflight684=== RUN TestService_healthCheckHandler685=== PAUSE TestService_healthCheckHandler686=== RUN TestService_readinessHandler687=== PAUSE TestService_readinessHandler688=== RUN TestGenerateLandingPage689=== PAUSE TestGenerateLandingPage690=== RUN TestChildrenInheritRaisedFileLimit691=== PAUSE TestChildrenInheritRaisedFileLimit692=== RUN TestCacheConfigHandlerMaxNarSize693=== PAUSE TestCacheConfigHandlerMaxNarSize694=== RUN TestCreatePendingClosureRejectsOversizedNAR695=== PAUSE TestCreatePendingClosureRejectsOversizedNAR696=== RUN TestNARDeduplicationMetadataUploadBug697=== PAUSE TestNARDeduplicationMetadataUploadBug698=== RUN TestMetricsInventory699=== PAUSE TestMetricsInventory700=== RUN TestMetricsCommit701=== PAUSE TestMetricsCommit702=== RUN TestService_NativeMTLS703=== PAUSE TestService_NativeMTLS704=== RUN TestServerTLSConfig705=== PAUSE TestServerTLSConfig706=== RUN TestMultipartCleanup707=== PAUSE TestMultipartCleanup708=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded709=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded710=== RUN TestPendingCleanupUsesOneCutoff711=== PAUSE TestPendingCleanupUsesOneCutoff712=== RUN TestPendingClosureFailureTracksEveryUpload713=== PAUSE TestPendingClosureFailureTracksEveryUpload714=== RUN TestPendingClosureFailureAbortsItsUploads715=== PAUSE TestPendingClosureFailureAbortsItsUploads716=== RUN TestObjectStatsTrigger717=== PAUSE TestObjectStatsTrigger718=== RUN TestObjectStatsUpdatedOncePerCommit719=== PAUSE TestObjectStatsUpdatedOncePerCommit720=== RUN TestReconnectLeavesObjectsUnlocked721=== PAUSE TestReconnectLeavesObjectsUnlocked722=== RUN TestOrphanedObjectsGC723=== PAUSE TestOrphanedObjectsGC724=== RUN TestOrphanedObjectsGCStressTest725=== PAUSE TestOrphanedObjectsGCStressTest726=== RUN TestCreatePin_ReservedPins727=== PAUSE TestCreatePin_ReservedPins728=== RUN TestConcurrentPinUpdatesAgree729=== PAUSE TestConcurrentPinUpdatesAgree730=== RUN TestCreatePinRejectsBadInput731=== PAUSE TestCreatePinRejectsBadInput732=== RUN TestDeletePinKeepsRowWhenS3Fails733=== PAUSE TestDeletePinKeepsRowWhenS3Fails734=== RUN TestPresentReportsOnlyClosureRoots735=== PAUSE TestPresentReportsOnlyClosureRoots736=== RUN TestPresentRefreshesOnlyStaleClosures737=== PAUSE TestPresentRefreshesOnlyStaleClosures738=== RUN TestPresentNotReportedWhileGCDeletesClosure739=== PAUSE TestPresentNotReportedWhileGCDeletesClosure740=== RUN TestParseSingleRange741=== PAUSE TestParseSingleRange742=== RUN TestProxyHeadersOnlyTrustedOnSocket7432026/10/25 19:48:02 INFO Starting HTTP server address=127.0.0.1:589027442026/10/25 19:48:02 INFO Starting HTTP server address=proxy.sock7452026/10/25 19:48:02 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7462026/10/25 19:48:02 INFO Shutdown signal received, draining in-flight requests timeout=10s747--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.18s)748=== RUN TestIsValidCachePath749=== PAUSE TestIsValidCachePath750=== RUN TestReadProxyNarinfo751=== PAUSE TestReadProxyNarinfo752=== RUN TestReadProxyNarinfoAlreadyDecompressed753=== PAUSE TestReadProxyNarinfoAlreadyDecompressed754=== RUN TestReadProxyContentNegotiation755=== PAUSE TestReadProxyContentNegotiation756=== RUN TestReadProxyNarStreaming757=== PAUSE TestReadProxyNarStreaming758=== RUN TestReadProxy404759=== PAUSE TestReadProxy404760=== RUN TestReadProxyInvalidPath761=== PAUSE TestReadProxyInvalidPath762=== RUN TestReadProxyHead763=== PAUSE TestReadProxyHead764=== RUN TestReadProxyOutlastsServerWriteTimeout765=== PAUSE TestReadProxyOutlastsServerWriteTimeout766=== RUN TestReadProxyConditionalGet767=== PAUSE TestReadProxyConditionalGet768=== RUN TestReadProxyRootRedirectsToIndexHTML769=== PAUSE TestReadProxyRootRedirectsToIndexHTML770=== RUN TestReadProxyDisabled771=== PAUSE TestReadProxyDisabled772=== RUN TestReadRedirectNar773=== PAUSE TestReadRedirectNar774=== RUN TestReadRedirectKeepsNarinfoProxied775=== PAUSE TestReadRedirectKeepsNarinfoProxied776=== RUN TestReadProxyRangeRequest777=== PAUSE TestReadProxyRangeRequest778=== RUN TestReadRedirectUsesPublicS3URL779=== PAUSE TestReadRedirectUsesPublicS3URL780=== RUN TestPush_OverlappingRootsStoreOneRowPerKey781=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey782=== RUN TestPush_CompleteCommitsEveryRoot783=== PAUSE TestPush_CompleteCommitsEveryRoot784=== RUN TestPush_RepeatedRootCommitsOnce785=== PAUSE TestPush_RepeatedRootCommitsOnce786=== RUN TestPush_CompleteWaitsForCleanupOfThePush787=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush788=== RUN TestPush_RootsAreLockedInByteOrder789=== PAUSE TestPush_RootsAreLockedInByteOrder790=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit791=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit792=== RUN TestPush_RejectsBadRequests793=== PAUSE TestPush_RejectsBadRequests794=== RUN TestPush_SignsNarinfosOfItsPendingObjects795=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects796=== RUN TestRedundantMultipartUpload797=== PAUSE TestRedundantMultipartUpload798=== RUN TestCompleteMultipartUpload_ErrorButObjectExists799=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists800=== RUN TestCompletedNarNotReofferedAcrossClosures801=== PAUSE TestCompletedNarNotReofferedAcrossClosures802=== RUN TestPresignedUploadRegisteredBeforeCommit803=== PAUSE TestPresignedUploadRegisteredBeforeCommit804=== RUN TestService_Rustfstest805=== PAUSE TestService_Rustfstest806=== RUN TestParseSize807=== PAUSE TestParseSize808=== RUN TestSkippedUploadsHandler809=== PAUSE TestSkippedUploadsHandler810=== RUN TestSystemdListenerNotActivated811--- PASS: TestSystemdListenerNotActivated (0.00s)812=== RUN TestWatchdogBeatsWhenHealthy813--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)814=== RUN TestWatchdogSkipsWhenUnhealthy8152026/10/25 19:48:02 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8162026/10/25 19:48:02 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8172026/10/25 19:48:02 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8182026/10/25 19:48:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8192026/10/25 19:48:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8202026/10/25 19:48:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8212026/10/25 19:48:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8222026/10/25 19:48:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8232026/10/25 19:48:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8242026/10/25 19:48:03 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"825--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)826=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle827=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle828=== RUN TestProxyWriteTimeout829=== PAUSE TestProxyWriteTimeout830=== RUN TestPendingClosureWriteTimeout831=== PAUSE TestPendingClosureWriteTimeout832=== RUN TestIsValidUploadKey833=== PAUSE TestIsValidUploadKey834=== RUN TestUploadHandlersRejectInvalidKeys835=== PAUSE TestUploadHandlersRejectInvalidKeys836=== RUN TestUploadHandlersRejectOversizedBody837=== PAUSE TestUploadHandlersRejectOversizedBody838=== RUN TestService_cleanupPendingClosuresHandler839=== PAUSE TestService_cleanupPendingClosuresHandler840=== RUN TestService_createPendingClosureHandler841=== PAUSE TestService_createPendingClosureHandler842=== RUN TestService_verifyS3Integrity843=== PAUSE TestService_verifyS3Integrity844=== RUN TestCompleteMultipartUnregistered845=== PAUSE TestCompleteMultipartUnregistered846=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT847=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT848=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit849=== CONT TestDeletePinKeepsRowWhenS3Fails850=== CONT TestConcurrentPinUpdatesAgree851=== CONT TestGCTaskStore_GetReturnsLatest852--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)853=== CONT TestGCTaskStore_GetEmpty854--- PASS: TestGCTaskStore_GetEmpty (0.00s)855=== CONT TestLeadElectsOneAndHandsOver856=== CONT TestLeadIncumbentAnnouncesAtOnce857=== CONT TestParseSize858=== CONT TestCreatePinRejectsBadInput859--- PASS: TestParseSize (0.00s)860=== CONT TestCompleteMultipartUnregistered861=== CONT TestService_AuthMiddleware_MTLSProxyHeader862=== CONT TestGracefulShutdownDrainsInflight863=== CONT TestFailedS3DeleteKeepsTombstone864=== CONT TestGCTaskStore_Fail865=== CONT TestService_Rustfstest866--- PASS: TestGCTaskStore_Fail (0.00s)867=== CONT TestReconnectLeavesObjectsUnlocked868=== CONT TestPresignedUploadRegisteredBeforeCommit869=== CONT TestGCTaskStore_ConflictDifferentParams870=== CONT TestCompletedNarNotReofferedAcrossClosures871=== CONT TestCompleteMultipartUpload_ErrorButObjectExists872=== CONT TestRedundantMultipartUpload873=== CONT TestGCTaskStore_StartNew874=== CONT TestSkippedUploadsHandler875=== CONT TestCreatePin_ReservedPins876=== CONT TestGCTaskStore_DeduplicateSameParams877=== CONT TestOrphanedObjectsGC878=== CONT TestGCEndsOnShutdown879=== CONT TestGCTaskStore_CompletedAllowsNewTask880--- PASS: TestGCTaskStore_StartNew (0.00s)881=== RUN TestGCEndsOnShutdown/before_the_run882=== CONT TestConnectWaitsForAPeerMigration883=== CONT TestPushWaitsForSweepHoldingRow884=== CONT TestObjectStatsUpdatedOncePerCommit885--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)886--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)887--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)888=== CONT TestConnectSerialisesConcurrentMigrations8892026/10/25 19:48:03 INFO Starting HTTP server address=127.0.0.1:58906890=== PAUSE TestGCEndsOnShutdown/before_the_run891=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete892=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete893=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark894=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark895=== CONT TestOrphanedObjectsGCStressTest8962026/10/25 19:48:03 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000897--- PASS: TestSkippedUploadsHandler (0.03s)898=== CONT TestPendingClosureFailureAbortsItsUploads8992026/10/25 19:48:03 INFO Shutdown signal received, draining in-flight requests timeout=10s900--- PASS: TestGracefulShutdownDrainsInflight (0.11s)901=== CONT TestResolveDBConnectionString902=== RUN TestResolveDBConnectionString/flag_wins903=== PAUSE TestResolveDBConnectionString/flag_wins904=== RUN TestResolveDBConnectionString/file_when_flag_empty905=== PAUSE TestResolveDBConnectionString/file_when_flag_empty906=== RUN TestResolveDBConnectionString/missing_file_is_an_error907=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error908=== RUN TestResolveDBConnectionString/PGHOST_allows_empty909=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty910=== RUN TestResolveDBConnectionString/nothing_configured911=== PAUSE TestResolveDBConnectionString/nothing_configured912=== CONT TestPendingClosureFailureTracksEveryUpload913=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false914=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false915=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true916=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true917=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock9182026/10/25 19:48:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:58908/oidc9192026/10/25 19:48:03 INFO Received uploads request method=POST path=/api/pending_closures920--- PASS: TestObjectStatsUpdatedOncePerCommit (0.95s)921=== CONT TestGetExistingObjectsLocksRows9222026/10/25 19:48:04 INFO Received create pin request method=POST path=/api/pins/app9232026/10/25 19:48:04 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo9242026/10/25 19:48:04 INFO Received delete pin request method=DELETE path=/api/pins/app9252026/10/25 19:48:04 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"9262026/10/25 19:48:04 INFO Received delete pin request method=DELETE path=/api/pins/app927--- PASS: TestPushWaitsForSweepHoldingRow (1.35s)928=== CONT TestCommitRacingPendingCleanupKeepsObjects9292026/10/25 19:48:04 INFO Received push request method=POST path=/api/pushes9302026/10/25 19:48:04 INFO Deleted pin name=app931--- PASS: TestDeletePinKeepsRowWhenS3Fails (1.45s)932=== CONT TestObjectStatsTrigger9332026/10/25 19:48:05 INFO Received uploads request method=POST path=/api/pending_closures9342026/10/25 19:48:05 INFO Aborted multipart uploads count=0 kept=09352026-10-25 19:48:05.465 UTC [63168] ERROR: duplicate key value violates unique constraint "pg_type_typname_nsp_index"9362026-10-25 19:48:05.465 UTC [63168] DETAIL: Key (typname, typnamespace)=(goose_db_version, 2200) already exists.9372026-10-25 19:48:05.465 UTC [63168] STATEMENT: CREATE TABLE goose_db_version (938 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,939 version_id bigint NOT NULL,940 is_applied boolean NOT NULL,941 tstamp timestamp NOT NULL DEFAULT now()942 )9432026/10/25 19:48:05 WARN Force mode enabled - objects will be deleted immediately without grace period9442026/10/25 19:48:05 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."9452026/10/25 19:48:05 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."946--- PASS: TestFailedS3DeleteKeepsTombstone (2.35s)947=== CONT TestSweepSkipsRowsLockedByPush9482026/10/25 19:48:05 INFO lead: acquired remote=192.0.2.1:12349492026/10/25 19:48:05 INFO lead: acquired remote=192.0.2.1:12349502026/10/25 19:48:05 INFO lead: released remote=192.0.2.1:1234951--- PASS: TestLeadIncumbentAnnouncesAtOnce (2.62s)952=== CONT TestClientFallsBackToClosures9532026/10/25 19:48:05 INFO Received create pin request method=POST path=/api/pins/deploy9542026/10/25 19:48:05 INFO Received create pin request method=POST path=/api/pins/deploy9552026/10/25 19:48:05 INFO Received create pin request method=POST path=/api/pins/deploy9562026/10/25 19:48:05 INFO Received create pin request method=POST path=/api/pins/deploy9572026/10/25 19:48:05 INFO Received create pin request method=POST path=/api/pins/deploy9582026/10/25 19:48:05 INFO Received create pin request method=POST path=/api/pins/deploy9592026/10/25 19:48:05 INFO Received create pin request method=POST path=/api/pins/deploy9602026/10/25 19:48:05 INFO Received create pin request method=POST path=/api/pins/deploy9612026/10/25 19:48:06 INFO Received create pin request method=POST path=/api/pins/deploy9622026/10/25 19:48:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9632026/10/25 19:48:06 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLjc3MWI5ZDNjLTFhZjQtNDNhYS1hNGFmLWY4NzM4YTM2M2IwMngxNzkyOTU3Njg0NTY0NTEwMDAw parts=109642026/10/25 19:48:06 INFO Received uploads request method=POST path=/api/pending_closures9652026/10/25 19:48:06 INFO Received create pin request method=POST path=/api/pins/deploy9662026/10/25 19:48:06 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo967--- PASS: TestCreatePinRejectsBadInput (3.24s)968=== CONT TestRegisterCompletedObjectNeedsPendingRow969--- PASS: TestConnectSerialisesConcurrentMigrations (3.34s)970=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded9712026/10/25 19:48:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9722026/10/25 19:48:06 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLjAzNTM0ZjQ0LTM0ODgtNDhjMS05MjhhLTdkMjNjYmFiNGY4ZHgxNzkyOTU3Njg2MjgyOTUzMDAw9732026/10/25 19:48:06 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLjAzNTM0ZjQ0LTM0ODgtNDhjMS05MjhhLTdkMjNjYmFiNGY4ZHgxNzkyOTU3Njg2MjgyOTUzMDAw error="Delete \"http://localhost:58878/bucket12/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLjAzNTM0ZjQ0LTM0ODgtNDhjMS05MjhhLTdkMjNjYmFiNGY4ZHgxNzkyOTU3Njg2MjgyOTUzMDAw\": injected: abort refused"9742026/10/25 19:48:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9752026/10/25 19:48:06 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLjAzNTM0ZjQ0LTM0ODgtNDhjMS05MjhhLTdkMjNjYmFiNGY4ZHgxNzkyOTU3Njg2MjgyOTUzMDAw9762026/10/25 19:48:06 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLjAzNTM0ZjQ0LTM0ODgtNDhjMS05MjhhLTdkMjNjYmFiNGY4ZHgxNzkyOTU3Njg2MjgyOTUzMDAw parts=19772026/10/25 19:48:06 INFO lead: released remote=192.0.2.1:1234978--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (3.59s)979=== CONT TestMultipartCleanup9802026/10/25 19:48:06 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9812026/10/25 19:48:06 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst9822026/10/25 19:48:06 INFO lead: acquired remote=192.0.2.1:1234983--- PASS: TestCompleteMultipartUnregistered (3.64s)984=== CONT TestPinProtectsFromGC9852026/10/25 19:48:07 INFO Received uploads request method=POST path=/api/pending_closures9862026/10/25 19:48:07 INFO Received uploads request method=POST path=/api/pending_closures9872026/10/25 19:48:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9882026/10/25 19:48:07 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9892026/10/25 19:48:07 INFO Received uploads request method=POST path=/api/pending_closures9902026/10/25 19:48:07 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLmRkNGZiZTUwLTM0ODUtNGEzNC1hY2QxLTFmNjY0NzdmMDgxY3gxNzkyOTU3Njg0NTY3NTAyMDAw parts=109912026/10/25 19:48:07 INFO Received complete push request method=POST path=/api/pushes/1/complete992--- PASS: TestPresignedUploadRegisteredBeforeCommit (4.36s)993=== CONT TestTombstonedObjectOfferedWithoutWaiting9942026/10/25 19:48:07 INFO Completed push id=1 objects=4 duration=27.258959ms9952026/10/25 19:48:07 INFO Received push request method=POST path=/api/pushes9962026/10/25 19:48:07 INFO Aborted multipart uploads count=0 kept=09972026/10/25 19:48:07 WARN Force mode enabled - objects will be deleted immediately without grace period9982026/10/25 19:48:07 INFO lead: released remote=192.0.2.1:1234999=== CONT TestClientPushesUseOnePush1000--- PASS: TestLeadElectsOneAndHandsOver (4.76s)1001--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (4.99s)1002=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10032026/10/25 19:48:08 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=010042026/10/25 19:48:08 INFO Vacuumed table table=pending_closures10052026/10/25 19:48:08 INFO Vacuumed table table=pending_objects10062026/10/25 19:48:08 INFO Vacuumed table table=multipart_uploads10072026/10/25 19:48:08 INFO Vacuumed table table=closures10082026/10/25 19:48:08 INFO Vacuumed table table=objects10092026/10/25 19:48:08 INFO Received uploads request method=POST path=/api/pending_closures10102026/10/25 19:48:08 INFO Received uploads request method=POST path=/api/pending_closures10112026/10/25 19:48:08 INFO Received uploads request method=POST path=/api/pending_closures1012--- PASS: TestPendingClosureFailureAbortsItsUploads (6.05s)1013=== CONT TestPendingCleanupUsesOneCutoff1014=== CONT TestClientSharedPathCommittedMidPush1015--- PASS: TestService_Rustfstest (6.37s)10162026/10/25 19:48:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10172026/10/25 19:48:09 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLjRhNTg3NjVlLTVjZGQtNDVmMy05MzkwLTcwODE5OWE5OGIzOHgxNzkyOTU3Njg3MTA1Mjc0MDAw parts=1210182026/10/25 19:48:09 INFO Received uploads request method=POST path=/api/pending_closures1019--- PASS: TestCompletedNarNotReofferedAcrossClosures (6.71s)1020=== CONT TestClientMultipleUploads1021--- PASS: TestReconnectLeavesObjectsUnlocked (7.06s)1022=== CONT TestGCSweepDeliversEachKeyOnce1023=== NAME TestOrphanedObjectsGC1024 orphaned_objects_gc_test.go:287: GC Test Summary:1025 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1026 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1027 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1028 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1029 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1030--- PASS: TestOrphanedObjectsGC (7.43s)1031=== CONT TestService_NativeMTLS1032--- PASS: TestConnectWaitsForAPeerMigration (7.77s)1033=== CONT TestForceGCDuringPushOffersSweptObject1034=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1035=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1036=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1037=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1038=== CONT TestServerTLSConfig1039=== RUN TestServerTLSConfig/no_client_CA1040=== PAUSE TestServerTLSConfig/no_client_CA1041=== RUN TestServerTLSConfig/missing_CA_file1042=== PAUSE TestServerTLSConfig/missing_CA_file1043=== RUN TestServerTLSConfig/not_a_PEM_file1044=== PAUSE TestServerTLSConfig/not_a_PEM_file1045=== CONT TestGCSweepSkipsPendingObjects10462026/10/25 19:48:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10472026/10/25 19:48:11 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLjNhZGQ5YjhiLWRjMzUtNDJjNS1iYzQwLTRhMzU0NDg0ZDlhYngxNzkyOTU3Njg3NTM1NjMzMDAw parts=1010482026/10/25 19:48:11 INFO Received complete push request method=POST path=/api/pushes/2/complete10492026/10/25 19:48:11 INFO Completed push id=2 objects=4 duration=8.13725ms1050--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (8.12s)1051=== CONT TestMetricsInventory10522026/10/25 19:48:11 INFO Received create pin request method=POST path=/api/pins/app10532026/10/25 19:48:11 INFO Received create pin request method=POST path=/api/pins/app10542026/10/25 19:48:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10552026/10/25 19:48:11 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10562026/10/25 19:48:11 WARN Refused reserved pin name=worker-x86_64-linux10572026/10/25 19:48:11 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10582026/10/25 19:48:11 INFO Received create pin request method=POST path=/api/pins/my-app10592026/10/25 19:48:11 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1060--- PASS: TestCreatePin_ReservedPins (8.79s)1061=== CONT TestClientIntegration10622026/10/25 19:48:11 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo10632026/10/25 19:48:11 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLmEzODc2MjBiLWEwYTItNDg3Yi04NGFkLWM4MjMyODFjMmQxM3gxNzkyOTU3Njg4NTk0MjY5MDAw parts=1210642026/10/25 19:48:12 INFO Received uploads request method=POST path=/api/pending_closures10652026/10/25 19:48:12 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo10662026/10/25 19:48:12 INFO Received uploads request method=POST path=/api/pending_closures1067--- PASS: TestConcurrentPinUpdatesAgree (8.98s)1068=== CONT TestDeduplicatedObjectsRecordedAsPending1069--- PASS: TestGetExistingObjectsLocksRows (8.23s)1070=== CONT TestMetricsCommit10712026/10/25 19:48:12 INFO Aborted multipart uploads count=0 kept=010722026/10/25 19:48:12 WARN Force mode enabled - objects will be deleted immediately without grace period10732026/10/25 19:48:12 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010742026/10/25 19:48:13 INFO Vacuumed table table=pending_closures10752026/10/25 19:48:13 INFO Vacuumed table table=pending_objects10762026/10/25 19:48:13 INFO Vacuumed table table=multipart_uploads10772026/10/25 19:48:13 INFO Vacuumed table table=closures10782026/10/25 19:48:13 INFO Vacuumed table table=objects1079--- PASS: TestCommitRacingPendingCleanupKeepsObjects (8.69s)1080=== CONT TestIsValidUploadKey1081=== RUN TestIsValidUploadKey/narinfo1082=== PAUSE TestIsValidUploadKey/narinfo1083=== RUN TestIsValidUploadKey/nar_zst1084=== PAUSE TestIsValidUploadKey/nar_zst1085=== RUN TestIsValidUploadKey/nar_xz1086=== PAUSE TestIsValidUploadKey/nar_xz1087=== RUN TestIsValidUploadKey/nar_plain1088=== PAUSE TestIsValidUploadKey/nar_plain1089=== RUN TestIsValidUploadKey/listing1090=== PAUSE TestIsValidUploadKey/listing1091=== RUN TestIsValidUploadKey/build_log1092=== PAUSE TestIsValidUploadKey/build_log1093=== RUN TestIsValidUploadKey/build_log_home-manager_file1094=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1095=== RUN TestIsValidUploadKey/build_log_plus_in_name1096=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1097=== RUN TestIsValidUploadKey/build_log_question_mark1098=== PAUSE TestIsValidUploadKey/build_log_question_mark1099=== RUN TestIsValidUploadKey/build_log_equals1100=== PAUSE TestIsValidUploadKey/build_log_equals1101--- PASS: TestObjectStatsTrigger (8.63s)1102=== CONT TestService_verifyS3Integrity1103=== RUN TestIsValidUploadKey/realisation1104=== PAUSE TestIsValidUploadKey/realisation1105=== RUN TestIsValidUploadKey/realisation_plus_in_output1106=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1107=== RUN TestIsValidUploadKey/nix-cache-info1108=== PAUSE TestIsValidUploadKey/nix-cache-info1109=== RUN TestIsValidUploadKey/index.html1110=== PAUSE TestIsValidUploadKey/index.html1111=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1112=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1113=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1114=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1115=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1116=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1117=== RUN TestIsValidUploadKey/traversal1118=== PAUSE TestIsValidUploadKey/traversal1119=== RUN TestIsValidUploadKey/traversal_nar1120=== PAUSE TestIsValidUploadKey/traversal_nar1121=== RUN TestIsValidUploadKey/absolute1122=== PAUSE TestIsValidUploadKey/absolute1123=== RUN TestIsValidUploadKey/empty_key1124=== PAUSE TestIsValidUploadKey/empty_key1125=== RUN TestIsValidUploadKey/unknown_type1126=== PAUSE TestIsValidUploadKey/unknown_type1127=== CONT TestService_createPendingClosureHandler11282026/10/25 19:48:13 INFO Aborted multipart uploads count=0 kept=011292026/10/25 19:48:13 WARN Force mode enabled - objects will be deleted immediately without grace period11302026/10/25 19:48:13 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=011312026/10/25 19:48:13 INFO Vacuumed table table=pending_closures11322026/10/25 19:48:13 INFO Vacuumed table table=pending_objects11332026/10/25 19:48:13 INFO Vacuumed table table=multipart_uploads11342026/10/25 19:48:13 INFO Vacuumed table table=closures11352026/10/25 19:48:14 INFO Vacuumed table table=objects11362026/10/25 19:48:14 INFO Aborted multipart uploads count=0 kept=011372026/10/25 19:48:14 WARN Force mode enabled - objects will be deleted immediately without grace period11382026/10/25 19:48:14 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=011392026/10/25 19:48:14 INFO Vacuumed table table=pending_closures11402026/10/25 19:48:14 INFO Vacuumed table table=pending_objects11412026/10/25 19:48:14 INFO Vacuumed table table=multipart_uploads11422026/10/25 19:48:14 INFO Vacuumed table table=closures11432026/10/25 19:48:14 INFO Vacuumed table table=objects1144--- PASS: TestSweepSkipsRowsLockedByPush (8.90s)1145=== CONT TestCreatePendingClosureRejectsOversizedNAR11462026/10/25 19:48:14 INFO Received uploads request method=POST path=/api/pending_closures1147--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1148=== CONT TestCacheConfigHandlerMaxNarSize1149--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1150=== CONT TestClientWithDependencies11512026/10/25 19:48:14 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11522026/10/25 19:48:14 INFO Received uploads request method=POST path=/api/pending_closures1153--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (11.35s)1154=== CONT TestNARDeduplicationMetadataUploadBug11552026/10/25 19:48:14 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLmFkYjU4OWMyLTlmMWMtNDhkZi04MWEwLTYyYWQ4NWIyNWZiMngxNzkyOTU3NjkyMDcyMzcyMDAw error="Get \"http://127.0.0.1:1/bucket19/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11562026/10/25 19:48:14 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLjBiODMwOGJmLTZhNjUtNDBiMy1iMzdkLTc5OTEwNTU5M2Q5ZngxNzkyOTU3NjkyMDEyODM0MDAw parts=1211572026/10/25 19:48:14 INFO Received cleanup request method=DELETE path=/api/pending_closures11582026/10/25 19:48:14 INFO Aborted multipart uploads count=1 kept=01159--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (8.38s)1160=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT1161--- PASS: TestRedundantMultipartUpload (11.79s)1162=== CONT TestClientErrorHandling1163=== RUN TestClientErrorHandling/InvalidStorePath1164=== PAUSE TestClientErrorHandling/InvalidStorePath1165=== RUN TestClientErrorHandling/InvalidAuthToken1166=== PAUSE TestClientErrorHandling/InvalidAuthToken1167=== RUN TestClientErrorHandling/ServerNotAvailable1168=== PAUSE TestClientErrorHandling/ServerNotAvailable1169=== CONT TestUploadHandlersRejectOversizedBody1170--- PASS: TestRegisterCompletedObjectNeedsPendingRow (8.69s)1171=== CONT TestGenerateLandingPage1172--- PASS: TestGenerateLandingPage (0.04s)1173=== CONT TestService_cleanupPendingClosuresHandler1174=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1175=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1176=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1177=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1178=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1179=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1180=== CONT TestClientCADerivations11812026/10/25 19:48:15 INFO Received uploads request method=POST path=/api/pending_closures11822026/10/25 19:48:15 INFO Received uploads request method=POST path=/api/pending_closures11832026/10/25 19:48:15 INFO Received uploads request method=POST path=/api/pending_closures11842026/10/25 19:48:15 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11852026/10/25 19:48:15 INFO Uploading 0s6i4qwn8qci8196f1jvdpzdvwnh4pdf-b (256B)11862026/10/25 19:48:15 INFO Uploading 659lbj6m2gjxbnhfz5qb09cimvsgjby5-shared-dep (136B)11872026/10/25 19:48:15 WARN Failed to register uploaded object key=842kwf6ly2xmjr73br5qmd7v1rkmy23z.ls error="server returned 404: 404 page not found\n"11882026/10/25 19:48:15 WARN Failed to register uploaded object key=nar/15bxx3f3f432ik49a4ybmarmvaarp5y8wy76g7l3gpikh6pa6lpg.nar.zst error="server returned 404: 404 page not found\n"11892026/10/25 19:48:15 WARN Failed to register uploaded object key=659lbj6m2gjxbnhfz5qb09cimvsgjby5.ls error="server returned 404: 404 page not found\n"11902026/10/25 19:48:15 WARN Failed to register uploaded object key=0s6i4qwn8qci8196f1jvdpzdvwnh4pdf.ls error="server returned 404: 404 page not found\n"11912026/10/25 19:48:15 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11922026/10/25 19:48:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11932026/10/25 19:48:15 INFO Signed narinfos id=2 count=211942026/10/25 19:48:15 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11952026/10/25 19:48:15 INFO Signed narinfos id=1 count=211962026/10/25 19:48:15 INFO Uploading 4 narinfos11972026/10/25 19:48:15 INFO Received cleanup request method=DELETE path=/api/pending_closures11982026/10/25 19:48:15 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket33/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11992026/10/25 19:48:15 INFO Aborted multipart uploads count=0 kept=112002026/10/25 19:48:15 WARN Failed to register uploaded object key=659lbj6m2gjxbnhfz5qb09cimvsgjby5.narinfo error="server returned 404: 404 page not found\n"12012026/10/25 19:48:15 INFO Received cleanup request method=DELETE path=/api/pending_closures12022026/10/25 19:48:15 WARN Failed to register uploaded object key=842kwf6ly2xmjr73br5qmd7v1rkmy23z.narinfo error="server returned 404: 404 page not found\n"12032026/10/25 19:48:15 WARN Failed to register uploaded object key=0s6i4qwn8qci8196f1jvdpzdvwnh4pdf.narinfo error="server returned 404: 404 page not found\n"12042026/10/25 19:48:15 INFO Aborted multipart uploads count=1 kept=012052026/10/25 19:48:15 WARN Failed to register uploaded object key=659lbj6m2gjxbnhfz5qb09cimvsgjby5.narinfo error="server returned 404: 404 page not found\n"12062026/10/25 19:48:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12072026/10/25 19:48:15 INFO Completed upload id=1 objects=6 duration=12.644208ms12082026/10/25 19:48:15 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12092026/10/25 19:48:15 INFO Completed upload id=2 objects=6 duration=15.16175ms12102026/10/25 19:48:15 INFO Upload complete. (592ms)1211=== NAME TestClientFallsBackToClosures1212 client_pushes_test.go:112: Retrieved narinfo from S3:1213 StorePath: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientFallsBackToClosures1936971926/001/store/659lbj6m2gjxbnhfz5qb09cimvsgjby5-shared-dep1214 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1215 Compression: zstd1216 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821217 NarSize: 1361218 References: 1219 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1220 client_pushes_test.go:112: Retrieved narinfo from S3:1221 StorePath: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientFallsBackToClosures1936971926/001/store/842kwf6ly2xmjr73br5qmd7v1rkmy23z-a1222 URL: nar/15bxx3f3f432ik49a4ybmarmvaarp5y8wy76g7l3gpikh6pa6lpg.nar.zst1223 Compression: zstd1224 NarHash: sha256:15bxx3f3f432ik49a4ybmarmvaarp5y8wy76g7l3gpikh6pa6lpg1225 NarSize: 2561226 References: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientFallsBackToClosures1936971926/001/store/659lbj6m2gjxbnhfz5qb09cimvsgjby5-shared-dep1227 CA: text:sha256:0wmr509x6ip0y275kfkxb25p9j65mgb0fb4mmas9favnixyj4ba91228 client_pushes_test.go:112: Retrieved narinfo from S3:1229 StorePath: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientFallsBackToClosures1936971926/001/store/0s6i4qwn8qci8196f1jvdpzdvwnh4pdf-b1230 URL: nar/15bxx3f3f432ik49a4ybmarmvaarp5y8wy76g7l3gpikh6pa6lpg.nar.zst1231 Compression: zstd1232 NarHash: sha256:15bxx3f3f432ik49a4ybmarmvaarp5y8wy76g7l3gpikh6pa6lpg1233 NarSize: 2561234 References: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientFallsBackToClosures1936971926/001/store/659lbj6m2gjxbnhfz5qb09cimvsgjby5-shared-dep1235 CA: text:sha256:0wmr509x6ip0y275kfkxb25p9j65mgb0fb4mmas9favnixyj4ba91236--- PASS: TestMultipartCleanup (9.15s)1237=== CONT TestReadProxyInvalidPath1238--- PASS: TestClientFallsBackToClosures (10.25s)1239=== CONT TestPush_RepeatedRootCommitsOnce1240=== NAME TestPinProtectsFromGC1241 client_integration_test.go:854: Pinned store path: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestPinProtectsFromGC3230503292/001/store/g5ssqvw3hmg65mks88qwrqy1frhlh7qs-pinned-file.txt1242 client_integration_test.go:855: Unpinned store path: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestPinProtectsFromGC3230503292/001/store/dgqr2paxb1bx3mmqk3d5wnc19lliilcb-unpinned-file.txt12432026/10/25 19:48:16 INFO Received uploads request method=POST path=/api/pending_closures1244--- PASS: TestTombstonedObjectOfferedWithoutWaiting (8.86s)1245=== CONT TestPush_CompleteCommitsEveryRoot12462026/10/25 19:48:16 INFO Received push request method=POST path=/api/pushes12472026/10/25 19:48:16 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12482026/10/25 19:48:16 INFO Uploading g5ssqvw3hmg65mks88qwrqy1frhlh7qs-pinned-file.txt (128B)12492026/10/25 19:48:16 INFO Received uploads request method=POST path=/api/pending_closures12502026/10/25 19:48:16 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"12512026/10/25 19:48:16 WARN Failed to register uploaded object key=g5ssqvw3hmg65mks88qwrqy1frhlh7qs.ls error="server returned 404: 404 page not found\n"12522026/10/25 19:48:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12532026/10/25 19:48:16 INFO Signed narinfos id=1 count=112542026/10/25 19:48:16 INFO Uploading 1 narinfos12552026/10/25 19:48:16 INFO Received complete push request method=POST path=/api/pushes/1/complete12562026/10/25 19:48:16 WARN Failed to register uploaded object key=g5ssqvw3hmg65mks88qwrqy1frhlh7qs.narinfo error="server returned 404: 404 page not found\n"12572026/10/25 19:48:16 INFO Completed push id=1 objects=3 duration=9.03725ms12582026/10/25 19:48:16 INFO Upload complete. (449ms)1259--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (8.80s)1260=== CONT TestReadRedirectUsesPublicS3URL12612026/10/25 19:48:16 INFO Received push request method=POST path=/api/pushes12622026/10/25 19:48:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12632026/10/25 19:48:17 INFO Uploading dgqr2paxb1bx3mmqk3d5wnc19lliilcb-unpinned-file.txt (128B)12642026/10/25 19:48:17 WARN Failed to register uploaded object key=dgqr2paxb1bx3mmqk3d5wnc19lliilcb.ls error="server returned 404: 404 page not found\n"12652026/10/25 19:48:17 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"12662026/10/25 19:48:17 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12672026/10/25 19:48:17 INFO Signed narinfos id=2 count=112682026/10/25 19:48:17 INFO Uploading 1 narinfos12692026/10/25 19:48:17 WARN Failed to register uploaded object key=dgqr2paxb1bx3mmqk3d5wnc19lliilcb.narinfo error="server returned 404: 404 page not found\n"12702026/10/25 19:48:17 INFO Received complete push request method=POST path=/api/pushes/2/complete12712026/10/25 19:48:17 INFO Completed push id=2 objects=3 duration=3.81125ms12722026/10/25 19:48:17 INFO Upload complete. (375ms)12732026/10/25 19:48:17 INFO Received uploads request method=POST path=/api/pending_closures12742026/10/25 19:48:17 INFO Starting cleanup of old closures method=DELETE path=/api/closures12752026/10/25 19:48:17 INFO Garbage collection started12762026/10/25 19:48:17 INFO Aborted multipart uploads count=0 kept=012772026/10/25 19:48:17 INFO Received uploads request method=POST path=/api/pending_closures12782026/10/25 19:48:17 WARN Force mode enabled - objects will be deleted immediately without grace period12792026/10/25 19:48:17 INFO Received cleanup request method=DELETE path=/api/pending_closures12802026/10/25 19:48:17 INFO Received push request method=POST path=/api/pushes12812026/10/25 19:48:17 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12822026/10/25 19:48:17 INFO Uploading 4pd3wg1s1raylb7n7a8gxp7l56g0z9b6-shared-dep (136B)12832026/10/25 19:48:17 INFO Uploading i27g9laxbn1nmc0877aignvdbqi00031-b (256B)12842026/10/25 19:48:17 WARN Failed to register uploaded object key=1jsffsx54qv277r3khvljdq5bf33j19b.ls error="server returned 404: 404 page not found\n"12852026/10/25 19:48:17 WARN Failed to register uploaded object key=i27g9laxbn1nmc0877aignvdbqi00031.ls error="server returned 404: 404 page not found\n"12862026/10/25 19:48:17 WARN Failed to register uploaded object key=4pd3wg1s1raylb7n7a8gxp7l56g0z9b6.ls error="server returned 404: 404 page not found\n"12872026/10/25 19:48:17 WARN Failed to register uploaded object key=nar/1mj8ll2zpg1fvwn700wb7arqg58gblp209cbk5i202dkh84cp028.nar.zst error="server returned 404: 404 page not found\n"12882026/10/25 19:48:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12892026/10/25 19:48:17 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12902026/10/25 19:48:17 INFO Signed narinfos id=1 count=312912026/10/25 19:48:17 INFO Uploading 3 narinfos12922026/10/25 19:48:17 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=012932026/10/25 19:48:18 WARN Failed to register uploaded object key=i27g9laxbn1nmc0877aignvdbqi00031.narinfo error="server returned 404: 404 page not found\n"12942026/10/25 19:48:18 WARN Failed to register uploaded object key=1jsffsx54qv277r3khvljdq5bf33j19b.narinfo error="server returned 404: 404 page not found\n"12952026/10/25 19:48:18 INFO Received complete push request method=POST path=/api/pushes/1/complete12962026/10/25 19:48:18 WARN Failed to register uploaded object key=4pd3wg1s1raylb7n7a8gxp7l56g0z9b6.narinfo error="server returned 404: 404 page not found\n"12972026/10/25 19:48:18 INFO Vacuumed table table=pending_closures12982026/10/25 19:48:18 INFO Completed push id=1 objects=8 duration=23.017ms12992026/10/25 19:48:18 INFO Vacuumed table table=pending_objects13002026/10/25 19:48:18 INFO Upload complete. (501ms)13012026/10/25 19:48:18 INFO Vacuumed table table=multipart_uploads13022026/10/25 19:48:18 INFO Vacuumed table table=closures1303=== NAME TestClientPushesUseOnePush1304 client_pushes_test.go:97: Retrieved narinfo from S3:1305 StorePath: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientPushesUseOnePush1689273873/001/store/4pd3wg1s1raylb7n7a8gxp7l56g0z9b6-shared-dep1306 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1307 Compression: zstd1308 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821309 NarSize: 1361310 References: 1311 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13122026/10/25 19:48:18 INFO Vacuumed table table=objects1313 client_pushes_test.go:97: Retrieved narinfo from S3:1314 StorePath: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientPushesUseOnePush1689273873/001/store/1jsffsx54qv277r3khvljdq5bf33j19b-a1315 URL: nar/1mj8ll2zpg1fvwn700wb7arqg58gblp209cbk5i202dkh84cp028.nar.zst1316 Compression: zstd1317 NarHash: sha256:1mj8ll2zpg1fvwn700wb7arqg58gblp209cbk5i202dkh84cp0281318 NarSize: 2561319 References: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientPushesUseOnePush1689273873/001/store/4pd3wg1s1raylb7n7a8gxp7l56g0z9b6-shared-dep1320 CA: text:sha256:1h8m59nsab8hmhlzp73a2wam6xlqb1gh5pna2wk98jn98f2mwg321321 client_pushes_test.go:97: Retrieved narinfo from S3:1322 StorePath: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientPushesUseOnePush1689273873/001/store/i27g9laxbn1nmc0877aignvdbqi00031-b1323 URL: nar/1mj8ll2zpg1fvwn700wb7arqg58gblp209cbk5i202dkh84cp028.nar.zst1324 Compression: zstd1325 NarHash: sha256:1mj8ll2zpg1fvwn700wb7arqg58gblp209cbk5i202dkh84cp0281326 NarSize: 2561327 References: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientPushesUseOnePush1689273873/001/store/4pd3wg1s1raylb7n7a8gxp7l56g0z9b6-shared-dep1328 CA: text:sha256:1h8m59nsab8hmhlzp73a2wam6xlqb1gh5pna2wk98jn98f2mwg3213292026/10/25 19:48:18 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13302026/10/25 19:48:18 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1331--- PASS: TestClientPushesUseOnePush (10.34s)1332=== CONT TestReadProxyRangeRequest1333--- PASS: TestService_NativeMTLS (7.76s)1334=== CONT TestPush_OverlappingRootsStoreOneRowPerKey13352026/10/25 19:48:18 INFO Received push request method=POST path=/api/pushes13362026/10/25 19:48:18 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)13372026/10/25 19:48:18 INFO Uploading jy77vwy4l8v1y7zx6n6zg5ip5lbvnjsf-shared-dep (136B)13382026/10/25 19:48:18 INFO Uploading z968q3hw9bfars9wjs8kpalz9kvgfmy0-top (264B)13392026/10/25 19:48:18 WARN Failed to register uploaded object key=z968q3hw9bfars9wjs8kpalz9kvgfmy0.ls error="server returned 404: 404 page not found\n"13402026/10/25 19:48:18 WARN Failed to register uploaded object key=jy77vwy4l8v1y7zx6n6zg5ip5lbvnjsf.ls error="server returned 404: 404 page not found\n"13412026/10/25 19:48:18 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13422026/10/25 19:48:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13432026/10/25 19:48:18 WARN Failed to register uploaded object key=nar/0898sa9jq2lar660h78wxsn6i1xjkdm228dq5yh5x1hl6n3qknhn.nar.zst error="server returned 404: 404 page not found\n"13442026/10/25 19:48:18 INFO Signed narinfos id=1 count=213452026/10/25 19:48:18 INFO Uploading 2 narinfos13462026/10/25 19:48:18 WARN Failed to register uploaded object key=z968q3hw9bfars9wjs8kpalz9kvgfmy0.narinfo error="server returned 404: 404 page not found\n"13472026/10/25 19:48:18 INFO Received complete push request method=POST path=/api/pushes/1/complete13482026/10/25 19:48:18 WARN Failed to register uploaded object key=jy77vwy4l8v1y7zx6n6zg5ip5lbvnjsf.narinfo error="server returned 404: 404 page not found\n"13492026/10/25 19:48:18 INFO Completed push id=1 objects=6 duration=39.62025ms13502026/10/25 19:48:18 INFO Upload complete. (377ms)1351=== NAME TestClientSharedPathCommittedMidPush1352 client_integration_test.go:803: Retrieved narinfo from S3:1353 StorePath: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientSharedPathCommittedMidPush546067196/001/store/jy77vwy4l8v1y7zx6n6zg5ip5lbvnjsf-shared-dep1354 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1355 Compression: zstd1356 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821357 NarSize: 1361358 References: 1359 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1360 client_integration_test.go:803: Retrieved narinfo from S3:1361 StorePath: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientSharedPathCommittedMidPush546067196/001/store/z968q3hw9bfars9wjs8kpalz9kvgfmy0-top1362 URL: nar/0898sa9jq2lar660h78wxsn6i1xjkdm228dq5yh5x1hl6n3qknhn.nar.zst1363 Compression: zstd1364 NarHash: sha256:0898sa9jq2lar660h78wxsn6i1xjkdm228dq5yh5x1hl6n3qknhn1365 NarSize: 2641366 References: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientSharedPathCommittedMidPush546067196/001/store/jy77vwy4l8v1y7zx6n6zg5ip5lbvnjsf-shared-dep1367 CA: text:sha256:11ih8rxlsxav5p9zf4lngs3q10mxsvbqhknggbddikjbgp90lk5q1368--- PASS: TestClientSharedPathCommittedMidPush (9.26s)1369=== CONT TestReadRedirectKeepsNarinfoProxied1370=== NAME TestClientMultipleUploads1371 client_integration_test.go:467: Created store path 0: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientMultipleUploads2496232644/001/store/qyslpc2qpyfh9hm29b41gh4xn17cjd1r-test-file-0.txt13722026/10/25 19:48:18 INFO Received uploads request method=POST path=/api/pending_closures1373 client_integration_test.go:467: Created store path 1: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientMultipleUploads2496232644/001/store/jgi171jvv1y4i0z3fi6xbj5sdy64fxjy-test-file-1.txt13742026/10/25 19:48:18 INFO Aborted multipart uploads count=0 kept=013752026/10/25 19:48:18 WARN Force mode enabled - objects will be deleted immediately without grace period13762026/10/25 19:48:19 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013772026/10/25 19:48:19 INFO Vacuumed table table=pending_closures1378 client_integration_test.go:467: Created store path 2: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientMultipleUploads2496232644/001/store/g2rf0cw00l6f3sazcmmy6wxvj322khb6-test-file-2.txt13792026/10/25 19:48:19 INFO Vacuumed table table=pending_objects13802026/10/25 19:48:19 INFO Vacuumed table table=multipart_uploads13812026/10/25 19:48:19 INFO Vacuumed table table=closures13822026/10/25 19:48:19 INFO Vacuumed table table=objects1383--- PASS: TestGCSweepSkipsPendingObjects (8.24s)1384=== CONT TestReadProxyDisabled13852026/10/25 19:48:19 INFO Received push request method=POST path=/api/pushes13862026/10/25 19:48:19 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)13872026/10/25 19:48:19 INFO Uploading qyslpc2qpyfh9hm29b41gh4xn17cjd1r-test-file-0.txt (160B)13882026/10/25 19:48:19 INFO Uploading g2rf0cw00l6f3sazcmmy6wxvj322khb6-test-file-2.txt (160B)13892026/10/25 19:48:19 INFO Uploading jgi171jvv1y4i0z3fi6xbj5sdy64fxjy-test-file-1.txt (160B)13902026/10/25 19:48:19 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"13912026/10/25 19:48:19 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=013922026/10/25 19:48:19 WARN Failed to register uploaded object key=jgi171jvv1y4i0z3fi6xbj5sdy64fxjy.ls error="server returned 404: 404 page not found\n"13932026/10/25 19:48:19 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"13942026/10/25 19:48:19 WARN Failed to register uploaded object key=qyslpc2qpyfh9hm29b41gh4xn17cjd1r.ls error="server returned 404: 404 page not found\n"13952026/10/25 19:48:19 WARN Failed to register uploaded object key=g2rf0cw00l6f3sazcmmy6wxvj322khb6.ls error="server returned 404: 404 page not found\n"13962026/10/25 19:48:19 INFO Received create pin request method=POST path=/api/pins/myapp13972026/10/25 19:48:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13982026/10/25 19:48:19 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"1399=== NAME TestClientIntegration1400 client_integration_test.go:331: Created store path: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientIntegration1771595225/002/store/pnawchik428w9lssawcb2rb80aq2jspz-test-file.txt14012026/10/25 19:48:19 INFO Signed narinfos id=1 count=314022026/10/25 19:48:19 INFO Uploading 3 narinfos14032026/10/25 19:48:19 WARN Failed to register uploaded object key=g2rf0cw00l6f3sazcmmy6wxvj322khb6.narinfo error="server returned 404: 404 page not found\n"14042026/10/25 19:48:19 WARN Failed to register uploaded object key=qyslpc2qpyfh9hm29b41gh4xn17cjd1r.narinfo error="server returned 404: 404 page not found\n"14052026/10/25 19:48:19 INFO Created/updated pin name=myapp store_path=/private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestPinProtectsFromGC3230503292/001/store/g5ssqvw3hmg65mks88qwrqy1frhlh7qs-pinned-file.txt narinfo_key=g5ssqvw3hmg65mks88qwrqy1frhlh7qs.narinfo14062026/10/25 19:48:19 INFO Received complete push request method=POST path=/api/pushes/1/complete14072026/10/25 19:48:19 WARN Failed to register uploaded object key=jgi171jvv1y4i0z3fi6xbj5sdy64fxjy.narinfo error="server returned 404: 404 page not found\n"14082026/10/25 19:48:19 INFO Starting cleanup of old closures method=DELETE path=/api/closures14092026/10/25 19:48:19 INFO Garbage collection started14102026/10/25 19:48:19 INFO Aborted multipart uploads count=0 kept=014112026/10/25 19:48:19 INFO Completed push id=1 objects=9 duration=34.862667ms14122026/10/25 19:48:19 INFO Upload complete. (480ms)1413=== NAME TestClientMultipleUploads1414 client_integration_test.go:478: Uploaded 3 paths in 530.950875ms14152026/10/25 19:48:19 WARN Force mode enabled - objects will be deleted immediately without grace period14162026/10/25 19:48:19 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=014172026/10/25 19:48:19 INFO Vacuumed table table=pending_closures14182026/10/25 19:48:19 INFO Vacuumed table table=pending_objects14192026/10/25 19:48:19 INFO Vacuumed table table=multipart_uploads14202026/10/25 19:48:19 INFO Vacuumed table table=closures14212026/10/25 19:48:19 INFO Vacuumed table table=objects1422--- PASS: TestMetricsInventory (8.50s)1423=== CONT TestReadProxyRootRedirectsToIndexHTML14242026/10/25 19:48:19 INFO Received push request method=POST path=/api/pushes14252026/10/25 19:48:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14262026/10/25 19:48:19 INFO Uploading pnawchik428w9lssawcb2rb80aq2jspz-test-file.txt (152B)1427--- PASS: TestClientMultipleUploads (10.03s)1428=== CONT TestReadRedirectNar14292026/10/25 19:48:19 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"14302026/10/25 19:48:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14312026/10/25 19:48:19 INFO Signed narinfos id=1 count=114322026/10/25 19:48:19 INFO Uploading 1 narinfos14332026/10/25 19:48:19 WARN Failed to register uploaded object key=pnawchik428w9lssawcb2rb80aq2jspz.ls error="server returned 404: 404 page not found\n"14342026/10/25 19:48:20 INFO Received complete push request method=POST path=/api/pushes/1/complete14352026/10/25 19:48:20 WARN Failed to register uploaded object key=pnawchik428w9lssawcb2rb80aq2jspz.narinfo error="server returned 404: 404 page not found\n"14362026/10/25 19:48:20 INFO Completed push id=1 objects=3 duration=14.622833ms14372026/10/25 19:48:20 INFO Upload complete. (507ms)14382026/10/25 19:48:20 INFO All 1 paths already cached1439=== NAME TestClientIntegration1440 client_integration_test.go:357: Retrieved narinfo from S3:1441 StorePath: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientIntegration1771595225/002/store/pnawchik428w9lssawcb2rb80aq2jspz-test-file.txt1442 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1443 Compression: zstd1444 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11445 NarSize: 1521446 References: 1447 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11448 client_integration_test.go:358: Retrieved .ls file from S3 (compressed size: 77 bytes)1449 client_integration_test.go:358: Decompressed .ls content (64 bytes):1450 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}14512026/10/25 19:48:20 INFO Aborted multipart uploads count=0 kept=014522026/10/25 19:48:20 WARN Force mode enabled - objects will be deleted immediately without grace period14532026/10/25 19:48:20 INFO Received uploads request method=POST path=/api/pending_closures1454--- PASS: TestDeduplicatedObjectsRecordedAsPending (8.44s)1455=== CONT TestReadProxyConditionalGet14562026/10/25 19:48:20 INFO Received push request method=POST path=/api/pushes14572026/10/25 19:48:20 INFO Object in database but missing from S3 key=pnawchik428w9lssawcb2rb80aq2jspz.ls14582026/10/25 19:48:20 WARN Found objects in DB but missing from S3, will re-upload count=114592026/10/25 19:48:20 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14602026/10/25 19:48:20 INFO Received complete push request method=POST path=/api/pushes/2/complete14612026/10/25 19:48:20 WARN Failed to register uploaded object key=pnawchik428w9lssawcb2rb80aq2jspz.ls error="server returned 404: 404 page not found\n"14622026/10/25 19:48:20 INFO Completed push id=2 objects=3 duration=1.006542ms14632026/10/25 19:48:20 INFO Upload complete. (183ms)1464=== NAME TestClientIntegration14652026/10/25 19:48:20 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=01466 client_integration_test.go:375: Retrieved .ls file from S3 (compressed size: 62 bytes)1467 client_integration_test.go:375: Decompressed .ls content (49 bytes):14682026/10/25 19:48:20 INFO Vacuumed table table=pending_closures1469 {"version":1,"root":{"type":"regular","size":39}}14702026/10/25 19:48:20 INFO Vacuumed table table=pending_objects14712026/10/25 19:48:20 INFO Vacuumed table table=multipart_uploads14722026/10/25 19:48:20 INFO Vacuumed table table=closures14732026/10/25 19:48:20 INFO Vacuumed table table=objects1474--- PASS: TestGCSweepDeliversEachKeyOnce (10.60s)1475=== CONT TestReadProxyHead14762026/10/25 19:48:20 INFO Received push request method=POST path=/api/pushes14772026/10/25 19:48:21 INFO Received push request method=POST path=/api/pushes14782026/10/25 19:48:21 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14792026/10/25 19:48:21 INFO Received complete push request method=POST path=/api/pushes/3/complete14802026/10/25 19:48:21 WARN Failed to register uploaded object key=pnawchik428w9lssawcb2rb80aq2jspz.ls error="server returned 404: 404 page not found\n"14812026/10/25 19:48:21 INFO Completed push id=3 objects=3 duration=1.272542ms14822026/10/25 19:48:21 INFO Received uploads request method=POST path=/api/pending_closures14832026/10/25 19:48:21 INFO Upload complete. (136ms)1484=== NAME TestClientIntegration1485 client_integration_test.go:392: Retrieved .ls file from S3 (compressed size: 62 bytes)1486 client_integration_test.go:392: Decompressed .ls content (49 bytes):1487 {"version":1,"root":{"type":"regular","size":39}}14882026/10/25 19:48:21 INFO Received uploads request method=POST path=/api/pending_closures14892026/10/25 19:48:21 INFO Received uploads request method=POST path=/api/pending_closures14902026/10/25 19:48:21 INFO Received uploads request method=POST path=/api/pending_closures1491=== NAME TestPinProtectsFromGC1492 client_integration_test.go:963: Pin successfully protected closure from garbage collection14932026/10/25 19:48:21 INFO Received push request method=POST path=/api/pushes14942026/10/25 19:48:21 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14952026/10/25 19:48:21 INFO Uploading kk5yxja57pn3l7h1sk2xi05f98s5yqcm-lost-commit.txt (152B)1496--- PASS: TestPinProtectsFromGC (14.96s)1497=== CONT TestReadProxyNarinfoAlreadyDecompressed14982026/10/25 19:48:21 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign14992026/10/25 19:48:21 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"15002026/10/25 19:48:21 WARN Failed to register uploaded object key=kk5yxja57pn3l7h1sk2xi05f98s5yqcm.ls error="server returned 404: 404 page not found\n"15012026/10/25 19:48:21 INFO Signed narinfos id=4 count=115022026/10/25 19:48:21 INFO Uploading 1 narinfos15032026/10/25 19:48:21 INFO Received complete push request method=POST path=/api/pushes/4/complete15042026/10/25 19:48:21 WARN Failed to register uploaded object key=kk5yxja57pn3l7h1sk2xi05f98s5yqcm.narinfo error="server returned 404: 404 page not found\n"15052026/10/25 19:48:21 INFO Completed push id=4 objects=3 duration=6.137791ms15062026/10/25 19:48:21 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:59157/api/pushes/4/complete\": EOF" url=http://127.0.0.1:59157/api/pushes/4/complete15072026/10/25 19:48:22 INFO Received complete push request method=POST path=/api/pushes/4/complete15082026-10-25 19:48:22.042 UTC [64920] ERROR: Push does not exist: id=415092026-10-25 19:48:22.042 UTC [64920] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE15102026-10-25 19:48:22.042 UTC [64920] STATEMENT: -- name: CommitPush :one1511 SELECT commit_push($1::bigint)::bigint1512 15132026/10/25 19:48:22 WARN Push not found id=415142026/10/25 19:48:22 INFO Upload complete. (616ms)1515=== NAME TestClientIntegration1516 client_integration_test.go:422: Retrieved narinfo from S3:1517 StorePath: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientIntegration1771595225/002/store/kk5yxja57pn3l7h1sk2xi05f98s5yqcm-lost-commit.txt1518 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1519 Compression: zstd1520 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1521 NarSize: 1521522 References: 1523 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1524 client_integration_test.go:425: Testing garbage collection...15252026/10/25 19:48:22 INFO Starting cleanup of old closures method=DELETE path=/api/closures15262026/10/25 19:48:22 INFO Garbage collection started15272026/10/25 19:48:22 INFO Aborted multipart uploads count=0 kept=015282026/10/25 19:48:22 WARN Force mode enabled - objects will be deleted immediately without grace period1529=== NAME TestClientWithDependencies1530 client_integration_test.go:722: Built derivation: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientWithDependencies2259809904/001/store/2msyjrvj1caaw86a73kvy73p9nyrm94g-test-script1531=== NAME TestNARDeduplicationMetadataUploadBug1532 metadata_upload_test.go:48: First store path: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestNARDeduplicationMetadataUploadBug1373149045/001/store/9s35qdpcsmpdvqvyb3j5xf885n8yjjgp-file1.txt15332026/10/25 19:48:23 INFO Received uploads request method=POST path=/api/pending_closures1534=== NAME TestClientWithDependencies1535 client_integration_test.go:724: Found 1 dependencies (including self)1536--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (8.57s)1537=== CONT TestReadProxy40415382026/10/25 19:48:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15392026/10/25 19:48:23 INFO Received push request method=POST path=/api/pushes15402026/10/25 19:48:23 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15412026/10/25 19:48:23 INFO Uploading 9s35qdpcsmpdvqvyb3j5xf885n8yjjgp-file1.txt (160B)15422026/10/25 19:48:23 INFO Aborted multipart uploads count=1 kept=015432026/10/25 19:48:23 INFO Received cleanup request method=DELETE path=/api/pending_closures15442026/10/25 19:48:23 WARN Failed to register uploaded object key=9s35qdpcsmpdvqvyb3j5xf885n8yjjgp.ls error="server returned 404: 404 page not found\n"15452026/10/25 19:48:23 INFO Aborted multipart uploads count=1 kept=015462026/10/25 19:48:23 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"15472026/10/25 19:48:23 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15482026/10/25 19:48:23 INFO Signed narinfos id=1 count=115492026/10/25 19:48:23 INFO Uploading 1 narinfos15502026/10/25 19:48:23 INFO Received cleanup request method=DELETE path=/api/pending_closures15512026/10/25 19:48:23 INFO Aborted multipart uploads count=0 kept=015522026/10/25 19:48:23 INFO Received uploads request method=POST path=/api/pending_closures15532026/10/25 19:48:23 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=015542026/10/25 19:48:23 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLjdiMmQyZTMxLTk0NTYtNDkzMy1hNDU0LTY0ZjVlZTk5NjI3MngxNzkyOTU3NzAwODc4NDk3MDAw parts=1015552026/10/25 19:48:23 INFO Received push request method=POST path=/api/pushes15562026/10/25 19:48:23 INFO Received complete push request method=POST path=/api/pushes/1/complete15572026/10/25 19:48:23 WARN Failed to register uploaded object key=9s35qdpcsmpdvqvyb3j5xf885n8yjjgp.narinfo error="server returned 404: 404 page not found\n"15582026/10/25 19:48:23 INFO Vacuumed table table=pending_closures15592026/10/25 19:48:23 INFO Completed push id=1 objects=3 duration=21.102208ms1560--- PASS: TestPendingCleanupUsesOneCutoff (14.76s)15612026/10/25 19:48:23 INFO Vacuumed table table=pending_objects15622026/10/25 19:48:23 INFO Upload complete. (842ms)1563=== CONT TestReadProxyOutlastsServerWriteTimeout1564=== NAME TestNARDeduplicationMetadataUploadBug1565 metadata_upload_test.go:54: Retrieved narinfo from S3:1566 StorePath: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestNARDeduplicationMetadataUploadBug1373149045/001/store/9s35qdpcsmpdvqvyb3j5xf885n8yjjgp-file1.txt1567 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1568 Compression: zstd1569 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1570 NarSize: 1601571 References: 1572 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf15732026/10/25 19:48:24 INFO Vacuumed table table=multipart_uploads15742026/10/25 19:48:24 INFO Vacuumed table table=closures15752026/10/25 19:48:24 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15762026/10/25 19:48:24 INFO Uploading 2msyjrvj1caaw86a73kvy73p9nyrm94g-test-script (136B)15772026/10/25 19:48:24 INFO Vacuumed table table=objects15782026/10/25 19:48:24 INFO Received cleanup request method=DELETE path=/api/pending_closures1579 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1580 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1581 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}15822026/10/25 19:48:24 INFO Aborted multipart uploads count=1 kept=015832026/10/25 19:48:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15842026-10-25 19:48:24.166 UTC [65166] ERROR: Closure does not exist: id=115852026-10-25 19:48:24.166 UTC [65166] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE15862026-10-25 19:48:24.166 UTC [65166] STATEMENT: -- name: CommitPendingClosure :one1587 SELECT commit_pending_closure($1::bigint)::bigint1588 15892026/10/25 19:48:24 WARN Failed to register uploaded object key=2msyjrvj1caaw86a73kvy73p9nyrm94g.ls error="server returned 404: 404 page not found\n"15902026/10/25 19:48:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15912026/10/25 19:48:24 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15922026/10/25 19:48:24 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"15932026/10/25 19:48:24 INFO Signed narinfos id=1 count=115942026/10/25 19:48:24 WARN Failed to register uploaded object key=log/76zy7kmiirw9ww0z4dyblnn5cf8isf7c-test-script.drv error="server returned 404: 404 page not found\n"15952026/10/25 19:48:24 INFO Uploading 1 narinfos1596 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestNARDeduplicationMetadataUploadBug1373149045/001/store/gfvsz81y6ghy9zbs5k84dngkix1dy7j3-file2.txt15972026/10/25 19:48:24 INFO Received complete push request method=POST path=/api/pushes/1/complete15982026/10/25 19:48:24 WARN Failed to register uploaded object key=2msyjrvj1caaw86a73kvy73p9nyrm94g.narinfo error="server returned 404: 404 page not found\n"1599--- PASS: TestService_cleanupPendingClosuresHandler (9.27s)1600=== CONT TestReadProxyContentNegotiation16012026/10/25 19:48:24 INFO Completed push id=1 objects=4 duration=62.828125ms16022026/10/25 19:48:24 INFO Upload complete. (990ms)16032026/10/25 19:48:24 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=01604=== NAME TestClientIntegration1605 client_integration_test.go:432: Objects in database after GC:1606 client_integration_test.go:432: Successfully deleted all objects with GC --force16072026/10/25 19:48:24 INFO Aborted multipart uploads count=0 kept=016082026/10/25 19:48:24 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLjMyOGUxNDhiLWI2OTItNDk0YS05ZmVlLTliYmUxNTkwN2NjMXgxNzkyOTU3NzAxMjE4OTg2MDAw parts=1016092026/10/25 19:48:24 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16102026/10/25 19:48:24 INFO Completed upload id=1 objects=2 duration=36.213458ms16112026/10/25 19:48:24 WARN Force mode enabled - objects will be deleted immediately without grace period1612=== NAME TestOrphanedObjectsGCStressTest1613 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains16142026/10/25 19:48:24 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=01615--- PASS: TestClientIntegration (12.84s)1616=== CONT TestReadProxyNarStreaming16172026/10/25 19:48:24 INFO Vacuumed table table=pending_closures16182026/10/25 19:48:24 INFO Vacuumed table table=pending_objects16192026/10/25 19:48:24 INFO Vacuumed table table=multipart_uploads16202026/10/25 19:48:24 INFO Vacuumed table table=closures1621=== NAME TestOrphanedObjectsGCStressTest1622 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion16232026/10/25 19:48:24 INFO Vacuumed table table=objects1624=== NAME TestClientWithDependencies1625 client_integration_test.go:740: Skipping nix copy test - isolated store (/private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientWithDependencies2259809904/001/store) requires matching store prefix16262026/10/25 19:48:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16272026/10/25 19:48:25 INFO Received push request method=POST path=/api/pushes16282026/10/25 19:48:25 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16292026/10/25 19:48:25 INFO Received uploads request method=POST path=/api/pending_closures1630--- PASS: TestClientWithDependencies (10.76s)1631=== CONT TestReadProxyNarinfo16322026/10/25 19:48:25 WARN Failed to register uploaded object key=gfvsz81y6ghy9zbs5k84dngkix1dy7j3.ls error="server returned 404: 404 page not found\n"16332026/10/25 19:48:25 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16342026/10/25 19:48:25 INFO Signed narinfos id=2 count=116352026/10/25 19:48:25 INFO Uploading 1 narinfos16362026/10/25 19:48:25 INFO Received uploads request method=POST path=/api/pending_closures16372026/10/25 19:48:25 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo16382026/10/25 19:48:25 WARN Found objects in DB but missing from S3, will re-upload count=116392026/10/25 19:48:25 INFO Received complete push request method=POST path=/api/pushes/2/complete16402026/10/25 19:48:25 WARN Failed to register uploaded object key=gfvsz81y6ghy9zbs5k84dngkix1dy7j3.narinfo error="server returned 404: 404 page not found\n"16412026/10/25 19:48:25 INFO Completed push id=2 objects=3 duration=2.165792ms16422026/10/25 19:48:25 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLjQ5MjY0M2NjLTAyMjMtNDVmNC05YzJkLTE1NmIxNTEwYjJjZXgxNzkyOTU3NzAxNjIyNzI1MDAw parts=1016432026/10/25 19:48:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16442026/10/25 19:48:25 INFO Upload complete. (854ms)1645=== NAME TestNARDeduplicationMetadataUploadBug1646 metadata_upload_test.go:76: Retrieved narinfo from S3:1647 StorePath: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestNARDeduplicationMetadataUploadBug1373149045/001/store/gfvsz81y6ghy9zbs5k84dngkix1dy7j3-file2.txt1648 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1649 Compression: zstd1650 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1651 NarSize: 1601652 References: 1653 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf16542026/10/25 19:48:25 INFO Completed upload id=1 objects=2 duration=14.193709ms1655 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1656 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1657 {"version":1,"root":{"type":"regular","size":44}}16582026/10/25 19:48:25 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001659--- PASS: TestReadProxyInvalidPath (9.51s)1660=== CONT TestPush_RootsAreLockedInByteOrder16612026/10/25 19:48:25 INFO Received uploads request method=POST path=/api/pending_closures16622026/10/25 19:48:25 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete16632026/10/25 19:48:25 INFO Completed upload id=3 objects=2 duration=8.303625ms16642026/10/25 19:48:25 INFO Starting cleanup of old closures method=DELETE path=/api/closures16652026/10/25 19:48:25 INFO Aborted multipart uploads count=0 kept=016662026/10/25 19:48:25 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=01667--- PASS: TestService_verifyS3Integrity (12.37s)1668=== CONT TestPush_RejectsBadRequests1669--- PASS: TestNARDeduplicationMetadataUploadBug (10.98s)1670=== CONT TestPresentRefreshesOnlyStaleClosures16712026/10/25 19:48:25 INFO Vacuumed table table=pending_closures16722026/10/25 19:48:25 INFO Vacuumed table table=pending_objects16732026/10/25 19:48:25 INFO Vacuumed table table=multipart_uploads16742026/10/25 19:48:25 INFO Vacuumed table table=closures16752026/10/25 19:48:25 INFO Vacuumed table table=objects16762026/10/25 19:48:25 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000016772026/10/25 19:48:25 INFO Received push request method=POST path=/api/pushes1678--- PASS: TestService_createPendingClosureHandler (12.55s)1679=== CONT TestParseSingleRange1680=== RUN TestParseSingleRange/none1681=== PAUSE TestParseSingleRange/none1682=== RUN TestParseSingleRange/unknown_unit1683=== PAUSE TestParseSingleRange/unknown_unit1684=== RUN TestParseSingleRange/multi-range_ignored1685=== PAUSE TestParseSingleRange/multi-range_ignored1686=== RUN TestParseSingleRange/malformed_no_dash1687=== PAUSE TestParseSingleRange/malformed_no_dash1688=== RUN TestParseSingleRange/malformed_both_empty1689=== PAUSE TestParseSingleRange/malformed_both_empty1690=== RUN TestParseSingleRange/malformed_end_before_start1691=== PAUSE TestParseSingleRange/malformed_end_before_start1692=== RUN TestParseSingleRange/closed1693=== PAUSE TestParseSingleRange/closed1694=== RUN TestParseSingleRange/open-ended1695=== PAUSE TestParseSingleRange/open-ended1696=== RUN TestParseSingleRange/end_clamped_to_size1697=== PAUSE TestParseSingleRange/end_clamped_to_size1698=== RUN TestParseSingleRange/suffix1699=== PAUSE TestParseSingleRange/suffix1700=== RUN TestParseSingleRange/suffix_exceeds_size1701=== PAUSE TestParseSingleRange/suffix_exceeds_size1702=== RUN TestParseSingleRange/single_byte1703=== PAUSE TestParseSingleRange/single_byte1704=== RUN TestParseSingleRange/start_past_EOF1705=== PAUSE TestParseSingleRange/start_past_EOF1706=== RUN TestParseSingleRange/start_far_past_EOF1707=== PAUSE TestParseSingleRange/start_far_past_EOF1708=== CONT TestPresentNotReportedWhileGCDeletesClosure1709=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1710=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1711=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1712=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1713=== CONT TestProxyWriteTimeout1714=== RUN TestProxyWriteTimeout/narinfo1715=== PAUSE TestProxyWriteTimeout/narinfo1716=== RUN TestProxyWriteTimeout/1_GiB_nar1717=== PAUSE TestProxyWriteTimeout/1_GiB_nar1718=== RUN TestProxyWriteTimeout/10_GiB_nar1719=== PAUSE TestProxyWriteTimeout/10_GiB_nar1720=== RUN TestProxyWriteTimeout/unknown_size1721=== PAUSE TestProxyWriteTimeout/unknown_size1722=== CONT TestUploadHandlersRejectInvalidKeys1723=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1724=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1725=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1726=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1727=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1728=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1729=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1730=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1731=== CONT TestPendingClosureWriteTimeout1732=== RUN TestPendingClosureWriteTimeout/empty1733=== PAUSE TestPendingClosureWriteTimeout/empty1734=== RUN TestPendingClosureWriteTimeout/400_objects1735=== PAUSE TestPendingClosureWriteTimeout/400_objects1736=== RUN TestPendingClosureWriteTimeout/670k_objects1737=== PAUSE TestPendingClosureWriteTimeout/670k_objects1738=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1739=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1740=== CONT TestPush_CompleteWaitsForCleanupOfThePush17412026/10/25 19:48:26 INFO Received push request method=POST path=/api/pushes1742=== NAME TestClientCADerivations1743 client_ca_test.go:136: Built CA derivation: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientCADerivations685046517/001/store/4lr483kl4nk4bwgd3sk437gywm30iccs-ca-test1744 client_ca_test.go:139: Found 1 dependencies (including self)17452026/10/25 19:48:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17462026/10/25 19:48:27 INFO Received push request method=POST path=/api/pushes17472026/10/25 19:48:27 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLjA4ZDBlZjEzLWRkMDUtNGU3Ny04YjQ1LTdkZmIwMjc0ZDU5N3gxNzkyOTU3NzAwODc5MTQ2MDAw parts=1017482026/10/25 19:48:27 INFO Received complete push request method=POST path=/api/pushes/1/complete17492026/10/25 19:48:27 INFO Completed push id=1 objects=4 duration=8.063958ms1750--- PASS: TestReadRedirectUsesPublicS3URL (10.25s)1751=== CONT TestIsValidCachePath1752=== RUN TestIsValidCachePath/narinfo1753=== PAUSE TestIsValidCachePath/narinfo1754=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1755=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1756=== RUN TestIsValidCachePath/nar_zst1757=== PAUSE TestIsValidCachePath/nar_zst1758=== RUN TestIsValidCachePath/nar_xz1759=== PAUSE TestIsValidCachePath/nar_xz1760=== RUN TestIsValidCachePath/nar_bz21761=== PAUSE TestIsValidCachePath/nar_bz21762=== RUN TestIsValidCachePath/nar_uncompressed1763=== PAUSE TestIsValidCachePath/nar_uncompressed1764=== RUN TestIsValidCachePath/ls1765=== PAUSE TestIsValidCachePath/ls1766=== RUN TestIsValidCachePath/log1767=== PAUSE TestIsValidCachePath/log1768=== RUN TestIsValidCachePath/realisation1769=== PAUSE TestIsValidCachePath/realisation1770=== RUN TestIsValidCachePath/nix-cache-info1771=== PAUSE TestIsValidCachePath/nix-cache-info1772=== RUN TestIsValidCachePath/index.html1773=== PAUSE TestIsValidCachePath/index.html1774=== RUN TestIsValidCachePath/traversal_parent1775=== PAUSE TestIsValidCachePath/traversal_parent1776=== RUN TestIsValidCachePath/traversal_in_middle1777=== PAUSE TestIsValidCachePath/traversal_in_middle1778=== RUN TestIsValidCachePath/invalid_char_e1779=== PAUSE TestIsValidCachePath/invalid_char_e1780=== RUN TestIsValidCachePath/invalid_char_u1781=== PAUSE TestIsValidCachePath/invalid_char_u1782=== RUN TestIsValidCachePath/random_path1783=== PAUSE TestIsValidCachePath/random_path1784=== RUN TestIsValidCachePath/empty1785=== PAUSE TestIsValidCachePath/empty1786=== RUN TestIsValidCachePath/leading_slash1787=== PAUSE TestIsValidCachePath/leading_slash1788=== RUN TestIsValidCachePath/wrong_extension1789=== PAUSE TestIsValidCachePath/wrong_extension1790=== RUN TestIsValidCachePath/short_hash1791=== PAUSE TestIsValidCachePath/short_hash1792=== CONT TestPresentReportsOnlyClosureRoots17932026/10/25 19:48:27 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17942026/10/25 19:48:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17952026/10/25 19:48:27 INFO Uploading 4lr483kl4nk4bwgd3sk437gywm30iccs-ca-test (144B)17962026/10/25 19:48:27 INFO Completed upload id=2 objects=2 duration=8.568375ms17972026/10/25 19:48:27 WARN Failed to register uploaded object key=4lr483kl4nk4bwgd3sk437gywm30iccs.ls error="server returned 404: 404 page not found\n"17982026/10/25 19:48:27 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"1799--- PASS: TestMetricsCommit (15.00s)1800=== CONT TestService_readinessHandler18012026/10/25 19:48:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18022026/10/25 19:48:27 WARN Failed to register uploaded object key=log/s61ikn9sas8rmj4kh1xr6yr8x3vziljf-ca-test.drv error="server returned 404: 404 page not found\n"18032026/10/25 19:48:27 INFO Signed narinfos id=1 count=118042026/10/25 19:48:27 INFO Uploading 1 narinfos18052026/10/25 19:48:27 INFO Received complete push request method=POST path=/api/pushes/1/complete18062026/10/25 19:48:27 WARN Failed to register uploaded object key=4lr483kl4nk4bwgd3sk437gywm30iccs.narinfo error="server returned 404: 404 page not found\n"18072026/10/25 19:48:27 INFO Completed push id=1 objects=4 duration=34.555792ms18082026/10/25 19:48:27 INFO Upload complete. (725ms)1809=== NAME TestClientCADerivations1810 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientCADerivations685046517/001/store/4lr483kl4nk4bwgd3sk437gywm30iccs-ca-test1811 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1812 Compression: zstd1813 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1814 NarSize: 1441815 References: 1816 Deriver: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientCADerivations685046517/001/store/s61ikn9sas8rmj4kh1xr6yr8x3vziljf-ca-test.drv1817 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1818 client_ca_test.go:185: Checking for realisation files in S3...1819 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1820 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1821--- PASS: TestReadProxyRangeRequest (9.43s)1822=== CONT TestGCMetrics1823=== NAME TestClientCADerivations1824 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket54?endpoint=http://localhost:58878®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestClientCADerivations685046517/001/store'1825 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 118262026/10/25 19:48:27 INFO Received push request method=POST path=/api/pushes1827--- PASS: TestClientCADerivations (12.79s)1828=== CONT TestService_healthCheckHandler1829--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (9.82s)1830=== CONT TestPushDedupSurvivesConcurrentGC1831--- PASS: TestReadRedirectKeepsNarinfoProxied (9.79s)1832=== CONT TestGCAdvisoryLockBlocksConcurrentRun18332026/10/25 19:48:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18342026/10/25 19:48:28 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLjNiMTJmZTc1LWM4NWEtNGY1ZC1iNDIxLWUzN2U5MzJlYWIzNXgxNzkyOTU3NzA1ODY3MDQ4MDAw parts=101835--- PASS: TestReadProxyDisabled (9.67s)1836=== CONT TestLeadEndsOnShutdown18372026/10/25 19:48:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18382026/10/25 19:48:29 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLmExNzNjMDIwLTAzMTctNDI3Zi05NTk1LWNlOTgzM2Y0MmNkZngxNzkyOTU3NzA2NDQyMzMxMDAw parts=101839--- PASS: TestReadProxyRootRedirectsToIndexHTML (9.51s)1840=== CONT TestGCBugBareHashReferences1841--- PASS: TestReadRedirectNar (9.73s)1842=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1843--- PASS: TestReadProxyHead (9.22s)1844=== CONT TestService_AuthMiddleware_OIDC18452026/10/25 19:48:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59397/oidc1846--- PASS: TestReadProxyConditionalGet (10.07s)1847=== CONT TestService_RequireScope_OIDC18482026/10/25 19:48:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18492026/10/25 19:48:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59407/oidc18502026/10/25 19:48:30 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLjYyOWU1ZDg2LWU2ZTQtNDI4Mi04MDUwLTY1ZGE3MjQwOTgzZHgxNzkyOTU3NzA1ODU1Mzk0MDAw parts=1018512026/10/25 19:48:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1852--- PASS: TestReadProxyNarinfoAlreadyDecompressed (9.43s)1853=== CONT TestCacheStatsHandler18542026/10/25 19:48:31 INFO Received complete push request method=POST path=/api/pushes/1/complete18552026/10/25 19:48:31 INFO Completed push id=1 objects=4 duration=17.1265ms18562026/10/25 19:48:31 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLjFiNjIzZWJlLWIzZTQtNGIwOC04ODcxLTIzMTk2ZDNmYWE4ZngxNzkyOTU3NzA2NDQ3MTg5MDAw parts=101857--- PASS: TestPush_RepeatedRootCommitsOnce (15.33s)1858=== CONT TestService_ReadScope_PublicByDefault18592026/10/25 19:48:32 WARN Rate limiter enabled after throttle name=s3-test rate=518602026/10/25 19:48:32 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."18612026/10/25 19:48:32 WARN Rate limiter backed off name=s3-test rate=518622026/10/25 19:48:32 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."1863--- PASS: TestReadProxy404 (9.47s)1864=== CONT TestService_ReadAuthMiddleware1865--- PASS: TestReadProxyNarStreaming (8.39s)1866=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1867--- PASS: TestReadProxyContentNegotiation (8.85s)1868=== CONT TestService_AuthMiddleware18692026/10/25 19:48:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18702026/10/25 19:48:33 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLmU5ZGUyZjIxLTg2ODAtNDI3ZS05Y2ExLTE0NWQyODNhNzNlM3gxNzkyOTU3NzA2Mzc4MzQ2MDAw parts=1018712026/10/25 19:48:33 INFO Received push request method=POST path=/api/pushes18722026/10/25 19:48:33 INFO Received complete push request method=POST path=/api/pushes/1/complete18732026/10/25 19:48:33 INFO Completed push id=1 objects=6 duration=59.414625ms18742026/10/25 19:48:33 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1875--- PASS: TestPush_CompleteCommitsEveryRoot (17.63s)1876--- PASS: TestReadProxyNarinfo (8.82s)1877=== CONT TestSweepRechecksPendingAfterLocking1878=== CONT TestPush_SignsNarinfosOfItsPendingObjects1879--- PASS: TestPresentRefreshesOnlyStaleClosures (8.83s)1880=== CONT TestDeleteClosuresRacingPins1881=== RUN TestPush_RejectsBadRequests/no_roots1882=== PAUSE TestPush_RejectsBadRequests/no_roots1883=== RUN TestPush_RejectsBadRequests/no_objects1884=== PAUSE TestPush_RejectsBadRequests/no_objects1885=== RUN TestPush_RejectsBadRequests/bad_root1886=== PAUSE TestPush_RejectsBadRequests/bad_root1887=== RUN TestPush_RejectsBadRequests/root_not_in_objects1888=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1889=== CONT TestGCTaskStore_PhaseUpdates1890--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1891=== CONT TestCacheConfigHandler1892=== RUN TestCacheConfigHandler/full_config,_no_issuer1893=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1894=== RUN TestCacheConfigHandler/no_cache_url_configured1895=== PAUSE TestCacheConfigHandler/no_cache_url_configured1896=== RUN TestCacheConfigHandler/no_signing_keys1897=== PAUSE TestCacheConfigHandler/no_signing_keys1898=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1899=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1900=== CONT TestChildrenInheritRaisedFileLimit1901--- PASS: TestChildrenInheritRaisedFileLimit (0.03s)1902=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete19032026/10/25 19:48:34 INFO Received push request method=POST path=/api/pushes1904--- PASS: TestPresentReportsOnlyClosureRoots (8.16s)1905=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark19062026/10/25 19:48:35 WARN readiness check failed error="closed pool"1907--- PASS: TestService_readinessHandler (8.34s)1908=== CONT TestGCEndsOnShutdown/before_the_run19092026/10/25 19:48:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19102026/10/25 19:48:35 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLjZhNGEyMmIxLWIwNDEtNGIzZS1iNmI4LTc1ZGEyZjIwZGQ1NXgxNzkyOTU3NzEzODQ3ODczMDAw parts=1019112026/10/25 19:48:35 INFO Aborted multipart uploads count=0 kept=019122026/10/25 19:48:36 WARN Force mode enabled - objects will be deleted immediately without grace period19132026/10/25 19:48:36 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=019142026/10/25 19:48:36 INFO Vacuumed table table=pending_closures19152026/10/25 19:48:36 INFO Vacuumed table table=pending_objects19162026/10/25 19:48:36 INFO Vacuumed table table=multipart_uploads19172026/10/25 19:48:36 INFO Vacuumed table table=closures19182026/10/25 19:48:36 INFO Vacuumed table table=objects1919--- PASS: TestGCMetrics (8.44s)1920=== CONT TestResolveDBConnectionString/file_when_flag_empty1921=== CONT TestResolveDBConnectionString/nothing_configured1922=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1923=== CONT TestResolveDBConnectionString/missing_file_is_an_error1924=== CONT TestResolveDBConnectionString/flag_wins1925=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1926--- PASS: TestResolveDBConnectionString (0.02s)1927 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1928 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1929 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1930 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1931 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1932--- PASS: TestReadProxyOutlastsServerWriteTimeout (12.38s)1933=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1934=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1935--- PASS: TestService_healthCheckHandler (8.39s)19362026/10/25 19:48:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19372026/10/25 19:48:36 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLjU3MTU1N2UxLTBhZmQtNDcwYS04OWM3LTEwYjYzNjBlYWFhMXgxNzkyOTU3NzE1MDI2NDYyMDAw parts=1019382026/10/25 19:48:36 INFO Received uploads request method=POST path=/api/pending_closures19392026/10/25 19:48:37 INFO Aborted multipart uploads count=0 kept=019402026-10-25 19:48:37.193 UTC [66740] ERROR: Push does not exist: id=119412026-10-25 19:48:37.193 UTC [66740] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE19422026-10-25 19:48:37.193 UTC [66740] STATEMENT: SELECT commit_push($1)19432026/10/25 19:48:37 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=01944--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (11.42s)1945=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows19462026/10/25 19:48:37 INFO Vacuumed table table=pending_closures19472026/10/25 19:48:37 INFO Vacuumed table table=pending_objects19482026/10/25 19:48:37 INFO Vacuumed table table=multipart_uploads19492026/10/25 19:48:37 INFO Vacuumed table table=closures19502026/10/25 19:48:37 INFO Vacuumed table table=objects19512026/10/25 19:48:37 INFO Aborted multipart uploads count=0 kept=019522026/10/25 19:48:37 WARN Force mode enabled - objects will be deleted immediately without grace period19532026/10/25 19:48:37 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=019542026/10/25 19:48:37 INFO Vacuumed table table=pending_closures19552026/10/25 19:48:37 INFO lead: acquired remote=192.0.2.1:123419562026/10/25 19:48:37 INFO Vacuumed table table=pending_objects19572026/10/25 19:48:37 INFO Vacuumed table table=multipart_uploads19582026/10/25 19:48:37 INFO Vacuumed table table=closures19592026/10/25 19:48:37 INFO Vacuumed table table=objects1960--- PASS: TestPushDedupSurvivesConcurrentGC (9.41s)1961=== CONT TestServerTLSConfig/no_client_CA1962=== CONT TestServerTLSConfig/not_a_PEM_file1963=== CONT TestServerTLSConfig/missing_CA_file1964=== CONT TestIsValidUploadKey/nar_zst1965--- PASS: TestServerTLSConfig (0.00s)1966 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1967 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)1968 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1969=== CONT TestIsValidUploadKey/realisation1970=== CONT TestIsValidUploadKey/empty_key1971=== CONT TestIsValidUploadKey/unknown_type1972=== CONT TestIsValidUploadKey/absolute1973=== CONT TestIsValidUploadKey/traversal_nar1974=== CONT TestIsValidUploadKey/traversal1975=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1976=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1977=== CONT TestIsValidUploadKey/index.html1978=== CONT TestIsValidUploadKey/nix-cache-info1979=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1980=== CONT TestIsValidUploadKey/build_log_question_mark1981=== CONT TestIsValidUploadKey/build_log_equals1982=== CONT TestIsValidUploadKey/realisation_plus_in_output1983=== CONT TestIsValidUploadKey/build_log_plus_in_name1984=== CONT TestIsValidUploadKey/build_log_home-manager_file1985=== CONT TestIsValidUploadKey/nar_plain1986=== CONT TestIsValidUploadKey/build_log1987=== CONT TestIsValidUploadKey/listing1988=== CONT TestIsValidUploadKey/nar_xz1989=== CONT TestIsValidUploadKey/narinfo1990=== CONT TestClientErrorHandling/InvalidStorePath1991--- PASS: TestIsValidUploadKey (0.04s)1992 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1993 --- PASS: TestIsValidUploadKey/realisation (0.00s)1994 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1995 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1996 --- PASS: TestIsValidUploadKey/absolute (0.00s)1997 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1998 --- PASS: TestIsValidUploadKey/traversal (0.00s)1999 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2000 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2001 --- PASS: TestIsValidUploadKey/index.html (0.00s)2002 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2003 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2004 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2005 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2006 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2007 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2008 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2009 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2010 --- PASS: TestIsValidUploadKey/build_log (0.00s)2011 --- PASS: TestIsValidUploadKey/listing (0.00s)2012 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2013 --- PASS: TestIsValidUploadKey/narinfo (0.00s)20142026/10/25 19:48:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20152026/10/25 19:48:37 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLjA4ZGQ1MWQ0LWJjMTEtNDE4YS04MTJhLWJhNjNlZWQ0NDdiMHgxNzkyOTU3NzEzODYzNzA4MDAw parts=102016--- PASS: TestGCBugBareHashReferences (8.89s)2017=== CONT TestClientErrorHandling/ServerNotAvailable20182026/10/25 19:48:38 INFO Received uploads request method=POST path=/api/pending_closures20192026/10/25 19:48:38 INFO lead: released remote=192.0.2.1:12342020--- PASS: TestLeadEndsOnShutdown (9.70s)2021=== CONT TestClientErrorHandling/InvalidAuthToken2022=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2023=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2024=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2025=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2026=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2027=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2028=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2029=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2030=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts20312026/10/25 19:48:38 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/present20322026/10/25 19:48:38 INFO Received request for more parts method=POST path=/20332026/10/25 19:48:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20342026/10/25 19:48:38 WARN Request failed, retrying attempt=2 backoff=200.665292ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20352026/10/25 19:48:38 WARN Request failed, retrying attempt=3 backoff=364.73925ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2036=== RUN TestService_RequireScope_OIDC/builder_may_write2037=== PAUSE TestService_RequireScope_OIDC/builder_may_write2038=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2039=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2040=== RUN TestService_RequireScope_OIDC/ops_may_admin2041=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2042=== RUN TestService_RequireScope_OIDC/ops_may_not_write2043=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2044=== RUN TestService_RequireScope_OIDC/reader_may_not_write2045=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2046=== RUN TestService_RequireScope_OIDC/static_token_may_admin2047=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2048=== RUN TestService_RequireScope_OIDC/static_token_may_write2049=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2050=== RUN TestService_RequireScope_OIDC/reader_may_read2051=== PAUSE TestService_RequireScope_OIDC/reader_may_read2052=== RUN TestService_RequireScope_OIDC/writer_implies_read2053=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2054=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2055=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2056=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc2057=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc2058=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2059=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2060=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2061=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2062=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2063=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2064=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart20652026/10/25 19:48:39 INFO Received complete multipart upload request method=POST path=/20662026/10/25 19:48:39 WARN Request failed, retrying attempt=4 backoff=837.712947ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2067=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure20682026/10/25 19:48:39 INFO Received uploads request method=POST path=/2069--- PASS: TestCacheStatsHandler (8.66s)2070=== CONT TestParseSingleRange/none2071=== CONT TestParseSingleRange/start_far_past_EOF2072=== CONT TestParseSingleRange/start_past_EOF2073=== CONT TestParseSingleRange/single_byte2074=== CONT TestParseSingleRange/suffix_exceeds_size2075=== CONT TestParseSingleRange/suffix2076=== CONT TestParseSingleRange/end_clamped_to_size2077=== CONT TestParseSingleRange/closed2078=== CONT TestParseSingleRange/open-ended2079=== CONT TestParseSingleRange/malformed_end_before_start2080=== CONT TestParseSingleRange/malformed_no_dash2081=== CONT TestParseSingleRange/multi-range_ignored2082=== CONT TestParseSingleRange/malformed_both_empty2083=== CONT TestParseSingleRange/unknown_unit2084--- PASS: TestParseSingleRange (0.00s)2085 --- PASS: TestParseSingleRange/none (0.00s)2086 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2087 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2088 --- PASS: TestParseSingleRange/single_byte (0.00s)2089 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2090 --- PASS: TestParseSingleRange/suffix (0.00s)2091 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2092 --- PASS: TestParseSingleRange/closed (0.00s)2093 --- PASS: TestParseSingleRange/open-ended (0.00s)2094 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2095 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2096 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2097 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2098 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2099=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh21002026/10/25 19:48:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2101=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale21022026/10/25 19:48:40 WARN Request failed, retrying attempt=5 backoff=1.44624085s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21032026/10/25 19:48:40 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLmQ1MDdmNjVmLTUyYTUtNDE2Ni04NTA1LWQxM2ZhOTdjNWE0YXgxNzkyOTU3NzEzODQ5NTA0MDAw parts=102104--- PASS: TestService_ReadScope_PublicByDefault (9.02s)2105=== CONT TestProxyWriteTimeout/1_GiB_nar2106=== CONT TestProxyWriteTimeout/10_GiB_nar2107=== CONT TestProxyWriteTimeout/unknown_size2108=== CONT TestProxyWriteTimeout/narinfo2109=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key2110--- PASS: TestProxyWriteTimeout (0.00s)2111 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2112 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2113 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2114 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)21152026/10/25 19:48:40 INFO Received complete multipart upload request method=POST path=/2116=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key21172026/10/25 19:48:40 INFO Received request for more parts method=POST path=/2118=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal21192026/10/25 19:48:40 INFO Received uploads request method=POST path=/2120=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info21212026/10/25 19:48:40 INFO Received uploads request method=POST path=/2122--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2123 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.01s)2124 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2125 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2126 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2127=== CONT TestPendingClosureWriteTimeout/400_objects2128=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline2129--- PASS: TestService_ReadAuthMiddleware (7.84s)2130=== CONT TestPendingClosureWriteTimeout/670k_objects2131=== CONT TestPendingClosureWriteTimeout/empty2132=== CONT TestIsValidCachePath/narinfo2133=== CONT TestIsValidCachePath/nix-cache-info2134=== CONT TestIsValidCachePath/wrong_extension2135=== CONT TestIsValidCachePath/leading_slash2136=== CONT TestIsValidCachePath/empty2137=== CONT TestIsValidCachePath/random_path2138=== CONT TestIsValidCachePath/short_hash2139=== CONT TestIsValidCachePath/invalid_char_e2140=== CONT TestIsValidCachePath/invalid_char_u2141=== CONT TestIsValidCachePath/traversal_in_middle2142=== CONT TestIsValidCachePath/index.html2143=== CONT TestIsValidCachePath/nar_bz22144=== CONT TestIsValidCachePath/realisation2145=== CONT TestIsValidCachePath/log2146=== CONT TestIsValidCachePath/ls2147=== CONT TestIsValidCachePath/nar_uncompressed2148=== CONT TestIsValidCachePath/nar_zst2149=== CONT TestIsValidCachePath/traversal_parent2150=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2151=== CONT TestIsValidCachePath/nar_xz2152=== CONT TestPush_RejectsBadRequests/no_roots21532026/10/25 19:48:40 INFO Received push request method=POST path=/api/pushes2154--- PASS: TestIsValidCachePath (0.02s)2155 --- PASS: TestIsValidCachePath/narinfo (0.00s)2156 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2157 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2158 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2159 --- PASS: TestIsValidCachePath/empty (0.00s)2160 --- PASS: TestIsValidCachePath/random_path (0.00s)2161 --- PASS: TestIsValidCachePath/short_hash (0.00s)2162 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2163 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2164 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2165 --- PASS: TestIsValidCachePath/index.html (0.00s)2166 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2167 --- PASS: TestIsValidCachePath/realisation (0.00s)2168 --- PASS: TestIsValidCachePath/log (0.00s)2169 --- PASS: TestIsValidCachePath/ls (0.00s)2170 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2171 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2172 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2173 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2174 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2175=== CONT TestPush_RejectsBadRequests/root_not_in_objects21762026/10/25 19:48:40 INFO Received push request method=POST path=/api/pushes2177=== CONT TestPush_RejectsBadRequests/bad_root21782026/10/25 19:48:40 INFO Received push request method=POST path=/api/pushes2179=== CONT TestPush_RejectsBadRequests/no_objects21802026/10/25 19:48:40 INFO Received push request method=POST path=/api/pushes2181=== CONT TestCacheConfigHandler/full_config,_no_issuer2182=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2183=== CONT TestCacheConfigHandler/no_cache_url_configured2184=== CONT TestCacheConfigHandler/no_signing_keys2185=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2186--- PASS: TestCacheConfigHandler (0.00s)2187 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2188 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2189 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2190 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2191=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected21922026/10/25 19:48:40 WARN Authentication failed token_preview=eyJhbGciOi...LGae9hGBJw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2193=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2194=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected21952026/10/25 19:48:40 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]2196=== CONT TestService_RequireScope_OIDC/builder_may_write2197=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2198=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2199=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read22002026/10/25 19:48:40 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]2201=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2202=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2203=== CONT TestService_RequireScope_OIDC/writer_implies_read2204=== CONT TestService_RequireScope_OIDC/reader_may_read2205=== CONT TestService_RequireScope_OIDC/static_token_may_admin2206=== CONT TestService_RequireScope_OIDC/static_token_may_write2207=== CONT TestService_RequireScope_OIDC/reader_may_not_write2208=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2209=== CONT TestService_RequireScope_OIDC/ops_may_not_write2210=== CONT TestService_RequireScope_OIDC/ops_may_admin2211--- PASS: TestService_AuthMiddleware_OIDC (8.74s)2212 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2213 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2214 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2215 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2216--- PASS: TestService_RequireScope_OIDC (8.69s)2217 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2218 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2219 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2220 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2221 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2222 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2223 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2224 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2225 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2226 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2227 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2228 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2229 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2230 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2231--- PASS: TestPush_RejectsBadRequests (9.28s)2232 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2233 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2234 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2235 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)22362026/10/25 19:48:41 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"22372026/10/25 19:48:41 WARN mTLS auth: bound subjects configured but subject DN unavailable22382026/10/25 19:48:41 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2239--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (8.04s)22402026/10/25 19:48:41 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"2241--- PASS: TestService_AuthMiddleware (8.39s)22422026/10/25 19:48:41 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-config22432026/10/25 19:48:41 INFO Received push request method=POST path=/api/pushes22442026/10/25 19:48:41 WARN Request failed, retrying attempt=2 backoff=201.264932ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22452026/10/25 19:48:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22462026/10/25 19:48:42 INFO Signed narinfos id=1 count=122472026/10/25 19:48:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22482026/10/25 19:48:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22492026/10/25 19:48:42 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"22502026/10/25 19:48:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22512026/10/25 19:48:42 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"22522026/10/25 19:48:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22532026/10/25 19:48:42 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=122542026/10/25 19:48:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22552026/10/25 19:48:42 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo22562026/10/25 19:48:42 WARN Request failed, retrying attempt=3 backoff=437.224134ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2257--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (8.20s)22582026/10/25 19:48:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22592026/10/25 19:48:42 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLjcwNmRiNDZiLWEwNmEtNDgzMi1iMjQ5LWFjNjY4MTM5MzkwZHgxNzkyOTU3NzEzODQ5NTE1MDAw parts=1022602026/10/25 19:48:42 INFO Aborted multipart uploads count=0 kept=022612026/10/25 19:48:42 WARN Force mode enabled - objects will be deleted immediately without grace period22622026/10/25 19:48:42 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=022632026/10/25 19:48:42 INFO Vacuumed table table=pending_closures22642026/10/25 19:48:42 INFO Vacuumed table table=pending_objects22652026/10/25 19:48:42 INFO Vacuumed table table=multipart_uploads22662026/10/25 19:48:42 INFO Vacuumed table table=closures22672026/10/25 19:48:42 WARN Request failed, retrying attempt=4 backoff=856.716232ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22682026/10/25 19:48:42 INFO Vacuumed table table=objects2269--- PASS: TestSweepRechecksPendingAfterLocking (8.72s)22702026/10/25 19:48:42 WARN Rate limiter enabled after throttle name=s3-test rate=522712026/10/25 19:48:43 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2272=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2273 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102274 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002275--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (13.57s)22762026-10-25 19:48:43.232 UTC [62636] LOG: checkpoint starting: wal22772026/10/25 19:48:43 INFO Aborted multipart uploads count=0 kept=022782026/10/25 19:48:43 WARN Force mode enabled - objects will be deleted immediately without grace period22792026/10/25 19:48:43 WARN Request failed, retrying attempt=5 backoff=1.517144392s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22802026/10/25 19:48:43 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:58878/bucket96/?delete=\": context canceled"22812026/10/25 19:48:43 INFO Aborted multipart uploads count=0 kept=022822026/10/25 19:48:43 WARN Force mode enabled - objects will be deleted immediately without grace period22832026-10-25 19:48:43.999 UTC [67013] ERROR: canceling statement due to user request22842026-10-25 19:48:43.999 UTC [67013] CONTEXT: while locking tuple (0,1) in relation "objects"22852026-10-25 19:48:43.999 UTC [67013] STATEMENT: -- name: MarkStaleObjects :execrows2286 WITH RECURSIVE ct AS (2287 SELECT timezone('UTC', now()) AS now2288 ),2289 closure_reach AS (2290 -- Start with all closure keys2291 SELECT o.key, o.refs2292 FROM objects o2293 INNER JOIN closures c ON o.key = c.key2294 UNION2295 -- Recursively add all referenced objects2296 SELECT o.key, o.refs2297 FROM objects o2298 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2299 ),2300 reachable_objects AS (2301 SELECT DISTINCT key FROM closure_reach2302 ),2303 stale_objects AS (2304 SELECT o.key2305 FROM objects AS o, ct2306 WHERE2307 NOT EXISTS (2308 SELECT 12309 FROM reachable_objects ro2310 WHERE ro.key = o.key2311 )2312 AND NOT EXISTS (2313 SELECT 12314 FROM pending_objects AS po2315 WHERE po.key = o.key2316 )2317 AND o.deleted_at IS NULL -- Only mark fresh objects2318 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2319 FOR UPDATE2320 )2321 UPDATE objects2322 SET2323 deleted_at = ct.now,2324 first_deleted_at = COALESCE(first_deleted_at, ct.now)2325 FROM stale_objects, ct2326 WHERE objects.key = stale_objects.key2327 2328--- PASS: TestGCEndsOnShutdown (0.00s)2329 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (8.90s)2330 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (8.89s)2331 --- PASS: TestGCEndsOnShutdown/before_the_run (8.93s)23322026/10/25 19:48:44 INFO Received uploads request method=POST path=/api/pending_closures23332026/10/25 19:48:45 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"23342026/10/25 19:48:45 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-config23352026/10/25 19:48:45 WARN Request failed, retrying attempt=2 backoff=195.826375ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23362026/10/25 19:48:45 WARN Request failed, retrying attempt=3 backoff=393.213905ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23372026/10/25 19:48:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23382026/10/25 19:48:45 INFO Received uploads request method=POST path=/api/pending_closures23392026/10/25 19:48:45 WARN Request failed, retrying attempt=4 backoff=845.701135ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23402026/10/25 19:48:45 INFO Aborted multipart uploads count=0 kept=023412026/10/25 19:48:45 WARN Force mode enabled - objects will be deleted immediately without grace period23422026/10/25 19:48:45 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=023432026/10/25 19:48:45 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLjEyYmVjYzkzLTI4ZTctNDNkYy1hMDY0LTkxZjQxYjk5NDI1ZHgxNzkyOTU3NzEzODMyNTk0MDAw parts=1023442026/10/25 19:48:45 INFO Vacuumed table table=pending_closures23452026/10/25 19:48:46 INFO Vacuumed table table=pending_objects23462026/10/25 19:48:46 INFO Vacuumed table table=multipart_uploads23472026/10/25 19:48:46 INFO Vacuumed table table=closures23482026/10/25 19:48:46 INFO Vacuumed table table=objects23492026/10/25 19:48:46 INFO Received uploads request method=POST path=/api/pending_closures23502026/10/25 19:48:46 WARN Request failed, retrying attempt=5 backoff=1.628133635s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23512026/10/25 19:48:47 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLjk3YTZiM2FlLWRmMWEtNDhkZC04Y2M5LTFlNzVmZmVkNDMwNngxNzkyOTU3NzI2NTIyODEwMDAw error="Access Denied"23522026/10/25 19:48:47 WARN keeping failed pending closure for cleanup to retry the abort id=123532026/10/25 19:48:47 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld6 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"2354--- PASS: TestPendingClosureFailureTracksEveryUpload (0.00s)2355 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (9.46s)2356 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (11.25s)2357--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (18.98s)23582026/10/25 19:48:48 INFO Received uploads request method=POST path=/api/pending_closures23592026/10/25 19:48:48 INFO Aborted multipart uploads count=0 kept=023602026/10/25 19:48:48 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_closures23612026/10/25 19:48:48 WARN Force mode enabled - objects will be deleted immediately without grace period23622026/10/25 19:48:48 WARN Request failed, retrying attempt=2 backoff=211.860867ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23632026/10/25 19:48:48 WARN Request failed, retrying attempt=3 backoff=421.471502ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2364--- PASS: TestDeleteClosuresRacingPins (14.36s)23652026/10/25 19:48:49 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=023662026/10/25 19:48:49 INFO Vacuumed table table=pending_closures23672026/10/25 19:48:49 INFO Vacuumed table table=pending_objects23682026/10/25 19:48:49 WARN Request failed, retrying attempt=4 backoff=721.162029ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23692026/10/25 19:48:49 INFO Vacuumed table table=multipart_uploads23702026/10/25 19:48:49 INFO Vacuumed table table=closures23712026/10/25 19:48:49 INFO Vacuumed table table=objects23722026/10/25 19:48:49 WARN Request failed, retrying attempt=5 backoff=1.672108988s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2373--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2374 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (10.13s)2375 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (12.65s)23762026/10/25 19:48:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23772026/10/25 19:48:50 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"23782026/10/25 19:48:50 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZGNkOGFiNDgtNGJhMC00ZDRlLWIwOTctNmE0NmQ3NWJlZWMxLjMwNTQxNGQ3LTIxZjYtNDJjZC1iNmNiLTMwM2IyMWJlMThhNHgxNzkyOTU3NzEzODYyODA0MDAw parts=1023792026/10/25 19:48:51 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"23802026-10-25 19:48:51.044 UTC [66484] ERROR: could not obtain lock on row in relation "closures"23812026-10-25 19:48:51.044 UTC [66484] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23822026-10-25 19:48:51.075 UTC [66484] ERROR: could not obtain lock on row in relation "closures"23832026-10-25 19:48:51.075 UTC [66484] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23842026-10-25 19:48:51.095 UTC [66484] ERROR: could not obtain lock on row in relation "closures"23852026-10-25 19:48:51.095 UTC [66484] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23862026-10-25 19:48:51.128 UTC [66484] ERROR: could not obtain lock on row in relation "closures"23872026-10-25 19:48:51.128 UTC [66484] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23882026-10-25 19:48:51.155 UTC [66484] ERROR: could not obtain lock on row in relation "closures"23892026-10-25 19:48:51.155 UTC [66484] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT2390--- PASS: TestPush_RootsAreLockedInByteOrder (26.10s)2391--- PASS: TestClientErrorHandling (0.00s)2392 --- PASS: TestClientErrorHandling/InvalidStorePath (11.57s)2393 --- PASS: TestClientErrorHandling/InvalidAuthToken (12.68s)2394 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.37s)23952026/10/25 19:48:51 INFO Received uploads request method=POST path=/api/pending_closures2396=== NAME TestOrphanedObjectsGCStressTest2397 orphaned_objects_gc_test.go:503: Stress test completed successfully:2398 orphaned_objects_gc_test.go:504: - Active objects preserved: 202399 orphaned_objects_gc_test.go:505: - Objects deleted: 2102400 orphaned_objects_gc_test.go:506: - Total GC'd: 2102401--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2402 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (11.49s)2403 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (12.00s)2404--- PASS: TestOrphanedObjectsGCStressTest (49.13s)2405--- PASS: TestPendingClosureWriteTimeout (0.00s)2406 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2407 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2408 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2409 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (12.39s)2410--- PASS: TestUploadHandlersRejectOversizedBody (0.26s)2411 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (1.02s)2412 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.89s)2413 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (14.45s)2414PASS2415{"timestamp":"2026-10-25T19:48:54.109269Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:59198","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(9)"}24162026-10-25 19:48:54.418 UTC [62631] LOG: received smart shutdown request24172026-10-25 19:48:54.422 UTC [62631] LOG: background worker "logical replication launcher" (PID 62641) exited with exit code 124182026-10-25 19:48:56.464 UTC [62636] LOG: checkpoint complete: wrote 11580 buffers (70.7%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=12.018 s, sync=1.111 s, total=13.233 s; sync files=37079, longest=0.005 s, average=0.001 s; distance=533068 kB, estimate=533068 kB; lsn=0/232FA5D0, redo lsn=0/2201FFC824192026-10-25 19:48:56.466 UTC [62636] LOG: shutting down24202026-10-25 19:48:56.466 UTC [62636] LOG: checkpoint starting: shutdown immediate24212026-10-25 19:48:56.475 UTC [62636] LOG: checkpoint complete: wrote 152 buffers (0.9%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 1 recycled; write=0.005 s, sync=0.003 s, total=0.009 s; sync files=88, longest=0.001 s, average=0.001 s; distance=19305 kB, estimate=481691 kB; lsn=0/232FA648, redo lsn=0/232FA64824222026-10-25 19:48:56.490 UTC [62631] LOG: database system is shut down2423Running OIDC tests...2424=== RUN TestAudienceForIssuer2425=== PAUSE TestAudienceForIssuer2426=== RUN TestHTTPClientForHasTimeouts2427=== PAUSE TestHTTPClientForHasTimeouts2428=== RUN TestGlobMatch2429=== PAUSE TestGlobMatch2430=== RUN TestValidateToken_ValidToken2431=== PAUSE TestValidateToken_ValidToken2432=== RUN TestValidateToken_WrongAudience2433=== PAUSE TestValidateToken_WrongAudience2434=== RUN TestValidateToken_Expired2435=== PAUSE TestValidateToken_Expired2436=== RUN TestValidateToken_BoundClaimsMismatch2437=== PAUSE TestValidateToken_BoundClaimsMismatch2438=== RUN TestValidateToken_BoundSubjectMismatch2439=== PAUSE TestValidateToken_BoundSubjectMismatch2440=== RUN TestValidateToken_MultipleProviders2441=== PAUSE TestValidateToken_MultipleProviders2442=== RUN TestValidateToken_NoMatchingProvider2443=== PAUSE TestValidateToken_NoMatchingProvider2444=== RUN TestValidateToken_KubernetesServiceAccount2445=== PAUSE TestValidateToken_KubernetesServiceAccount2446=== RUN TestNewValidator_KubernetesRequiresCA2447=== PAUSE TestNewValidator_KubernetesRequiresCA2448=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2449=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2450=== RUN TestPins_ReservedForMatchingRule2451=== PAUSE TestPins_ReservedForMatchingRule2452=== RUN TestPins_TopLevelShorthand2453=== PAUSE TestPins_TopLevelShorthand2454=== RUN TestPins_ConfigValidation2455=== PAUSE TestPins_ConfigValidation2456=== RUN TestScopes_LegacyProviderDefaultsToWrite2457=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2458=== RUN TestScopes_Rules2459=== PAUSE TestScopes_Rules2460=== RUN TestScopes_ConfigValidation2461=== PAUSE TestScopes_ConfigValidation2462=== CONT TestHTTPClientForHasTimeouts2463=== CONT TestValidateToken_WrongAudience2464=== CONT TestPins_TopLevelShorthand2465=== CONT TestValidateToken_NoMatchingProvider2466=== CONT TestPins_ReservedForMatchingRule2467=== CONT TestScopes_ConfigValidation2468=== CONT TestNewValidator_KubernetesRequiresCA2469--- PASS: TestScopes_ConfigValidation (0.00s)2470=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2471=== CONT TestGlobMatch2472=== RUN TestGlobMatch/foo_foo2473=== CONT TestValidateToken_ValidToken2474=== PAUSE TestGlobMatch/foo_foo2475=== RUN TestGlobMatch/foo_bar2476=== PAUSE TestGlobMatch/foo_bar2477=== RUN TestGlobMatch/*_2478=== PAUSE TestGlobMatch/*_2479=== RUN TestGlobMatch/*_anything2480=== PAUSE TestGlobMatch/*_anything2481=== RUN TestGlobMatch/foo*_foo2482=== PAUSE TestGlobMatch/foo*_foo2483=== RUN TestGlobMatch/foo*_foobar2484=== PAUSE TestGlobMatch/foo*_foobar2485=== RUN TestGlobMatch/foo*_bar2486=== PAUSE TestGlobMatch/foo*_bar2487=== RUN TestGlobMatch/*bar_bar2488=== PAUSE TestGlobMatch/*bar_bar2489=== RUN TestGlobMatch/*bar_foobar2490=== PAUSE TestGlobMatch/*bar_foobar2491=== RUN TestGlobMatch/*bar_foo2492=== PAUSE TestGlobMatch/*bar_foo2493=== RUN TestGlobMatch/foo*bar_foobar2494=== PAUSE TestGlobMatch/foo*bar_foobar2495=== RUN TestGlobMatch/foo*bar_foo123bar2496=== PAUSE TestGlobMatch/foo*bar_foo123bar2497=== RUN TestGlobMatch/foo*bar_foobarbaz2498=== PAUSE TestGlobMatch/foo*bar_foobarbaz2499=== RUN TestGlobMatch/*/*_foo/bar2500=== PAUSE TestGlobMatch/*/*_foo/bar2501=== RUN TestGlobMatch/*/*_foo2502=== PAUSE TestGlobMatch/*/*_foo2503=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2504=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2505=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02506=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02507=== RUN TestGlobMatch/refs/*/main_refs/heads/main2508=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2509=== RUN TestGlobMatch/fo?_foo2510=== PAUSE TestGlobMatch/fo?_foo2511=== RUN TestGlobMatch/fo?_fo2512=== PAUSE TestGlobMatch/fo?_fo2513=== RUN TestGlobMatch/fo?_fooo2514=== PAUSE TestGlobMatch/fo?_fooo2515=== RUN TestGlobMatch/?oo_foo2516=== PAUSE TestGlobMatch/?oo_foo2517=== RUN TestGlobMatch/?oo_boo2518=== PAUSE TestGlobMatch/?oo_boo2519=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2520=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2521=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2522=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2523=== CONT TestGlobMatch/foo_foo2524=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2525=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2526=== CONT TestGlobMatch/?oo_boo2527=== CONT TestGlobMatch/?oo_foo2528=== CONT TestGlobMatch/fo?_fo2529=== CONT TestGlobMatch/fo?_foo2530=== CONT TestGlobMatch/refs/*/main_refs/heads/main2531=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02532=== CONT TestGlobMatch/fo?_fooo2533=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2534=== CONT TestGlobMatch/*/*_foo2535=== CONT TestGlobMatch/foo*bar_foobarbaz2536=== CONT TestGlobMatch/*/*_foo/bar2537=== CONT TestGlobMatch/foo*bar_foobar2538=== CONT TestGlobMatch/*bar_foo2539=== CONT TestGlobMatch/*bar_foobar2540=== CONT TestGlobMatch/*bar_bar2541=== CONT TestGlobMatch/foo*bar_foo123bar2542=== CONT TestGlobMatch/foo*_bar2543=== CONT TestGlobMatch/foo*_foobar2544=== CONT TestGlobMatch/foo*_foo2545=== CONT TestGlobMatch/*_2546=== CONT TestGlobMatch/*_anything2547=== CONT TestGlobMatch/foo_bar2548--- PASS: TestGlobMatch (0.00s)2549 --- PASS: TestGlobMatch/foo_foo (0.00s)2550 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2551 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2552 --- PASS: TestGlobMatch/?oo_boo (0.00s)2553 --- PASS: TestGlobMatch/?oo_foo (0.00s)2554 --- PASS: TestGlobMatch/fo?_fo (0.00s)2555 --- PASS: TestGlobMatch/fo?_foo (0.00s)2556 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2557 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2558 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2559 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2560 --- PASS: TestGlobMatch/*/*_foo (0.00s)2561 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2562 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2563 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2564 --- PASS: TestGlobMatch/*bar_foo (0.00s)2565 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2566 --- PASS: TestGlobMatch/*bar_bar (0.00s)2567 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2568 --- PASS: TestGlobMatch/foo*_bar (0.00s)2569 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2570 --- PASS: TestGlobMatch/foo*_foo (0.00s)2571 --- PASS: TestGlobMatch/*_ (0.00s)2572 --- PASS: TestGlobMatch/*_anything (0.00s)2573 --- PASS: TestGlobMatch/foo_bar (0.00s)2574=== CONT TestValidateToken_Expired2575=== CONT TestAudienceForIssuer2576--- PASS: TestAudienceForIssuer (0.00s)2577=== CONT TestValidateToken_KubernetesServiceAccount2578=== CONT TestValidateToken_MultipleProviders2579=== CONT TestScopes_LegacyProviderDefaultsToWrite2580=== CONT TestScopes_Rules2581=== CONT TestPins_ConfigValidation2582--- PASS: TestPins_ConfigValidation (0.00s)2583=== CONT TestValidateToken_BoundClaimsMismatch2584=== CONT TestValidateToken_BoundSubjectMismatch25852026/10/25 19:48:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59700/oidc2586--- PASS: TestValidateToken_WrongAudience (0.11s)25872026/10/25 19:48:59 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:5970225882026/10/25 19:48:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59704/oidc25892026/10/25 19:48:59 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232590--- PASS: TestPins_TopLevelShorthand (0.16s)2591--- PASS: TestValidateToken_KubernetesServiceAccount (0.15s)25922026/10/25 19:48:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59707/oidc2593--- PASS: TestValidateToken_Expired (0.17s)25942026/10/25 19:48:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59709/oidc2595--- PASS: TestValidateToken_BoundClaimsMismatch (0.18s)2596--- PASS: TestHTTPClientForHasTimeouts (0.22s)2597--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.30s)25982026/10/25 19:48:59 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:59713/oidc2599--- PASS: TestValidateToken_NoMatchingProvider (0.40s)26002026/10/25 19:48:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59716/oidc2601--- PASS: TestValidateToken_BoundSubjectMismatch (0.39s)26022026/10/25 19:48:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59718/oidc2603--- PASS: TestValidateToken_ValidToken (0.43s)26042026/10/25 19:49:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59720/oidc2605--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.46s)26062026/10/25 19:49:00 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:59712/oidc26072026/10/25 19:49:00 http: TLS handshake error from 127.0.0.1:59723: remote error: tls: bad certificate26082026/10/25 19:49:00 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:59724/oidc26092026/10/25 19:49:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59726/oidc2610--- PASS: TestNewValidator_KubernetesRequiresCA (0.58s)2611--- PASS: TestValidateToken_MultipleProviders (0.57s)2612--- PASS: TestPins_ReservedForMatchingRule (0.59s)26132026/10/25 19:49:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59729/oidc2614--- PASS: TestScopes_Rules (0.75s)2615PASS2616Running hook tests...2617=== RUN TestSendPathsEmpty2618=== PAUSE TestSendPathsEmpty2619=== RUN TestQueueEnqueueAndFetch2620=== PAUSE TestQueueEnqueueAndFetch2621=== RUN TestQueueDeduplication2622=== PAUSE TestQueueDeduplication2623=== RUN TestQueueRemove2624=== PAUSE TestQueueRemove2625=== RUN TestQueueFetchBatchLimit2626=== PAUSE TestQueueFetchBatchLimit2627=== RUN TestQueueRetryMovesToBack2628=== PAUSE TestQueueRetryMovesToBack2629=== RUN TestQueueFetchRemoveLifecycle2630=== PAUSE TestQueueFetchRemoveLifecycle2631=== RUN TestQueueConcurrentWriters2632=== PAUSE TestQueueConcurrentWriters2633=== RUN TestQueueEnqueueWaitsOutSlowWriter2634=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2635=== RUN TestQueueRemoveLargeClosure2636=== PAUSE TestQueueRemoveLargeClosure2637=== RUN TestServerClientIntegration2638--- PASS: TestServerClientIntegration (0.02s)2639=== RUN TestServerQueueError26402026/10/25 19:49:01 ERROR Failed to queue paths error="permission denied" count=12641--- PASS: TestServerQueueError (0.00s)2642=== RUN TestServerRefusesOversizedAndNonStoreRequests2643=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2644=== RUN TestGetListenerSocketActivation2645 server_test.go:236: systemd socket activation does not exist on darwin2646--- SKIP: TestGetListenerSocketActivation (0.00s)2647=== RUN TestServerStalledClientDoesNotBlockShutdown2648=== PAUSE TestServerStalledClientDoesNotBlockShutdown2649=== RUN TestServerBacksOffOnAcceptErrors2650=== PAUSE TestServerBacksOffOnAcceptErrors2651=== RUN TestDrainIsolatesPoisonPath2652=== PAUSE TestDrainIsolatesPoisonPath2653=== RUN TestRunNotBlockedByPoisonHead2654=== PAUSE TestRunNotBlockedByPoisonHead2655=== RUN TestDrainGivesUpWhenServerDown2656=== PAUSE TestDrainGivesUpWhenServerDown2657=== RUN TestFailedPathPrunedByLaterClosure2658=== PAUSE TestFailedPathPrunedByLaterClosure2659=== RUN TestWorkerUploadsAndRemoves2660=== PAUSE TestWorkerUploadsAndRemoves2661=== RUN TestWorkerSkipsGCdPaths2662=== PAUSE TestWorkerSkipsGCdPaths2663=== RUN TestWorkerPrunesClosureDeps2664=== PAUSE TestWorkerPrunesClosureDeps2665=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2666=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2667=== RUN TestDrainTimeout2668=== PAUSE TestDrainTimeout2669=== RUN TestDrainTimeoutDuringIsolation2670=== PAUSE TestDrainTimeoutDuringIsolation2671=== RUN TestShutdownFinishesInFlightPush2672=== PAUSE TestShutdownFinishesInFlightPush2673=== RUN TestWorkerRemoveFailureIsNotProgress2674=== PAUSE TestWorkerRemoveFailureIsNotProgress2675=== RUN TestWorkerKeepsPathItCannotStat2676=== PAUSE TestWorkerKeepsPathItCannotStat2677=== CONT TestQueueDeduplication2678=== CONT TestServerBacksOffOnAcceptErrors2679=== CONT TestQueueFetchRemoveLifecycle2680=== CONT TestRunNotBlockedByPoisonHead26812026/10/25 19:49:01 ERROR Accept failed error="too many open files"2682=== CONT TestServerRefusesOversizedAndNonStoreRequests2683=== CONT TestQueueRemoveLargeClosure2684=== CONT TestQueueEnqueueWaitsOutSlowWriter2685=== CONT TestServerStalledClientDoesNotBlockShutdown2686=== CONT TestWorkerPrunesClosureDeps2687=== CONT TestWorkerRemoveFailureIsNotProgress2688=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2689=== CONT TestShutdownFinishesInFlightPush2690=== RUN TestShutdownFinishesInFlightPush/completes2691=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2692=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2693=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2694=== CONT TestDrainTimeoutDuringIsolation2695=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2696=== PAUSE TestShutdownFinishesInFlightPush/completes2697=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2698=== CONT TestDrainTimeout2699=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2700=== CONT TestQueueRemove2701=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2702=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2703=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2704=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2705=== CONT TestSendPathsEmpty27062026/10/25 19:49:01 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2707--- PASS: TestSendPathsEmpty (0.00s)2708=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths2709=== CONT TestWorkerUploadsAndRemoves2710=== CONT TestWorkerSkipsGCdPaths2711=== CONT TestWorkerKeepsPathItCannotStat2712=== CONT TestDrainGivesUpWhenServerDown27132026/10/25 19:49:01 ERROR Refusing path outside the store path=/nix/store store=/nix/store2714=== CONT TestFailedPathPrunedByLaterClosure2715=== CONT TestQueueRetryMovesToBack2716=== CONT TestQueueConcurrentWriters2717=== CONT TestQueueFetchBatchLimit27182026/10/25 19:49:01 ERROR Accept failed error="too many open files"2719=== CONT TestDrainIsolatesPoisonPath2720=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2721=== CONT TestQueueEnqueueAndFetch2722=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2723=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch27242026/10/25 19:49:01 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store27252026/10/25 19:49:01 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store27262026/10/25 19:49:01 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store27272026/10/25 19:49:01 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27282026/10/25 19:49:01 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27292026/10/25 19:49:01 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store27302026/10/25 19:49:01 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store27312026/10/25 19:49:01 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store27322026/10/25 19:49:01 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store27332026/10/25 19:49:01 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store27342026/10/25 19:49:01 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store27352026/10/25 19:49:01 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store27362026/10/25 19:49:01 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store27372026/10/25 19:49:01 ERROR Failed to decode request error="unexpected EOF"2738--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2739=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27402026/10/25 19:49:01 ERROR Accept failed error="too many open files"27412026/10/25 19:49:01 INFO Uploading batch count=127422026/10/25 19:49:01 ERROR Upload failed error="upload failed" count=127432026/10/25 19:49:01 WARN Cannot stat store path, will retry later path=/private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestWorkerKeepsPathItCannotStat1598260155/002/locked/aaa error="lstat /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestWorkerKeepsPathItCannotStat1598260155/002/locked/aaa: permission denied"27442026/10/25 19:49:01 INFO Uploading batch count=227452026/10/25 19:49:01 INFO Uploading batch count=127462026/10/25 19:49:01 INFO Upload queue status pending=227472026/10/25 19:49:01 INFO Uploading batch count=427482026/10/25 19:49:01 ERROR Upload failed error="upload failed" count=427492026/10/25 19:49:01 INFO Uploading batch count=227502026/10/25 19:49:01 ERROR Upload failed error="upload failed" count=227512026/10/25 19:49:01 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestDrainGivesUpWhenServerDown1777643323/002/a27522026/10/25 19:49:01 WARN Cannot stat store path, will retry later path=/private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestWorkerKeepsPathItCannotStat1598260155/002/locked/aaa error="lstat /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestWorkerKeepsPathItCannotStat1598260155/002/locked/aaa: permission denied"27532026/10/25 19:49:01 INFO Uploading batch count=127542026/10/25 19:49:01 INFO Upload queue status pending=227552026/10/25 19:49:01 INFO Uploading batch count=127562026/10/25 19:49:01 ERROR Accept failed error="too many open files"27572026/10/25 19:49:01 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestDrainGivesUpWhenServerDown1777643323/002/b27582026/10/25 19:49:01 INFO Upload queue status pending=327592026/10/25 19:49:01 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestDrainIsolatesPoisonPath971585785/002/bbb27602026/10/25 19:49:01 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestWorkerSkipsGCdPaths1988107571/002/nonexistent27612026/10/25 19:49:01 INFO Uploading batch count=22762--- PASS: TestQueueDeduplication (0.04s)2763=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short27642026/10/25 19:49:01 INFO Uploading batch count=22765--- PASS: TestQueueFetchRemoveLifecycle (0.04s)2766=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline27672026/10/25 19:49:01 INFO Upload queue status pending=327682026/10/25 19:49:01 INFO Uploading batch count=227692026/10/25 19:49:01 INFO Uploading batch count=127702026/10/25 19:49:01 ERROR Upload failed error="upload failed" count=227712026/10/25 19:49:01 ERROR Upload failed error="upload failed" count=127722026/10/25 19:49:01 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestDrainGivesUpWhenServerDown1777643323/002/c27732026/10/25 19:49:01 WARN Cannot stat store path, will retry later path=/private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestWorkerKeepsPathItCannotStat1598260155/002/locked/aaa error="lstat /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestWorkerKeepsPathItCannotStat1598260155/002/locked/aaa: permission denied"27742026/10/25 19:49:01 INFO Upload queue status pending=22775--- PASS: TestQueueFetchBatchLimit (0.04s)2776=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout27772026/10/25 19:49:01 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestDrainGivesUpWhenServerDown1777643323/002/d27782026/10/25 19:49:01 INFO Uploading batch count=227792026/10/25 19:49:01 ERROR Drain finished with paths left in queue remaining=127802026/10/25 19:49:01 INFO Uploading batch count=127812026/10/25 19:49:01 ERROR Upload failed error="upload failed" count=127822026/10/25 19:49:01 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestWorkerRemoveFailureIsNotProgresscollected_path2923475154/001/nonexistent27832026/10/25 19:49:01 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127842026/10/25 19:49:01 INFO Uploading batch count=227852026/10/25 19:49:01 ERROR Upload failed error="upload failed" count=227862026/10/25 19:49:01 INFO Uploading batch count=227872026/10/25 19:49:01 ERROR Upload failed error="upload failed" count=227882026/10/25 19:49:01 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestDrainGivesUpWhenServerDown1777643323/002/e2789--- PASS: TestQueueRemove (0.04s)2790=== CONT TestShutdownFinishesInFlightPush/completes27912026/10/25 19:49:01 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=12792--- PASS: TestQueueEnqueueAndFetch (0.04s)27932026/10/25 19:49:01 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestDrainGivesUpWhenServerDown1777643323/002/f27942026/10/25 19:49:01 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestWorkerRemoveFailureIsNotProgresscollected_path2923475154/001/nonexistent2795--- PASS: TestFailedPathPrunedByLaterClosure (0.04s)27962026/10/25 19:49:01 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=12797--- PASS: TestQueueRetryMovesToBack (0.04s)27982026/10/25 19:49:01 ERROR Drain finished with paths left in queue remaining=1027992026/10/25 19:49:01 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128002026/10/25 19:49:01 INFO Uploading batch count=228012026/10/25 19:49:01 ERROR Upload failed error="upload failed" count=228022026/10/25 19:49:01 INFO Uploading batch count=128032026/10/25 19:49:01 ERROR Upload failed error="upload failed" count=128042026/10/25 19:49:01 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128052026/10/25 19:49:01 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestWorkerRemoveFailureIsNotProgresscollected_path2923475154/001/nonexistent2806--- PASS: TestWorkerKeepsPathItCannotStat (0.05s)28072026/10/25 19:49:01 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128082026/10/25 19:49:01 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128092026/10/25 19:49:01 INFO Uploading batch count=128102026/10/25 19:49:01 ERROR Upload failed error="upload failed" count=128112026/10/25 19:49:01 ERROR Drain finished with paths left in queue remaining=128122026/10/25 19:49:01 INFO Uploading batch count=228132026/10/25 19:49:01 ERROR Upload failed error="upload failed" count=228142026/10/25 19:49:01 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128152026/10/25 19:49:01 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128162026/10/25 19:49:01 ERROR Drain finished with paths left in queue remaining=228172026/10/25 19:49:01 ERROR Drain finished with paths left in queue remaining=12818--- PASS: TestDrainGivesUpWhenServerDown (0.05s)28192026/10/25 19:49:01 INFO Uploading batch count=428202026/10/25 19:49:01 ERROR Upload failed error="upload failed" count=42821--- PASS: TestDrainIsolatesPoisonPath (0.05s)28222026/10/25 19:49:01 INFO Uploading batch count=428232026/10/25 19:49:01 INFO Uploading batch count=228242026/10/25 19:49:01 ERROR Upload failed error="upload failed" count=428252026/10/25 19:49:01 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=22826--- PASS: TestWorkerPrunesClosureDeps (0.06s)28272026/10/25 19:49:01 INFO Upload queue status pending=228282026/10/25 19:49:01 INFO Uploading batch count=228292026/10/25 19:49:01 INFO Uploading batch count=228302026/10/25 19:49:01 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228312026/10/25 19:49:01 INFO Uploading batch count=22832--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.06s)28332026/10/25 19:49:01 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=22834--- PASS: TestWorkerSkipsGCdPaths (0.06s)28352026/10/25 19:49:01 INFO Upload queue status pending=228362026/10/25 19:49:01 ERROR Drain finished with paths left in queue remaining=228372026/10/25 19:49:01 INFO Uploading batch count=22838--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2839 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.04s)2840 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.05s)2841 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.05s)2842--- PASS: TestWorkerUploadsAndRemoves (0.06s)28432026/10/25 19:49:01 ERROR Accept failed error="too many open files"28442026/10/25 19:49:01 ERROR Accept failed error="too many open files"28452026/10/25 19:49:01 ERROR Failed to decode request error="read unix /private/var/tb/6/scratch/e3c58ef3d7a98188/build/hook1520111110/test.sock->: i/o timeout"28462026/10/25 19:49:01 ERROR Failed to write response error="write unix /private/var/tb/6/scratch/e3c58ef3d7a98188/build/hook1520111110/test.sock->: i/o timeout"2847--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)28482026/10/25 19:49:01 ERROR Upload failed error="context canceled" count=228492026/10/25 19:49:01 ERROR Drain finished with paths left in queue remaining=42850--- PASS: TestDrainTimeout (0.23s)28512026/10/25 19:49:02 ERROR Drain finished with paths left in queue remaining=428522026/10/25 19:49:02 ERROR Upload failed error="context canceled" count=228532026/10/25 19:49:02 ERROR Drain finished with paths left in queue remaining=22854--- PASS: TestShutdownFinishesInFlightPush (0.01s)2855 --- PASS: TestShutdownFinishesInFlightPush/completes (0.13s)2856 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.22s)28572026/10/25 19:49:02 ERROR Accept failed error="too many open files"2858--- PASS: TestQueueConcurrentWriters (0.35s)28592026/10/25 19:49:02 ERROR Drain finished with paths left in queue remaining=32860--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2861 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.22s)2862 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.32s)28632026/10/25 19:49:02 ERROR Accept failed error="too many open files"2864--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)28652026/10/25 19:49:02 INFO Uploading batch count=128662026/10/25 19:49:02 INFO Uploading batch count=128672026/10/25 19:49:02 INFO Uploading batch count=128682026/10/25 19:49:02 ERROR Upload failed error="upload failed" count=128692026/10/25 19:49:02 INFO Uploading batch count=128702026/10/25 19:49:02 ERROR Upload failed error="upload failed" count=128712026/10/25 19:49:02 INFO Uploading batch count=128722026/10/25 19:49:02 ERROR Upload failed error="upload failed" count=128732026/10/25 19:49:02 INFO Uploading batch count=128742026/10/25 19:49:02 ERROR Upload failed error="upload failed" count=128752026/10/25 19:49:02 ERROR Drain finished with paths left in queue remaining=12876--- PASS: TestRunNotBlockedByPoisonHead (1.07s)2877--- PASS: TestQueueRemoveLargeClosure (1.37s)2878--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.03s)2879PASS2880Running signing tests...2881=== RUN TestExternalSigner2882=== PAUSE TestExternalSigner2883=== RUN TestExternalSignerWrongPublicKey2884=== PAUSE TestExternalSignerWrongPublicKey2885=== RUN TestExternalSignerErrors2886=== PAUSE TestExternalSignerErrors2887=== RUN TestExternalSignerRestartsAfterCrash2888=== PAUSE TestExternalSignerRestartsAfterCrash2889=== RUN TestExternalSignerProgramErrorKeepsProcess2890=== PAUSE TestExternalSignerProgramErrorKeepsProcess2891=== RUN TestExternalSignerClose2892=== PAUSE TestExternalSignerClose2893=== RUN TestExternalSignerRejectsInvalidPublicKey2894=== PAUSE TestExternalSignerRejectsInvalidPublicKey2895=== RUN TestExternalSignerCancellation2896=== PAUSE TestExternalSignerCancellation2897=== RUN TestGenerateFingerprint2898=== PAUSE TestGenerateFingerprint2899=== RUN TestParseSigningKey2900=== PAUSE TestParseSigningKey2901=== RUN TestSign2902=== PAUSE TestSign2903=== RUN TestSignBatch2904=== PAUSE TestSignBatch2905=== RUN TestNilKeyPublicKey2906=== PAUSE TestNilKeyPublicKey2907=== RUN TestSignErrors2908=== PAUSE TestSignErrors2909=== CONT TestExternalSignerWrongPublicKey2910=== CONT TestExternalSignerRejectsInvalidPublicKey2911=== RUN TestExternalSignerRejectsInvalidPublicKey/#002912=== CONT TestNilKeyPublicKey2913=== CONT TestSignErrors2914--- PASS: TestNilKeyPublicKey (0.00s)2915=== CONT TestExternalSignerRestartsAfterCrash2916=== CONT TestExternalSignerClose2917=== CONT TestExternalSignerProgramErrorKeepsProcess2918=== CONT TestGenerateFingerprint2919=== RUN TestGenerateFingerprint/basic_with_references2920=== CONT TestSignBatch2921=== PAUSE TestGenerateFingerprint/basic_with_references2922=== CONT TestExternalSignerErrors2923=== RUN TestGenerateFingerprint/no_references2924=== RUN TestExternalSignerErrors/exit_at_startup2925=== PAUSE TestGenerateFingerprint/no_references2926=== CONT TestExternalSignerCancellation2927=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2928=== CONT TestParseSigningKey2929=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2930=== CONT TestExternalSigner2931=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2932=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2933=== CONT TestSign2934=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002935=== PAUSE TestExternalSignerErrors/exit_at_startup2936=== RUN TestParseSigningKey/valid_32-byte_key2937=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2938=== PAUSE TestParseSigningKey/valid_32-byte_key2939=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2940=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2941=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2942=== RUN TestParseSigningKey/no_colon2943=== RUN TestExternalSignerErrors/invalid_JSON2944=== PAUSE TestExternalSignerErrors/invalid_JSON2945=== PAUSE TestParseSigningKey/no_colon2946=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2947=== RUN TestExternalSignerErrors/wrong_shape2948=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2949=== PAUSE TestExternalSignerErrors/wrong_shape2950=== RUN TestParseSigningKey/empty_name2951=== RUN TestExternalSignerErrors/null2952=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2953=== PAUSE TestExternalSignerErrors/null2954=== RUN TestExternalSignerErrors/missing_signatures2955=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2956=== PAUSE TestExternalSignerErrors/missing_signatures2957=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2958=== RUN TestExternalSignerErrors/exit_on_request2959=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2960=== PAUSE TestExternalSignerErrors/exit_on_request2961=== PAUSE TestParseSigningKey/empty_name2962=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2963=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2964=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2965=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2966=== CONT TestExternalSignerRejectsInvalidPublicKey/#002967=== RUN TestExternalSignerErrors/wrong_id2968=== RUN TestParseSigningKey/invalid_base642969=== PAUSE TestParseSigningKey/invalid_base642970--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2971 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2972 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2973 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2974 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2975 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2976=== PAUSE TestExternalSignerErrors/wrong_id2977=== RUN TestExternalSignerErrors/wrong_signatures_shape2978=== RUN TestParseSigningKey/wrong_length2979=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2980=== PAUSE TestParseSigningKey/wrong_length2981=== RUN TestExternalSignerErrors/unrequested_key2982=== PAUSE TestExternalSignerErrors/unrequested_key2983=== RUN TestExternalSignerErrors/missing_signature_name2984=== CONT TestParseSigningKey/valid_32-byte_key2985=== CONT TestParseSigningKey/invalid_base642986=== CONT TestParseSigningKey/empty_name2987=== PAUSE TestExternalSignerErrors/missing_signature_name2988=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2989=== CONT TestParseSigningKey/wrong_length2990=== CONT TestParseSigningKey/no_colon2991--- PASS: TestParseSigningKey (0.00s)2992 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2993 --- PASS: TestParseSigningKey/wrong_length (0.00s)2994 --- PASS: TestParseSigningKey/empty_name (0.00s)2995 --- PASS: TestParseSigningKey/no_colon (0.00s)2996 --- PASS: TestParseSigningKey/valid_32-byte_key (0.01s)2997 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.01s)2998=== RUN TestSignErrors/nil_key2999=== PAUSE TestSignErrors/nil_key3000=== RUN TestSignErrors/nil_narinfo3001=== PAUSE TestSignErrors/nil_narinfo3002=== RUN TestSignErrors/invalid_narinfo3003=== PAUSE TestSignErrors/invalid_narinfo3004=== RUN TestSignErrors/canceled3005=== PAUSE TestSignErrors/canceled3006=== CONT TestSignErrors/nil_key3007=== CONT TestSignErrors/canceled3008=== CONT TestSignErrors/invalid_narinfo3009=== CONT TestSignErrors/nil_narinfo3010--- PASS: TestSignErrors (0.01s)3011 --- PASS: TestSignErrors/nil_key (0.00s)3012 --- PASS: TestSignErrors/canceled (0.00s)3013 --- PASS: TestSignErrors/invalid_narinfo (0.00s)3014 --- PASS: TestSignErrors/nil_narinfo (0.00s)3015=== RUN TestGenerateFingerprint/invalid_nar_hash_length3016=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length3017=== RUN TestGenerateFingerprint/invalid_store_path_prefix3018=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix3019=== RUN TestGenerateFingerprint/invalid_reference_prefix3020=== PAUSE TestGenerateFingerprint/invalid_reference_prefix3021=== CONT TestGenerateFingerprint/invalid_reference_prefix3022=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix3023=== CONT TestGenerateFingerprint/no_references3024=== CONT TestGenerateFingerprint/unsorted_references_get_sorted3025=== CONT TestGenerateFingerprint/basic_with_references3026=== CONT TestGenerateFingerprint/invalid_store_path_prefix3027=== CONT TestGenerateFingerprint/invalid_nar_hash_length3028=== RUN TestExternalSignerErrors/too_few_signatures3029=== PAUSE TestExternalSignerErrors/too_few_signatures3030=== RUN TestExternalSignerErrors/wrong_signature_name3031--- PASS: TestSignBatch (0.02s)3032--- PASS: TestSign (0.02s)3033--- PASS: TestGenerateFingerprint (0.01s)3034 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)3035 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)3036 --- PASS: TestGenerateFingerprint/no_references (0.00s)3037 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)3038 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)3039 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)3040 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.01s)3041=== PAUSE TestExternalSignerErrors/wrong_signature_name3042=== RUN TestExternalSignerErrors/invalid_signature_base643043=== PAUSE TestExternalSignerErrors/invalid_signature_base643044=== RUN TestExternalSignerErrors/wrong_signature_length3045=== PAUSE TestExternalSignerErrors/wrong_signature_length3046=== RUN TestExternalSignerErrors/program_error3047=== PAUSE TestExternalSignerErrors/program_error3048=== RUN TestExternalSignerErrors/null_signatures3049=== PAUSE TestExternalSignerErrors/null_signatures3050=== CONT TestExternalSignerErrors/invalid_JSON3051=== CONT TestExternalSignerErrors/missing_signatures3052=== CONT TestExternalSignerErrors/unrequested_key3053=== CONT TestExternalSignerErrors/wrong_signatures_shape3054=== CONT TestExternalSignerErrors/program_error3055=== CONT TestExternalSignerErrors/wrong_signature_length3056=== CONT TestExternalSignerErrors/null3057=== CONT TestExternalSignerErrors/null_signatures3058=== CONT TestExternalSignerErrors/invalid_signature_base643059=== CONT TestExternalSignerErrors/too_few_signatures3060=== CONT TestExternalSignerErrors/missing_signature_name3061=== CONT TestExternalSignerErrors/wrong_id3062=== CONT TestExternalSignerErrors/exit_on_request3063=== CONT TestExternalSignerErrors/wrong_signature_name3064=== CONT TestExternalSignerErrors/wrong_shape3065=== CONT TestExternalSignerErrors/exit_at_startup3066--- PASS: TestExternalSignerWrongPublicKey (0.21s)3067--- PASS: TestExternalSignerClose (0.40s)3068--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.59s)3069--- PASS: TestExternalSigner (0.80s)3070--- PASS: TestExternalSignerRestartsAfterCrash (0.99s)3071/private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestExternalSignerRestartsAfterCrash2138731562/001/sign program: line 7: /private/var/tb/6/scratch/e3c58ef3d7a98188/build/TestExternalSignerRestartsAfterCrash2138731562/001/sign program.starts: No such file or directory3072--- PASS: TestExternalSignerCancellation (1.17s)3073--- PASS: TestExternalSignerErrors (0.03s)3074 --- PASS: TestExternalSignerErrors/unrequested_key (1.33s)3075 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (1.50s)3076 --- PASS: TestExternalSignerErrors/missing_signature_name (1.68s)3077 --- PASS: TestExternalSignerErrors/too_few_signatures (1.88s)3078 --- PASS: TestExternalSignerErrors/exit_on_request (2.08s)3079 --- PASS: TestExternalSignerErrors/null_signatures (2.27s)3080 --- PASS: TestExternalSignerErrors/wrong_shape (2.45s)3081 --- PASS: TestExternalSignerErrors/missing_signatures (2.65s)3082 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (2.84s)3083 --- PASS: TestExternalSignerErrors/wrong_id (3.02s)3084 --- PASS: TestExternalSignerErrors/program_error (3.21s)3085 --- PASS: TestExternalSignerErrors/null (3.40s)3086 --- PASS: TestExternalSignerErrors/invalid_JSON (3.59s)3087 --- PASS: TestExternalSignerErrors/exit_at_startup (3.77s)3088 --- PASS: TestExternalSignerErrors/wrong_signature_length (3.96s)3089 --- PASS: TestExternalSignerErrors/wrong_signature_name (4.16s)3090PASS3091Running OpenBao signer tests...3092=== RUN TestSign3093=== PAUSE TestSign3094=== RUN TestSignErrors3095=== PAUSE TestSignErrors3096=== RUN TestServe3097=== PAUSE TestServe3098=== RUN TestServeRejectsGarbage3099=== PAUSE TestServeRejectsGarbage3100=== CONT TestServeRejectsGarbage3101=== CONT TestSign3102=== CONT TestSignErrors3103=== RUN TestSignErrors/http_error3104=== CONT TestServe3105--- PASS: TestServeRejectsGarbage (0.00s)3106=== PAUSE TestSignErrors/http_error3107=== RUN TestSignErrors/invalid_json3108=== PAUSE TestSignErrors/invalid_json3109=== RUN TestSignErrors/no_prefix3110=== PAUSE TestSignErrors/no_prefix3111=== RUN TestSignErrors/invalid_base643112=== PAUSE TestSignErrors/invalid_base643113=== CONT TestSignErrors/invalid_json3114=== CONT TestSignErrors/no_prefix3115=== CONT TestSignErrors/invalid_base643116--- PASS: TestServe (0.00s)3117=== CONT TestSignErrors/http_error3118--- PASS: TestSignErrors (0.00s)3119 --- PASS: TestSignErrors/invalid_json (0.00s)3120 --- PASS: TestSignErrors/no_prefix (0.00s)3121 --- PASS: TestSignErrors/http_error (0.00s)3122 --- PASS: TestSignErrors/invalid_base64 (0.01s)3123--- PASS: TestSign (0.01s)3124PASS3125Running niks3-hook command tests...3126=== RUN TestServeSecondSignalEndsDrain3127=== PAUSE TestServeSecondSignalEndsDrain3128=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown3129=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown3130=== CONT TestServeSecondSignalEndsDrain3131=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown3132--- PASS: TestServeSecondSignalEndsDrain (0.06s)31332026/10/25 19:49:16 INFO Upload queue status pending=131342026/10/25 19:49:16 INFO Uploading batch count=13135--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.12s)3136PASS3137Running rate limiter tests...3138=== RUN TestAdaptiveRateLimiter_ThreadSafety3139=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3140=== CONT TestAdaptiveRateLimiter_ThreadSafety31412026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=7031422026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=4931432026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=34.331442026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=24.00999999999999831452026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=16.80731462026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=11.76489999999999931472026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=8.2354331482026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=5.76480099999999931492026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531502026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531512026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531522026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=5.63678500000000131532026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531542026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531552026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531562026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531572026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531582026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531592026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531602026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531612026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531622026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=9.07809861035000631632026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=6.35466902724500431642026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531652026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531662026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531672026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531682026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531692026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531702026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531712026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531722026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=5.12435000000000131732026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531742026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531752026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531762026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531772026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531782026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531792026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531802026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531812026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531822026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531832026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531842026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531852026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531862026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531872026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531882026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531892026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531902026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531912026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531922026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531932026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531942026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531952026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531962026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=531972026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=8.25281691850000431982026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=5.77697184295000331992026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532002026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532012026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532022026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532032026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532042026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532052026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532062026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532072026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532082026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=8.25281691850000432092026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=5.77697184295000332102026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532112026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532122026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532132026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532142026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532152026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532162026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532172026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532182026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532192026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532202026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532212026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532222026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532232026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532242026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532252026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532262026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532272026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532282026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532292026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532302026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532312026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532322026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532332026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532342026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532352026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532362026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532372026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532382026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532392026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=532402026/10/25 19:49:17 WARN Rate limiter backed off name=test rate=53241--- PASS: TestAdaptiveRateLimiter_ThreadSafety (0.08s)3242PASS