niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #431
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure18=== PAUSE TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure19=== RUN TestUploadMultipart_PartsInParallel20=== PAUSE TestUploadMultipart_PartsInParallel21=== RUN TestUploadMultipart_FailedPartBufferNotReused22=== PAUSE TestUploadMultipart_FailedPartBufferNotReused23=== RUN TestUploadMultipart_ProducerErrorIsNotEOF24=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestUploadMultipart_SupersededByPeer28=== PAUSE TestUploadMultipart_SupersededByPeer29=== RUN TestDumpPathCaseHackMatchesNix30--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)31=== RUN TestDumpPathCaseHackCollision32--- PASS: TestDumpPathCaseHackCollision (0.00s)33=== RUN TestSupersededNARStillUploadsListing34=== PAUSE TestSupersededNARStillUploadsListing35=== RUN TestTruncatedNARDumpIsNotCompleted36=== PAUSE TestTruncatedNARDumpIsNotCompleted37=== RUN TestDumpPathMatchesNix38=== PAUSE TestDumpPathMatchesNix39=== RUN TestDumpPathSingleFile40=== PAUSE TestDumpPathSingleFile41=== RUN TestDumpPathWriterError42=== PAUSE TestDumpPathWriterError43=== RUN TestDumpPathWriterErrorStopsReading44 nar_test.go:289: read 114 of 32768000 bytes45--- PASS: TestDumpPathWriterErrorStopsReading (0.63s)46=== RUN TestEncodeNixBase3247=== PAUSE TestEncodeNixBase3248=== RUN TestEncodeNixBase32WithRealHash49=== PAUSE TestEncodeNixBase32WithRealHash50=== RUN TestConvertHashToNix3251=== PAUSE TestConvertHashToNix3252=== RUN TestGetStorePathHash53=== PAUSE TestGetStorePathHash54=== RUN TestPathInfoHashCompatibility55=== PAUSE TestPathInfoHashCompatibility56=== RUN TestParsePathInfoJSON57=== PAUSE TestParsePathInfoJSON58=== RUN TestParsePathInfoJSONMultiplePaths59=== PAUSE TestParsePathInfoJSONMultiplePaths60=== RUN TestPathInfoCACompatibility61=== PAUSE TestPathInfoCACompatibility62=== RUN TestUploadPendingObjectsStopsStartingAfterFailure63--- PASS: TestUploadPendingObjectsStopsStartingAfterFailure (0.02s)64=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent65=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent66=== RUN TestCompletePendingClosure_NotFoundWithoutKey67=== PAUSE TestCompletePendingClosure_NotFoundWithoutKey68=== RUN TestRateLimiterFeedback69=== PAUSE TestRateLimiterFeedback70=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess71=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess72=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer73=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer74=== RUN TestResolveStorePath75=== PAUSE TestResolveStorePath76=== RUN TestDoWithRetry_BodyReplayedViaGetBody77=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody78=== RUN TestRetryTimeoutOutlastsMaxRetries79=== PAUSE TestRetryTimeoutOutlastsMaxRetries80=== RUN TestDoWithRetry_FinalResponseBodyReadable81=== PAUSE TestDoWithRetry_FinalResponseBodyReadable82=== RUN TestShellSplit83=== PAUSE TestShellSplit84=== RUN TestShellSplitErrors85=== PAUSE TestShellSplitErrors86=== RUN TestStreamPushReportsEveryPath87=== PAUSE TestStreamPushReportsEveryPath88=== RUN TestStreamPushBatchesUnderLoad89=== PAUSE TestStreamPushBatchesUnderLoad90=== RUN TestStreamPushIsolatesFailures91=== PAUSE TestStreamPushIsolatesFailures92=== RUN TestStreamPushGivesUpOnDeadServer93=== PAUSE TestStreamPushGivesUpOnDeadServer94=== RUN TestStreamPushRequestLine95=== PAUSE TestStreamPushRequestLine96=== RUN TestStreamPushReportsSignatures97=== PAUSE TestStreamPushReportsSignatures98=== RUN TestStreamPushReportsSkippedPaths99=== PAUSE TestStreamPushReportsSkippedPaths100=== RUN TestClientSignaturesByStorePath101=== PAUSE TestClientSignaturesByStorePath102=== RUN TestStreamPushStopsWhenCanceled103=== PAUSE TestStreamPushStopsWhenCanceled104=== RUN TestStreamPushStopsOnCancel105=== PAUSE TestStreamPushStopsOnCancel106=== RUN 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 TestDoServerRequestAttachesToken135=== CONT TestStaticToken136=== CONT TestEncodeNixBase32WithRealHash137=== CONT TestScriptTokenCachesUntilRefresh138--- PASS: TestEncodeNixBase32WithRealHash (0.00s)139=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer140=== CONT TestUploadMultipart_ProducerErrorIsNotEOF141=== CONT TestPartSizeForNAR142=== CONT TestStreamPushStopsOnCancel143=== RUN TestPartSizeForNAR/zero_stays_at_minimum144=== RUN TestStreamPushStopsOnCancel/waiting_for_input145=== CONT TestSetClientTLS146=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum147=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input148=== CONT TestParsePathInfoJSON149=== CONT TestClientSignaturesByStorePath150=== CONT TestDumpPathSingleFile151=== CONT TestStreamPushReportsSignatures152=== CONT TestStreamPushRequestLine153=== CONT TestGetStorePathHash154=== CONT TestDumpPathMatchesNix155=== CONT TestStreamPushGivesUpOnDeadServer156=== CONT TestEncodeNixBase32157=== CONT TestStreamPushBatchesUnderLoad158=== CONT TestShellSplitErrors159=== CONT TestDoWithRetry_FinalResponseBodyReadable160=== CONT TestScriptTokenEmptyToken161=== CONT TestUploadMultipart_PartsInParallel162=== CONT TestSetClientTLSErrors163=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent164=== CONT TestScriptTokenNoExpiryRerunsEveryCall165--- PASS: TestStaticToken (0.00s)166=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part167=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part168=== RUN TestPartSizeForNAR/small_stays_at_minimum169--- PASS: TestClientSignaturesByStorePath (0.00s)170--- PASS: TestDoServerRequestAttachesToken (0.00s)171=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary172=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary173=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot174=== RUN TestParsePathInfoJSON/Nix_format175=== CONT TestResolveStorePath176=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot177=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot178=== CONT TestSetClientTLSDoesNotMutateDefaultTransport179=== RUN TestGetStorePathHash/valid_store_path180=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier181=== PAUSE TestParsePathInfoJSON/Nix_format182=== CONT TestRateLimiterFeedback183=== CONT TestParsePathInfoJSONMultiplePaths184=== RUN TestEncodeNixBase32/test_string_hash185=== RUN TestStreamPushBatchesUnderLoad/together186=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot187--- PASS: TestShellSplitErrors (0.00s)188=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier189=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot190=== RUN TestRateLimiterFeedback/429_enables_limiter191=== RUN TestParsePathInfoJSON/Lix_format192=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths193=== CONT TestShellSplit194=== PAUSE TestEncodeNixBase32/test_string_hash195=== PAUSE TestStreamPushBatchesUnderLoad/together196--- PASS: TestResolveStorePath (0.00s)197=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up198=== PAUSE TestPartSizeForNAR/small_stays_at_minimum199--- PASS: TestShellSplit (0.00s)200=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot201=== PAUSE TestParsePathInfoJSON/Lix_format202=== PAUSE TestRateLimiterFeedback/429_enables_limiter203=== PAUSE TestGetStorePathHash/valid_store_path204=== RUN TestEncodeNixBase32/empty_input205=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot206=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths207=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time208=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up209=== CONT TestDumpPathWriterError210=== PAUSE TestEncodeNixBase32/empty_input211=== CONT TestUploadMultipart_SupersededByPeer212=== RUN TestUploadMultipart_SupersededByPeer/exists213=== RUN TestParsePathInfoJSON/empty_input214=== RUN TestGetStorePathHash/basename_without_hyphen_should_error215=== CONT TestStreamPushReportsSkippedPaths216=== CONT TestSupersededNARStillUploadsListing217=== PAUSE TestParsePathInfoJSON/empty_input218=== RUN TestParsePathInfoJSON/whitespace_only219--- PASS: TestScriptTokenEmptyToken (0.01s)220=== RUN TestSetClientTLSErrors/missing_cert_file221=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths222=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot223=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier224=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time225=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum226=== CONT TestTruncatedNARDumpIsNotCompleted227=== CONT TestStreamPushReportsEveryPath228=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum229=== RUN TestRateLimiterFeedback/503_enables_limiter230=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts231=== PAUSE TestRateLimiterFeedback/503_enables_limiter232=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts233=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error234=== RUN TestSupersededNARStillUploadsListing/small_NAR235=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error236=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error237=== CONT TestPathInfoHashCompatibility238=== CONT TestStreamPushStopsWhenCanceled239=== PAUSE TestParsePathInfoJSON/whitespace_only240--- PASS: TestStreamPushReportsSkippedPaths (0.00s)241=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun242=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure243=== PAUSE TestSetClientTLSErrors/missing_cert_file244=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths245=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken246=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier247=== PAUSE TestUploadMultipart_SupersededByPeer/exists248=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter249=== RUN TestPartSizeForNAR/1_TiB250=== PAUSE TestSupersededNARStillUploadsListing/small_NAR251=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica252=== RUN TestParsePathInfoJSON/invalid_JSON253--- PASS: TestStreamPushReportsSignatures (0.01s)254=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error255=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)256=== RUN TestSetClientTLSErrors/missing_key_file257=== CONT TestConvertHashToNix32258=== RUN TestConvertHashToNix32/SRI_format_to_Nix32259=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken260=== RUN TestUploadMultipart_SupersededByPeer/missing261=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client262=== CONT TestFileTokenReadsAndCaches263=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter264=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter265=== PAUSE TestPartSizeForNAR/1_TiB266=== CONT TestCaseHackSuffix267=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter268--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)269--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)270=== PAUSE TestParsePathInfoJSON/invalid_JSON271=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error272=== PAUSE TestSetClientTLSErrors/missing_key_file273=== CONT TestFilterOversizedClosures274=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)275=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32276=== PAUSE TestUploadMultipart_SupersededByPeer/missing277=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon278=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon279=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client280=== RUN TestSupersededNARStillUploadsListing/dump_cut_short281=== RUN TestPartSizeForNAR/5_TiB_S3_max_object282=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object283=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI284=== CONT TestUploadMultipart_FailedPartBufferNotReused285=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client286=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client287=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short288--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)289--- PASS: TestStreamPushReportsEveryPath (0.01s)290=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI291=== CONT TestScriptTokenDoesNotWaitForItsChildren292=== RUN TestSetClientTLSErrors/missing_ca_file293=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs294=== PAUSE TestSetClientTLSErrors/missing_ca_file295=== RUN TestSetClientTLSErrors/invalid_ca_file296=== RUN TestConvertHashToNix32/already_Nix32_format297=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry298=== CONT TestRetryTimeoutOutlastsMaxRetries299=== RUN TestPartSizeForNAR/capped_at_5_GiB300=== CONT TestRegisterUploadedObjectReusesConnections301=== CONT TestFileTokenMissing302=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails303=== CONT TestDoWithRetry_BodyReplayedViaGetBody304=== CONT TestFileTokenEmpty305=== CONT TestCompletePendingClosure_NotFoundWithoutKey306=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails307=== CONT TestScriptTokenScriptFails308=== CONT TestScriptTokenEmptyCommand309=== CONT TestPathInfoCACompatibility310=== RUN TestPathInfoCACompatibility/null_ca_field311=== PAUSE TestPathInfoCACompatibility/null_ca_field312=== RUN TestPathInfoCACompatibility/old_string_format_-_text313=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text314=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive315=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive316=== RUN TestPathInfoCACompatibility/new_structured_format_-_text317=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text318=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method319=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method320=== CONT TestScriptTokenBadJSON321=== RUN TestSetClientTLS/rejects_connection_without_client_cert322--- PASS: TestStreamPushStopsWhenCanceled (0.01s)323=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512324=== RUN TestFilterOversizedClosures/no_limit_keeps_everything325=== PAUSE TestSetClientTLSErrors/invalid_ca_file326=== PAUSE TestConvertHashToNix32/already_Nix32_format327=== PAUSE TestPartSizeForNAR/capped_at_5_GiB328=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs329=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess330=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512331=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything332=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped333=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout334=== CONT TestStreamPushIsolatesFailures335=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part336=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout337--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.26s)338--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.26s)339=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert340=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped341=== RUN TestFilterOversizedClosures/all_closures_skipped342=== PAUSE TestFilterOversizedClosures/all_closures_skipped343=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary344=== CONT TestEncodeNixBase32/empty_input345=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths346=== RUN TestConvertHashToNix32/invalid_format347=== PAUSE TestConvertHashToNix32/invalid_format348=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time349=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA350--- PASS: TestDumpPathSingleFile (0.26s)351=== CONT TestEncodeNixBase32/test_string_hash352=== CONT TestStreamPushBatchesUnderLoad/together353=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths354=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA355=== RUN TestSetClientTLS/preserves_debug_logging_transport356=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken357=== CONT TestStreamPushStopsOnCancel/waiting_for_input358--- PASS: TestFileTokenReadsAndCaches (0.00s)359=== PAUSE TestSetClientTLS/preserves_debug_logging_transport360=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot361=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot362=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot363=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot364--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.25s)365=== CONT TestRateLimiterFeedback/429_enables_limiter366--- PASS: TestFileTokenMissing (0.00s)367--- PASS: TestFileTokenEmpty (0.00s)368--- PASS: TestScriptTokenEmptyCommand (0.00s)369--- PASS: TestScriptTokenScriptFails (0.00s)370--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)371--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.01s)372--- PASS: TestStreamPushIsolatesFailures (0.17s)373=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter374--- PASS: TestCaseHackSuffix (0.18s)375--- PASS: TestParsePathInfoJSONMultiplePaths (0.02s)376 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)377 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)378--- PASS: TestEncodeNixBase32 (0.01s)379 --- PASS: TestEncodeNixBase32/empty_input (0.00s)380 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)381=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter382--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.18s)383--- PASS: TestStreamPushBatchesUnderLoad (0.01s)384 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)385 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)386--- PASS: TestScriptTokenBadJSON (0.17s)387=== CONT TestRateLimiterFeedback/503_enables_limiter388=== CONT TestParsePathInfoJSON/whitespace_only389=== CONT TestParsePathInfoJSON/invalid_JSON390=== CONT TestParsePathInfoJSON/empty_input391=== CONT TestParsePathInfoJSON/Lix_format392=== CONT TestParsePathInfoJSON/Nix_format393=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error394=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error395--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.18s)396=== CONT TestGetStorePathHash/valid_store_path397=== CONT TestUploadMultipart_SupersededByPeer/exists398=== CONT TestGetStorePathHash/basename_without_hyphen_should_error399--- PASS: TestParsePathInfoJSON (0.26s)400 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)401 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)402 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)403 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)404 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)405=== CONT TestUploadMultipart_SupersededByPeer/missing406=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier407=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client408--- PASS: TestRateLimiterFeedback (0.26s)409 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)410 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)411 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)412 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)413--- PASS: TestGetStorePathHash (0.26s)414 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)415 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)416 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)417 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)418=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier419=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client420=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up421--- PASS: TestUploadMultipart_SupersededByPeer (0.25s)422 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)423 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)424=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails425=== CONT TestSupersededNARStillUploadsListing/dump_cut_short426=== CONT TestSupersededNARStillUploadsListing/small_NAR427=== CONT TestPathInfoCACompatibility/null_ca_field428=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method429=== CONT TestPathInfoCACompatibility/new_structured_format_-_text430--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.27s)431 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.00s)432 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.00s)433 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.00s)434 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.00s)435 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.00s)436=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive437=== CONT TestPartSizeForNAR/1_TiB438=== CONT TestSetClientTLSErrors/missing_key_file439=== CONT TestPartSizeForNAR/capped_at_5_GiB440=== CONT TestPartSizeForNAR/5_TiB_S3_max_object441=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts442=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum443=== CONT TestPartSizeForNAR/small_stays_at_minimum444=== CONT TestPartSizeForNAR/zero_stays_at_minimum445=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout446=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs447--- PASS: TestPartSizeForNAR (0.27s)448 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)449 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)450 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)451 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)452 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)453 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)454 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)455=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI456=== CONT TestPathInfoCACompatibility/old_string_format_-_text457=== CONT TestSetClientTLSErrors/missing_ca_file458--- PASS: TestPathInfoCACompatibility (0.00s)459 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)460 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)461 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)462 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)463 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)464=== CONT TestFilterOversizedClosures/no_limit_keeps_everything465=== CONT TestSetClientTLSErrors/invalid_ca_file466=== CONT TestSetClientTLSErrors/missing_cert_file467=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon468=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512469=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped470=== CONT TestConvertHashToNix32/already_Nix32_format471=== CONT TestFilterOversizedClosures/all_closures_skipped472=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)473=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA474=== CONT TestSetClientTLS/rejects_connection_without_client_cert475=== CONT TestSetClientTLS/preserves_debug_logging_transport476=== CONT TestConvertHashToNix32/invalid_format477=== CONT TestConvertHashToNix32/SRI_format_to_Nix32478--- PASS: TestPathInfoHashCompatibility (0.26s)479 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)480 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)481 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)482 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)483--- PASS: TestFilterOversizedClosures (0.01s)484 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)485 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)486 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)487--- PASS: TestSetClientTLSErrors (0.27s)488 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)489 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)490 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)491 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)492--- PASS: TestStreamPushStopsOnCancel (0.26s)493 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.28s)494 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.28s)495 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.28s)496 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.28s)497 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.28s)498 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.28s)499--- PASS: TestConvertHashToNix32 (0.18s)500 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)501 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)502 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)503--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.71s)504--- PASS: TestDumpPathWriterError (0.75s)505--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.49s)506--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.00s)507 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.49s)508 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.49s)509--- PASS: TestSetClientTLS (0.44s)510 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.03s)511 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.04s)512 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.09s)513--- PASS: TestRegisterUploadedObjectReusesConnections (0.58s)514--- PASS: TestDumpPathMatchesNix (0.85s)515--- PASS: TestStreamPushRequestLine (0.90s)516--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)517--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)518--- PASS: TestUploadMultipart_PartsInParallel (1.41s)519--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.24s)520--- PASS: TestTruncatedNARDumpIsNotCompleted (1.50s)521--- PASS: TestSupersededNARStillUploadsListing (0.26s)522 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.27s)523 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.27s)524 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.07s)525--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.01s)526 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.00s)527 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.26s)528PASS529Running server tests...530The files belonging to this database system will be owned by user "nixbld".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 /build/postgres159104066/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 /build/postgres159104066/data -l logfile start556557/build/postgres159104066:5432 - no response5582026-10-25 17:21:01.414 UTC [168] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5592026-10-25 17:21:01.414 UTC [168] LOG: listening on Unix socket "/build/postgres159104066/.s.PGSQL.5432"5602026-10-25 17:21:01.419 UTC [175] LOG: database system was shut down at 2026-10-25 17:21:01 UTC5612026-10-25 17:21:01.423 UTC [168] LOG: database system is ready to accept connections562/build/postgres159104066:5432 - accepting connections563{"timestamp":"2026-10-25T17:21:01.618475347Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"550c65f9-0600-40fa-8fe0-a5d84f9f8d19","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(206)"}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 17:21:01 INFO lead: acquired remote=192.0.2.1:12346142026/10/25 17:21:02 INFO lead: released remote=192.0.2.1:12346152026/10/25 17:21:02 INFO lead: acquired remote=192.0.2.1:12346162026/10/25 17:21:03 INFO lead: released remote=192.0.2.1:1234617--- PASS: TestLeadIncumbentWinsAfterRestart (1.93s)618=== RUN TestLeadIncumbentAnnouncesAtOnce619=== PAUSE TestLeadIncumbentAnnouncesAtOnce620=== RUN TestLeadEndsOnShutdown621=== PAUSE TestLeadEndsOnShutdown622=== RUN TestLeadEndsWhenItsConnectionHangs6232026/10/25 17:21:03 INFO lead: acquired remote=192.0.2.1:12346242026-10-25 17:21:05.194 UTC [425] FATAL: terminating connection due to administrator command6252026/10/25 17:21:05 INFO lead: acquired remote=192.0.2.1:12346262026/10/25 17:21:06 WARN lead: lock connection lost error="timeout: context deadline exceeded"6272026/10/25 17:21:06 INFO lead: released remote=192.0.2.1:12346282026/10/25 17:21:06 INFO lead: released remote=192.0.2.1:1234629--- PASS: TestLeadEndsWhenItsConnectionHangs (3.16s)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 17:21:06 INFO Starting HTTP server address=127.0.0.1:434157442026/10/25 17:21:06 INFO Starting HTTP server address=proxy.sock7452026/10/25 17:21:06 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7462026/10/25 17:21:06 INFO Shutdown signal received, draining in-flight requests timeout=10s747--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.14s)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 17:21:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8162026/10/25 17:21:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8172026/10/25 17:21:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8182026/10/25 17:21:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8192026/10/25 17:21:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8202026/10/25 17:21:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8212026/10/25 17:21:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8222026/10/25 17:21:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8232026/10/25 17:21:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8242026/10/25 17:21:07 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 TestSkippedUploadsHandler849=== CONT TestUploadHandlersRejectOversizedBody850=== CONT TestCompleteMultipartUpload_ErrorButObjectExists851=== CONT TestService_AuthMiddleware852=== CONT TestParseSize853=== CONT TestConcurrentPinUpdatesAgree854--- PASS: TestParseSize (0.00s)855=== CONT TestReadRedirectNar856=== CONT TestReadProxyDisabled857=== CONT TestOrphanedObjectsGCStressTest858=== CONT TestPendingClosureWriteTimeout859=== CONT TestCreatePin_ReservedPins860=== CONT TestOrphanedObjectsGC861=== CONT TestService_Rustfstest862=== CONT TestReadProxyRootRedirectsToIndexHTML863=== CONT TestReconnectLeavesObjectsUnlocked864=== CONT TestPendingClosureFailureAbortsItsUploads865=== CONT TestReadProxyHead866=== CONT TestPush_RootsAreLockedInByteOrder867=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT868=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit869=== CONT TestGCSweepSkipsPendingObjects870=== CONT TestReadProxyContentNegotiation871=== CONT TestCompleteMultipartUnregistered872=== CONT TestPresentReportsOnlyClosureRoots873=== CONT TestPush_CompleteCommitsEveryRoot874=== RUN TestPendingClosureWriteTimeout/empty875=== PAUSE TestPendingClosureWriteTimeout/empty876=== RUN TestPendingClosureWriteTimeout/400_objects877=== PAUSE TestPendingClosureWriteTimeout/400_objects878=== RUN TestPendingClosureWriteTimeout/670k_objects879=== PAUSE TestPendingClosureWriteTimeout/670k_objects880=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline881=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline882=== CONT TestService_createPendingClosureHandler8832026/10/25 17:21:07 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000884=== CONT TestClientWithDependencies885--- PASS: TestSkippedUploadsHandler (0.04s)8862026/10/25 17:21:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38565/oidc8872026/10/25 17:21:07 INFO Received create pin request method=POST path=/api/pins/app8882026/10/25 17:21:07 INFO Received uploads request method=POST path=/api/pending_closures8892026/10/25 17:21:07 INFO Received create pin request method=POST path=/api/pins/app8902026/10/25 17:21:07 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"891=== CONT TestService_NativeMTLS892--- PASS: TestService_AuthMiddleware (0.32s)8932026/10/25 17:21:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8942026/10/25 17:21:07 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LmVjYjI5NDM4LWVlYmEtNGE5Ni04NDk1LTI1N2U3YWE1ZDQyNXgxNzkyOTQ4ODY3NDczNTg0Mzk3895--- PASS: TestReconnectLeavesObjectsUnlocked (0.36s)896=== CONT TestConnectWaitsForAPeerMigration897--- PASS: TestReadRedirectNar (0.37s)898=== CONT TestPush_OverlappingRootsStoreOneRowPerKey899=== CONT TestDeletePinKeepsRowWhenS3Fails900--- PASS: TestReadProxyDisabled (0.37s)9012026/10/25 17:21:07 INFO Received push request method=POST path=/api/pushes9022026/10/25 17:21:07 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LmVjYjI5NDM4LWVlYmEtNGE5Ni04NDk1LTI1N2U3YWE1ZDQyNXgxNzkyOTQ4ODY3NDczNTg0Mzk3 error="Delete \"http://localhost:45219/bucket5/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LmVjYjI5NDM4LWVlYmEtNGE5Ni04NDk1LTI1N2U3YWE1ZDQyNXgxNzkyOTQ4ODY3NDczNTg0Mzk3\": injected: abort refused"9032026/10/25 17:21:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete904--- PASS: TestService_Rustfstest (0.42s)905=== CONT TestServerTLSConfig906=== RUN TestServerTLSConfig/no_client_CA907=== PAUSE TestServerTLSConfig/no_client_CA908=== RUN TestServerTLSConfig/missing_CA_file909=== PAUSE TestServerTLSConfig/missing_CA_file910=== RUN TestServerTLSConfig/not_a_PEM_file911=== PAUSE TestServerTLSConfig/not_a_PEM_file912=== CONT TestPush_RepeatedRootCommitsOnce9132026/10/25 17:21:07 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LmVjYjI5NDM4LWVlYmEtNGE5Ni04NDk1LTI1N2U3YWE1ZDQyNXgxNzkyOTQ4ODY3NDczNTg0Mzk39142026/10/25 17:21:07 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LmVjYjI5NDM4LWVlYmEtNGE5Ni04NDk1LTI1N2U3YWE1ZDQyNXgxNzkyOTQ4ODY3NDczNTg0Mzk3 parts=1915--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.46s)916=== CONT TestGenerateLandingPage917=== CONT TestCreatePendingClosureRejectsOversizedNAR918--- PASS: TestGenerateLandingPage (0.02s)9192026/10/25 17:21:07 INFO Received uploads request method=POST path=/api/pending_closures920--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)921=== CONT TestCacheStatsHandler922=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure923=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure924=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart925=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart926=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts927=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts928=== CONT TestCacheConfigHandlerMaxNarSize929=== CONT TestUploadHandlersRejectInvalidKeys930=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info931--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)932=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info933=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal934=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal935=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key936=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key937=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key938=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key939=== CONT TestIsValidUploadKey940=== RUN TestIsValidUploadKey/narinfo941=== PAUSE TestIsValidUploadKey/narinfo942=== RUN TestIsValidUploadKey/nar_zst943=== PAUSE TestIsValidUploadKey/nar_zst944=== RUN TestIsValidUploadKey/nar_xz945=== PAUSE TestIsValidUploadKey/nar_xz946=== RUN TestIsValidUploadKey/nar_plain947=== PAUSE TestIsValidUploadKey/nar_plain948=== RUN TestIsValidUploadKey/listing949=== PAUSE TestIsValidUploadKey/listing950=== RUN TestIsValidUploadKey/build_log951=== PAUSE TestIsValidUploadKey/build_log952=== RUN TestIsValidUploadKey/build_log_home-manager_file953=== PAUSE TestIsValidUploadKey/build_log_home-manager_file954=== RUN TestIsValidUploadKey/build_log_plus_in_name955=== PAUSE TestIsValidUploadKey/build_log_plus_in_name956=== RUN TestIsValidUploadKey/build_log_question_mark957=== PAUSE TestIsValidUploadKey/build_log_question_mark958=== RUN TestIsValidUploadKey/build_log_equals959=== PAUSE TestIsValidUploadKey/build_log_equals960=== RUN TestIsValidUploadKey/realisation961=== PAUSE TestIsValidUploadKey/realisation962=== RUN TestIsValidUploadKey/realisation_plus_in_output963=== PAUSE TestIsValidUploadKey/realisation_plus_in_output964=== RUN TestIsValidUploadKey/nix-cache-info965=== PAUSE TestIsValidUploadKey/nix-cache-info966=== RUN TestIsValidUploadKey/index.html967=== PAUSE TestIsValidUploadKey/index.html968=== RUN TestIsValidUploadKey/narinfo_key,_nar_type969=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type970=== RUN TestIsValidUploadKey/nar_key,_narinfo_type971=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type972=== RUN TestIsValidUploadKey/listing_key,_narinfo_type973=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type974=== RUN TestIsValidUploadKey/traversal975=== PAUSE TestIsValidUploadKey/traversal976=== RUN TestIsValidUploadKey/traversal_nar977=== PAUSE TestIsValidUploadKey/traversal_nar978=== RUN TestIsValidUploadKey/absolute979=== PAUSE TestIsValidUploadKey/absolute980=== RUN TestIsValidUploadKey/empty_key981=== PAUSE TestIsValidUploadKey/empty_key982=== RUN TestIsValidUploadKey/unknown_type983=== PAUSE TestIsValidUploadKey/unknown_type984=== CONT TestPinProtectsFromGC9852026/10/25 17:21:07 INFO Received uploads request method=POST path=/api/pending_closures9862026/10/25 17:21:07 INFO Aborted multipart uploads count=0 kept=09872026/10/25 17:21:07 WARN Force mode enabled - objects will be deleted immediately without grace period9882026/10/25 17:21:07 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=09892026/10/25 17:21:07 INFO Vacuumed table table=pending_closures9902026/10/25 17:21:07 INFO Received uploads request method=POST path=/api/pending_closures9912026/10/25 17:21:07 INFO Vacuumed table table=pending_objects9922026/10/25 17:21:07 INFO Vacuumed table table=multipart_uploads9932026/10/25 17:21:07 INFO Vacuumed table table=closures9942026/10/25 17:21:07 INFO Vacuumed table table=objects9952026/10/25 17:21:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9962026/10/25 17:21:07 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst997=== CONT TestMetricsCommit998--- PASS: TestReadProxyHead (0.56s)999--- PASS: TestGCSweepSkipsPendingObjects (0.56s)1000=== CONT TestFailedS3DeleteKeepsTombstone1001=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1002--- PASS: TestCompleteMultipartUnregistered (0.57s)1003--- PASS: TestPendingClosureFailureAbortsItsUploads (0.58s)1004=== CONT TestGCTaskStore_ConflictDifferentParams1005=== CONT TestPendingClosureFailureTracksEveryUpload1006=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1007--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1008=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1009=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1010=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1011=== CONT TestPush_CompleteWaitsForCleanupOfThePush1012=== NAME TestClientWithDependencies1013 client_integration_test.go:735: Built derivation: /build/TestClientWithDependencies1086663573/001/store/xpzyn9lhjlqmxb1d7wvsm082gyia1cm2-test-script1014--- PASS: TestPresentReportsOnlyClosureRoots (0.60s)1015=== CONT TestClientSharedPathCommittedMidPush10162026/10/25 17:21:07 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10172026/10/25 17:21:07 WARN Refused reserved pin name=worker-x86_64-linux10182026/10/25 17:21:07 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10192026/10/25 17:21:07 INFO Received create pin request method=POST path=/api/pins/my-app10202026/10/25 17:21:07 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1021--- PASS: TestCreatePin_ReservedPins (0.64s)1022=== CONT TestCreatePinRejectsBadInput1023=== NAME TestClientWithDependencies1024 client_integration_test.go:737: Found 1 dependencies (including self)10252026/10/25 17:21:07 INFO Received push request method=POST path=/api/pushes1026=== CONT TestPresignedUploadRegisteredBeforeCommit1027--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.65s)10282026/10/25 17:21:07 INFO Received push request method=POST path=/api/pushes10292026/10/25 17:21:07 INFO Received uploads request method=POST path=/api/pending_closures10302026/10/25 17:21:07 INFO Received uploads request method=POST path=/api/pending_closures10312026/10/25 17:21:07 INFO Received uploads request method=POST path=/api/pending_closures10322026/10/25 17:21:07 INFO Received push request method=POST path=/api/pushes10332026/10/25 17:21:07 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10342026/10/25 17:21:07 INFO Uploading xpzyn9lhjlqmxb1d7wvsm082gyia1cm2-test-script (136B)10352026/10/25 17:21:07 INFO Received uploads request method=POST path=/api/pending_closures10362026/10/25 17:21:07 WARN Failed to register uploaded object key=log/f3qv62fd64pa8dm70cgwlgbmpxgqc3gd-test-script.drv error="server returned 404: 404 page not found\n"10372026/10/25 17:21:07 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10382026/10/25 17:21:07 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10392026/10/25 17:21:07 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"10402026/10/25 17:21:07 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10412026/10/25 17:21:07 WARN Failed to register uploaded object key=xpzyn9lhjlqmxb1d7wvsm082gyia1cm2.ls error="server returned 404: 404 page not found\n"10422026/10/25 17:21:07 INFO Signed narinfos id=1 count=110432026/10/25 17:21:07 INFO Uploading 1 narinfos10442026/10/25 17:21:07 INFO Received complete push request method=POST path=/api/pushes/1/complete10452026/10/25 17:21:07 WARN Failed to register uploaded object key=xpzyn9lhjlqmxb1d7wvsm082gyia1cm2.narinfo error="server returned 404: 404 page not found\n"10462026/10/25 17:21:07 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo10472026/10/25 17:21:07 INFO Received push request method=POST path=/api/pushes1048--- PASS: TestService_NativeMTLS (0.47s)1049=== CONT TestCompletedNarNotReofferedAcrossClosures10502026/10/25 17:21:07 INFO Completed push id=1 objects=4 duration=6.320738ms10512026/10/25 17:21:07 INFO Upload complete. (111ms)1052--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.79s)1053=== CONT TestReadRedirectUsesPublicS3URL10542026/10/25 17:21:07 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo10552026/10/25 17:21:07 INFO Aborted multipart uploads count=0 kept=010562026/10/25 17:21:08 INFO Received create pin request method=POST path=/api/pins/app10572026/10/25 17:21:08 WARN Force mode enabled - objects will be deleted immediately without grace period10582026/10/25 17:21:08 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=01059=== CONT TestRedundantMultipartUpload1060--- PASS: TestConcurrentPinUpdatesAgree (0.82s)10612026/10/25 17:21:08 INFO Vacuumed table table=pending_closures10622026/10/25 17:21:08 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo10632026/10/25 17:21:08 INFO Received delete pin request method=DELETE path=/api/pins/app10642026/10/25 17:21:08 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket29/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"10652026/10/25 17:21:08 INFO Vacuumed table table=pending_objects10662026/10/25 17:21:08 INFO Vacuumed table table=multipart_uploads10672026/10/25 17:21:08 INFO Received delete pin request method=DELETE path=/api/pins/app10682026/10/25 17:21:08 INFO Vacuumed table table=closures10692026/10/25 17:21:08 INFO Vacuumed table table=objects1070=== NAME TestClientWithDependencies1071 client_integration_test.go:753: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1086663573/001/store) requires matching store prefix10722026/10/25 17:21:08 INFO Received push request method=POST path=/api/pushes10732026/10/25 17:21:08 INFO Deleted pin name=app1074--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.47s)1075=== CONT TestPush_SignsNarinfosOfItsPendingObjects1076--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.48s)1077=== CONT TestObjectStatsTrigger1078--- PASS: TestClientWithDependencies (0.82s)1079=== CONT TestPush_RejectsBadRequests1080--- PASS: TestReadProxyContentNegotiation (0.87s)1081=== CONT TestObjectStatsUpdatedOncePerCommit1082=== CONT TestReadProxyConditionalGet1083--- PASS: TestCacheStatsHandler (0.42s)10842026/10/25 17:21:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10852026/10/25 17:21:08 INFO Received uploads request method=POST path=/api/pending_closures10862026/10/25 17:21:08 INFO Received push request method=POST path=/api/pushes10872026/10/25 17:21:08 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LjE0OWIxNWUzLTc5MjUtNDc2Mi05MzkwLWJlN2IzMWQ0Y2Y1MngxNzkyOTQ4ODY3NTgxOTYwNTcw parts=1010882026/10/25 17:21:08 INFO Received push request method=POST path=/api/pushes1089=== NAME TestPinProtectsFromGC1090 client_integration_test.go:867: Pinned store path: /build/TestPinProtectsFromGC3592547463/001/store/xw70pqb6fngg93ngk9zv4438csvh1f6m-pinned-file.txt1091 client_integration_test.go:868: Unpinned store path: /build/TestPinProtectsFromGC3592547463/001/store/w85fz02nq3c67rgvpiyg8pcfdf792hw1-unpinned-file.txt10922026/10/25 17:21:08 INFO Received uploads request method=POST path=/api/pending_closures10932026/10/25 17:21:08 INFO Aborted multipart uploads count=0 kept=010942026/10/25 17:21:08 INFO Received create pin request method=POST path=/api/pins/deploy10952026/10/25 17:21:08 WARN Force mode enabled - objects will be deleted immediately without grace period10962026/10/25 17:21:08 INFO Received create pin request method=POST path=/api/pins/deploy10972026/10/25 17:21:08 INFO Received create pin request method=POST path=/api/pins/deploy10982026/10/25 17:21:08 INFO Received create pin request method=POST path=/api/pins/deploy10992026/10/25 17:21:08 INFO Received create pin request method=POST path=/api/pins/deploy11002026/10/25 17:21:08 INFO Received create pin request method=POST path=/api/pins/deploy11012026/10/25 17:21:08 INFO Received create pin request method=POST path=/api/pins/deploy11022026/10/25 17:21:08 INFO Received create pin request method=POST path=/api/pins/deploy11032026/10/25 17:21:08 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11042026/10/25 17:21:08 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."11052026/10/25 17:21:08 INFO Received uploads request method=POST path=/api/pending_closures11062026/10/25 17:21:08 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11072026/10/25 17:21:08 INFO Received uploads request method=POST path=/api/pending_closures1108--- PASS: TestFailedS3DeleteKeepsTombstone (0.51s)1109=== CONT TestReadProxyInvalidPath11102026/10/25 17:21:08 INFO Received create pin request method=POST path=/api/pins/deploy11112026/10/25 17:21:08 INFO Received push request method=POST path=/api/pushes11122026/10/25 17:21:08 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11132026/10/25 17:21:08 INFO Uploading xw70pqb6fngg93ngk9zv4438csvh1f6m-pinned-file.txt (128B)1114=== NAME TestOrphanedObjectsGC1115 orphaned_objects_gc_test.go:287: GC Test Summary:1116 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1117 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1118 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1119 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1120 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects11212026/10/25 17:21:08 WARN Failed to register uploaded object key=xw70pqb6fngg93ngk9zv4438csvh1f6m.ls error="server returned 404: 404 page not found\n"11222026/10/25 17:21:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11232026/10/25 17:21:08 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"11242026/10/25 17:21:08 INFO Signed narinfos id=1 count=111252026/10/25 17:21:08 INFO Uploading 1 narinfos1126--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.49s)1127=== CONT TestReadProxyOutlastsServerWriteTimeout1128--- PASS: TestOrphanedObjectsGC (1.14s)1129=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded11302026/10/25 17:21:08 INFO Received complete push request method=POST path=/api/pushes/1/complete11312026/10/25 17:21:08 WARN Failed to register uploaded object key=xw70pqb6fngg93ngk9zv4438csvh1f6m.narinfo error="server returned 404: 404 page not found\n"11322026/10/25 17:21:08 INFO Completed push id=1 objects=3 duration=7.275467ms11332026/10/25 17:21:08 INFO Upload complete. (127ms)11342026/10/25 17:21:08 INFO Received uploads request method=POST path=/api/pending_closures11352026/10/25 17:21:08 INFO Received uploads request method=POST path=/api/pending_closures11362026/10/25 17:21:08 INFO Received uploads request method=POST path=/api/pending_closures11372026/10/25 17:21:08 INFO Received push request method=POST path=/api/pushes11382026/10/25 17:21:08 INFO Received push request method=POST path=/api/pushes11392026/10/25 17:21:08 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11402026/10/25 17:21:08 INFO Uploading w85fz02nq3c67rgvpiyg8pcfdf792hw1-unpinned-file.txt (128B)11412026/10/25 17:21:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1142--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.66s)1143=== CONT TestReadProxyNarStreaming11442026/10/25 17:21:08 INFO Signed narinfos id=1 count=111452026/10/25 17:21:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11462026/10/25 17:21:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11472026/10/25 17:21:08 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"11482026/10/25 17:21:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11492026/10/25 17:21:08 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"11502026/10/25 17:21:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11512026/10/25 17:21:08 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=111522026/10/25 17:21:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11532026/10/25 17:21:08 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"11542026/10/25 17:21:08 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11552026/10/25 17:21:08 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo11562026/10/25 17:21:08 WARN Failed to register uploaded object key=w85fz02nq3c67rgvpiyg8pcfdf792hw1.ls error="server returned 404: 404 page not found\n"11572026/10/25 17:21:08 INFO Signed narinfos id=2 count=111582026/10/25 17:21:08 INFO Uploading 1 narinfos11592026/10/25 17:21:08 INFO Received push request method=POST path=/api/pushes11602026/10/25 17:21:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11612026/10/25 17:21:08 INFO Received complete push request method=POST path=/api/pushes/2/complete11622026/10/25 17:21:08 WARN Failed to register uploaded object key=w85fz02nq3c67rgvpiyg8pcfdf792hw1.narinfo error="server returned 404: 404 page not found\n"11632026/10/25 17:21:08 INFO Completed push id=2 objects=3 duration=2.435902ms11642026/10/25 17:21:08 INFO Upload complete. (71ms)11652026/10/25 17:21:08 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)11662026/10/25 17:21:08 INFO Uploading ghkn6nkp4yg2viw29qs4j2f8648bjz5c-top (224B)11672026/10/25 17:21:08 INFO Uploading ljh1fm8j6wx9lpcpnpyq0d1dxi9qp2df-shared-dep (136B)1168--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.42s)1169=== CONT TestTombstonedObjectOfferedWithoutWaiting11702026/10/25 17:21:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11712026/10/25 17:21:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1172=== RUN TestPush_RejectsBadRequests/no_objects1173=== PAUSE TestPush_RejectsBadRequests/no_objects1174=== RUN TestPush_RejectsBadRequests/bad_root1175=== PAUSE TestPush_RejectsBadRequests/bad_root1176=== RUN TestPush_RejectsBadRequests/root_not_in_objects1177=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1178=== RUN TestPush_RejectsBadRequests/no_roots1179=== PAUSE TestPush_RejectsBadRequests/no_roots1180=== CONT TestPushDedupSurvivesConcurrentGC11812026/10/25 17:21:08 WARN Failed to register uploaded object key=nar/0xryz6cs7yhcvvkv51lhx47n8d2nd73j5l0whpbfkyfjw3mzkgbj.nar.zst error="server returned 404: 404 page not found\n"11822026/10/25 17:21:08 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11832026/10/25 17:21:08 WARN Failed to register uploaded object key=ghkn6nkp4yg2viw29qs4j2f8648bjz5c.ls error="server returned 404: 404 page not found\n"11842026/10/25 17:21:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11852026/10/25 17:21:08 WARN Failed to register uploaded object key=ljh1fm8j6wx9lpcpnpyq0d1dxi9qp2df.ls error="server returned 404: 404 page not found\n"11862026/10/25 17:21:08 INFO Signed narinfos id=1 count=21187=== CONT TestReadProxy4041188--- PASS: TestObjectStatsTrigger (0.42s)11892026/10/25 17:21:08 INFO Uploading 2 narinfos11902026/10/25 17:21:08 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LjI3YWYyOGI0LTJlZDQtNGI4NC1iNzE4LTAzOWY4MWUyOTM2ZngxNzkyOTQ4ODY3ODcwMTAxODY4 parts=1011912026/10/25 17:21:08 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LmY1NDkyNjQ1LTFkYTgtNDUyZC05MGU2LTFhNDY4ZTY5NmU5MXgxNzkyOTQ4ODY3ODUwNDIyMjA4 parts=1011922026/10/25 17:21:08 INFO Received complete push request method=POST path=/api/pushes/1/complete11932026/10/25 17:21:08 WARN Failed to register uploaded object key=ljh1fm8j6wx9lpcpnpyq0d1dxi9qp2df.narinfo error="server returned 404: 404 page not found\n"11942026/10/25 17:21:08 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LmQ0YzM4ZWE1LTI2MGQtNDkwZS05ZmUwLWFmNmVlNWM3NDdhZHgxNzkyOTQ4ODY3ODk0MzcyNzUw parts=1011952026/10/25 17:21:08 WARN Failed to register uploaded object key=ghkn6nkp4yg2viw29qs4j2f8648bjz5c.narinfo error="server returned 404: 404 page not found\n"11962026/10/25 17:21:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11972026/10/25 17:21:08 INFO Starting cleanup of old closures method=DELETE path=/api/closures11982026/10/25 17:21:08 INFO Completed upload id=1 objects=2 duration=4.220559ms11992026/10/25 17:21:08 INFO Garbage collection started12002026/10/25 17:21:08 INFO Completed push id=1 objects=6 duration=6.59874ms12012026/10/25 17:21:08 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012022026/10/25 17:21:08 INFO Upload complete. (96ms)12032026/10/25 17:21:08 INFO Received uploads request method=POST path=/api/pending_closures1204=== NAME TestClientSharedPathCommittedMidPush1205 client_integration_test.go:816: Retrieved narinfo from S3:1206 StorePath: /build/TestClientSharedPathCommittedMidPush614708936/001/store/ljh1fm8j6wx9lpcpnpyq0d1dxi9qp2df-shared-dep1207 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1208 Compression: zstd1209 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821210 NarSize: 1361211 References: 1212 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n12132026/10/25 17:21:08 INFO Starting cleanup of old closures method=DELETE path=/api/closures1214--- PASS: TestReadRedirectUsesPublicS3URL (0.52s)1215=== CONT TestService_cleanupPendingClosuresHandler1216=== NAME TestClientSharedPathCommittedMidPush1217 client_integration_test.go:816: Retrieved narinfo from S3:1218 StorePath: /build/TestClientSharedPathCommittedMidPush614708936/001/store/ghkn6nkp4yg2viw29qs4j2f8648bjz5c-top1219 URL: nar/0xryz6cs7yhcvvkv51lhx47n8d2nd73j5l0whpbfkyfjw3mzkgbj.nar.zst1220 Compression: zstd1221 NarHash: sha256:0xryz6cs7yhcvvkv51lhx47n8d2nd73j5l0whpbfkyfjw3mzkgbj1222 NarSize: 2241223 References: /build/TestClientSharedPathCommittedMidPush614708936/001/store/ljh1fm8j6wx9lpcpnpyq0d1dxi9qp2df-shared-dep1224 CA: text:sha256:0h3m4rbiaxfj7lrd9n8pidylls5nj2harn3vxmrap866y1q9n0yx12252026/10/25 17:21:08 INFO Aborted multipart uploads count=0 kept=012262026/10/25 17:21:08 INFO Aborted multipart uploads count=0 kept=012272026/10/25 17:21:08 WARN Force mode enabled - objects will be deleted immediately without grace period12282026/10/25 17:21:08 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=012292026/10/25 17:21:08 INFO Vacuumed table table=pending_closures12302026/10/25 17:21:08 INFO Vacuumed table table=pending_objects12312026/10/25 17:21:08 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=012322026/10/25 17:21:08 INFO Vacuumed table table=multipart_uploads12332026/10/25 17:21:08 INFO Vacuumed table table=pending_closures1234=== CONT TestService_readinessHandler1235--- PASS: TestClientSharedPathCommittedMidPush (0.74s)12362026/10/25 17:21:08 INFO Vacuumed table table=closures12372026/10/25 17:21:08 INFO Vacuumed table table=pending_objects12382026/10/25 17:21:08 INFO Vacuumed table table=objects12392026/10/25 17:21:08 INFO Vacuumed table table=multipart_uploads12402026/10/25 17:21:08 INFO Vacuumed table table=closures12412026/10/25 17:21:08 INFO Vacuumed table table=objects12422026/10/25 17:21:08 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001243--- PASS: TestObjectStatsUpdatedOncePerCommit (0.49s)1244=== CONT TestReadProxyNarinfo1245--- PASS: TestReadProxyInvalidPath (0.30s)1246=== CONT TestGetExistingObjectsLocksRows1247=== CONT TestMultipartCleanup1248--- PASS: TestService_createPendingClosureHandler (1.38s)12492026/10/25 17:21:08 INFO Received uploads request method=POST path=/api/pending_closures12502026/10/25 17:21:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12512026/10/25 17:21:08 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LmUwZDEzZGU5LTA2MDktNDM5YS05MjUyLTAwMGZlMDg1YzQ0Y3gxNzkyOTQ4ODY4MDQzMDAzNzEx parts=101252--- PASS: TestReadProxyConditionalGet (0.55s)1253=== CONT TestPresentRefreshesOnlyStaleClosures1254--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.33s)1255=== CONT TestPendingCleanupUsesOneCutoff12562026/10/25 17:21:08 INFO Received uploads request method=POST path=/api/pending_closures12572026/10/25 17:21:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1258--- PASS: TestReadProxyNarStreaming (0.24s)1259=== CONT TestDeduplicatedObjectsRecordedAsPending12602026/10/25 17:21:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12612026/10/25 17:21:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12622026/10/25 17:21:08 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LmZjOTJjMzNjLTc3NzAtNDliZC1hYjM1LWEzODRmMDRkNDg4M3gxNzkyOTQ4ODY3NTgyNTYwMjc1 parts=1012632026/10/25 17:21:08 INFO Received complete push request method=POST path=/api/pushes/1/complete1264--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.23s)1265=== CONT TestParseSingleRange1266=== RUN TestParseSingleRange/none1267=== PAUSE TestParseSingleRange/none1268=== RUN TestParseSingleRange/unknown_unit1269=== PAUSE TestParseSingleRange/unknown_unit1270=== RUN TestParseSingleRange/multi-range_ignored1271=== PAUSE TestParseSingleRange/multi-range_ignored1272=== RUN TestParseSingleRange/malformed_no_dash1273=== PAUSE TestParseSingleRange/malformed_no_dash1274=== RUN TestParseSingleRange/malformed_both_empty1275=== PAUSE TestParseSingleRange/malformed_both_empty1276=== RUN TestParseSingleRange/malformed_end_before_start1277=== PAUSE TestParseSingleRange/malformed_end_before_start1278=== RUN TestParseSingleRange/closed1279=== PAUSE TestParseSingleRange/closed1280=== RUN TestParseSingleRange/open-ended1281=== PAUSE TestParseSingleRange/open-ended1282=== RUN TestParseSingleRange/end_clamped_to_size1283=== PAUSE TestParseSingleRange/end_clamped_to_size1284=== RUN TestParseSingleRange/suffix1285=== PAUSE TestParseSingleRange/suffix1286=== RUN TestParseSingleRange/suffix_exceeds_size1287=== PAUSE TestParseSingleRange/suffix_exceeds_size1288=== RUN TestParseSingleRange/single_byte1289=== PAUSE TestParseSingleRange/single_byte1290=== RUN TestParseSingleRange/start_past_EOF1291=== PAUSE TestParseSingleRange/start_past_EOF1292=== RUN TestParseSingleRange/start_far_past_EOF1293=== PAUSE TestParseSingleRange/start_far_past_EOF1294=== CONT TestGCBugBareHashReferences12952026/10/25 17:21:08 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LmI2ZDI1OWFiLWM5YzctNDE0MC04YTAwLTM4NjFhYmQxNzIzOHgxNzkyOTQ4ODY4MTYxODQ0MTk5 parts=1012962026/10/25 17:21:08 INFO Completed push id=1 objects=4 duration=7.345107ms12972026/10/25 17:21:08 INFO Received push request method=POST path=/api/pushes12982026/10/25 17:21:08 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LjAzNGJkYWRiLTkyMTktNDcwNy1iOTUxLTdiNDAyZjg4MjU5N3gxNzkyOTQ4ODY4MTMzNzA0NDAx parts=1012992026/10/25 17:21:08 INFO Received uploads request method=POST path=/api/pending_closures13002026/10/25 17:21:08 INFO Received cleanup request method=DELETE path=/api/pending_closures13012026/10/25 17:21:08 INFO Aborted multipart uploads count=0 kept=013022026/10/25 17:21:08 INFO Received uploads request method=POST path=/api/pending_closures13032026/10/25 17:21:08 INFO Aborted multipart uploads count=0 kept=013042026/10/25 17:21:08 INFO Received cleanup request method=DELETE path=/api/pending_closures13052026/10/25 17:21:08 INFO Aborted multipart uploads count=1 kept=013062026/10/25 17:21:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13072026/10/25 17:21:08 WARN readiness check failed error="closed pool"13082026-10-25 17:21:08.765 UTC [985] ERROR: Closure does not exist: id=113092026-10-25 17:21:08.765 UTC [985] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE13102026-10-25 17:21:08.765 UTC [985] STATEMENT: -- name: CommitPendingClosure :one1311 SELECT commit_pending_closure($1::bigint)::bigint1312 13132026/10/25 17:21:08 WARN Force mode enabled - objects will be deleted immediately without grace period1314=== CONT TestReadProxyNarinfoAlreadyDecompressed1315--- PASS: TestService_cleanupPendingClosuresHandler (0.29s)1316--- PASS: TestService_readinessHandler (0.25s)1317=== CONT TestPresentNotReportedWhileGCDeletesClosure1318=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1319=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1320=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1321=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1322=== CONT TestService_RequireScope_OIDC13232026/10/25 17:21:08 INFO Aborted multipart uploads count=0 kept=013242026/10/25 17:21:08 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=013252026/10/25 17:21:08 INFO Vacuumed table table=pending_closures13262026/10/25 17:21:08 INFO Vacuumed table table=pending_objects13272026/10/25 17:21:08 INFO Vacuumed table table=multipart_uploads13282026/10/25 17:21:08 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=013292026/10/25 17:21:08 INFO Vacuumed table table=closures13302026/10/25 17:21:08 INFO Vacuumed table table=pending_closures13312026/10/25 17:21:08 INFO Vacuumed table table=objects13322026/10/25 17:21:08 INFO Vacuumed table table=pending_objects13332026/10/25 17:21:08 INFO Vacuumed table table=multipart_uploads13342026/10/25 17:21:08 INFO Vacuumed table table=closures13352026/10/25 17:21:08 INFO Vacuumed table table=objects13362026/10/25 17:21:08 INFO Aborted multipart uploads count=0 kept=013372026/10/25 17:21:08 WARN Force mode enabled - objects will be deleted immediately without grace period13382026/10/25 17:21:08 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013392026/10/25 17:21:08 INFO Vacuumed table table=pending_closures13402026/10/25 17:21:08 INFO Vacuumed table table=pending_objects13412026/10/25 17:21:08 INFO Vacuumed table table=multipart_uploads13422026/10/25 17:21:08 INFO Vacuumed table table=closures13432026/10/25 17:21:08 INFO Vacuumed table table=objects13442026/10/25 17:21:08 INFO Received uploads request method=POST path=/api/pending_closures1345--- PASS: TestPushDedupSurvivesConcurrentGC (0.40s)1346=== CONT TestSweepRechecksPendingAfterLocking1347--- PASS: TestGetExistingObjectsLocksRows (0.29s)1348=== CONT TestGCMetrics13492026/10/25 17:21:08 INFO Received uploads request method=POST path=/api/pending_closures13502026/10/25 17:21:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1351--- PASS: TestPresentRefreshesOnlyStaleClosures (0.26s)1352=== CONT TestClientMultipleUploads13532026/10/25 17:21:08 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LjE5MTcwMzI3LTQ2YjQtNGE4Ni1iYjZmLTc5ZTFiNzg1ODE2MngxNzkyOTQ4ODY4MzU4NTkyMjgx parts=1213542026/10/25 17:21:08 INFO Received uploads request method=POST path=/api/pending_closures13552026/10/25 17:21:08 INFO Received uploads request method=POST path=/api/pending_closures13562026/10/25 17:21:08 INFO Received uploads request method=POST path=/api/pending_closures13572026/10/25 17:21:08 INFO Received cleanup request method=DELETE path=/api/pending_closures13582026/10/25 17:21:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1359=== CONT TestClientIntegration1360--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.97s)1361--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.29s)1362=== CONT TestDeleteClosuresRacingPins13632026/10/25 17:21:08 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LjNmNmVkYjQ0LTUyM2MtNDY4YS1iMThjLWMzYjBiZGI2MDljNXgxNzkyOTQ4ODY3ODY5MDk0NzU4 parts=1013642026/10/25 17:21:08 INFO Received cleanup request method=DELETE path=/api/pending_closures13652026/10/25 17:21:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13662026/10/25 17:21:08 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket59/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""13672026/10/25 17:21:08 INFO Aborted multipart uploads count=0 kept=113682026/10/25 17:21:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13692026/10/25 17:21:08 INFO Received cleanup request method=DELETE path=/api/pending_closures13702026/10/25 17:21:08 INFO Aborted multipart uploads count=1 kept=013712026/10/25 17:21:08 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LjFhZjQ1MGNmLTY3ZTEtNDg3ZC1hZTcyLTc0M2I2YTI0MzM1MngxNzkyOTQ4ODY3ODQ4NjY5OTkx parts=1013722026-10-25 17:21:08.988 UTC [1001] ERROR: Push does not exist: id=113732026-10-25 17:21:08.988 UTC [1001] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE13742026-10-25 17:21:08.988 UTC [1001] STATEMENT: SELECT commit_push($1)13752026/10/25 17:21:08 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43623/oidc13762026/10/25 17:21:09 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LjFhZjA3NTA1LWVmZDItNDY5Ni05ZmQ1LWIxZmJkYTBmYTQxMXgxNzkyOTQ4ODY4MzgxODM0MDkz parts=1213772026/10/25 17:21:09 INFO Received uploads request method=POST path=/api/pending_closures1378--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.23s)1379=== CONT TestGCTaskStore_CompletedAllowsNewTask1380--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1381=== CONT TestChildrenInheritRaisedFileLimit1382--- PASS: TestMultipartCleanup (0.44s)1383=== CONT TestIsValidCachePath1384=== RUN TestIsValidCachePath/narinfo1385=== PAUSE TestIsValidCachePath/narinfo1386=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1387=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1388=== RUN TestIsValidCachePath/nar_zst1389=== PAUSE TestIsValidCachePath/nar_zst1390=== RUN TestIsValidCachePath/nar_xz1391=== PAUSE TestIsValidCachePath/nar_xz1392=== RUN TestIsValidCachePath/nar_bz21393=== PAUSE TestIsValidCachePath/nar_bz21394=== RUN TestIsValidCachePath/nar_uncompressed1395=== PAUSE TestIsValidCachePath/nar_uncompressed1396=== RUN TestIsValidCachePath/ls1397=== PAUSE TestIsValidCachePath/ls1398=== RUN TestIsValidCachePath/log1399=== PAUSE TestIsValidCachePath/log1400=== RUN TestIsValidCachePath/realisation1401=== PAUSE TestIsValidCachePath/realisation1402=== RUN TestIsValidCachePath/nix-cache-info1403=== PAUSE TestIsValidCachePath/nix-cache-info1404=== RUN TestIsValidCachePath/index.html1405=== PAUSE TestIsValidCachePath/index.html1406=== RUN TestIsValidCachePath/traversal_parent1407=== PAUSE TestIsValidCachePath/traversal_parent1408=== RUN TestIsValidCachePath/traversal_in_middle1409=== PAUSE TestIsValidCachePath/traversal_in_middle1410=== RUN TestIsValidCachePath/invalid_char_e1411=== PAUSE TestIsValidCachePath/invalid_char_e1412=== RUN TestIsValidCachePath/invalid_char_u1413=== PAUSE TestIsValidCachePath/invalid_char_u1414=== RUN TestIsValidCachePath/random_path1415=== PAUSE TestIsValidCachePath/random_path1416=== RUN TestIsValidCachePath/empty1417=== PAUSE TestIsValidCachePath/empty1418=== RUN TestIsValidCachePath/leading_slash1419=== PAUSE TestIsValidCachePath/leading_slash1420=== RUN TestIsValidCachePath/wrong_extension1421=== PAUSE TestIsValidCachePath/wrong_extension1422=== RUN TestIsValidCachePath/short_hash1423=== PAUSE TestIsValidCachePath/short_hash1424=== CONT TestService_AuthMiddleware_OIDC1425--- PASS: TestChildrenInheritRaisedFileLimit (0.00s)1426=== CONT TestGCTaskStore_GetReturnsLatest1427=== CONT TestClientCADerivations1428--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1429--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.25s)1430=== CONT TestGCTaskStore_StartNew1431--- PASS: TestGCTaskStore_StartNew (0.00s)1432=== CONT TestGCTaskStore_DeduplicateSameParams1433--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1434=== CONT TestRegisterCompletedObjectNeedsPendingRow14352026/10/25 17:21:09 INFO Received uploads request method=POST path=/api/pending_closures14362026/10/25 17:21:09 INFO Aborted multipart uploads count=0 kept=014372026/10/25 17:21:09 WARN Force mode enabled - objects will be deleted immediately without grace period14382026/10/25 17:21:09 INFO Aborted multipart uploads count=0 kept=014392026/10/25 17:21:09 WARN Force mode enabled - objects will be deleted immediately without grace period14402026/10/25 17:21:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14412026/10/25 17:21:09 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=014422026/10/25 17:21:09 INFO Vacuumed table table=pending_closures14432026/10/25 17:21:09 INFO Vacuumed table table=pending_objects14442026/10/25 17:21:09 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=014452026/10/25 17:21:09 INFO Vacuumed table table=multipart_uploads14462026/10/25 17:21:09 INFO Vacuumed table table=closures14472026/10/25 17:21:09 INFO Vacuumed table table=objects14482026/10/25 17:21:09 INFO Vacuumed table table=pending_closures14492026/10/25 17:21:09 INFO Vacuumed table table=pending_objects14502026/10/25 17:21:09 INFO Vacuumed table table=multipart_uploads14512026/10/25 17:21:09 INFO Vacuumed table table=closures14522026/10/25 17:21:09 INFO Vacuumed table table=objects14532026/10/25 17:21:09 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LjI3NzMwYTZmLWU2Y2YtNDM3YS04OWU3LWI4MDI5NTExMjAwZXgxNzkyOTQ4ODY4MDQyMTg5NzQz parts=1014542026/10/25 17:21:09 INFO Received complete push request method=POST path=/api/pushes/1/complete14552026/10/25 17:21:09 WARN Rate limiter enabled after throttle name=s3-test rate=514562026/10/25 17:21:09 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."14572026/10/25 17:21:09 INFO Completed push id=1 objects=4 duration=5.109346ms1458=== CONT TestService_healthCheckHandler1459--- PASS: TestSweepRechecksPendingAfterLocking (0.26s)1460--- PASS: TestGCMetrics (0.26s)1461=== CONT TestService_ReadScope_PublicByDefault1462--- PASS: TestPush_RepeatedRootCommitsOnce (1.51s)1463=== CONT TestGracefulShutdownDrainsInflight14642026/10/25 17:21:09 INFO Starting HTTP server address=127.0.0.1:3638514652026/10/25 17:21:09 INFO Shutdown signal received, draining in-flight requests timeout=10s1466=== NAME TestClientMultipleUploads1467 client_integration_test.go:480: Created store path 0: /build/TestClientMultipleUploads2176918384/001/store/1ryy5yhiragcsc7b1hd8wbcvzpdzlax4-test-file-0.txt14682026/10/25 17:21:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1469=== NAME TestClientIntegration1470 client_integration_test.go:334: Created store path: /build/TestClientIntegration3358446932/002/store/2ni9j3kfydr18ml89m4aqya4ws8mp806-test-file.txt1471=== NAME TestClientMultipleUploads1472 client_integration_test.go:480: Created store path 1: /build/TestClientMultipleUploads2176918384/001/store/cqgicq0ga7kyrnwx171akbzny8q5rcf6-test-file-1.txt14732026/10/25 17:21:09 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LjZlZmQ1N2YzLTRhZWUtNDgxYi1iYjA1LTAxNTdkMjAxMTg1NXgxNzkyOTQ4ODY4MTMyOTQyMzM0 parts=1014742026/10/25 17:21:09 INFO Received complete push request method=POST path=/api/pushes/1/complete14752026/10/25 17:21:09 INFO Completed push id=1 objects=4 duration=7.865172ms14762026/10/25 17:21:09 INFO Received create pin request method=POST path=/api/pins/deploy14772026/10/25 17:21:09 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14782026/10/25 17:21:09 INFO Completed upload id=2 objects=2 duration=1.726456ms1479--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1480=== CONT TestClientErrorHandling1481=== RUN TestClientErrorHandling/InvalidStorePath1482=== PAUSE TestClientErrorHandling/InvalidStorePath1483=== RUN TestClientErrorHandling/InvalidAuthToken1484=== PAUSE TestClientErrorHandling/InvalidAuthToken1485=== RUN TestClientErrorHandling/ServerNotAvailable1486=== PAUSE TestClientErrorHandling/ServerNotAvailable1487=== CONT TestReadProxyRangeRequest1488=== CONT TestGCTaskStore_Fail1489--- PASS: TestGCBugBareHashReferences (0.51s)1490=== CONT TestCacheConfigHandler1491--- PASS: TestGCTaskStore_Fail (0.00s)1492=== RUN TestCacheConfigHandler/full_config,_no_issuer1493=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1494=== RUN TestCacheConfigHandler/no_cache_url_configured1495=== PAUSE TestCacheConfigHandler/no_cache_url_configured1496=== RUN TestCacheConfigHandler/no_signing_keys14972026/10/25 17:21:09 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo1498=== PAUSE TestCacheConfigHandler/no_signing_keys1499=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1500=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1501=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1502=== RUN TestService_RequireScope_OIDC/builder_may_write1503=== PAUSE TestService_RequireScope_OIDC/builder_may_write1504=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1505=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1506=== RUN TestService_RequireScope_OIDC/ops_may_admin1507=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1508=== RUN TestService_RequireScope_OIDC/ops_may_not_write1509=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1510=== RUN TestService_RequireScope_OIDC/reader_may_not_write1511=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1512=== RUN TestService_RequireScope_OIDC/static_token_may_admin1513=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1514=== RUN TestService_RequireScope_OIDC/static_token_may_write1515=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1516=== RUN TestService_RequireScope_OIDC/reader_may_read1517=== PAUSE TestService_RequireScope_OIDC/reader_may_read1518=== RUN TestService_RequireScope_OIDC/writer_implies_read1519=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1520=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1521=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1522=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1523=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1524=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1525=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1526=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1527=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1528=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1529=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1530=== CONT TestService_ReadAuthMiddleware1531=== NAME TestClientMultipleUploads1532 client_integration_test.go:480: Created store path 2: /build/TestClientMultipleUploads2176918384/001/store/cmr3shdw6qgzs7xmyhm2hwq0aalby0n4-test-file-2.txt1533--- PASS: TestCreatePinRejectsBadInput (1.40s)1534=== CONT TestResolveDBConnectionString1535=== RUN TestResolveDBConnectionString/flag_wins1536=== PAUSE TestResolveDBConnectionString/flag_wins1537=== RUN TestResolveDBConnectionString/file_when_flag_empty1538=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1539=== RUN TestResolveDBConnectionString/missing_file_is_an_error1540=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1541=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1542=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1543=== RUN TestResolveDBConnectionString/nothing_configured1544=== PAUSE TestResolveDBConnectionString/nothing_configured1545=== CONT TestGCTaskStore_GetEmpty15462026/10/25 17:21:09 WARN Rate limiter backed off name=s3-test rate=51547=== CONT TestGCTaskStore_PhaseUpdates15482026/10/25 17:21:09 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."1549--- PASS: TestGCTaskStore_GetEmpty (0.00s)1550=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1551--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1552--- PASS: TestReadProxy404 (0.78s)1553=== CONT TestCommitRacingPendingCleanupKeepsObjects15542026/10/25 17:21:09 INFO Received push request method=POST path=/api/pushes1555--- PASS: TestMetricsCommit (1.50s)1556=== CONT TestPushWaitsForSweepHoldingRow15572026/10/25 17:21:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15582026/10/25 17:21:09 INFO Uploading 2ni9j3kfydr18ml89m4aqya4ws8mp806-test-file.txt (152B)1559--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.24s)1560=== CONT TestService_AuthMiddleware_MTLSProxyHeader15612026/10/25 17:21:09 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15622026/10/25 17:21:09 WARN Failed to register uploaded object key=2ni9j3kfydr18ml89m4aqya4ws8mp806.ls error="server returned 404: 404 page not found\n"15632026/10/25 17:21:09 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15642026/10/25 17:21:09 INFO Signed narinfos id=1 count=115652026/10/25 17:21:09 INFO Uploading 1 narinfos15662026/10/25 17:21:09 INFO Received complete push request method=POST path=/api/pushes/1/complete15672026/10/25 17:21:09 WARN Failed to register uploaded object key=2ni9j3kfydr18ml89m4aqya4ws8mp806.narinfo error="server returned 404: 404 page not found\n"15682026/10/25 17:21:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45963/oidc15692026/10/25 17:21:09 INFO Received push request method=POST path=/api/pushes15702026/10/25 17:21:09 INFO Completed push id=1 objects=3 duration=9.220584ms15712026/10/25 17:21:09 INFO Upload complete. (86ms)15722026/10/25 17:21:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1573=== NAME TestClientCADerivations1574 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2686199037/001/store/09y13gbb172m0yvf0yb2vy2nag3k083q-ca-test15752026/10/25 17:21:09 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15762026/10/25 17:21:09 INFO Uploading cmr3shdw6qgzs7xmyhm2hwq0aalby0n4-test-file-2.txt (160B)15772026/10/25 17:21:09 INFO Uploading 1ryy5yhiragcsc7b1hd8wbcvzpdzlax4-test-file-0.txt (160B)15782026/10/25 17:21:09 INFO Uploading cqgicq0ga7kyrnwx171akbzny8q5rcf6-test-file-1.txt (160B)15792026/10/25 17:21:09 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2Ljk1NWYwZTFmLWFhMDgtNDg5OC04Y2ZlLTM5NWRmZDIyMTBjYXgxNzkyOTQ4ODY4Njk0OTc3Nzgx parts=1015802026/10/25 17:21:09 INFO Received complete push request method=POST path=/api/pushes/2/complete15812026/10/25 17:21:09 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15822026/10/25 17:21:09 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15832026/10/25 17:21:09 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15842026/10/25 17:21:09 INFO Completed push id=2 objects=4 duration=5.060347ms15852026/10/25 17:21:09 WARN Failed to register uploaded object key=cmr3shdw6qgzs7xmyhm2hwq0aalby0n4.ls error="server returned 404: 404 page not found\n"15862026/10/25 17:21:09 WARN Failed to register uploaded object key=cqgicq0ga7kyrnwx171akbzny8q5rcf6.ls error="server returned 404: 404 page not found\n"15872026/10/25 17:21:09 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15882026/10/25 17:21:09 WARN Failed to register uploaded object key=1ryy5yhiragcsc7b1hd8wbcvzpdzlax4.ls error="server returned 404: 404 page not found\n"15892026/10/25 17:21:09 INFO Signed narinfos id=1 count=315902026/10/25 17:21:09 INFO Uploading 3 narinfos1591--- PASS: TestService_healthCheckHandler (0.22s)1592=== CONT TestClientPushesUseOnePush1593=== CONT TestReadRedirectKeepsNarinfoProxied1594--- PASS: TestService_ReadScope_PublicByDefault (0.22s)15952026/10/25 17:21:09 WARN Failed to register uploaded object key=1ryy5yhiragcsc7b1hd8wbcvzpdzlax4.narinfo error="server returned 404: 404 page not found\n"15962026/10/25 17:21:09 WARN Failed to register uploaded object key=cmr3shdw6qgzs7xmyhm2hwq0aalby0n4.narinfo error="server returned 404: 404 page not found\n"15972026/10/25 17:21:09 INFO Received complete push request method=POST path=/api/pushes/1/complete15982026/10/25 17:21:09 WARN Failed to register uploaded object key=cqgicq0ga7kyrnwx171akbzny8q5rcf6.narinfo error="server returned 404: 404 page not found\n"1599=== NAME TestClientCADerivations1600 client_ca_test.go:139: Found 1 dependencies (including self)1601--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.17s)1602=== CONT TestMetricsInventory16032026/10/25 17:21:09 INFO Completed push id=1 objects=9 duration=15.451121ms16042026/10/25 17:21:09 INFO Upload complete. (115ms)1605=== NAME TestClientMultipleUploads1606 client_integration_test.go:491: Uploaded 3 paths in 154.621076ms16072026/10/25 17:21:09 INFO All 1 paths already cached1608=== NAME TestClientIntegration1609 client_integration_test.go:360: Retrieved narinfo from S3:1610 StorePath: /build/TestClientIntegration3358446932/002/store/2ni9j3kfydr18ml89m4aqya4ws8mp806-test-file.txt1611 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1612 Compression: zstd1613 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11614 NarSize: 1521615 References: 1616 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11617 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)1618 client_integration_test.go:361: Decompressed .ls content (64 bytes):1619 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1620--- PASS: TestClientMultipleUploads (0.51s)1621=== CONT TestGCEndsOnShutdown1622=== RUN TestGCEndsOnShutdown/before_the_run1623=== PAUSE TestGCEndsOnShutdown/before_the_run1624=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1625=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1626=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1627=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1628=== CONT TestNARDeduplicationMetadataUploadBug16292026/10/25 17:21:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1630=== CONT TestLeadIncumbentAnnouncesAtOnce1631--- PASS: TestReadProxyRangeRequest (0.24s)16322026/10/25 17:21:09 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LmZlNjhiYmVhLWIxZjgtNDM5OS1hYzk1LTdmYzA2MzJmMmMzYngxNzkyOTQ4ODY3ODcwMDk4MzY4 parts=1016332026/10/25 17:21:09 INFO Received complete push request method=POST path=/api/pushes/1/complete16342026/10/25 17:21:09 INFO Received push request method=POST path=/api/pushes16352026/10/25 17:21:09 INFO Completed push id=1 objects=6 duration=10.169053ms16362026/10/25 17:21:09 INFO Object in database but missing from S3 key=2ni9j3kfydr18ml89m4aqya4ws8mp806.ls16372026/10/25 17:21:09 WARN Found objects in DB but missing from S3, will re-upload count=116382026/10/25 17:21:09 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1639--- PASS: TestService_ReadAuthMiddleware (0.26s)1640=== CONT TestSweepSkipsRowsLockedByPush16412026/10/25 17:21:09 INFO Received push request method=POST path=/api/pushes16422026/10/25 17:21:09 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16432026/10/25 17:21:09 WARN mTLS auth: bound subjects configured but subject DN unavailable16442026/10/25 17:21:09 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"16452026/10/25 17:21:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16462026/10/25 17:21:09 INFO Received complete push request method=POST path=/api/pushes/2/complete16472026/10/25 17:21:09 WARN Failed to register uploaded object key=2ni9j3kfydr18ml89m4aqya4ws8mp806.ls error="server returned 404: 404 page not found\n"16482026/10/25 17:21:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16492026/10/25 17:21:09 INFO Uploading 09y13gbb172m0yvf0yb2vy2nag3k083q-ca-test (144B)16502026/10/25 17:21:09 INFO Completed push id=2 objects=3 duration=2.420542ms16512026/10/25 17:21:09 INFO Upload complete. (64ms)1652=== NAME TestClientIntegration1653 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)1654 client_integration_test.go:389: Decompressed .ls content (49 bytes):1655 {"version":1,"root":{"type":"regular","size":39}}1656--- PASS: TestPush_CompleteCommitsEveryRoot (2.29s)1657=== CONT TestLeadEndsOnShutdown16582026/10/25 17:21:09 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LjJlNjY4ZmMwLWY2ZDktNGEyZi04N2E0LWEwMjBmYTljOTQyMXgxNzkyOTQ4ODY3ODUwODkwODcy parts=1016592026/10/25 17:21:09 WARN Failed to register uploaded object key=log/9r446dqmva6kivnwm32lz7n7h746hj53-ca-test.drv error="server returned 404: 404 page not found\n"16602026/10/25 17:21:09 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"1661=== CONT TestProxyWriteTimeout1662=== RUN TestProxyWriteTimeout/narinfo1663--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.27s)1664=== PAUSE TestProxyWriteTimeout/narinfo1665=== RUN TestProxyWriteTimeout/1_GiB_nar1666=== PAUSE TestProxyWriteTimeout/1_GiB_nar1667=== RUN TestProxyWriteTimeout/10_GiB_nar1668=== PAUSE TestProxyWriteTimeout/10_GiB_nar1669=== RUN TestProxyWriteTimeout/unknown_size1670=== PAUSE TestProxyWriteTimeout/unknown_size1671=== CONT TestClientFallsBackToClosures16722026/10/25 17:21:09 WARN Failed to register uploaded object key=09y13gbb172m0yvf0yb2vy2nag3k083q.ls error="server returned 404: 404 page not found\n"16732026/10/25 17:21:09 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16742026/10/25 17:21:09 INFO Signed narinfos id=1 count=116752026/10/25 17:21:09 INFO Uploading 1 narinfos16762026/10/25 17:21:09 INFO Received complete push request method=POST path=/api/pushes/1/complete16772026/10/25 17:21:09 WARN Failed to register uploaded object key=09y13gbb172m0yvf0yb2vy2nag3k083q.narinfo error="server returned 404: 404 page not found\n"16782026/10/25 17:21:09 INFO Completed push id=1 objects=4 duration=9.192483ms16792026/10/25 17:21:09 INFO Upload complete. (136ms)1680=== NAME TestClientCADerivations1681 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2686199037/001/store/09y13gbb172m0yvf0yb2vy2nag3k083q-ca-test1682 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1683 Compression: zstd1684 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1685 NarSize: 1441686 References: 1687 Deriver: /build/TestClientCADerivations2686199037/001/store/9r446dqmva6kivnwm32lz7n7h746hj53-ca-test.drv1688 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1689 client_ca_test.go:185: Checking for realisation files in S3...1690 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1691 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache16922026/10/25 17:21:09 INFO Aborted multipart uploads count=0 kept=016932026/10/25 17:21:09 WARN Force mode enabled - objects will be deleted immediately without grace period1694=== CONT TestService_verifyS3Integrity1695--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.28s)16962026/10/25 17:21:09 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=016972026/10/25 17:21:09 INFO Vacuumed table table=pending_closures16982026/10/25 17:21:09 INFO Received uploads request method=POST path=/api/pending_closures16992026/10/25 17:21:09 INFO Vacuumed table table=pending_objects17002026/10/25 17:21:09 INFO Vacuumed table table=multipart_uploads17012026/10/25 17:21:09 INFO Vacuumed table table=closures17022026/10/25 17:21:09 INFO Vacuumed table table=objects17032026/10/25 17:21:09 INFO Received push request method=POST path=/api/pushes17042026/10/25 17:21:09 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17052026/10/25 17:21:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1706=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1707=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1708=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1709=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1710=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1711=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1712=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1713=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1714=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle17152026/10/25 17:21:09 INFO Received complete push request method=POST path=/api/pushes/3/complete17162026/10/25 17:21:09 WARN Failed to register uploaded object key=2ni9j3kfydr18ml89m4aqya4ws8mp806.ls error="server returned 404: 404 page not found\n"17172026/10/25 17:21:09 INFO Completed push id=3 objects=3 duration=2.493543ms17182026/10/25 17:21:09 INFO Upload complete. (57ms)1719--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.34s)1720=== CONT TestConnectSerialisesConcurrentMigrations1721=== NAME TestClientIntegration1722 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)1723 client_integration_test.go:405: Decompressed .ls content (49 bytes):1724 {"version":1,"root":{"type":"regular","size":39}}17252026/10/25 17:21:09 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LjdiYmU4NjA2LWZjZWUtNDhiOC1iZWU0LWQwZjZiNmY5OGJkYngxNzkyOTQ4ODY5MDM1NzAzNTgw error="Get \"http://127.0.0.1:1/bucket42/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"17262026/10/25 17:21:09 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LjY1NTA4YWFjLWJiZjctNDgyMi04ZTlmLTkwZjUwNmQ5MjQ3ZHgxNzkyOTQ4ODY5MDE2NDQ1Mzg0 parts=1217272026/10/25 17:21:09 INFO Received cleanup request method=DELETE path=/api/pending_closures17282026/10/25 17:21:09 INFO Aborted multipart uploads count=1 kept=01729--- PASS: TestRedundantMultipartUpload (1.61s)1730=== CONT TestForceGCDuringPushOffersSweptObject1731=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1732=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1733=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1734=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1735=== CONT TestLeadElectsOneAndHandsOver1736=== NAME TestClientCADerivations1737 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1738 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1739 error: binary cache 's3://bucket71?endpoint=http://localhost:45219®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2686199037/001/store'1740 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11741--- PASS: TestClientCADerivations (0.64s)1742=== CONT TestGCSweepDeliversEachKeyOnce17432026-10-25 17:21:09.718 UTC [1676] ERROR: duplicate key value violates unique constraint "pg_type_typname_nsp_index"17442026-10-25 17:21:09.718 UTC [1676] DETAIL: Key (typname, typnamespace)=(goose_db_version, 2200) already exists.17452026-10-25 17:21:09.718 UTC [1676] STATEMENT: CREATE TABLE goose_db_version (1746 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1747 version_id bigint NOT NULL,1748 is_applied boolean NOT NULL,1749 tstamp timestamp NOT NULL DEFAULT now()1750 )17512026/10/25 17:21:09 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1752=== CONT TestGCAdvisoryLockBlocksConcurrentRun1753--- PASS: TestMetricsInventory (0.38s)17542026/10/25 17:21:09 INFO Received push request method=POST path=/api/pushes17552026/10/25 17:21:09 INFO lead: acquired remote=192.0.2.1:123417562026/10/25 17:21:09 INFO lead: released remote=192.0.2.1:123417572026/10/25 17:21:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17582026/10/25 17:21:09 INFO Uploading i4mcgwq920lq3alnfnyv4116cc82dpwd-lost-commit.txt (152B)1759--- PASS: TestReadProxyNarinfo (1.20s)1760=== CONT TestPendingClosureWriteTimeout/empty1761=== CONT TestPendingClosureWriteTimeout/670k_objects17622026/10/25 17:21:09 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"1763=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1764--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.33s)1765=== CONT TestPendingClosureWriteTimeout/400_objects1766=== CONT TestServerTLSConfig/no_client_CA1767=== CONT TestServerTLSConfig/missing_CA_file1768=== CONT TestServerTLSConfig/not_a_PEM_file1769=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts1770--- PASS: TestServerTLSConfig (0.00s)1771 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1772 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1773 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)17742026/10/25 17:21:09 INFO Received request for more parts method=POST path=/1775=== NAME TestNARDeduplicationMetadataUploadBug1776 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2960462443/001/store/5nqc7h7bp1lqa0wg0dg9n6gj9mka9b8z-file1.txt17772026/10/25 17:21:09 WARN Failed to register uploaded object key=i4mcgwq920lq3alnfnyv4116cc82dpwd.ls error="server returned 404: 404 page not found\n"17782026/10/25 17:21:09 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign17792026/10/25 17:21:09 INFO Signed narinfos id=4 count=117802026/10/25 17:21:09 INFO Uploading 1 narinfos17812026/10/25 17:21:09 INFO Received complete push request method=POST path=/api/pushes/4/complete17822026/10/25 17:21:09 WARN Failed to register uploaded object key=i4mcgwq920lq3alnfnyv4116cc82dpwd.narinfo error="server returned 404: 404 page not found\n"17832026/10/25 17:21:09 INFO Completed push id=4 objects=3 duration=2.447022ms17842026/10/25 17:21:09 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:44301/api/pushes/4/complete\": EOF" url=http://127.0.0.1:44301/api/pushes/4/complete17852026/10/25 17:21:09 INFO Aborted multipart uploads count=0 kept=017862026/10/25 17:21:09 INFO lead: acquired remote=192.0.2.1:123417872026/10/25 17:21:09 WARN Force mode enabled - objects will be deleted immediately without grace period17882026/10/25 17:21:09 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=017892026/10/25 17:21:09 INFO Vacuumed table table=pending_closures17902026/10/25 17:21:09 INFO Vacuumed table table=pending_objects17912026/10/25 17:21:09 INFO Vacuumed table table=multipart_uploads17922026/10/25 17:21:09 INFO Vacuumed table table=closures17932026/10/25 17:21:09 INFO Vacuumed table table=objects17942026/10/25 17:21:09 INFO Aborted multipart uploads count=0 kept=017952026/10/25 17:21:09 WARN Force mode enabled - objects will be deleted immediately without grace period1796=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17972026/10/25 17:21:09 INFO Received push request method=POST path=/api/pushes1798--- PASS: TestReadRedirectKeepsNarinfoProxied (0.47s)17992026/10/25 17:21:09 INFO Received complete multipart upload request method=POST path=/18002026/10/25 17:21:09 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)18012026/10/25 17:21:09 INFO Uploading pd3324rx0k7xm3ggnk8frfi5labwf1l0-a (208B)18022026/10/25 17:21:09 INFO Uploading dybizrwbbqv0swaj1j4n9yw4frhslbd7-shared-dep (136B)18032026/10/25 17:21:09 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=018042026/10/25 17:21:09 INFO Vacuumed table table=pending_closures18052026/10/25 17:21:09 INFO Vacuumed table table=pending_objects18062026/10/25 17:21:09 INFO Vacuumed table table=multipart_uploads18072026/10/25 17:21:09 INFO Vacuumed table table=closures18082026/10/25 17:21:09 INFO Vacuumed table table=objects18092026/10/25 17:21:09 WARN Failed to register uploaded object key=mgis31qjiqdll09wcqvgrfv67rq7glfs.ls error="server returned 404: 404 page not found\n"18102026/10/25 17:21:09 WARN Failed to register uploaded object key=nar/0vnn5am1n1rv4k83bk0h2pd0h9nhl6a9554jnd11cdfblkjvwfrk.nar.zst error="server returned 404: 404 page not found\n"18112026/10/25 17:21:09 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18122026/10/25 17:21:09 INFO Received uploads request method=POST path=/api/pending_closures18132026/10/25 17:21:09 WARN Failed to register uploaded object key=dybizrwbbqv0swaj1j4n9yw4frhslbd7.ls error="server returned 404: 404 page not found\n"18142026/10/25 17:21:09 INFO Received push request method=POST path=/api/pushes18152026/10/25 17:21:09 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18162026/10/25 17:21:09 WARN Failed to register uploaded object key=pd3324rx0k7xm3ggnk8frfi5labwf1l0.ls error="server returned 404: 404 page not found\n"18172026/10/25 17:21:09 INFO Signed narinfos id=1 count=318182026/10/25 17:21:09 INFO Uploading 3 narinfos1819=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure1820--- PASS: TestSweepSkipsRowsLockedByPush (0.39s)18212026/10/25 17:21:09 INFO Received uploads request method=POST path=/18222026/10/25 17:21:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18232026/10/25 17:21:09 INFO Uploading 5nqc7h7bp1lqa0wg0dg9n6gj9mka9b8z-file1.txt (160B)18242026/10/25 17:21:09 INFO Received complete push request method=POST path=/api/pushes/1/complete18252026/10/25 17:21:09 WARN Failed to register uploaded object key=dybizrwbbqv0swaj1j4n9yw4frhslbd7.narinfo error="server returned 404: 404 page not found\n"18262026/10/25 17:21:09 WARN Failed to register uploaded object key=mgis31qjiqdll09wcqvgrfv67rq7glfs.narinfo error="server returned 404: 404 page not found\n"18272026/10/25 17:21:09 WARN Failed to register uploaded object key=pd3324rx0k7xm3ggnk8frfi5labwf1l0.narinfo error="server returned 404: 404 page not found\n"18282026/10/25 17:21:09 INFO Completed push id=1 objects=8 duration=5.917394ms18292026/10/25 17:21:09 INFO Upload complete. (82ms)18302026/10/25 17:21:09 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"1831=== NAME TestClientPushesUseOnePush1832 client_pushes_test.go:97: Retrieved narinfo from S3:1833 StorePath: /build/TestClientPushesUseOnePush716324565/001/store/dybizrwbbqv0swaj1j4n9yw4frhslbd7-shared-dep1834 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1835 Compression: zstd1836 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821837 NarSize: 1361838 References: 1839 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n18402026/10/25 17:21:09 INFO Received uploads request method=POST path=/api/pending_closures18412026/10/25 17:21:09 WARN Failed to register uploaded object key=5nqc7h7bp1lqa0wg0dg9n6gj9mka9b8z.ls error="server returned 404: 404 page not found\n"18422026/10/25 17:21:09 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18432026/10/25 17:21:09 INFO Signed narinfos id=1 count=118442026/10/25 17:21:09 INFO Uploading 1 narinfos1845 client_pushes_test.go:97: Retrieved narinfo from S3:1846 StorePath: /build/TestClientPushesUseOnePush716324565/001/store/pd3324rx0k7xm3ggnk8frfi5labwf1l0-a1847 URL: nar/0vnn5am1n1rv4k83bk0h2pd0h9nhl6a9554jnd11cdfblkjvwfrk.nar.zst1848 Compression: zstd1849 NarHash: sha256:0vnn5am1n1rv4k83bk0h2pd0h9nhl6a9554jnd11cdfblkjvwfrk1850 NarSize: 2081851 References: /build/TestClientPushesUseOnePush716324565/001/store/dybizrwbbqv0swaj1j4n9yw4frhslbd7-shared-dep1852 CA: text:sha256:1jlk7qva6ixb6zzrwv3ix46slp9lksri5b4cxn77nbk7rl3prkca1853 client_pushes_test.go:97: Retrieved narinfo from S3:1854 StorePath: /build/TestClientPushesUseOnePush716324565/001/store/mgis31qjiqdll09wcqvgrfv67rq7glfs-b1855 URL: nar/0vnn5am1n1rv4k83bk0h2pd0h9nhl6a9554jnd11cdfblkjvwfrk.nar.zst1856 Compression: zstd1857 NarHash: sha256:0vnn5am1n1rv4k83bk0h2pd0h9nhl6a9554jnd11cdfblkjvwfrk1858 NarSize: 2081859 References: /build/TestClientPushesUseOnePush716324565/001/store/dybizrwbbqv0swaj1j4n9yw4frhslbd7-shared-dep1860 CA: text:sha256:1jlk7qva6ixb6zzrwv3ix46slp9lksri5b4cxn77nbk7rl3prkca18612026/10/25 17:21:09 INFO Received complete push request method=POST path=/api/pushes/1/complete18622026/10/25 17:21:09 WARN Failed to register uploaded object key=5nqc7h7bp1lqa0wg0dg9n6gj9mka9b8z.narinfo error="server returned 404: 404 page not found\n"18632026/10/25 17:21:09 INFO Received complete push request method=POST path=/api/pushes/4/complete18642026-10-25 17:21:09.882 UTC [1042] ERROR: Push does not exist: id=418652026-10-25 17:21:09.882 UTC [1042] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE18662026-10-25 17:21:09.882 UTC [1042] STATEMENT: -- name: CommitPush :one1867 SELECT commit_push($1::bigint)::bigint1868 18692026/10/25 17:21:09 WARN Push not found id=418702026/10/25 17:21:09 INFO Completed push id=1 objects=3 duration=5.134886ms18712026/10/25 17:21:09 INFO Upload complete. (81ms)18722026/10/25 17:21:09 INFO lead: acquired remote=192.0.2.1:123418732026/10/25 17:21:09 INFO Upload complete. (228ms)1874=== NAME TestNARDeduplicationMetadataUploadBug1875 metadata_upload_test.go:54: Retrieved narinfo from S3:1876 StorePath: /build/TestNARDeduplicationMetadataUploadBug2960462443/001/store/5nqc7h7bp1lqa0wg0dg9n6gj9mka9b8z-file1.txt1877 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1878 Compression: zstd1879 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1880 NarSize: 1601881 References: 1882 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1883=== NAME TestClientIntegration1884 client_integration_test.go:435: Retrieved narinfo from S3:1885 StorePath: /build/TestClientIntegration3358446932/002/store/i4mcgwq920lq3alnfnyv4116cc82dpwd-lost-commit.txt1886 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1887 Compression: zstd1888 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1889 NarSize: 1521890 References: 1891 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1892 client_integration_test.go:438: Testing garbage collection...1893=== NAME TestNARDeduplicationMetadataUploadBug1894 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1895 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1896 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1897=== NAME TestOrphanedObjectsGCStressTest1898 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1899=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1900--- PASS: TestClientPushesUseOnePush (0.57s)19012026/10/25 17:21:09 INFO Received uploads request method=POST path=/1902=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19032026/10/25 17:21:09 INFO Received complete multipart upload request method=POST path=/1904=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19052026/10/25 17:21:09 INFO Received request for more parts method=POST path=/1906=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19072026/10/25 17:21:09 INFO Received uploads request method=POST path=/1908=== CONT TestIsValidUploadKey/nar_zst1909--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1910 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1911 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1912 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1913 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1914=== CONT TestIsValidUploadKey/nix-cache-info1915=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1916=== CONT TestIsValidUploadKey/traversal1917=== CONT TestIsValidUploadKey/unknown_type1918=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1919=== CONT TestIsValidUploadKey/empty_key1920=== CONT TestIsValidUploadKey/index.html1921=== CONT TestIsValidUploadKey/absolute1922=== CONT TestIsValidUploadKey/realisation_plus_in_output1923=== CONT TestIsValidUploadKey/traversal_nar1924=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1925=== CONT TestIsValidUploadKey/listing1926=== CONT TestIsValidUploadKey/realisation1927=== CONT TestIsValidUploadKey/nar_xz1928=== CONT TestIsValidUploadKey/build_log_plus_in_name1929=== CONT TestIsValidUploadKey/build_log_question_mark1930=== CONT TestIsValidUploadKey/build_log1931=== CONT TestIsValidUploadKey/build_log_home-manager_file1932=== CONT TestIsValidUploadKey/nar_plain1933=== CONT TestIsValidUploadKey/build_log_equals1934=== CONT TestIsValidUploadKey/narinfo1935=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1936--- PASS: TestIsValidUploadKey (0.00s)1937 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1938 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1939 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1940 --- PASS: TestIsValidUploadKey/traversal (0.00s)1941 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1942 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1943 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1944 --- PASS: TestIsValidUploadKey/index.html (0.00s)1945 --- PASS: TestIsValidUploadKey/absolute (0.00s)1946 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1947 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1948 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1949 --- PASS: TestIsValidUploadKey/listing (0.00s)1950 --- PASS: TestIsValidUploadKey/realisation (0.00s)1951 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1952 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1953 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1954 --- PASS: TestIsValidUploadKey/build_log (0.00s)1955 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1956 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1957 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1958 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1959=== NAME TestOrphanedObjectsGCStressTest1960 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion1961=== NAME TestNARDeduplicationMetadataUploadBug1962 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2960462443/001/store/98f03khnivn9l88hjznz0fy38zslqysf-file2.txt19632026/10/25 17:21:09 INFO Starting cleanup of old closures method=DELETE path=/api/closures19642026/10/25 17:21:09 INFO Garbage collection started19652026/10/25 17:21:09 INFO Aborted multipart uploads count=0 kept=019662026/10/25 17:21:09 INFO Aborted multipart uploads count=0 kept=019672026/10/25 17:21:09 WARN Force mode enabled - objects will be deleted immediately without grace period19682026/10/25 17:21:09 WARN Force mode enabled - objects will be deleted immediately without grace period19692026/10/25 17:21:09 INFO Received uploads request method=POST path=/api/pending_closures19702026/10/25 17:21:09 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=019712026/10/25 17:21:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19722026/10/25 17:21:09 INFO Vacuumed table table=pending_closures19732026/10/25 17:21:09 INFO Vacuumed table table=pending_objects19742026/10/25 17:21:09 INFO Vacuumed table table=multipart_uploads19752026/10/25 17:21:09 INFO Vacuumed table table=closures19762026/10/25 17:21:09 INFO Vacuumed table table=objects19772026/10/25 17:21:09 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=019782026/10/25 17:21:09 INFO Vacuumed table table=pending_closures19792026/10/25 17:21:09 INFO Vacuumed table table=pending_objects19802026/10/25 17:21:09 INFO Vacuumed table table=multipart_uploads19812026/10/25 17:21:09 INFO Vacuumed table table=closures19822026/10/25 17:21:09 INFO Vacuumed table table=objects19832026/10/25 17:21:09 INFO Received push request method=POST path=/api/pushes19842026/10/25 17:21:10 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19852026/10/25 17:21:10 WARN Failed to register uploaded object key=98f03khnivn9l88hjznz0fy38zslqysf.ls error="server returned 404: 404 page not found\n"19862026/10/25 17:21:10 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign19872026/10/25 17:21:10 INFO Signed narinfos id=2 count=119882026/10/25 17:21:10 INFO Uploading 1 narinfos19892026/10/25 17:21:10 INFO Received uploads request method=POST path=/api/pending_closures1990--- PASS: TestGCSweepDeliversEachKeyOnce (0.35s)1991=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true19922026/10/25 17:21:10 INFO Received uploads request method=POST path=/api/pending_closures19932026/10/25 17:21:10 INFO Received complete push request method=POST path=/api/pushes/2/complete19942026/10/25 17:21:10 WARN Failed to register uploaded object key=98f03khnivn9l88hjznz0fy38zslqysf.narinfo error="server returned 404: 404 page not found\n"19952026/10/25 17:21:10 INFO Completed push id=2 objects=3 duration=2.807385ms19962026/10/25 17:21:10 INFO Upload complete. (61ms)19972026/10/25 17:21:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1998=== NAME TestNARDeduplicationMetadataUploadBug1999 metadata_upload_test.go:76: Retrieved narinfo from S3:2000 StorePath: /build/TestNARDeduplicationMetadataUploadBug2960462443/001/store/98f03khnivn9l88hjznz0fy38zslqysf-file2.txt2001 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2002 Compression: zstd2003 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2004 NarSize: 1602005 References: 2006 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf20072026/10/25 17:21:10 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)20082026/10/25 17:21:10 INFO Uploading vj7jmd0pcprygjcanf861m472bfa8p3a-b (216B)20092026/10/25 17:21:10 INFO Uploading 8ih2lsq4nsdc9mrfbpfixi1n8yyqrh51-shared-dep (136B)2010 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2011 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2012 {"version":1,"root":{"type":"regular","size":44}}20132026/10/25 17:21:10 WARN Failed to register uploaded object key=4jabrs3jrjgcr8azksvlva70x4zbp4z0.ls error="server returned 404: 404 page not found\n"20142026/10/25 17:21:10 WARN Failed to register uploaded object key=8ih2lsq4nsdc9mrfbpfixi1n8yyqrh51.ls error="server returned 404: 404 page not found\n"20152026/10/25 17:21:10 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"20162026/10/25 17:21:10 WARN Failed to register uploaded object key=nar/0wwq9hwnd4yn90dh1fxmc467f2zzazcb5i7x8yglqsva8yn1wkv7.nar.zst error="server returned 404: 404 page not found\n"20172026/10/25 17:21:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20182026/10/25 17:21:10 WARN Failed to register uploaded object key=vj7jmd0pcprygjcanf861m472bfa8p3a.ls error="server returned 404: 404 page not found\n"20192026/10/25 17:21:10 INFO Signed narinfos id=1 count=220202026/10/25 17:21:10 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign20212026/10/25 17:21:10 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LmMxNzkxMWRiLWU4NGQtNGY4MC04OWI1LTIxZWM3MzAxZjUwM3gxNzkyOTQ4ODY3ODUwNTg2NTI5 parts=1020222026/10/25 17:21:10 INFO Signed narinfos id=2 count=220232026/10/25 17:21:10 INFO Uploading 4 narinfos20242026/10/25 17:21:10 INFO Received uploads request method=POST path=/api/pending_closures20252026/10/25 17:21:10 WARN Failed to register uploaded object key=8ih2lsq4nsdc9mrfbpfixi1n8yyqrh51.narinfo error="server returned 404: 404 page not found\n"2026--- PASS: TestNARDeduplicationMetadataUploadBug (0.65s)2027=== CONT TestPush_RejectsBadRequests/bad_root20282026/10/25 17:21:10 INFO Received push request method=POST path=/api/pushes20292026/10/25 17:21:10 WARN Failed to register uploaded object key=vj7jmd0pcprygjcanf861m472bfa8p3a.narinfo error="server returned 404: 404 page not found\n"2030=== CONT TestPush_RejectsBadRequests/root_not_in_objects20312026/10/25 17:21:10 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete20322026/10/25 17:21:10 INFO Received push request method=POST path=/api/pushes20332026/10/25 17:21:10 WARN Failed to register uploaded object key=4jabrs3jrjgcr8azksvlva70x4zbp4z0.narinfo error="server returned 404: 404 page not found\n"20342026/10/25 17:21:10 WARN Failed to register uploaded object key=8ih2lsq4nsdc9mrfbpfixi1n8yyqrh51.narinfo error="server returned 404: 404 page not found\n"2035=== CONT TestPush_RejectsBadRequests/no_roots20362026/10/25 17:21:10 INFO Received push request method=POST path=/api/pushes2037=== CONT TestPush_RejectsBadRequests/no_objects20382026/10/25 17:21:10 INFO Received push request method=POST path=/api/pushes2039=== CONT TestParseSingleRange/none2040=== CONT TestParseSingleRange/start_far_past_EOF2041=== CONT TestParseSingleRange/start_past_EOF2042=== CONT TestParseSingleRange/single_byte2043=== CONT TestParseSingleRange/suffix_exceeds_size2044=== CONT TestParseSingleRange/end_clamped_to_size2045=== CONT TestParseSingleRange/open-ended2046=== CONT TestParseSingleRange/multi-range_ignored2047=== CONT TestParseSingleRange/unknown_unit2048=== CONT TestParseSingleRange/malformed_no_dash2049=== CONT TestParseSingleRange/malformed_end_before_start2050=== CONT TestParseSingleRange/suffix2051=== CONT TestParseSingleRange/closed2052=== CONT TestParseSingleRange/malformed_both_empty2053=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale2054--- PASS: TestParseSingleRange (0.00s)2055 --- PASS: TestParseSingleRange/none (0.00s)2056 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2057 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2058 --- PASS: TestParseSingleRange/single_byte (0.00s)2059 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2060 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2061 --- PASS: TestParseSingleRange/open-ended (0.00s)2062 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2063 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2064 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2065 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2066 --- PASS: TestParseSingleRange/suffix (0.00s)2067 --- PASS: TestParseSingleRange/closed (0.00s)2068 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)20692026/10/25 17:21:10 INFO Completed upload id=2 objects=6 duration=4.593242ms20702026/10/25 17:21:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete2071=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh2072--- PASS: TestPushWaitsForSweepHoldingRow (0.82s)20732026/10/25 17:21:10 INFO Completed upload id=1 objects=6 duration=1.477993ms20742026/10/25 17:21:10 INFO Upload complete. (106ms)2075=== NAME TestClientFallsBackToClosures2076 client_pushes_test.go:112: Retrieved narinfo from S3:2077 StorePath: /build/TestClientFallsBackToClosures1663602114/001/store/8ih2lsq4nsdc9mrfbpfixi1n8yyqrh51-shared-dep2078 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2079 Compression: zstd2080 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822081 NarSize: 1362082 References: 2083 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2084 client_pushes_test.go:112: Retrieved narinfo from S3:2085 StorePath: /build/TestClientFallsBackToClosures1663602114/001/store/4jabrs3jrjgcr8azksvlva70x4zbp4z0-a2086 URL: nar/0wwq9hwnd4yn90dh1fxmc467f2zzazcb5i7x8yglqsva8yn1wkv7.nar.zst2087 Compression: zstd2088 NarHash: sha256:0wwq9hwnd4yn90dh1fxmc467f2zzazcb5i7x8yglqsva8yn1wkv72089 NarSize: 2162090 References: /build/TestClientFallsBackToClosures1663602114/001/store/8ih2lsq4nsdc9mrfbpfixi1n8yyqrh51-shared-dep2091 CA: text:sha256:0f9g16pw7wxnj9yhk8xxjf7s3ax5d8s7f3qzyavvsmqf1gwym8y52092 client_pushes_test.go:112: Retrieved narinfo from S3:2093 StorePath: /build/TestClientFallsBackToClosures1663602114/001/store/vj7jmd0pcprygjcanf861m472bfa8p3a-b2094 URL: nar/0wwq9hwnd4yn90dh1fxmc467f2zzazcb5i7x8yglqsva8yn1wkv7.nar.zst2095 Compression: zstd2096 NarHash: sha256:0wwq9hwnd4yn90dh1fxmc467f2zzazcb5i7x8yglqsva8yn1wkv72097 NarSize: 2162098 References: /build/TestClientFallsBackToClosures1663602114/001/store/8ih2lsq4nsdc9mrfbpfixi1n8yyqrh51-shared-dep2099 CA: text:sha256:0f9g16pw7wxnj9yhk8xxjf7s3ax5d8s7f3qzyavvsmqf1gwym8y52100--- PASS: TestPush_RejectsBadRequests (0.43s)2101 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2102 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2103 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2104 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)21052026/10/25 17:21:10 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"2106--- PASS: TestClientFallsBackToClosures (0.63s)2107=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2108=== CONT TestIsValidCachePath/short_hash2109=== CONT TestIsValidCachePath/leading_slash2110=== CONT TestIsValidCachePath/wrong_extension2111=== CONT TestIsValidCachePath/random_path2112=== CONT TestIsValidCachePath/invalid_char_u2113=== CONT TestIsValidCachePath/ls2114=== CONT TestIsValidCachePath/nar_uncompressed2115=== CONT TestIsValidCachePath/log2116=== CONT TestIsValidCachePath/nar_xz2117=== CONT TestIsValidCachePath/empty2118=== CONT TestIsValidCachePath/nar_zst2119=== CONT TestIsValidCachePath/traversal_in_middle2120=== CONT TestIsValidCachePath/traversal_parent2121=== CONT TestIsValidCachePath/nix-cache-info2122=== CONT TestIsValidCachePath/index.html2123=== CONT TestIsValidCachePath/realisation2124=== CONT TestIsValidCachePath/narinfo2125=== CONT TestIsValidCachePath/invalid_char_e2126=== CONT TestIsValidCachePath/nar_bz22127=== CONT TestClientErrorHandling/InvalidAuthToken2128--- PASS: TestIsValidCachePath (0.00s)2129 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2130 --- PASS: TestIsValidCachePath/short_hash (0.00s)2131 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2132 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2133 --- PASS: TestIsValidCachePath/random_path (0.00s)2134 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2135 --- PASS: TestIsValidCachePath/ls (0.00s)2136 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2137 --- PASS: TestIsValidCachePath/log (0.00s)2138 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2139 --- PASS: TestIsValidCachePath/empty (0.00s)2140 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2141 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2142 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2143 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2144 --- PASS: TestIsValidCachePath/index.html (0.00s)2145 --- PASS: TestIsValidCachePath/realisation (0.00s)2146 --- PASS: TestIsValidCachePath/narinfo (0.00s)2147 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2148 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2149--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.41s)2150=== CONT TestClientErrorHandling/ServerNotAvailable21512026/10/25 17:21:10 INFO Received uploads request method=POST path=/api/pending_closures21522026/10/25 17:21:10 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/present2153--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.05s)2154=== CONT TestClientErrorHandling/InvalidStorePath2155=== NAME TestOrphanedObjectsGCStressTest2156 orphaned_objects_gc_test.go:503: Stress test completed successfully:2157 orphaned_objects_gc_test.go:504: - Active objects preserved: 202158 orphaned_objects_gc_test.go:505: - Objects deleted: 2102159 orphaned_objects_gc_test.go:506: - Total GC'd: 21021602026/10/25 17:21:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21612026/10/25 17:21:10 WARN Request failed, retrying attempt=2 backoff=205.813988ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2162=== CONT TestCacheConfigHandler/no_signing_keys2163--- PASS: TestOrphanedObjectsGCStressTest (3.14s)2164=== CONT TestCacheConfigHandler/full_config,_no_issuer2165=== CONT TestCacheConfigHandler/no_cache_url_configured2166=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2167=== CONT TestService_RequireScope_OIDC/builder_may_write2168--- PASS: TestCacheConfigHandler (0.00s)2169 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2170 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2171 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2172 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2173=== CONT TestService_RequireScope_OIDC/reader_may_read2174=== CONT TestService_RequireScope_OIDC/static_token_may_admin2175=== CONT TestService_RequireScope_OIDC/writer_implies_read21762026/10/25 17:21:10 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LjIyYTdlZGIzLTZiMDgtNDFiMS04ZjZlLWVhYjliOTIyNmRhNHgxNzkyOTQ4ODY5ODQ2NTY0NjA1 parts=102177=== CONT TestService_RequireScope_OIDC/reader_may_not_write2178=== CONT TestService_RequireScope_OIDC/static_token_may_write2179=== CONT TestService_RequireScope_OIDC/ops_may_not_write2180=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2181=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2182=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2183=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2184=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2185=== CONT TestService_RequireScope_OIDC/ops_may_admin2186=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read21872026/10/25 17:21:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21882026/10/25 17:21:10 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]2189=== CONT TestResolveDBConnectionString/flag_wins2190=== CONT TestResolveDBConnectionString/nothing_configured2191=== CONT TestResolveDBConnectionString/missing_file_is_an_error2192=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2193=== CONT TestResolveDBConnectionString/file_when_flag_empty2194=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete2195--- PASS: TestResolveDBConnectionString (0.00s)2196 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2197 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2198 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2199 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2200 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)22012026/10/25 17:21:10 INFO Completed upload id=1 objects=2 duration=3.28953ms22022026/10/25 17:21:10 INFO Received uploads request method=POST path=/api/pending_closures22032026/10/25 17:21:10 INFO Received uploads request method=POST path=/api/pending_closures22042026/10/25 17:21:10 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo22052026/10/25 17:21:10 WARN Found objects in DB but missing from S3, will re-upload count=12206--- PASS: TestService_RequireScope_OIDC (0.45s)2207 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.01s)2208 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2209 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2210 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2211 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2212 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2213 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2214 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2215 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2216 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2217 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2218 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2219 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2220 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)22212026/10/25 17:21:10 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22222026/10/25 17:21:10 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete22232026/10/25 17:21:10 INFO Completed upload id=3 objects=2 duration=2.829466ms2224--- PASS: TestService_verifyS3Integrity (0.85s)2225=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark22262026/10/25 17:21:10 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2227=== CONT TestGCEndsOnShutdown/before_the_run22282026/10/25 17:21:10 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02229=== CONT TestProxyWriteTimeout/1_GiB_nar22302026/10/25 17:21:10 INFO Received create pin request method=POST path=/api/pins/myapp2231=== CONT TestProxyWriteTimeout/unknown_size2232=== CONT TestProxyWriteTimeout/narinfo2233=== CONT TestProxyWriteTimeout/10_GiB_nar2234=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2235--- PASS: TestProxyWriteTimeout (0.00s)2236 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2237 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2238 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2239 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2240=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2241=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected22422026/10/25 17:21:10 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC3592547463/001/store/xw70pqb6fngg93ngk9zv4438csvh1f6m-pinned-file.txt narinfo_key=xw70pqb6fngg93ngk9zv4438csvh1f6m.narinfo22432026/10/25 17:21:10 INFO Starting cleanup of old closures method=DELETE path=/api/closures22442026/10/25 17:21:10 WARN Authentication failed token_preview=eyJhbGciOi...SiMddyNUfw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2245=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected22462026/10/25 17:21:10 INFO Garbage collection started22472026/10/25 17:21:10 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]2248=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows22492026/10/25 17:21:10 INFO Aborted multipart uploads count=0 kept=022502026/10/25 17:21:10 WARN Force mode enabled - objects will be deleted immediately without grace period22512026/10/25 17:21:10 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=022522026/10/25 17:21:10 INFO Vacuumed table table=pending_closures22532026/10/25 17:21:10 INFO Vacuumed table table=pending_objects22542026/10/25 17:21:10 INFO Vacuumed table table=multipart_uploads2255--- PASS: TestService_AuthMiddleware_OIDC (0.58s)2256 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2257 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2258 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)2259 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)22602026/10/25 17:21:10 INFO Vacuumed table table=closures22612026-10-25 17:21:10.533 UTC [173] LOG: checkpoints are occurring too frequently (9 seconds apart)22622026-10-25 17:21:10.533 UTC [173] HINT: Consider increasing the configuration parameter "max_wal_size".22632026-10-25 17:21:10.533 UTC [173] LOG: checkpoint starting: wal22642026/10/25 17:21:10 WARN Request failed, retrying attempt=3 backoff=404.808766ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22652026/10/25 17:21:10 INFO Vacuumed table table=objects22662026/10/25 17:21:10 INFO Aborted multipart uploads count=0 kept=022672026/10/25 17:21:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22682026/10/25 17:21:10 WARN Force mode enabled - objects will be deleted immediately without grace period22692026/10/25 17:21:10 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:45219/bucket104/?delete=\": context canceled"22702026/10/25 17:21:10 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LmNlMzZjMmU2LTMyMjAtNDJiOC05MzU5LWMxMjJkY2EyZjNmNngxNzkyOTQ4ODY3ODUwNzUzNDMx parts=102271=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check22722026/10/25 17:21:10 INFO Aborted multipart uploads count=0 kept=022732026/10/25 17:21:10 WARN Force mode enabled - objects will be deleted immediately without grace period2274--- PASS: TestDeleteClosuresRacingPins (1.69s)2275--- PASS: TestGCEndsOnShutdown (0.00s)2276 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.24s)2277 --- PASS: TestGCEndsOnShutdown/before_the_run (0.20s)2278 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.26s)22792026/10/25 17:21:10 INFO Received uploads request method=POST path=/api/pending_closures22802026/10/25 17:21:10 INFO Aborted multipart uploads count=0 kept=022812026/10/25 17:21:10 WARN Force mode enabled - objects will be deleted immediately without grace period22822026/10/25 17:21:10 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=022832026/10/25 17:21:10 INFO Vacuumed table table=pending_closures22842026/10/25 17:21:10 INFO Vacuumed table table=pending_objects22852026/10/25 17:21:10 INFO Vacuumed table table=multipart_uploads22862026/10/25 17:21:10 INFO Vacuumed table table=closures22872026/10/25 17:21:10 INFO Vacuumed table table=objects22882026/10/25 17:21:10 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LjhhMWRmODg0LWU3YWItNGI0Ny1iYmM3LWUxOGEzNjBkZmRiYXgxNzkyOTQ4ODcwMTk3MzUzNzc3 error="Access Denied"22892026/10/25 17:21:10 WARN keeping failed pending closure for cleanup to retry the abort id=12290--- PASS: TestPendingClosureFailureTracksEveryUpload (0.00s)2291 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (0.69s)2292 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (0.72s)2293--- PASS: TestConnectSerialisesConcurrentMigrations (1.15s)22942026/10/25 17:21:10 INFO Received uploads request method=POST path=/api/pending_closures22952026/10/25 17:21:10 INFO Aborted multipart uploads count=0 kept=022962026/10/25 17:21:10 WARN Force mode enabled - objects will be deleted immediately without grace period22972026/10/25 17:21:10 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=022982026/10/25 17:21:10 INFO Vacuumed table table=pending_closures22992026/10/25 17:21:10 INFO Vacuumed table table=pending_objects23002026/10/25 17:21:10 INFO Vacuumed table table=multipart_uploads23012026/10/25 17:21:10 INFO Vacuumed table table=closures23022026/10/25 17:21:10 INFO Vacuumed table table=objects2303--- PASS: TestPendingClosureWriteTimeout (0.00s)2304 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2305 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2306 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2307 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.02s)2308--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2309 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.69s)2310 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.72s)2311--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2312 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.24s)2313 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.21s)23142026/10/25 17:21:10 INFO lead: released remote=192.0.2.1:12342315--- PASS: TestLeadEndsOnShutdown (1.38s)23162026/10/25 17:21:10 WARN Request failed, retrying attempt=4 backoff=853.936444ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23172026/10/25 17:21:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23182026/10/25 17:21:11 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=M2U1M2ZjNDctYmQxNC00ODZmLTgyMjItMDI1YWMyNmZjM2E2LjBkMGI4YmM5LTAzNjktNDBjMS1hZTcyLWFjNDJhYzk3NjAwZHgxNzkyOTQ4ODY3ODUwMjU0NDg2 parts=1023192026-10-25 17:21:11.086 UTC [648] ERROR: could not obtain lock on row in relation "closures"23202026-10-25 17:21:11.086 UTC [648] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23212026/10/25 17:21:11 INFO lead: released remote=192.0.2.1:123423222026-10-25 17:21:11.086 UTC [648] ERROR: could not obtain lock on row in relation "closures"23232026-10-25 17:21:11.086 UTC [648] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23242026-10-25 17:21:11.087 UTC [648] ERROR: could not obtain lock on row in relation "closures"23252026-10-25 17:21:11.087 UTC [648] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23262026-10-25 17:21:11.087 UTC [648] ERROR: could not obtain lock on row in relation "closures"23272026-10-25 17:21:11.087 UTC [648] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23282026-10-25 17:21:11.088 UTC [648] ERROR: could not obtain lock on row in relation "closures"23292026-10-25 17:21:11.088 UTC [648] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT2330--- PASS: TestPush_RootsAreLockedInByteOrder (3.93s)23312026/10/25 17:21:11 INFO lead: acquired remote=192.0.2.1:123423322026/10/25 17:21:11 WARN Request failed, retrying attempt=5 backoff=1.676702446s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23332026/10/25 17:21:11 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02334=== NAME TestClientIntegration2335 client_integration_test.go:445: Objects in database after GC:2336 client_integration_test.go:445: Successfully deleted all objects with GC --force2337--- PASS: TestClientIntegration (3.00s)23382026/10/25 17:21:12 INFO lead: released remote=192.0.2.1:12342339--- PASS: TestLeadElectsOneAndHandsOver (2.64s)2340=== NAME TestPinProtectsFromGC2341 client_integration_test.go:976: Pin successfully protected closure from garbage collection2342--- PASS: TestPinProtectsFromGC (4.86s)2343--- PASS: TestConnectWaitsForAPeerMigration (5.14s)2344--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.58s)23452026/10/25 17:21:13 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23462026/10/25 17:21:13 WARN Request failed, retrying attempt=2 backoff=196.803605ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23472026/10/25 17:21:13 WARN Request failed, retrying attempt=3 backoff=406.269061ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23482026/10/25 17:21:14 WARN Request failed, retrying attempt=4 backoff=801.39812ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23492026/10/25 17:21:14 WARN Rate limiter enabled after throttle name=s3-test rate=523502026/10/25 17:21:14 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2351=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2352 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102353 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002354--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.70s)23552026/10/25 17:21:14 INFO Aborted multipart uploads count=1 kept=023562026/10/25 17:21:14 INFO Received cleanup request method=DELETE path=/api/pending_closures23572026/10/25 17:21:14 INFO Aborted multipart uploads count=1 kept=02358--- PASS: TestPendingCleanupUsesOneCutoff (6.32s)23592026/10/25 17:21:15 WARN Request failed, retrying attempt=5 backoff=1.626766461s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23602026/10/25 17:21:16 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"23612026/10/25 17:21:16 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-config23622026/10/25 17:21:16 WARN Request failed, retrying attempt=2 backoff=184.312889ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23632026/10/25 17:21:16 WARN Request failed, retrying attempt=3 backoff=410.006355ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23642026/10/25 17:21:17 WARN Request failed, retrying attempt=4 backoff=786.554444ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23652026/10/25 17:21:18 WARN Request failed, retrying attempt=5 backoff=1.728121433s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23662026/10/25 17:21:19 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_closures23672026/10/25 17:21:19 WARN Request failed, retrying attempt=2 backoff=212.891627ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23682026/10/25 17:21:20 WARN Request failed, retrying attempt=3 backoff=402.134461ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23692026/10/25 17:21:20 WARN Request failed, retrying attempt=4 backoff=868.402192ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23702026/10/25 17:21:21 WARN Request failed, retrying attempt=5 backoff=1.664761229s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2371--- PASS: TestClientErrorHandling (0.00s)2372 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.33s)2373 --- PASS: TestClientErrorHandling/InvalidStorePath (0.24s)2374 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.98s)2375--- PASS: TestUploadHandlersRejectOversizedBody (0.49s)2376 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.97s)2377 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.96s)2378 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (14.41s)2379PASS2380{"timestamp":"2026-10-25T17:21:24.26229773Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:37612","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2386,"threadName":"rustfs-worker","threadId":"ThreadId(208)"}2381{"timestamp":"2026-10-25T17:21:24.262380191Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:38258","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2386,"threadName":"rustfs-worker","threadId":"ThreadId(196)"}2382{"timestamp":"2026-10-25T17:21:24.262420551Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:38074","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2386,"threadName":"rustfs-worker","threadId":"ThreadId(200)"}2383{"timestamp":"2026-10-25T17:21:24.262524332Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:37722","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2386,"threadName":"rustfs-worker","threadId":"ThreadId(203)"}23842026-10-25 17:21:24.622 UTC [168] LOG: received smart shutdown request23852026-10-25 17:21:24.627 UTC [168] LOG: background worker "logical replication launcher" (PID 178) exited with exit code 123862026-10-25 17:21:25.423 UTC [173] LOG: checkpoint complete: wrote 8596 buffers (52.5%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=14.233 s, sync=0.612 s, total=14.891 s; sync files=37080, longest=0.004 s, average=0.001 s; distance=533217 kB, estimate=533217 kB; lsn=0/229EA500, redo lsn=0/2201E43023872026-10-25 17:21:25.428 UTC [173] LOG: shutting down23882026-10-25 17:21:25.429 UTC [173] LOG: checkpoint starting: shutdown immediate23892026-10-25 17:21:25.519 UTC [173] LOG: checkpoint complete: wrote 1689 buffers (10.3%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.026 s, sync=0.063 s, total=0.091 s; sync files=536, longest=0.002 s, average=0.001 s; distance=10032 kB, estimate=480899 kB; lsn=0/229EA578, redo lsn=0/229EA57823902026-10-25 17:21:25.600 UTC [168] LOG: database system is shut down2391Running OIDC tests...2392=== RUN TestAudienceForIssuer2393=== PAUSE TestAudienceForIssuer2394=== RUN TestHTTPClientForHasTimeouts2395=== PAUSE TestHTTPClientForHasTimeouts2396=== RUN TestGlobMatch2397=== PAUSE TestGlobMatch2398=== RUN TestValidateToken_ValidToken2399=== PAUSE TestValidateToken_ValidToken2400=== RUN TestValidateToken_WrongAudience2401=== PAUSE TestValidateToken_WrongAudience2402=== RUN TestValidateToken_Expired2403=== PAUSE TestValidateToken_Expired2404=== RUN TestValidateToken_BoundClaimsMismatch2405=== PAUSE TestValidateToken_BoundClaimsMismatch2406=== RUN TestValidateToken_BoundSubjectMismatch2407=== PAUSE TestValidateToken_BoundSubjectMismatch2408=== RUN TestValidateToken_MultipleProviders2409=== PAUSE TestValidateToken_MultipleProviders2410=== RUN TestValidateToken_NoMatchingProvider2411=== PAUSE TestValidateToken_NoMatchingProvider2412=== RUN TestValidateToken_KubernetesServiceAccount2413=== PAUSE TestValidateToken_KubernetesServiceAccount2414=== RUN TestNewValidator_KubernetesRequiresCA2415=== PAUSE TestNewValidator_KubernetesRequiresCA2416=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2417=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2418=== RUN TestPins_ReservedForMatchingRule2419=== PAUSE TestPins_ReservedForMatchingRule2420=== RUN TestPins_TopLevelShorthand2421=== PAUSE TestPins_TopLevelShorthand2422=== RUN TestPins_ConfigValidation2423=== PAUSE TestPins_ConfigValidation2424=== RUN TestScopes_LegacyProviderDefaultsToWrite2425=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2426=== RUN TestScopes_Rules2427=== PAUSE TestScopes_Rules2428=== RUN TestScopes_ConfigValidation2429=== PAUSE TestScopes_ConfigValidation2430=== CONT TestAudienceForIssuer2431=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2432--- PASS: TestAudienceForIssuer (0.00s)2433=== CONT TestValidateToken_NoMatchingProvider2434=== CONT TestScopes_LegacyProviderDefaultsToWrite2435=== CONT TestScopes_ConfigValidation2436=== CONT TestScopes_Rules2437=== CONT TestPins_ConfigValidation2438=== CONT TestPins_ReservedForMatchingRule2439=== CONT TestValidateToken_Expired2440=== CONT TestNewValidator_KubernetesRequiresCA2441=== CONT TestValidateToken_BoundSubjectMismatch2442--- PASS: TestPins_ConfigValidation (0.00s)2443=== CONT TestValidateToken_BoundClaimsMismatch2444=== CONT TestValidateToken_MultipleProviders2445=== CONT TestValidateToken_KubernetesServiceAccount2446=== CONT TestGlobMatch2447=== RUN TestGlobMatch/foo_foo2448=== CONT TestValidateToken_WrongAudience2449=== PAUSE TestGlobMatch/foo_foo2450=== RUN TestGlobMatch/foo_bar2451=== PAUSE TestGlobMatch/foo_bar2452=== RUN TestGlobMatch/*_2453=== PAUSE TestGlobMatch/*_2454=== RUN TestGlobMatch/*_anything2455=== CONT TestHTTPClientForHasTimeouts2456=== CONT TestValidateToken_ValidToken2457=== CONT TestPins_TopLevelShorthand2458--- PASS: TestScopes_ConfigValidation (0.00s)2459=== PAUSE TestGlobMatch/*_anything2460=== RUN TestGlobMatch/foo*_foo2461=== PAUSE TestGlobMatch/foo*_foo2462=== RUN TestGlobMatch/foo*_foobar2463=== PAUSE TestGlobMatch/foo*_foobar2464=== RUN TestGlobMatch/foo*_bar2465=== PAUSE TestGlobMatch/foo*_bar2466=== RUN TestGlobMatch/*bar_bar2467=== PAUSE TestGlobMatch/*bar_bar2468=== RUN TestGlobMatch/*bar_foobar2469=== PAUSE TestGlobMatch/*bar_foobar2470=== RUN TestGlobMatch/*bar_foo2471=== PAUSE TestGlobMatch/*bar_foo2472=== RUN TestGlobMatch/foo*bar_foobar2473=== PAUSE TestGlobMatch/foo*bar_foobar2474=== RUN TestGlobMatch/foo*bar_foo123bar2475=== PAUSE TestGlobMatch/foo*bar_foo123bar2476=== RUN TestGlobMatch/foo*bar_foobarbaz2477=== PAUSE TestGlobMatch/foo*bar_foobarbaz2478=== RUN TestGlobMatch/*/*_foo/bar2479=== PAUSE TestGlobMatch/*/*_foo/bar2480=== RUN TestGlobMatch/*/*_foo2481=== PAUSE TestGlobMatch/*/*_foo2482=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2483=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2484=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02485=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02486=== RUN TestGlobMatch/refs/*/main_refs/heads/main2487=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2488=== RUN TestGlobMatch/fo?_foo2489=== PAUSE TestGlobMatch/fo?_foo2490=== RUN TestGlobMatch/fo?_fo2491=== PAUSE TestGlobMatch/fo?_fo2492=== RUN TestGlobMatch/fo?_fooo2493=== PAUSE TestGlobMatch/fo?_fooo2494=== RUN TestGlobMatch/?oo_foo2495=== PAUSE TestGlobMatch/?oo_foo2496=== RUN TestGlobMatch/?oo_boo2497=== PAUSE TestGlobMatch/?oo_boo2498=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2499=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2500=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2501=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2502=== CONT TestGlobMatch/*_2503=== CONT TestGlobMatch/foo*bar_foo123bar2504=== CONT TestGlobMatch/foo*bar_foobarbaz2505=== CONT TestGlobMatch/foo*bar_foobar2506=== CONT TestGlobMatch/foo*_foobar2507=== CONT TestGlobMatch/*/*_foo/bar2508=== CONT TestGlobMatch/*bar_foo2509=== CONT TestGlobMatch/fo?_foo2510=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2511=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2512=== CONT TestGlobMatch/?oo_boo2513=== CONT TestGlobMatch/foo*_bar2514=== CONT TestGlobMatch/*bar_foobar2515=== CONT TestGlobMatch/refs/*/main_refs/heads/main2516=== CONT TestGlobMatch/foo*_foo2517=== CONT TestGlobMatch/*_anything2518=== CONT TestGlobMatch/foo_bar2519=== CONT TestGlobMatch/foo_foo2520=== CONT TestGlobMatch/?oo_foo2521=== CONT TestGlobMatch/fo?_fooo2522=== CONT TestGlobMatch/*bar_bar2523=== CONT TestGlobMatch/fo?_fo2524=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2525=== CONT TestGlobMatch/*/*_foo2526=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02527--- PASS: TestGlobMatch (0.00s)2528 --- PASS: TestGlobMatch/*_ (0.00s)2529 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2530 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2531 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2532 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2533 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2534 --- PASS: TestGlobMatch/*bar_foo (0.00s)2535 --- PASS: TestGlobMatch/fo?_foo (0.00s)2536 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2537 --- PASS: TestGlobMatch/?oo_boo (0.00s)2538 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2539 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2540 --- PASS: TestGlobMatch/foo*_bar (0.00s)2541 --- PASS: TestGlobMatch/foo*_foo (0.00s)2542 --- PASS: TestGlobMatch/*_anything (0.00s)2543 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2544 --- PASS: TestGlobMatch/?oo_foo (0.00s)2545 --- PASS: TestGlobMatch/foo_bar (0.00s)2546 --- PASS: TestGlobMatch/foo_foo (0.00s)2547 --- PASS: TestGlobMatch/*bar_bar (0.00s)2548 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2549 --- PASS: TestGlobMatch/fo?_fo (0.00s)2550 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2551 --- PASS: TestGlobMatch/*/*_foo (0.00s)2552 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)25532026/10/25 17:21:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39293/oidc2554--- PASS: TestScopes_Rules (0.08s)25552026/10/25 17:21:28 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12325562026/10/25 17:21:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37567/oidc2557--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.10s)25582026/10/25 17:21:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32779/oidc2559--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.11s)2560--- PASS: TestValidateToken_Expired (0.11s)25612026/10/25 17:21:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39699/oidc2562--- PASS: TestPins_TopLevelShorthand (0.13s)25632026/10/25 17:21:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45023/oidc2564--- PASS: TestValidateToken_ValidToken (0.14s)25652026/10/25 17:21:28 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44023/oidc2566--- PASS: TestPins_ReservedForMatchingRule (0.19s)25672026/10/25 17:21:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35423/oidc25682026/10/25 17:21:29 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:46339/oidc2569--- PASS: TestValidateToken_BoundClaimsMismatch (0.20s)25702026/10/25 17:21:29 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:32941/oidc2571--- PASS: TestHTTPClientForHasTimeouts (0.20s)2572--- PASS: TestValidateToken_MultipleProviders (0.21s)25732026/10/25 17:21:29 http: TLS handshake error from 127.0.0.1:46112: remote error: tls: bad certificate2574--- PASS: TestNewValidator_KubernetesRequiresCA (0.23s)25752026/10/25 17:21:29 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:35895/oidc2576--- PASS: TestValidateToken_NoMatchingProvider (0.25s)25772026/10/25 17:21:29 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:362872578--- PASS: TestValidateToken_KubernetesServiceAccount (0.28s)25792026/10/25 17:21:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33247/oidc2580--- PASS: TestValidateToken_WrongAudience (0.29s)25812026/10/25 17:21:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37259/oidc2582--- PASS: TestValidateToken_BoundSubjectMismatch (0.48s)2583PASS2584Running hook tests...2585=== RUN TestSendPathsEmpty2586=== PAUSE TestSendPathsEmpty2587=== RUN TestQueueEnqueueAndFetch2588=== PAUSE TestQueueEnqueueAndFetch2589=== RUN TestQueueDeduplication2590=== PAUSE TestQueueDeduplication2591=== RUN TestQueueRemove2592=== PAUSE TestQueueRemove2593=== RUN TestQueueFetchBatchLimit2594=== PAUSE TestQueueFetchBatchLimit2595=== RUN TestQueueRetryMovesToBack2596=== PAUSE TestQueueRetryMovesToBack2597=== RUN TestQueueFetchRemoveLifecycle2598=== PAUSE TestQueueFetchRemoveLifecycle2599=== RUN TestQueueConcurrentWriters2600=== PAUSE TestQueueConcurrentWriters2601=== RUN TestQueueEnqueueWaitsOutSlowWriter2602=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2603=== RUN TestQueueRemoveLargeClosure2604=== PAUSE TestQueueRemoveLargeClosure2605=== RUN TestServerClientIntegration2606--- PASS: TestServerClientIntegration (0.00s)2607=== RUN TestServerQueueError26082026/10/25 17:21:30 ERROR Failed to queue paths error="permission denied" count=12609--- PASS: TestServerQueueError (0.00s)2610=== RUN TestServerRefusesOversizedAndNonStoreRequests2611=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2612=== RUN TestGetListenerSocketActivation2613 server_test.go:329: === RUN TestGetListenerSocketActivation2614 --- PASS: TestGetListenerSocketActivation (0.00s)2615 PASS2616 2617--- PASS: TestGetListenerSocketActivation (1.02s)2618=== RUN TestServerStalledClientDoesNotBlockShutdown2619=== PAUSE TestServerStalledClientDoesNotBlockShutdown2620=== RUN TestServerBacksOffOnAcceptErrors2621=== PAUSE TestServerBacksOffOnAcceptErrors2622=== RUN TestDrainIsolatesPoisonPath2623=== PAUSE TestDrainIsolatesPoisonPath2624=== RUN TestRunNotBlockedByPoisonHead2625=== PAUSE TestRunNotBlockedByPoisonHead2626=== RUN TestDrainGivesUpWhenServerDown2627=== PAUSE TestDrainGivesUpWhenServerDown2628=== RUN TestFailedPathPrunedByLaterClosure2629=== PAUSE TestFailedPathPrunedByLaterClosure2630=== RUN TestWorkerUploadsAndRemoves2631=== PAUSE TestWorkerUploadsAndRemoves2632=== RUN TestWorkerSkipsGCdPaths2633=== PAUSE TestWorkerSkipsGCdPaths2634=== RUN TestWorkerPrunesClosureDeps2635=== PAUSE TestWorkerPrunesClosureDeps2636=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2637=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2638=== RUN TestDrainTimeout2639=== PAUSE TestDrainTimeout2640=== RUN TestDrainTimeoutDuringIsolation2641=== PAUSE TestDrainTimeoutDuringIsolation2642=== RUN TestShutdownFinishesInFlightPush2643=== PAUSE TestShutdownFinishesInFlightPush2644=== RUN TestWorkerRemoveFailureIsNotProgress2645=== PAUSE TestWorkerRemoveFailureIsNotProgress2646=== RUN TestWorkerKeepsPathItCannotStat2647=== PAUSE TestWorkerKeepsPathItCannotStat2648=== CONT TestQueueRemove2649=== CONT TestDrainIsolatesPoisonPath2650=== CONT TestQueueRemoveLargeClosure2651=== CONT TestWorkerUploadsAndRemoves2652=== CONT TestWorkerRemoveFailureIsNotProgress2653=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2654=== CONT TestShutdownFinishesInFlightPush2655=== RUN TestShutdownFinishesInFlightPush/completes2656=== CONT TestDrainTimeoutDuringIsolation2657=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2658=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2659=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2660=== CONT TestWorkerKeepsPathItCannotStat2661=== CONT TestQueueFetchRemoveLifecycle2662=== CONT TestQueueConcurrentWriters2663=== CONT TestQueueEnqueueWaitsOutSlowWriter2664=== CONT TestQueueRetryMovesToBack2665=== CONT TestServerRefusesOversizedAndNonStoreRequests2666=== CONT TestQueueFetchBatchLimit2667=== CONT TestQueueEnqueueAndFetch2668=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2669=== CONT TestQueueDeduplication2670=== CONT TestWorkerSkipsGCdPaths2671=== CONT TestFailedPathPrunedByLaterClosure2672=== CONT TestServerStalledClientDoesNotBlockShutdown2673=== CONT TestDrainGivesUpWhenServerDown2674=== CONT TestServerBacksOffOnAcceptErrors2675=== CONT TestWorkerPrunesClosureDeps2676=== CONT TestDrainTimeout2677=== PAUSE TestShutdownFinishesInFlightPush/completes2678=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2679=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2680=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline26812026/10/25 17:21:31 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2682=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2683=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2684=== CONT TestRunNotBlockedByPoisonHead2685=== CONT TestSendPathsEmpty26862026/10/25 17:21:31 ERROR Refusing path outside the store path=/nix/store store=/nix/store2687=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short2688=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2689--- PASS: TestSendPathsEmpty (0.00s)2690=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2691=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2692=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline26932026/10/25 17:21:31 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store26942026/10/25 17:21:31 ERROR Accept failed error="too many open files"26952026/10/25 17:21:31 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store26962026/10/25 17:21:31 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store26972026/10/25 17:21:31 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26982026/10/25 17:21:31 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26992026/10/25 17:21:31 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store27002026/10/25 17:21:31 ERROR Accept failed error="too many open files"27012026/10/25 17:21:31 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store27022026/10/25 17:21:31 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store27032026/10/25 17:21:31 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store27042026/10/25 17:21:31 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store27052026/10/25 17:21:31 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store27062026/10/25 17:21:31 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store27072026/10/25 17:21:31 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store27082026/10/25 17:21:31 ERROR Failed to decode request error="unexpected EOF"2709--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2710=== CONT TestShutdownFinishesInFlightPush/completes27112026/10/25 17:21:31 ERROR Accept failed error="too many open files"27122026/10/25 17:21:31 ERROR Accept failed error="too many open files"27132026/10/25 17:21:31 INFO Uploading batch count=427142026/10/25 17:21:31 ERROR Upload failed error="upload failed" count=427152026/10/25 17:21:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2386027335/002/bbb2716--- PASS: TestQueueFetchRemoveLifecycle (0.06s)2717=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout27182026/10/25 17:21:31 INFO Uploading batch count=427192026/10/25 17:21:31 ERROR Upload failed error="upload failed" count=427202026/10/25 17:21:31 INFO Uploading batch count=427212026/10/25 17:21:31 ERROR Upload failed error="upload failed" count=427222026/10/25 17:21:31 INFO Uploading batch count=227232026/10/25 17:21:31 ERROR Upload failed error="upload failed" count=227242026/10/25 17:21:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2309858780/002/a27252026/10/25 17:21:31 INFO Uploading batch count=227262026/10/25 17:21:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2309858780/002/b27272026/10/25 17:21:31 INFO Upload queue status pending=227282026/10/25 17:21:31 INFO Upload queue status pending=327292026/10/25 17:21:31 INFO Uploading batch count=127302026/10/25 17:21:31 ERROR Upload failed error="upload failed" count=127312026/10/25 17:21:31 INFO Upload queue status pending=227322026/10/25 17:21:31 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths705179667/002/nonexistent27332026/10/25 17:21:31 INFO Uploading batch count=227342026/10/25 17:21:31 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2276268231/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2276268231/002/locked/aaa: permission denied"27352026/10/25 17:21:31 INFO Uploading batch count=227362026/10/25 17:21:31 INFO Uploading batch count=227372026/10/25 17:21:31 INFO Uploading batch count=127382026/10/25 17:21:31 ERROR Upload failed error="upload failed" count=127392026/10/25 17:21:31 INFO Uploading batch count=127402026/10/25 17:21:31 INFO Upload queue status pending=227412026/10/25 17:21:31 INFO Uploading batch count=227422026/10/25 17:21:31 ERROR Upload failed error="upload failed" count=227432026/10/25 17:21:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2309858780/002/c27442026/10/25 17:21:31 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2276268231/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2276268231/002/locked/aaa: permission denied"27452026/10/25 17:21:31 INFO Uploading batch count=127462026/10/25 17:21:31 INFO Upload queue status pending=327472026/10/25 17:21:31 INFO Upload queue status pending=227482026/10/25 17:21:31 INFO Uploading batch count=127492026/10/25 17:21:31 ERROR Upload failed error="upload failed" count=12750--- PASS: TestQueueRemove (0.08s)2751=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch27522026/10/25 17:21:31 INFO Uploading batch count=127532026/10/25 17:21:31 ERROR Upload failed error="upload failed" count=127542026/10/25 17:21:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2309858780/002/d27552026/10/25 17:21:31 INFO Uploading batch count=12756=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths2757--- PASS: TestQueueEnqueueAndFetch (0.08s)27582026/10/25 17:21:31 INFO Uploading batch count=227592026/10/25 17:21:31 ERROR Accept failed error="too many open files"27602026/10/25 17:21:31 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2276268231/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2276268231/002/locked/aaa: permission denied"2761--- PASS: TestQueueFetchBatchLimit (0.08s)2762=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27632026/10/25 17:21:31 INFO Uploading batch count=127642026/10/25 17:21:31 ERROR Upload failed error="upload failed" count=127652026/10/25 17:21:31 INFO Uploading batch count=227662026/10/25 17:21:31 ERROR Upload failed error="upload failed" count=227672026/10/25 17:21:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2309858780/002/e2768--- PASS: TestQueueDeduplication (0.08s)27692026/10/25 17:21:31 ERROR Drain finished with paths left in queue remaining=127702026/10/25 17:21:31 INFO Upload queue status pending=227712026/10/25 17:21:31 ERROR Drain finished with paths left in queue remaining=127722026/10/25 17:21:31 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2309858780/002/f2773--- PASS: TestQueueRetryMovesToBack (0.09s)27742026/10/25 17:21:31 INFO Uploading batch count=22775--- PASS: TestFailedPathPrunedByLaterClosure (0.09s)27762026/10/25 17:21:31 ERROR Drain finished with paths left in queue remaining=102777--- PASS: TestWorkerKeepsPathItCannotStat (0.09s)2778--- PASS: TestDrainIsolatesPoisonPath (0.09s)2779--- PASS: TestDrainGivesUpWhenServerDown (0.09s)2780--- PASS: TestWorkerSkipsGCdPaths (0.09s)2781--- PASS: TestWorkerUploadsAndRemoves (0.10s)2782--- PASS: TestWorkerPrunesClosureDeps (0.10s)2783--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.10s)27842026/10/25 17:21:31 INFO Uploading batch count=227852026/10/25 17:21:31 ERROR Upload failed error="upload failed" count=227862026/10/25 17:21:31 INFO Uploading batch count=227872026/10/25 17:21:31 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path470964464/001/nonexistent27882026/10/25 17:21:31 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127892026/10/25 17:21:31 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227902026/10/25 17:21:31 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127912026/10/25 17:21:31 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127922026/10/25 17:21:31 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path470964464/001/nonexistent27932026/10/25 17:21:31 INFO Uploading batch count=227942026/10/25 17:21:31 INFO Uploading batch count=227952026/10/25 17:21:31 ERROR Upload failed error="upload failed" count=227962026/10/25 17:21:31 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127972026/10/25 17:21:31 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227982026/10/25 17:21:31 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127992026/10/25 17:21:31 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path470964464/001/nonexistent28002026/10/25 17:21:31 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128012026/10/25 17:21:31 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128022026/10/25 17:21:31 INFO Uploading batch count=228032026/10/25 17:21:31 ERROR Drain finished with paths left in queue remaining=128042026/10/25 17:21:31 INFO Uploading batch count=228052026/10/25 17:21:31 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228062026/10/25 17:21:31 ERROR Upload failed error="upload failed" count=228072026/10/25 17:21:31 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128082026/10/25 17:21:31 ERROR Drain finished with paths left in queue remaining=228092026/10/25 17:21:31 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128102026/10/25 17:21:31 ERROR Drain finished with paths left in queue remaining=22811--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2812 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.04s)2813 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.04s)2814 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.04s)28152026/10/25 17:21:31 ERROR Accept failed error="too many open files"28162026/10/25 17:21:31 ERROR Failed to decode request error="read unix /build/hook1106666663/test.sock->@: i/o timeout"28172026/10/25 17:21:31 ERROR Failed to write response error="write unix /build/hook1106666663/test.sock->@: i/o timeout"2818--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)28192026/10/25 17:21:31 ERROR Drain finished with paths left in queue remaining=428202026/10/25 17:21:31 ERROR Upload failed error="context canceled" count=228212026/10/25 17:21:31 ERROR Drain finished with paths left in queue remaining=42822--- PASS: TestDrainTimeout (0.27s)28232026/10/25 17:21:31 ERROR Upload failed error="context canceled" count=228242026/10/25 17:21:31 ERROR Drain finished with paths left in queue remaining=22825--- PASS: TestShutdownFinishesInFlightPush (0.00s)2826 --- PASS: TestShutdownFinishesInFlightPush/completes (0.16s)2827 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.23s)28282026/10/25 17:21:31 ERROR Accept failed error="too many open files"28292026/10/25 17:21:31 ERROR Drain finished with paths left in queue remaining=32830--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2831 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.26s)2832 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.37s)2833--- PASS: TestQueueConcurrentWriters (0.54s)28342026/10/25 17:21:32 ERROR Accept failed error="too many open files"2835--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)28362026/10/25 17:21:32 INFO Uploading batch count=128372026/10/25 17:21:32 INFO Uploading batch count=128382026/10/25 17:21:32 INFO Uploading batch count=128392026/10/25 17:21:32 ERROR Upload failed error="upload failed" count=128402026/10/25 17:21:32 INFO Uploading batch count=128412026/10/25 17:21:32 ERROR Upload failed error="upload failed" count=128422026/10/25 17:21:32 INFO Uploading batch count=128432026/10/25 17:21:32 ERROR Upload failed error="upload failed" count=128442026/10/25 17:21:32 INFO Uploading batch count=128452026/10/25 17:21:32 ERROR Upload failed error="upload failed" count=128462026/10/25 17:21:32 ERROR Drain finished with paths left in queue remaining=12847--- PASS: TestRunNotBlockedByPoisonHead (1.12s)2848--- PASS: TestQueueRemoveLargeClosure (2.78s)2849--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.06s)2850PASS2851Running signing tests...2852=== RUN TestExternalSigner2853=== PAUSE TestExternalSigner2854=== RUN TestExternalSignerWrongPublicKey2855=== PAUSE TestExternalSignerWrongPublicKey2856=== RUN TestExternalSignerErrors2857=== PAUSE TestExternalSignerErrors2858=== RUN TestExternalSignerRestartsAfterCrash2859=== PAUSE TestExternalSignerRestartsAfterCrash2860=== RUN TestExternalSignerProgramErrorKeepsProcess2861=== PAUSE TestExternalSignerProgramErrorKeepsProcess2862=== RUN TestExternalSignerClose2863=== PAUSE TestExternalSignerClose2864=== RUN TestExternalSignerRejectsInvalidPublicKey2865=== PAUSE TestExternalSignerRejectsInvalidPublicKey2866=== RUN TestExternalSignerCancellation2867=== PAUSE TestExternalSignerCancellation2868=== RUN TestGenerateFingerprint2869=== PAUSE TestGenerateFingerprint2870=== RUN TestParseSigningKey2871=== PAUSE TestParseSigningKey2872=== RUN TestSign2873=== PAUSE TestSign2874=== RUN TestSignBatch2875=== PAUSE TestSignBatch2876=== RUN TestNilKeyPublicKey2877=== PAUSE TestNilKeyPublicKey2878=== RUN TestSignErrors2879=== PAUSE TestSignErrors2880=== CONT TestExternalSigner2881=== CONT TestSign2882=== CONT TestExternalSignerRejectsInvalidPublicKey2883=== CONT TestSignBatch2884=== CONT TestNilKeyPublicKey2885=== CONT TestParseSigningKey2886--- PASS: TestNilKeyPublicKey (0.00s)2887=== RUN TestParseSigningKey/valid_32-byte_key2888=== CONT TestExternalSignerRestartsAfterCrash2889=== CONT TestExternalSignerProgramErrorKeepsProcess2890=== CONT TestGenerateFingerprint2891=== RUN TestGenerateFingerprint/basic_with_references2892=== PAUSE TestGenerateFingerprint/basic_with_references2893=== RUN TestGenerateFingerprint/no_references2894=== CONT TestExternalSignerWrongPublicKey2895=== PAUSE TestGenerateFingerprint/no_references2896=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2897=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2898=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2899=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2900=== RUN TestGenerateFingerprint/invalid_nar_hash_length2901=== CONT TestExternalSignerErrors2902=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2903=== RUN TestGenerateFingerprint/invalid_store_path_prefix2904=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2905=== RUN TestExternalSignerErrors/wrong_signature_name2906=== RUN TestGenerateFingerprint/invalid_reference_prefix2907=== PAUSE TestExternalSignerErrors/wrong_signature_name2908=== RUN TestExternalSignerErrors/program_error2909=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2910=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2911=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2912=== CONT TestGenerateFingerprint/invalid_nar_hash_length2913=== CONT TestGenerateFingerprint/no_references2914=== CONT TestGenerateFingerprint/basic_with_references2915=== PAUSE TestParseSigningKey/valid_32-byte_key2916=== CONT TestExternalSignerCancellation2917=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2918=== CONT TestExternalSignerClose2919=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2920=== RUN TestParseSigningKey/no_colon2921=== CONT TestSignErrors2922=== PAUSE TestExternalSignerErrors/program_error2923=== RUN TestExternalSignerErrors/wrong_shape2924=== PAUSE TestExternalSignerErrors/wrong_shape2925=== CONT TestGenerateFingerprint/invalid_store_path_prefix2926=== RUN TestExternalSignerRejectsInvalidPublicKey/#002927=== CONT TestGenerateFingerprint/invalid_reference_prefix2928=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002929=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2930=== PAUSE TestParseSigningKey/no_colon2931=== RUN TestExternalSignerErrors/unrequested_key2932--- PASS: TestGenerateFingerprint (0.00s)2933 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2934 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2935 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2936 --- PASS: TestGenerateFingerprint/no_references (0.00s)2937 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2938 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2939 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2940=== RUN TestParseSigningKey/empty_name2941=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2942=== PAUSE TestExternalSignerErrors/unrequested_key2943=== PAUSE TestParseSigningKey/empty_name2944=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2945=== RUN TestParseSigningKey/invalid_base642946=== RUN TestExternalSignerErrors/invalid_signature_base642947=== PAUSE TestParseSigningKey/invalid_base642948=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2949=== RUN TestParseSigningKey/wrong_length2950=== PAUSE TestParseSigningKey/wrong_length2951=== PAUSE TestExternalSignerErrors/invalid_signature_base642952=== CONT TestParseSigningKey/no_colon2953=== RUN TestExternalSignerErrors/exit_at_startup2954=== CONT TestParseSigningKey/valid_32-byte_key2955=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2956=== CONT TestParseSigningKey/wrong_length2957=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2958=== CONT TestParseSigningKey/invalid_base642959=== CONT TestParseSigningKey/empty_name2960=== PAUSE TestExternalSignerErrors/exit_at_startup2961=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2962--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2963=== RUN TestExternalSignerErrors/wrong_id2964=== PAUSE TestExternalSignerErrors/wrong_id2965=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2966=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2967=== CONT TestExternalSignerRejectsInvalidPublicKey/#002968=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2969=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2970=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2971=== RUN TestExternalSignerErrors/missing_signatures2972=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2973=== PAUSE TestExternalSignerErrors/missing_signatures2974=== RUN TestExternalSignerErrors/wrong_signature_length2975--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.01s)2976 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2977 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2978 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2979 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2980 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2981=== PAUSE TestExternalSignerErrors/wrong_signature_length2982=== RUN TestExternalSignerErrors/exit_on_request2983=== PAUSE TestExternalSignerErrors/exit_on_request2984=== RUN TestExternalSignerErrors/invalid_JSON2985=== PAUSE TestExternalSignerErrors/invalid_JSON2986=== RUN TestExternalSignerErrors/null_signatures2987=== PAUSE TestExternalSignerErrors/null_signatures2988=== RUN TestExternalSignerErrors/too_few_signatures2989=== PAUSE TestExternalSignerErrors/too_few_signatures2990=== RUN TestExternalSignerErrors/null2991=== PAUSE TestExternalSignerErrors/null2992=== RUN TestExternalSignerErrors/wrong_signatures_shape2993=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2994=== RUN TestExternalSignerErrors/missing_signature_name2995=== PAUSE TestExternalSignerErrors/missing_signature_name2996=== CONT TestExternalSignerErrors/program_error2997=== CONT TestExternalSignerErrors/wrong_signatures_shape2998=== CONT TestExternalSignerErrors/invalid_JSON2999=== CONT TestExternalSignerErrors/wrong_id3000=== CONT TestExternalSignerErrors/invalid_signature_base643001=== CONT TestExternalSignerErrors/missing_signature_name3002=== CONT TestExternalSignerErrors/exit_at_startup3003=== CONT TestExternalSignerErrors/wrong_shape3004=== CONT TestExternalSignerErrors/unrequested_key3005=== CONT TestExternalSignerErrors/too_few_signatures3006=== CONT TestExternalSignerErrors/null3007=== CONT TestExternalSignerErrors/null_signatures3008=== CONT TestExternalSignerErrors/exit_on_request3009=== CONT TestExternalSignerErrors/missing_signatures3010--- PASS: TestExternalSignerWrongPublicKey (0.01s)3011--- PASS: TestExternalSignerClose (0.01s)3012=== CONT TestExternalSignerErrors/wrong_signature_length3013=== CONT TestExternalSignerErrors/wrong_signature_name3014=== RUN TestSignErrors/nil_key3015--- PASS: TestParseSigningKey (0.00s)3016 --- PASS: TestParseSigningKey/no_colon (0.00s)3017 --- PASS: TestParseSigningKey/wrong_length (0.00s)3018 --- PASS: TestParseSigningKey/empty_name (0.00s)3019 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)3020 --- PASS: TestParseSigningKey/valid_32-byte_key (0.01s)3021 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.01s)3022=== PAUSE TestSignErrors/nil_key3023=== RUN TestSignErrors/nil_narinfo3024=== PAUSE TestSignErrors/nil_narinfo3025=== RUN TestSignErrors/invalid_narinfo3026=== PAUSE TestSignErrors/invalid_narinfo3027=== RUN TestSignErrors/canceled3028=== PAUSE TestSignErrors/canceled3029=== CONT TestSignErrors/nil_key3030--- PASS: TestExternalSignerErrors (0.01s)3031 --- PASS: TestExternalSignerErrors/program_error (0.00s)3032 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)3033 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)3034 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)3035 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)3036 --- PASS: TestExternalSignerErrors/null (0.01s)3037 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)3038 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)3039 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)3040 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)3041 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)3042 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)3043 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)3044 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)3045 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)3046 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)3047=== CONT TestSignErrors/nil_narinfo3048=== CONT TestSignErrors/invalid_narinfo3049--- PASS: TestSign (0.02s)3050=== CONT TestSignErrors/canceled3051--- PASS: TestExternalSignerRestartsAfterCrash (0.02s)3052--- PASS: TestSignErrors (0.01s)3053 --- PASS: TestSignErrors/nil_key (0.00s)3054 --- PASS: TestSignErrors/nil_narinfo (0.00s)3055 --- PASS: TestSignErrors/invalid_narinfo (0.00s)3056 --- PASS: TestSignErrors/canceled (0.00s)3057--- PASS: TestExternalSigner (0.02s)3058--- PASS: TestExternalSignerCancellation (0.02s)3059--- PASS: TestSignBatch (0.03s)3060PASS3061Running OpenBao signer tests...3062=== RUN TestSign3063=== PAUSE TestSign3064=== RUN TestSignErrors3065=== PAUSE TestSignErrors3066=== RUN TestServe3067=== PAUSE TestServe3068=== RUN TestServeRejectsGarbage3069=== PAUSE TestServeRejectsGarbage3070=== CONT TestSignErrors3071=== CONT TestSign3072=== RUN TestSignErrors/invalid_base643073=== CONT TestServe3074=== CONT TestServeRejectsGarbage3075=== PAUSE TestSignErrors/invalid_base643076=== RUN TestSignErrors/http_error3077=== PAUSE TestSignErrors/http_error3078=== RUN TestSignErrors/invalid_json3079=== PAUSE TestSignErrors/invalid_json3080=== RUN TestSignErrors/no_prefix3081=== PAUSE TestSignErrors/no_prefix3082=== CONT TestSignErrors/invalid_base643083--- PASS: TestServeRejectsGarbage (0.00s)3084=== CONT TestSignErrors/no_prefix3085=== CONT TestSignErrors/invalid_json3086--- PASS: TestServe (0.00s)3087=== CONT TestSignErrors/http_error3088--- PASS: TestSign (0.01s)3089--- PASS: TestSignErrors (0.00s)3090 --- PASS: TestSignErrors/invalid_json (0.00s)3091 --- PASS: TestSignErrors/no_prefix (0.00s)3092 --- PASS: TestSignErrors/http_error (0.00s)3093 --- PASS: TestSignErrors/invalid_base64 (0.01s)3094PASS3095Running niks3-hook command tests...3096=== RUN TestServeSecondSignalEndsDrain3097=== PAUSE TestServeSecondSignalEndsDrain3098=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown3099=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown3100=== CONT TestServeSecondSignalEndsDrain3101=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown3102--- PASS: TestServeSecondSignalEndsDrain (0.07s)31032026/10/25 17:21:40 INFO Upload queue status pending=131042026/10/25 17:21:40 INFO Uploading batch count=13105--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.14s)3106PASS3107Running rate limiter tests...3108=== RUN TestAdaptiveRateLimiter_ThreadSafety3109=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3110=== CONT TestAdaptiveRateLimiter_ThreadSafety31112026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=7031122026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=4931132026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=34.331142026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=24.00999999999999831152026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=16.80731162026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=11.76489999999999931172026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=8.2354331182026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=5.76480099999999931192026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531202026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531212026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=5.63678500000000131222026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531232026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531242026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531252026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531262026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531272026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531282026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531292026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531302026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531312026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531322026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531332026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531342026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531352026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531362026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531372026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531382026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531392026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531402026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531412026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531422026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531432026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531442026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531452026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531462026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531472026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531482026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531492026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531502026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531512026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531522026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531532026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531542026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531552026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531562026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531572026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531582026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531592026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531602026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531612026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531622026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531632026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531642026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531652026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531662026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531672026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531682026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531692026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531702026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531712026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531722026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531732026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=8.25281691850000431742026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=5.77697184295000331752026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531762026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531772026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531782026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531792026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531802026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531812026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531822026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531832026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531842026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531852026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531862026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531872026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531882026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531892026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531902026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531912026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531922026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531932026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531942026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531952026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531962026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531972026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531982026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=531992026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=532002026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=532012026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=532022026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=8.25281691850000432032026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=5.77697184295000332042026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=532052026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=532062026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=532072026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=532082026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=532092026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=532102026/10/25 17:21:41 WARN Rate limiter backed off name=test rate=53211--- PASS: TestAdaptiveRateLimiter_ThreadSafety (0.09s)3212PASS