niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #412
· 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_ProducerErrorIsNotEOF22=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF23=== RUN TestUploadMultipart_FailedPartBufferNotReused24=== PAUSE TestUploadMultipart_FailedPartBufferNotReused25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestUploadMultipart_SupersededByPeer28=== PAUSE TestUploadMultipart_SupersededByPeer29=== RUN TestDumpPathCaseHackMatchesNix30--- PASS: TestDumpPathCaseHackMatchesNix (0.10s)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.38s)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 TestScriptTokenDoesNotWaitForItsChildren135=== CONT TestRateLimiterFeedback136=== CONT TestDumpPathMatchesNix137=== RUN TestRateLimiterFeedback/429_enables_limiter138=== CONT TestParsePathInfoJSON139=== RUN TestParsePathInfoJSON/Nix_format140=== PAUSE TestParsePathInfoJSON/Nix_format141=== CONT TestStreamPushReportsSkippedPaths142=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer143=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess144=== CONT TestScriptTokenScriptFails145=== CONT TestCompletePendingClosure_NotFoundWithoutKey146=== CONT TestScriptTokenEmptyCommand147--- PASS: TestScriptTokenEmptyCommand (0.00s)148=== CONT TestEncodeNixBase32WithRealHash149=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent150=== CONT TestStreamPushIsolatesFailures151=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier152=== CONT TestGetStorePathHash153=== CONT TestStreamPushStopsWhenCanceled154=== RUN TestGetStorePathHash/valid_store_path155=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier156=== CONT TestClientSignaturesByStorePath157=== CONT TestEncodeNixBase32158=== RUN TestEncodeNixBase32/test_string_hash159=== CONT TestShellSplit160=== CONT TestStreamPushReportsSignatures161=== CONT TestConvertHashToNix32162=== RUN TestConvertHashToNix32/SRI_format_to_Nix32163=== CONT TestStreamPushRequestLine164=== CONT TestDumpPathWriterError165=== CONT TestStreamPushGivesUpOnDeadServer166=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs167=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica168=== PAUSE TestRateLimiterFeedback/429_enables_limiter169=== RUN TestRateLimiterFeedback/503_enables_limiter170=== RUN TestParsePathInfoJSON/Lix_format171=== CONT TestShellSplitErrors172--- PASS: TestEncodeNixBase32WithRealHash (0.00s)173=== CONT TestPathInfoCACompatibility174--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.00s)175=== RUN TestPathInfoCACompatibility/null_ca_field176--- PASS: TestClientSignaturesByStorePath (0.00s)177=== PAUSE TestPathInfoCACompatibility/null_ca_field178=== CONT TestDoWithRetry_BodyReplayedViaGetBody179=== CONT TestRetryTimeoutOutlastsMaxRetries180=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up181=== PAUSE TestGetStorePathHash/valid_store_path182=== CONT TestStreamPushBatchesUnderLoad183=== CONT TestStreamPushReportsEveryPath184=== PAUSE TestEncodeNixBase32/test_string_hash185=== CONT TestFileTokenReadsAndCaches186=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32187=== CONT TestScriptTokenEmptyToken188=== RUN TestGetStorePathHash/basename_without_hyphen_should_error189=== RUN TestStreamPushBatchesUnderLoad/together190=== RUN TestEncodeNixBase32/empty_input191=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs192=== PAUSE TestEncodeNixBase32/empty_input193=== PAUSE TestParsePathInfoJSON/Lix_format194=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout195=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout196=== CONT TestDoWithRetry_FinalResponseBodyReadable197=== RUN TestParsePathInfoJSON/empty_input198=== CONT TestScriptTokenCachesUntilRefresh199=== CONT TestStaticToken200=== CONT TestFileTokenMissing201=== PAUSE TestParsePathInfoJSON/empty_input202=== CONT TestPathInfoHashCompatibility203--- PASS: TestStreamPushStopsWhenCanceled (0.00s)204=== PAUSE TestRateLimiterFeedback/503_enables_limiter205--- PASS: TestStreamPushReportsSkippedPaths (0.00s)206=== RUN TestPathInfoCACompatibility/old_string_format_-_text207=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up208=== CONT TestSetClientTLSDoesNotMutateDefaultTransport209=== RUN TestConvertHashToNix32/already_Nix32_format210=== CONT TestScriptTokenBadJSON211=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error212=== PAUSE TestStreamPushBatchesUnderLoad/together213=== CONT TestScriptTokenNoExpiryRerunsEveryCall214=== RUN TestParsePathInfoJSON/whitespace_only215=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter216=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)217=== CONT TestFileTokenEmpty218--- PASS: TestShellSplit (0.00s)219=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error220=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text221=== CONT TestFilterOversizedClosures222=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier223=== PAUSE TestConvertHashToNix32/already_Nix32_format224=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time225=== PAUSE TestParsePathInfoJSON/whitespace_only226=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter227=== RUN TestFilterOversizedClosures/no_limit_keeps_everything228=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier229--- PASS: TestStreamPushIsolatesFailures (0.00s)230=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)231=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive232=== RUN TestConvertHashToNix32/invalid_format233=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time234=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter235=== CONT TestDumpPathSingleFile236=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error237=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error238=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client239=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client240=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client241=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything242=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client243--- PASS: TestStreamPushReportsSignatures (0.00s)244=== CONT TestPartSizeForNAR245--- PASS: TestShellSplitErrors (0.00s)246=== RUN TestPartSizeForNAR/zero_stays_at_minimum247=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped248--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)249=== CONT TestTruncatedNARDumpIsNotCompleted250--- PASS: TestScriptTokenScriptFails (0.00s)251=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon252=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon253--- PASS: TestStreamPushReportsEveryPath (0.00s)254=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive255=== RUN TestPathInfoCACompatibility/new_structured_format_-_text256=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI257--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)258=== PAUSE TestConvertHashToNix32/invalid_format259=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text260=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI261--- PASS: TestStaticToken (0.00s)262--- PASS: TestFileTokenReadsAndCaches (0.00s)263=== RUN TestParsePathInfoJSON/invalid_JSON264=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter265=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error266=== CONT TestRegisterUploadedObjectReusesConnections267=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum268=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped269--- PASS: TestFileTokenMissing (0.00s)270=== CONT TestSupersededNARStillUploadsListing271=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method272=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512273=== PAUSE TestParsePathInfoJSON/invalid_JSON274=== CONT TestStreamPushStopsOnCancel275=== RUN TestStreamPushStopsOnCancel/waiting_for_input276=== RUN TestSupersededNARStillUploadsListing/small_NAR277=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input278--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)279=== CONT TestUploadMultipart_PartsInParallel280--- PASS: TestFileTokenEmpty (0.01s)281=== CONT TestUploadMultipart_SupersededByPeer282--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.02s)283=== RUN TestUploadMultipart_SupersededByPeer/exists284=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512285=== PAUSE TestUploadMultipart_SupersededByPeer/exists286=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot287=== RUN TestUploadMultipart_SupersededByPeer/missing288=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun289--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)290=== CONT TestUploadMultipart_FailedPartBufferNotReused291=== RUN TestFilterOversizedClosures/all_closures_skipped292=== PAUSE TestFilterOversizedClosures/all_closures_skipped293=== RUN TestPartSizeForNAR/small_stays_at_minimum294=== PAUSE TestPartSizeForNAR/small_stays_at_minimum295=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method296=== CONT TestSetClientTLSErrors297=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure298=== CONT TestSetClientTLS299=== PAUSE TestSupersededNARStillUploadsListing/small_NAR300=== RUN TestSupersededNARStillUploadsListing/dump_cut_short301=== CONT TestUploadMultipart_ProducerErrorIsNotEOF302=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part303=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot304=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short305=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part306=== PAUSE TestUploadMultipart_SupersededByPeer/missing307=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot308=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails309=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails310=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary311=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum312=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum313=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts314=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary315=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts316=== CONT TestParsePathInfoJSONMultiplePaths317=== CONT TestCaseHackSuffix318=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot319=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot320=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot321=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot322=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot323=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken324=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken325=== RUN TestPartSizeForNAR/1_TiB326=== PAUSE TestPartSizeForNAR/1_TiB327=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths328=== CONT TestResolveStorePath329=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths330=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths331=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths332=== RUN TestPartSizeForNAR/5_TiB_S3_max_object333=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object334=== RUN TestPartSizeForNAR/capped_at_5_GiB335=== PAUSE TestPartSizeForNAR/capped_at_5_GiB336=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry337=== CONT TestDoServerRequestAttachesToken338--- PASS: TestResolveStorePath (0.00s)339=== CONT TestEncodeNixBase32/test_string_hash340=== CONT TestEncodeNixBase32/empty_input341--- PASS: TestEncodeNixBase32 (0.00s)342 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)343 --- PASS: TestEncodeNixBase32/empty_input (0.00s)344=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout345--- PASS: TestScriptTokenEmptyToken (0.02s)346=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs347=== CONT TestStreamPushBatchesUnderLoad/together348=== RUN TestSetClientTLSErrors/missing_cert_file349=== PAUSE TestSetClientTLSErrors/missing_cert_file350=== RUN TestSetClientTLSErrors/missing_key_file351--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)352=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time353=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier354--- PASS: TestScriptTokenBadJSON (0.02s)355=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client356=== PAUSE TestSetClientTLSErrors/missing_key_file357=== RUN TestSetClientTLSErrors/missing_ca_file358=== PAUSE TestSetClientTLSErrors/missing_ca_file359=== RUN TestSetClientTLSErrors/invalid_ca_file360=== PAUSE TestSetClientTLSErrors/invalid_ca_file361=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client362=== RUN TestSetClientTLS/rejects_connection_without_client_cert363=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert364=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA365=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA366=== RUN TestSetClientTLS/preserves_debug_logging_transport367=== PAUSE TestSetClientTLS/preserves_debug_logging_transport368=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up369=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier370=== CONT TestConvertHashToNix32/SRI_format_to_Nix32371=== CONT TestConvertHashToNix32/already_Nix32_format372--- PASS: TestStreamPushBatchesUnderLoad (0.01s)373 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)374 --- PASS: TestStreamPushBatchesUnderLoad/together (0.02s)375=== CONT TestConvertHashToNix32/invalid_format376=== CONT TestRateLimiterFeedback/429_enables_limiter377--- PASS: TestConvertHashToNix32 (0.01s)378 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)379 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)380 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)381=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter382--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.03s)383--- PASS: TestDoServerRequestAttachesToken (0.03s)384=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter385=== CONT TestGetStorePathHash/valid_store_path386=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error387=== CONT TestGetStorePathHash/basename_without_hyphen_should_error388=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error389=== CONT TestParsePathInfoJSON/Nix_format390=== CONT TestParsePathInfoJSON/invalid_JSON391--- PASS: TestGetStorePathHash (0.02s)392 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)393 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)394 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)395 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)396=== CONT TestParsePathInfoJSON/whitespace_only397=== CONT TestParsePathInfoJSON/empty_input398=== CONT TestParsePathInfoJSON/Lix_format399=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512400=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon401=== CONT TestRateLimiterFeedback/503_enables_limiter402--- PASS: TestParsePathInfoJSON (0.02s)403 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)404 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)405 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)406 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)407 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)408=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI409=== CONT TestFilterOversizedClosures/all_closures_skipped410=== CONT TestPathInfoCACompatibility/null_ca_field411=== CONT TestFilterOversizedClosures/no_limit_keeps_everything412=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)413=== CONT TestPathInfoCACompatibility/new_structured_format_-_text414=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method415--- PASS: TestPathInfoHashCompatibility (0.01s)416 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)417 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)418 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)419 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)420=== CONT TestPathInfoCACompatibility/old_string_format_-_text421=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive422=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped423=== CONT TestSupersededNARStillUploadsListing/dump_cut_short424=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails425--- PASS: TestFilterOversizedClosures (0.01s)426 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)427 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)428 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)429=== CONT TestUploadMultipart_SupersededByPeer/exists430--- PASS: TestPathInfoCACompatibility (0.02s)431 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)432 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)433 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)434 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)435 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)436=== CONT TestSupersededNARStillUploadsListing/small_NAR437=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary438--- PASS: TestScriptTokenCachesUntilRefresh (0.07s)439=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part440=== CONT TestUploadMultipart_SupersededByPeer/missing441=== CONT TestStreamPushStopsOnCancel/waiting_for_input442--- PASS: TestRateLimiterFeedback (0.03s)443 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)444 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)445 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)446 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.02s)447=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot448--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.02s)449 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.01s)450 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.02s)451 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.01s)452 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.02s)453 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.04s)454--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.08s)455=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken456--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)457 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.02s)458 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)459=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot460--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.08s)461=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot462=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot463=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths464=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths465=== CONT TestPartSizeForNAR/zero_stays_at_minimum466--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)467 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)468 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)469=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts470=== CONT TestPartSizeForNAR/capped_at_5_GiB471=== CONT TestPartSizeForNAR/1_TiB472=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum473=== CONT TestPartSizeForNAR/5_TiB_S3_max_object474=== CONT TestPartSizeForNAR/small_stays_at_minimum475=== CONT TestSetClientTLSErrors/missing_cert_file476--- PASS: TestPartSizeForNAR (0.01s)477 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)478 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)479 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)480 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)481 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)482 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)483 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)484=== CONT TestSetClientTLSErrors/invalid_ca_file485=== CONT TestSetClientTLSErrors/missing_key_file486=== CONT TestSetClientTLSErrors/missing_ca_file487=== CONT TestSetClientTLS/rejects_connection_without_client_cert488--- PASS: TestSetClientTLSErrors (0.02s)489 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)490 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)491 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)492 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)493--- PASS: TestDumpPathSingleFile (0.10s)494=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA495=== CONT TestSetClientTLS/preserves_debug_logging_transport496--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.00s)497 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.05s)498 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.06s)499--- PASS: TestStreamPushRequestLine (0.12s)500--- PASS: TestStreamPushStopsOnCancel (0.00s)501 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.05s)502 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.06s)503 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.06s)504 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)505 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.06s)506 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.05s)507--- PASS: TestCaseHackSuffix (0.14s)508--- PASS: TestSetClientTLS (0.03s)509 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)510 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)511 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.03s)512--- PASS: TestDumpPathWriterError (0.15s)513--- PASS: TestDumpPathMatchesNix (0.22s)514--- PASS: TestRegisterUploadedObjectReusesConnections (0.23s)515--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.23s)516--- PASS: TestTruncatedNARDumpIsNotCompleted (0.43s)517--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.68s)518--- PASS: TestUploadMultipart_PartsInParallel (0.69s)519--- PASS: TestSupersededNARStillUploadsListing (0.00s)520 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.04s)521 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.05s)522 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.70s)523--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)524--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)525--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.01s)526 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.03s)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 "_tribuchetbld2".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/2/scratch/6891134b3cadde62/build/postgres1664809635/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/2/scratch/6891134b3cadde62/build/postgres1664809635/data -l logfile start5565572026-10-11 06:50:19.536 UTC [316] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5582026-10-11 06:50:19.537 UTC [316] LOG: listening on Unix socket "/private/var/tb/2/scratch/6891134b3cadde62/build/postgres1664809635/.s.PGSQL.5432"5592026-10-11 06:50:19.539 UTC [323] LOG: database system was shut down at 2026-10-11 06:50:19 UTC5602026-10-11 06:50:19.539 UTC [324] FATAL: the database system is starting up561/private/var/tb/2/scratch/6891134b3cadde62/build/postgres1664809635:5432 - rejecting connections5622026-10-11 06:50:19.540 UTC [316] LOG: database system is ready to accept connections563/private/var/tb/2/scratch/6891134b3cadde62/build/postgres1664809635:5432 - accepting connections564{"timestamp":"2026-10-11T06:50:19.796543Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"02e662cd-3fff-4074-b66b-31f3ef305c7d","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":8,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(7)"}565{"timestamp":"2026-10-11T06:50:19.907778Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"0a9e231a-9879-4c56-be82-71e5d30e2ebc","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(3)"}566=== RUN TestService_AuthMiddleware567=== PAUSE TestService_AuthMiddleware568=== RUN TestService_AuthMiddleware_MTLSProxyHeader569=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader570=== RUN TestService_AuthMiddleware_MTLSBoundSubjects571=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects572=== RUN TestService_ReadAuthMiddleware573=== PAUSE TestService_ReadAuthMiddleware574=== RUN TestService_AuthMiddleware_OIDC575=== PAUSE TestService_AuthMiddleware_OIDC576=== RUN TestService_RequireScope_OIDC577=== PAUSE TestService_RequireScope_OIDC578=== RUN TestService_ReadScope_PublicByDefault579=== PAUSE TestService_ReadScope_PublicByDefault580=== RUN TestCacheConfigHandler581=== PAUSE TestCacheConfigHandler582=== RUN TestCacheStatsHandler583=== PAUSE TestCacheStatsHandler584=== RUN TestClientCADerivations585=== PAUSE TestClientCADerivations586=== RUN TestClientErrorHandling587=== PAUSE TestClientErrorHandling588=== RUN TestClientIntegration589=== PAUSE TestClientIntegration590=== RUN TestClientMultipleUploads591=== PAUSE TestClientMultipleUploads592=== RUN TestClientWithDependencies593=== PAUSE TestClientWithDependencies594=== RUN TestClientSharedPathCommittedMidPush595=== PAUSE TestClientSharedPathCommittedMidPush596=== RUN TestPinProtectsFromGC597=== PAUSE TestPinProtectsFromGC598=== RUN TestClientPushesUseOnePush599=== PAUSE TestClientPushesUseOnePush600=== RUN TestClientFallsBackToClosures601=== PAUSE TestClientFallsBackToClosures602=== RUN TestDeleteClosuresRacingPins603=== PAUSE TestDeleteClosuresRacingPins604=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock605=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock606=== RUN TestResolveDBConnectionString607=== PAUSE TestResolveDBConnectionString608=== RUN TestConnectWaitsForAPeerMigration609=== PAUSE TestConnectWaitsForAPeerMigration610=== RUN TestConnectSerialisesConcurrentMigrations611=== PAUSE TestConnectSerialisesConcurrentMigrations612=== RUN TestLeadElectsOneAndHandsOver613=== PAUSE TestLeadElectsOneAndHandsOver614=== RUN TestLeadIncumbentWinsAfterRestart6152026/10/11 06:50:20 INFO lead: acquired remote=192.0.2.1:12346162026/10/11 06:50:20 INFO lead: released remote=192.0.2.1:12346172026/10/11 06:50:20 INFO lead: acquired remote=192.0.2.1:12346182026/10/11 06:50:22 INFO lead: released remote=192.0.2.1:1234619--- PASS: TestLeadIncumbentWinsAfterRestart (2.06s)620=== RUN TestLeadIncumbentAnnouncesAtOnce621=== PAUSE TestLeadIncumbentAnnouncesAtOnce622=== RUN TestLeadEndsOnShutdown623=== PAUSE TestLeadEndsOnShutdown624=== RUN TestLeadEndsWhenItsConnectionHangs6252026/10/11 06:50:22 INFO lead: acquired remote=192.0.2.1:12346262026-10-11 06:50:23.436 UTC [360] FATAL: terminating connection due to administrator command6272026/10/11 06:50:23 INFO lead: acquired remote=192.0.2.1:12346282026/10/11 06:50:24 WARN lead: lock connection lost error="timeout: context deadline exceeded"6292026/10/11 06:50:24 INFO lead: released remote=192.0.2.1:12346302026/10/11 06:50:24 INFO lead: released remote=192.0.2.1:1234631--- PASS: TestLeadEndsWhenItsConnectionHangs (2.78s)632=== RUN TestGCAdvisoryLockBlocksConcurrentRun633=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun634=== RUN TestGCBugBareHashReferences635=== PAUSE TestGCBugBareHashReferences636=== RUN TestGCMetrics637=== PAUSE TestGCMetrics638=== RUN TestPushDedupSurvivesConcurrentGC639=== PAUSE TestPushDedupSurvivesConcurrentGC640=== RUN TestDeduplicatedObjectsRecordedAsPending641=== PAUSE TestDeduplicatedObjectsRecordedAsPending642=== RUN TestGCSweepSkipsPendingObjects643=== PAUSE TestGCSweepSkipsPendingObjects644=== RUN TestTombstonedObjectOfferedWithoutWaiting645=== PAUSE TestTombstonedObjectOfferedWithoutWaiting646=== RUN TestGCSweepDeliversEachKeyOnce647=== PAUSE TestGCSweepDeliversEachKeyOnce648=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection649=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection650=== RUN TestForceGCDuringPushOffersSweptObject651=== PAUSE TestForceGCDuringPushOffersSweptObject652=== RUN TestFailedS3DeleteKeepsTombstone653=== PAUSE TestFailedS3DeleteKeepsTombstone654=== RUN TestSweepSkipsRowsLockedByPush655=== PAUSE TestSweepSkipsRowsLockedByPush656=== RUN TestRegisterCompletedObjectNeedsPendingRow657=== PAUSE TestRegisterCompletedObjectNeedsPendingRow658=== RUN TestGetExistingObjectsLocksRows659=== PAUSE TestGetExistingObjectsLocksRows660=== RUN TestSweepRechecksPendingAfterLocking661=== PAUSE TestSweepRechecksPendingAfterLocking662=== RUN TestPushWaitsForSweepHoldingRow663=== PAUSE TestPushWaitsForSweepHoldingRow664=== RUN TestCommitRacingPendingCleanupKeepsObjects665=== PAUSE TestCommitRacingPendingCleanupKeepsObjects666=== RUN TestGCEndsOnShutdown667=== PAUSE TestGCEndsOnShutdown668=== RUN TestGCTaskStore_StartNew669=== PAUSE TestGCTaskStore_StartNew670=== RUN TestGCTaskStore_DeduplicateSameParams671=== PAUSE TestGCTaskStore_DeduplicateSameParams672=== RUN TestGCTaskStore_ConflictDifferentParams673=== PAUSE TestGCTaskStore_ConflictDifferentParams674=== RUN TestGCTaskStore_GetEmpty675=== PAUSE TestGCTaskStore_GetEmpty676=== RUN TestGCTaskStore_GetReturnsLatest677=== PAUSE TestGCTaskStore_GetReturnsLatest678=== RUN TestGCTaskStore_CompletedAllowsNewTask679=== PAUSE TestGCTaskStore_CompletedAllowsNewTask680=== RUN TestGCTaskStore_PhaseUpdates681=== PAUSE TestGCTaskStore_PhaseUpdates682=== RUN TestGCTaskStore_Fail683=== PAUSE TestGCTaskStore_Fail684=== RUN TestGracefulShutdownDrainsInflight685=== PAUSE TestGracefulShutdownDrainsInflight686=== RUN TestService_healthCheckHandler687=== PAUSE TestService_healthCheckHandler688=== RUN TestService_readinessHandler689=== PAUSE TestService_readinessHandler690=== RUN TestGenerateLandingPage691=== PAUSE TestGenerateLandingPage692=== RUN TestChildrenInheritRaisedFileLimit693=== PAUSE TestChildrenInheritRaisedFileLimit694=== RUN TestCacheConfigHandlerMaxNarSize695=== PAUSE TestCacheConfigHandlerMaxNarSize696=== RUN TestCreatePendingClosureRejectsOversizedNAR697=== PAUSE TestCreatePendingClosureRejectsOversizedNAR698=== RUN TestNARDeduplicationMetadataUploadBug699=== PAUSE TestNARDeduplicationMetadataUploadBug700=== RUN TestMetricsInventory701=== PAUSE TestMetricsInventory702=== RUN TestMetricsCommit703=== PAUSE TestMetricsCommit704=== RUN TestService_NativeMTLS705=== PAUSE TestService_NativeMTLS706=== RUN TestServerTLSConfig707=== PAUSE TestServerTLSConfig708=== RUN TestMultipartCleanup709=== PAUSE TestMultipartCleanup710=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded711=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded712=== RUN TestPendingCleanupUsesOneCutoff713=== PAUSE TestPendingCleanupUsesOneCutoff714=== RUN TestPendingClosureFailureTracksEveryUpload715=== PAUSE TestPendingClosureFailureTracksEveryUpload716=== RUN TestPendingClosureFailureAbortsItsUploads717=== PAUSE TestPendingClosureFailureAbortsItsUploads718=== RUN TestObjectStatsTrigger719=== PAUSE TestObjectStatsTrigger720=== RUN TestObjectStatsLargeCommit721=== PAUSE TestObjectStatsLargeCommit722=== RUN TestReconnectLeavesObjectsUnlocked723=== PAUSE TestReconnectLeavesObjectsUnlocked724=== RUN TestOrphanedObjectsGC725=== PAUSE TestOrphanedObjectsGC726=== RUN TestOrphanedObjectsGCStressTest727=== PAUSE TestOrphanedObjectsGCStressTest728=== RUN TestCreatePin_ReservedPins729=== PAUSE TestCreatePin_ReservedPins730=== RUN TestConcurrentPinUpdatesAgree731=== PAUSE TestConcurrentPinUpdatesAgree732=== RUN TestCreatePinRejectsBadInput733=== PAUSE TestCreatePinRejectsBadInput734=== RUN TestDeletePinKeepsRowWhenS3Fails735=== PAUSE TestDeletePinKeepsRowWhenS3Fails736=== RUN TestPresentReportsOnlyClosureRoots737=== PAUSE TestPresentReportsOnlyClosureRoots738=== RUN TestPresentRefreshesOnlyStaleClosures739=== PAUSE TestPresentRefreshesOnlyStaleClosures740=== RUN TestPresentNotReportedWhileGCDeletesClosure741=== PAUSE TestPresentNotReportedWhileGCDeletesClosure742=== RUN TestParseSingleRange743=== PAUSE TestParseSingleRange744=== RUN TestProxyHeadersOnlyTrustedOnSocket7452026/10/11 06:50:25 INFO Starting HTTP server address=127.0.0.1:602077462026/10/11 06:50:25 INFO Starting HTTP server address=proxy.sock7472026/10/11 06:50:25 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7482026/10/11 06:50:25 INFO Shutdown signal received, draining in-flight requests timeout=10s749--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.17s)750=== RUN TestIsValidCachePath751=== PAUSE TestIsValidCachePath752=== RUN TestReadProxyNarinfo753=== PAUSE TestReadProxyNarinfo754=== RUN TestReadProxyNarinfoAlreadyDecompressed755=== PAUSE TestReadProxyNarinfoAlreadyDecompressed756=== RUN TestReadProxyContentNegotiation757=== PAUSE TestReadProxyContentNegotiation758=== RUN TestReadProxyNarStreaming759=== PAUSE TestReadProxyNarStreaming760=== RUN TestReadProxy404761=== PAUSE TestReadProxy404762=== RUN TestReadProxyInvalidPath763=== PAUSE TestReadProxyInvalidPath764=== RUN TestReadProxyHead765=== PAUSE TestReadProxyHead766=== RUN TestReadProxyOutlastsServerWriteTimeout767=== PAUSE TestReadProxyOutlastsServerWriteTimeout768=== RUN TestReadProxyConditionalGet769=== PAUSE TestReadProxyConditionalGet770=== RUN TestReadProxyRootRedirectsToIndexHTML771=== PAUSE TestReadProxyRootRedirectsToIndexHTML772=== RUN TestReadProxyDisabled773=== PAUSE TestReadProxyDisabled774=== RUN TestReadRedirectNar775=== PAUSE TestReadRedirectNar776=== RUN TestReadRedirectKeepsNarinfoProxied777=== PAUSE TestReadRedirectKeepsNarinfoProxied778=== RUN TestReadProxyRangeRequest779=== PAUSE TestReadProxyRangeRequest780=== RUN TestReadRedirectUsesPublicS3URL781=== PAUSE TestReadRedirectUsesPublicS3URL782=== RUN TestPush_OverlappingRootsStoreOneRowPerKey783=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey784=== RUN TestPush_CompleteCommitsEveryRoot785=== PAUSE TestPush_CompleteCommitsEveryRoot786=== RUN TestPush_RepeatedRootCommitsOnce787=== PAUSE TestPush_RepeatedRootCommitsOnce788=== RUN TestPush_CompleteWaitsForCleanupOfThePush789=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush790=== RUN TestPush_RootsAreLockedInByteOrder791=== PAUSE TestPush_RootsAreLockedInByteOrder792=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit793=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit794=== RUN TestPush_RejectsBadRequests795=== PAUSE TestPush_RejectsBadRequests796=== RUN TestPush_SignsNarinfosOfItsPendingObjects797=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects798=== RUN TestRedundantMultipartUpload799=== PAUSE TestRedundantMultipartUpload800=== RUN TestCompleteMultipartUpload_ErrorButObjectExists801=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists802=== RUN TestCompletedNarNotReofferedAcrossClosures803=== PAUSE TestCompletedNarNotReofferedAcrossClosures804=== RUN TestPresignedUploadRegisteredBeforeCommit805=== PAUSE TestPresignedUploadRegisteredBeforeCommit806=== RUN TestService_Rustfstest807=== PAUSE TestService_Rustfstest808=== RUN TestParseSize809=== PAUSE TestParseSize810=== RUN TestSkippedUploadsHandler811=== PAUSE TestSkippedUploadsHandler812=== RUN TestSystemdListenerNotActivated813--- PASS: TestSystemdListenerNotActivated (0.00s)814=== RUN TestWatchdogBeatsWhenHealthy815--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)816=== RUN TestWatchdogSkipsWhenUnhealthy8172026/10/11 06:50:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8182026/10/11 06:50:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8192026/10/11 06:50:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8202026/10/11 06:50:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8212026/10/11 06:50:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8222026/10/11 06:50:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8232026/10/11 06:50:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8242026/10/11 06:50:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8252026/10/11 06:50:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8262026/10/11 06:50:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"827--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)828=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle829=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle830=== RUN TestProxyWriteTimeout831=== PAUSE TestProxyWriteTimeout832=== RUN TestPendingClosureWriteTimeout833=== PAUSE TestPendingClosureWriteTimeout834=== RUN TestIsValidUploadKey835=== PAUSE TestIsValidUploadKey836=== RUN TestUploadHandlersRejectInvalidKeys837=== PAUSE TestUploadHandlersRejectInvalidKeys838=== RUN TestUploadHandlersRejectOversizedBody839=== PAUSE TestUploadHandlersRejectOversizedBody840=== RUN TestService_cleanupPendingClosuresHandler841=== PAUSE TestService_cleanupPendingClosuresHandler842=== RUN TestService_createPendingClosureHandler843=== PAUSE TestService_createPendingClosureHandler844=== RUN TestService_verifyS3Integrity845=== PAUSE TestService_verifyS3Integrity846=== RUN TestCompleteMultipartUnregistered847=== PAUSE TestCompleteMultipartUnregistered848=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT849=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT850=== CONT TestReadProxyHead851=== CONT TestReadProxyNarinfoAlreadyDecompressed852=== CONT TestService_cleanupPendingClosuresHandler853=== CONT TestCompleteMultipartUpload_ErrorButObjectExists854=== CONT TestCompleteMultipartUnregistered855=== CONT TestReadRedirectKeepsNarinfoProxied856=== CONT TestReadProxyNarStreaming857=== CONT TestReadProxyContentNegotiation858=== CONT TestIsValidUploadKey859=== RUN TestIsValidUploadKey/narinfo860=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT861=== CONT TestService_createPendingClosureHandler862=== PAUSE TestIsValidUploadKey/narinfo863=== CONT TestService_AuthMiddleware_OIDC864=== RUN TestIsValidUploadKey/nar_zst865=== CONT TestService_verifyS3Integrity866=== CONT TestPush_OverlappingRootsStoreOneRowPerKey867=== CONT TestPendingClosureWriteTimeout868=== CONT TestReadProxyInvalidPath869=== CONT TestPush_RepeatedRootCommitsOnce870=== CONT TestProxyWriteTimeout871=== CONT TestPush_CompleteWaitsForCleanupOfThePush872=== RUN TestProxyWriteTimeout/narinfo873=== CONT TestSkippedUploadsHandler874=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle875=== CONT TestPush_SignsNarinfosOfItsPendingObjects876=== CONT TestParseSize877--- PASS: TestParseSize (0.00s)878=== CONT TestPush_RejectsBadRequests879=== CONT TestRedundantMultipartUpload880=== PAUSE TestIsValidUploadKey/nar_zst881=== RUN TestPendingClosureWriteTimeout/empty882=== PAUSE TestProxyWriteTimeout/narinfo883=== RUN TestIsValidUploadKey/nar_xz884=== PAUSE TestIsValidUploadKey/nar_xz885=== RUN TestProxyWriteTimeout/1_GiB_nar886=== PAUSE TestPendingClosureWriteTimeout/empty887=== RUN TestPendingClosureWriteTimeout/400_objects888=== RUN TestIsValidUploadKey/nar_plain889=== PAUSE TestProxyWriteTimeout/1_GiB_nar890=== PAUSE TestPendingClosureWriteTimeout/400_objects891=== PAUSE TestIsValidUploadKey/nar_plain892=== RUN TestPendingClosureWriteTimeout/670k_objects893=== RUN TestProxyWriteTimeout/10_GiB_nar894=== PAUSE TestPendingClosureWriteTimeout/670k_objects895=== RUN TestIsValidUploadKey/listing896=== PAUSE TestIsValidUploadKey/listing897=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline898=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline899=== RUN TestIsValidUploadKey/build_log900=== PAUSE TestIsValidUploadKey/build_log901=== RUN TestIsValidUploadKey/build_log_home-manager_file902=== PAUSE TestIsValidUploadKey/build_log_home-manager_file903=== RUN TestIsValidUploadKey/build_log_plus_in_name904=== PAUSE TestProxyWriteTimeout/10_GiB_nar905=== PAUSE TestIsValidUploadKey/build_log_plus_in_name906=== RUN TestIsValidUploadKey/build_log_question_mark907=== RUN TestProxyWriteTimeout/unknown_size908=== CONT TestService_Rustfstest909=== PAUSE TestProxyWriteTimeout/unknown_size910=== PAUSE TestIsValidUploadKey/build_log_question_mark911=== CONT TestUploadHandlersRejectInvalidKeys912=== RUN TestIsValidUploadKey/build_log_equals913=== PAUSE TestIsValidUploadKey/build_log_equals914=== RUN TestIsValidUploadKey/realisation915=== PAUSE TestIsValidUploadKey/realisation916=== RUN TestIsValidUploadKey/realisation_plus_in_output917=== PAUSE TestIsValidUploadKey/realisation_plus_in_output918=== RUN TestIsValidUploadKey/nix-cache-info919=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info920=== PAUSE TestIsValidUploadKey/nix-cache-info921=== RUN TestIsValidUploadKey/index.html922=== PAUSE TestIsValidUploadKey/index.html923=== RUN TestIsValidUploadKey/narinfo_key,_nar_type924=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type925=== RUN TestIsValidUploadKey/nar_key,_narinfo_type926=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type927=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info928=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal929=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal930=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key931=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key932=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key9332026/10/11 06:50:25 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000934=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key935=== CONT TestCompletedNarNotReofferedAcrossClosures936=== RUN TestIsValidUploadKey/listing_key,_narinfo_type937=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type938=== RUN TestIsValidUploadKey/traversal939=== PAUSE TestIsValidUploadKey/traversal940=== RUN TestIsValidUploadKey/traversal_nar941=== PAUSE TestIsValidUploadKey/traversal_nar942=== RUN TestIsValidUploadKey/absolute943=== PAUSE TestIsValidUploadKey/absolute944=== CONT TestPresignedUploadRegisteredBeforeCommit945=== RUN TestIsValidUploadKey/empty_key946=== PAUSE TestIsValidUploadKey/empty_key947=== RUN TestIsValidUploadKey/unknown_type948=== PAUSE TestIsValidUploadKey/unknown_type949--- PASS: TestSkippedUploadsHandler (0.04s)950=== CONT TestUploadHandlersRejectOversizedBody9512026/10/11 06:50:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60211/oidc952=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart953=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart954=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts955=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts956=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure957=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure958=== CONT TestPush_RootsAreLockedInByteOrder9592026/10/11 06:50:25 INFO Received uploads request method=POST path=/api/pending_closures960=== RUN TestPush_RejectsBadRequests/no_roots961=== PAUSE TestPush_RejectsBadRequests/no_roots962=== RUN TestPush_RejectsBadRequests/no_objects963=== PAUSE TestPush_RejectsBadRequests/no_objects964=== RUN TestPush_RejectsBadRequests/bad_root965=== PAUSE TestPush_RejectsBadRequests/bad_root966=== RUN TestPush_RejectsBadRequests/root_not_in_objects967=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects968=== CONT TestReadRedirectNar9692026/10/11 06:50:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9702026/10/11 06:50:26 INFO Received cleanup request method=DELETE path=/api/pending_closures9712026/10/11 06:50:26 INFO Aborted multipart uploads count=0 kept=09722026/10/11 06:50:26 INFO Received uploads request method=POST path=/api/pending_closures9732026/10/11 06:50:26 INFO Received cleanup request method=DELETE path=/api/pending_closures9742026/10/11 06:50:26 INFO Aborted multipart uploads count=1 kept=09752026/10/11 06:50:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9762026-10-11 06:50:26.691 UTC [419] ERROR: Closure does not exist: id=19772026-10-11 06:50:26.691 UTC [419] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9782026-10-11 06:50:26.691 UTC [419] STATEMENT: -- name: CommitPendingClosure :one979 SELECT commit_pending_closure($1::bigint)::bigint980 981--- PASS: TestService_cleanupPendingClosuresHandler (1.44s)982=== CONT TestReadRedirectUsesPublicS3URL983--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.59s)984=== CONT TestReadProxyRangeRequest985--- PASS: TestReadProxyNarStreaming (1.93s)986=== CONT TestPush_CompleteCommitsEveryRoot9872026/10/11 06:50:27 INFO Received uploads request method=POST path=/api/pending_closures9882026/10/11 06:50:27 INFO Received uploads request method=POST path=/api/pending_closures9892026/10/11 06:50:27 INFO Received uploads request method=POST path=/api/pending_closures9902026/10/11 06:50:27 INFO Received uploads request method=POST path=/api/pending_closures9912026/10/11 06:50:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9922026/10/11 06:50:28 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LjBkMWY1M2JkLTlkZWItNGMxMy04OTg1LWY2OTJkY2FhYzgzNHgxNzkxNzAxNDI3ODI3NzY3MDAw9932026/10/11 06:50:28 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LjBkMWY1M2JkLTlkZWItNGMxMy04OTg1LWY2OTJkY2FhYzgzNHgxNzkxNzAxNDI3ODI3NzY3MDAw error="Delete \"http://localhost:60189/bucket10/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LjBkMWY1M2JkLTlkZWItNGMxMy04OTg1LWY2OTJkY2FhYzgzNHgxNzkxNzAxNDI3ODI3NzY3MDAw\": injected: abort refused"9942026/10/11 06:50:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9952026/10/11 06:50:28 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LjBkMWY1M2JkLTlkZWItNGMxMy04OTg1LWY2OTJkY2FhYzgzNHgxNzkxNzAxNDI3ODI3NzY3MDAw996--- PASS: TestReadProxyContentNegotiation (2.89s)997=== CONT TestCommitRacingPendingCleanupKeepsObjects9982026/10/11 06:50:28 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LjBkMWY1M2JkLTlkZWItNGMxMy04OTg1LWY2OTJkY2FhYzgzNHgxNzkxNzAxNDI3ODI3NzY3MDAw parts=1999--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (3.00s)1000=== CONT TestConnectSerialisesConcurrentMigrations10012026/10/11 06:50:28 INFO Received uploads request method=POST path=/api/pending_closures10022026/10/11 06:50:28 INFO Received push request method=POST path=/api/pushes1003--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (3.49s)1004=== CONT TestReadProxyNarinfo10052026/10/11 06:50:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10062026/10/11 06:50:28 INFO Received push request method=POST path=/api/pushes10072026/10/11 06:50:29 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LjZjYWQ0YWZlLTQyNTgtNGIxZC05MjY3LTI2YmU3YWI1ZTNlOHgxNzkxNzAxNDI3NTk0NjcxMDAw parts=1010082026/10/11 06:50:29 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10092026/10/11 06:50:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10102026/10/11 06:50:29 INFO Completed upload id=1 objects=2 duration=19.673208ms10112026/10/11 06:50:29 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010122026/10/11 06:50:29 INFO Signed narinfos id=1 count=110132026/10/11 06:50:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10142026/10/11 06:50:29 INFO Received uploads request method=POST path=/api/pending_closures10152026/10/11 06:50:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10162026/10/11 06:50:29 INFO Starting cleanup of old closures method=DELETE path=/api/closures10172026/10/11 06:50:29 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10182026/10/11 06:50:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10192026/10/11 06:50:29 INFO Aborted multipart uploads count=0 kept=010202026/10/11 06:50:29 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10212026/10/11 06:50:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10222026/10/11 06:50:29 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110232026/10/11 06:50:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10242026/10/11 06:50:29 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo10252026/10/11 06:50:29 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=01026--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (3.83s)1027=== CONT TestIsValidCachePath1028=== RUN TestIsValidCachePath/narinfo1029=== PAUSE TestIsValidCachePath/narinfo1030=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1031=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1032=== RUN TestIsValidCachePath/nar_zst1033=== PAUSE TestIsValidCachePath/nar_zst1034=== RUN TestIsValidCachePath/nar_xz1035=== PAUSE TestIsValidCachePath/nar_xz1036=== RUN TestIsValidCachePath/nar_bz21037=== PAUSE TestIsValidCachePath/nar_bz21038=== RUN TestIsValidCachePath/nar_uncompressed1039=== PAUSE TestIsValidCachePath/nar_uncompressed1040=== RUN TestIsValidCachePath/ls1041=== PAUSE TestIsValidCachePath/ls1042=== RUN TestIsValidCachePath/log1043=== PAUSE TestIsValidCachePath/log1044=== RUN TestIsValidCachePath/realisation1045=== PAUSE TestIsValidCachePath/realisation1046=== RUN TestIsValidCachePath/nix-cache-info1047=== PAUSE TestIsValidCachePath/nix-cache-info1048=== RUN TestIsValidCachePath/index.html1049=== PAUSE TestIsValidCachePath/index.html1050=== RUN TestIsValidCachePath/traversal_parent1051=== PAUSE TestIsValidCachePath/traversal_parent10522026/10/11 06:50:29 INFO Vacuumed table table=pending_closures1053=== RUN TestIsValidCachePath/traversal_in_middle1054=== PAUSE TestIsValidCachePath/traversal_in_middle1055=== RUN TestIsValidCachePath/invalid_char_e1056=== PAUSE TestIsValidCachePath/invalid_char_e1057=== RUN TestIsValidCachePath/invalid_char_u1058=== PAUSE TestIsValidCachePath/invalid_char_u1059=== RUN TestIsValidCachePath/random_path1060=== PAUSE TestIsValidCachePath/random_path1061=== RUN TestIsValidCachePath/empty1062=== PAUSE TestIsValidCachePath/empty1063=== RUN TestIsValidCachePath/leading_slash1064=== PAUSE TestIsValidCachePath/leading_slash1065=== RUN TestIsValidCachePath/wrong_extension1066=== PAUSE TestIsValidCachePath/wrong_extension1067=== RUN TestIsValidCachePath/short_hash1068=== PAUSE TestIsValidCachePath/short_hash1069=== CONT TestParseSingleRange1070=== RUN TestParseSingleRange/none1071=== PAUSE TestParseSingleRange/none1072=== RUN TestParseSingleRange/unknown_unit1073=== PAUSE TestParseSingleRange/unknown_unit1074=== RUN TestParseSingleRange/multi-range_ignored1075=== PAUSE TestParseSingleRange/multi-range_ignored1076=== RUN TestParseSingleRange/malformed_no_dash1077=== PAUSE TestParseSingleRange/malformed_no_dash1078=== RUN TestParseSingleRange/malformed_both_empty1079=== PAUSE TestParseSingleRange/malformed_both_empty1080=== RUN TestParseSingleRange/malformed_end_before_start1081=== PAUSE TestParseSingleRange/malformed_end_before_start1082=== RUN TestParseSingleRange/closed1083=== PAUSE TestParseSingleRange/closed1084=== RUN TestParseSingleRange/open-ended1085=== PAUSE TestParseSingleRange/open-ended1086=== RUN TestParseSingleRange/end_clamped_to_size1087=== PAUSE TestParseSingleRange/end_clamped_to_size1088=== RUN TestParseSingleRange/suffix1089=== PAUSE TestParseSingleRange/suffix1090=== RUN TestParseSingleRange/suffix_exceeds_size1091=== PAUSE TestParseSingleRange/suffix_exceeds_size1092=== RUN TestParseSingleRange/single_byte1093=== PAUSE TestParseSingleRange/single_byte1094=== RUN TestParseSingleRange/start_past_EOF1095=== PAUSE TestParseSingleRange/start_past_EOF1096=== RUN TestParseSingleRange/start_far_past_EOF1097=== PAUSE TestParseSingleRange/start_far_past_EOF1098=== CONT TestReadProxy40410992026/10/11 06:50:29 INFO Vacuumed table table=pending_objects11002026/10/11 06:50:29 INFO Vacuumed table table=multipart_uploads11012026/10/11 06:50:29 INFO Vacuumed table table=closures11022026/10/11 06:50:29 INFO Vacuumed table table=objects11032026/10/11 06:50:29 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001104--- PASS: TestService_createPendingClosureHandler (3.98s)1105=== CONT TestPushWaitsForSweepHoldingRow11062026/10/11 06:50:29 INFO Received uploads request method=POST path=/api/pending_closures1107--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (4.08s)1108=== CONT TestPresentRefreshesOnlyStaleClosures11092026/10/11 06:50:29 INFO Received push request method=POST path=/api/pushes11102026/10/11 06:50:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11112026/10/11 06:50:29 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1112--- PASS: TestCompleteMultipartUnregistered (4.46s)1113=== CONT TestSweepRechecksPendingAfterLocking11142026/10/11 06:50:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11152026/10/11 06:50:29 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0Ljc1ZWE5ZDEzLWUzY2EtNDMzMC1hMDQwLTM0MmVlZDcwOTc5YngxNzkxNzAxNDI4Mzk0MTgxMDAw parts=1011162026/10/11 06:50:29 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11172026/10/11 06:50:29 INFO Completed upload id=1 objects=2 duration=19.637834ms11182026/10/11 06:50:29 INFO Received uploads request method=POST path=/api/pending_closures11192026/10/11 06:50:29 INFO Received uploads request method=POST path=/api/pending_closures11202026/10/11 06:50:29 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11212026/10/11 06:50:29 WARN Found objects in DB but missing from S3, will re-upload count=111222026/10/11 06:50:29 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete11232026/10/11 06:50:29 INFO Completed upload id=3 objects=2 duration=830.209µs1124--- PASS: TestService_verifyS3Integrity (4.68s)1125=== CONT TestPresentReportsOnlyClosureRoots1126--- PASS: TestReadRedirectKeepsNarinfoProxied (4.83s)1127=== CONT TestGCEndsOnShutdown1128=== RUN TestGCEndsOnShutdown/before_the_run1129=== PAUSE TestGCEndsOnShutdown/before_the_run1130=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1131=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1132=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1133=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1134=== CONT TestDeletePinKeepsRowWhenS3Fails11352026-10-11 06:50:30.255 UTC [486] ERROR: duplicate key value violates unique constraint "pg_class_relname_nsp_index"11362026-10-11 06:50:30.255 UTC [486] DETAIL: Key (relname, relnamespace)=(goose_db_version_id_seq, 2200) already exists.11372026-10-11 06:50:30.255 UTC [486] STATEMENT: CREATE TABLE goose_db_version (1138 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1139 version_id bigint NOT NULL,1140 is_applied boolean NOT NULL,1141 tstamp timestamp NOT NULL DEFAULT now()1142 )11432026/10/11 06:50:30 INFO Received uploads request method=POST path=/api/pending_closures11442026/10/11 06:50:30 INFO Received uploads request method=POST path=/api/pending_closures11452026/10/11 06:50:30 INFO Received uploads request method=POST path=/api/pending_closures11462026/10/11 06:50:30 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11472026/10/11 06:50:30 INFO Received uploads request method=POST path=/api/pending_closures1148=== CONT TestGetExistingObjectsLocksRows1149--- PASS: TestPresignedUploadRegisteredBeforeCommit (5.40s)1150=== CONT TestRegisterCompletedObjectNeedsPendingRow1151--- PASS: TestService_Rustfstest (5.61s)11522026/10/11 06:50:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11532026/10/11 06:50:31 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LmFlYzBiY2FmLTg5YjktNDcyNC1iYjgzLTMwODBmZDYwYzgxOHgxNzkxNzAxNDI5NTUwMDYzMDAw parts=101154--- PASS: TestReadProxyInvalidPath (5.95s)1155=== CONT TestCreatePinRejectsBadInput1156--- PASS: TestConnectSerialisesConcurrentMigrations (3.01s)1157=== CONT TestConcurrentPinUpdatesAgree11582026/10/11 06:50:31 WARN Rate limiter enabled after throttle name=s3-test rate=511592026/10/11 06:50:31 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1160=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1161 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101162 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001163--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.13s)1164=== CONT TestOrphanedObjectsGCStressTest11652026/10/11 06:50:31 INFO Received push request method=POST path=/api/pushes11662026/10/11 06:50:32 INFO Received uploads request method=POST path=/api/pending_closures11672026/10/11 06:50:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1168--- PASS: TestReadProxyHead (7.27s)1169=== CONT TestCreatePin_ReservedPins11702026/10/11 06:50:32 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LjNhNmY2YjE2LTM2YmItNGU0Ni05YjQxLTdlMTZjMWJlYmRjNXgxNzkxNzAxNDMwMzMxMjE2MDAw parts=1211712026/10/11 06:50:32 INFO Received uploads request method=POST path=/api/pending_closures11722026/10/11 06:50:32 INFO Received uploads request method=POST path=/api/pending_closures11732026/10/11 06:50:32 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60285/oidc1174=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1175=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1176=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1177=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1178=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1179=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1180=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1181=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1182=== CONT TestReconnectLeavesObjectsUnlocked11832026/10/11 06:50:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11842026/10/11 06:50:33 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LjgyMzc2MzAxLTRhMTUtNDJkNC04MmQyLTM4MTUwMzQ0MzE3NHgxNzkxNzAxNDI5NTQ5NjE2MDAw parts=1011852026/10/11 06:50:33 INFO Received complete push request method=POST path=/api/pushes/1/complete11862026/10/11 06:50:33 INFO Received push request method=POST path=/api/pushes11872026/10/11 06:50:33 INFO Completed push id=1 objects=4 duration=118.162292ms1188--- PASS: TestPush_RepeatedRootCommitsOnce (8.10s)1189=== CONT TestObjectStatsLargeCommit11902026/10/11 06:50:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11912026/10/11 06:50:33 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LjNkMWQ0M2ZlLTRhYzktNGM4MC04YzhlLTE4NjZmNjcxMzIwM3gxNzkxNzAxNDMxNjYxMDk2MDAw parts=101192--- PASS: TestReadRedirectUsesPublicS3URL (7.23s)1193=== CONT TestSweepSkipsRowsLockedByPush11942026-10-11 06:50:34.256 UTC [523] ERROR: Push does not exist: id=111952026-10-11 06:50:34.256 UTC [523] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE11962026-10-11 06:50:34.256 UTC [523] STATEMENT: SELECT commit_push($1)1197--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (9.02s)1198=== CONT TestObjectStatsTrigger1199--- PASS: TestReadProxyRangeRequest (7.48s)1200=== CONT TestOrphanedObjectsGC12012026/10/11 06:50:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1202=== CONT TestPendingClosureFailureTracksEveryUpload12032026/10/11 06:50:34 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LmZjYWRmZDdlLTk1MTktNDgwYi1hMTkyLTEyYmU0NDEzMmY5ZHgxNzkxNzAxNDMyMDkyOTkwMDAw parts=121204--- PASS: TestReadRedirectNar (8.62s)1205=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false12062026/10/11 06:50:34 INFO Received uploads request method=POST path=/api/pending_closures1207=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1208=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1209--- PASS: TestCompletedNarNotReofferedAcrossClosures (9.52s)1210=== CONT TestFailedS3DeleteKeepsTombstone1211=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1212=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection12132026/10/11 06:50:35 INFO Received push request method=POST path=/api/pushes12142026/10/11 06:50:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12152026/10/11 06:50:35 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LmEzMDhkMzg3LTk5OTQtNDIxZi1iNDQxLTdmZTE4NmNhMjI1OHgxNzkxNzAxNDMyNjM1MTA1MDAw error="Get \"http://127.0.0.1:1/bucket19/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12162026/10/11 06:50:35 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LjZkNzc0MTUwLWM0MWUtNDdlZS1hYmUzLWVmYjJiYWFmZjRmYXgxNzkxNzAxNDMyNTg5ODg5MDAw parts=1212172026/10/11 06:50:35 INFO Received cleanup request method=DELETE path=/api/pending_closures12182026/10/11 06:50:35 INFO Aborted multipart uploads count=1 kept=01219=== CONT TestGCSweepDeliversEachKeyOnce1220--- PASS: TestRedundantMultipartUpload (10.13s)12212026/10/11 06:50:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12222026/10/11 06:50:35 INFO Aborted multipart uploads count=0 kept=012232026/10/11 06:50:35 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LmVhYjNmZDI5LWY0YmEtNDIzOS1hNTMyLTE5NmE3YmNiNDlmMngxNzkxNzAxNDMzNDM0NDAwMDAw parts=1012242026/10/11 06:50:35 WARN Force mode enabled - objects will be deleted immediately without grace period12252026/10/11 06:50:35 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=012262026/10/11 06:50:35 INFO Vacuumed table table=pending_closures12272026/10/11 06:50:35 INFO Vacuumed table table=pending_objects12282026/10/11 06:50:35 INFO Vacuumed table table=multipart_uploads12292026/10/11 06:50:35 INFO Vacuumed table table=closures12302026/10/11 06:50:36 INFO Vacuumed table table=objects1231--- PASS: TestCommitRacingPendingCleanupKeepsObjects (7.89s)1232=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded12332026/10/11 06:50:36 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1234=== CONT TestTombstonedObjectOfferedWithoutWaiting1235--- PASS: TestReadProxyNarinfo (7.58s)12362026/10/11 06:50:36 INFO Received uploads request method=POST path=/api/pending_closures1237--- PASS: TestPushWaitsForSweepHoldingRow (7.71s)1238=== CONT TestPendingCleanupUsesOneCutoff12392026/10/11 06:50:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12402026/10/11 06:50:37 WARN Rate limiter enabled after throttle name=s3-test rate=512412026/10/11 06:50:37 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."12422026/10/11 06:50:37 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0Ljc3MWFlOGI4LTMxNzMtNDk0Ni04MDFlLTA2MTRiOWMxZTU0OHgxNzkxNzAxNDM1MjcwMTYyMDAw parts=1012432026/10/11 06:50:37 WARN Rate limiter backed off name=s3-test rate=512442026/10/11 06:50:37 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."1245=== CONT TestForceGCDuringPushOffersSweptObject1246--- PASS: TestReadProxy404 (8.07s)1247=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1248--- PASS: TestPresentRefreshesOnlyStaleClosures (7.91s)1249=== CONT TestMultipartCleanup1250=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1251=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1252=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1253=== CONT TestGCSweepSkipsPendingObjects12542026/10/11 06:50:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12552026/10/11 06:50:37 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LmNmZGQ2ZDY5LWU4OTItNDcwYS04NTBmLTgxY2Y2MzZmNjYwZHgxNzkxNzAxNDMzNDM0MDU5MDAw parts=1012562026/10/11 06:50:37 INFO Aborted multipart uploads count=0 kept=012572026/10/11 06:50:37 WARN Force mode enabled - objects will be deleted immediately without grace period12582026/10/11 06:50: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=012592026/10/11 06:50:37 INFO Vacuumed table table=pending_closures12602026/10/11 06:50:37 INFO Vacuumed table table=pending_objects12612026/10/11 06:50:37 INFO Vacuumed table table=multipart_uploads12622026/10/11 06:50:37 INFO Vacuumed table table=closures12632026/10/11 06:50:37 INFO Vacuumed table table=objects1264--- PASS: TestSweepRechecksPendingAfterLocking (8.18s)1265=== CONT TestServerTLSConfig1266=== RUN TestServerTLSConfig/no_client_CA1267=== PAUSE TestServerTLSConfig/no_client_CA1268=== RUN TestServerTLSConfig/missing_CA_file1269=== PAUSE TestServerTLSConfig/missing_CA_file1270=== RUN TestServerTLSConfig/not_a_PEM_file1271=== PAUSE TestServerTLSConfig/not_a_PEM_file1272=== CONT TestPushDedupSurvivesConcurrentGC1273--- PASS: TestPresentReportsOnlyClosureRoots (8.11s)1274=== CONT TestMetricsCommit12752026/10/11 06:50:38 INFO Received create pin request method=POST path=/api/pins/app12762026/10/11 06:50:38 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo12772026/10/11 06:50:38 INFO Received delete pin request method=DELETE path=/api/pins/app12782026/10/11 06:50:38 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket39/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12792026/10/11 06:50:38 INFO Received delete pin request method=DELETE path=/api/pins/app12802026/10/11 06:50:38 INFO Deleted pin name=app1281--- PASS: TestDeletePinKeepsRowWhenS3Fails (8.45s)1282=== CONT TestGCMetrics1283--- PASS: TestGetExistingObjectsLocksRows (8.15s)1284=== CONT TestMetricsInventory12852026/10/11 06:50:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12862026/10/11 06:50:39 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LjAzZDM3ZmEwLTk1NWQtNDMwZi1iZDI1LTU4NTg4MmVmNzA3OHgxNzkxNzAxNDM1MjcwODkxMDAw parts=101287--- PASS: TestRegisterCompletedObjectNeedsPendingRow (8.38s)1288=== CONT TestGCBugBareHashReferences12892026/10/11 06:50:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12902026/10/11 06:50:39 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LjI1YmU4MzI1LWZlMDAtNDc4MC1hZTFiLTI4ZTMwMTJhZjI2MXgxNzkxNzAxNDMzNDM0NDEyMDAw parts=1012912026/10/11 06:50:39 INFO Received create pin request method=POST path=/api/pins/deploy12922026/10/11 06:50:39 INFO Received create pin request method=POST path=/api/pins/deploy12932026/10/11 06:50:39 INFO Received create pin request method=POST path=/api/pins/deploy12942026/10/11 06:50:39 INFO Received create pin request method=POST path=/api/pins/deploy12952026/10/11 06:50:39 INFO Received create pin request method=POST path=/api/pins/deploy12962026/10/11 06:50:39 INFO Received create pin request method=POST path=/api/pins/deploy12972026/10/11 06:50:39 INFO Received create pin request method=POST path=/api/pins/deploy12982026/10/11 06:50:39 INFO Received create pin request method=POST path=/api/pins/deploy12992026/10/11 06:50:39 INFO Received create pin request method=POST path=/api/pins/deploy13002026/10/11 06:50:39 INFO Received create pin request method=POST path=/api/pins/deploy13012026/10/11 06:50:39 INFO Received create pin request method=POST path=/api/pins/app13022026/10/11 06:50:39 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo13032026/10/11 06:50:39 INFO Received create pin request method=POST path=/api/pins/app1304--- PASS: TestCreatePinRejectsBadInput (8.75s)1305=== CONT TestNARDeduplicationMetadataUploadBug13062026/10/11 06:50:40 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo13072026/10/11 06:50:40 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo1308=== CONT TestService_NativeMTLS1309--- PASS: TestConcurrentPinUpdatesAgree (9.30s)1310--- PASS: TestReconnectLeavesObjectsUnlocked (8.01s)1311=== CONT TestLeadEndsOnShutdown13122026/10/11 06:50:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13132026/10/11 06:50:41 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LmUxZWE0MjIyLTRiMTMtNDcwOS1iZDc2LTg5OWQxMmU1YzU3Y3gxNzkxNzAxNDM1MjcwODE5MDAw parts=1013142026/10/11 06:50:41 INFO Received complete push request method=POST path=/api/pushes/1/complete13152026/10/11 06:50:41 INFO Completed push id=1 objects=6 duration=33.262166ms13162026/10/11 06:50:41 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1317--- PASS: TestPush_CompleteCommitsEveryRoot (14.06s)1318=== CONT TestCreatePendingClosureRejectsOversizedNAR13192026/10/11 06:50:41 WARN Refused reserved pin name=worker-x86_64-linux13202026/10/11 06:50:41 INFO Received uploads request method=POST path=/api/pending_closures13212026/10/11 06:50:41 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1322--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1323=== CONT TestLeadIncumbentAnnouncesAtOnce13242026/10/11 06:50:41 INFO Received create pin request method=POST path=/api/pins/my-app13252026/10/11 06:50:41 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1326--- PASS: TestCreatePin_ReservedPins (8.77s)1327=== CONT TestLeadElectsOneAndHandsOver13282026/10/11 06:50:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13292026/10/11 06:50:41 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LjUyMWFiNTFmLTdiNzMtNDI2MC1iNjRmLTEzZDQxNTUzNzZhZXgxNzkxNzAxNDMzNDM0MzQ2MDAw parts=1013302026/10/11 06:50:42 INFO Aborted multipart uploads count=0 kept=013312026/10/11 06:50:42 WARN Force mode enabled - objects will be deleted immediately without grace period13322026/10/11 06:50: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=013332026/10/11 06:50:42 INFO Vacuumed table table=pending_closures13342026/10/11 06:50:42 INFO Vacuumed table table=pending_objects13352026/10/11 06:50:42 INFO Vacuumed table table=multipart_uploads13362026/10/11 06:50:42 INFO Vacuumed table table=closures13372026/10/11 06:50:42 INFO Vacuumed table table=objects13382026/10/11 06:50:42 INFO Aborted multipart uploads count=0 kept=013392026/10/11 06:50:42 WARN Force mode enabled - objects will be deleted immediately without grace period13402026/10/11 06:50:42 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=013412026/10/11 06:50:42 INFO Vacuumed table table=pending_closures13422026/10/11 06:50:42 INFO Vacuumed table table=pending_objects13432026/10/11 06:50:42 INFO Vacuumed table table=multipart_uploads13442026/10/11 06:50:42 INFO Vacuumed table table=closures13452026/10/11 06:50:42 INFO Vacuumed table table=objects1346--- PASS: TestSweepSkipsRowsLockedByPush (8.30s)1347=== CONT TestCacheConfigHandlerMaxNarSize1348--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1349=== CONT TestChildrenInheritRaisedFileLimit1350=== CONT TestDeduplicatedObjectsRecordedAsPending1351--- PASS: TestChildrenInheritRaisedFileLimit (0.01s)1352--- PASS: TestObjectStatsTrigger (8.11s)1353=== CONT TestGenerateLandingPage1354--- PASS: TestGenerateLandingPage (0.00s)1355=== CONT TestPendingClosureFailureAbortsItsUploads13562026/10/11 06:50:42 INFO Received uploads request method=POST path=/api/pending_closures13572026/10/11 06:50:43 INFO Aborted multipart uploads count=0 kept=013582026/10/11 06:50:43 WARN Force mode enabled - objects will be deleted immediately without grace period13592026/10/11 06:50:43 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."13602026/10/11 06:50:43 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1361--- PASS: TestFailedS3DeleteKeepsTombstone (8.39s)1362=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit13632026/10/11 06:50:43 INFO Received uploads request method=POST path=/api/pending_closures13642026/10/11 06:50:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13652026/10/11 06:50:43 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LjdjYzM5NDk2LTM5MDctNDE4YS05MDczLTBmNjIxNDViNmNlYXgxNzkxNzAxNDMzNDM0NDI0MDAw parts=101366=== NAME TestOrphanedObjectsGC1367 orphaned_objects_gc_test.go:287: GC Test Summary:1368 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1369 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1370 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1371 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1372 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1373--- PASS: TestOrphanedObjectsGC (9.21s)1374=== CONT TestService_readinessHandler1375--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (8.75s)1376=== CONT TestService_healthCheckHandler13772026/10/11 06:50:43 INFO Aborted multipart uploads count=0 kept=013782026/10/11 06:50:43 WARN Force mode enabled - objects will be deleted immediately without grace period13792026/10/11 06:50:43 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=013802026/10/11 06:50:43 INFO Vacuumed table table=pending_closures13812026/10/11 06:50:43 INFO Vacuumed table table=pending_objects13822026/10/11 06:50:43 INFO Vacuumed table table=multipart_uploads13832026/10/11 06:50:43 INFO Vacuumed table table=closures13842026/10/11 06:50:43 INFO Received uploads request method=POST path=/api/pending_closures13852026/10/11 06:50:43 INFO Vacuumed table table=objects1386--- PASS: TestGCSweepDeliversEachKeyOnce (8.60s)1387=== CONT TestGracefulShutdownDrainsInflight13882026/10/11 06:50:44 INFO Starting HTTP server address=127.0.0.1:6038013892026/10/11 06:50:44 INFO Shutdown signal received, draining in-flight requests timeout=10s1390--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (8.00s)1391=== CONT TestGCTaskStore_PhaseUpdates1392--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1393=== CONT TestGCTaskStore_Fail1394--- PASS: TestGCTaskStore_Fail (0.00s)1395=== CONT TestResolveDBConnectionString1396=== RUN TestResolveDBConnectionString/flag_wins1397=== PAUSE TestResolveDBConnectionString/flag_wins1398=== RUN TestResolveDBConnectionString/file_when_flag_empty1399--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1400=== CONT TestGCTaskStore_GetReturnsLatest1401=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1402--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1403=== RUN TestResolveDBConnectionString/missing_file_is_an_error1404=== CONT TestGCTaskStore_CompletedAllowsNewTask1405--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1406=== CONT TestGCTaskStore_GetEmpty1407--- PASS: TestGCTaskStore_GetEmpty (0.00s)1408=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1409=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1410=== CONT TestDeleteClosuresRacingPins1411=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1412=== RUN TestResolveDBConnectionString/nothing_configured1413=== PAUSE TestResolveDBConnectionString/nothing_configured1414=== CONT TestGCTaskStore_ConflictDifferentParams1415--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1416=== CONT TestClientFallsBackToClosures14172026/10/11 06:50:44 INFO Received uploads request method=POST path=/api/pending_closures1418--- PASS: TestTombstonedObjectOfferedWithoutWaiting (8.04s)1419=== CONT TestGCTaskStore_DeduplicateSameParams1420--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1421=== CONT TestConnectWaitsForAPeerMigration14222026/10/11 06:50:44 INFO Received uploads request method=POST path=/api/pending_closures14232026/10/11 06:50:44 INFO Received uploads request method=POST path=/api/pending_closures14242026/10/11 06:50:44 INFO Received cleanup request method=DELETE path=/api/pending_closures14252026/10/11 06:50:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14262026/10/11 06:50:44 INFO Received uploads request method=POST path=/api/pending_closures14272026/10/11 06:50:45 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LjBkODEwODgwLWNlMjQtNDQ4MS1hZTkyLTcyMGRmZDEyNTU3NHgxNzkxNzAxNDMzNDM0NDg1MDAw parts=1014282026-10-11 06:50:45.143 UTC [520] ERROR: could not obtain lock on row in relation "closures"14292026-10-11 06:50:45.143 UTC [520] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14302026-10-11 06:50:45.149 UTC [520] ERROR: could not obtain lock on row in relation "closures"14312026-10-11 06:50:45.149 UTC [520] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14322026-10-11 06:50:45.149 UTC [520] ERROR: could not obtain lock on row in relation "closures"14332026-10-11 06:50:45.149 UTC [520] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14342026-10-11 06:50:45.150 UTC [520] ERROR: could not obtain lock on row in relation "closures"14352026-10-11 06:50:45.150 UTC [520] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT14362026-10-11 06:50:45.158 UTC [520] ERROR: could not obtain lock on row in relation "closures"14372026-10-11 06:50:45.158 UTC [520] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1438--- PASS: TestPush_RootsAreLockedInByteOrder (19.71s)1439=== CONT TestGCTaskStore_StartNew1440--- PASS: TestGCTaskStore_StartNew (0.00s)1441=== CONT TestGCAdvisoryLockBlocksConcurrentRun14422026/10/11 06:50:45 INFO Received cleanup request method=DELETE path=/api/pending_closures14432026/10/11 06:50:45 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket57/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""14442026/10/11 06:50:45 INFO Aborted multipart uploads count=0 kept=114452026/10/11 06:50:45 INFO Received cleanup request method=DELETE path=/api/pending_closures14462026/10/11 06:50:45 INFO Aborted multipart uploads count=1 kept=014472026/10/11 06:50:45 INFO Received uploads request method=POST path=/api/pending_closures1448--- PASS: TestMultipartCleanup (8.03s)1449=== CONT TestClientPushesUseOnePush14502026/10/11 06:50:45 INFO Aborted multipart uploads count=0 kept=014512026/10/11 06:50:45 WARN Force mode enabled - objects will be deleted immediately without grace period14522026/10/11 06:50: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=014532026/10/11 06:50:45 INFO Vacuumed table table=pending_closures14542026/10/11 06:50:45 INFO Vacuumed table table=pending_objects14552026/10/11 06:50:45 INFO Vacuumed table table=multipart_uploads14562026/10/11 06:50:45 INFO Vacuumed table table=closures14572026/10/11 06:50:45 INFO Vacuumed table table=objects1458--- PASS: TestGCSweepSkipsPendingObjects (8.35s)1459=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock14602026/10/11 06:50:45 INFO Received uploads request method=POST path=/api/pending_closures14612026/10/11 06:50:45 INFO Aborted multipart uploads count=0 kept=014622026/10/11 06:50:45 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=014632026/10/11 06:50:45 INFO Vacuumed table table=pending_closures14642026/10/11 06:50:45 INFO Received push request method=POST path=/api/pushes14652026/10/11 06:50:45 INFO Vacuumed table table=pending_objects14662026/10/11 06:50:46 INFO Vacuumed table table=multipart_uploads14672026/10/11 06:50:46 INFO Vacuumed table table=closures14682026/10/11 06:50:46 INFO Vacuumed table table=objects14692026/10/11 06:50:46 INFO Aborted multipart uploads count=0 kept=014702026/10/11 06:50:46 WARN Force mode enabled - objects will be deleted immediately without grace period14712026/10/11 06:50:46 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=014722026/10/11 06:50:46 INFO Vacuumed table table=pending_closures14732026/10/11 06:50:46 INFO Vacuumed table table=pending_objects14742026/10/11 06:50:46 INFO Vacuumed table table=multipart_uploads14752026/10/11 06:50:46 INFO Vacuumed table table=closures14762026/10/11 06:50:46 INFO Vacuumed table table=objects1477--- PASS: TestPushDedupSurvivesConcurrentGC (8.31s)1478=== CONT TestPresentNotReportedWhileGCDeletesClosure1479=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1480=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1481=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1482=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1483=== CONT TestPinProtectsFromGC14842026/10/11 06:50:46 INFO Aborted multipart uploads count=0 kept=014852026/10/11 06:50:46 WARN Force mode enabled - objects will be deleted immediately without grace period14862026/10/11 06:50:46 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=014872026/10/11 06:50:46 INFO Vacuumed table table=pending_closures14882026/10/11 06:50:46 INFO Vacuumed table table=pending_objects14892026/10/11 06:50:46 INFO Vacuumed table table=multipart_uploads14902026/10/11 06:50:46 INFO Vacuumed table table=closures14912026/10/11 06:50:46 INFO Vacuumed table table=objects1492--- PASS: TestGCMetrics (7.99s)1493=== CONT TestClientSharedPathCommittedMidPush1494--- PASS: TestMetricsInventory (8.03s)1495=== CONT TestClientErrorHandling1496=== RUN TestClientErrorHandling/InvalidStorePath1497=== PAUSE TestClientErrorHandling/InvalidStorePath1498=== RUN TestClientErrorHandling/InvalidAuthToken1499=== PAUSE TestClientErrorHandling/InvalidAuthToken1500=== RUN TestClientErrorHandling/ServerNotAvailable1501=== PAUSE TestClientErrorHandling/ServerNotAvailable1502=== CONT TestClientMultipleUploads1503--- PASS: TestGCBugBareHashReferences (8.17s)1504=== CONT TestClientWithDependencies15052026/10/11 06:50:47 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15062026/10/11 06:50:47 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1507=== NAME TestNARDeduplicationMetadataUploadBug1508 metadata_upload_test.go:48: First store path: /private/var/tb/2/scratch/6891134b3cadde62/build/TestNARDeduplicationMetadataUploadBug3797725734/001/store/dpiiisbrim4d3smcchmz9hv54ii91k4h-file1.txt1509--- PASS: TestService_NativeMTLS (7.35s)1510=== CONT TestReadProxyRootRedirectsToIndexHTML15112026/10/11 06:50:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15122026/10/11 06:50:48 INFO Received push request method=POST path=/api/pushes15132026/10/11 06:50:48 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15142026/10/11 06:50:48 INFO Uploading dpiiisbrim4d3smcchmz9hv54ii91k4h-file1.txt (160B)15152026/10/11 06:50:48 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LjA1Njc0MDdjLTA2OTQtNDk4Ny1hMTY4LTFlOTE0Nzk1MjI3NHgxNzkxNzAxNDQ2MDE2NTE0MDAw parts=1015162026/10/11 06:50:48 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"15172026/10/11 06:50:48 WARN Failed to register uploaded object key=dpiiisbrim4d3smcchmz9hv54ii91k4h.ls error="server returned 404: 404 page not found\n"15182026/10/11 06:50:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15192026/10/11 06:50:48 INFO Signed narinfos id=1 count=115202026/10/11 06:50:48 INFO Uploading 1 narinfos15212026/10/11 06:50:48 INFO Received complete push request method=POST path=/api/pushes/1/complete15222026/10/11 06:50:48 WARN Failed to register uploaded object key=dpiiisbrim4d3smcchmz9hv54ii91k4h.narinfo error="server returned 404: 404 page not found\n"15232026/10/11 06:50:48 INFO Completed push id=1 objects=3 duration=30.208292ms15242026/10/11 06:50:48 INFO Upload complete. (326ms)1525=== NAME TestNARDeduplicationMetadataUploadBug15262026/10/11 06:50:48 INFO lead: acquired remote=192.0.2.1:12341527 metadata_upload_test.go:54: Retrieved narinfo from S3:1528 StorePath: /private/var/tb/2/scratch/6891134b3cadde62/build/TestNARDeduplicationMetadataUploadBug3797725734/001/store/dpiiisbrim4d3smcchmz9hv54ii91k4h-file1.txt1529 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1530 Compression: zstd1531 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1532 NarSize: 1601533 References: 1534 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1535 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1536 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1537 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1538=== NAME TestOrphanedObjectsGCStressTest1539 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1540=== NAME TestNARDeduplicationMetadataUploadBug1541 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/2/scratch/6891134b3cadde62/build/TestNARDeduplicationMetadataUploadBug3797725734/001/store/5z5as48f88ihajiy2zayp1njfhs8z3n3-file2.txt1542=== NAME TestOrphanedObjectsGCStressTest1543 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion15442026/10/11 06:50:48 INFO Received push request method=POST path=/api/pushes15452026/10/11 06:50:48 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)15462026/10/11 06:50:48 WARN Failed to register uploaded object key=5z5as48f88ihajiy2zayp1njfhs8z3n3.ls error="server returned 404: 404 page not found\n"15472026/10/11 06:50:48 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15482026/10/11 06:50:48 INFO Signed narinfos id=2 count=115492026/10/11 06:50:48 INFO Uploading 1 narinfos15502026/10/11 06:50:48 INFO lead: acquired remote=192.0.2.1:123415512026/10/11 06:50:48 INFO Received complete push request method=POST path=/api/pushes/2/complete15522026/10/11 06:50:48 WARN Failed to register uploaded object key=5z5as48f88ihajiy2zayp1njfhs8z3n3.narinfo error="server returned 404: 404 page not found\n"15532026/10/11 06:50:48 INFO Completed push id=2 objects=3 duration=769.375µs15542026/10/11 06:50:48 INFO Upload complete. (134ms)1555=== NAME TestNARDeduplicationMetadataUploadBug1556 metadata_upload_test.go:76: Retrieved narinfo from S3:1557 StorePath: /private/var/tb/2/scratch/6891134b3cadde62/build/TestNARDeduplicationMetadataUploadBug3797725734/001/store/5z5as48f88ihajiy2zayp1njfhs8z3n3-file2.txt1558 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1559 Compression: zstd1560 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1561 NarSize: 1601562 References: 1563 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1564 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1565 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1566 {"version":1,"root":{"type":"regular","size":44}}1567--- PASS: TestNARDeduplicationMetadataUploadBug (8.76s)1568=== CONT TestReadProxyDisabled15692026/10/11 06:50:48 INFO lead: acquired remote=192.0.2.1:123415702026/10/11 06:50:48 INFO lead: released remote=192.0.2.1:12341571--- PASS: TestLeadIncumbentAnnouncesAtOnce (7.69s)1572=== CONT TestReadProxyConditionalGet15732026/10/11 06:50:49 INFO Received uploads request method=POST path=/api/pending_closures15742026/10/11 06:50:49 INFO lead: released remote=192.0.2.1:12341575--- PASS: TestDeduplicatedObjectsRecordedAsPending (7.08s)1576=== CONT TestClientIntegration1577--- PASS: TestLeadEndsOnShutdown (8.45s)1578=== CONT TestCacheConfigHandler1579=== RUN TestCacheConfigHandler/full_config,_no_issuer1580=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1581=== RUN TestCacheConfigHandler/no_cache_url_configured1582=== PAUSE TestCacheConfigHandler/no_cache_url_configured1583=== RUN TestCacheConfigHandler/no_signing_keys1584=== PAUSE TestCacheConfigHandler/no_signing_keys1585=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1586=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1587=== CONT TestClientCADerivations15882026/10/11 06:50:49 INFO Received uploads request method=POST path=/api/pending_closures15892026/10/11 06:50:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1590--- PASS: TestPendingClosureFailureAbortsItsUploads (7.33s)1591=== CONT TestCacheStatsHandler15922026/10/11 06:50:49 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LjA1MmUxYzIxLTAyOGUtNDI5Zi05MjQ1LTMzNTUwMWQyNzVlM3gxNzkxNzAxNDQ2MDE3MjQ1MDAw parts=1015932026/10/11 06:50:49 INFO lead: released remote=192.0.2.1:123415942026/10/11 06:50:49 INFO Received complete push request method=POST path=/api/pushes/1/complete15952026/10/11 06:50:49 INFO lead: acquired remote=192.0.2.1:123415962026/10/11 06:50:49 INFO Completed push id=1 objects=4 duration=40.985625ms15972026/10/11 06:50:49 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15982026/10/11 06:50:49 INFO Completed upload id=2 objects=2 duration=974.042µs1599--- PASS: TestMetricsCommit (11.82s)1600=== CONT TestService_AuthMiddleware_MTLSBoundSubjects16012026/10/11 06:50:49 INFO Received push request method=POST path=/api/pushes1602--- PASS: TestService_healthCheckHandler (6.69s)1603=== CONT TestService_ReadScope_PublicByDefault16042026/10/11 06:50:50 WARN readiness check failed error="closed pool"1605--- PASS: TestService_readinessHandler (7.07s)1606=== CONT TestService_RequireScope_OIDC16072026/10/11 06:50:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60437/oidc16082026/10/11 06:50:50 INFO Aborted multipart uploads count=1 kept=016092026/10/11 06:50:50 INFO lead: released remote=192.0.2.1:123416102026/10/11 06:50:50 INFO Received cleanup request method=DELETE path=/api/pending_closures1611--- PASS: TestLeadElectsOneAndHandsOver (9.58s)1612=== CONT TestService_ReadAuthMiddleware16132026/10/11 06:50:50 INFO Aborted multipart uploads count=1 kept=01614--- PASS: TestPendingCleanupUsesOneCutoff (13.98s)1615=== CONT TestReadProxyOutlastsServerWriteTimeout16162026/10/11 06:50:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16172026/10/11 06:50:51 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LjA1MDBjOWIwLWUyMWEtNDdjOC1iNzY3LWJhMjJjOGEzMGFhYngxNzkxNzAxNDUwMDA1NjkzMDAw parts=1016182026/10/11 06:50:51 INFO Received uploads request method=POST path=/api/pending_closures16192026/10/11 06:50:51 INFO Received uploads request method=POST path=/api/pending_closures16202026/10/11 06:50:51 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16212026/10/11 06:50:51 INFO Uploading 1zgf25bb94ivg3lrn6a202bkdfdy6k1c-a (256B)16222026/10/11 06:50:51 INFO Uploading ljn7p5lnz6jz1g75h0b0g5d4cni4hyqj-shared-dep (136B)16232026/10/11 06:50:51 WARN Failed to register uploaded object key=n9sbn2r93bb8asj7mw9vngzpd6xcwdzx.ls error="server returned 404: 404 page not found\n"16242026/10/11 06:50:51 WARN Failed to register uploaded object key=ljn7p5lnz6jz1g75h0b0g5d4cni4hyqj.ls error="server returned 404: 404 page not found\n"16252026/10/11 06:50:51 WARN Failed to register uploaded object key=1zgf25bb94ivg3lrn6a202bkdfdy6k1c.ls error="server returned 404: 404 page not found\n"16262026/10/11 06:50:51 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16272026/10/11 06:50:51 WARN Failed to register uploaded object key=nar/1zc9p8vm158shn6y25cx3c09dxa7jpybl2cnhhb5zglad7d7k9sm.nar.zst error="server returned 404: 404 page not found\n"16282026/10/11 06:50:51 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16292026/10/11 06:50:51 INFO Signed narinfos id=1 count=216302026/10/11 06:50:51 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16312026/10/11 06:50:51 INFO Signed narinfos id=2 count=216322026/10/11 06:50:51 INFO Uploading 4 narinfos16332026/10/11 06:50:51 WARN Failed to register uploaded object key=ljn7p5lnz6jz1g75h0b0g5d4cni4hyqj.narinfo error="server returned 404: 404 page not found\n"16342026/10/11 06:50:51 WARN Failed to register uploaded object key=1zgf25bb94ivg3lrn6a202bkdfdy6k1c.narinfo error="server returned 404: 404 page not found\n"16352026/10/11 06:50:51 WARN Failed to register uploaded object key=n9sbn2r93bb8asj7mw9vngzpd6xcwdzx.narinfo error="server returned 404: 404 page not found\n"16362026/10/11 06:50:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16372026/10/11 06:50:51 WARN Failed to register uploaded object key=ljn7p5lnz6jz1g75h0b0g5d4cni4hyqj.narinfo error="server returned 404: 404 page not found\n"16382026/10/11 06:50:52 INFO Completed upload id=1 objects=6 duration=37.808875ms16392026/10/11 06:50:52 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16402026/10/11 06:50:52 INFO Completed upload id=2 objects=6 duration=633.583µs16412026/10/11 06:50:52 INFO Upload complete. (380ms)1642=== NAME TestClientFallsBackToClosures1643 client_pushes_test.go:112: Retrieved narinfo from S3:1644 StorePath: /private/var/tb/2/scratch/6891134b3cadde62/build/TestClientFallsBackToClosures1866991675/001/store/ljn7p5lnz6jz1g75h0b0g5d4cni4hyqj-shared-dep1645 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1646 Compression: zstd1647 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821648 NarSize: 1361649 References: 1650 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1651 client_pushes_test.go:112: Retrieved narinfo from S3:1652 StorePath: /private/var/tb/2/scratch/6891134b3cadde62/build/TestClientFallsBackToClosures1866991675/001/store/1zgf25bb94ivg3lrn6a202bkdfdy6k1c-a1653 URL: nar/1zc9p8vm158shn6y25cx3c09dxa7jpybl2cnhhb5zglad7d7k9sm.nar.zst1654 Compression: zstd1655 NarHash: sha256:1zc9p8vm158shn6y25cx3c09dxa7jpybl2cnhhb5zglad7d7k9sm1656--- PASS: TestObjectStatsLargeCommit (18.70s)1657=== CONT TestService_AuthMiddleware_MTLSProxyHeader1658=== NAME TestClientFallsBackToClosures1659 NarSize: 2561660 References: /private/var/tb/2/scratch/6891134b3cadde62/build/TestClientFallsBackToClosures1866991675/001/store/ljn7p5lnz6jz1g75h0b0g5d4cni4hyqj-shared-dep1661 CA: text:sha256:0cah7kbf6n2lnkfwx6sx6qsnajjcixd9x0a12f706x0hmmpnkncq1662 client_pushes_test.go:112: Retrieved narinfo from S3:1663 StorePath: /private/var/tb/2/scratch/6891134b3cadde62/build/TestClientFallsBackToClosures1866991675/001/store/n9sbn2r93bb8asj7mw9vngzpd6xcwdzx-b1664 URL: nar/1zc9p8vm158shn6y25cx3c09dxa7jpybl2cnhhb5zglad7d7k9sm.nar.zst1665 Compression: zstd1666 NarHash: sha256:1zc9p8vm158shn6y25cx3c09dxa7jpybl2cnhhb5zglad7d7k9sm1667 NarSize: 2561668 References: /private/var/tb/2/scratch/6891134b3cadde62/build/TestClientFallsBackToClosures1866991675/001/store/ljn7p5lnz6jz1g75h0b0g5d4cni4hyqj-shared-dep1669 CA: text:sha256:0cah7kbf6n2lnkfwx6sx6qsnajjcixd9x0a12f706x0hmmpnkncq1670--- PASS: TestClientFallsBackToClosures (8.17s)1671=== CONT TestService_AuthMiddleware1672=== NAME TestOrphanedObjectsGCStressTest1673 orphaned_objects_gc_test.go:503: Stress test completed successfully:1674 orphaned_objects_gc_test.go:504: - Active objects preserved: 201675 orphaned_objects_gc_test.go:505: - Objects deleted: 2101676 orphaned_objects_gc_test.go:506: - Total GC'd: 2101677--- PASS: TestOrphanedObjectsGCStressTest (21.19s)1678=== CONT TestPendingClosureWriteTimeout/empty1679=== CONT TestPendingClosureWriteTimeout/670k_objects1680=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline16812026/10/11 06:50:53 INFO Received push request method=POST path=/api/pushes16822026/10/11 06:50:53 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16832026/10/11 06:50:53 INFO Uploading vzybprj58fz5pa44dqgf7vg6pvpkjhkn-b (256B)16842026/10/11 06:50:53 INFO Uploading wmk1d8jymzj54qcfkicc88q51968lnnh-shared-dep (136B)1685=== NAME TestPinProtectsFromGC1686 client_integration_test.go:867: Pinned store path: /private/var/tb/2/scratch/6891134b3cadde62/build/TestPinProtectsFromGC51001059/001/store/3gzh1kxxhq4hwgng641f4xmlw5w6hd0m-pinned-file.txt1687 client_integration_test.go:868: Unpinned store path: /private/var/tb/2/scratch/6891134b3cadde62/build/TestPinProtectsFromGC51001059/001/store/62vvlm9dzc33ghpf8i2yarnpsmll6d6c-unpinned-file.txt16882026/10/11 06:50:53 WARN Failed to register uploaded object key=nar/06pd2zxz5x6av5rhmd5c74n381b95wkjh2mr758yvd4filkw66pw.nar.zst error="server returned 404: 404 page not found\n"16892026/10/11 06:50:53 WARN Failed to register uploaded object key=wmk1d8jymzj54qcfkicc88q51968lnnh.ls error="server returned 404: 404 page not found\n"16902026/10/11 06:50:53 WARN Failed to register uploaded object key=1y6wdqkkxjap1mhqls1lk70lmzxm2vam.ls error="server returned 404: 404 page not found\n"16912026/10/11 06:50:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16922026/10/11 06:50:53 WARN Failed to register uploaded object key=vzybprj58fz5pa44dqgf7vg6pvpkjhkn.ls error="server returned 404: 404 page not found\n"16932026/10/11 06:50:53 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16942026/10/11 06:50:53 INFO Signed narinfos id=1 count=316952026/10/11 06:50:53 INFO Uploading 3 narinfos16962026/10/11 06:50:53 WARN Failed to register uploaded object key=wmk1d8jymzj54qcfkicc88q51968lnnh.narinfo error="server returned 404: 404 page not found\n"16972026/10/11 06:50:53 WARN Failed to register uploaded object key=vzybprj58fz5pa44dqgf7vg6pvpkjhkn.narinfo error="server returned 404: 404 page not found\n"16982026/10/11 06:50:53 INFO Received complete push request method=POST path=/api/pushes/1/complete16992026/10/11 06:50:53 WARN Failed to register uploaded object key=1y6wdqkkxjap1mhqls1lk70lmzxm2vam.narinfo error="server returned 404: 404 page not found\n"17002026/10/11 06:50:53 INFO Completed push id=1 objects=8 duration=41.458042ms17012026/10/11 06:50:53 INFO Upload complete. (262ms)17022026/10/11 06:50:53 INFO Received push request method=POST path=/api/pushes1703=== NAME TestClientPushesUseOnePush1704 client_pushes_test.go:97: Retrieved narinfo from S3:1705 StorePath: /private/var/tb/2/scratch/6891134b3cadde62/build/TestClientPushesUseOnePush1723633066/001/store/wmk1d8jymzj54qcfkicc88q51968lnnh-shared-dep1706 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1707 Compression: zstd1708 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821709 NarSize: 1361710 References: 1711 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1712 client_pushes_test.go:97: Retrieved narinfo from S3:1713 StorePath: /private/var/tb/2/scratch/6891134b3cadde62/build/TestClientPushesUseOnePush1723633066/001/store/1y6wdqkkxjap1mhqls1lk70lmzxm2vam-a1714 URL: nar/06pd2zxz5x6av5rhmd5c74n381b95wkjh2mr758yvd4filkw66pw.nar.zst1715 Compression: zstd1716 NarHash: sha256:06pd2zxz5x6av5rhmd5c74n381b95wkjh2mr758yvd4filkw66pw1717 NarSize: 2561718 References: /private/var/tb/2/scratch/6891134b3cadde62/build/TestClientPushesUseOnePush1723633066/001/store/wmk1d8jymzj54qcfkicc88q51968lnnh-shared-dep1719 CA: text:sha256:0n8hn1h4d7d494fsk74jn30ngf95w5pqs39y8sql129d2bbsanab1720 client_pushes_test.go:97: Retrieved narinfo from S3:1721 StorePath: /private/var/tb/2/scratch/6891134b3cadde62/build/TestClientPushesUseOnePush1723633066/001/store/vzybprj58fz5pa44dqgf7vg6pvpkjhkn-b1722 URL: nar/06pd2zxz5x6av5rhmd5c74n381b95wkjh2mr758yvd4filkw66pw.nar.zst1723 Compression: zstd1724 NarHash: sha256:06pd2zxz5x6av5rhmd5c74n381b95wkjh2mr758yvd4filkw66pw1725 NarSize: 2561726 References: /private/var/tb/2/scratch/6891134b3cadde62/build/TestClientPushesUseOnePush1723633066/001/store/wmk1d8jymzj54qcfkicc88q51968lnnh-shared-dep1727 CA: text:sha256:0n8hn1h4d7d494fsk74jn30ngf95w5pqs39y8sql129d2bbsanab1728--- PASS: TestConnectWaitsForAPeerMigration (8.91s)17292026/10/11 06:50:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1730=== CONT TestPendingClosureWriteTimeout/400_objects17312026/10/11 06:50:53 INFO Uploading 3gzh1kxxhq4hwgng641f4xmlw5w6hd0m-pinned-file.txt (128B)1732=== CONT TestProxyWriteTimeout/1_GiB_nar1733=== CONT TestProxyWriteTimeout/unknown_size1734=== CONT TestProxyWriteTimeout/10_GiB_nar1735=== CONT TestProxyWriteTimeout/narinfo1736--- PASS: TestProxyWriteTimeout (0.02s)1737 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1738 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1739 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1740 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1741=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17422026/10/11 06:50:53 INFO Received uploads request method=POST path=/1743=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17442026/10/11 06:50:53 INFO Received request for more parts method=POST path=/1745=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17462026/10/11 06:50:53 INFO Received complete multipart upload request method=POST path=/1747=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17482026/10/11 06:50:53 INFO Received uploads request method=POST path=/1749=== CONT TestIsValidUploadKey/narinfo1750--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)1751 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1752 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1753 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1754 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1755=== CONT TestIsValidUploadKey/unknown_type1756=== CONT TestIsValidUploadKey/empty_key1757=== CONT TestIsValidUploadKey/build_log_equals1758=== CONT TestIsValidUploadKey/traversal_nar1759=== CONT TestIsValidUploadKey/traversal1760=== CONT TestIsValidUploadKey/absolute17612026/10/11 06:50:53 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17622026/10/11 06:50:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1763=== CONT TestIsValidUploadKey/listing_key,_narinfo_type17642026/10/11 06:50:53 WARN Failed to register uploaded object key=3gzh1kxxhq4hwgng641f4xmlw5w6hd0m.ls error="server returned 404: 404 page not found\n"1765=== CONT TestIsValidUploadKey/narinfo_key,_nar_type17662026/10/11 06:50:53 INFO Signed narinfos id=1 count=11767=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1768=== CONT TestIsValidUploadKey/nix-cache-info17692026/10/11 06:50:53 INFO Uploading 1 narinfos1770=== CONT TestIsValidUploadKey/index.html1771=== CONT TestIsValidUploadKey/realisation1772=== CONT TestIsValidUploadKey/build_log1773=== CONT TestIsValidUploadKey/realisation_plus_in_output1774=== CONT TestIsValidUploadKey/build_log_question_mark1775=== CONT TestIsValidUploadKey/build_log_plus_in_name1776--- PASS: TestClientPushesUseOnePush (8.04s)1777=== CONT TestIsValidUploadKey/build_log_home-manager_file1778=== CONT TestIsValidUploadKey/listing1779=== CONT TestIsValidUploadKey/nar_plain1780=== CONT TestIsValidUploadKey/nar_xz1781=== CONT TestIsValidUploadKey/nar_zst1782=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17832026/10/11 06:50:53 INFO Received complete push request method=POST path=/api/pushes/1/complete1784=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure1785--- PASS: TestIsValidUploadKey (0.05s)1786 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1787 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1788 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1789 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1790 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1791 --- PASS: TestIsValidUploadKey/traversal (0.00s)1792 --- PASS: TestIsValidUploadKey/absolute (0.01s)1793 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1794 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1795 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1796 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1797 --- PASS: TestIsValidUploadKey/index.html (0.00s)1798 --- PASS: TestIsValidUploadKey/realisation (0.00s)1799 --- PASS: TestIsValidUploadKey/build_log (0.00s)1800 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1801 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1802 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1803 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1804 --- PASS: TestIsValidUploadKey/listing (0.00s)1805 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1806 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1807 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)18082026/10/11 06:50:53 WARN Failed to register uploaded object key=3gzh1kxxhq4hwgng641f4xmlw5w6hd0m.narinfo error="server returned 404: 404 page not found\n"18092026/10/11 06:50:53 INFO Received request for more parts method=POST path=/18102026/10/11 06:50:53 INFO Received uploads request method=POST path=/18112026/10/11 06:50:53 INFO Completed push id=1 objects=3 duration=32.503791ms18122026/10/11 06:50:53 INFO Upload complete. (280ms)18132026/10/11 06:50:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18142026/10/11 06:50:53 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LmJhYWUxZDRlLTY0YjItNDk0Yi1iNjQ1LWE1Mzc2ZTJjYWE2M3gxNzkxNzAxNDUwMDA2MDQ3MDAw parts=1018152026/10/11 06:50:53 INFO Received complete push request method=POST path=/api/pushes/1/complete18162026/10/11 06:50:53 INFO Completed push id=1 objects=4 duration=21.19475ms18172026/10/11 06:50:53 INFO Received push request method=POST path=/api/pushes18182026/10/11 06:50:53 INFO Received push request method=POST path=/api/pushes18192026/10/11 06:50:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18202026/10/11 06:50:53 INFO Uploading 62vvlm9dzc33ghpf8i2yarnpsmll6d6c-unpinned-file.txt (128B)18212026/10/11 06:50:53 INFO Received push request method=POST path=/api/pushes18222026/10/11 06:50:53 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18232026/10/11 06:50:53 WARN Failed to register uploaded object key=62vvlm9dzc33ghpf8i2yarnpsmll6d6c.ls error="server returned 404: 404 page not found\n"18242026/10/11 06:50:53 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18252026/10/11 06:50:53 INFO Signed narinfos id=2 count=118262026/10/11 06:50:53 INFO Uploading 1 narinfos18272026/10/11 06:50:53 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)18282026/10/11 06:50:53 INFO Uploading 6d94s3pmksv7flzh0y7mjam63saj3nbs-shared-dep (136B)18292026/10/11 06:50:53 INFO Uploading ncaiz4adnvdb18d2psg6446s1yrnzgiw-top (264B)18302026/10/11 06:50:53 INFO Received complete push request method=POST path=/api/pushes/2/complete18312026/10/11 06:50:53 WARN Failed to register uploaded object key=62vvlm9dzc33ghpf8i2yarnpsmll6d6c.narinfo error="server returned 404: 404 page not found\n"18322026/10/11 06:50:53 INFO Aborted multipart uploads count=0 kept=018332026/10/11 06:50:53 INFO Completed push id=2 objects=3 duration=854.542µs18342026/10/11 06:50:53 INFO Upload complete. (191ms)18352026/10/11 06:50:53 WARN Force mode enabled - objects will be deleted immediately without grace period18362026/10/11 06:50:53 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18372026/10/11 06:50:53 WARN Failed to register uploaded object key=nar/0lqp8qhs54l0ilrlcfi1h5p22zmjkwhbl7bp2lh0karcz8327n83.nar.zst error="server returned 404: 404 page not found\n"18382026/10/11 06:50:53 WARN Failed to register uploaded object key=6d94s3pmksv7flzh0y7mjam63saj3nbs.ls error="server returned 404: 404 page not found\n"18392026/10/11 06:50:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18402026/10/11 06:50:53 WARN Failed to register uploaded object key=ncaiz4adnvdb18d2psg6446s1yrnzgiw.ls error="server returned 404: 404 page not found\n"18412026/10/11 06:50:53 INFO Signed narinfos id=1 count=218422026/10/11 06:50:53 INFO Uploading 2 narinfos1843=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18442026/10/11 06:50:53 INFO Received complete multipart upload request method=POST path=/18452026/10/11 06:50:53 INFO Starting cleanup of old closures method=DELETE path=/api/closures18462026/10/11 06:50:53 INFO Garbage collection started18472026/10/11 06:50:53 WARN Failed to register uploaded object key=6d94s3pmksv7flzh0y7mjam63saj3nbs.narinfo error="server returned 404: 404 page not found\n"18482026/10/11 06:50:53 INFO Received complete push request method=POST path=/api/pushes/1/complete18492026/10/11 06:50:53 WARN Failed to register uploaded object key=ncaiz4adnvdb18d2psg6446s1yrnzgiw.narinfo error="server returned 404: 404 page not found\n"18502026/10/11 06:50:53 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=018512026/10/11 06:50:53 INFO Aborted multipart uploads count=0 kept=018522026/10/11 06:50:53 WARN Force mode enabled - objects will be deleted immediately without grace period18532026/10/11 06:50:53 INFO Completed push id=1 objects=6 duration=37.950458ms18542026/10/11 06:50:53 INFO Upload complete. (306ms)1855=== NAME TestClientMultipleUploads1856 client_integration_test.go:480: Created store path 0: /private/var/tb/2/scratch/6891134b3cadde62/build/TestClientMultipleUploads3360784019/001/store/8ya5bjnnss8a7wakmm0qz4r8py458r7s-test-file-0.txt18572026/10/11 06:50:53 INFO Vacuumed table table=pending_closures1858=== NAME TestClientSharedPathCommittedMidPush1859 client_integration_test.go:816: Retrieved narinfo from S3:1860 StorePath: /private/var/tb/2/scratch/6891134b3cadde62/build/TestClientSharedPathCommittedMidPush1849238371/001/store/6d94s3pmksv7flzh0y7mjam63saj3nbs-shared-dep1861 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1862 Compression: zstd1863 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821864 NarSize: 1361865 References: 1866 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1867 client_integration_test.go:816: Retrieved narinfo from S3:1868 StorePath: /private/var/tb/2/scratch/6891134b3cadde62/build/TestClientSharedPathCommittedMidPush1849238371/001/store/ncaiz4adnvdb18d2psg6446s1yrnzgiw-top1869 URL: nar/0lqp8qhs54l0ilrlcfi1h5p22zmjkwhbl7bp2lh0karcz8327n83.nar.zst1870 Compression: zstd1871 NarHash: sha256:0lqp8qhs54l0ilrlcfi1h5p22zmjkwhbl7bp2lh0karcz8327n831872 NarSize: 2641873 References: /private/var/tb/2/scratch/6891134b3cadde62/build/TestClientSharedPathCommittedMidPush1849238371/001/store/6d94s3pmksv7flzh0y7mjam63saj3nbs-shared-dep1874 CA: text:sha256:1llzwbl1j3gan747032rjrd5xm0an2pgwl9ryx65vzrwbh66vyvn18752026/10/11 06:50:53 INFO Vacuumed table table=pending_objects18762026/10/11 06:50:53 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=018772026/10/11 06:50:53 INFO Vacuumed table table=multipart_uploads1878=== NAME TestClientMultipleUploads1879 client_integration_test.go:480: Created store path 1: /private/var/tb/2/scratch/6891134b3cadde62/build/TestClientMultipleUploads3360784019/001/store/fisscd1x60bws0y96zikblml6ypgnzhj-test-file-1.txt18802026/10/11 06:50:53 INFO Vacuumed table table=pending_closures1881--- PASS: TestClientSharedPathCommittedMidPush (7.42s)1882=== CONT TestPush_RejectsBadRequests/no_roots18832026/10/11 06:50:54 INFO Received push request method=POST path=/api/pushes1884=== CONT TestPush_RejectsBadRequests/bad_root18852026/10/11 06:50:54 INFO Received push request method=POST path=/api/pushes1886=== CONT TestPush_RejectsBadRequests/root_not_in_objects18872026/10/11 06:50:54 INFO Received push request method=POST path=/api/pushes1888=== CONT TestPush_RejectsBadRequests/no_objects18892026/10/11 06:50:54 INFO Vacuumed table table=closures18902026/10/11 06:50:54 INFO Received push request method=POST path=/api/pushes1891=== CONT TestIsValidCachePath/narinfo1892=== CONT TestIsValidCachePath/short_hash1893=== CONT TestIsValidCachePath/wrong_extension18942026/10/11 06:50:54 INFO Vacuumed table table=pending_objects1895=== CONT TestIsValidCachePath/leading_slash1896=== CONT TestIsValidCachePath/empty1897=== CONT TestIsValidCachePath/ls1898=== CONT TestIsValidCachePath/nar_uncompressed1899=== CONT TestIsValidCachePath/nar_bz21900=== CONT TestIsValidCachePath/log1901=== CONT TestIsValidCachePath/nar_zst1902=== CONT TestIsValidCachePath/random_path1903=== CONT TestIsValidCachePath/invalid_char_e19042026/10/11 06:50:54 INFO Vacuumed table table=multipart_uploads1905=== CONT TestIsValidCachePath/realisation1906=== CONT TestIsValidCachePath/nix-cache-info1907=== CONT TestIsValidCachePath/invalid_char_u1908=== CONT TestIsValidCachePath/index.html1909=== CONT TestIsValidCachePath/nar_xz1910=== CONT TestIsValidCachePath/traversal_in_middle1911=== CONT TestIsValidCachePath/traversal_parent1912=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars19132026/10/11 06:50:54 INFO Vacuumed table table=objects1914=== CONT TestParseSingleRange/malformed_no_dash1915=== CONT TestParseSingleRange/closed1916=== CONT TestParseSingleRange/start_far_past_EOF1917=== CONT TestParseSingleRange/start_past_EOF1918--- PASS: TestIsValidCachePath (0.06s)1919 --- PASS: TestIsValidCachePath/narinfo (0.00s)1920 --- PASS: TestIsValidCachePath/short_hash (0.00s)1921 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1922 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1923 --- PASS: TestIsValidCachePath/empty (0.00s)1924 --- PASS: TestIsValidCachePath/ls (0.00s)1925 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1926 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1927 --- PASS: TestIsValidCachePath/log (0.00s)1928 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1929 --- PASS: TestIsValidCachePath/random_path (0.00s)1930 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1931 --- PASS: TestIsValidCachePath/realisation (0.00s)1932 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1933 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1934 --- PASS: TestIsValidCachePath/index.html (0.00s)1935 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1936 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1937 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1938 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1939=== CONT TestParseSingleRange/suffix_exceeds_size1940=== CONT TestParseSingleRange/single_byte19412026/10/11 06:50:54 INFO Vacuumed table table=closures1942=== CONT TestParseSingleRange/suffix1943=== CONT TestParseSingleRange/open-ended1944=== CONT TestParseSingleRange/malformed_both_empty1945=== CONT TestParseSingleRange/malformed_end_before_start1946=== CONT TestParseSingleRange/unknown_unit1947=== CONT TestParseSingleRange/end_clamped_to_size1948=== CONT TestParseSingleRange/multi-range_ignored1949=== CONT TestParseSingleRange/none1950=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1951=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1952--- PASS: TestParseSingleRange (0.01s)1953 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1954 --- PASS: TestParseSingleRange/closed (0.00s)1955 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1956 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1957 --- PASS: TestParseSingleRange/single_byte (0.00s)1958 --- PASS: TestParseSingleRange/suffix (0.00s)1959 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1960 --- PASS: TestParseSingleRange/open-ended (0.00s)1961 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1962 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1963 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1964 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1965 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1966 --- PASS: TestParseSingleRange/none (0.00s)1967=== NAME TestClientMultipleUploads19682026/10/11 06:50:54 INFO Vacuumed table table=objects1969 client_integration_test.go:480: Created store path 2: /private/var/tb/2/scratch/6891134b3cadde62/build/TestClientMultipleUploads3360784019/001/store/isq1vah1h2c9bknbhxwg9df4wpmbnns6-test-file-2.txt1970--- PASS: TestPush_RejectsBadRequests (1.03s)1971 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1972 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1973 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1974 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)19752026/10/11 06:50:54 INFO Received push request method=POST path=/api/pushes1976--- PASS: TestReadProxyRootRedirectsToIndexHTML (6.29s)1977=== CONT TestGCEndsOnShutdown/before_the_run19782026/10/11 06:50:54 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)19792026/10/11 06:50:54 INFO Uploading 8ya5bjnnss8a7wakmm0qz4r8py458r7s-test-file-0.txt (160B)19802026/10/11 06:50:54 INFO Uploading fisscd1x60bws0y96zikblml6ypgnzhj-test-file-1.txt (160B)19812026/10/11 06:50:54 INFO Uploading isq1vah1h2c9bknbhxwg9df4wpmbnns6-test-file-2.txt (160B)19822026/10/11 06:50:54 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"1983=== NAME TestClientWithDependencies1984 client_integration_test.go:735: Built derivation: /private/var/tb/2/scratch/6891134b3cadde62/build/TestClientWithDependencies2993367045/001/store/k704ckg126sd8bs518mm5al1is8f9g8v-test-script19852026/10/11 06:50:54 WARN Failed to register uploaded object key=8ya5bjnnss8a7wakmm0qz4r8py458r7s.ls error="server returned 404: 404 page not found\n"19862026/10/11 06:50:54 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"19872026/10/11 06:50:54 WARN Failed to register uploaded object key=isq1vah1h2c9bknbhxwg9df4wpmbnns6.ls error="server returned 404: 404 page not found\n"19882026/10/11 06:50:54 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"19892026/10/11 06:50:54 WARN Failed to register uploaded object key=fisscd1x60bws0y96zikblml6ypgnzhj.ls error="server returned 404: 404 page not found\n"19902026/10/11 06:50:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19912026/10/11 06:50:54 INFO Signed narinfos id=1 count=319922026/10/11 06:50:54 INFO Uploading 3 narinfos19932026/10/11 06:50:54 WARN Failed to register uploaded object key=8ya5bjnnss8a7wakmm0qz4r8py458r7s.narinfo error="server returned 404: 404 page not found\n"19942026/10/11 06:50:54 WARN Failed to register uploaded object key=fisscd1x60bws0y96zikblml6ypgnzhj.narinfo error="server returned 404: 404 page not found\n"19952026/10/11 06:50:54 INFO Received complete push request method=POST path=/api/pushes/1/complete1996 client_integration_test.go:737: Found 1 dependencies (including self)19972026/10/11 06:50:54 WARN Failed to register uploaded object key=isq1vah1h2c9bknbhxwg9df4wpmbnns6.narinfo error="server returned 404: 404 page not found\n"19982026/10/11 06:50:54 INFO Completed push id=1 objects=9 duration=21.367ms19992026/10/11 06:50:54 INFO Upload complete. (278ms)2000=== NAME TestClientMultipleUploads2001 client_integration_test.go:491: Uploaded 3 paths in 336.303792ms20022026/10/11 06:50:54 INFO Received push request method=POST path=/api/pushes2003--- PASS: TestReadProxyDisabled (5.83s)20042026/10/11 06:50:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)2005=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token20062026/10/11 06:50:54 INFO Uploading k704ckg126sd8bs518mm5al1is8f9g8v-test-script (136B)2007=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20082026/10/11 06:50:54 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]2009--- PASS: TestClientMultipleUploads (7.66s)2010=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2011=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2012=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true20132026/10/11 06:50:54 WARN Authentication failed token_preview=eyJhbGciOi...K4F-GQ-S4Q token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2014=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false20152026/10/11 06:50:54 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"20162026/10/11 06:50:54 WARN Failed to register uploaded object key=k704ckg126sd8bs518mm5al1is8f9g8v.ls error="server returned 404: 404 page not found\n"20172026/10/11 06:50:54 WARN Failed to register uploaded object key=log/wk6971b3xfpklj5mxpl2w2c4lbmyk6pb-test-script.drv error="server returned 404: 404 page not found\n"20182026/10/11 06:50:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20192026/10/11 06:50:54 INFO Signed narinfos id=1 count=120202026/10/11 06:50:54 INFO Uploading 1 narinfos2021--- PASS: TestService_AuthMiddleware_OIDC (7.74s)2022 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2023 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.01s)2024 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2025 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)20262026/10/11 06:50:54 INFO Received complete push request method=POST path=/api/pushes/1/complete20272026/10/11 06:50:54 WARN Failed to register uploaded object key=k704ckg126sd8bs518mm5al1is8f9g8v.narinfo error="server returned 404: 404 page not found\n"20282026-10-11 06:50:54.780 UTC [321] LOG: checkpoint starting: wal20292026/10/11 06:50:54 INFO Completed push id=1 objects=4 duration=114.314291ms20302026/10/11 06:50:54 INFO Upload complete. (428ms)20312026/10/11 06:50:54 INFO Aborted multipart uploads count=0 kept=02032--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (9.25s)2033=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check20342026/10/11 06:50:54 WARN Force mode enabled - objects will be deleted immediately without grace period20352026/10/11 06:50:54 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=020362026/10/11 06:50:54 INFO Vacuumed table table=pending_closures2037--- PASS: TestReadProxyConditionalGet (6.07s)2038=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows20392026/10/11 06:50:55 INFO Vacuumed table table=pending_objects20402026/10/11 06:50:55 INFO Vacuumed table table=multipart_uploads20412026/10/11 06:50:55 INFO Vacuumed table table=closures20422026/10/11 06:50:55 INFO Vacuumed table table=objects2043=== NAME TestClientWithDependencies2044 client_integration_test.go:753: Skipping nix copy test - isolated store (/private/var/tb/2/scratch/6891134b3cadde62/build/TestClientWithDependencies2993367045/001/store) requires matching store prefix2045--- PASS: TestClientWithDependencies (7.77s)2046=== CONT TestServerTLSConfig/missing_CA_file2047=== CONT TestServerTLSConfig/not_a_PEM_file2048=== CONT TestServerTLSConfig/no_client_CA2049=== CONT TestResolveDBConnectionString/flag_wins2050--- PASS: TestServerTLSConfig (0.01s)2051 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2052 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)2053 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2054=== CONT TestResolveDBConnectionString/missing_file_is_an_error2055=== CONT TestResolveDBConnectionString/nothing_configured2056=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2057=== CONT TestResolveDBConnectionString/file_when_flag_empty2058=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh2059--- PASS: TestResolveDBConnectionString (0.04s)2060 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2061 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2062 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2063 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2064 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2065=== NAME TestClientIntegration2066 client_integration_test.go:334: Created store path: /private/var/tb/2/scratch/6891134b3cadde62/build/TestClientIntegration1783007146/002/store/a0ww6syp93idh9mbmbd34p9xk02dcc8f-test-file.txt20672026/10/11 06:50:55 INFO Received push request method=POST path=/api/pushes20682026/10/11 06:50:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20692026/10/11 06:50:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20702026/10/11 06:50:55 INFO Uploading a0ww6syp93idh9mbmbd34p9xk02dcc8f-test-file.txt (152B)20712026/10/11 06:50:55 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"20722026/10/11 06:50:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20732026/10/11 06:50:55 WARN Failed to register uploaded object key=a0ww6syp93idh9mbmbd34p9xk02dcc8f.ls error="server returned 404: 404 page not found\n"20742026/10/11 06:50:55 INFO Signed narinfos id=1 count=120752026/10/11 06:50:55 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LjI5OTBjMjgwLWYwMDMtNDE1OC05NTA1LWFmNDBmM2ZhNGJlZngxNzkxNzAxNDUzNTY0NDIwMDAw parts=1020762026/10/11 06:50:55 INFO Received complete push request method=POST path=/api/pushes/2/complete20772026/10/11 06:50:55 INFO Uploading 1 narinfos20782026/10/11 06:50:55 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020792026/10/11 06:50:55 INFO Completed push id=2 objects=4 duration=1.67ms20802026/10/11 06:50:55 INFO Received create pin request method=POST path=/api/pins/myapp2081--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (12.54s)2082=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale20832026/10/11 06:50:55 INFO Received complete push request method=POST path=/api/pushes/1/complete20842026/10/11 06:50:55 WARN Failed to register uploaded object key=a0ww6syp93idh9mbmbd34p9xk02dcc8f.narinfo error="server returned 404: 404 page not found\n"20852026/10/11 06:50:55 INFO Created/updated pin name=myapp store_path=/private/var/tb/2/scratch/6891134b3cadde62/build/TestPinProtectsFromGC51001059/001/store/3gzh1kxxhq4hwgng641f4xmlw5w6hd0m-pinned-file.txt narinfo_key=3gzh1kxxhq4hwgng641f4xmlw5w6hd0m.narinfo20862026/10/11 06:50:55 INFO Starting cleanup of old closures method=DELETE path=/api/closures20872026/10/11 06:50:55 INFO Garbage collection started20882026/10/11 06:50:55 INFO Aborted multipart uploads count=0 kept=020892026/10/11 06:50:55 INFO Completed push id=1 objects=3 duration=32.860834ms20902026/10/11 06:50:55 INFO Upload complete. (207ms)20912026/10/11 06:50:55 WARN Force mode enabled - objects will be deleted immediately without grace period20922026/10/11 06:50:55 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=020932026/10/11 06:50:55 INFO Vacuumed table table=pending_closures20942026/10/11 06:50:55 INFO Vacuumed table table=pending_objects20952026/10/11 06:50:55 INFO Vacuumed table table=multipart_uploads20962026/10/11 06:50:55 INFO Vacuumed table table=closures20972026/10/11 06:50:55 INFO Vacuumed table table=objects20982026/10/11 06:50:55 INFO All 1 paths already cached2099=== NAME TestClientIntegration2100 client_integration_test.go:360: Retrieved narinfo from S3:2101 StorePath: /private/var/tb/2/scratch/6891134b3cadde62/build/TestClientIntegration1783007146/002/store/a0ww6syp93idh9mbmbd34p9xk02dcc8f-test-file.txt2102 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2103 Compression: zstd2104 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12105 NarSize: 1522106 References: 2107 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12108 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)2109 client_integration_test.go:361: Decompressed .ls content (64 bytes):2110 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2111--- PASS: TestCacheStatsHandler (6.25s)2112=== CONT TestClientErrorHandling/ServerNotAvailable21132026/10/11 06:50:56 INFO Received push request method=POST path=/api/pushes21142026/10/11 06:50:56 INFO Object in database but missing from S3 key=a0ww6syp93idh9mbmbd34p9xk02dcc8f.ls21152026/10/11 06:50:56 WARN Found objects in DB but missing from S3, will re-upload count=121162026/10/11 06:50:56 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21172026/10/11 06:50:56 WARN Failed to register uploaded object key=a0ww6syp93idh9mbmbd34p9xk02dcc8f.ls error="server returned 404: 404 page not found\n"21182026/10/11 06:50:56 INFO Received complete push request method=POST path=/api/pushes/2/complete21192026/10/11 06:50:56 INFO Completed push id=2 objects=3 duration=1.284167ms21202026/10/11 06:50:56 INFO Upload complete. (131ms)2121=== NAME TestClientIntegration2122 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)2123 client_integration_test.go:389: Decompressed .ls content (49 bytes):2124 {"version":1,"root":{"type":"regular","size":39}}2125--- PASS: TestDeleteClosuresRacingPins (12.11s)2126=== CONT TestClientErrorHandling/InvalidAuthToken21272026/10/11 06:50:56 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21282026/10/11 06:50:56 WARN mTLS auth: bound subjects configured but subject DN unavailable21292026/10/11 06:50:56 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2130--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (6.41s)2131=== CONT TestClientErrorHandling/InvalidStorePath2132=== NAME TestClientCADerivations21332026/10/11 06:50:56 INFO Received push request method=POST path=/api/pushes2134 client_ca_test.go:136: Built CA derivation: /private/var/tb/2/scratch/6891134b3cadde62/build/TestClientCADerivations4098654634/001/store/lzd53g302gfnhisz3ndnmmdivbdqcy79-ca-test21352026/10/11 06:50:56 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21362026/10/11 06:50:56 INFO Received complete push request method=POST path=/api/pushes/3/complete21372026/10/11 06:50:56 WARN Failed to register uploaded object key=a0ww6syp93idh9mbmbd34p9xk02dcc8f.ls error="server returned 404: 404 page not found\n"21382026/10/11 06:50:56 INFO Completed push id=3 objects=3 duration=1.168708ms21392026/10/11 06:50:56 INFO Upload complete. (117ms)2140=== NAME TestClientIntegration2141 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)2142 client_integration_test.go:405: Decompressed .ls content (49 bytes):2143 {"version":1,"root":{"type":"regular","size":39}}21442026/10/11 06:50:56 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2145=== NAME TestClientCADerivations2146 client_ca_test.go:139: Found 1 dependencies (including self)21472026/10/11 06:50:56 WARN Request failed, retrying attempt=2 backoff=193.018441ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21482026/10/11 06:50:56 INFO Received push request method=POST path=/api/pushes21492026/10/11 06:50:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21502026/10/11 06:50:56 INFO Uploading lzd53g302gfnhisz3ndnmmdivbdqcy79-ca-test (144B)21512026/10/11 06:50:56 INFO Received push request method=POST path=/api/pushes21522026/10/11 06:50:56 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21532026/10/11 06:50:56 INFO Uploading 53a3l32ysagkkaj20rqkdpbbabs44wfv-lost-commit.txt (152B)21542026/10/11 06:50:56 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"2155--- PASS: TestService_ReadScope_PublicByDefault (6.32s)2156=== CONT TestCacheConfigHandler/full_config,_no_issuer2157=== CONT TestCacheConfigHandler/no_signing_keys21582026/10/11 06:50:56 WARN Failed to register uploaded object key=lzd53g302gfnhisz3ndnmmdivbdqcy79.ls error="server returned 404: 404 page not found\n"2159=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator21602026/10/11 06:50:56 WARN Failed to register uploaded object key=log/qnr03yndm2z9bnpmdys0rmr51iqjcflm-ca-test.drv error="server returned 404: 404 page not found\n"2161=== CONT TestCacheConfigHandler/no_cache_url_configured2162--- PASS: TestCacheConfigHandler (0.01s)2163 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2164 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2165 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2166 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)21672026/10/11 06:50:56 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21682026/10/11 06:50:56 INFO Signed narinfos id=1 count=121692026/10/11 06:50:56 WARN Failed to register uploaded object key=53a3l32ysagkkaj20rqkdpbbabs44wfv.ls error="server returned 404: 404 page not found\n"21702026/10/11 06:50:56 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign21712026/10/11 06:50:56 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"21722026/10/11 06:50:56 INFO Uploading 1 narinfos21732026/10/11 06:50:56 INFO Signed narinfos id=4 count=121742026/10/11 06:50:56 INFO Uploading 1 narinfos21752026/10/11 06:50:56 INFO Received complete push request method=POST path=/api/pushes/1/complete21762026/10/11 06:50:56 INFO Received complete push request method=POST path=/api/pushes/4/complete21772026/10/11 06:50:56 WARN Failed to register uploaded object key=53a3l32ysagkkaj20rqkdpbbabs44wfv.narinfo error="server returned 404: 404 page not found\n"21782026/10/11 06:50:56 WARN Request failed, retrying attempt=3 backoff=433.492684ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21792026/10/11 06:50:56 WARN Failed to register uploaded object key=lzd53g302gfnhisz3ndnmmdivbdqcy79.narinfo error="server returned 404: 404 page not found\n"21802026/10/11 06:50:56 INFO Completed push id=4 objects=3 duration=1.304666ms21812026/10/11 06:50:56 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:60535/api/pushes/4/complete\": EOF" url=http://127.0.0.1:60535/api/pushes/4/complete21822026/10/11 06:50:56 INFO Completed push id=1 objects=4 duration=33.890167ms21832026/10/11 06:50:56 INFO Upload complete. (308ms)2184=== NAME TestClientCADerivations2185 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/2/scratch/6891134b3cadde62/build/TestClientCADerivations4098654634/001/store/lzd53g302gfnhisz3ndnmmdivbdqcy79-ca-test2186 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2187 Compression: zstd2188 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2189 NarSize: 1442190 References: 2191 Deriver: /private/var/tb/2/scratch/6891134b3cadde62/build/TestClientCADerivations4098654634/001/store/qnr03yndm2z9bnpmdys0rmr51iqjcflm-ca-test.drv2192 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2193 client_ca_test.go:185: Checking for realisation files in S3...2194 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2195 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache21962026/10/11 06:50:56 INFO Received complete push request method=POST path=/api/pushes/4/complete21972026-10-11 06:50:56.808 UTC [836] ERROR: Push does not exist: id=421982026-10-11 06:50:56.808 UTC [836] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE21992026-10-11 06:50:56.808 UTC [836] STATEMENT: -- name: CommitPush :one2200 SELECT commit_push($1::bigint)::bigint2201 22022026/10/11 06:50:56 WARN Push not found id=422032026/10/11 06:50:56 INFO Upload complete. (298ms)2204=== NAME TestClientIntegration2205 client_integration_test.go:435: Retrieved narinfo from S3:2206 StorePath: /private/var/tb/2/scratch/6891134b3cadde62/build/TestClientIntegration1783007146/002/store/53a3l32ysagkkaj20rqkdpbbabs44wfv-lost-commit.txt2207 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst2208 Compression: zstd2209 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2210 NarSize: 1522211 References: 2212 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2213 client_integration_test.go:438: Testing garbage collection...2214=== NAME TestClientCADerivations2215 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket87?endpoint=http://localhost:60189®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/2/scratch/6891134b3cadde62/build/TestClientCADerivations4098654634/001/store'2216 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 122172026/10/11 06:50:56 INFO Starting cleanup of old closures method=DELETE path=/api/closures22182026/10/11 06:50:56 INFO Garbage collection started22192026/10/11 06:50:56 INFO Aborted multipart uploads count=0 kept=022202026/10/11 06:50:56 WARN Force mode enabled - objects will be deleted immediately without grace period2221--- PASS: TestService_ReadAuthMiddleware (6.04s)22222026/10/11 06:50:57 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=02223--- PASS: TestClientCADerivations (7.67s)22242026/10/11 06:50:57 INFO Vacuumed table table=pending_closures22252026/10/11 06:50:57 WARN Request failed, retrying attempt=4 backoff=745.998286ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22262026/10/11 06:50:57 INFO Vacuumed table table=pending_objects22272026/10/11 06:50:57 INFO Vacuumed table table=multipart_uploads22282026/10/11 06:50:57 INFO Vacuumed table table=closures22292026/10/11 06:50:57 INFO Vacuumed table table=objects2230=== RUN TestService_RequireScope_OIDC/builder_may_write2231=== PAUSE TestService_RequireScope_OIDC/builder_may_write2232=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2233=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2234=== RUN TestService_RequireScope_OIDC/ops_may_admin2235=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2236=== RUN TestService_RequireScope_OIDC/ops_may_not_write2237=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2238=== RUN TestService_RequireScope_OIDC/reader_may_not_write2239=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2240=== RUN TestService_RequireScope_OIDC/static_token_may_admin2241=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2242=== RUN TestService_RequireScope_OIDC/static_token_may_write2243=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2244=== RUN TestService_RequireScope_OIDC/reader_may_read2245=== PAUSE TestService_RequireScope_OIDC/reader_may_read2246=== RUN TestService_RequireScope_OIDC/writer_implies_read2247=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2248=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2249=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2250=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc2251=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc2252=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2253=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2254=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2255=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2256=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2257=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2258=== CONT TestService_RequireScope_OIDC/builder_may_write2259=== CONT TestService_RequireScope_OIDC/reader_may_read2260=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2261=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2262=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2263=== CONT TestService_RequireScope_OIDC/static_token_may_admin2264=== CONT TestService_RequireScope_OIDC/static_token_may_write2265=== CONT TestService_RequireScope_OIDC/reader_may_not_write2266=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2267=== CONT TestService_RequireScope_OIDC/ops_may_not_write2268=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2269=== CONT TestService_RequireScope_OIDC/writer_implies_read22702026/10/11 06:50:57 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]2271=== CONT TestService_RequireScope_OIDC/ops_may_admin2272=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2273--- PASS: TestService_RequireScope_OIDC (6.69s)2274 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2275 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2276 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2277 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2278 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2279 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2280 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2281 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2282 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2283 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2284 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2285 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2286 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2287 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)22882026/10/11 06:50:57 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld2 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"2289=== NAME TestPinProtectsFromGC2290 client_integration_test.go:976: Pin successfully protected closure from garbage collection22912026/10/11 06:50:57 WARN Request failed, retrying attempt=5 backoff=1.74805522s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2292--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (12.66s)2293--- PASS: TestPinProtectsFromGC (11.66s)2294--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (5.98s)2295--- PASS: TestUploadHandlersRejectOversizedBody (0.20s)2296 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.32s)2297 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.31s)2298 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (4.77s)22992026/10/11 06:50:58 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"2300--- PASS: TestService_AuthMiddleware (5.95s)23012026/10/11 06:50:58 INFO Received uploads request method=POST path=/api/pending_closures23022026/10/11 06:50:58 INFO Aborted multipart uploads count=0 kept=023032026/10/11 06:50:58 WARN Force mode enabled - objects will be deleted immediately without grace period23042026-10-11 06:50:58.556 UTC [1152] ERROR: canceling statement due to user request23052026-10-11 06:50:58.556 UTC [1152] STATEMENT: -- name: MarkStaleObjects :execrows2306 WITH RECURSIVE ct AS (2307 SELECT timezone('UTC', now()) AS now2308 ),2309 closure_reach AS (2310 -- Start with all closure keys2311 SELECT o.key, o.refs2312 FROM objects o2313 INNER JOIN closures c ON o.key = c.key2314 UNION2315 -- Recursively add all referenced objects2316 SELECT o.key, o.refs2317 FROM objects o2318 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2319 ),2320 reachable_objects AS (2321 SELECT DISTINCT key FROM closure_reach2322 ),2323 stale_objects AS (2324 SELECT o.key2325 FROM objects AS o, ct2326 WHERE2327 NOT EXISTS (2328 SELECT 12329 FROM reachable_objects ro2330 WHERE ro.key = o.key2331 )2332 AND NOT EXISTS (2333 SELECT 12334 FROM pending_objects AS po2335 WHERE po.key = o.key2336 )2337 AND o.deleted_at IS NULL -- Only mark fresh objects2338 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2339 FOR UPDATE2340 )2341 UPDATE objects2342 SET2343 deleted_at = ct.now,2344 first_deleted_at = COALESCE(first_deleted_at, ct.now)2345 FROM stale_objects, ct2346 WHERE objects.key = stale_objects.key2347 23482026/10/11 06:50:58 INFO Aborted multipart uploads count=0 kept=023492026/10/11 06:50:58 WARN Force mode enabled - objects will be deleted immediately without grace period23502026/10/11 06:50:58 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:60189/bucket100/?delete=\": context canceled"2351--- PASS: TestGCEndsOnShutdown (0.01s)2352 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (4.50s)2353 --- PASS: TestGCEndsOnShutdown/before_the_run (4.44s)2354 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (4.76s)23552026/10/11 06:50:58 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02356=== NAME TestClientIntegration2357 client_integration_test.go:445: Objects in database after GC:2358 client_integration_test.go:445: Successfully deleted all objects with GC --force23592026/10/11 06:50:58 INFO Received uploads request method=POST path=/api/pending_closures2360--- PASS: TestClientIntegration (9.59s)23612026/10/11 06:50:59 INFO Received uploads request method=POST path=/api/pending_closures2362--- PASS: TestPendingClosureWriteTimeout (0.01s)2363 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2364 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2365 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2366 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (6.61s)23672026/10/11 06:50:59 INFO Received uploads request method=POST path=/api/pending_closures23682026/10/11 06:50:59 INFO Aborted multipart uploads count=0 kept=023692026/10/11 06:50:59 WARN Force mode enabled - objects will be deleted immediately without grace period23702026/10/11 06:50:59 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=023712026/10/11 06:50:59 INFO Vacuumed table table=pending_closures23722026/10/11 06:50:59 INFO Vacuumed table table=pending_objects23732026/10/11 06:50:59 INFO Vacuumed table table=multipart_uploads23742026/10/11 06:50:59 INFO Vacuumed table table=closures23752026/10/11 06:50:59 INFO Vacuumed table table=objects23762026/10/11 06:50:59 INFO Received uploads request method=POST path=/api/pending_closures23772026/10/11 06:50:59 INFO Aborted multipart uploads count=0 kept=023782026/10/11 06:50:59 WARN Force mode enabled - objects will be deleted immediately without grace period23792026/10/11 06:50:59 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=023802026/10/11 06:50:59 INFO Vacuumed table table=pending_closures23812026/10/11 06:50:59 INFO Vacuumed table table=pending_objects23822026/10/11 06:50:59 INFO Vacuumed table table=multipart_uploads23832026/10/11 06:50:59 INFO Vacuumed table table=closures23842026/10/11 06:50:59 INFO Vacuumed table table=objects2385--- PASS: TestForceGCDuringPushOffersSweptObject (0.05s)2386 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (4.42s)2387 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (4.49s)23882026/10/11 06:50:59 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=MjkwNTViYWUtODIxMS00YmFiLWE3ZGQtYmVmNGIyM2RkMzU0LjM3MzFiMWI3LWZmYmItNGVkZS1iNGI2LWU5MDI5ZTBjMmNiY3gxNzkxNzAxNDU5MDk4MzE4MDAw error="Access Denied"23892026/10/11 06:50:59 WARN keeping failed pending closure for cleanup to retry the abort id=12390--- PASS: TestPendingClosureFailureTracksEveryUpload (0.02s)2391 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (4.87s)2392 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (5.03s)23932026/10/11 06:50:59 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23942026/10/11 06:50:59 WARN Request failed, retrying attempt=2 backoff=183.483298ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23952026/10/11 06:50:59 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"23962026/10/11 06:51:00 WARN Request failed, retrying attempt=3 backoff=405.855943ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23972026/10/11 06:51:00 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2398--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.01s)2399 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (4.79s)2400 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (4.42s)24012026/10/11 06:51:00 WARN Request failed, retrying attempt=4 backoff=855.366843ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24022026/10/11 06:51:01 WARN Request failed, retrying attempt=5 backoff=1.677303958s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2403--- PASS: TestReadProxyOutlastsServerWriteTimeout (10.87s)24042026/10/11 06:51:02 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 127.0.0.1:19999: connect: connection refused"24052026/10/11 06:51:02 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24062026/10/11 06:51:03 WARN Request failed, retrying attempt=2 backoff=197.486099ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24072026/10/11 06:51:03 WARN Request failed, retrying attempt=3 backoff=386.562014ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24082026/10/11 06:51:03 WARN Request failed, retrying attempt=4 backoff=735.583009ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24092026/10/11 06:51:04 WARN Request failed, retrying attempt=5 backoff=1.602119028s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24102026/10/11 06:51:05 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24112026/10/11 06:51:06 WARN Request failed, retrying attempt=2 backoff=203.879015ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24122026/10/11 06:51:06 WARN Request failed, retrying attempt=3 backoff=429.826561ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24132026/10/11 06:51:06 WARN Request failed, retrying attempt=4 backoff=790.920216ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24142026/10/11 06:51:07 WARN Request failed, retrying attempt=5 backoff=1.510525634s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2415--- PASS: TestClientErrorHandling (0.02s)2416 --- PASS: TestClientErrorHandling/InvalidStorePath (3.52s)2417 --- PASS: TestClientErrorHandling/InvalidAuthToken (3.80s)2418 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.07s)2419PASS2420{"timestamp":"2026-10-11T06:51:09.088946Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:60549","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(8)"}24212026-10-11 06:51:09.299 UTC [316] LOG: received smart shutdown request24222026-10-11 06:51:09.300 UTC [316] LOG: background worker "logical replication launcher" (PID 327) exited with exit code 124232026-10-11 06:51:10.207 UTC [321] LOG: checkpoint complete: wrote 5166 buffers (31.5%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=14.641 s, sync=0.732 s, total=15.428 s; sync files=37077, longest=0.021 s, average=0.001 s; distance=532941 kB, estimate=532941 kB; lsn=0/25964128, redo lsn=0/220003C024242026-10-11 06:51:10.209 UTC [321] LOG: shutting down24252026-10-11 06:51:10.209 UTC [321] LOG: checkpoint starting: shutdown immediate24262026-10-11 06:51:10.583 UTC [321] LOG: checkpoint complete: wrote 6354 buffers (38.8%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 3 recycled; write=0.333 s, sync=0.039 s, total=0.374 s; sync files=1932, longest=0.001 s, average=0.001 s; distance=58767 kB, estimate=485523 kB; lsn=0/259641A0, redo lsn=0/259641A024272026-10-11 06:51:10.589 UTC [316] LOG: database system is shut down2428Running OIDC tests...2429=== RUN TestAudienceForIssuer2430=== PAUSE TestAudienceForIssuer2431=== RUN TestHTTPClientForHasTimeouts2432=== PAUSE TestHTTPClientForHasTimeouts2433=== RUN TestGlobMatch2434=== PAUSE TestGlobMatch2435=== RUN TestValidateToken_ValidToken2436=== PAUSE TestValidateToken_ValidToken2437=== RUN TestValidateToken_WrongAudience2438=== PAUSE TestValidateToken_WrongAudience2439=== RUN TestValidateToken_Expired2440=== PAUSE TestValidateToken_Expired2441=== RUN TestValidateToken_BoundClaimsMismatch2442=== PAUSE TestValidateToken_BoundClaimsMismatch2443=== RUN TestValidateToken_BoundSubjectMismatch2444=== PAUSE TestValidateToken_BoundSubjectMismatch2445=== RUN TestValidateToken_MultipleProviders2446=== PAUSE TestValidateToken_MultipleProviders2447=== RUN TestValidateToken_NoMatchingProvider2448=== PAUSE TestValidateToken_NoMatchingProvider2449=== RUN TestValidateToken_KubernetesServiceAccount2450=== PAUSE TestValidateToken_KubernetesServiceAccount2451=== RUN TestNewValidator_KubernetesRequiresCA2452=== PAUSE TestNewValidator_KubernetesRequiresCA2453=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2454=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2455=== RUN TestPins_ReservedForMatchingRule2456=== PAUSE TestPins_ReservedForMatchingRule2457=== RUN TestPins_TopLevelShorthand2458=== PAUSE TestPins_TopLevelShorthand2459=== RUN TestPins_ConfigValidation2460=== PAUSE TestPins_ConfigValidation2461=== RUN TestScopes_LegacyProviderDefaultsToWrite2462=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2463=== RUN TestScopes_Rules2464=== PAUSE TestScopes_Rules2465=== RUN TestScopes_ConfigValidation2466=== PAUSE TestScopes_ConfigValidation2467=== CONT TestAudienceForIssuer2468=== CONT TestPins_ConfigValidation2469=== CONT TestScopes_ConfigValidation2470=== CONT TestValidateToken_NoMatchingProvider2471=== CONT TestPins_TopLevelShorthand2472=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2473=== CONT TestNewValidator_KubernetesRequiresCA2474=== CONT TestValidateToken_KubernetesServiceAccount2475--- PASS: TestAudienceForIssuer (0.00s)2476=== CONT TestScopes_LegacyProviderDefaultsToWrite2477=== CONT TestValidateToken_Expired2478=== CONT TestScopes_Rules2479--- PASS: TestPins_ConfigValidation (0.00s)2480=== CONT TestValidateToken_ValidToken2481--- PASS: TestScopes_ConfigValidation (0.01s)2482=== CONT TestValidateToken_BoundSubjectMismatch2483=== CONT TestHTTPClientForHasTimeouts2484=== CONT TestValidateToken_MultipleProviders2485=== CONT TestGlobMatch2486=== RUN TestGlobMatch/foo_foo2487=== CONT TestValidateToken_WrongAudience2488=== PAUSE TestGlobMatch/foo_foo2489=== RUN TestGlobMatch/foo_bar2490=== PAUSE TestGlobMatch/foo_bar2491=== RUN TestGlobMatch/*_2492=== PAUSE TestGlobMatch/*_2493=== RUN TestGlobMatch/*_anything2494=== PAUSE TestGlobMatch/*_anything2495=== RUN TestGlobMatch/foo*_foo2496=== PAUSE TestGlobMatch/foo*_foo2497=== RUN TestGlobMatch/foo*_foobar2498=== PAUSE TestGlobMatch/foo*_foobar2499=== RUN TestGlobMatch/foo*_bar2500=== PAUSE TestGlobMatch/foo*_bar2501=== RUN TestGlobMatch/*bar_bar2502=== CONT TestPins_ReservedForMatchingRule2503=== CONT TestValidateToken_BoundClaimsMismatch2504=== PAUSE TestGlobMatch/*bar_bar2505=== RUN TestGlobMatch/*bar_foobar2506=== PAUSE TestGlobMatch/*bar_foobar2507=== RUN TestGlobMatch/*bar_foo2508=== PAUSE TestGlobMatch/*bar_foo2509=== RUN TestGlobMatch/foo*bar_foobar2510=== PAUSE TestGlobMatch/foo*bar_foobar2511=== RUN TestGlobMatch/foo*bar_foo123bar2512=== PAUSE TestGlobMatch/foo*bar_foo123bar2513=== RUN TestGlobMatch/foo*bar_foobarbaz2514=== PAUSE TestGlobMatch/foo*bar_foobarbaz2515=== RUN TestGlobMatch/*/*_foo/bar2516=== PAUSE TestGlobMatch/*/*_foo/bar2517=== RUN TestGlobMatch/*/*_foo2518=== PAUSE TestGlobMatch/*/*_foo2519=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2520=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2521=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02522=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02523=== RUN TestGlobMatch/refs/*/main_refs/heads/main2524=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2525=== RUN TestGlobMatch/fo?_foo2526=== PAUSE TestGlobMatch/fo?_foo2527=== RUN TestGlobMatch/fo?_fo2528=== PAUSE TestGlobMatch/fo?_fo2529=== RUN TestGlobMatch/fo?_fooo2530=== PAUSE TestGlobMatch/fo?_fooo2531=== RUN TestGlobMatch/?oo_foo2532=== PAUSE TestGlobMatch/?oo_foo2533=== RUN TestGlobMatch/?oo_boo2534=== PAUSE TestGlobMatch/?oo_boo2535=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2536=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2537=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2538=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2539=== CONT TestGlobMatch/foo_bar2540=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2541=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2542=== CONT TestGlobMatch/?oo_foo2543=== CONT TestGlobMatch/fo?_fooo2544=== CONT TestGlobMatch/fo?_fo2545=== CONT TestGlobMatch/fo?_foo2546=== CONT TestGlobMatch/?oo_boo2547=== CONT TestGlobMatch/*bar_foobar2548=== CONT TestGlobMatch/refs/*/main_refs/heads/main2549=== CONT TestGlobMatch/foo_foo2550=== CONT TestGlobMatch/*_anything2551=== CONT TestGlobMatch/foo*_foobar2552=== CONT TestGlobMatch/*/*_foo2553=== CONT TestGlobMatch/*bar_bar2554=== CONT TestGlobMatch/foo*bar_foobar2555=== CONT TestGlobMatch/foo*bar_foo123bar2556=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2557=== CONT TestGlobMatch/foo*_bar2558=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02559=== CONT TestGlobMatch/foo*bar_foobarbaz2560=== CONT TestGlobMatch/foo*_foo2561=== CONT TestGlobMatch/*/*_foo/bar2562=== CONT TestGlobMatch/*_2563=== CONT TestGlobMatch/*bar_foo2564--- PASS: TestGlobMatch (0.01s)2565 --- PASS: TestGlobMatch/foo_bar (0.00s)2566 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2567 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2568 --- PASS: TestGlobMatch/foo_foo (0.00s)2569 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2570 --- PASS: TestGlobMatch/*_anything (0.00s)2571 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2572 --- PASS: TestGlobMatch/*/*_foo (0.00s)2573 --- PASS: TestGlobMatch/*bar_bar (0.00s)2574 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2575 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2576 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2577 --- PASS: TestGlobMatch/foo*_bar (0.00s)2578 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2579 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2580 --- PASS: TestGlobMatch/foo*_foo (0.00s)2581 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2582 --- PASS: TestGlobMatch/*_ (0.00s)2583 --- PASS: TestGlobMatch/*bar_foo (0.00s)2584 --- PASS: TestGlobMatch/?oo_foo (0.00s)2585 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2586 --- PASS: TestGlobMatch/fo?_fo (0.00s)2587 --- PASS: TestGlobMatch/fo?_foo (0.00s)2588 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2589 --- PASS: TestGlobMatch/?oo_boo (0.00s)25902026/10/11 06:51:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60682/oidc2591--- PASS: TestValidateToken_Expired (0.05s)25922026/10/11 06:51:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60684/oidc25932026/10/11 06:51:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60686/oidc2594--- PASS: TestValidateToken_ValidToken (0.07s)2595--- PASS: TestValidateToken_BoundSubjectMismatch (0.07s)25962026/10/11 06:51:13 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:6068825972026/10/11 06:51:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60690/oidc2598--- PASS: TestPins_TopLevelShorthand (0.10s)2599--- PASS: TestValidateToken_KubernetesServiceAccount (0.10s)26002026/10/11 06:51:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60695/oidc26012026/10/11 06:51:13 http: TLS handshake error from 127.0.0.1:60693: remote error: tls: bad certificate2602--- PASS: TestNewValidator_KubernetesRequiresCA (0.11s)2603--- PASS: TestPins_ReservedForMatchingRule (0.11s)26042026/10/11 06:51:13 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12326052026/10/11 06:51:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60699/oidc26062026/10/11 06:51:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60701/oidc2607--- PASS: TestValidateToken_WrongAudience (0.13s)2608--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.14s)2609--- PASS: TestValidateToken_BoundClaimsMismatch (0.13s)26102026/10/11 06:51:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60703/oidc2611--- PASS: TestScopes_Rules (0.14s)26122026/10/11 06:51:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60706/oidc2613--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.16s)26142026/10/11 06:51:13 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:60694/oidc26152026/10/11 06:51:13 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:60708/oidc26162026/10/11 06:51:13 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:60705/oidc2617--- PASS: TestValidateToken_NoMatchingProvider (0.19s)2618--- PASS: TestValidateToken_MultipleProviders (0.18s)2619--- PASS: TestHTTPClientForHasTimeouts (0.20s)2620PASS2621Running hook tests...2622=== RUN TestSendPathsEmpty2623=== PAUSE TestSendPathsEmpty2624=== RUN TestQueueEnqueueAndFetch2625=== PAUSE TestQueueEnqueueAndFetch2626=== RUN TestQueueDeduplication2627=== PAUSE TestQueueDeduplication2628=== RUN TestQueueRemove2629=== PAUSE TestQueueRemove2630=== RUN TestQueueFetchBatchLimit2631=== PAUSE TestQueueFetchBatchLimit2632=== RUN TestQueueRetryMovesToBack2633=== PAUSE TestQueueRetryMovesToBack2634=== RUN TestQueueFetchRemoveLifecycle2635=== PAUSE TestQueueFetchRemoveLifecycle2636=== RUN TestQueueConcurrentWriters2637=== PAUSE TestQueueConcurrentWriters2638=== RUN TestQueueEnqueueWaitsOutSlowWriter2639=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2640=== RUN TestQueueRemoveLargeClosure2641=== PAUSE TestQueueRemoveLargeClosure2642=== RUN TestServerClientIntegration2643--- PASS: TestServerClientIntegration (0.00s)2644=== RUN TestServerQueueError26452026/10/11 06:51:15 ERROR Failed to queue paths error="permission denied" count=12646--- PASS: TestServerQueueError (0.00s)2647=== RUN TestServerRefusesOversizedAndNonStoreRequests2648=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2649=== RUN TestGetListenerSocketActivation2650 server_test.go:256: systemd socket activation does not exist on darwin2651--- SKIP: TestGetListenerSocketActivation (0.00s)2652=== RUN TestServerStalledClientDoesNotBlockShutdown2653=== PAUSE TestServerStalledClientDoesNotBlockShutdown2654=== RUN TestServerBacksOffOnAcceptErrors2655=== PAUSE TestServerBacksOffOnAcceptErrors2656=== RUN TestDrainIsolatesPoisonPath2657=== PAUSE TestDrainIsolatesPoisonPath2658=== RUN TestRunNotBlockedByPoisonHead2659=== PAUSE TestRunNotBlockedByPoisonHead2660=== RUN TestDrainGivesUpWhenServerDown2661=== PAUSE TestDrainGivesUpWhenServerDown2662=== RUN TestFailedPathPrunedByLaterClosure2663=== PAUSE TestFailedPathPrunedByLaterClosure2664=== RUN TestWorkerUploadsAndRemoves2665=== PAUSE TestWorkerUploadsAndRemoves2666=== RUN TestWorkerSkipsGCdPaths2667=== PAUSE TestWorkerSkipsGCdPaths2668=== RUN TestWorkerPrunesClosureDeps2669=== PAUSE TestWorkerPrunesClosureDeps2670=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2671=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2672=== RUN TestDrainTimeout2673=== PAUSE TestDrainTimeout2674=== RUN TestDrainTimeoutDuringIsolation2675=== PAUSE TestDrainTimeoutDuringIsolation2676=== RUN TestShutdownFinishesInFlightPush2677=== PAUSE TestShutdownFinishesInFlightPush2678=== RUN TestWorkerRemoveFailureIsNotProgress2679=== PAUSE TestWorkerRemoveFailureIsNotProgress2680=== RUN TestWorkerKeepsPathItCannotStat2681=== PAUSE TestWorkerKeepsPathItCannotStat2682=== CONT TestSendPathsEmpty2683=== CONT TestWorkerUploadsAndRemoves2684=== CONT TestWorkerSkipsGCdPaths2685=== CONT TestWorkerKeepsPathItCannotStat2686=== CONT TestWorkerRemoveFailureIsNotProgress2687=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2688=== CONT TestShutdownFinishesInFlightPush2689=== RUN TestShutdownFinishesInFlightPush/completes2690=== CONT TestDrainTimeout2691=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2692=== CONT TestWorkerPrunesClosureDeps2693=== CONT TestDrainTimeoutDuringIsolation2694=== CONT TestDrainGivesUpWhenServerDown2695=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2696=== CONT TestRunNotBlockedByPoisonHead2697=== CONT TestServerBacksOffOnAcceptErrors2698=== CONT TestQueueRetryMovesToBack26992026/10/11 06:51:15 ERROR Accept failed error="too many open files"2700=== CONT TestServerStalledClientDoesNotBlockShutdown2701=== CONT TestQueueRemoveLargeClosure2702=== CONT TestServerRefusesOversizedAndNonStoreRequests2703=== CONT TestQueueConcurrentWriters2704=== CONT TestQueueEnqueueWaitsOutSlowWriter27052026/10/11 06:51:15 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2706=== CONT TestDrainIsolatesPoisonPath2707=== CONT TestQueueEnqueueAndFetch2708=== CONT TestQueueRemove27092026/10/11 06:51:15 ERROR Refusing path outside the store path=/nix/store store=/nix/store2710=== CONT TestQueueFetchRemoveLifecycle27112026/10/11 06:51:15 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store2712=== CONT TestFailedPathPrunedByLaterClosure27132026/10/11 06:51:15 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store2714=== CONT TestQueueFetchBatchLimit27152026/10/11 06:51:15 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store27162026/10/11 06:51:15 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store2717--- PASS: TestSendPathsEmpty (0.00s)2718=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2719=== PAUSE TestShutdownFinishesInFlightPush/completes2720=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2721=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2722=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch27232026/10/11 06:51:15 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store2724=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2725=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2726=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2727=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2728=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2729=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2730=== CONT TestQueueDeduplication2731=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths2732=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch27332026/10/11 06:51:15 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store27342026/10/11 06:51:15 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store27352026/10/11 06:51:15 ERROR Accept failed error="too many open files"27362026/10/11 06:51:15 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store27372026/10/11 06:51:15 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store27382026/10/11 06:51:15 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store27392026/10/11 06:51:15 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store27402026/10/11 06:51:15 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store27412026/10/11 06:51:15 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store27422026/10/11 06:51:15 ERROR Failed to decode request error="unexpected EOF"2743--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2744=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27452026/10/11 06:51:15 ERROR Accept failed error="too many open files"27462026/10/11 06:51:15 INFO Upload queue status pending=327472026/10/11 06:51:15 INFO Uploading batch count=127482026/10/11 06:51:15 ERROR Upload failed error="upload failed" count=127492026/10/11 06:51:15 WARN Cannot stat store path, will retry later path=/private/var/tb/2/scratch/6891134b3cadde62/build/TestWorkerKeepsPathItCannotStat2932116301/002/locked/aaa error="lstat /private/var/tb/2/scratch/6891134b3cadde62/build/TestWorkerKeepsPathItCannotStat2932116301/002/locked/aaa: permission denied"27502026/10/11 06:51:15 INFO Uploading batch count=127512026/10/11 06:51:15 ERROR Upload failed error="upload failed" count=127522026/10/11 06:51:15 INFO Upload queue status pending=227532026/10/11 06:51:15 INFO Upload queue status pending=227542026/10/11 06:51:15 INFO Uploading batch count=227552026/10/11 06:51:15 ERROR Upload failed error="upload failed" count=227562026/10/11 06:51:15 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/2/scratch/6891134b3cadde62/build/TestDrainGivesUpWhenServerDown1165295416/002/a27572026/10/11 06:51:15 INFO Uploading batch count=227582026/10/11 06:51:15 INFO Uploading batch count=427592026/10/11 06:51:15 ERROR Upload failed error="upload failed" count=427602026/10/11 06:51:15 INFO Uploading batch count=127612026/10/11 06:51:15 INFO Upload queue status pending=227622026/10/11 06:51:15 INFO Uploading batch count=227632026/10/11 06:51:15 INFO Uploading batch count=227642026/10/11 06:51:15 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/2/scratch/6891134b3cadde62/build/TestDrainIsolatesPoisonPath4215864395/002/bbb27652026/10/11 06:51:15 INFO Uploading batch count=12766--- PASS: TestQueueEnqueueAndFetch (0.03s)2767=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout27682026/10/11 06:51:15 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/2/scratch/6891134b3cadde62/build/TestDrainGivesUpWhenServerDown1165295416/002/b2769--- PASS: TestQueueFetchRemoveLifecycle (0.03s)2770=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short27712026/10/11 06:51:15 INFO Upload queue status pending=327722026/10/11 06:51:15 WARN Cannot stat store path, will retry later path=/private/var/tb/2/scratch/6891134b3cadde62/build/TestWorkerKeepsPathItCannotStat2932116301/002/locked/aaa error="lstat /private/var/tb/2/scratch/6891134b3cadde62/build/TestWorkerKeepsPathItCannotStat2932116301/002/locked/aaa: permission denied"27732026/10/11 06:51:15 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/2/scratch/6891134b3cadde62/build/TestWorkerSkipsGCdPaths3825637416/002/nonexistent27742026/10/11 06:51:15 INFO Uploading batch count=12775--- PASS: TestQueueRemove (0.03s)27762026/10/11 06:51:15 INFO Uploading batch count=12777=== CONT TestShutdownFinishesInFlightPush/completes27782026/10/11 06:51:15 ERROR Upload failed error="upload failed" count=127792026/10/11 06:51:15 INFO Uploading batch count=227802026/10/11 06:51:15 INFO Uploading batch count=22781--- PASS: TestQueueFetchBatchLimit (0.03s)27822026/10/11 06:51:15 ERROR Upload failed error="upload failed" count=22783=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline27842026/10/11 06:51:15 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/2/scratch/6891134b3cadde62/build/TestDrainGivesUpWhenServerDown1165295416/002/c27852026/10/11 06:51:15 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/2/scratch/6891134b3cadde62/build/TestDrainGivesUpWhenServerDown1165295416/002/d27862026/10/11 06:51:15 INFO Uploading batch count=127872026/10/11 06:51:15 ERROR Upload failed error="upload failed" count=127882026/10/11 06:51:15 ERROR Accept failed error="too many open files"27892026/10/11 06:51:15 WARN Cannot stat store path, will retry later path=/private/var/tb/2/scratch/6891134b3cadde62/build/TestWorkerKeepsPathItCannotStat2932116301/002/locked/aaa error="lstat /private/var/tb/2/scratch/6891134b3cadde62/build/TestWorkerKeepsPathItCannotStat2932116301/002/locked/aaa: permission denied"27902026/10/11 06:51:15 INFO Uploading batch count=227912026/10/11 06:51:15 INFO Uploading batch count=227922026/10/11 06:51:15 ERROR Upload failed error="upload failed" count=227932026/10/11 06:51:15 ERROR Upload failed error="upload failed" count=227942026/10/11 06:51:15 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/2/scratch/6891134b3cadde62/build/TestDrainGivesUpWhenServerDown1165295416/002/e27952026/10/11 06:51:15 ERROR Drain finished with paths left in queue remaining=127962026/10/11 06:51:15 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127972026/10/11 06:51:15 INFO Uploading batch count=127982026/10/11 06:51:15 ERROR Upload failed error="upload failed" count=12799--- PASS: TestQueueDeduplication (0.03s)28002026/10/11 06:51:15 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128012026/10/11 06:51:15 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/2/scratch/6891134b3cadde62/build/TestDrainGivesUpWhenServerDown1165295416/002/f28022026/10/11 06:51:15 INFO Uploading batch count=228032026/10/11 06:51:15 ERROR Upload failed error="upload failed" count=22804--- PASS: TestQueueRetryMovesToBack (0.04s)28052026/10/11 06:51:15 ERROR Drain finished with paths left in queue remaining=128062026/10/11 06:51:15 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128072026/10/11 06:51:15 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128082026/10/11 06:51:15 INFO Uploading batch count=228092026/10/11 06:51:15 ERROR Upload failed error="upload failed" count=228102026/10/11 06:51:15 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128112026/10/11 06:51:15 ERROR Drain finished with paths left in queue remaining=1028122026/10/11 06:51:15 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=12813--- PASS: TestWorkerKeepsPathItCannotStat (0.04s)28142026/10/11 06:51:15 ERROR Drain finished with paths left in queue remaining=22815--- PASS: TestDrainIsolatesPoisonPath (0.04s)2816--- PASS: TestFailedPathPrunedByLaterClosure (0.04s)28172026/10/11 06:51:15 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/2/scratch/6891134b3cadde62/build/TestWorkerRemoveFailureIsNotProgresscollected_path1343109520/001/nonexistent28182026/10/11 06:51:15 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128192026/10/11 06:51:15 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/2/scratch/6891134b3cadde62/build/TestWorkerRemoveFailureIsNotProgresscollected_path1343109520/001/nonexistent28202026/10/11 06:51:15 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128212026/10/11 06:51:15 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/2/scratch/6891134b3cadde62/build/TestWorkerRemoveFailureIsNotProgresscollected_path1343109520/001/nonexistent28222026/10/11 06:51:15 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128232026/10/11 06:51:15 INFO Uploading batch count=22824--- PASS: TestDrainGivesUpWhenServerDown (0.04s)28252026/10/11 06:51:15 ERROR Drain finished with paths left in queue remaining=128262026/10/11 06:51:15 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228272026/10/11 06:51:15 INFO Upload queue status pending=228282026/10/11 06:51:15 INFO Uploading batch count=228292026/10/11 06:51:15 INFO Uploading batch count=228302026/10/11 06:51:15 INFO Upload queue status pending=228312026/10/11 06:51:15 INFO Uploading batch count=428322026/10/11 06:51:15 ERROR Upload failed error="upload failed" count=428332026/10/11 06:51:15 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228342026/10/11 06:51:15 INFO Uploading batch count=228352026/10/11 06:51:15 INFO Uploading batch count=428362026/10/11 06:51:15 ERROR Upload failed error="upload failed" count=428372026/10/11 06:51:15 INFO Uploading batch count=228382026/10/11 06:51:15 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228392026/10/11 06:51:15 ERROR Drain finished with paths left in queue remaining=22840--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2841 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.04s)2842 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.04s)2843 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.04s)2844--- PASS: TestWorkerPrunesClosureDeps (0.05s)2845--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.05s)2846--- PASS: TestWorkerUploadsAndRemoves (0.05s)2847--- PASS: TestWorkerSkipsGCdPaths (0.05s)28482026/10/11 06:51:15 ERROR Accept failed error="too many open files"28492026/10/11 06:51:15 ERROR Accept failed error="too many open files"2850--- PASS: TestQueueConcurrentWriters (0.17s)28512026/10/11 06:51:15 ERROR Failed to decode request error="read unix /private/var/tb/2/scratch/6891134b3cadde62/build/hook907816285/test.sock->: i/o timeout"28522026/10/11 06:51:15 ERROR Failed to write response error="write unix /private/var/tb/2/scratch/6891134b3cadde62/build/hook907816285/test.sock->: i/o timeout"2853--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)28542026/10/11 06:51:15 ERROR Upload failed error="context canceled" count=228552026/10/11 06:51:15 ERROR Drain finished with paths left in queue remaining=42856--- PASS: TestDrainTimeout (0.23s)28572026/10/11 06:51:15 ERROR Upload failed error="context canceled" count=228582026/10/11 06:51:15 ERROR Drain finished with paths left in queue remaining=428592026/10/11 06:51:15 ERROR Drain finished with paths left in queue remaining=22860--- PASS: TestShutdownFinishesInFlightPush (0.00s)2861 --- PASS: TestShutdownFinishesInFlightPush/completes (0.11s)2862 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.22s)28632026/10/11 06:51:15 ERROR Accept failed error="too many open files"28642026/10/11 06:51:15 ERROR Drain finished with paths left in queue remaining=32865--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2866 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.22s)2867 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.31s)28682026/10/11 06:51:15 ERROR Accept failed error="too many open files"2869--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)2870--- PASS: TestQueueRemoveLargeClosure (0.81s)28712026/10/11 06:51:16 INFO Uploading batch count=128722026/10/11 06:51:16 INFO Uploading batch count=128732026/10/11 06:51:16 INFO Uploading batch count=128742026/10/11 06:51:16 ERROR Upload failed error="upload failed" count=128752026/10/11 06:51:16 INFO Uploading batch count=128762026/10/11 06:51:16 ERROR Upload failed error="upload failed" count=128772026/10/11 06:51:16 INFO Uploading batch count=128782026/10/11 06:51:16 ERROR Upload failed error="upload failed" count=128792026/10/11 06:51:16 INFO Uploading batch count=128802026/10/11 06:51:16 ERROR Upload failed error="upload failed" count=128812026/10/11 06:51:16 ERROR Drain finished with paths left in queue remaining=12882--- PASS: TestRunNotBlockedByPoisonHead (1.06s)2883--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.03s)2884PASS2885Running signing tests...2886=== RUN TestExternalSigner2887=== PAUSE TestExternalSigner2888=== RUN TestExternalSignerWrongPublicKey2889=== PAUSE TestExternalSignerWrongPublicKey2890=== RUN TestExternalSignerErrors2891=== PAUSE TestExternalSignerErrors2892=== RUN TestExternalSignerRestartsAfterCrash2893=== PAUSE TestExternalSignerRestartsAfterCrash2894=== RUN TestExternalSignerProgramErrorKeepsProcess2895=== PAUSE TestExternalSignerProgramErrorKeepsProcess2896=== RUN TestExternalSignerClose2897=== PAUSE TestExternalSignerClose2898=== RUN TestExternalSignerRejectsInvalidPublicKey2899=== PAUSE TestExternalSignerRejectsInvalidPublicKey2900=== RUN TestExternalSignerCancellation2901=== PAUSE TestExternalSignerCancellation2902=== RUN TestGenerateFingerprint2903=== PAUSE TestGenerateFingerprint2904=== RUN TestParseSigningKey2905=== PAUSE TestParseSigningKey2906=== RUN TestSign2907=== PAUSE TestSign2908=== RUN TestSignBatch2909=== PAUSE TestSignBatch2910=== RUN TestNilKeyPublicKey2911=== PAUSE TestNilKeyPublicKey2912=== RUN TestSignErrors2913=== PAUSE TestSignErrors2914=== CONT TestExternalSigner2915=== CONT TestExternalSignerRejectsInvalidPublicKey2916=== RUN TestExternalSignerRejectsInvalidPublicKey/#002917=== CONT TestSignBatch2918=== CONT TestExternalSignerProgramErrorKeepsProcess2919=== CONT TestParseSigningKey2920=== CONT TestExternalSignerClose2921=== CONT TestSign2922=== CONT TestExternalSignerErrors2923=== RUN TestExternalSignerErrors/exit_at_startup2924=== CONT TestGenerateFingerprint2925=== RUN TestGenerateFingerprint/basic_with_references2926=== CONT TestExternalSignerCancellation2927=== PAUSE TestExternalSignerErrors/exit_at_startup2928=== PAUSE TestGenerateFingerprint/basic_with_references2929=== CONT TestExternalSignerWrongPublicKey2930=== RUN TestExternalSignerErrors/exit_on_request2931=== PAUSE TestExternalSignerErrors/exit_on_request2932=== RUN TestExternalSignerErrors/wrong_shape2933=== RUN TestGenerateFingerprint/no_references2934=== PAUSE TestExternalSignerErrors/wrong_shape2935=== CONT TestNilKeyPublicKey2936=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002937=== RUN TestParseSigningKey/valid_32-byte_key2938=== CONT TestExternalSignerRestartsAfterCrash2939=== PAUSE TestParseSigningKey/valid_32-byte_key2940=== CONT TestSignErrors2941--- PASS: TestSign (0.01s)2942=== PAUSE TestGenerateFingerprint/no_references2943--- PASS: TestNilKeyPublicKey (0.00s)2944=== RUN TestExternalSignerErrors/wrong_id2945=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2946=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2947=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2948=== RUN TestSignErrors/nil_key2949=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2950=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2951=== PAUSE TestExternalSignerErrors/wrong_id2952=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2953--- PASS: TestSignBatch (0.01s)2954=== PAUSE TestSignErrors/nil_key2955=== RUN TestParseSigningKey/no_colon2956=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2957=== RUN TestExternalSignerErrors/too_few_signatures2958=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2959=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2960=== PAUSE TestParseSigningKey/no_colon2961=== RUN TestGenerateFingerprint/invalid_nar_hash_length2962=== RUN TestSignErrors/nil_narinfo2963=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2964=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2965=== RUN TestGenerateFingerprint/invalid_store_path_prefix2966=== PAUSE TestExternalSignerErrors/too_few_signatures2967=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2968=== PAUSE TestSignErrors/nil_narinfo2969=== RUN TestExternalSignerErrors/missing_signature_name2970=== RUN TestGenerateFingerprint/invalid_reference_prefix2971=== RUN TestSignErrors/invalid_narinfo2972=== PAUSE TestExternalSignerErrors/missing_signature_name2973=== RUN TestParseSigningKey/empty_name2974=== PAUSE TestSignErrors/invalid_narinfo2975=== PAUSE TestParseSigningKey/empty_name2976=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2977=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2978=== RUN TestExternalSignerErrors/wrong_signature_name2979=== PAUSE TestExternalSignerErrors/wrong_signature_name2980=== RUN TestExternalSignerErrors/null2981=== PAUSE TestExternalSignerErrors/null2982=== RUN TestExternalSignerErrors/missing_signatures2983=== RUN TestParseSigningKey/invalid_base642984=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2985=== PAUSE TestExternalSignerErrors/missing_signatures2986=== RUN TestExternalSignerErrors/invalid_signature_base642987=== PAUSE TestExternalSignerErrors/invalid_signature_base642988=== CONT TestGenerateFingerprint/invalid_store_path_prefix2989=== CONT TestGenerateFingerprint/basic_with_references2990=== RUN TestExternalSignerErrors/wrong_signature_length2991=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2992=== PAUSE TestExternalSignerErrors/wrong_signature_length2993=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2994=== CONT TestGenerateFingerprint/no_references2995=== CONT TestGenerateFingerprint/invalid_reference_prefix2996=== RUN TestExternalSignerErrors/null_signatures2997=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2998=== RUN TestSignErrors/canceled2999=== CONT TestGenerateFingerprint/invalid_nar_hash_length3000=== PAUSE TestParseSigningKey/invalid_base643001=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==3002=== PAUSE TestExternalSignerErrors/null_signatures3003=== CONT TestExternalSignerRejectsInvalidPublicKey/#003004=== RUN TestParseSigningKey/wrong_length3005--- PASS: TestGenerateFingerprint (0.01s)3006 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)3007 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)3008 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)3009 --- PASS: TestGenerateFingerprint/no_references (0.00s)3010 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)3011 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)3012 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)3013=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!3014=== RUN TestExternalSignerErrors/program_error3015=== PAUSE TestExternalSignerErrors/program_error3016=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon3017=== RUN TestExternalSignerErrors/invalid_JSON3018=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==3019=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=3020=== PAUSE TestExternalSignerErrors/invalid_JSON3021=== PAUSE TestSignErrors/canceled3022--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.02s)3023 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)3024 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)3025 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)3026 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)3027 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)3028=== CONT TestSignErrors/nil_key3029=== RUN TestExternalSignerErrors/wrong_signatures_shape3030=== PAUSE TestExternalSignerErrors/wrong_signatures_shape3031=== PAUSE TestParseSigningKey/wrong_length3032=== CONT TestSignErrors/nil_narinfo3033=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name3034=== CONT TestParseSigningKey/invalid_base643035=== CONT TestParseSigningKey/valid_32-byte_key3036=== CONT TestSignErrors/canceled3037=== CONT TestParseSigningKey/empty_name3038=== CONT TestParseSigningKey/no_colon3039=== RUN TestExternalSignerErrors/unrequested_key3040=== CONT TestParseSigningKey/wrong_length3041=== PAUSE TestExternalSignerErrors/unrequested_key3042=== CONT TestSignErrors/invalid_narinfo3043=== CONT TestExternalSignerErrors/wrong_signature_name3044=== CONT TestExternalSignerErrors/missing_signature_name3045=== CONT TestExternalSignerErrors/exit_at_startup3046--- PASS: TestSignErrors (0.01s)3047 --- PASS: TestSignErrors/nil_key (0.00s)3048 --- PASS: TestSignErrors/nil_narinfo (0.00s)3049 --- PASS: TestSignErrors/canceled (0.00s)3050 --- PASS: TestSignErrors/invalid_narinfo (0.00s)3051=== CONT TestExternalSignerErrors/null3052=== CONT TestExternalSignerErrors/wrong_id3053=== CONT TestExternalSignerErrors/wrong_signature_length3054=== CONT TestExternalSignerErrors/wrong_signatures_shape3055=== CONT TestExternalSignerErrors/too_few_signatures3056--- PASS: TestParseSigningKey (0.02s)3057 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)3058 --- PASS: TestParseSigningKey/no_colon (0.00s)3059 --- PASS: TestParseSigningKey/empty_name (0.00s)3060 --- PASS: TestParseSigningKey/wrong_length (0.00s)3061 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)3062 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)3063=== CONT TestExternalSignerErrors/invalid_JSON3064=== CONT TestExternalSignerErrors/exit_on_request3065=== CONT TestExternalSignerErrors/program_error3066=== CONT TestExternalSignerErrors/null_signatures3067=== CONT TestExternalSignerErrors/missing_signatures3068=== CONT TestExternalSignerErrors/invalid_signature_base643069=== CONT TestExternalSignerErrors/wrong_shape3070=== CONT TestExternalSignerErrors/unrequested_key3071--- PASS: TestExternalSigner (0.28s)3072--- PASS: TestExternalSignerClose (0.46s)3073--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.65s)3074--- PASS: TestExternalSignerCancellation (0.85s)3075--- PASS: TestExternalSignerWrongPublicKey (1.02s)3076--- PASS: TestExternalSignerRestartsAfterCrash (1.23s)3077--- PASS: TestExternalSignerErrors (0.02s)3078 --- PASS: TestExternalSignerErrors/missing_signature_name (1.39s)3079 --- PASS: TestExternalSignerErrors/exit_at_startup (1.58s)3080 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (1.77s)3081 --- PASS: TestExternalSignerErrors/missing_signatures (1.96s)3082 --- PASS: TestExternalSignerErrors/program_error (2.15s)3083 --- PASS: TestExternalSignerErrors/invalid_JSON (2.34s)3084 --- PASS: TestExternalSignerErrors/null (2.53s)3085 --- PASS: TestExternalSignerErrors/exit_on_request (2.72s)3086 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (2.91s)3087 --- PASS: TestExternalSignerErrors/null_signatures (3.34s)3088 --- PASS: TestExternalSignerErrors/wrong_id (3.53s)3089 --- PASS: TestExternalSignerErrors/wrong_signature_name (3.72s)3090 --- PASS: TestExternalSignerErrors/too_few_signatures (3.91s)3091 --- PASS: TestExternalSignerErrors/wrong_shape (4.10s)3092 --- PASS: TestExternalSignerErrors/wrong_signature_length (4.29s)3093 --- PASS: TestExternalSignerErrors/unrequested_key (4.48s)3094PASS3095Running OpenBao signer tests...3096=== RUN TestSign3097=== PAUSE TestSign3098=== RUN TestSignErrors3099=== PAUSE TestSignErrors3100=== RUN TestServe3101=== PAUSE TestServe3102=== RUN TestServeRejectsGarbage3103=== PAUSE TestServeRejectsGarbage3104=== CONT TestSign3105=== CONT TestServe3106=== CONT TestSignErrors3107=== CONT TestServeRejectsGarbage3108=== RUN TestSignErrors/no_prefix3109--- PASS: TestServeRejectsGarbage (0.00s)3110=== PAUSE TestSignErrors/no_prefix3111=== RUN TestSignErrors/invalid_base643112=== PAUSE TestSignErrors/invalid_base643113=== RUN TestSignErrors/http_error3114=== PAUSE TestSignErrors/http_error3115=== RUN TestSignErrors/invalid_json3116=== PAUSE TestSignErrors/invalid_json3117=== CONT TestSignErrors/no_prefix3118=== CONT TestSignErrors/http_error3119=== CONT TestSignErrors/invalid_base643120=== CONT TestSignErrors/invalid_json3121--- PASS: TestServe (0.00s)3122--- PASS: TestSign (0.00s)3123--- PASS: TestSignErrors (0.00s)3124 --- PASS: TestSignErrors/invalid_json (0.00s)3125 --- PASS: TestSignErrors/http_error (0.00s)3126 --- PASS: TestSignErrors/no_prefix (0.00s)3127 --- PASS: TestSignErrors/invalid_base64 (0.00s)3128PASS3129Running niks3-hook command tests...3130=== RUN TestServeSecondSignalEndsDrain3131=== PAUSE TestServeSecondSignalEndsDrain3132=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown3133=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown3134=== CONT TestServeSecondSignalEndsDrain3135=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown3136--- PASS: TestServeSecondSignalEndsDrain (0.07s)31372026/10/11 06:51:30 INFO Upload queue status pending=131382026/10/11 06:51:30 INFO Uploading batch count=13139--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.12s)3140PASS3141Running rate limiter tests...3142=== RUN TestAdaptiveRateLimiter_ThreadSafety3143=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3144=== CONT TestAdaptiveRateLimiter_ThreadSafety31452026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=150.0512167000001431462026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=105.0358516900000931472026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=73.5250961830000631482026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=51.4675673281000431492026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=36.02729712967002531502026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=25.21910799076901531512026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=17.6533755935383131522026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=12.35736291547681631532026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=8.6501540408337731542026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=6.055107828583639531552026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=6.82626819630856931562026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531572026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531582026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531592026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531602026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531612026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531622026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531632026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531642026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531652026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531662026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531672026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531682026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531692026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531702026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531712026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531722026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531732026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531742026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531752026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531762026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531772026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531782026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531792026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531802026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531812026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531822026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531832026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531842026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531852026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531862026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531872026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531882026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531892026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531902026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531912026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=5.12435000000000131922026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531932026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531942026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531952026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531962026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531972026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531982026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=531992026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532002026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532012026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532022026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532032026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532042026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532052026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532062026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532072026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532082026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532092026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532102026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532112026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532122026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532132026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532142026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532152026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532162026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532172026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532182026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532192026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532202026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532212026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532222026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532232026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532242026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532252026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=13.29124417541344832262026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=9.30387092278941332272026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=6.51270964595258832282026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532292026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532302026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532312026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=5.63678500000000132322026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532332026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532342026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532352026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532362026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532372026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532382026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532392026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532402026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532412026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532422026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532432026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=532442026/10/11 06:51:31 WARN Rate limiter backed off name=test rate=53245--- PASS: TestAdaptiveRateLimiter_ThreadSafety (0.06s)3246PASS