niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #434
· raw
1tribuchet: building on mac022Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure18=== PAUSE TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure19=== RUN TestUploadMultipart_PartsInParallel20=== PAUSE TestUploadMultipart_PartsInParallel21=== RUN TestUploadMultipart_FailedPartBufferNotReused22=== PAUSE TestUploadMultipart_FailedPartBufferNotReused23=== RUN TestUploadMultipart_ProducerErrorIsNotEOF24=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestUploadMultipart_SupersededByPeer28=== PAUSE TestUploadMultipart_SupersededByPeer29=== RUN TestDumpPathCaseHackMatchesNix30--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)31=== RUN TestDumpPathCaseHackCollision32--- PASS: TestDumpPathCaseHackCollision (0.00s)33=== RUN TestSupersededNARStillUploadsListing34=== PAUSE TestSupersededNARStillUploadsListing35=== RUN TestTruncatedNARDumpIsNotCompleted36=== PAUSE TestTruncatedNARDumpIsNotCompleted37=== RUN TestDumpPathMatchesNix38=== PAUSE TestDumpPathMatchesNix39=== RUN TestDumpPathSingleFile40=== PAUSE TestDumpPathSingleFile41=== RUN TestDumpPathWriterError42=== PAUSE TestDumpPathWriterError43=== RUN TestDumpPathWriterErrorStopsReading44 nar_test.go:280: no /proc/self/io: open /proc/self/io: no such file or directory45--- SKIP: TestDumpPathWriterErrorStopsReading (0.37s)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 TestRegisterUploadedObject_BoundedAgainstSilentServer135=== CONT TestScriptTokenDoesNotWaitForItsChildren136=== CONT TestTruncatedNARDumpIsNotCompleted137=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs138=== CONT TestParsePathInfoJSONMultiplePaths139=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths140=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs141=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths142=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths143=== CONT TestRateLimiterFeedback144=== RUN TestRateLimiterFeedback/429_enables_limiter145=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout146=== CONT TestScriptTokenEmptyCommand147--- PASS: TestScriptTokenEmptyCommand (0.00s)148=== PAUSE TestRateLimiterFeedback/429_enables_limiter149=== CONT TestResolveStorePath150=== CONT TestScriptTokenEmptyToken151=== CONT TestStreamPushStopsWhenCanceled152=== CONT TestCompletePendingClosure_NotFoundWithoutKey153=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent154=== CONT TestPathInfoCACompatibility155=== CONT TestGetStorePathHash156=== CONT TestFileTokenMissing157=== CONT TestConvertHashToNix32158=== RUN TestConvertHashToNix32/SRI_format_to_Nix32159=== CONT TestParsePathInfoJSON160=== RUN TestParsePathInfoJSON/Nix_format161=== CONT TestEncodeNixBase32WithRealHash162=== CONT TestPathInfoHashCompatibility163=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)164=== CONT TestEncodeNixBase32165=== CONT TestScriptTokenScriptFails166=== CONT TestDumpPathSingleFile167=== CONT TestSupersededNARStillUploadsListing168=== CONT TestScriptTokenBadJSON169=== CONT TestScriptTokenCachesUntilRefresh170=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess171=== CONT TestDoServerRequestAttachesToken172=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths173=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout174=== RUN TestRateLimiterFeedback/503_enables_limiter175=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier176=== RUN TestPathInfoCACompatibility/null_ca_field177=== RUN TestGetStorePathHash/valid_store_path178=== PAUSE TestGetStorePathHash/valid_store_path179--- PASS: TestFileTokenMissing (0.00s)180--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.00s)181=== CONT TestUploadMultipart_ProducerErrorIsNotEOF182=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part183=== CONT TestFileTokenEmpty184=== PAUSE TestParsePathInfoJSON/Nix_format185=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32186=== CONT TestDumpPathWriterError187=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure188=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)189=== RUN TestEncodeNixBase32/test_string_hash190=== RUN TestSupersededNARStillUploadsListing/small_NAR191=== CONT TestDumpPathMatchesNix192=== CONT TestPartSizeForNAR193=== PAUSE TestRateLimiterFeedback/503_enables_limiter194=== RUN TestConvertHashToNix32/already_Nix32_format195=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier196=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up197=== PAUSE TestPathInfoCACompatibility/null_ca_field198=== RUN TestGetStorePathHash/basename_without_hyphen_should_error199=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error200=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up201--- PASS: TestEncodeNixBase32WithRealHash (0.00s)202=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part203=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon204=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary205=== PAUSE TestSupersededNARStillUploadsListing/small_NAR206=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary207=== PAUSE TestEncodeNixBase32/test_string_hash208=== RUN TestSupersededNARStillUploadsListing/dump_cut_short209=== RUN TestEncodeNixBase32/empty_input210=== PAUSE TestEncodeNixBase32/empty_input211=== PAUSE TestConvertHashToNix32/already_Nix32_format212=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short213=== CONT TestSetClientTLSDoesNotMutateDefaultTransport214=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter215=== RUN TestParsePathInfoJSON/Lix_format216=== CONT TestUploadMultipart_FailedPartBufferNotReused217=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter218=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier219=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error220=== RUN TestPathInfoCACompatibility/old_string_format_-_text221--- PASS: TestStreamPushStopsWhenCanceled (0.00s)222=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon223=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error224=== CONT TestUploadMultipart_SupersededByPeer225=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error226--- PASS: TestResolveStorePath (0.00s)227=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text228=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive229--- PASS: TestFileTokenEmpty (0.00s)230=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive231=== RUN TestConvertHashToNix32/invalid_format232=== RUN TestPathInfoCACompatibility/new_structured_format_-_text233=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text234=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method235=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier236=== PAUSE TestConvertHashToNix32/invalid_format237=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client238=== CONT TestFileTokenReadsAndCaches239=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client240=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails241=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter242=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails243=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI244=== RUN TestPartSizeForNAR/zero_stays_at_minimum245=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error246=== RUN TestUploadMultipart_SupersededByPeer/exists247=== PAUSE TestParsePathInfoJSON/Lix_format248=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method249=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client250=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter251=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client252=== CONT TestClientSignaturesByStorePath253=== CONT TestStreamPushStopsOnCancel254--- PASS: TestClientSignaturesByStorePath (0.00s)255=== CONT TestStreamPushReportsSkippedPaths256=== CONT TestScriptTokenNoExpiryRerunsEveryCall257=== RUN TestStreamPushStopsOnCancel/waiting_for_input258=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI259=== PAUSE TestUploadMultipart_SupersededByPeer/exists260=== RUN TestUploadMultipart_SupersededByPeer/missing261=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input262=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512263=== CONT TestSetClientTLSErrors264=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot265=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512266=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum267=== CONT TestStreamPushBatchesUnderLoad268=== RUN TestParsePathInfoJSON/empty_input269=== PAUSE TestUploadMultipart_SupersededByPeer/missing270=== CONT TestStreamPushRequestLine271=== CONT TestStreamPushReportsSignatures272=== RUN TestPartSizeForNAR/small_stays_at_minimum273=== PAUSE TestPartSizeForNAR/small_stays_at_minimum274=== CONT TestStreamPushIsolatesFailures275=== PAUSE TestParsePathInfoJSON/empty_input276=== CONT TestDoWithRetry_FinalResponseBodyReadable277=== RUN TestStreamPushBatchesUnderLoad/together278--- PASS: TestStreamPushReportsSkippedPaths (0.00s)279=== PAUSE TestStreamPushBatchesUnderLoad/together280=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot281=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time282=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot283=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum284=== RUN TestParsePathInfoJSON/whitespace_only285=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum286=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot287=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot288=== PAUSE TestParsePathInfoJSON/whitespace_only289=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts290=== RUN TestParsePathInfoJSON/invalid_JSON291=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts292=== PAUSE TestParsePathInfoJSON/invalid_JSON293=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot294=== RUN TestPartSizeForNAR/1_TiB295=== CONT TestStreamPushGivesUpOnDeadServer296=== CONT TestSetClientTLS297=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time298--- PASS: TestScriptTokenScriptFails (0.01s)299--- PASS: TestDoServerRequestAttachesToken (0.01s)300=== CONT TestRetryTimeoutOutlastsMaxRetries301--- PASS: TestStreamPushReportsSignatures (0.00s)302--- PASS: TestStreamPushIsolatesFailures (0.00s)303--- PASS: TestFileTokenReadsAndCaches (0.01s)304--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)305=== CONT TestShellSplit306--- PASS: TestShellSplit (0.00s)307=== CONT TestShellSplitErrors308--- PASS: TestShellSplitErrors (0.00s)309=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun310=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot311=== PAUSE TestPartSizeForNAR/1_TiB312=== CONT TestStaticToken313--- PASS: TestStaticToken (0.00s)314=== CONT TestUploadMultipart_PartsInParallel315=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot316=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken317=== RUN TestPartSizeForNAR/5_TiB_S3_max_object318=== CONT TestDoWithRetry_BodyReplayedViaGetBody319=== CONT TestStreamPushReportsEveryPath320=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken321=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object322=== RUN TestPartSizeForNAR/capped_at_5_GiB323=== CONT TestCaseHackSuffix324=== PAUSE TestPartSizeForNAR/capped_at_5_GiB325--- PASS: TestStreamPushReportsEveryPath (0.00s)326=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry327=== CONT TestFilterOversizedClosures328--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)329=== CONT TestRegisterUploadedObjectReusesConnections330=== RUN TestFilterOversizedClosures/no_limit_keeps_everything331=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything332=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped333=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped334=== RUN TestFilterOversizedClosures/all_closures_skipped335=== PAUSE TestFilterOversizedClosures/all_closures_skipped336=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica337--- PASS: TestScriptTokenBadJSON (0.02s)338=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths339=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths340=== RUN TestSetClientTLSErrors/missing_cert_file341--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.02s)342=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part343--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)344=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs345=== PAUSE TestSetClientTLSErrors/missing_cert_file346=== RUN TestSetClientTLSErrors/missing_key_file347=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout348--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)349 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)350 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)351=== RUN TestSetClientTLS/rejects_connection_without_client_cert352=== PAUSE TestSetClientTLSErrors/missing_key_file353=== RUN TestSetClientTLSErrors/missing_ca_file354=== PAUSE TestSetClientTLSErrors/missing_ca_file355=== RUN TestSetClientTLSErrors/invalid_ca_file356=== PAUSE TestSetClientTLSErrors/invalid_ca_file357=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary358=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert359=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA360=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA361=== RUN TestSetClientTLS/preserves_debug_logging_transport362=== PAUSE TestSetClientTLS/preserves_debug_logging_transport363=== CONT TestEncodeNixBase32/empty_input364=== CONT TestEncodeNixBase32/test_string_hash365=== CONT TestConvertHashToNix32/invalid_format366--- PASS: TestEncodeNixBase32 (0.00s)367 --- PASS: TestEncodeNixBase32/empty_input (0.00s)368 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)369=== CONT TestConvertHashToNix32/SRI_format_to_Nix32370=== CONT TestConvertHashToNix32/already_Nix32_format371=== CONT TestSupersededNARStillUploadsListing/small_NAR372--- PASS: TestConvertHashToNix32 (0.00s)373 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)374 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)375 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)376--- PASS: TestScriptTokenEmptyToken (0.04s)377=== CONT TestSupersededNARStillUploadsListing/dump_cut_short378--- PASS: TestDumpPathSingleFile (0.06s)379=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails380--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.07s)381=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error382=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error383=== CONT TestGetStorePathHash/basename_without_hyphen_should_error384=== CONT TestGetStorePathHash/valid_store_path385=== CONT TestPathInfoCACompatibility/null_ca_field386--- PASS: TestGetStorePathHash (0.01s)387 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)388 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)389 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)390 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)391--- PASS: TestScriptTokenCachesUntilRefresh (0.08s)392=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier393=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client394--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.09s)395--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.09s)396=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client397--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.00s)398 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.07s)399 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.09s)400=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive401--- PASS: TestCaseHackSuffix (0.12s)402=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter403=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method404=== CONT TestPathInfoCACompatibility/old_string_format_-_text405=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter406=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier407=== CONT TestPathInfoCACompatibility/new_structured_format_-_text408=== CONT TestRateLimiterFeedback/503_enables_limiter409=== CONT TestRateLimiterFeedback/429_enables_limiter410=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)411=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up412=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512413=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon414=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI415--- PASS: TestPathInfoCACompatibility (0.01s)416 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.01s)417 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)418 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)419 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)420 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)421=== CONT TestUploadMultipart_SupersededByPeer/missing422--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.12s)423=== CONT TestUploadMultipart_SupersededByPeer/exists424--- PASS: TestPathInfoHashCompatibility (0.01s)425 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)426 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)427 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)428 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)429=== CONT TestParsePathInfoJSON/Lix_format430=== CONT TestParsePathInfoJSON/invalid_JSON431=== CONT TestParsePathInfoJSON/empty_input432=== CONT TestParsePathInfoJSON/whitespace_only433=== CONT TestParsePathInfoJSON/Nix_format434=== CONT TestStreamPushBatchesUnderLoad/together435=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot436=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken437=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot438=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot439=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot440=== CONT TestStreamPushStopsOnCancel/waiting_for_input441=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time442--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.01s)443 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.02s)444 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.00s)445 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.01s)446 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.00s)447 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.00s)448--- PASS: TestParsePathInfoJSON (0.01s)449 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)450 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)451 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)452 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)453 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)454=== CONT TestPartSizeForNAR/1_TiB455=== CONT TestPartSizeForNAR/small_stays_at_minimum456=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts457--- PASS: TestRateLimiterFeedback (0.01s)458 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)459 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)460 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)461 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)462--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)463 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)464 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)465=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum466=== CONT TestPartSizeForNAR/5_TiB_S3_max_object467=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped468=== CONT TestFilterOversizedClosures/all_closures_skipped469=== CONT TestPartSizeForNAR/zero_stays_at_minimum470=== CONT TestFilterOversizedClosures/no_limit_keeps_everything471=== CONT TestSetClientTLSErrors/missing_key_file472=== CONT TestSetClientTLSErrors/invalid_ca_file473=== CONT TestPartSizeForNAR/capped_at_5_GiB474=== CONT TestSetClientTLSErrors/missing_ca_file475--- PASS: TestFilterOversizedClosures (0.00s)476 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)477 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)478 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)479=== CONT TestSetClientTLSErrors/missing_cert_file480=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA481=== CONT TestSetClientTLS/preserves_debug_logging_transport482=== CONT TestSetClientTLS/rejects_connection_without_client_cert483--- PASS: TestPartSizeForNAR (0.01s)484 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)485 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)486 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)487 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)488 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)489 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)490 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)491--- PASS: TestSetClientTLSErrors (0.02s)492 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)493 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)494 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)495 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)496--- PASS: TestStreamPushBatchesUnderLoad (0.00s)497 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)498 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)499--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.13s)500--- PASS: TestStreamPushRequestLine (0.14s)501--- PASS: TestStreamPushStopsOnCancel (0.00s)502 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.05s)503 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.05s)504 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.05s)505 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.05s)506 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.05s)507 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)508--- PASS: TestSetClientTLS (0.02s)509 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)510 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)511 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.07s)512--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.22s)513--- PASS: TestDumpPathWriterError (0.22s)514--- PASS: TestDumpPathMatchesNix (0.26s)515--- PASS: TestRegisterUploadedObjectReusesConnections (0.27s)516--- PASS: TestTruncatedNARDumpIsNotCompleted (0.46s)517--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.69s)518--- PASS: TestUploadMultipart_PartsInParallel (0.72s)519--- PASS: TestSupersededNARStillUploadsListing (0.01s)520 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.09s)521 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.07s)522 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.72s)523--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)524--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)525--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.00s)526 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.10s)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/52f05e2dc9743da8/build/postgres4063804541/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/52f05e2dc9743da8/build/postgres4063804541/data -l logfile start556557/private/var/tb/2/scratch/52f05e2dc9743da8/build/postgres4063804541:5432 - no response5582026-10-25 19:18:09.515 UTC [33958] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5592026-10-25 19:18:09.515 UTC [33958] LOG: listening on Unix socket "/private/var/tb/2/scratch/52f05e2dc9743da8/build/postgres4063804541/.s.PGSQL.5432"5602026-10-25 19:18:09.517 UTC [33965] LOG: database system was shut down at 2026-10-25 19:18:09 UTC5612026-10-25 19:18:09.518 UTC [33958] LOG: database system is ready to accept connections562/private/var/tb/2/scratch/52f05e2dc9743da8/build/postgres4063804541:5432 - accepting connections563{"timestamp":"2026-10-25T19:18:09.734497Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"18a5dbea-af47-4429-b569-b3ef514a2037","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(7)"}564=== RUN TestService_AuthMiddleware565=== PAUSE TestService_AuthMiddleware566=== RUN TestService_AuthMiddleware_MTLSProxyHeader567=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader568=== RUN TestService_AuthMiddleware_MTLSBoundSubjects569=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects570=== RUN TestService_ReadAuthMiddleware571=== PAUSE TestService_ReadAuthMiddleware572=== RUN TestService_AuthMiddleware_OIDC573=== PAUSE TestService_AuthMiddleware_OIDC574=== RUN TestService_RequireScope_OIDC575=== PAUSE TestService_RequireScope_OIDC576=== RUN TestService_ReadScope_PublicByDefault577=== PAUSE TestService_ReadScope_PublicByDefault578=== RUN TestCacheConfigHandler579=== PAUSE TestCacheConfigHandler580=== RUN TestCacheStatsHandler581=== PAUSE TestCacheStatsHandler582=== RUN TestClientCADerivations583=== PAUSE TestClientCADerivations584=== RUN TestClientErrorHandling585=== PAUSE TestClientErrorHandling586=== RUN TestClientIntegration587=== PAUSE TestClientIntegration588=== RUN TestClientMultipleUploads589=== PAUSE TestClientMultipleUploads590=== RUN TestClientWithDependencies591=== PAUSE TestClientWithDependencies592=== RUN TestClientSharedPathCommittedMidPush593=== PAUSE TestClientSharedPathCommittedMidPush594=== RUN TestPinProtectsFromGC595=== PAUSE TestPinProtectsFromGC596=== RUN TestClientPushesUseOnePush597=== PAUSE TestClientPushesUseOnePush598=== RUN TestClientFallsBackToClosures599=== PAUSE TestClientFallsBackToClosures600=== RUN TestDeleteClosuresRacingPins601=== PAUSE TestDeleteClosuresRacingPins602=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock603=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock604=== RUN TestResolveDBConnectionString605=== PAUSE TestResolveDBConnectionString606=== RUN TestConnectWaitsForAPeerMigration607=== PAUSE TestConnectWaitsForAPeerMigration608=== RUN TestConnectSerialisesConcurrentMigrations609=== PAUSE TestConnectSerialisesConcurrentMigrations610=== RUN TestLeadElectsOneAndHandsOver611=== PAUSE TestLeadElectsOneAndHandsOver612=== RUN TestLeadIncumbentWinsAfterRestart6132026/10/25 19:18:09 INFO lead: acquired remote=192.0.2.1:12346142026/10/25 19:18:10 INFO lead: released remote=192.0.2.1:12346152026/10/25 19:18:10 INFO lead: acquired remote=192.0.2.1:12346162026/10/25 19:18:11 INFO lead: released remote=192.0.2.1:1234617--- PASS: TestLeadIncumbentWinsAfterRestart (1.91s)618=== RUN TestLeadIncumbentAnnouncesAtOnce619=== PAUSE TestLeadIncumbentAnnouncesAtOnce620=== RUN TestLeadEndsOnShutdown621=== PAUSE TestLeadEndsOnShutdown622=== RUN TestLeadEndsWhenItsConnectionHangs6232026/10/25 19:18:11 INFO lead: acquired remote=192.0.2.1:12346242026-10-25 19:18:13.109 UTC [34001] FATAL: terminating connection due to administrator command6252026/10/25 19:18:13 INFO lead: acquired remote=192.0.2.1:12346262026/10/25 19:18:14 WARN lead: lock connection lost error="timeout: context deadline exceeded"6272026/10/25 19:18:14 INFO lead: released remote=192.0.2.1:12346282026/10/25 19:18:14 INFO lead: released remote=192.0.2.1:1234629--- PASS: TestLeadEndsWhenItsConnectionHangs (2.78s)630=== RUN TestGCAdvisoryLockBlocksConcurrentRun631=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun632=== RUN TestGCBugBareHashReferences633=== PAUSE TestGCBugBareHashReferences634=== RUN TestGCMetrics635=== PAUSE TestGCMetrics636=== RUN TestPushDedupSurvivesConcurrentGC637=== PAUSE TestPushDedupSurvivesConcurrentGC638=== RUN TestDeduplicatedObjectsRecordedAsPending639=== PAUSE TestDeduplicatedObjectsRecordedAsPending640=== RUN TestGCSweepSkipsPendingObjects641=== PAUSE TestGCSweepSkipsPendingObjects642=== RUN TestTombstonedObjectOfferedWithoutWaiting643=== PAUSE TestTombstonedObjectOfferedWithoutWaiting644=== RUN TestGCSweepDeliversEachKeyOnce645=== PAUSE TestGCSweepDeliversEachKeyOnce646=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection647=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection648=== RUN TestForceGCDuringPushOffersSweptObject649=== PAUSE TestForceGCDuringPushOffersSweptObject650=== RUN TestFailedS3DeleteKeepsTombstone651=== PAUSE TestFailedS3DeleteKeepsTombstone652=== RUN TestSweepSkipsRowsLockedByPush653=== PAUSE TestSweepSkipsRowsLockedByPush654=== RUN TestRegisterCompletedObjectNeedsPendingRow655=== PAUSE TestRegisterCompletedObjectNeedsPendingRow656=== RUN TestGetExistingObjectsLocksRows657=== PAUSE TestGetExistingObjectsLocksRows658=== RUN TestSweepRechecksPendingAfterLocking659=== PAUSE TestSweepRechecksPendingAfterLocking660=== RUN TestPushWaitsForSweepHoldingRow661=== PAUSE TestPushWaitsForSweepHoldingRow662=== RUN TestCommitRacingPendingCleanupKeepsObjects663=== PAUSE TestCommitRacingPendingCleanupKeepsObjects664=== RUN TestGCEndsOnShutdown665=== PAUSE TestGCEndsOnShutdown666=== RUN TestGCTaskStore_StartNew667=== PAUSE TestGCTaskStore_StartNew668=== RUN TestGCTaskStore_DeduplicateSameParams669=== PAUSE TestGCTaskStore_DeduplicateSameParams670=== RUN TestGCTaskStore_ConflictDifferentParams671=== PAUSE TestGCTaskStore_ConflictDifferentParams672=== RUN TestGCTaskStore_GetEmpty673=== PAUSE TestGCTaskStore_GetEmpty674=== RUN TestGCTaskStore_GetReturnsLatest675=== PAUSE TestGCTaskStore_GetReturnsLatest676=== RUN TestGCTaskStore_CompletedAllowsNewTask677=== PAUSE TestGCTaskStore_CompletedAllowsNewTask678=== RUN TestGCTaskStore_PhaseUpdates679=== PAUSE TestGCTaskStore_PhaseUpdates680=== RUN TestGCTaskStore_Fail681=== PAUSE TestGCTaskStore_Fail682=== RUN TestGracefulShutdownDrainsInflight683=== PAUSE TestGracefulShutdownDrainsInflight684=== RUN TestService_healthCheckHandler685=== PAUSE TestService_healthCheckHandler686=== RUN TestService_readinessHandler687=== PAUSE TestService_readinessHandler688=== RUN TestGenerateLandingPage689=== PAUSE TestGenerateLandingPage690=== RUN TestChildrenInheritRaisedFileLimit691=== PAUSE TestChildrenInheritRaisedFileLimit692=== RUN TestCacheConfigHandlerMaxNarSize693=== PAUSE TestCacheConfigHandlerMaxNarSize694=== RUN TestCreatePendingClosureRejectsOversizedNAR695=== PAUSE TestCreatePendingClosureRejectsOversizedNAR696=== RUN TestNARDeduplicationMetadataUploadBug697=== PAUSE TestNARDeduplicationMetadataUploadBug698=== RUN TestMetricsInventory699=== PAUSE TestMetricsInventory700=== RUN TestMetricsCommit701=== PAUSE TestMetricsCommit702=== RUN TestService_NativeMTLS703=== PAUSE TestService_NativeMTLS704=== RUN TestServerTLSConfig705=== PAUSE TestServerTLSConfig706=== RUN TestMultipartCleanup707=== PAUSE TestMultipartCleanup708=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded709=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded710=== RUN TestPendingCleanupUsesOneCutoff711=== PAUSE TestPendingCleanupUsesOneCutoff712=== RUN TestPendingClosureFailureTracksEveryUpload713=== PAUSE TestPendingClosureFailureTracksEveryUpload714=== RUN TestPendingClosureFailureAbortsItsUploads715=== PAUSE TestPendingClosureFailureAbortsItsUploads716=== RUN TestObjectStatsTrigger717=== PAUSE TestObjectStatsTrigger718=== RUN TestObjectStatsUpdatedOncePerCommit719=== PAUSE TestObjectStatsUpdatedOncePerCommit720=== RUN TestReconnectLeavesObjectsUnlocked721=== PAUSE TestReconnectLeavesObjectsUnlocked722=== RUN TestOrphanedObjectsGC723=== PAUSE TestOrphanedObjectsGC724=== RUN TestOrphanedObjectsGCStressTest725=== PAUSE TestOrphanedObjectsGCStressTest726=== RUN TestCreatePin_ReservedPins727=== PAUSE TestCreatePin_ReservedPins728=== RUN TestConcurrentPinUpdatesAgree729=== PAUSE TestConcurrentPinUpdatesAgree730=== RUN TestCreatePinRejectsBadInput731=== PAUSE TestCreatePinRejectsBadInput732=== RUN TestDeletePinKeepsRowWhenS3Fails733=== PAUSE TestDeletePinKeepsRowWhenS3Fails734=== RUN TestPresentReportsOnlyClosureRoots735=== PAUSE TestPresentReportsOnlyClosureRoots736=== RUN TestPresentRefreshesOnlyStaleClosures737=== PAUSE TestPresentRefreshesOnlyStaleClosures738=== RUN TestPresentNotReportedWhileGCDeletesClosure739=== PAUSE TestPresentNotReportedWhileGCDeletesClosure740=== RUN TestParseSingleRange741=== PAUSE TestParseSingleRange742=== RUN TestProxyHeadersOnlyTrustedOnSocket7432026/10/25 19:18:14 INFO Starting HTTP server address=proxy.sock7442026/10/25 19:18:14 INFO Starting HTTP server address=127.0.0.1:562777452026/10/25 19:18:14 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7462026/10/25 19:18:14 INFO Shutdown signal received, draining in-flight requests timeout=10s747--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.16s)748=== RUN TestIsValidCachePath749=== PAUSE TestIsValidCachePath750=== RUN TestReadProxyNarinfo751=== PAUSE TestReadProxyNarinfo752=== RUN TestReadProxyNarinfoAlreadyDecompressed753=== PAUSE TestReadProxyNarinfoAlreadyDecompressed754=== RUN TestReadProxyContentNegotiation755=== PAUSE TestReadProxyContentNegotiation756=== RUN TestReadProxyNarStreaming757=== PAUSE TestReadProxyNarStreaming758=== RUN TestReadProxy404759=== PAUSE TestReadProxy404760=== RUN TestReadProxyInvalidPath761=== PAUSE TestReadProxyInvalidPath762=== RUN TestReadProxyHead763=== PAUSE TestReadProxyHead764=== RUN TestReadProxyOutlastsServerWriteTimeout765=== PAUSE TestReadProxyOutlastsServerWriteTimeout766=== RUN TestReadProxyConditionalGet767=== PAUSE TestReadProxyConditionalGet768=== RUN TestReadProxyRootRedirectsToIndexHTML769=== PAUSE TestReadProxyRootRedirectsToIndexHTML770=== RUN TestReadProxyDisabled771=== PAUSE TestReadProxyDisabled772=== RUN TestReadRedirectNar773=== PAUSE TestReadRedirectNar774=== RUN TestReadRedirectKeepsNarinfoProxied775=== PAUSE TestReadRedirectKeepsNarinfoProxied776=== RUN TestReadProxyRangeRequest777=== PAUSE TestReadProxyRangeRequest778=== RUN TestReadRedirectUsesPublicS3URL779=== PAUSE TestReadRedirectUsesPublicS3URL780=== RUN TestPush_OverlappingRootsStoreOneRowPerKey781=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey782=== RUN TestPush_CompleteCommitsEveryRoot783=== PAUSE TestPush_CompleteCommitsEveryRoot784=== RUN TestPush_RepeatedRootCommitsOnce785=== PAUSE TestPush_RepeatedRootCommitsOnce786=== RUN TestPush_CompleteWaitsForCleanupOfThePush787=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush788=== RUN TestPush_RootsAreLockedInByteOrder789=== PAUSE TestPush_RootsAreLockedInByteOrder790=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit791=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit792=== RUN TestPush_RejectsBadRequests793=== PAUSE TestPush_RejectsBadRequests794=== RUN TestPush_SignsNarinfosOfItsPendingObjects795=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects796=== RUN TestRedundantMultipartUpload797=== PAUSE TestRedundantMultipartUpload798=== RUN TestCompleteMultipartUpload_ErrorButObjectExists799=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists800=== RUN TestCompletedNarNotReofferedAcrossClosures801=== PAUSE TestCompletedNarNotReofferedAcrossClosures802=== RUN TestPresignedUploadRegisteredBeforeCommit803=== PAUSE TestPresignedUploadRegisteredBeforeCommit804=== RUN TestService_Rustfstest805=== PAUSE TestService_Rustfstest806=== RUN TestParseSize807=== PAUSE TestParseSize808=== RUN TestSkippedUploadsHandler809=== PAUSE TestSkippedUploadsHandler810=== RUN TestSystemdListenerNotActivated811--- PASS: TestSystemdListenerNotActivated (0.00s)812=== RUN TestWatchdogBeatsWhenHealthy813--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)814=== RUN TestWatchdogSkipsWhenUnhealthy8152026/10/25 19:18:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8162026/10/25 19:18:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8172026/10/25 19:18:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8182026/10/25 19:18:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8192026/10/25 19:18:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8202026/10/25 19:18:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8212026/10/25 19:18:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8222026/10/25 19:18:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8232026/10/25 19:18:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8242026/10/25 19:18:14 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"825--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)826=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle827=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle828=== RUN TestProxyWriteTimeout829=== PAUSE TestProxyWriteTimeout830=== RUN TestPendingClosureWriteTimeout831=== PAUSE TestPendingClosureWriteTimeout832=== RUN TestIsValidUploadKey833=== PAUSE TestIsValidUploadKey834=== RUN TestUploadHandlersRejectInvalidKeys835=== PAUSE TestUploadHandlersRejectInvalidKeys836=== RUN TestUploadHandlersRejectOversizedBody837=== PAUSE TestUploadHandlersRejectOversizedBody838=== RUN TestService_cleanupPendingClosuresHandler839=== PAUSE TestService_cleanupPendingClosuresHandler840=== RUN TestService_createPendingClosureHandler841=== PAUSE TestService_createPendingClosureHandler842=== RUN TestService_verifyS3Integrity843=== PAUSE TestService_verifyS3Integrity844=== RUN TestCompleteMultipartUnregistered845=== PAUSE TestCompleteMultipartUnregistered846=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT847=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT848=== CONT TestReadRedirectUsesPublicS3URL849=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT850=== CONT TestReadProxyDisabled851=== CONT TestCommitRacingPendingCleanupKeepsObjects852=== CONT TestService_AuthMiddleware_MTLSProxyHeader853=== CONT TestGCTaskStore_GetReturnsLatest854=== CONT TestOrphanedObjectsGCStressTest855=== CONT TestGCTaskStore_Fail856=== CONT TestReconnectLeavesObjectsUnlocked857=== CONT TestGCTaskStore_DeduplicateSameParams858=== CONT TestReadProxyRangeRequest859=== CONT TestOrphanedObjectsGC860=== CONT TestReadRedirectKeepsNarinfoProxied861=== CONT TestReadRedirectNar862=== CONT TestPush_OverlappingRootsStoreOneRowPerKey863=== CONT TestIsValidUploadKey864=== CONT TestReadProxyRootRedirectsToIndexHTML865=== CONT TestObjectStatsUpdatedOncePerCommit866=== CONT TestCompleteMultipartUnregistered867=== CONT TestGCTaskStore_StartNew868=== CONT TestService_createPendingClosureHandler869=== CONT TestPendingCleanupUsesOneCutoff870=== CONT TestGCTaskStore_GetEmpty871=== CONT TestGCEndsOnShutdown872=== CONT TestService_verifyS3Integrity873=== CONT TestNARDeduplicationMetadataUploadBug874--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)875=== CONT TestObjectStatsTrigger876=== CONT TestPendingClosureFailureAbortsItsUploads877=== RUN TestIsValidUploadKey/narinfo878=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded879=== RUN TestGCEndsOnShutdown/before_the_run880--- PASS: TestGCTaskStore_Fail (0.00s)881=== PAUSE TestGCEndsOnShutdown/before_the_run882--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)883--- PASS: TestGCTaskStore_StartNew (0.00s)884=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete885--- PASS: TestGCTaskStore_GetEmpty (0.00s)886=== PAUSE TestIsValidUploadKey/narinfo887=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete888=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark889=== RUN TestIsValidUploadKey/nar_zst890=== PAUSE TestIsValidUploadKey/nar_zst891=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark892=== RUN TestIsValidUploadKey/nar_xz893=== CONT TestMultipartCleanup894=== PAUSE TestIsValidUploadKey/nar_xz895=== RUN TestIsValidUploadKey/nar_plain896=== PAUSE TestIsValidUploadKey/nar_plain897=== RUN TestIsValidUploadKey/listing898=== PAUSE TestIsValidUploadKey/listing899=== 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 TestIsValidUploadKey/build_log_plus_in_name905=== RUN TestIsValidUploadKey/build_log_question_mark906=== PAUSE TestIsValidUploadKey/build_log_question_mark907=== RUN TestIsValidUploadKey/build_log_equals908=== PAUSE TestIsValidUploadKey/build_log_equals909=== RUN TestIsValidUploadKey/realisation910=== PAUSE TestIsValidUploadKey/realisation911=== RUN TestIsValidUploadKey/realisation_plus_in_output912=== PAUSE TestIsValidUploadKey/realisation_plus_in_output913=== RUN TestIsValidUploadKey/nix-cache-info914=== PAUSE TestIsValidUploadKey/nix-cache-info915=== RUN TestIsValidUploadKey/index.html916=== PAUSE TestIsValidUploadKey/index.html917=== RUN TestIsValidUploadKey/narinfo_key,_nar_type918=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type919=== RUN TestIsValidUploadKey/nar_key,_narinfo_type920=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type921=== RUN TestIsValidUploadKey/listing_key,_narinfo_type922=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type923=== RUN TestIsValidUploadKey/traversal924=== PAUSE TestIsValidUploadKey/traversal925=== RUN TestIsValidUploadKey/traversal_nar926=== PAUSE TestIsValidUploadKey/traversal_nar927=== RUN TestIsValidUploadKey/absolute928=== PAUSE TestIsValidUploadKey/absolute929=== RUN TestIsValidUploadKey/empty_key930=== PAUSE TestIsValidUploadKey/empty_key931=== RUN TestIsValidUploadKey/unknown_type932=== PAUSE TestIsValidUploadKey/unknown_type933=== CONT TestServerTLSConfig934=== RUN TestServerTLSConfig/no_client_CA935=== PAUSE TestServerTLSConfig/no_client_CA936=== RUN TestServerTLSConfig/missing_CA_file937=== PAUSE TestServerTLSConfig/missing_CA_file938=== RUN TestServerTLSConfig/not_a_PEM_file939=== PAUSE TestServerTLSConfig/not_a_PEM_file940=== CONT TestService_NativeMTLS9412026/10/25 19:18:15 INFO Aborted multipart uploads count=0 kept=09422026/10/25 19:18:15 WARN Force mode enabled - objects will be deleted immediately without grace period9432026/10/25 19:18:15 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=0944--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.89s)945=== CONT TestPendingClosureFailureTracksEveryUpload946=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false947=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false948=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true949=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true950=== CONT TestMetricsCommit9512026/10/25 19:18:15 INFO Vacuumed table table=pending_closures9522026/10/25 19:18:15 INFO Vacuumed table table=pending_objects9532026/10/25 19:18:15 INFO Vacuumed table table=multipart_uploads9542026/10/25 19:18:15 INFO Vacuumed table table=closures9552026/10/25 19:18:15 INFO Vacuumed table table=objects956--- PASS: TestCommitRacingPendingCleanupKeepsObjects (1.10s)957=== CONT TestService_readinessHandler958--- PASS: TestReadProxyDisabled (1.18s)959=== CONT TestCreatePendingClosureRejectsOversizedNAR9602026/10/25 19:18:16 INFO Received uploads request method=POST path=/api/pending_closures961--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)962=== CONT TestCacheConfigHandlerMaxNarSize963--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)964=== CONT TestMetricsInventory965--- PASS: TestReadRedirectUsesPublicS3URL (1.54s)966=== CONT TestChildrenInheritRaisedFileLimit967--- PASS: TestChildrenInheritRaisedFileLimit (0.01s)968=== CONT TestConnectWaitsForAPeerMigration9692026/10/25 19:18:16 WARN mTLS auth: subject not in bound subjects subject="CN=reader"9702026/10/25 19:18:16 WARN mTLS auth: subject not in bound subjects subject="CN=reader"971--- PASS: TestService_NativeMTLS (1.84s)972=== CONT TestPushWaitsForSweepHoldingRow9732026/10/25 19:18:17 INFO Received uploads request method=POST path=/api/pending_closures974=== CONT TestGetExistingObjectsLocksRows975--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.14s)9762026/10/25 19:18:17 INFO Received push request method=POST path=/api/pushes977--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (2.55s)978=== CONT TestSweepRechecksPendingAfterLocking979=== NAME TestNARDeduplicationMetadataUploadBug980 metadata_upload_test.go:48: First store path: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestNARDeduplicationMetadataUploadBug1991448794/001/store/n8zi9dlnx9x61rhfnfy6iwpb0bm5qdys-file1.txt981--- PASS: TestObjectStatsTrigger (3.38s)982=== CONT TestSweepSkipsRowsLockedByPush9832026/10/25 19:18:18 INFO Received push request method=POST path=/api/pushes9842026/10/25 19:18:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9852026/10/25 19:18:18 INFO Uploading n8zi9dlnx9x61rhfnfy6iwpb0bm5qdys-file1.txt (160B)986--- PASS: TestReconnectLeavesObjectsUnlocked (3.64s)9872026/10/25 19:18:18 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"988=== CONT TestRegisterCompletedObjectNeedsPendingRow9892026/10/25 19:18:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9902026/10/25 19:18:18 WARN Failed to register uploaded object key=n8zi9dlnx9x61rhfnfy6iwpb0bm5qdys.ls error="server returned 404: 404 page not found\n"9912026/10/25 19:18:18 INFO Signed narinfos id=1 count=19922026/10/25 19:18:18 INFO Uploading 1 narinfos9932026/10/25 19:18:18 INFO Received complete push request method=POST path=/api/pushes/1/complete9942026/10/25 19:18:18 WARN Failed to register uploaded object key=n8zi9dlnx9x61rhfnfy6iwpb0bm5qdys.narinfo error="server returned 404: 404 page not found\n"9952026/10/25 19:18:18 INFO Completed push id=1 objects=3 duration=29.136083ms9962026/10/25 19:18:18 INFO Upload complete. (322ms)997=== NAME TestNARDeduplicationMetadataUploadBug998 metadata_upload_test.go:54: Retrieved narinfo from S3:999 StorePath: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestNARDeduplicationMetadataUploadBug1991448794/001/store/n8zi9dlnx9x61rhfnfy6iwpb0bm5qdys-file1.txt1000 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1001 Compression: zstd1002 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1003 NarSize: 1601004 References: 1005 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1006 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1007 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1008 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1009 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestNARDeduplicationMetadataUploadBug1991448794/001/store/y0bfw61mk7ma3g5vhhc19j9gwym9p40z-file2.txt1010=== NAME TestOrphanedObjectsGC1011 orphaned_objects_gc_test.go:287: GC Test Summary:1012 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1013 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1014 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1015 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1016 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1017--- PASS: TestOrphanedObjectsGC (4.05s)1018=== CONT TestForceGCDuringPushOffersSweptObject1019=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1020=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1021=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1022=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1023=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10242026/10/25 19:18:19 INFO Received push request method=POST path=/api/pushes10252026/10/25 19:18:19 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1026--- PASS: TestReadProxyRangeRequest (4.15s)1027=== CONT TestGCSweepDeliversEachKeyOnce10282026/10/25 19:18:19 WARN Failed to register uploaded object key=y0bfw61mk7ma3g5vhhc19j9gwym9p40z.ls error="server returned 404: 404 page not found\n"10292026/10/25 19:18:19 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign10302026/10/25 19:18:19 INFO Signed narinfos id=2 count=110312026/10/25 19:18:19 INFO Uploading 1 narinfos10322026/10/25 19:18:19 INFO Received complete push request method=POST path=/api/pushes/2/complete10332026/10/25 19:18:19 WARN Failed to register uploaded object key=y0bfw61mk7ma3g5vhhc19j9gwym9p40z.narinfo error="server returned 404: 404 page not found\n"10342026/10/25 19:18:19 INFO Completed push id=2 objects=3 duration=676.875µs10352026/10/25 19:18:19 INFO Upload complete. (145ms)1036=== NAME TestNARDeduplicationMetadataUploadBug1037 metadata_upload_test.go:76: Retrieved narinfo from S3:1038 StorePath: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestNARDeduplicationMetadataUploadBug1991448794/001/store/y0bfw61mk7ma3g5vhhc19j9gwym9p40z-file2.txt1039 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1040 Compression: zstd1041 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1042 NarSize: 1601043 References: 1044 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1045 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1046 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1047 {"version":1,"root":{"type":"regular","size":44}}1048--- PASS: TestNARDeduplicationMetadataUploadBug (4.32s)1049=== CONT TestFailedS3DeleteKeepsTombstone1050--- PASS: TestReadRedirectNar (4.42s)1051=== CONT TestGCSweepSkipsPendingObjects10522026/10/25 19:18:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10532026/10/25 19:18:19 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1054--- PASS: TestCompleteMultipartUnregistered (4.58s)1055=== CONT TestDeduplicatedObjectsRecordedAsPending1056--- PASS: TestReadRedirectKeepsNarinfoProxied (4.85s)1057=== CONT TestPushDedupSurvivesConcurrentGC10582026/10/25 19:18:19 INFO Received uploads request method=POST path=/api/pending_closures10592026/10/25 19:18:20 INFO Received uploads request method=POST path=/api/pending_closures10602026/10/25 19:18:20 INFO Received cleanup request method=DELETE path=/api/pending_closures10612026/10/25 19:18:20 INFO Received uploads request method=POST path=/api/pending_closures1062--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (5.41s)1063=== CONT TestGCMetrics10642026/10/25 19:18:20 INFO Received uploads request method=POST path=/api/pending_closures1065--- PASS: TestPendingClosureFailureAbortsItsUploads (5.68s)1066=== CONT TestGCBugBareHashReferences10672026/10/25 19:18:20 INFO Received uploads request method=POST path=/api/pending_closures10682026/10/25 19:18:21 INFO Received uploads request method=POST path=/api/pending_closures10692026/10/25 19:18:21 INFO Received uploads request method=POST path=/api/pending_closures10702026/10/25 19:18:21 INFO Received uploads request method=POST path=/api/pending_closures10712026/10/25 19:18:21 INFO Received uploads request method=POST path=/api/pending_closures1072--- PASS: TestObjectStatsUpdatedOncePerCommit (6.93s)1073=== CONT TestGCAdvisoryLockBlocksConcurrentRun10742026/10/25 19:18:22 INFO Received cleanup request method=DELETE path=/api/pending_closures10752026/10/25 19:18:22 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket26/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10762026/10/25 19:18:22 INFO Aborted multipart uploads count=0 kept=110772026/10/25 19:18:22 INFO Received cleanup request method=DELETE path=/api/pending_closures10782026/10/25 19:18:22 INFO Aborted multipart uploads count=1 kept=01079=== CONT TestTombstonedObjectOfferedWithoutWaiting1080--- PASS: TestMultipartCleanup (7.25s)1081--- PASS: TestReadProxyRootRedirectsToIndexHTML (7.41s)1082=== CONT TestLeadIncumbentAnnouncesAtOnce10832026/10/25 19:18:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1084--- PASS: TestMetricsInventory (6.63s)1085=== CONT TestLeadEndsOnShutdown10862026/10/25 19:18:22 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLjFlOGY0NWVmLTE0NWYtNGVjYi04ZjZmLTY2ZmYxNzU1NGVhNngxNzkyOTU1OTAwODI1MzEzMDAw parts=1010872026/10/25 19:18:22 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10882026/10/25 19:18:22 INFO Completed upload id=1 objects=2 duration=12.591083ms10892026/10/25 19:18:23 INFO Received push request method=POST path=/api/pushes10902026/10/25 19:18:23 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10912026/10/25 19:18:23 INFO Received uploads request method=POST path=/api/pending_closures10922026/10/25 19:18:23 INFO Received uploads request method=POST path=/api/pending_closures10932026/10/25 19:18:23 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10942026/10/25 19:18:23 WARN Found objects in DB but missing from S3, will re-upload count=110952026/10/25 19:18:23 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete10962026/10/25 19:18:23 INFO Completed upload id=3 objects=2 duration=1.048625ms10972026/10/25 19:18:23 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLjlhOGEwN2YxLTA0MjgtNDVkNy1hOTI1LTJkOTBjZmU2MjM0MXgxNzkyOTU1OTAxMTYxNjcxMDAw parts=101098--- PASS: TestService_verifyS3Integrity (8.35s)1099=== CONT TestConnectSerialisesConcurrentMigrations11002026/10/25 19:18:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11012026/10/25 19:18:23 INFO Completed upload id=1 objects=2 duration=20.025459ms11022026/10/25 19:18:23 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011032026/10/25 19:18:23 INFO Received uploads request method=POST path=/api/pending_closures11042026/10/25 19:18:23 INFO Starting cleanup of old closures method=DELETE path=/api/closures11052026/10/25 19:18:23 INFO Aborted multipart uploads count=0 kept=011062026/10/25 19:18:23 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=01107--- PASS: TestConnectWaitsForAPeerMigration (6.94s)1108=== CONT TestLeadElectsOneAndHandsOver11092026/10/25 19:18:23 INFO Vacuumed table table=pending_closures11102026/10/25 19:18:23 INFO Vacuumed table table=pending_objects11112026/10/25 19:18:23 WARN readiness check failed error="closed pool"11122026/10/25 19:18:23 INFO Vacuumed table table=multipart_uploads1113--- PASS: TestService_readinessHandler (7.49s)1114=== CONT TestReadProxyNarinfo11152026/10/25 19:18:23 INFO Vacuumed table table=closures11162026/10/25 19:18:23 INFO Vacuumed table table=objects11172026/10/25 19:18:23 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001118--- PASS: TestService_createPendingClosureHandler (8.70s)1119=== CONT TestReadProxyOutlastsServerWriteTimeout11202026/10/25 19:18:23 INFO Received uploads request method=POST path=/api/pending_closures1121--- PASS: TestGetExistingObjectsLocksRows (7.24s)1122=== CONT TestReadProxyHead1123--- PASS: TestPushWaitsForSweepHoldingRow (7.61s)1124=== CONT TestReadProxyConditionalGet11252026/10/25 19:18:24 INFO Aborted multipart uploads count=0 kept=011262026/10/25 19:18:24 WARN Force mode enabled - objects will be deleted immediately without grace period11272026/10/25 19:18:24 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011282026/10/25 19:18:24 INFO Vacuumed table table=pending_closures11292026/10/25 19:18:24 INFO Vacuumed table table=pending_objects11302026/10/25 19:18:24 INFO Vacuumed table table=multipart_uploads11312026/10/25 19:18:24 INFO Vacuumed table table=closures11322026/10/25 19:18:24 INFO Vacuumed table table=objects1133--- PASS: TestSweepRechecksPendingAfterLocking (7.36s)1134=== CONT TestReadProxy40411352026/10/25 19:18:24 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11362026/10/25 19:18:25 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLmE5MmIyYjVjLTFmNGQtNGViOC05ZmEwLTExNGY4MjNhNmY5NXgxNzkyOTU1OTAzMTMxNDcxMDAw parts=1011372026/10/25 19:18:25 INFO Aborted multipart uploads count=0 kept=011382026/10/25 19:18:25 WARN Force mode enabled - objects will be deleted immediately without grace period11392026/10/25 19:18:25 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=011402026/10/25 19:18:25 INFO Vacuumed table table=pending_closures11412026/10/25 19:18:25 INFO Vacuumed table table=pending_objects11422026/10/25 19:18:25 INFO Vacuumed table table=multipart_uploads11432026/10/25 19:18:25 INFO Vacuumed table table=closures11442026/10/25 19:18:25 INFO Vacuumed table table=objects11452026/10/25 19:18:25 INFO Aborted multipart uploads count=0 kept=011462026/10/25 19:18:25 WARN Force mode enabled - objects will be deleted immediately without grace period1147--- PASS: TestRegisterCompletedObjectNeedsPendingRow (6.67s)1148=== CONT TestReadProxyNarStreaming11492026/10/25 19:18:25 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=011502026/10/25 19:18:25 INFO Vacuumed table table=pending_closures11512026/10/25 19:18:25 INFO Vacuumed table table=pending_objects11522026/10/25 19:18:25 INFO Vacuumed table table=multipart_uploads11532026/10/25 19:18:25 INFO Vacuumed table table=closures11542026/10/25 19:18:25 INFO Vacuumed table table=objects1155--- PASS: TestSweepSkipsRowsLockedByPush (7.16s)1156=== CONT TestReadProxyInvalidPath11572026/10/25 19:18:25 INFO Received uploads request method=POST path=/api/pending_closures1158--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (6.89s)1159=== CONT TestReadProxyContentNegotiation11602026/10/25 19:18:26 INFO Aborted multipart uploads count=1 kept=011612026/10/25 19:18:26 INFO Received cleanup request method=DELETE path=/api/pending_closures11622026/10/25 19:18:26 INFO Aborted multipart uploads count=1 kept=011632026/10/25 19:18:26 INFO Aborted multipart uploads count=0 kept=011642026/10/25 19:18:26 WARN Force mode enabled - objects will be deleted immediately without grace period1165--- PASS: TestPendingCleanupUsesOneCutoff (11.36s)1166=== CONT TestReadProxyNarinfoAlreadyDecompressed11672026-10-25 19:18:26.324 UTC [34221] ERROR: duplicate key value violates unique constraint "pg_type_typname_nsp_index"11682026-10-25 19:18:26.324 UTC [34221] DETAIL: Key (typname, typnamespace)=(goose_db_version, 2200) already exists.11692026-10-25 19:18:26.324 UTC [34221] STATEMENT: CREATE TABLE goose_db_version (1170 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1171 version_id bigint NOT NULL,1172 is_applied boolean NOT NULL,1173 tstamp timestamp NOT NULL DEFAULT now()1174 )11752026/10/25 19:18:26 INFO Received uploads request method=POST path=/api/pending_closures11762026/10/25 19:18:26 INFO Aborted multipart uploads count=0 kept=011772026/10/25 19:18:26 WARN Force mode enabled - objects will be deleted immediately without grace period11782026/10/25 19:18:26 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=011792026/10/25 19:18:26 INFO Vacuumed table table=pending_closures11802026/10/25 19:18:26 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=011812026/10/25 19:18:26 INFO Received uploads request method=POST path=/api/pending_closures11822026/10/25 19:18:26 INFO Vacuumed table table=pending_objects11832026/10/25 19:18:26 INFO Vacuumed table table=pending_closures11842026/10/25 19:18:26 INFO Vacuumed table table=multipart_uploads11852026/10/25 19:18:26 INFO Vacuumed table table=pending_objects11862026/10/25 19:18:26 INFO Vacuumed table table=closures11872026/10/25 19:18:26 INFO Vacuumed table table=multipart_uploads11882026/10/25 19:18:26 INFO Vacuumed table table=closures11892026/10/25 19:18:26 INFO Vacuumed table table=objects11902026/10/25 19:18:26 INFO Vacuumed table table=objects11912026/10/25 19:18:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1192--- PASS: TestGCSweepDeliversEachKeyOnce (7.94s)1193=== CONT TestCompletedNarNotReofferedAcrossClosures1194--- PASS: TestGCSweepSkipsPendingObjects (7.73s)1195=== CONT TestProxyWriteTimeout1196=== RUN TestProxyWriteTimeout/narinfo1197=== PAUSE TestProxyWriteTimeout/narinfo1198=== RUN TestProxyWriteTimeout/1_GiB_nar1199=== PAUSE TestProxyWriteTimeout/1_GiB_nar1200=== RUN TestProxyWriteTimeout/10_GiB_nar1201=== PAUSE TestProxyWriteTimeout/10_GiB_nar1202=== RUN TestProxyWriteTimeout/unknown_size1203=== PAUSE TestProxyWriteTimeout/unknown_size1204=== CONT TestPresignedUploadRegisteredBeforeCommit12052026/10/25 19:18:27 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLjc0YzE0NmQ0LTY2N2UtNGIzMS1iOGExLWExODMyYmQxYTBlZXgxNzkyOTU1OTAzMTMwNjkzMDAw parts=1012062026/10/25 19:18:27 INFO Aborted multipart uploads count=0 kept=012072026/10/25 19:18:27 WARN Force mode enabled - objects will be deleted immediately without grace period12082026/10/25 19:18:27 INFO Received complete push request method=POST path=/api/pushes/1/complete12092026/10/25 19:18:27 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12102026/10/25 19:18:27 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1211--- PASS: TestFailedS3DeleteKeepsTombstone (7.99s)12122026/10/25 19:18:27 INFO Completed push id=1 objects=4 duration=21.250666ms1213=== CONT TestCompleteMultipartUpload_ErrorButObjectExists12142026/10/25 19:18:27 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12152026/10/25 19:18:27 INFO Completed upload id=2 objects=2 duration=2.955875ms1216--- PASS: TestMetricsCommit (11.48s)1217=== CONT TestRedundantMultipartUpload12182026/10/25 19:18:27 INFO Received uploads request method=POST path=/api/pending_closures1219--- PASS: TestConnectSerialisesConcurrentMigrations (4.08s)1220=== CONT TestPush_SignsNarinfosOfItsPendingObjects1221--- PASS: TestDeduplicatedObjectsRecordedAsPending (7.91s)1222=== CONT TestPresentRefreshesOnlyStaleClosures12232026/10/25 19:18:27 INFO Received uploads request method=POST path=/api/pending_closures12242026/10/25 19:18:28 INFO Aborted multipart uploads count=0 kept=012252026/10/25 19:18:28 INFO Aborted multipart uploads count=0 kept=012262026/10/25 19:18:28 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=012272026/10/25 19:18:28 WARN Force mode enabled - objects will be deleted immediately without grace period12282026/10/25 19:18:28 INFO Vacuumed table table=pending_closures12292026/10/25 19:18:28 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=012302026/10/25 19:18:28 INFO Vacuumed table table=pending_closures12312026/10/25 19:18:28 INFO Vacuumed table table=pending_objects12322026/10/25 19:18:28 INFO Vacuumed table table=multipart_uploads12332026/10/25 19:18:28 INFO Vacuumed table table=closures12342026/10/25 19:18:28 INFO Vacuumed table table=pending_objects12352026/10/25 19:18:28 INFO Vacuumed table table=objects12362026/10/25 19:18:28 INFO Vacuumed table table=multipart_uploads1237--- PASS: TestGCMetrics (7.81s)1238=== CONT TestIsValidCachePath1239=== RUN TestIsValidCachePath/narinfo1240=== PAUSE TestIsValidCachePath/narinfo1241=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1242=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1243=== RUN TestIsValidCachePath/nar_zst1244=== PAUSE TestIsValidCachePath/nar_zst1245=== RUN TestIsValidCachePath/nar_xz1246=== PAUSE TestIsValidCachePath/nar_xz1247=== RUN TestIsValidCachePath/nar_bz21248=== PAUSE TestIsValidCachePath/nar_bz21249=== RUN TestIsValidCachePath/nar_uncompressed1250=== PAUSE TestIsValidCachePath/nar_uncompressed1251=== RUN TestIsValidCachePath/ls1252=== PAUSE TestIsValidCachePath/ls1253=== RUN TestIsValidCachePath/log1254=== PAUSE TestIsValidCachePath/log1255=== RUN TestIsValidCachePath/realisation1256=== PAUSE TestIsValidCachePath/realisation1257=== RUN TestIsValidCachePath/nix-cache-info1258=== PAUSE TestIsValidCachePath/nix-cache-info1259=== RUN TestIsValidCachePath/index.html1260=== PAUSE TestIsValidCachePath/index.html1261=== RUN TestIsValidCachePath/traversal_parent1262=== PAUSE TestIsValidCachePath/traversal_parent1263=== RUN TestIsValidCachePath/traversal_in_middle1264=== PAUSE TestIsValidCachePath/traversal_in_middle1265=== RUN TestIsValidCachePath/invalid_char_e1266=== PAUSE TestIsValidCachePath/invalid_char_e1267=== RUN TestIsValidCachePath/invalid_char_u1268=== PAUSE TestIsValidCachePath/invalid_char_u1269=== RUN TestIsValidCachePath/random_path1270=== PAUSE TestIsValidCachePath/random_path1271=== RUN TestIsValidCachePath/empty1272=== PAUSE TestIsValidCachePath/empty1273=== RUN TestIsValidCachePath/leading_slash1274=== PAUSE TestIsValidCachePath/leading_slash1275=== RUN TestIsValidCachePath/wrong_extension1276=== PAUSE TestIsValidCachePath/wrong_extension1277=== RUN TestIsValidCachePath/short_hash1278=== PAUSE TestIsValidCachePath/short_hash1279=== CONT TestParseSingleRange1280=== RUN TestParseSingleRange/none1281=== PAUSE TestParseSingleRange/none1282=== RUN TestParseSingleRange/unknown_unit1283=== PAUSE TestParseSingleRange/unknown_unit12842026/10/25 19:18:28 INFO Vacuumed table table=closures1285=== RUN TestParseSingleRange/multi-range_ignored1286=== PAUSE TestParseSingleRange/multi-range_ignored1287=== RUN TestParseSingleRange/malformed_no_dash1288=== PAUSE TestParseSingleRange/malformed_no_dash1289=== RUN TestParseSingleRange/malformed_both_empty1290=== PAUSE TestParseSingleRange/malformed_both_empty1291=== RUN TestParseSingleRange/malformed_end_before_start1292=== PAUSE TestParseSingleRange/malformed_end_before_start1293=== RUN TestParseSingleRange/closed1294=== PAUSE TestParseSingleRange/closed1295=== RUN TestParseSingleRange/open-ended1296=== PAUSE TestParseSingleRange/open-ended1297=== RUN TestParseSingleRange/end_clamped_to_size1298=== PAUSE TestParseSingleRange/end_clamped_to_size1299=== RUN TestParseSingleRange/suffix1300=== PAUSE TestParseSingleRange/suffix1301=== RUN TestParseSingleRange/suffix_exceeds_size1302=== PAUSE TestParseSingleRange/suffix_exceeds_size1303=== RUN TestParseSingleRange/single_byte1304=== PAUSE TestParseSingleRange/single_byte1305=== RUN TestParseSingleRange/start_past_EOF1306=== PAUSE TestParseSingleRange/start_past_EOF1307=== RUN TestParseSingleRange/start_far_past_EOF1308=== PAUSE TestParseSingleRange/start_far_past_EOF1309=== CONT TestPresentNotReportedWhileGCDeletesClosure1310=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1311=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1312=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1313=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1314=== CONT TestPresentReportsOnlyClosureRoots13152026/10/25 19:18:28 INFO Vacuumed table table=objects13162026/10/25 19:18:28 INFO Aborted multipart uploads count=0 kept=013172026/10/25 19:18:28 WARN Force mode enabled - objects will be deleted immediately without grace period13182026/10/25 19:18:28 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=013192026/10/25 19:18:28 INFO Vacuumed table table=pending_closures13202026/10/25 19:18:28 INFO Vacuumed table table=pending_objects13212026/10/25 19:18:28 INFO Vacuumed table table=multipart_uploads13222026/10/25 19:18:28 INFO Vacuumed table table=closures13232026/10/25 19:18:28 INFO Vacuumed table table=objects1324--- PASS: TestPushDedupSurvivesConcurrentGC (8.52s)1325=== CONT TestService_healthCheckHandler1326--- PASS: TestGCBugBareHashReferences (8.03s)1327=== CONT TestGenerateLandingPage1328--- PASS: TestGenerateLandingPage (0.01s)1329=== CONT TestGracefulShutdownDrainsInflight13302026/10/25 19:18:28 INFO Starting HTTP server address=127.0.0.1:5650013312026/10/25 19:18:28 INFO Shutdown signal received, draining in-flight requests timeout=10s1332--- PASS: TestGracefulShutdownDrainsInflight (0.09s)1333=== CONT TestPush_RootsAreLockedInByteOrder13342026/10/25 19:18:28 INFO Received uploads request method=POST path=/api/pending_closures1335--- PASS: TestTombstonedObjectOfferedWithoutWaiting (6.86s)1336=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit13372026/10/25 19:18:29 INFO lead: acquired remote=192.0.2.1:123413382026/10/25 19:18:29 INFO lead: released remote=192.0.2.1:12341339--- PASS: TestLeadIncumbentAnnouncesAtOnce (6.98s)1340=== CONT TestPush_RejectsBadRequests13412026/10/25 19:18:29 INFO lead: acquired remote=192.0.2.1:123413422026/10/25 19:18:29 INFO lead: acquired remote=192.0.2.1:12341343=== NAME TestOrphanedObjectsGCStressTest1344 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1345 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion13462026/10/25 19:18:30 INFO lead: released remote=192.0.2.1:12341347--- PASS: TestLeadEndsOnShutdown (7.99s)1348=== CONT TestGCTaskStore_PhaseUpdates1349--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1350=== CONT TestClientErrorHandling1351=== RUN TestClientErrorHandling/InvalidStorePath1352=== PAUSE TestClientErrorHandling/InvalidStorePath1353=== RUN TestClientErrorHandling/InvalidAuthToken1354=== PAUSE TestClientErrorHandling/InvalidAuthToken1355=== RUN TestClientErrorHandling/ServerNotAvailable1356=== PAUSE TestClientErrorHandling/ServerNotAvailable1357=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock13582026/10/25 19:18:30 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1359--- PASS: TestReadProxyNarinfo (7.35s)1360=== CONT TestDeleteClosuresRacingPins1361--- PASS: TestReadProxyHead (6.60s)1362=== CONT TestClientFallsBackToClosures1363--- PASS: TestReadProxyConditionalGet (6.73s)1364=== CONT TestResolveDBConnectionString1365=== RUN TestResolveDBConnectionString/flag_wins1366=== PAUSE TestResolveDBConnectionString/flag_wins1367=== RUN TestResolveDBConnectionString/file_when_flag_empty1368=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1369=== RUN TestResolveDBConnectionString/missing_file_is_an_error1370=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1371=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1372=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1373=== RUN TestResolveDBConnectionString/nothing_configured1374=== PAUSE TestResolveDBConnectionString/nothing_configured1375=== CONT TestPinProtectsFromGC13762026/10/25 19:18:31 INFO lead: released remote=192.0.2.1:123413772026/10/25 19:18:31 INFO lead: acquired remote=192.0.2.1:12341378--- PASS: TestReadProxyNarStreaming (6.48s)1379=== CONT TestCacheStatsHandler1380--- PASS: TestReadProxyContentNegotiation (6.28s)13812026/10/25 19:18:32 WARN Rate limiter enabled after throttle name=s3-test rate=513822026/10/25 19:18:32 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."1383=== CONT TestPendingClosureWriteTimeout1384=== RUN TestPendingClosureWriteTimeout/empty1385=== PAUSE TestPendingClosureWriteTimeout/empty1386=== RUN TestPendingClosureWriteTimeout/400_objects1387=== PAUSE TestPendingClosureWriteTimeout/400_objects1388=== RUN TestPendingClosureWriteTimeout/670k_objects1389=== PAUSE TestPendingClosureWriteTimeout/670k_objects1390=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1391=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1392=== CONT TestService_cleanupPendingClosuresHandler1393--- PASS: TestReadProxyInvalidPath (6.75s)1394=== CONT TestCacheConfigHandler1395=== RUN TestCacheConfigHandler/full_config,_no_issuer1396=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1397=== RUN TestCacheConfigHandler/no_cache_url_configured1398=== PAUSE TestCacheConfigHandler/no_cache_url_configured1399=== RUN TestCacheConfigHandler/no_signing_keys1400=== PAUSE TestCacheConfigHandler/no_signing_keys1401=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1402=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1403=== CONT TestClientSharedPathCommittedMidPush14042026/10/25 19:18:32 INFO lead: released remote=192.0.2.1:123414052026/10/25 19:18:32 WARN Rate limiter backed off name=s3-test rate=514062026/10/25 19:18:32 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."1407--- PASS: TestLeadElectsOneAndHandsOver (8.91s)1408=== CONT TestParseSize1409--- PASS: TestParseSize (0.00s)1410=== CONT TestCreatePin_ReservedPins1411--- PASS: TestReadProxy404 (7.50s)1412=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle14132026/10/25 19:18:32 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56570/oidc1414=== CONT TestClientPushesUseOnePush1415--- PASS: TestReadProxyNarinfoAlreadyDecompressed (6.22s)14162026/10/25 19:18:32 INFO Received uploads request method=POST path=/api/pending_closures14172026/10/25 19:18:33 INFO Received uploads request method=POST path=/api/pending_closures14182026/10/25 19:18:33 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst14192026/10/25 19:18:33 INFO Received uploads request method=POST path=/api/pending_closures1420--- PASS: TestPresignedUploadRegisteredBeforeCommit (6.41s)1421=== CONT TestUploadHandlersRejectInvalidKeys1422=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1423=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1424=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1425=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1426=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1427=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1428=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1429=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1430=== CONT TestClientCADerivations14312026/10/25 19:18:33 INFO Received uploads request method=POST path=/api/pending_closures14322026/10/25 19:18:33 INFO Received uploads request method=POST path=/api/pending_closures1433--- PASS: TestPresentRefreshesOnlyStaleClosures (6.92s)1434=== CONT TestSkippedUploadsHandler14352026/10/25 19:18:34 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001436--- PASS: TestSkippedUploadsHandler (0.01s)1437=== CONT TestPush_RepeatedRootCommitsOnce14382026/10/25 19:18:34 INFO Received uploads request method=POST path=/api/pending_closures1439--- PASS: TestReadProxyOutlastsServerWriteTimeout (10.99s)1440=== CONT TestPush_CompleteWaitsForCleanupOfThePush14412026/10/25 19:18:35 INFO Received push request method=POST path=/api/pushes14422026/10/25 19:18:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14432026/10/25 19:18:35 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLjE4ZDA2ZDU2LWI4N2YtNDUxZS1iMDkyLTI5NjQ1NDhhYTMwMXgxNzkyOTU1OTE0NjgxNjQyMDAw14442026/10/25 19:18:35 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLjE4ZDA2ZDU2LWI4N2YtNDUxZS1iMDkyLTI5NjQ1NDhhYTMwMXgxNzkyOTU1OTE0NjgxNjQyMDAw error="Delete \"http://localhost:56253/bucket62/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLjE4ZDA2ZDU2LWI4N2YtNDUxZS1iMDkyLTI5NjQ1NDhhYTMwMXgxNzkyOTU1OTE0NjgxNjQyMDAw\": injected: abort refused"14452026/10/25 19:18:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14462026/10/25 19:18:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14472026/10/25 19:18:35 INFO Signed narinfos id=1 count=114482026/10/25 19:18:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14492026/10/25 19:18:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14502026/10/25 19:18:35 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLjE4ZDA2ZDU2LWI4N2YtNDUxZS1iMDkyLTI5NjQ1NDhhYTMwMXgxNzkyOTU1OTE0NjgxNjQyMDAw14512026/10/25 19:18:35 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"14522026/10/25 19:18:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14532026/10/25 19:18:35 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"14542026/10/25 19:18:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14552026/10/25 19:18:35 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=114562026/10/25 19:18:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14572026/10/25 19:18:35 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo14582026/10/25 19:18:35 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLjE4ZDA2ZDU2LWI4N2YtNDUxZS1iMDkyLTI5NjQ1NDhhYTMwMXgxNzkyOTU1OTE0NjgxNjQyMDAw parts=11459--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (7.94s)1460--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (8.08s)1461=== CONT TestService_ReadScope_PublicByDefault1462=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14632026/10/25 19:18:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14642026/10/25 19:18:35 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLmMyNjQ3YTI2LTk5YTctNGFiZi1hZDI0LWE2ZDJhMWUyMDMzYXgxNzkyOTU1OTEyODc3NTcyMDAw parts=1214652026/10/25 19:18:35 INFO Received uploads request method=POST path=/api/pending_closures1466--- PASS: TestPresentReportsOnlyClosureRoots (7.56s)1467=== CONT TestClientIntegration1468--- PASS: TestCompletedNarNotReofferedAcrossClosures (8.85s)1469=== CONT TestService_RequireScope_OIDC1470--- PASS: TestService_healthCheckHandler (7.72s)1471=== CONT TestClientWithDependencies14722026/10/25 19:18:36 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56620/oidc14732026/10/25 19:18:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14742026/10/25 19:18:36 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"14752026/10/25 19:18:36 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLjRmMGIzOWVjLTllYTAtNDMxYy04MDZhLTdjMGRlMTI2MDM4MHgxNzkyOTU1OTEzNzk5OTU0MDAw parts=1214762026/10/25 19:18:36 INFO Received uploads request method=POST path=/api/pending_closures1477--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (14.83s)1478=== CONT TestService_ReadAuthMiddleware14792026/10/25 19:18:36 INFO Received uploads request method=POST path=/api/pending_closures14802026/10/25 19:18:36 INFO Received push request method=POST path=/api/pushes14812026/10/25 19:18:37 INFO Received push request method=POST path=/api/pushes1482=== RUN TestPush_RejectsBadRequests/no_roots1483=== PAUSE TestPush_RejectsBadRequests/no_roots1484=== RUN TestPush_RejectsBadRequests/no_objects1485=== PAUSE TestPush_RejectsBadRequests/no_objects1486=== RUN TestPush_RejectsBadRequests/bad_root1487=== PAUSE TestPush_RejectsBadRequests/bad_root1488=== RUN TestPush_RejectsBadRequests/root_not_in_objects1489=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1490=== CONT TestClientMultipleUploads14912026/10/25 19:18:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14922026/10/25 19:18:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14932026/10/25 19:18:39 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLjk0OWIxMjBkLTY0YzctNDM1Mi1hODNjLTM2ZTdhNTQzNmQ3MXgxNzkyOTU1OTE2NzQwNzU5MDAw error="Get \"http://127.0.0.1:1/bucket60/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"14942026/10/25 19:18:39 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLjQzODExM2Y1LTc2MDYtNDgzMC04NTNiLWQxMjA4OTUzNjliZXgxNzkyOTU1OTE2Njg3MzM2MDAw parts=1214952026/10/25 19:18:39 INFO Received cleanup request method=DELETE path=/api/pending_closures14962026/10/25 19:18:39 INFO Aborted multipart uploads count=1 kept=014972026/10/25 19:18:39 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLmFlZTBhNjA4LTY5NjktNGRjYS1iYjFmLWVjMWU2NzM0NTg1YXgxNzkyOTU1OTE3MDEyOTg2MDAw parts=101498--- PASS: TestRedundantMultipartUpload (12.29s)1499=== CONT TestService_AuthMiddleware_OIDC15002026/10/25 19:18:39 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:56658/oidc15012026/10/25 19:18:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15022026/10/25 19:18:39 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLmE5ODA1NDI3LTY3YzEtNDdlZC1hNDM4LWIzNDhhNWZiMjNiNngxNzkyOTU1OTE3NDgzMDUyMDAw parts=1015032026/10/25 19:18:40 INFO Received uploads request method=POST path=/api/pending_closures15042026/10/25 19:18:40 INFO Received uploads request method=POST path=/api/pending_closures15052026/10/25 19:18:40 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15062026/10/25 19:18:40 INFO Uploading db148m9axdy9bngarqksl1aa57rlrbbw-shared-dep (136B)15072026/10/25 19:18:40 INFO Uploading g5nw9mhqqc6a1f8bhq2vyhqb55679xnh-b (256B)15082026/10/25 19:18:40 WARN Failed to register uploaded object key=8h6rwl3qj086yr0hgp95bjrir7xq6diq.ls error="server returned 404: 404 page not found\n"15092026/10/25 19:18:40 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15102026/10/25 19:18:40 WARN Failed to register uploaded object key=g5nw9mhqqc6a1f8bhq2vyhqb55679xnh.ls error="server returned 404: 404 page not found\n"15112026/10/25 19:18:40 WARN Failed to register uploaded object key=db148m9axdy9bngarqksl1aa57rlrbbw.ls error="server returned 404: 404 page not found\n"15122026/10/25 19:18:40 WARN Failed to register uploaded object key=nar/1gdhr62vfpb6qh1jf7zbwb8qi48gy2bf3j4lb7485dbpw2h00518.nar.zst error="server returned 404: 404 page not found\n"15132026/10/25 19:18:40 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15142026/10/25 19:18:40 INFO Signed narinfos id=1 count=215152026/10/25 19:18:40 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15162026/10/25 19:18:40 INFO Signed narinfos id=2 count=215172026/10/25 19:18:40 INFO Uploading 4 narinfos15182026/10/25 19:18:40 WARN Failed to register uploaded object key=8h6rwl3qj086yr0hgp95bjrir7xq6diq.narinfo error="server returned 404: 404 page not found\n"1519=== NAME TestPinProtectsFromGC1520 client_integration_test.go:867: Pinned store path: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestPinProtectsFromGC1528060401/001/store/9agclzl4yz3g1jk3w0xb9nd64hlda0h8-pinned-file.txt15212026/10/25 19:18:40 WARN Failed to register uploaded object key=g5nw9mhqqc6a1f8bhq2vyhqb55679xnh.narinfo error="server returned 404: 404 page not found\n"1522--- PASS: TestCacheStatsHandler (8.63s)1523=== NAME TestPinProtectsFromGC15242026/10/25 19:18:40 WARN Failed to register uploaded object key=db148m9axdy9bngarqksl1aa57rlrbbw.narinfo error="server returned 404: 404 page not found\n"1525 client_integration_test.go:868: Unpinned store path: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestPinProtectsFromGC1528060401/001/store/484b33kwb251b3wxc6zfa5ds8pkvgi4n-unpinned-file.txt1526=== CONT TestPush_CompleteCommitsEveryRoot15272026/10/25 19:18:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15282026/10/25 19:18:40 WARN Failed to register uploaded object key=db148m9axdy9bngarqksl1aa57rlrbbw.narinfo error="server returned 404: 404 page not found\n"15292026/10/25 19:18:40 INFO Received push request method=POST path=/api/pushes15302026/10/25 19:18:40 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15312026/10/25 19:18:40 INFO Uploading 9agclzl4yz3g1jk3w0xb9nd64hlda0h8-pinned-file.txt (128B)15322026/10/25 19:18:40 INFO Completed upload id=1 objects=6 duration=62.360084ms15332026/10/25 19:18:40 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15342026/10/25 19:18:40 INFO Completed upload id=2 objects=6 duration=688.375µs15352026/10/25 19:18:40 INFO Upload complete. (541ms)1536=== NAME TestClientFallsBackToClosures1537 client_pushes_test.go:112: Retrieved narinfo from S3:1538 StorePath: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientFallsBackToClosures2789790499/001/store/db148m9axdy9bngarqksl1aa57rlrbbw-shared-dep1539 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1540 Compression: zstd1541 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821542 NarSize: 1361543 References: 1544 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1545 client_pushes_test.go:112: Retrieved narinfo from S3:1546 StorePath: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientFallsBackToClosures2789790499/001/store/8h6rwl3qj086yr0hgp95bjrir7xq6diq-a1547 URL: nar/1gdhr62vfpb6qh1jf7zbwb8qi48gy2bf3j4lb7485dbpw2h00518.nar.zst1548 Compression: zstd1549 NarHash: sha256:1gdhr62vfpb6qh1jf7zbwb8qi48gy2bf3j4lb7485dbpw2h005181550 NarSize: 2561551 References: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientFallsBackToClosures2789790499/001/store/db148m9axdy9bngarqksl1aa57rlrbbw-shared-dep1552 CA: text:sha256:1xmjs6r6ah5r8d51sj42056q4v16idvpqlpsvi7jd0rmdz3xn1b81553 client_pushes_test.go:112: Retrieved narinfo from S3:1554 StorePath: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientFallsBackToClosures2789790499/001/store/g5nw9mhqqc6a1f8bhq2vyhqb55679xnh-b1555 URL: nar/1gdhr62vfpb6qh1jf7zbwb8qi48gy2bf3j4lb7485dbpw2h00518.nar.zst1556 Compression: zstd15572026/10/25 19:18:40 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"1558 NarHash: sha256:1gdhr62vfpb6qh1jf7zbwb8qi48gy2bf3j4lb7485dbpw2h005181559 NarSize: 2561560 References: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientFallsBackToClosures2789790499/001/store/db148m9axdy9bngarqksl1aa57rlrbbw-shared-dep15612026/10/25 19:18:40 WARN Failed to register uploaded object key=9agclzl4yz3g1jk3w0xb9nd64hlda0h8.ls error="server returned 404: 404 page not found\n"15622026/10/25 19:18:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1563 CA: text:sha256:1xmjs6r6ah5r8d51sj42056q4v16idvpqlpsvi7jd0rmdz3xn1b815642026/10/25 19:18:40 INFO Signed narinfos id=1 count=115652026/10/25 19:18:40 INFO Uploading 1 narinfos15662026/10/25 19:18:40 INFO Received complete push request method=POST path=/api/pushes/1/complete15672026/10/25 19:18:40 WARN Failed to register uploaded object key=9agclzl4yz3g1jk3w0xb9nd64hlda0h8.narinfo error="server returned 404: 404 page not found\n"15682026/10/25 19:18:40 INFO Received cleanup request method=DELETE path=/api/pending_closures15692026/10/25 19:18:40 INFO Completed push id=1 objects=3 duration=123.606041ms15702026/10/25 19:18:40 INFO Upload complete. (456ms)15712026/10/25 19:18:40 INFO Aborted multipart uploads count=0 kept=015722026/10/25 19:18:40 INFO Received uploads request method=POST path=/api/pending_closures1573--- PASS: TestClientFallsBackToClosures (10.02s)1574=== CONT TestService_AuthMiddleware15752026/10/25 19:18:41 INFO Received cleanup request method=DELETE path=/api/pending_closures15762026/10/25 19:18:41 INFO Received push request method=POST path=/api/pushes15772026/10/25 19:18:41 INFO Aborted multipart uploads count=1 kept=015782026/10/25 19:18:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15792026/10/25 19:18:41 INFO Uploading 484b33kwb251b3wxc6zfa5ds8pkvgi4n-unpinned-file.txt (128B)15802026/10/25 19:18:41 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15812026-10-25 19:18:41.076 UTC [34350] ERROR: Closure does not exist: id=115822026-10-25 19:18:41.076 UTC [34350] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE15832026-10-25 19:18:41.076 UTC [34350] STATEMENT: -- name: CommitPendingClosure :one1584 SELECT commit_pending_closure($1::bigint)::bigint1585 15862026/10/25 19:18:41 WARN Failed to register uploaded object key=484b33kwb251b3wxc6zfa5ds8pkvgi4n.ls error="server returned 404: 404 page not found\n"1587--- PASS: TestService_cleanupPendingClosuresHandler (8.94s)1588=== CONT TestGCTaskStore_CompletedAllowsNewTask1589--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1590=== CONT TestUploadHandlersRejectOversizedBody15912026/10/25 19:18:41 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15922026/10/25 19:18:41 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15932026/10/25 19:18:41 INFO Signed narinfos id=2 count=115942026/10/25 19:18:41 INFO Uploading 1 narinfos1595=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1596=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1597=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1598=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1599=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1600=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1601=== CONT TestConcurrentPinUpdatesAgree16022026/10/25 19:18:41 INFO Received complete push request method=POST path=/api/pushes/2/complete16032026/10/25 19:18:41 WARN Failed to register uploaded object key=484b33kwb251b3wxc6zfa5ds8pkvgi4n.narinfo error="server returned 404: 404 page not found\n"16042026/10/25 19:18:41 INFO Completed push id=2 objects=3 duration=895.125µs16052026/10/25 19:18:41 INFO Upload complete. (262ms)16062026/10/25 19:18:41 INFO Starting cleanup of old closures method=DELETE path=/api/closures16072026/10/25 19:18:41 INFO Garbage collection started16082026/10/25 19:18:41 INFO Aborted multipart uploads count=0 kept=016092026/10/25 19:18:41 WARN Force mode enabled - objects will be deleted immediately without grace period16102026/10/25 19:18:41 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux16112026/10/25 19:18:41 WARN Refused reserved pin name=worker-x86_64-linux16122026/10/25 19:18:41 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux16132026/10/25 19:18:41 INFO Received create pin request method=POST path=/api/pins/my-app16142026/10/25 19:18:41 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1615--- PASS: TestCreatePin_ReservedPins (9.40s)16162026/10/25 19:18:41 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1617=== CONT TestGCTaskStore_ConflictDifferentParams1618--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1619=== CONT TestCreatePinRejectsBadInput16202026/10/25 19:18:41 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLjRiYzJjOTYzLWFmYjktNGE5Yy04ODJlLTcxZDdiODFlM2NmOXgxNzkyOTU1OTE3MDEzODgyMDAw parts=1016212026/10/25 19:18:41 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=016222026/10/25 19:18:42 INFO Vacuumed table table=pending_closures16232026/10/25 19:18:42 INFO Vacuumed table table=pending_objects16242026/10/25 19:18:42 INFO Vacuumed table table=multipart_uploads16252026/10/25 19:18:42 INFO Received uploads request method=POST path=/api/pending_closures16262026/10/25 19:18:42 INFO Received push request method=POST path=/api/pushes16272026/10/25 19:18:42 INFO Vacuumed table table=closures16282026/10/25 19:18:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16292026/10/25 19:18:42 INFO Vacuumed table table=objects16302026/10/25 19:18:42 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16312026/10/25 19:18:42 INFO Uploading 2wd7b6dqqqd3d3snviwm4ppzs1vpfqsy-shared-dep (136B)16322026/10/25 19:18:42 INFO Uploading 08ypyf6phz85w48xhhjh68cs2lnwhkkl-top (264B)16332026/10/25 19:18:42 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLjM0ZWE5ZDI1LTUwNjctNDA0Mi1hOWY4LTEwYjRhYTQ1MzkxOXgxNzkyOTU1OTE3NDgzNDMwMDAw parts=1016342026/10/25 19:18:42 INFO Received complete push request method=POST path=/api/pushes/1/complete16352026/10/25 19:18:42 WARN Failed to register uploaded object key=2wd7b6dqqqd3d3snviwm4ppzs1vpfqsy.ls error="server returned 404: 404 page not found\n"16362026/10/25 19:18:42 WARN Failed to register uploaded object key=nar/13rs7p2r1g0ic92q66hhwxxvw4fcaiwfmdvzqmias1pgxxzp2vi8.nar.zst error="server returned 404: 404 page not found\n"16372026/10/25 19:18:42 WARN Failed to register uploaded object key=08ypyf6phz85w48xhhjh68cs2lnwhkkl.ls error="server returned 404: 404 page not found\n"16382026/10/25 19:18:42 INFO Completed push id=1 objects=4 duration=28.002375ms16392026/10/25 19:18:42 INFO Received push request method=POST path=/api/pushes16402026/10/25 19:18:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16412026/10/25 19:18:42 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16422026/10/25 19:18:42 INFO Signed narinfos id=1 count=216432026/10/25 19:18:42 INFO Uploading 2 narinfos16442026/10/25 19:18:42 WARN Failed to register uploaded object key=08ypyf6phz85w48xhhjh68cs2lnwhkkl.narinfo error="server returned 404: 404 page not found\n"16452026/10/25 19:18:42 INFO Received complete push request method=POST path=/api/pushes/1/complete16462026/10/25 19:18:42 WARN Failed to register uploaded object key=2wd7b6dqqqd3d3snviwm4ppzs1vpfqsy.narinfo error="server returned 404: 404 page not found\n"16472026/10/25 19:18:42 INFO Aborted multipart uploads count=0 kept=016482026/10/25 19:18:42 INFO Completed push id=1 objects=6 duration=38.565417ms16492026/10/25 19:18:42 INFO Upload complete. (402ms)1650=== NAME TestClientSharedPathCommittedMidPush1651 client_integration_test.go:816: Retrieved narinfo from S3:1652 StorePath: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientSharedPathCommittedMidPush3965307913/001/store/2wd7b6dqqqd3d3snviwm4ppzs1vpfqsy-shared-dep1653 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1654 Compression: zstd1655 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821656 NarSize: 1361657--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (11.75s)1658=== CONT TestDeletePinKeepsRowWhenS3Fails16592026/10/25 19:18:42 WARN Force mode enabled - objects will be deleted immediately without grace period1660=== NAME TestClientSharedPathCommittedMidPush1661 References: 1662 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1663 client_integration_test.go:816: Retrieved narinfo from S3:1664 StorePath: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientSharedPathCommittedMidPush3965307913/001/store/08ypyf6phz85w48xhhjh68cs2lnwhkkl-top1665 URL: nar/13rs7p2r1g0ic92q66hhwxxvw4fcaiwfmdvzqmias1pgxxzp2vi8.nar.zst1666 Compression: zstd1667 NarHash: sha256:13rs7p2r1g0ic92q66hhwxxvw4fcaiwfmdvzqmias1pgxxzp2vi81668 NarSize: 2641669 References: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientSharedPathCommittedMidPush3965307913/001/store/2wd7b6dqqqd3d3snviwm4ppzs1vpfqsy-shared-dep1670 CA: text:sha256:1yfxqdf79rdqfmcrafpva6d7dcch1l4q7fqwjh51hqdradh11d5d16712026/10/25 19:18:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1672--- PASS: TestClientSharedPathCommittedMidPush (10.47s)1673=== CONT TestService_Rustfstest16742026/10/25 19:18:43 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=016752026/10/25 19:18:43 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=016762026/10/25 19:18:43 INFO Received create pin request method=POST path=/api/pins/myapp16772026/10/25 19:18:43 INFO Vacuumed table table=pending_closures16782026/10/25 19:18:43 INFO Vacuumed table table=pending_objects16792026/10/25 19:18:43 INFO Created/updated pin name=myapp store_path=/private/var/tb/2/scratch/52f05e2dc9743da8/build/TestPinProtectsFromGC1528060401/001/store/9agclzl4yz3g1jk3w0xb9nd64hlda0h8-pinned-file.txt narinfo_key=9agclzl4yz3g1jk3w0xb9nd64hlda0h8.narinfo16802026/10/25 19:18:43 INFO Vacuumed table table=multipart_uploads16812026/10/25 19:18:43 INFO Starting cleanup of old closures method=DELETE path=/api/closures16822026/10/25 19:18:43 INFO Garbage collection started16832026/10/25 19:18:43 INFO Aborted multipart uploads count=0 kept=016842026/10/25 19:18:43 WARN Force mode enabled - objects will be deleted immediately without grace period16852026/10/25 19:18:43 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016862026/10/25 19:18:43 INFO Vacuumed table table=pending_closures16872026/10/25 19:18:43 INFO Vacuumed table table=pending_objects16882026/10/25 19:18:43 INFO Vacuumed table table=closures16892026/10/25 19:18:43 INFO Vacuumed table table=multipart_uploads16902026/10/25 19:18:43 INFO Vacuumed table table=closures16912026/10/25 19:18:43 INFO Vacuumed table table=objects16922026/10/25 19:18:43 INFO Vacuumed table table=objects16932026/10/25 19:18:43 INFO Received push request method=POST path=/api/pushes16942026/10/25 19:18:43 INFO Received push request method=POST path=/api/pushes16952026/10/25 19:18:43 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16962026/10/25 19:18:43 INFO Uploading zhv8sl6dhawqnld6rk3sa9pj4nqj7lyv-shared-dep (136B)16972026/10/25 19:18:43 INFO Uploading hf2wxbkm42k3mki2bb92hap4rjwiqbib-b (256B)16982026/10/25 19:18:43 WARN Failed to register uploaded object key=hf2wxbkm42k3mki2bb92hap4rjwiqbib.ls error="server returned 404: 404 page not found\n"16992026/10/25 19:18:43 WARN Failed to register uploaded object key=41mfllda2df96s5l2h21502zybpx5igz.ls error="server returned 404: 404 page not found\n"17002026/10/25 19:18:43 WARN Failed to register uploaded object key=zhv8sl6dhawqnld6rk3sa9pj4nqj7lyv.ls error="server returned 404: 404 page not found\n"17012026/10/25 19:18:43 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17022026/10/25 19:18:43 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17032026/10/25 19:18:43 WARN Failed to register uploaded object key=nar/1ywpmwxsyygprskggdxgs1cigmvdz9a8bpyyblxa05k0j6gc3z85.nar.zst error="server returned 404: 404 page not found\n"17042026/10/25 19:18:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17052026/10/25 19:18:43 INFO Signed narinfos id=1 count=317062026/10/25 19:18:43 INFO Uploading 3 narinfos17072026/10/25 19:18:43 INFO Received push request method=POST path=/api/pushes17082026/10/25 19:18:43 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLmVmZDhmMjkzLWU1MTgtNDUyZi1hNzQ5LWZiMjFmMzNmNjBmM3gxNzkyOTU1OTE3MDEzOTA2MDAw parts=1017092026/10/25 19:18:43 WARN Failed to register uploaded object key=41mfllda2df96s5l2h21502zybpx5igz.narinfo error="server returned 404: 404 page not found\n"17102026/10/25 19:18:43 WARN Failed to register uploaded object key=hf2wxbkm42k3mki2bb92hap4rjwiqbib.narinfo error="server returned 404: 404 page not found\n"17112026/10/25 19:18:44 INFO Received complete push request method=POST path=/api/pushes/1/complete17122026/10/25 19:18:44 WARN Failed to register uploaded object key=zhv8sl6dhawqnld6rk3sa9pj4nqj7lyv.narinfo error="server returned 404: 404 page not found\n"17132026/10/25 19:18:44 INFO Completed push id=1 objects=8 duration=37.263583ms17142026/10/25 19:18:44 INFO Upload complete. (478ms)1715=== NAME TestClientPushesUseOnePush1716 client_pushes_test.go:97: Retrieved narinfo from S3:1717 StorePath: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientPushesUseOnePush376670079/001/store/zhv8sl6dhawqnld6rk3sa9pj4nqj7lyv-shared-dep1718 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1719 Compression: zstd1720 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821721 NarSize: 1361722 References: 1723 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1724 client_pushes_test.go:97: Retrieved narinfo from S3:1725 StorePath: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientPushesUseOnePush376670079/001/store/41mfllda2df96s5l2h21502zybpx5igz-a1726 URL: nar/1ywpmwxsyygprskggdxgs1cigmvdz9a8bpyyblxa05k0j6gc3z85.nar.zst1727 Compression: zstd1728 NarHash: sha256:1ywpmwxsyygprskggdxgs1cigmvdz9a8bpyyblxa05k0j6gc3z851729 NarSize: 2561730 References: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientPushesUseOnePush376670079/001/store/zhv8sl6dhawqnld6rk3sa9pj4nqj7lyv-shared-dep1731 CA: text:sha256:1dksr4nx35nycfd1z4s7fxw0m840jdxllcm4f7pgl825m2f2lzmq1732 client_pushes_test.go:97: Retrieved narinfo from S3:1733 StorePath: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientPushesUseOnePush376670079/001/store/hf2wxbkm42k3mki2bb92hap4rjwiqbib-b1734 URL: nar/1ywpmwxsyygprskggdxgs1cigmvdz9a8bpyyblxa05k0j6gc3z85.nar.zst1735 Compression: zstd1736 NarHash: sha256:1ywpmwxsyygprskggdxgs1cigmvdz9a8bpyyblxa05k0j6gc3z851737 NarSize: 2561738 References: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientPushesUseOnePush376670079/001/store/zhv8sl6dhawqnld6rk3sa9pj4nqj7lyv-shared-dep1739 CA: text:sha256:1dksr4nx35nycfd1z4s7fxw0m840jdxllcm4f7pgl825m2f2lzmq1740=== NAME TestClientCADerivations1741 client_ca_test.go:136: Built CA derivation: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientCADerivations3886343327/001/store/w53jzz7m9ifkgb2zaj1h7f3ijkj0b5gc-ca-test1742 client_ca_test.go:139: Found 1 dependencies (including self)1743--- PASS: TestClientPushesUseOnePush (11.77s)1744=== CONT TestGCEndsOnShutdown/before_the_run17452026/10/25 19:18:44 INFO Received push request method=POST path=/api/pushes17462026/10/25 19:18:44 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17472026/10/25 19:18:44 WARN mTLS auth: bound subjects configured but subject DN unavailable17482026/10/25 19:18:44 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"17492026/10/25 19:18:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17502026/10/25 19:18:44 INFO Uploading w53jzz7m9ifkgb2zaj1h7f3ijkj0b5gc-ca-test (144B)1751--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (9.15s)1752=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark17532026/10/25 19:18:44 WARN Failed to register uploaded object key=w53jzz7m9ifkgb2zaj1h7f3ijkj0b5gc.ls error="server returned 404: 404 page not found\n"17542026/10/25 19:18:44 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"17552026/10/25 19:18:44 WARN Failed to register uploaded object key=log/170dpc826kqks6jhf816gcdy2kqws6yk-ca-test.drv error="server returned 404: 404 page not found\n"17562026/10/25 19:18:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17572026/10/25 19:18:44 INFO Signed narinfos id=1 count=117582026/10/25 19:18:44 INFO Uploading 1 narinfos17592026/10/25 19:18:44 INFO Received complete push request method=POST path=/api/pushes/1/complete17602026/10/25 19:18:44 WARN Failed to register uploaded object key=w53jzz7m9ifkgb2zaj1h7f3ijkj0b5gc.narinfo error="server returned 404: 404 page not found\n"17612026/10/25 19:18:44 INFO Completed push id=1 objects=4 duration=203.4845ms17622026/10/25 19:18:44 INFO Upload complete. (707ms)1763=== NAME TestClientCADerivations1764 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientCADerivations3886343327/001/store/w53jzz7m9ifkgb2zaj1h7f3ijkj0b5gc-ca-test1765 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1766 Compression: zstd1767 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1768 NarSize: 1441769 References: 1770 Deriver: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientCADerivations3886343327/001/store/170dpc826kqks6jhf816gcdy2kqws6yk-ca-test.drv1771 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1772 client_ca_test.go:185: Checking for realisation files in S3...1773 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1774 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1775 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket80?endpoint=http://localhost:56253®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientCADerivations3886343327/001/store'1776 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11777=== NAME TestPinProtectsFromGC1778 client_integration_test.go:976: Pin successfully protected closure from garbage collection1779--- PASS: TestService_ReadScope_PublicByDefault (10.14s)1780=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1781--- PASS: TestClientCADerivations (12.06s)1782=== CONT TestIsValidUploadKey/narinfo1783=== CONT TestIsValidUploadKey/unknown_type1784=== CONT TestIsValidUploadKey/empty_key1785--- PASS: TestPinProtectsFromGC (14.48s)1786=== CONT TestIsValidUploadKey/absolute1787=== CONT TestIsValidUploadKey/traversal_nar1788=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1789=== CONT TestIsValidUploadKey/traversal1790=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1791=== CONT TestIsValidUploadKey/index.html1792=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1793=== CONT TestIsValidUploadKey/nix-cache-info1794=== CONT TestIsValidUploadKey/realisation_plus_in_output1795=== CONT TestIsValidUploadKey/build_log_equals1796=== CONT TestIsValidUploadKey/build_log_question_mark1797=== CONT TestIsValidUploadKey/build_log_plus_in_name1798=== CONT TestIsValidUploadKey/realisation1799=== CONT TestIsValidUploadKey/build_log1800=== CONT TestIsValidUploadKey/build_log_home-manager_file1801=== CONT TestIsValidUploadKey/nar_plain1802=== CONT TestIsValidUploadKey/listing1803=== CONT TestIsValidUploadKey/nar_xz1804=== CONT TestServerTLSConfig/no_client_CA1805=== CONT TestServerTLSConfig/missing_CA_file1806=== CONT TestIsValidUploadKey/nar_zst1807=== CONT TestServerTLSConfig/not_a_PEM_file1808=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1809--- PASS: TestIsValidUploadKey (0.02s)1810 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1811 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1812 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1813 --- PASS: TestIsValidUploadKey/absolute (0.00s)1814 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1815 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1816 --- PASS: TestIsValidUploadKey/traversal (0.00s)1817 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1818 --- PASS: TestIsValidUploadKey/index.html (0.00s)1819 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1820 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1821 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1822 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1823 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1824 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1825 --- PASS: TestIsValidUploadKey/realisation (0.00s)1826 --- PASS: TestIsValidUploadKey/build_log (0.00s)1827 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1828 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1829 --- PASS: TestIsValidUploadKey/listing (0.00s)1830 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1831 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1832=== NAME TestClientIntegration1833 client_integration_test.go:334: Created store path: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientIntegration3483601220/002/store/ydgjhl68nm3bvl6hnmdq1hs1ikw4d96d-test-file.txt1834=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1835--- PASS: TestServerTLSConfig (0.00s)1836 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1837 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1838 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.03s)18392026/10/25 19:18:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18402026/10/25 19:18:45 INFO Received push request method=POST path=/api/pushes18412026/10/25 19:18:45 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLjk2YzQxZTZiLThhNWQtNDNjYy05OTJmLTI5OGViMjQxZTAyZXgxNzkyOTU1OTIyMzY1NDEyMDAw parts=1018422026/10/25 19:18:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18432026/10/25 19:18:45 INFO Uploading ydgjhl68nm3bvl6hnmdq1hs1ikw4d96d-test-file.txt (152B)18442026/10/25 19:18:46 INFO Received complete push request method=POST path=/api/pushes/2/complete18452026/10/25 19:18:46 INFO Completed push id=2 objects=4 duration=24.826ms18462026/10/25 19:18:46 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"18472026/10/25 19:18:46 WARN Failed to register uploaded object key=ydgjhl68nm3bvl6hnmdq1hs1ikw4d96d.ls error="server returned 404: 404 page not found\n"18482026/10/25 19:18:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18492026/10/25 19:18:46 INFO Signed narinfos id=1 count=118502026/10/25 19:18:46 INFO Uploading 1 narinfos1851--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (17.02s)1852=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows18532026/10/25 19:18:46 INFO Received complete push request method=POST path=/api/pushes/1/complete18542026/10/25 19:18:46 WARN Failed to register uploaded object key=ydgjhl68nm3bvl6hnmdq1hs1ikw4d96d.narinfo error="server returned 404: 404 page not found\n"18552026/10/25 19:18:46 INFO Completed push id=1 objects=3 duration=49.211333ms18562026/10/25 19:18:46 INFO Upload complete. (496ms)18572026/10/25 19:18:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18582026/10/25 19:18:46 INFO All 1 paths already cached1859=== NAME TestClientIntegration1860 client_integration_test.go:360: Retrieved narinfo from S3:1861 StorePath: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientIntegration3483601220/002/store/ydgjhl68nm3bvl6hnmdq1hs1ikw4d96d-test-file.txt1862 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1863 Compression: zstd1864 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11865 NarSize: 1521866 References: 1867 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11868 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)1869 client_integration_test.go:361: Decompressed .ls content (64 bytes):1870 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}18712026/10/25 19:18:46 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLjhhNTNiNzNkLWIyN2UtNDE4NS1iYzEyLTJhYjFhMjlkOWE5NXgxNzkyOTU1OTIzNTE0NDc5MDAw parts=1018722026/10/25 19:18:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1873=== RUN TestService_RequireScope_OIDC/builder_may_write1874=== PAUSE TestService_RequireScope_OIDC/builder_may_write1875=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1876=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1877=== RUN TestService_RequireScope_OIDC/ops_may_admin1878=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1879=== RUN TestService_RequireScope_OIDC/ops_may_not_write1880=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1881=== RUN TestService_RequireScope_OIDC/reader_may_not_write1882=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1883=== RUN TestService_RequireScope_OIDC/static_token_may_admin1884=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1885=== RUN TestService_RequireScope_OIDC/static_token_may_write1886=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1887=== RUN TestService_RequireScope_OIDC/reader_may_read1888=== PAUSE TestService_RequireScope_OIDC/reader_may_read1889=== RUN TestService_RequireScope_OIDC/writer_implies_read1890=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1891=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1892=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1893=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1894=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1895=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1896=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1897=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1898=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1899=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1900=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1901=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check19022026/10/25 19:18:46 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLmFlZjhlMDg5LTUxMWYtNGVjMC1hNjJhLTNhNTU0NWNkNjg5MngxNzkyOTU1OTE3MDEzODI0MDAw parts=1019032026/10/25 19:18:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19042026/10/25 19:18:46 INFO Received push request method=POST path=/api/pushes19052026/10/25 19:18:46 INFO Object in database but missing from S3 key=ydgjhl68nm3bvl6hnmdq1hs1ikw4d96d.ls19062026/10/25 19:18:46 WARN Found objects in DB but missing from S3, will re-upload count=119072026/10/25 19:18:46 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLjhkYjkwYzE0LTcyMWItNDQyMS05OWU3LWZjM2Y0YWQyN2Q0ZngxNzkyOTU1OTI0MDI1MjE3MDAw parts=1019082026/10/25 19:18:46 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19092026/10/25 19:18:46 INFO Received complete push request method=POST path=/api/pushes/2/complete19102026/10/25 19:18:46 WARN Failed to register uploaded object key=ydgjhl68nm3bvl6hnmdq1hs1ikw4d96d.ls error="server returned 404: 404 page not found\n"19112026/10/25 19:18:46 INFO Completed push id=2 objects=3 duration=759.708µs19122026/10/25 19:18:46 INFO Upload complete. (165ms)1913=== NAME TestClientIntegration1914 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)1915 client_integration_test.go:389: Decompressed .ls content (49 bytes):1916 {"version":1,"root":{"type":"regular","size":39}}1917--- PASS: TestService_ReadAuthMiddleware (10.28s)1918=== CONT TestProxyWriteTimeout/narinfo1919=== CONT TestProxyWriteTimeout/unknown_size1920=== CONT TestProxyWriteTimeout/10_GiB_nar1921=== CONT TestProxyWriteTimeout/1_GiB_nar1922=== CONT TestIsValidCachePath/nar_zst1923--- PASS: TestProxyWriteTimeout (0.01s)1924 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1925 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1926 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1927 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1928=== CONT TestIsValidCachePath/short_hash1929=== CONT TestIsValidCachePath/wrong_extension1930=== CONT TestIsValidCachePath/leading_slash1931=== CONT TestIsValidCachePath/realisation1932=== CONT TestIsValidCachePath/empty1933=== CONT TestIsValidCachePath/random_path1934=== NAME TestClientWithDependencies1935 client_integration_test.go:735: Built derivation: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientWithDependencies4213648480/001/store/x6fqvl7abn5frfvn7ynspzhmbi1ywc06-test-script1936=== CONT TestIsValidCachePath/invalid_char_u1937=== CONT TestIsValidCachePath/traversal_in_middle1938=== CONT TestIsValidCachePath/invalid_char_e1939=== CONT TestIsValidCachePath/traversal_parent1940=== CONT TestIsValidCachePath/nix-cache-info1941=== CONT TestIsValidCachePath/ls1942=== CONT TestIsValidCachePath/log1943=== CONT TestIsValidCachePath/index.html1944=== CONT TestIsValidCachePath/nar_uncompressed1945=== CONT TestIsValidCachePath/nar_xz1946=== CONT TestIsValidCachePath/nar_bz21947=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1948=== CONT TestIsValidCachePath/narinfo1949=== CONT TestParseSingleRange/multi-range_ignored1950--- PASS: TestIsValidCachePath (0.00s)1951 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1952 --- PASS: TestIsValidCachePath/short_hash (0.00s)1953 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1954 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1955 --- PASS: TestIsValidCachePath/realisation (0.00s)1956 --- PASS: TestIsValidCachePath/empty (0.00s)1957 --- PASS: TestIsValidCachePath/random_path (0.00s)1958 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1959 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1960 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1961 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1962 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1963 --- PASS: TestIsValidCachePath/ls (0.00s)1964 --- PASS: TestIsValidCachePath/log (0.00s)1965 --- PASS: TestIsValidCachePath/index.html (0.00s)1966 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1967 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1968 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1969 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1970 --- PASS: TestIsValidCachePath/narinfo (0.00s)1971=== CONT TestParseSingleRange/start_far_past_EOF1972=== CONT TestParseSingleRange/open-ended1973=== CONT TestParseSingleRange/single_byte1974=== CONT TestParseSingleRange/suffix_exceeds_size1975=== CONT TestParseSingleRange/start_past_EOF1976=== CONT TestParseSingleRange/suffix1977=== CONT TestParseSingleRange/end_clamped_to_size1978=== CONT TestParseSingleRange/malformed_both_empty1979=== CONT TestParseSingleRange/malformed_end_before_start1980=== CONT TestParseSingleRange/closed1981=== CONT TestParseSingleRange/unknown_unit1982=== CONT TestParseSingleRange/malformed_no_dash1983=== NAME TestClientWithDependencies1984 client_integration_test.go:737: Found 1 dependencies (including self)1985=== CONT TestParseSingleRange/none1986=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1987--- PASS: TestParseSingleRange (0.00s)1988 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1989 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1990 --- PASS: TestParseSingleRange/open-ended (0.00s)1991 --- PASS: TestParseSingleRange/single_byte (0.00s)1992 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1993 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1994 --- PASS: TestParseSingleRange/suffix (0.00s)1995 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1996 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1997 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1998 --- PASS: TestParseSingleRange/closed (0.00s)1999 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2000 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2001 --- PASS: TestParseSingleRange/none (0.00s)20022026-10-25 19:18:47.174 UTC [34475] ERROR: Push does not exist: id=120032026-10-25 19:18:47.174 UTC [34475] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE20042026-10-25 19:18:47.174 UTC [34475] STATEMENT: SELECT commit_push($1)2005--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (12.55s)2006=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale20072026/10/25 19:18:47 INFO Received push request method=POST path=/api/pushes2008--- PASS: TestDeleteClosuresRacingPins (16.40s)2009=== CONT TestClientErrorHandling/InvalidStorePath20102026/10/25 19:18:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20112026/10/25 19:18:47 INFO Uploading x6fqvl7abn5frfvn7ynspzhmbi1ywc06-test-script (136B)20122026/10/25 19:18:47 WARN Rate limiter enabled after throttle name=s3-test rate=520132026/10/25 19:18:47 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2014=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2015 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=1020162026/10/25 19:18:47 INFO Received push request method=POST path=/api/pushes2017 throttle_test.go:215: Rate limiter: enabled=true, rate=5.0020182026/10/25 19:18:47 WARN Failed to register uploaded object key=x6fqvl7abn5frfvn7ynspzhmbi1ywc06.ls error="server returned 404: 404 page not found\n"20192026/10/25 19:18:47 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"20202026/10/25 19:18:47 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)20212026/10/25 19:18:47 WARN Failed to register uploaded object key=log/6p27sq5507qq8w4kkwlihs1937fl68m5-test-script.drv error="server returned 404: 404 page not found\n"20222026/10/25 19:18:47 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20232026/10/25 19:18:47 INFO Signed narinfos id=1 count=12024--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (15.13s)20252026/10/25 19:18:47 INFO Uploading 1 narinfos2026=== CONT TestClientErrorHandling/ServerNotAvailable20272026/10/25 19:18:47 INFO Received complete push request method=POST path=/api/pushes/3/complete20282026/10/25 19:18:47 WARN Failed to register uploaded object key=ydgjhl68nm3bvl6hnmdq1hs1ikw4d96d.ls error="server returned 404: 404 page not found\n"20292026/10/25 19:18:47 INFO Completed push id=3 objects=3 duration=1.044916ms20302026/10/25 19:18:47 INFO Upload complete. (226ms)2031=== NAME TestClientIntegration2032 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)2033 client_integration_test.go:405: Decompressed .ls content (49 bytes):2034 {"version":1,"root":{"type":"regular","size":39}}20352026/10/25 19:18:47 INFO Received complete push request method=POST path=/api/pushes/1/complete20362026/10/25 19:18:47 WARN Failed to register uploaded object key=x6fqvl7abn5frfvn7ynspzhmbi1ywc06.narinfo error="server returned 404: 404 page not found\n"20372026/10/25 19:18:47 INFO Completed push id=1 objects=4 duration=52.122041ms20382026/10/25 19:18:47 INFO Upload complete. (488ms)20392026/10/25 19:18:47 INFO Aborted multipart uploads count=0 kept=020402026/10/25 19:18:47 WARN Force mode enabled - objects will be deleted immediately without grace period20412026/10/25 19:18:47 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=020422026/10/25 19:18:47 INFO Vacuumed table table=pending_closures20432026/10/25 19:18:47 INFO Vacuumed table table=pending_objects20442026/10/25 19:18:47 INFO Vacuumed table table=multipart_uploads20452026/10/25 19:18:47 INFO Received push request method=POST path=/api/pushes20462026/10/25 19:18:47 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20472026/10/25 19:18:47 INFO Uploading a87khsh43zjwl5952fl14ym2ng5sf18p-lost-commit.txt (152B)2048=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2049=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2050=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2051=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2052=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2053=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2054=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2055=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2056=== CONT TestClientErrorHandling/InvalidAuthToken20572026/10/25 19:18:47 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"20582026/10/25 19:18:47 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign20592026/10/25 19:18:47 WARN Failed to register uploaded object key=a87khsh43zjwl5952fl14ym2ng5sf18p.ls error="server returned 404: 404 page not found\n"20602026/10/25 19:18:47 INFO Signed narinfos id=4 count=120612026/10/25 19:18:47 INFO Uploading 1 narinfos20622026/10/25 19:18:48 INFO Vacuumed table table=closures20632026/10/25 19:18:48 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20642026/10/25 19:18:48 INFO Received complete push request method=POST path=/api/pushes/4/complete20652026/10/25 19:18:48 WARN Failed to register uploaded object key=a87khsh43zjwl5952fl14ym2ng5sf18p.narinfo error="server returned 404: 404 page not found\n"20662026/10/25 19:18:48 INFO Completed push id=4 objects=3 duration=997.667µs2067=== NAME TestClientMultipleUploads20682026/10/25 19:18:48 INFO Vacuumed table table=objects2069 client_integration_test.go:480: Created store path 0: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientMultipleUploads1964179780/001/store/4rhiwp662mb7c1f3iap4047h7fpcbf3f-test-file-0.txt20702026/10/25 19:18:48 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:56775/api/pushes/4/complete\": EOF" url=http://127.0.0.1:56775/api/pushes/4/complete2071=== NAME TestClientWithDependencies2072 client_integration_test.go:753: Skipping nix copy test - isolated store (/private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientWithDependencies4213648480/001/store) requires matching store prefix20732026/10/25 19:18:48 WARN Request failed, retrying attempt=2 backoff=182.402679ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20742026/10/25 19:18:48 INFO Received complete push request method=POST path=/api/pushes/4/complete20752026-10-25 19:18:48.211 UTC [34383] ERROR: Push does not exist: id=420762026-10-25 19:18:48.211 UTC [34383] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE20772026-10-25 19:18:48.211 UTC [34383] STATEMENT: -- name: CommitPush :one2078 SELECT commit_push($1::bigint)::bigint2079 20802026/10/25 19:18:48 WARN Push not found id=420812026/10/25 19:18:48 INFO Upload complete. (402ms)2082=== NAME TestClientIntegration2083 client_integration_test.go:435: Retrieved narinfo from S3:2084 StorePath: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientIntegration3483601220/002/store/a87khsh43zjwl5952fl14ym2ng5sf18p-lost-commit.txt2085 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst2086 Compression: zstd2087 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2088 NarSize: 1522089 References: 2090 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2091 client_integration_test.go:438: Testing garbage collection...20922026/10/25 19:18:48 INFO Starting cleanup of old closures method=DELETE path=/api/closures20932026/10/25 19:18:48 INFO Garbage collection started2094=== NAME TestClientMultipleUploads2095 client_integration_test.go:480: Created store path 1: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientMultipleUploads1964179780/001/store/vlgss1669xzjp5q3v8vjzy33yamfl4ab-test-file-1.txt20962026/10/25 19:18:48 INFO Aborted multipart uploads count=0 kept=020972026/10/25 19:18:48 WARN Request failed, retrying attempt=3 backoff=398.899894ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20982026/10/25 19:18:48 WARN Force mode enabled - objects will be deleted immediately without grace period2099--- PASS: TestClientWithDependencies (12.34s)2100=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2101=== CONT TestResolveDBConnectionString/missing_file_is_an_error2102=== CONT TestResolveDBConnectionString/nothing_configured2103=== CONT TestResolveDBConnectionString/file_when_flag_empty2104=== CONT TestResolveDBConnectionString/flag_wins2105=== CONT TestPendingClosureWriteTimeout/670k_objects2106=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline2107--- PASS: TestResolveDBConnectionString (0.03s)2108 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2109 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2110 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2111 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2112 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)21132026/10/25 19:18:48 INFO Received push request method=POST path=/api/pushes2114=== NAME TestClientMultipleUploads2115 client_integration_test.go:480: Created store path 2: /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestClientMultipleUploads1964179780/001/store/q3rrsm8nn5jqag8ipfdnz5iz1x9g3n2m-test-file-2.txt21162026/10/25 19:18:48 INFO Received push request method=POST path=/api/pushes21172026/10/25 19:18:48 WARN Request failed, retrying attempt=4 backoff=872.736255ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21182026/10/25 19:18:48 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)21192026/10/25 19:18:48 INFO Uploading vlgss1669xzjp5q3v8vjzy33yamfl4ab-test-file-1.txt (160B)21202026/10/25 19:18:48 INFO Uploading q3rrsm8nn5jqag8ipfdnz5iz1x9g3n2m-test-file-2.txt (160B)21212026/10/25 19:18:48 INFO Uploading 4rhiwp662mb7c1f3iap4047h7fpcbf3f-test-file-0.txt (160B)21222026/10/25 19:18:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21232026/10/25 19:18:48 WARN Failed to register uploaded object key=4rhiwp662mb7c1f3iap4047h7fpcbf3f.ls error="server returned 404: 404 page not found\n"21242026/10/25 19:18:48 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"21252026/10/25 19:18:48 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"21262026/10/25 19:18:48 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"21272026/10/25 19:18:48 WARN Failed to register uploaded object key=vlgss1669xzjp5q3v8vjzy33yamfl4ab.ls error="server returned 404: 404 page not found\n"21282026/10/25 19:18:48 WARN Failed to register uploaded object key=q3rrsm8nn5jqag8ipfdnz5iz1x9g3n2m.ls error="server returned 404: 404 page not found\n"21292026/10/25 19:18:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21302026/10/25 19:18:48 INFO Signed narinfos id=1 count=321312026/10/25 19:18:48 INFO Uploading 3 narinfos21322026/10/25 19:18:48 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"2133--- PASS: TestService_AuthMiddleware (8.05s)2134=== CONT TestPendingClosureWriteTimeout/400_objects2135=== CONT TestPendingClosureWriteTimeout/empty2136=== CONT TestCacheConfigHandler/full_config,_no_issuer2137=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2138=== CONT TestCacheConfigHandler/no_signing_keys2139=== CONT TestCacheConfigHandler/no_cache_url_configured2140=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key2141--- PASS: TestCacheConfigHandler (0.01s)2142 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2143 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2144 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2145 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)21462026/10/25 19:18:49 INFO Received request for more parts method=POST path=/2147=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key21482026/10/25 19:18:49 WARN Failed to register uploaded object key=4rhiwp662mb7c1f3iap4047h7fpcbf3f.narinfo error="server returned 404: 404 page not found\n"21492026/10/25 19:18:49 INFO Received complete multipart upload request method=POST path=/21502026/10/25 19:18:49 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLmEzOTVlZmYwLTg0ODMtNGExMC1hYzhlLTFiMWZhYTEzN2JkOXgxNzkyOTU1OTIzNTE0MTI2MDAw parts=102151=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal21522026/10/25 19:18:49 INFO Received uploads request method=POST path=/21532026/10/25 19:18:49 INFO Received complete push request method=POST path=/api/pushes/1/complete2154=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info21552026/10/25 19:18:49 WARN Failed to register uploaded object key=q3rrsm8nn5jqag8ipfdnz5iz1x9g3n2m.narinfo error="server returned 404: 404 page not found\n"21562026/10/25 19:18:49 INFO Received uploads request method=POST path=/21572026/10/25 19:18:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2158=== CONT TestPush_RejectsBadRequests/bad_root2159--- PASS: TestUploadHandlersRejectInvalidKeys (0.04s)2160 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2161 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.01s)2162 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2163 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.01s)21642026/10/25 19:18:49 INFO Received push request method=POST path=/api/pushes21652026/10/25 19:18:49 INFO Received complete push request method=POST path=/api/pushes/1/complete21662026/10/25 19:18:49 WARN Failed to register uploaded object key=vlgss1669xzjp5q3v8vjzy33yamfl4ab.narinfo error="server returned 404: 404 page not found\n"21672026/10/25 19:18:49 INFO Completed push id=1 objects=4 duration=45.238708ms2168=== CONT TestPush_RejectsBadRequests/root_not_in_objects21692026/10/25 19:18:49 INFO Received push request method=POST path=/api/pushes2170=== CONT TestPush_RejectsBadRequests/no_objects21712026/10/25 19:18:49 INFO Received push request method=POST path=/api/pushes2172=== CONT TestPush_RejectsBadRequests/no_roots2173--- PASS: TestPush_RepeatedRootCommitsOnce (14.79s)21742026/10/25 19:18:49 INFO Received push request method=POST path=/api/pushes2175=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure2176=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts21772026/10/25 19:18:49 INFO Received uploads request method=POST path=/21782026/10/25 19:18:49 INFO Received request for more parts method=POST path=/21792026/10/25 19:18:49 INFO Completed push id=1 objects=9 duration=95.011167ms21802026/10/25 19:18:49 INFO Upload complete. (616ms)2181=== NAME TestClientMultipleUploads2182 client_integration_test.go:491: Uploaded 3 paths in 656.813917ms21832026/10/25 19:18:49 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLmRkMjAyZGMyLTRjN2EtNDljYy05NDE4LWZlNzQwNzYwYzQ1ZHgxNzkyOTU1OTE3MDEzODIzMDAw parts=102184--- PASS: TestPush_RejectsBadRequests (8.76s)2185 --- PASS: TestPush_RejectsBadRequests/bad_root (0.02s)2186 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.02s)2187 --- PASS: TestPush_RejectsBadRequests/no_objects (0.01s)2188 --- PASS: TestPush_RejectsBadRequests/no_roots (0.02s)21892026/10/25 19:18:49 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=02190--- PASS: TestClientMultipleUploads (11.62s)2191=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart21922026/10/25 19:18:49 INFO Received complete multipart upload request method=POST path=/2193=== CONT TestService_RequireScope_OIDC/builder_may_write2194=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2195=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read21962026/10/25 19:18:49 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]2197=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2198=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2199=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc22002026/10/25 19:18:49 INFO Vacuumed table table=pending_closures2201=== CONT TestService_RequireScope_OIDC/writer_implies_read2202=== CONT TestService_RequireScope_OIDC/reader_may_read22032026-10-25 19:18:49.560 UTC [33963] LOG: checkpoint starting: wal2204=== CONT TestService_RequireScope_OIDC/static_token_may_write2205=== CONT TestService_RequireScope_OIDC/static_token_may_admin2206=== CONT TestService_RequireScope_OIDC/reader_may_not_write2207=== CONT TestService_RequireScope_OIDC/ops_may_not_write2208=== CONT TestService_RequireScope_OIDC/ops_may_admin2209=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2210=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2211=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected22122026/10/25 19:18:49 WARN Request failed, retrying attempt=5 backoff=1.522382655s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22132026/10/25 19:18:49 WARN Authentication failed token_preview=eyJhbGciOi...jCdKIvhbWA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2214=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2215=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected22162026/10/25 19:18:49 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]22172026/10/25 19:18:49 INFO Received create pin request method=POST path=/api/pins/app22182026/10/25 19:18:49 INFO Vacuumed table table=pending_objects22192026/10/25 19:18:49 INFO Vacuumed table table=multipart_uploads2220--- PASS: TestService_RequireScope_OIDC (10.73s)2221 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2222 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2223 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.01s)2224 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2225 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2226 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2227 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2228 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2229 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2230 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2231 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2232 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2233 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2234 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2235--- PASS: TestService_AuthMiddleware_OIDC (8.41s)2236 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2237 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)2238 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2239 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)22402026/10/25 19:18:49 INFO Vacuumed table table=closures22412026/10/25 19:18:49 INFO Received create pin request method=POST path=/api/pins/app22422026/10/25 19:18:49 INFO Vacuumed table table=objects22432026/10/25 19:18:49 INFO Received create pin request method=POST path=/api/pins/deploy22442026/10/25 19:18:49 INFO Received create pin request method=POST path=/api/pins/deploy22452026/10/25 19:18:49 INFO Received create pin request method=POST path=/api/pins/deploy22462026/10/25 19:18:49 INFO Received create pin request method=POST path=/api/pins/deploy22472026/10/25 19:18:49 INFO Received create pin request method=POST path=/api/pins/deploy22482026/10/25 19:18:49 INFO Received create pin request method=POST path=/api/pins/deploy22492026/10/25 19:18:49 INFO Received create pin request method=POST path=/api/pins/deploy22502026/10/25 19:18:49 INFO Received create pin request method=POST path=/api/pins/deploy22512026/10/25 19:18:49 INFO Received create pin request method=POST path=/api/pins/deploy22522026/10/25 19:18:50 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo22532026/10/25 19:18:50 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02254=== NAME TestClientIntegration2255 client_integration_test.go:445: Objects in database after GC:2256 client_integration_test.go:445: Successfully deleted all objects with GC --force22572026/10/25 19:18:50 INFO Received create pin request method=POST path=/api/pins/deploy22582026/10/25 19:18:50 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo22592026/10/25 19:18:50 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo2260--- PASS: TestClientIntegration (14.91s)2261--- PASS: TestCreatePinRejectsBadInput (8.91s)2262--- PASS: TestConcurrentPinUpdatesAgree (9.53s)22632026/10/25 19:18:51 INFO Received create pin request method=POST path=/api/pins/app22642026/10/25 19:18:51 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22652026/10/25 19:18:51 WARN Request failed, retrying attempt=2 backoff=194.441486ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22662026/10/25 19:18:51 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo22672026/10/25 19:18:51 INFO Received delete pin request method=DELETE path=/api/pins/app22682026/10/25 19:18:51 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket95/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"22692026/10/25 19:18:51 INFO Received delete pin request method=DELETE path=/api/pins/app22702026/10/25 19:18:51 WARN Request failed, retrying attempt=3 backoff=366.416135ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22712026/10/25 19:18:51 WARN Request failed, retrying attempt=4 backoff=875.989857ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22722026/10/25 19:18:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2273--- PASS: TestService_Rustfstest (9.59s)22742026/10/25 19:18:52 INFO Deleted pin name=app2275--- PASS: TestDeletePinKeepsRowWhenS3Fails (10.01s)22762026/10/25 19:18:52 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLjg3YjA4ZDdlLTE3NWUtNDNlZS04MzcxLTI0NWNlOTk1ZmEyM3gxNzkyOTU1OTI4NTgyMTk0MDAw parts=1022772026/10/25 19:18:52 WARN Request failed, retrying attempt=5 backoff=1.613271139s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22782026/10/25 19:18:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2279--- PASS: TestUploadHandlersRejectOversizedBody (0.07s)2280 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.32s)2281 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.30s)2282 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (4.46s)22832026/10/25 19:18:54 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLmIxMDJhMzA0LWQ4OWQtNDgzYy1hMWViLTk5MjQxNzE2ZjE3MngxNzkyOTU1OTE3MDEzODYyMDAw parts=1022842026-10-25 19:18:54.309 UTC [34534] ERROR: could not obtain lock on row in relation "closures"22852026-10-25 19:18:54.309 UTC [34534] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT22862026-10-25 19:18:54.318 UTC [34534] ERROR: could not obtain lock on row in relation "closures"22872026-10-25 19:18:54.318 UTC [34534] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT22882026-10-25 19:18:54.325 UTC [34534] ERROR: could not obtain lock on row in relation "closures"22892026-10-25 19:18:54.325 UTC [34534] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT22902026-10-25 19:18:54.331 UTC [34534] ERROR: could not obtain lock on row in relation "closures"22912026-10-25 19:18:54.331 UTC [34534] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT22922026-10-25 19:18:54.341 UTC [34534] ERROR: could not obtain lock on row in relation "closures"22932026-10-25 19:18:54.341 UTC [34534] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT2294--- PASS: TestPush_RootsAreLockedInByteOrder (25.60s)22952026/10/25 19:18:54 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"22962026/10/25 19:18:54 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22972026/10/25 19:18:54 WARN Request failed, retrying attempt=2 backoff=187.850989ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22982026/10/25 19:18:54 WARN Request failed, retrying attempt=3 backoff=401.254304ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22992026/10/25 19:18:54 INFO Aborted multipart uploads count=0 kept=023002026/10/25 19:18:54 WARN Force mode enabled - objects will be deleted immediately without grace period23012026-10-25 19:18:54.828 UTC [34541] ERROR: canceling statement due to user request23022026-10-25 19:18:54.828 UTC [34541] STATEMENT: -- name: MarkStaleObjects :execrows2303 WITH RECURSIVE ct AS (2304 SELECT timezone('UTC', now()) AS now2305 ),2306 closure_reach AS (2307 -- Start with all closure keys2308 SELECT o.key, o.refs2309 FROM objects o2310 INNER JOIN closures c ON o.key = c.key2311 UNION2312 -- Recursively add all referenced objects2313 SELECT o.key, o.refs2314 FROM objects o2315 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2316 ),2317 reachable_objects AS (2318 SELECT DISTINCT key FROM closure_reach2319 ),2320 stale_objects AS (2321 SELECT o.key2322 FROM objects AS o, ct2323 WHERE2324 NOT EXISTS (2325 SELECT 12326 FROM reachable_objects ro2327 WHERE ro.key = o.key2328 )2329 AND NOT EXISTS (2330 SELECT 12331 FROM pending_objects AS po2332 WHERE po.key = o.key2333 )2334 AND o.deleted_at IS NULL -- Only mark fresh objects2335 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2336 FOR UPDATE2337 )2338 UPDATE objects2339 SET2340 deleted_at = ct.now,2341 first_deleted_at = COALESCE(first_deleted_at, ct.now)2342 FROM stale_objects, ct2343 WHERE objects.key = stale_objects.key2344 23452026/10/25 19:18:55 WARN Request failed, retrying attempt=4 backoff=737.787098ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23462026/10/25 19:18:55 WARN Request failed, retrying attempt=5 backoff=1.727389212s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23472026/10/25 19:18:55 INFO Aborted multipart uploads count=0 kept=023482026/10/25 19:18:55 WARN Force mode enabled - objects will be deleted immediately without grace period23492026/10/25 19:18:55 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:56253/bucket99/?delete=\": context canceled"2350--- PASS: TestGCEndsOnShutdown (0.01s)2351 --- PASS: TestGCEndsOnShutdown/before_the_run (9.19s)2352 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (10.36s)2353 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (10.45s)23542026/10/25 19:18:56 INFO Received uploads request method=POST path=/api/pending_closures2355=== NAME TestOrphanedObjectsGCStressTest2356 orphaned_objects_gc_test.go:503: Stress test completed successfully:2357 orphaned_objects_gc_test.go:504: - Active objects preserved: 202358 orphaned_objects_gc_test.go:505: - Objects deleted: 2102359 orphaned_objects_gc_test.go:506: - Total GC'd: 2102360--- PASS: TestOrphanedObjectsGCStressTest (41.71s)23612026/10/25 19:18:56 INFO Received uploads request method=POST path=/api/pending_closures23622026/10/25 19:18:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23632026/10/25 19:18:56 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLjdjZTM0NTM2LWRiNWUtNDEyMi05NGI2LTQ1MThkY2Q5ODdjOHgxNzkyOTU1OTI4NTgxNzczMDAw parts=1023642026/10/25 19:18:57 INFO Received uploads request method=POST path=/api/pending_closures23652026/10/25 19:18:57 INFO Aborted multipart uploads count=0 kept=023662026/10/25 19:18:57 WARN Force mode enabled - objects will be deleted immediately without grace period23672026/10/25 19:18:57 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLmZmZjFiM2YwLWJhZGQtNGM2Yi05ODcyLTE3MmQ5NWIyZjMzZXgxNzkyOTU1OTM2NTg3MjkxMDAw error="Access Denied"23682026/10/25 19:18:57 WARN keeping failed pending closure for cleanup to retry the abort id=123692026/10/25 19:18:57 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=023702026/10/25 19:18:57 INFO Vacuumed table table=pending_closures23712026/10/25 19:18:57 INFO Vacuumed table table=pending_objects23722026/10/25 19:18:57 INFO Vacuumed table table=multipart_uploads23732026/10/25 19:18:57 INFO Vacuumed table table=closures23742026/10/25 19:18:57 INFO Received uploads request method=POST path=/api/pending_closures23752026/10/25 19:18:57 INFO Vacuumed table table=objects23762026/10/25 19:18:57 INFO Aborted multipart uploads count=0 kept=023772026/10/25 19:18:57 WARN Force mode enabled - objects will be deleted immediately without grace period23782026/10/25 19:18:57 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=023792026/10/25 19:18:57 INFO Vacuumed table table=pending_closures23802026/10/25 19:18:57 INFO Vacuumed table table=pending_objects23812026/10/25 19:18:57 INFO Vacuumed table table=multipart_uploads23822026/10/25 19:18:57 INFO Vacuumed table table=closures23832026/10/25 19:18:57 INFO Vacuumed table table=objects2384--- PASS: TestPendingClosureFailureTracksEveryUpload (0.00s)2385 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (11.47s)2386 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (11.68s)2387--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2388 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (11.29s)2389 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (10.87s)23902026/10/25 19:18:57 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23912026/10/25 19:18:57 WARN Request failed, retrying attempt=2 backoff=180.089467ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23922026/10/25 19:18:57 WARN Request failed, retrying attempt=3 backoff=360.521574ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23932026/10/25 19:18:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23942026/10/25 19:18:58 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NDY5OGFlMGQtZWM5Ny00ZWQwLTgyN2YtYTYyNWFjMmE4MGVmLmQyYjExNGQwLWIyNjYtNGMxZS1iYWZkLTY2YWRmYmVjMGQ1N3gxNzkyOTU1OTI4NTgyMjUyMDAw parts=1023952026/10/25 19:18:58 INFO Received complete push request method=POST path=/api/pushes/1/complete23962026/10/25 19:18:58 INFO Completed push id=1 objects=6 duration=10.700792ms2397--- PASS: TestPush_CompleteCommitsEveryRoot (17.69s)2398--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2399 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (10.84s)2400 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (10.91s)24012026/10/25 19:18:58 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"24022026/10/25 19:18:58 INFO Received uploads request method=POST path=/api/pending_closures24032026/10/25 19:18:58 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"24042026/10/25 19:18:58 WARN Request failed, retrying attempt=4 backoff=807.178594ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2405--- PASS: TestPendingClosureWriteTimeout (0.01s)2406 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2407 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2408 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2409 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (10.61s)24102026/10/25 19:18:59 WARN Request failed, retrying attempt=5 backoff=1.665261236s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2411--- PASS: TestClientErrorHandling (0.00s)2412 --- PASS: TestClientErrorHandling/InvalidStorePath (10.57s)2413 --- PASS: TestClientErrorHandling/InvalidAuthToken (10.26s)2414 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.27s)2415PASS2416{"timestamp":"2026-10-25T19:19:00.777072Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:56805","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(3)"}24172026-10-25 19:19:00.964 UTC [33958] LOG: received smart shutdown request24182026-10-25 19:19:00.965 UTC [33958] LOG: background worker "logical replication launcher" (PID 33968) exited with exit code 124192026-10-25 19:19:02.093 UTC [33963] LOG: checkpoint complete: wrote 8786 buffers (53.6%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=11.628 s, sync=0.728 s, total=12.533 s; sync files=37079, longest=0.003 s, average=0.001 s; distance=532963 kB, estimate=532963 kB; lsn=0/233DE288, redo lsn=0/22005CB824202026-10-25 19:19:02.094 UTC [33963] LOG: shutting down24212026-10-25 19:19:02.094 UTC [33963] LOG: checkpoint starting: shutdown immediate24222026-10-25 19:19:02.252 UTC [33963] LOG: checkpoint complete: wrote 3370 buffers (20.6%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 1 recycled; write=0.118 s, sync=0.039 s, total=0.159 s; sync files=1171, longest=0.001 s, average=0.001 s; distance=20321 kB, estimate=481699 kB; lsn=0/233DE300, redo lsn=0/233DE30024232026-10-25 19:19:02.259 UTC [33958] LOG: database system is shut down2424Running OIDC tests...2425=== RUN TestAudienceForIssuer2426=== PAUSE TestAudienceForIssuer2427=== RUN TestHTTPClientForHasTimeouts2428=== PAUSE TestHTTPClientForHasTimeouts2429=== RUN TestGlobMatch2430=== PAUSE TestGlobMatch2431=== RUN TestValidateToken_ValidToken2432=== PAUSE TestValidateToken_ValidToken2433=== RUN TestValidateToken_WrongAudience2434=== PAUSE TestValidateToken_WrongAudience2435=== RUN TestValidateToken_Expired2436=== PAUSE TestValidateToken_Expired2437=== RUN TestValidateToken_BoundClaimsMismatch2438=== PAUSE TestValidateToken_BoundClaimsMismatch2439=== RUN TestValidateToken_BoundSubjectMismatch2440=== PAUSE TestValidateToken_BoundSubjectMismatch2441=== RUN TestValidateToken_MultipleProviders2442=== PAUSE TestValidateToken_MultipleProviders2443=== RUN TestValidateToken_NoMatchingProvider2444=== PAUSE TestValidateToken_NoMatchingProvider2445=== RUN TestValidateToken_KubernetesServiceAccount2446=== PAUSE TestValidateToken_KubernetesServiceAccount2447=== RUN TestNewValidator_KubernetesRequiresCA2448=== PAUSE TestNewValidator_KubernetesRequiresCA2449=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2450=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2451=== RUN TestPins_ReservedForMatchingRule2452=== PAUSE TestPins_ReservedForMatchingRule2453=== RUN TestPins_TopLevelShorthand2454=== PAUSE TestPins_TopLevelShorthand2455=== RUN TestPins_ConfigValidation2456=== PAUSE TestPins_ConfigValidation2457=== RUN TestScopes_LegacyProviderDefaultsToWrite2458=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2459=== RUN TestScopes_Rules2460=== PAUSE TestScopes_Rules2461=== RUN TestScopes_ConfigValidation2462=== PAUSE TestScopes_ConfigValidation2463=== CONT TestHTTPClientForHasTimeouts2464=== CONT TestValidateToken_WrongAudience2465=== CONT TestValidateToken_ValidToken2466=== CONT TestValidateToken_KubernetesServiceAccount2467=== CONT TestValidateToken_Expired2468=== CONT TestGlobMatch2469=== RUN TestGlobMatch/foo_foo2470=== PAUSE TestGlobMatch/foo_foo2471=== RUN TestGlobMatch/foo_bar2472=== PAUSE TestGlobMatch/foo_bar2473=== CONT TestPins_ReservedForMatchingRule2474=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2475=== CONT TestNewValidator_KubernetesRequiresCA2476=== CONT TestPins_TopLevelShorthand2477=== CONT TestValidateToken_BoundClaimsMismatch2478=== CONT TestPins_ConfigValidation2479=== CONT TestScopes_ConfigValidation2480=== CONT TestScopes_Rules2481=== CONT TestScopes_LegacyProviderDefaultsToWrite2482--- PASS: TestPins_ConfigValidation (0.00s)2483=== CONT TestValidateToken_NoMatchingProvider2484=== CONT TestValidateToken_MultipleProviders2485--- PASS: TestScopes_ConfigValidation (0.00s)2486=== CONT TestAudienceForIssuer2487--- PASS: TestAudienceForIssuer (0.00s)2488=== CONT TestValidateToken_BoundSubjectMismatch2489=== RUN TestGlobMatch/*_2490=== PAUSE TestGlobMatch/*_2491=== RUN TestGlobMatch/*_anything2492=== PAUSE TestGlobMatch/*_anything2493=== RUN TestGlobMatch/foo*_foo2494=== PAUSE TestGlobMatch/foo*_foo2495=== RUN TestGlobMatch/foo*_foobar2496=== PAUSE TestGlobMatch/foo*_foobar2497=== RUN TestGlobMatch/foo*_bar2498=== PAUSE TestGlobMatch/foo*_bar2499=== RUN TestGlobMatch/*bar_bar2500=== PAUSE TestGlobMatch/*bar_bar2501=== RUN TestGlobMatch/*bar_foobar2502=== PAUSE TestGlobMatch/*bar_foobar2503=== RUN TestGlobMatch/*bar_foo2504=== PAUSE TestGlobMatch/*bar_foo2505=== RUN TestGlobMatch/foo*bar_foobar2506=== PAUSE TestGlobMatch/foo*bar_foobar2507=== RUN TestGlobMatch/foo*bar_foo123bar2508=== PAUSE TestGlobMatch/foo*bar_foo123bar2509=== RUN TestGlobMatch/foo*bar_foobarbaz2510=== PAUSE TestGlobMatch/foo*bar_foobarbaz2511=== RUN TestGlobMatch/*/*_foo/bar2512=== PAUSE TestGlobMatch/*/*_foo/bar2513=== RUN TestGlobMatch/*/*_foo2514=== PAUSE TestGlobMatch/*/*_foo2515=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2516=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2517=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02518=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02519=== RUN TestGlobMatch/refs/*/main_refs/heads/main2520=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2521=== RUN TestGlobMatch/fo?_foo2522=== PAUSE TestGlobMatch/fo?_foo2523=== RUN TestGlobMatch/fo?_fo2524=== PAUSE TestGlobMatch/fo?_fo2525=== RUN TestGlobMatch/fo?_fooo2526=== PAUSE TestGlobMatch/fo?_fooo2527=== RUN TestGlobMatch/?oo_foo2528=== PAUSE TestGlobMatch/?oo_foo2529=== RUN TestGlobMatch/?oo_boo2530=== PAUSE TestGlobMatch/?oo_boo2531=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2532=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2533=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2534=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2535=== CONT TestGlobMatch/foo_foo2536=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2537=== CONT TestGlobMatch/?oo_boo2538=== CONT TestGlobMatch/?oo_foo2539=== CONT TestGlobMatch/fo?_fooo2540=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2541=== CONT TestGlobMatch/fo?_foo2542=== CONT TestGlobMatch/fo?_fo2543=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02544=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2545=== CONT TestGlobMatch/*/*_foo2546=== CONT TestGlobMatch/refs/*/main_refs/heads/main2547=== CONT TestGlobMatch/*/*_foo/bar2548=== CONT TestGlobMatch/foo*bar_foobarbaz2549=== CONT TestGlobMatch/foo*bar_foobar2550=== CONT TestGlobMatch/*bar_foo2551=== CONT TestGlobMatch/*bar_foobar2552=== CONT TestGlobMatch/*bar_bar2553=== CONT TestGlobMatch/foo*bar_foo123bar2554=== CONT TestGlobMatch/foo*_foobar2555=== CONT TestGlobMatch/foo*_foo2556=== CONT TestGlobMatch/foo*_bar2557=== CONT TestGlobMatch/foo_bar2558=== CONT TestGlobMatch/*_anything2559=== CONT TestGlobMatch/*_2560--- PASS: TestGlobMatch (0.01s)2561 --- PASS: TestGlobMatch/foo_foo (0.00s)2562 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2563 --- PASS: TestGlobMatch/?oo_boo (0.00s)2564 --- PASS: TestGlobMatch/?oo_foo (0.00s)2565 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2566 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2567 --- PASS: TestGlobMatch/fo?_foo (0.00s)2568 --- PASS: TestGlobMatch/fo?_fo (0.00s)2569 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2570 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2571 --- PASS: TestGlobMatch/*/*_foo (0.00s)2572 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2573 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2574 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2575 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2576 --- PASS: TestGlobMatch/*bar_foo (0.00s)2577 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2578 --- PASS: TestGlobMatch/*bar_bar (0.00s)2579 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2580 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2581 --- PASS: TestGlobMatch/foo*_foo (0.00s)2582 --- PASS: TestGlobMatch/foo*_bar (0.00s)2583 --- PASS: TestGlobMatch/foo_bar (0.00s)2584 --- PASS: TestGlobMatch/*_anything (0.00s)2585 --- PASS: TestGlobMatch/*_ (0.00s)25862026/10/25 19:19:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57048/oidc25872026/10/25 19:19:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57045/oidc2588--- PASS: TestValidateToken_Expired (0.07s)25892026/10/25 19:19:05 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:5704625902026/10/25 19:19:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57051/oidc2591--- PASS: TestPins_ReservedForMatchingRule (0.07s)2592--- PASS: TestValidateToken_KubernetesServiceAccount (0.08s)25932026/10/25 19:19:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57055/oidc2594--- PASS: TestPins_TopLevelShorthand (0.08s)2595--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.08s)25962026/10/25 19:19:05 http: TLS handshake error from 127.0.0.1:57054: remote error: tls: bad certificate2597--- PASS: TestNewValidator_KubernetesRequiresCA (0.08s)25982026/10/25 19:19:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57057/oidc2599--- PASS: TestValidateToken_BoundClaimsMismatch (0.13s)26002026/10/25 19:19:05 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12326012026/10/25 19:19:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57061/oidc26022026/10/25 19:19:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57064/oidc2603--- PASS: TestValidateToken_ValidToken (0.16s)2604--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.16s)2605--- PASS: TestScopes_Rules (0.16s)26062026/10/25 19:19:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57066/oidc2607--- PASS: TestValidateToken_WrongAudience (0.18s)26082026/10/25 19:19:05 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:57069/oidc2609--- PASS: TestValidateToken_BoundSubjectMismatch (0.19s)26102026/10/25 19:19:05 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:57059/oidc26112026/10/25 19:19:05 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:57071/oidc2612--- PASS: TestValidateToken_MultipleProviders (0.19s)2613--- PASS: TestHTTPClientForHasTimeouts (0.20s)26142026/10/25 19:19:05 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:57068/oidc2615--- PASS: TestValidateToken_NoMatchingProvider (0.23s)2616PASS2617Running hook tests...2618=== RUN TestSendPathsEmpty2619=== PAUSE TestSendPathsEmpty2620=== RUN TestQueueEnqueueAndFetch2621=== PAUSE TestQueueEnqueueAndFetch2622=== RUN TestQueueDeduplication2623=== PAUSE TestQueueDeduplication2624=== RUN TestQueueRemove2625=== PAUSE TestQueueRemove2626=== RUN TestQueueFetchBatchLimit2627=== PAUSE TestQueueFetchBatchLimit2628=== RUN TestQueueRetryMovesToBack2629=== PAUSE TestQueueRetryMovesToBack2630=== RUN TestQueueFetchRemoveLifecycle2631=== PAUSE TestQueueFetchRemoveLifecycle2632=== RUN TestQueueConcurrentWriters2633=== PAUSE TestQueueConcurrentWriters2634=== RUN TestQueueEnqueueWaitsOutSlowWriter2635=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2636=== RUN TestQueueRemoveLargeClosure2637=== PAUSE TestQueueRemoveLargeClosure2638=== RUN TestServerClientIntegration2639--- PASS: TestServerClientIntegration (0.00s)2640=== RUN TestServerQueueError26412026/10/25 19:19:06 ERROR Failed to queue paths error="permission denied" count=12642--- PASS: TestServerQueueError (0.00s)2643=== RUN TestServerRefusesOversizedAndNonStoreRequests2644=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2645=== RUN TestGetListenerSocketActivation2646 server_test.go:236: systemd socket activation does not exist on darwin2647--- SKIP: TestGetListenerSocketActivation (0.00s)2648=== RUN TestServerStalledClientDoesNotBlockShutdown2649=== PAUSE TestServerStalledClientDoesNotBlockShutdown2650=== RUN TestServerBacksOffOnAcceptErrors2651=== PAUSE TestServerBacksOffOnAcceptErrors2652=== RUN TestDrainIsolatesPoisonPath2653=== PAUSE TestDrainIsolatesPoisonPath2654=== RUN TestRunNotBlockedByPoisonHead2655=== PAUSE TestRunNotBlockedByPoisonHead2656=== RUN TestDrainGivesUpWhenServerDown2657=== PAUSE TestDrainGivesUpWhenServerDown2658=== RUN TestFailedPathPrunedByLaterClosure2659=== PAUSE TestFailedPathPrunedByLaterClosure2660=== RUN TestWorkerUploadsAndRemoves2661=== PAUSE TestWorkerUploadsAndRemoves2662=== RUN TestWorkerSkipsGCdPaths2663=== PAUSE TestWorkerSkipsGCdPaths2664=== RUN TestWorkerPrunesClosureDeps2665=== PAUSE TestWorkerPrunesClosureDeps2666=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2667=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2668=== RUN TestDrainTimeout2669=== PAUSE TestDrainTimeout2670=== RUN TestDrainTimeoutDuringIsolation2671=== PAUSE TestDrainTimeoutDuringIsolation2672=== RUN TestShutdownFinishesInFlightPush2673=== PAUSE TestShutdownFinishesInFlightPush2674=== RUN TestWorkerRemoveFailureIsNotProgress2675=== PAUSE TestWorkerRemoveFailureIsNotProgress2676=== RUN TestWorkerKeepsPathItCannotStat2677=== PAUSE TestWorkerKeepsPathItCannotStat2678=== CONT TestSendPathsEmpty2679=== CONT TestDrainTimeoutDuringIsolation2680=== CONT TestQueueFetchBatchLimit2681=== CONT TestWorkerUploadsAndRemoves2682=== CONT TestQueueConcurrentWriters2683=== CONT TestWorkerKeepsPathItCannotStat2684=== CONT TestShutdownFinishesInFlightPush2685=== RUN TestShutdownFinishesInFlightPush/completes2686=== CONT TestWorkerRemoveFailureIsNotProgress2687=== PAUSE TestShutdownFinishesInFlightPush/completes2688=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2689=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2690=== CONT TestWorkerPrunesClosureDeps2691=== CONT TestWorkerSkipsGCdPaths2692=== CONT TestDrainGivesUpWhenServerDown2693=== CONT TestServerStalledClientDoesNotBlockShutdown2694=== CONT TestQueueFetchRemoveLifecycle2695=== CONT TestServerRefusesOversizedAndNonStoreRequests2696=== CONT TestDrainTimeout2697=== CONT TestDrainIsolatesPoisonPath2698=== CONT TestQueueEnqueueAndFetch2699=== CONT TestRunNotBlockedByPoisonHead27002026/10/25 19:19:06 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2701=== CONT TestQueueRemove2702=== CONT TestFailedPathPrunedByLaterClosure2703--- PASS: TestSendPathsEmpty (0.00s)2704=== CONT TestServerBacksOffOnAcceptErrors27052026/10/25 19:19:06 ERROR Refusing path outside the store path=/nix/store store=/nix/store2706=== CONT TestQueueRetryMovesToBack2707=== CONT TestQueueEnqueueWaitsOutSlowWriter27082026/10/25 19:19:06 ERROR Accept failed error="too many open files"2709=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2710=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2711=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2712=== CONT TestQueueRemoveLargeClosure27132026/10/25 19:19:06 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store27142026/10/25 19:19:06 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store2715=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2716=== CONT TestQueueDeduplication2717=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2718=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2719=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2720=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2721=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline27222026/10/25 19:19:06 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store2723=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2724=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2725=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2726=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short27272026/10/25 19:19:06 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27282026/10/25 19:19:06 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27292026/10/25 19:19:06 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store27302026/10/25 19:19:06 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store27312026/10/25 19:19:06 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store27322026/10/25 19:19:06 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store27332026/10/25 19:19:06 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store27342026/10/25 19:19:06 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store27352026/10/25 19:19:06 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store27362026/10/25 19:19:06 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store27372026/10/25 19:19:06 ERROR Accept failed error="too many open files"27382026/10/25 19:19:06 ERROR Failed to decode request error="unexpected EOF"2739=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2740--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)27412026/10/25 19:19:07 ERROR Accept failed error="too many open files"27422026/10/25 19:19:07 INFO Upload queue status pending=227432026/10/25 19:19:07 INFO Uploading batch count=227442026/10/25 19:19:07 INFO Uploading batch count=427452026/10/25 19:19:07 ERROR Upload failed error="upload failed" count=427462026/10/25 19:19:07 INFO Uploading batch count=427472026/10/25 19:19:07 ERROR Upload failed error="upload failed" count=427482026/10/25 19:19:07 WARN Cannot stat store path, will retry later path=/private/var/tb/2/scratch/52f05e2dc9743da8/build/TestWorkerKeepsPathItCannotStat4086253255/002/locked/aaa error="lstat /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestWorkerKeepsPathItCannotStat4086253255/002/locked/aaa: permission denied"27492026/10/25 19:19:07 INFO Upload queue status pending=227502026/10/25 19:19:07 INFO Uploading batch count=227512026/10/25 19:19:07 ERROR Upload failed error="upload failed" count=227522026/10/25 19:19:07 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/2/scratch/52f05e2dc9743da8/build/TestDrainGivesUpWhenServerDown1927901017/002/a27532026/10/25 19:19:07 INFO Uploading batch count=127542026/10/25 19:19:07 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/2/scratch/52f05e2dc9743da8/build/TestDrainIsolatesPoisonPath1609272109/002/bbb27552026/10/25 19:19:07 INFO Upload queue status pending=327562026/10/25 19:19:07 INFO Uploading batch count=427572026/10/25 19:19:07 ERROR Upload failed error="upload failed" count=427582026/10/25 19:19:07 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/2/scratch/52f05e2dc9743da8/build/TestWorkerSkipsGCdPaths3324277846/002/nonexistent27592026/10/25 19:19:07 WARN Cannot stat store path, will retry later path=/private/var/tb/2/scratch/52f05e2dc9743da8/build/TestWorkerKeepsPathItCannotStat4086253255/002/locked/aaa error="lstat /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestWorkerKeepsPathItCannotStat4086253255/002/locked/aaa: permission denied"27602026/10/25 19:19:07 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/2/scratch/52f05e2dc9743da8/build/TestDrainGivesUpWhenServerDown1927901017/002/b27612026/10/25 19:19:07 INFO Upload queue status pending=227622026/10/25 19:19:07 INFO Uploading batch count=227632026/10/25 19:19:07 INFO Uploading batch count=227642026/10/25 19:19:07 INFO Uploading batch count=127652026/10/25 19:19:07 ERROR Upload failed error="upload failed" count=127662026/10/25 19:19:07 INFO Uploading batch count=22767--- PASS: TestQueueDeduplication (0.03s)2768--- PASS: TestQueueRetryMovesToBack (0.04s)2769=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27702026/10/25 19:19:07 ERROR Accept failed error="too many open files"2771=== CONT TestShutdownFinishesInFlightPush/completes27722026/10/25 19:19:07 INFO Upload queue status pending=327732026/10/25 19:19:07 INFO Upload queue status pending=22774--- PASS: TestQueueEnqueueAndFetch (0.04s)2775=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch27762026/10/25 19:19:07 INFO Uploading batch count=227772026/10/25 19:19:07 ERROR Upload failed error="upload failed" count=227782026/10/25 19:19:07 WARN Cannot stat store path, will retry later path=/private/var/tb/2/scratch/52f05e2dc9743da8/build/TestWorkerKeepsPathItCannotStat4086253255/002/locked/aaa error="lstat /private/var/tb/2/scratch/52f05e2dc9743da8/build/TestWorkerKeepsPathItCannotStat4086253255/002/locked/aaa: permission denied"27792026/10/25 19:19:07 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/2/scratch/52f05e2dc9743da8/build/TestDrainGivesUpWhenServerDown1927901017/002/c2780--- PASS: TestQueueRemove (0.04s)2781=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths27822026/10/25 19:19:07 INFO Uploading batch count=227832026/10/25 19:19:07 ERROR Drain finished with paths left in queue remaining=127842026/10/25 19:19:07 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/2/scratch/52f05e2dc9743da8/build/TestDrainGivesUpWhenServerDown1927901017/002/d27852026/10/25 19:19:07 INFO Uploading batch count=127862026/10/25 19:19:07 ERROR Upload failed error="upload failed" count=127872026/10/25 19:19:07 INFO Uploading batch count=127882026/10/25 19:19:07 ERROR Upload failed error="upload failed" count=127892026/10/25 19:19:07 INFO Uploading batch count=127902026/10/25 19:19:07 INFO Uploading batch count=227912026/10/25 19:19:07 ERROR Upload failed error="upload failed" count=227922026/10/25 19:19:07 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/2/scratch/52f05e2dc9743da8/build/TestDrainGivesUpWhenServerDown1927901017/002/e2793--- PASS: TestQueueFetchRemoveLifecycle (0.04s)27942026/10/25 19:19:07 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/2/scratch/52f05e2dc9743da8/build/TestDrainGivesUpWhenServerDown1927901017/002/f2795--- PASS: TestWorkerKeepsPathItCannotStat (0.04s)2796--- PASS: TestQueueFetchBatchLimit (0.04s)27972026/10/25 19:19:07 INFO Uploading batch count=127982026/10/25 19:19:07 INFO Uploading batch count=127992026/10/25 19:19:07 ERROR Upload failed error="upload failed" count=128002026/10/25 19:19:07 ERROR Drain finished with paths left in queue remaining=1028012026/10/25 19:19:07 INFO Uploading batch count=128022026/10/25 19:19:07 ERROR Upload failed error="upload failed" count=128032026/10/25 19:19:07 ERROR Drain finished with paths left in queue remaining=12804--- PASS: TestFailedPathPrunedByLaterClosure (0.04s)2805--- PASS: TestDrainGivesUpWhenServerDown (0.05s)28062026/10/25 19:19:07 INFO Upload queue status pending=22807--- PASS: TestDrainIsolatesPoisonPath (0.05s)28082026/10/25 19:19:07 INFO Uploading batch count=22809--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.05s)28102026/10/25 19:19:07 INFO Uploading batch count=228112026/10/25 19:19:07 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228122026/10/25 19:19:07 INFO Uploading batch count=228132026/10/25 19:19:07 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228142026/10/25 19:19:07 INFO Uploading batch count=228152026/10/25 19:19:07 ERROR Upload failed error="upload failed" count=228162026/10/25 19:19:07 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/2/scratch/52f05e2dc9743da8/build/TestWorkerRemoveFailureIsNotProgresscollected_path2942164416/001/nonexistent28172026/10/25 19:19:07 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128182026/10/25 19:19:07 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128192026/10/25 19:19:07 INFO Uploading batch count=228202026/10/25 19:19:07 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/2/scratch/52f05e2dc9743da8/build/TestWorkerRemoveFailureIsNotProgresscollected_path2942164416/001/nonexistent28212026/10/25 19:19:07 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128222026/10/25 19:19:07 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228232026/10/25 19:19:07 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128242026/10/25 19:19:07 ERROR Drain finished with paths left in queue remaining=228252026/10/25 19:19:07 INFO Uploading batch count=228262026/10/25 19:19:07 ERROR Upload failed error="upload failed" count=228272026/10/25 19:19:07 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/2/scratch/52f05e2dc9743da8/build/TestWorkerRemoveFailureIsNotProgresscollected_path2942164416/001/nonexistent28282026/10/25 19:19:07 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128292026/10/25 19:19:07 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128302026/10/25 19:19:07 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128312026/10/25 19:19:07 ERROR Drain finished with paths left in queue remaining=128322026/10/25 19:19:07 INFO Uploading batch count=228332026/10/25 19:19:07 ERROR Upload failed error="upload failed" count=228342026/10/25 19:19:07 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=12835--- PASS: TestWorkerPrunesClosureDeps (0.05s)28362026/10/25 19:19:07 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128372026/10/25 19:19:07 ERROR Drain finished with paths left in queue remaining=22838--- PASS: TestWorkerSkipsGCdPaths (0.06s)2839--- PASS: TestWorkerUploadsAndRemoves (0.06s)2840--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2841 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.02s)2842 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.02s)2843 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.02s)28442026/10/25 19:19:07 ERROR Accept failed error="too many open files"28452026/10/25 19:19:07 ERROR Accept failed error="too many open files"2846--- PASS: TestQueueConcurrentWriters (0.17s)28472026/10/25 19:19:07 ERROR Failed to decode request error="read unix /private/var/tb/2/scratch/52f05e2dc9743da8/build/hook1308622133/test.sock->: i/o timeout"28482026/10/25 19:19:07 ERROR Failed to write response error="write unix /private/var/tb/2/scratch/52f05e2dc9743da8/build/hook1308622133/test.sock->: i/o timeout"2849--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)28502026/10/25 19:19:07 ERROR Drain finished with paths left in queue remaining=428512026/10/25 19:19:07 ERROR Upload failed error="context canceled" count=228522026/10/25 19:19:07 ERROR Drain finished with paths left in queue remaining=42853--- PASS: TestDrainTimeout (0.24s)28542026/10/25 19:19:07 ERROR Upload failed error="context canceled" count=228552026/10/25 19:19:07 ERROR Drain finished with paths left in queue remaining=22856--- PASS: TestShutdownFinishesInFlightPush (0.00s)2857 --- PASS: TestShutdownFinishesInFlightPush/completes (0.11s)2858 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.23s)28592026/10/25 19:19:07 ERROR Accept failed error="too many open files"28602026/10/25 19:19:07 ERROR Drain finished with paths left in queue remaining=32861--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2862 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.23s)2863 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.33s)28642026/10/25 19:19:07 ERROR Accept failed error="too many open files"2865--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)2866--- PASS: TestQueueRemoveLargeClosure (0.80s)28672026/10/25 19:19:08 INFO Uploading batch count=128682026/10/25 19:19:08 INFO Uploading batch count=128692026/10/25 19:19:08 INFO Uploading batch count=128702026/10/25 19:19:08 ERROR Upload failed error="upload failed" count=128712026/10/25 19:19:08 INFO Uploading batch count=128722026/10/25 19:19:08 ERROR Upload failed error="upload failed" count=128732026/10/25 19:19:08 INFO Uploading batch count=128742026/10/25 19:19:08 ERROR Upload failed error="upload failed" count=128752026/10/25 19:19:08 INFO Uploading batch count=128762026/10/25 19:19:08 ERROR Upload failed error="upload failed" count=128772026/10/25 19:19:08 ERROR Drain finished with paths left in queue remaining=12878--- PASS: TestRunNotBlockedByPoisonHead (1.08s)2879--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.04s)2880PASS2881Running signing tests...2882=== RUN TestExternalSigner2883=== PAUSE TestExternalSigner2884=== RUN TestExternalSignerWrongPublicKey2885=== PAUSE TestExternalSignerWrongPublicKey2886=== RUN TestExternalSignerErrors2887=== PAUSE TestExternalSignerErrors2888=== RUN TestExternalSignerRestartsAfterCrash2889=== PAUSE TestExternalSignerRestartsAfterCrash2890=== RUN TestExternalSignerProgramErrorKeepsProcess2891=== PAUSE TestExternalSignerProgramErrorKeepsProcess2892=== RUN TestExternalSignerClose2893=== PAUSE TestExternalSignerClose2894=== RUN TestExternalSignerRejectsInvalidPublicKey2895=== PAUSE TestExternalSignerRejectsInvalidPublicKey2896=== RUN TestExternalSignerCancellation2897=== PAUSE TestExternalSignerCancellation2898=== RUN TestGenerateFingerprint2899=== PAUSE TestGenerateFingerprint2900=== RUN TestParseSigningKey2901=== PAUSE TestParseSigningKey2902=== RUN TestSign2903=== PAUSE TestSign2904=== RUN TestSignBatch2905=== PAUSE TestSignBatch2906=== RUN TestNilKeyPublicKey2907=== PAUSE TestNilKeyPublicKey2908=== RUN TestSignErrors2909=== PAUSE TestSignErrors2910=== CONT TestExternalSigner2911=== CONT TestExternalSignerRejectsInvalidPublicKey2912=== CONT TestExternalSignerClose2913=== CONT TestSign2914=== CONT TestSignErrors2915=== CONT TestExternalSignerProgramErrorKeepsProcess2916=== CONT TestNilKeyPublicKey2917--- PASS: TestNilKeyPublicKey (0.00s)2918=== CONT TestExternalSignerWrongPublicKey2919=== CONT TestGenerateFingerprint2920=== RUN TestGenerateFingerprint/basic_with_references2921=== PAUSE TestGenerateFingerprint/basic_with_references2922=== CONT TestExternalSignerErrors2923=== RUN TestExternalSignerErrors/program_error2924=== PAUSE TestExternalSignerErrors/program_error2925=== CONT TestSignBatch2926=== RUN TestGenerateFingerprint/no_references2927=== RUN TestExternalSignerErrors/invalid_JSON2928=== CONT TestExternalSignerRestartsAfterCrash2929=== PAUSE TestExternalSignerErrors/invalid_JSON2930=== RUN TestExternalSignerErrors/wrong_shape2931=== PAUSE TestExternalSignerErrors/wrong_shape2932=== RUN TestExternalSignerErrors/invalid_signature_base642933=== PAUSE TestExternalSignerErrors/invalid_signature_base642934=== CONT TestParseSigningKey2935=== CONT TestExternalSignerCancellation2936=== RUN TestExternalSignerRejectsInvalidPublicKey/#002937=== PAUSE TestGenerateFingerprint/no_references2938=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2939=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002940=== RUN TestExternalSignerErrors/wrong_signature_length2941=== RUN TestParseSigningKey/valid_32-byte_key2942=== PAUSE TestExternalSignerErrors/wrong_signature_length2943=== RUN TestExternalSignerErrors/null2944=== PAUSE TestParseSigningKey/valid_32-byte_key2945=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2946=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2947=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2948=== PAUSE TestExternalSignerErrors/null2949=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2950=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2951=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2952=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2953=== RUN TestExternalSignerErrors/null_signatures2954=== PAUSE TestExternalSignerErrors/null_signatures2955=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2956=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2957=== RUN TestParseSigningKey/no_colon2958=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2959=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2960=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2961=== CONT TestExternalSignerRejectsInvalidPublicKey/#002962=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2963=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2964=== RUN TestGenerateFingerprint/invalid_nar_hash_length2965=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2966=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2967=== RUN TestExternalSignerErrors/wrong_signatures_shape2968=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2969=== RUN TestGenerateFingerprint/invalid_store_path_prefix2970=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2971=== RUN TestExternalSignerErrors/exit_at_startup2972=== RUN TestGenerateFingerprint/invalid_reference_prefix2973=== PAUSE TestExternalSignerErrors/exit_at_startup2974=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2975=== PAUSE TestParseSigningKey/no_colon2976=== RUN TestExternalSignerErrors/exit_on_request2977=== RUN TestParseSigningKey/empty_name2978=== PAUSE TestExternalSignerErrors/exit_on_request2979=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2980=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2981--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2982 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2983 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2984 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2985 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2986 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2987=== RUN TestExternalSignerErrors/unrequested_key2988=== CONT TestGenerateFingerprint/basic_with_references2989=== CONT TestGenerateFingerprint/invalid_store_path_prefix2990=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2991=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2992=== CONT TestGenerateFingerprint/no_references2993=== PAUSE TestParseSigningKey/empty_name2994=== PAUSE TestExternalSignerErrors/unrequested_key2995=== CONT TestGenerateFingerprint/invalid_reference_prefix2996=== CONT TestGenerateFingerprint/invalid_nar_hash_length2997=== RUN TestParseSigningKey/invalid_base642998--- PASS: TestGenerateFingerprint (0.00s)2999 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)3000 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)3001 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)3002 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)3003 --- PASS: TestGenerateFingerprint/no_references (0.00s)3004 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)3005 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)3006=== PAUSE TestParseSigningKey/invalid_base643007=== RUN TestExternalSignerErrors/missing_signature_name3008=== RUN TestParseSigningKey/wrong_length3009=== PAUSE TestExternalSignerErrors/missing_signature_name3010=== PAUSE TestParseSigningKey/wrong_length3011=== RUN TestExternalSignerErrors/wrong_signature_name3012=== PAUSE TestExternalSignerErrors/wrong_signature_name3013=== RUN TestExternalSignerErrors/wrong_id3014=== CONT TestParseSigningKey/no_colon3015=== CONT TestParseSigningKey/invalid_base643016=== PAUSE TestExternalSignerErrors/wrong_id3017=== CONT TestParseSigningKey/wrong_length3018=== CONT TestParseSigningKey/empty_name3019=== CONT TestParseSigningKey/valid_32-byte_key3020=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name3021=== RUN TestExternalSignerErrors/missing_signatures3022=== PAUSE TestExternalSignerErrors/missing_signatures3023=== RUN TestExternalSignerErrors/too_few_signatures3024=== PAUSE TestExternalSignerErrors/too_few_signatures3025=== CONT TestExternalSignerErrors/invalid_signature_base643026=== CONT TestExternalSignerErrors/missing_signature_name3027=== CONT TestExternalSignerErrors/wrong_signatures_shape3028=== CONT TestExternalSignerErrors/invalid_JSON3029=== CONT TestExternalSignerErrors/wrong_signature_name3030--- PASS: TestParseSigningKey (0.01s)3031 --- PASS: TestParseSigningKey/no_colon (0.00s)3032 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)3033 --- PASS: TestParseSigningKey/wrong_length (0.00s)3034 --- PASS: TestParseSigningKey/empty_name (0.00s)3035 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)3036 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)3037=== CONT TestExternalSignerErrors/wrong_shape3038=== CONT TestExternalSignerErrors/wrong_id3039=== CONT TestExternalSignerErrors/unrequested_key3040=== CONT TestExternalSignerErrors/exit_at_startup3041=== RUN TestSignErrors/nil_key3042=== PAUSE TestSignErrors/nil_key3043=== CONT TestExternalSignerErrors/wrong_signature_length3044=== RUN TestSignErrors/nil_narinfo3045=== CONT TestExternalSignerErrors/exit_on_request3046=== CONT TestExternalSignerErrors/null3047=== CONT TestExternalSignerErrors/null_signatures3048=== CONT TestExternalSignerErrors/too_few_signatures3049=== CONT TestExternalSignerErrors/program_error3050--- PASS: TestSign (0.01s)3051=== PAUSE TestSignErrors/nil_narinfo3052=== CONT TestExternalSignerErrors/missing_signatures3053=== RUN TestSignErrors/invalid_narinfo3054=== PAUSE TestSignErrors/invalid_narinfo3055=== RUN TestSignErrors/canceled3056=== PAUSE TestSignErrors/canceled3057=== CONT TestSignErrors/nil_key3058=== CONT TestSignErrors/canceled3059=== CONT TestSignErrors/invalid_narinfo3060=== CONT TestSignErrors/nil_narinfo3061--- PASS: TestSignErrors (0.01s)3062 --- PASS: TestSignErrors/nil_key (0.00s)3063 --- PASS: TestSignErrors/canceled (0.00s)3064 --- PASS: TestSignErrors/invalid_narinfo (0.00s)3065 --- PASS: TestSignErrors/nil_narinfo (0.00s)3066--- PASS: TestSignBatch (0.02s)3067--- PASS: TestExternalSignerClose (0.22s)3068--- PASS: TestExternalSigner (0.44s)3069--- PASS: TestExternalSignerWrongPublicKey (0.61s)3070--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.81s)3071--- PASS: TestExternalSignerRestartsAfterCrash (1.01s)3072--- PASS: TestExternalSignerCancellation (1.21s)3073--- PASS: TestExternalSignerErrors (0.01s)3074 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (1.36s)3075 --- PASS: TestExternalSignerErrors/missing_signature_name (1.56s)3076 --- PASS: TestExternalSignerErrors/invalid_JSON (1.74s)3077 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (1.94s)3078 --- PASS: TestExternalSignerErrors/wrong_signature_name (2.13s)3079 --- PASS: TestExternalSignerErrors/null_signatures (2.32s)3080 --- PASS: TestExternalSignerErrors/program_error (2.51s)3081 --- PASS: TestExternalSignerErrors/wrong_id (2.69s)3082 --- PASS: TestExternalSignerErrors/unrequested_key (2.88s)3083 --- PASS: TestExternalSignerErrors/wrong_shape (3.11s)3084 --- PASS: TestExternalSignerErrors/missing_signatures (3.30s)3085 --- PASS: TestExternalSignerErrors/too_few_signatures (3.50s)3086 --- PASS: TestExternalSignerErrors/null (3.72s)3087 --- PASS: TestExternalSignerErrors/exit_on_request (3.93s)3088 --- PASS: TestExternalSignerErrors/exit_at_startup (4.13s)3089 --- PASS: TestExternalSignerErrors/wrong_signature_length (4.33s)3090PASS3091Running OpenBao signer tests...3092=== RUN TestSign3093=== PAUSE TestSign3094=== RUN TestSignErrors3095=== PAUSE TestSignErrors3096=== RUN TestServe3097=== PAUSE TestServe3098=== RUN TestServeRejectsGarbage3099=== PAUSE TestServeRejectsGarbage3100=== CONT TestSign3101=== CONT TestSignErrors3102=== RUN TestSignErrors/http_error3103=== CONT TestServe3104=== CONT TestServeRejectsGarbage3105=== PAUSE TestSignErrors/http_error3106--- PASS: TestServeRejectsGarbage (0.00s)3107=== RUN TestSignErrors/invalid_json3108=== PAUSE TestSignErrors/invalid_json3109=== RUN TestSignErrors/no_prefix3110=== PAUSE TestSignErrors/no_prefix3111=== RUN TestSignErrors/invalid_base643112=== PAUSE TestSignErrors/invalid_base643113=== CONT TestSignErrors/no_prefix3114=== CONT TestSignErrors/invalid_json3115=== CONT TestSignErrors/invalid_base643116--- PASS: TestServe (0.00s)3117=== CONT TestSignErrors/http_error3118--- PASS: TestSign (0.00s)3119--- PASS: TestSignErrors (0.00s)3120 --- PASS: TestSignErrors/invalid_json (0.00s)3121 --- PASS: TestSignErrors/no_prefix (0.00s)3122 --- PASS: TestSignErrors/invalid_base64 (0.00s)3123 --- PASS: TestSignErrors/http_error (0.00s)3124PASS3125Running niks3-hook command tests...3126=== RUN TestServeSecondSignalEndsDrain3127=== PAUSE TestServeSecondSignalEndsDrain3128=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown3129=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown3130=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown3131=== CONT TestServeSecondSignalEndsDrain3132--- PASS: TestServeSecondSignalEndsDrain (0.05s)31332026/10/25 19:19:21 INFO Upload queue status pending=131342026/10/25 19:19:21 INFO Uploading batch count=13135--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.13s)3136PASS3137Running rate limiter tests...3138=== RUN TestAdaptiveRateLimiter_ThreadSafety3139=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3140=== CONT TestAdaptiveRateLimiter_ThreadSafety31412026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=7031422026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=4931432026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=34.331442026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=24.00999999999999831452026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=16.80731462026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=11.76489999999999931472026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=8.2354331482026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=5.76480099999999931492026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531502026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531512026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531522026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531532026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531542026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531552026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531562026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531572026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531582026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531592026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531602026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531612026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=10.98449931852350831622026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=7.68914952296645531632026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=5.38240466607651831642026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531652026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531662026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531672026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531682026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531692026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531702026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531712026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531722026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531732026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531742026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531752026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531762026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531772026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531782026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531792026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531802026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531812026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531822026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531832026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531842026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531852026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531862026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531872026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531882026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531892026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531902026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531912026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531922026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531932026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531942026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531952026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531962026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531972026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531982026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=531992026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532002026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532012026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532022026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532032026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532042026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532052026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532062026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532072026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532082026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532092026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532102026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532112026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=12.0829492503758632122026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=8.45806447526310232132026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=5.92064513268417132142026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532152026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532162026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532172026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532182026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532192026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532202026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532212026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532222026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532232026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532242026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532252026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=7.50256083500000332262026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=8.45806447526310232272026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=5.92064513268417132282026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532292026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532302026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532312026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532322026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532332026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532342026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532352026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532362026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532372026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532382026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532392026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=532402026/10/25 19:19:23 WARN Rate limiter backed off name=test rate=53241--- PASS: TestAdaptiveRateLimiter_ThreadSafety (0.07s)3242PASS