niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #273
· 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_ProducerErrorIsNotEOF22=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF23=== RUN TestUploadMultipart_FailedPartBufferNotReused24=== PAUSE TestUploadMultipart_FailedPartBufferNotReused25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestUploadMultipart_SupersededByPeer28=== PAUSE TestUploadMultipart_SupersededByPeer29=== RUN TestDumpPathCaseHackMatchesNix30--- PASS: TestDumpPathCaseHackMatchesNix (0.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.80s)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 TestDoWithRetry_FinalResponseBodyReadable79=== PAUSE TestDoWithRetry_FinalResponseBodyReadable80=== RUN TestShellSplit81=== PAUSE TestShellSplit82=== RUN TestShellSplitErrors83=== PAUSE TestShellSplitErrors84=== RUN TestStreamPushReportsEveryPath85=== PAUSE TestStreamPushReportsEveryPath86=== RUN TestStreamPushBatchesUnderLoad87=== PAUSE TestStreamPushBatchesUnderLoad88=== RUN TestStreamPushIsolatesFailures89=== PAUSE TestStreamPushIsolatesFailures90=== RUN TestStreamPushGivesUpOnDeadServer91=== PAUSE TestStreamPushGivesUpOnDeadServer92=== RUN TestStreamPushRequestLine93=== PAUSE TestStreamPushRequestLine94=== RUN TestStreamPushReportsSignatures95=== PAUSE TestStreamPushReportsSignatures96=== RUN TestClientSignaturesByStorePath97=== PAUSE TestClientSignaturesByStorePath98=== RUN TestStreamPushStopsOnCancel99=== PAUSE TestStreamPushStopsOnCancel100=== RUN TestSetClientTLS101=== PAUSE TestSetClientTLS102=== RUN TestSetClientTLSDoesNotMutateDefaultTransport103=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport104=== RUN TestSetClientTLSErrors105=== PAUSE TestSetClientTLSErrors106=== RUN TestStaticToken107=== PAUSE TestStaticToken108=== RUN TestFileTokenReadsAndCaches109=== PAUSE TestFileTokenReadsAndCaches110=== RUN TestFileTokenMissing111=== PAUSE TestFileTokenMissing112=== RUN TestFileTokenEmpty113=== PAUSE TestFileTokenEmpty114=== RUN TestScriptTokenNoExpiryRerunsEveryCall115=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall116=== RUN TestScriptTokenCachesUntilRefresh117=== PAUSE TestScriptTokenCachesUntilRefresh118=== RUN TestScriptTokenEmptyToken119=== PAUSE TestScriptTokenEmptyToken120=== RUN TestScriptTokenBadJSON121=== PAUSE TestScriptTokenBadJSON122=== RUN TestScriptTokenScriptFails123=== PAUSE TestScriptTokenScriptFails124=== RUN TestScriptTokenEmptyCommand125=== PAUSE TestScriptTokenEmptyCommand126=== RUN TestScriptTokenDoesNotWaitForItsChildren127=== PAUSE TestScriptTokenDoesNotWaitForItsChildren128=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica129=== CONT TestScriptTokenBadJSON130=== CONT TestStreamPushGivesUpOnDeadServer131=== CONT TestScriptTokenDoesNotWaitForItsChildren132=== CONT TestPathInfoHashCompatibility133=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs134=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer135=== CONT TestConvertHashToNix32136=== RUN TestConvertHashToNix32/SRI_format_to_Nix32137=== CONT TestScriptTokenEmptyCommand138=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32139=== CONT TestDoWithRetry_BodyReplayedViaGetBody140=== CONT TestFileTokenMissing141--- PASS: TestScriptTokenEmptyCommand (0.00s)142=== CONT TestRateLimiterFeedback143=== RUN TestConvertHashToNix32/already_Nix32_format144=== CONT TestStreamPushReportsEveryPath145=== CONT TestStreamPushBatchesUnderLoad146=== CONT TestCompletePendingClosure_NotFoundWithoutKey147=== CONT TestClientSignaturesByStorePath148=== CONT TestShellSplit149=== CONT TestStreamPushIsolatesFailures150=== CONT TestShellSplitErrors151=== CONT TestEncodeNixBase32WithRealHash152=== CONT TestTruncatedNARDumpIsNotCompleted153=== CONT TestFileTokenReadsAndCaches154=== CONT TestPartSizeForNAR155=== CONT TestSetClientTLS156=== CONT TestDoServerRequestAttachesToken157=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)158=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs159=== CONT TestStreamPushRequestLine160=== RUN TestRateLimiterFeedback/429_enables_limiter161=== PAUSE TestConvertHashToNix32/already_Nix32_format162=== RUN TestStreamPushBatchesUnderLoad/together163--- PASS: TestClientSignaturesByStorePath (0.00s)164=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess165=== CONT TestGetStorePathHash166=== CONT TestParsePathInfoJSONMultiplePaths167=== CONT TestPathInfoCACompatibility168=== CONT TestDoWithRetry_FinalResponseBodyReadable169=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)170=== RUN TestPartSizeForNAR/zero_stays_at_minimum171=== CONT TestUploadMultipart_ProducerErrorIsNotEOF172=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout173=== CONT TestDumpPathMatchesNix174=== RUN TestConvertHashToNix32/invalid_format175--- PASS: TestStreamPushReportsEveryPath (0.00s)176--- PASS: TestFileTokenMissing (0.00s)177=== CONT TestDumpPathSingleFile178=== RUN TestGetStorePathHash/valid_store_path179=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths180=== PAUSE TestStreamPushBatchesUnderLoad/together181=== RUN TestPathInfoCACompatibility/null_ca_field182=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent183=== PAUSE TestPathInfoCACompatibility/null_ca_field184=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier185=== RUN TestPathInfoCACompatibility/old_string_format_-_text186=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout187=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part188=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum189=== CONT TestParsePathInfoJSON190=== PAUSE TestConvertHashToNix32/invalid_format191=== PAUSE TestRateLimiterFeedback/429_enables_limiter192--- PASS: TestShellSplitErrors (0.00s)193=== PAUSE TestGetStorePathHash/valid_store_path194=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time195=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths196=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon197=== CONT TestFilterOversizedClosures198=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths199=== RUN TestFilterOversizedClosures/no_limit_keeps_everything200=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier201=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text202=== CONT TestUploadMultipart_PartsInParallel203=== RUN TestPartSizeForNAR/small_stays_at_minimum204=== RUN TestParsePathInfoJSON/Nix_format205=== CONT TestDumpPathWriterError206=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part207--- PASS: TestShellSplit (0.00s)208=== RUN TestRateLimiterFeedback/503_enables_limiter209=== RUN TestGetStorePathHash/basename_without_hyphen_should_error210=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time211=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun212=== CONT TestSupersededNARStillUploadsListing213=== RUN TestSupersededNARStillUploadsListing/small_NAR214=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon215=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths216=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything217=== CONT TestEncodeNixBase32218=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive219=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped220=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive221=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up222=== RUN TestPathInfoCACompatibility/new_structured_format_-_text223=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up224=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text225=== CONT TestUploadMultipart_SupersededByPeer226=== RUN TestEncodeNixBase32/test_string_hash227=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method228=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method229=== PAUSE TestPartSizeForNAR/small_stays_at_minimum230=== PAUSE TestParsePathInfoJSON/Nix_format231=== CONT TestStreamPushReportsSignatures232--- PASS: TestEncodeNixBase32WithRealHash (0.00s)233=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary234=== PAUSE TestRateLimiterFeedback/503_enables_limiter235=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error236=== PAUSE TestSupersededNARStillUploadsListing/small_NAR237=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI238=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error239=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure240=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped241=== RUN TestUploadMultipart_SupersededByPeer/exists242=== PAUSE TestEncodeNixBase32/test_string_hash243=== CONT TestStaticToken244=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum245=== RUN TestEncodeNixBase32/empty_input246=== PAUSE TestEncodeNixBase32/empty_input247=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum248=== CONT TestSetClientTLSDoesNotMutateDefaultTransport249=== CONT TestScriptTokenEmptyToken250=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts251=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts252=== RUN TestPartSizeForNAR/1_TiB253=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary254=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter255=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI256=== RUN TestSupersededNARStillUploadsListing/dump_cut_short257=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short258=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error259=== RUN TestFilterOversizedClosures/all_closures_skipped260=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error261=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error262=== PAUSE TestUploadMultipart_SupersededByPeer/exists263=== CONT TestCaseHackSuffix264=== CONT TestScriptTokenCachesUntilRefresh265=== RUN TestParsePathInfoJSON/Lix_format266--- PASS: TestScriptTokenBadJSON (0.01s)267=== PAUSE TestPartSizeForNAR/1_TiB268=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter269=== CONT TestSetClientTLSErrors270=== RUN TestPartSizeForNAR/5_TiB_S3_max_object271=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails272=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512273=== PAUSE TestFilterOversizedClosures/all_closures_skipped274=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512275=== RUN TestUploadMultipart_SupersededByPeer/missing276=== CONT TestFileTokenEmpty277=== CONT TestScriptTokenScriptFails278=== PAUSE TestUploadMultipart_SupersededByPeer/missing279--- PASS: TestFileTokenReadsAndCaches (0.00s)280=== CONT TestResolveStorePath281--- PASS: TestStreamPushIsolatesFailures (0.00s)282=== PAUSE TestParsePathInfoJSON/Lix_format283=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails284=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry285=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter286=== RUN TestParsePathInfoJSON/empty_input287--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)288--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)289=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object290=== CONT TestStreamPushStopsOnCancel291=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter292=== CONT TestScriptTokenNoExpiryRerunsEveryCall293=== RUN TestStreamPushStopsOnCancel/waiting_for_input294=== CONT TestRegisterUploadedObjectReusesConnections295=== CONT TestUploadMultipart_FailedPartBufferNotReused296=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs297=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input298--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.01s)299--- PASS: TestDoServerRequestAttachesToken (0.01s)300=== RUN TestPartSizeForNAR/capped_at_5_GiB301=== PAUSE TestParsePathInfoJSON/empty_input302=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot303--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)304--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)305--- PASS: TestStaticToken (0.00s)306=== RUN TestSetClientTLSErrors/missing_cert_file307=== PAUSE TestSetClientTLSErrors/missing_cert_file308=== PAUSE TestPartSizeForNAR/capped_at_5_GiB309=== RUN TestSetClientTLSErrors/missing_key_file310=== CONT TestStreamPushBatchesUnderLoad/together311=== PAUSE TestSetClientTLSErrors/missing_key_file312=== RUN TestSetClientTLS/rejects_connection_without_client_cert313--- PASS: TestStreamPushReportsSignatures (0.00s)314=== RUN TestParsePathInfoJSON/whitespace_only315=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert316=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA317=== RUN TestSetClientTLSErrors/missing_ca_file318=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot319=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA320=== RUN TestSetClientTLS/preserves_debug_logging_transport321=== PAUSE TestSetClientTLSErrors/missing_ca_file322--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)323--- PASS: TestFileTokenEmpty (0.28s)324=== PAUSE TestParsePathInfoJSON/whitespace_only325=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot326=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths327--- PASS: TestScriptTokenScriptFails (0.28s)328=== RUN TestParsePathInfoJSON/invalid_JSON329=== PAUSE TestSetClientTLS/preserves_debug_logging_transport330=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot331=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier332--- PASS: TestScriptTokenEmptyToken (0.28s)333=== PAUSE TestParsePathInfoJSON/invalid_JSON334=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot335=== RUN TestSetClientTLSErrors/invalid_ca_file336=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot337=== PAUSE TestSetClientTLSErrors/invalid_ca_file338=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot339=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths340=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot341=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken342=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken343=== CONT TestPathInfoCACompatibility/new_structured_format_-_text344--- PASS: TestDumpPathSingleFile (0.29s)345--- PASS: TestResolveStorePath (0.28s)346--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.28s)347=== CONT TestPathInfoCACompatibility/null_ca_field348=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up349=== CONT TestPathInfoCACompatibility/old_string_format_-_text350=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method351=== CONT TestEncodeNixBase32/test_string_hash352=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive353--- PASS: TestCaseHackSuffix (0.28s)354=== CONT TestEncodeNixBase32/empty_input355=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part356=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary357=== CONT TestGetStorePathHash/valid_store_path358=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error359=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error360=== CONT TestGetStorePathHash/basename_without_hyphen_should_error361=== CONT TestFilterOversizedClosures/all_closures_skipped362=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped363=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout364=== CONT TestFilterOversizedClosures/no_limit_keeps_everything365=== CONT TestConvertHashToNix32/already_Nix32_format366=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon367=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)368--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.29s)369=== CONT TestUploadMultipart_SupersededByPeer/exists370=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512371=== CONT TestSupersededNARStillUploadsListing/small_NAR372--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)373 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)374 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)375--- PASS: TestEncodeNixBase32 (0.00s)376 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)377 --- PASS: TestEncodeNixBase32/empty_input (0.00s)378=== CONT TestUploadMultipart_SupersededByPeer/missing379=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI380--- PASS: TestPathInfoCACompatibility (0.01s)381 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)382 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)383 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)384 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)385 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)386--- PASS: TestFilterOversizedClosures (0.00s)387 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)388 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)389 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)390=== CONT TestConvertHashToNix32/invalid_format391=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails392=== CONT TestConvertHashToNix32/SRI_format_to_Nix32393=== CONT TestSupersededNARStillUploadsListing/dump_cut_short394--- PASS: TestConvertHashToNix32 (0.01s)395 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)396 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)397 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)398--- PASS: TestScriptTokenCachesUntilRefresh (0.31s)399=== CONT TestRateLimiterFeedback/429_enables_limiter400=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter401=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time402--- PASS: TestGetStorePathHash (0.02s)403 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)404 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)405 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)406 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)407=== CONT TestRateLimiterFeedback/503_enables_limiter408--- PASS: TestStreamPushBatchesUnderLoad (0.01s)409 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)410 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)411--- PASS: TestPathInfoHashCompatibility (0.01s)412 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)413 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)414 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)415 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)416--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.00s)417 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.01s)418 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.02s)419--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.31s)420=== CONT TestPartSizeForNAR/zero_stays_at_minimum421=== CONT TestPartSizeForNAR/5_TiB_S3_max_object422=== CONT TestPartSizeForNAR/small_stays_at_minimum423=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum424=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter425=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA426=== CONT TestSetClientTLS/preserves_debug_logging_transport427=== CONT TestSetClientTLS/rejects_connection_without_client_cert428=== CONT TestParsePathInfoJSON/Nix_format429=== CONT TestParsePathInfoJSON/whitespace_only430=== CONT TestParsePathInfoJSON/invalid_JSON431--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)432 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)433 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.02s)434=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts435=== CONT TestPartSizeForNAR/capped_at_5_GiB436=== CONT TestSetClientTLSErrors/missing_cert_file437=== CONT TestParsePathInfoJSON/Lix_format438=== CONT TestStreamPushStopsOnCancel/waiting_for_input439=== CONT TestPartSizeForNAR/1_TiB440=== CONT TestSetClientTLSErrors/missing_key_file441=== CONT TestParsePathInfoJSON/empty_input442=== CONT TestSetClientTLSErrors/invalid_ca_file443=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot444=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken445--- PASS: TestRateLimiterFeedback (0.01s)446 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)447 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)448 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)449 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)450=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot451--- PASS: TestPartSizeForNAR (0.30s)452 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)453 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)454 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)455 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)456 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)457 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)458 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)459--- PASS: TestParsePathInfoJSON (0.30s)460 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)461 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)462 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)463 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)464 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)465=== CONT TestSetClientTLSErrors/missing_ca_file466=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot467--- PASS: TestSetClientTLSErrors (0.29s)468 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)469 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)470 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)471 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)472=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot473--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.36s)474--- PASS: TestDumpPathWriterError (0.38s)475--- PASS: TestStreamPushStopsOnCancel (0.29s)476 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.05s)477 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.05s)478 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.05s)479 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.06s)480 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)481 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.05s)482--- PASS: TestSetClientTLS (0.30s)483 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)484 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.03s)485 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.07s)486--- PASS: TestDumpPathMatchesNix (0.64s)487--- PASS: TestRegisterUploadedObjectReusesConnections (0.36s)488--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.01s)489 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.37s)490 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.38s)491--- PASS: TestStreamPushRequestLine (0.76s)492--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)493--- PASS: TestUploadMultipart_PartsInParallel (1.46s)494--- PASS: TestSupersededNARStillUploadsListing (0.00s)495 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.03s)496 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.03s)497 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.19s)498--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.25s)499--- PASS: TestTruncatedNARDumpIsNotCompleted (1.88s)500--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (2.00s)501--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.01s)502 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.01s)503 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.29s)504PASS505Running server tests...506The files belonging to this database system will be owned by user "nixbld".507This user must also own the server process.508509The database cluster will be initialized with locale "C".510The default database encoding has accordingly been set to "SQL_ASCII".511The default text search configuration will be set to "english".512513Data page checksums are enabled.514515creating directory /build/postgres3237815241/data ... ok516creating subdirectories ... ok517selecting dynamic shared memory implementation ... posix518selecting default "max_connections" ... 100519selecting default "shared_buffers" ... 128MB520selecting default time zone ... UTC521creating configuration files ... ok522running bootstrap script ... ok523performing post-bootstrap initialization ... ok524syncing data to disk ... ok525526initdb: warning: enabling "trust" authentication for local connections527initdb: 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.528529Success. You can now start the database server using:530531 pg_ctl -D /build/postgres3237815241/data -l logfile start532533/build/postgres3237815241:5432 - no response5342026-09-24 18:05:45.572 UTC [170] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5352026-09-24 18:05:45.573 UTC [170] LOG: listening on Unix socket "/build/postgres3237815241/.s.PGSQL.5432"5362026-09-24 18:05:45.577 UTC [177] LOG: database system was shut down at 2026-09-24 18:05:45 UTC5372026-09-24 18:05:45.581 UTC [170] LOG: database system is ready to accept connections538/build/postgres3237815241:5432 - accepting connections539=== RUN TestService_AuthMiddleware540=== PAUSE TestService_AuthMiddleware541=== RUN TestService_AuthMiddleware_MTLSProxyHeader542=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader543=== RUN TestService_AuthMiddleware_MTLSBoundSubjects544=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects545=== RUN TestService_ReadAuthMiddleware546=== PAUSE TestService_ReadAuthMiddleware547=== RUN TestService_AuthMiddleware_OIDC548=== PAUSE TestService_AuthMiddleware_OIDC549=== RUN TestService_RequireScope_OIDC550=== PAUSE TestService_RequireScope_OIDC551=== RUN TestService_ReadScope_PublicByDefault552=== PAUSE TestService_ReadScope_PublicByDefault553=== RUN TestCacheConfigHandler554=== PAUSE TestCacheConfigHandler555=== RUN TestCacheStatsHandler556=== PAUSE TestCacheStatsHandler557=== RUN TestClientCADerivations558=== PAUSE TestClientCADerivations559=== RUN TestClientErrorHandling560=== PAUSE TestClientErrorHandling561=== RUN TestClientIntegration562=== PAUSE TestClientIntegration563=== RUN TestClientMultipleUploads564=== PAUSE TestClientMultipleUploads565=== RUN TestClientWithDependencies566=== PAUSE TestClientWithDependencies567=== RUN TestClientSharedPathCommittedMidPush568=== PAUSE TestClientSharedPathCommittedMidPush569=== RUN TestPinProtectsFromGC570=== PAUSE TestPinProtectsFromGC571=== RUN TestClientPushesUseOnePush572=== PAUSE TestClientPushesUseOnePush573=== RUN TestClientFallsBackToClosures574=== PAUSE TestClientFallsBackToClosures575=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock576=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock577=== RUN TestResolveDBConnectionString578=== PAUSE TestResolveDBConnectionString579=== RUN TestConnectWaitsForAPeerMigration580=== PAUSE TestConnectWaitsForAPeerMigration581=== RUN TestConnectSerialisesConcurrentMigrations582=== PAUSE TestConnectSerialisesConcurrentMigrations583=== RUN TestLeadElectsOneAndHandsOver584=== PAUSE TestLeadElectsOneAndHandsOver585=== RUN TestLeadIncumbentWinsAfterRestart5862026/09/24 18:05:46 INFO lead: acquired remote=192.0.2.1:12345872026/09/24 18:05:47 INFO lead: released remote=192.0.2.1:12345882026/09/24 18:05:47 INFO lead: acquired remote=192.0.2.1:12345892026/09/24 18:05:48 INFO lead: released remote=192.0.2.1:1234590--- PASS: TestLeadIncumbentWinsAfterRestart (2.40s)591=== RUN TestLeadEndsOnShutdown592=== PAUSE TestLeadEndsOnShutdown593=== RUN TestLeadEndsWhenItsConnectionHangs5942026/09/24 18:05:48 INFO lead: acquired remote=192.0.2.1:12345952026-09-24 18:05:49.645 UTC [431] FATAL: terminating connection due to administrator command5962026/09/24 18:05:49 INFO lead: acquired remote=192.0.2.1:12345972026/09/24 18:05:50 WARN lead: lock connection lost error="timeout: context deadline exceeded"5982026/09/24 18:05:50 INFO lead: released remote=192.0.2.1:12345992026/09/24 18:05:51 INFO lead: released remote=192.0.2.1:1234600--- PASS: TestLeadEndsWhenItsConnectionHangs (2.77s)601=== RUN TestGCAdvisoryLockBlocksConcurrentRun602=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun603=== RUN TestGCBugBareHashReferences604=== PAUSE TestGCBugBareHashReferences605=== RUN TestGCMetrics606=== PAUSE TestGCMetrics607=== RUN TestPushDedupSurvivesConcurrentGC608=== PAUSE TestPushDedupSurvivesConcurrentGC609=== RUN TestDeduplicatedObjectsRecordedAsPending610=== PAUSE TestDeduplicatedObjectsRecordedAsPending611=== RUN TestGCSweepSkipsPendingObjects612=== PAUSE TestGCSweepSkipsPendingObjects613=== RUN TestTombstonedObjectOfferedWithoutWaiting614=== PAUSE TestTombstonedObjectOfferedWithoutWaiting615=== RUN TestGCSweepDeliversEachKeyOnce616=== PAUSE TestGCSweepDeliversEachKeyOnce617=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection618=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection619=== RUN TestForceGCDuringPushOffersSweptObject620=== PAUSE TestForceGCDuringPushOffersSweptObject621=== RUN TestSweepRowDeleteSparesResurrectedObject622=== PAUSE TestSweepRowDeleteSparesResurrectedObject623=== RUN TestSweepSparesObjectReuploadedMidSweep624=== PAUSE TestSweepSparesObjectReuploadedMidSweep625=== RUN TestCommitRacingPendingCleanupKeepsObjects626=== PAUSE TestCommitRacingPendingCleanupKeepsObjects627=== RUN TestGCEndsOnShutdown628=== PAUSE TestGCEndsOnShutdown629=== RUN TestGCTaskStore_StartNew630=== PAUSE TestGCTaskStore_StartNew631=== RUN TestGCTaskStore_DeduplicateSameParams632=== PAUSE TestGCTaskStore_DeduplicateSameParams633=== RUN TestGCTaskStore_ConflictDifferentParams634=== PAUSE TestGCTaskStore_ConflictDifferentParams635=== RUN TestGCTaskStore_GetEmpty636=== PAUSE TestGCTaskStore_GetEmpty637=== RUN TestGCTaskStore_GetReturnsLatest638=== PAUSE TestGCTaskStore_GetReturnsLatest639=== RUN TestGCTaskStore_CompletedAllowsNewTask640=== PAUSE TestGCTaskStore_CompletedAllowsNewTask641=== RUN TestGCTaskStore_PhaseUpdates642=== PAUSE TestGCTaskStore_PhaseUpdates643=== RUN TestGCTaskStore_Fail644=== PAUSE TestGCTaskStore_Fail645=== RUN TestGracefulShutdownDrainsInflight646=== PAUSE TestGracefulShutdownDrainsInflight647=== RUN TestService_healthCheckHandler648=== PAUSE TestService_healthCheckHandler649=== RUN TestService_readinessHandler650=== PAUSE TestService_readinessHandler651=== RUN TestGenerateLandingPage652=== PAUSE TestGenerateLandingPage653=== RUN TestCacheConfigHandlerMaxNarSize654=== PAUSE TestCacheConfigHandlerMaxNarSize655=== RUN TestCreatePendingClosureRejectsOversizedNAR656=== PAUSE TestCreatePendingClosureRejectsOversizedNAR657=== RUN TestNARDeduplicationMetadataUploadBug658=== PAUSE TestNARDeduplicationMetadataUploadBug659=== RUN TestMetricsInventory660=== PAUSE TestMetricsInventory661=== RUN TestService_NativeMTLS662=== PAUSE TestService_NativeMTLS663=== RUN TestServerTLSConfig664=== PAUSE TestServerTLSConfig665=== RUN TestMultipartCleanup666=== PAUSE TestMultipartCleanup667=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded668=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded669=== RUN TestPendingCleanupUsesOneCutoff670=== PAUSE TestPendingCleanupUsesOneCutoff671=== RUN TestPendingClosureFailureTracksEveryUpload672=== PAUSE TestPendingClosureFailureTracksEveryUpload673=== RUN TestPendingClosureFailureAbortsItsUploads674=== PAUSE TestPendingClosureFailureAbortsItsUploads675=== RUN TestObjectStatsTrigger676=== PAUSE TestObjectStatsTrigger677=== RUN TestReconnectLeavesObjectsUnlocked678=== PAUSE TestReconnectLeavesObjectsUnlocked679=== RUN TestValidateS3Concurrency680=== PAUSE TestValidateS3Concurrency681=== RUN TestOrphanedObjectsGC682=== PAUSE TestOrphanedObjectsGC683=== RUN TestOrphanedObjectsGCStressTest684=== PAUSE TestOrphanedObjectsGCStressTest685=== RUN TestResurrectedObjectNotDeleted686=== PAUSE TestResurrectedObjectNotDeleted687=== RUN TestSweepKeepsTombstoneWhenDeleteOutcomeUnknown688=== PAUSE TestSweepKeepsTombstoneWhenDeleteOutcomeUnknown689=== RUN TestCreatePin_ReservedPins690=== PAUSE TestCreatePin_ReservedPins691=== RUN TestConcurrentPinUpdatesAgree692=== PAUSE TestConcurrentPinUpdatesAgree693=== RUN TestCreatePinRejectsBadInput694=== PAUSE TestCreatePinRejectsBadInput695=== RUN TestDeletePinKeepsRowWhenS3Fails696=== PAUSE TestDeletePinKeepsRowWhenS3Fails697=== RUN TestPresentReportsOnlyClosureRoots698=== PAUSE TestPresentReportsOnlyClosureRoots699=== RUN TestPresentNotReportedWhileGCDeletesClosure700=== PAUSE TestPresentNotReportedWhileGCDeletesClosure701=== RUN TestParseSingleRange702=== PAUSE TestParseSingleRange703=== RUN TestProxyHeadersOnlyTrustedOnSocket704=== PAUSE TestProxyHeadersOnlyTrustedOnSocket705=== RUN TestIsValidCachePath706=== PAUSE TestIsValidCachePath707=== RUN TestReadProxyNarinfo708=== PAUSE TestReadProxyNarinfo709=== RUN TestReadProxyNarinfoAlreadyDecompressed710=== PAUSE TestReadProxyNarinfoAlreadyDecompressed711=== RUN TestReadProxyNarStreaming712=== PAUSE TestReadProxyNarStreaming713=== RUN TestReadProxy404714=== PAUSE TestReadProxy404715=== RUN TestReadProxyInvalidPath716=== PAUSE TestReadProxyInvalidPath717=== RUN TestReadProxyHead718=== PAUSE TestReadProxyHead719=== RUN TestReadProxyOutlastsServerWriteTimeout720=== PAUSE TestReadProxyOutlastsServerWriteTimeout721=== RUN TestReadProxyConditionalGet722=== PAUSE TestReadProxyConditionalGet723=== RUN TestReadProxyRootRedirectsToIndexHTML724=== PAUSE TestReadProxyRootRedirectsToIndexHTML725=== RUN TestReadProxyDisabled726=== PAUSE TestReadProxyDisabled727=== RUN TestReadRedirectNar728=== PAUSE TestReadRedirectNar729=== RUN TestReadRedirectKeepsNarinfoProxied730=== PAUSE TestReadRedirectKeepsNarinfoProxied731=== RUN TestReadProxyRangeRequest732=== PAUSE TestReadProxyRangeRequest733=== RUN TestReadRedirectUsesPublicS3URL734=== PAUSE TestReadRedirectUsesPublicS3URL735=== RUN TestPush_OverlappingRootsStoreOneRowPerKey736=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey737=== RUN TestPush_CompleteCommitsEveryRoot738=== PAUSE TestPush_CompleteCommitsEveryRoot739=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit740=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit741=== RUN TestPush_RejectsBadRequests742=== PAUSE TestPush_RejectsBadRequests743=== RUN TestPush_SignsNarinfosOfItsPendingObjects744=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects745=== RUN TestRedundantMultipartUpload746=== PAUSE TestRedundantMultipartUpload747=== RUN TestCompleteMultipartUpload_ErrorButObjectExists748=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists749=== RUN TestCompletedNarNotReofferedAcrossClosures750=== PAUSE TestCompletedNarNotReofferedAcrossClosures751=== RUN TestPresignedUploadRegisteredBeforeCommit752=== PAUSE TestPresignedUploadRegisteredBeforeCommit753=== RUN TestService_Rustfstest754=== PAUSE TestService_Rustfstest755=== RUN TestParseSize756=== PAUSE TestParseSize757=== RUN TestSkippedUploadsHandler758=== PAUSE TestSkippedUploadsHandler759=== RUN TestSystemdListenerNotActivated760--- PASS: TestSystemdListenerNotActivated (0.00s)761=== RUN TestWatchdogBeatsWhenHealthy762--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)763=== RUN TestWatchdogSkipsWhenUnhealthy7642026/09/24 18:05:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7652026/09/24 18:05:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7662026/09/24 18:05:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7672026/09/24 18:05:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7682026/09/24 18:05:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/09/24 18:05:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/09/24 18:05:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/09/24 18:05:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/09/24 18:05:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/09/24 18:05:51 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"774--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)775=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle776=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle777=== RUN TestProxyWriteTimeout778=== PAUSE TestProxyWriteTimeout779=== RUN TestPendingClosureWriteTimeout780=== PAUSE TestPendingClosureWriteTimeout781=== RUN TestIsValidUploadKey782=== PAUSE TestIsValidUploadKey783=== RUN TestUploadHandlersRejectInvalidKeys784=== PAUSE TestUploadHandlersRejectInvalidKeys785=== RUN TestUploadHandlersRejectOversizedBody786=== PAUSE TestUploadHandlersRejectOversizedBody787=== RUN TestService_cleanupPendingClosuresHandler788=== PAUSE TestService_cleanupPendingClosuresHandler789=== RUN TestService_createPendingClosureHandler790=== PAUSE TestService_createPendingClosureHandler791=== RUN TestService_verifyS3Integrity792=== PAUSE TestService_verifyS3Integrity793=== RUN TestCompleteMultipartUnregistered794=== PAUSE TestCompleteMultipartUnregistered795=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT796=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT797=== CONT TestService_AuthMiddleware_MTLSProxyHeader798=== CONT TestService_createPendingClosureHandler799=== CONT TestPresentReportsOnlyClosureRoots800=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock801=== CONT TestClientMultipleUploads802=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle803=== CONT TestIsValidUploadKey804=== CONT TestPendingClosureWriteTimeout805=== CONT TestProxyWriteTimeout806=== RUN TestProxyWriteTimeout/narinfo807=== CONT TestUploadHandlersRejectOversizedBody808=== CONT TestService_cleanupPendingClosuresHandler809=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT810=== CONT TestUploadHandlersRejectInvalidKeys811=== CONT TestService_verifyS3Integrity812=== CONT TestSkippedUploadsHandler813=== CONT TestGCAdvisoryLockBlocksConcurrentRun814=== CONT TestService_Rustfstest815=== CONT TestGracefulShutdownDrainsInflight816=== CONT TestClientFallsBackToClosures817=== CONT TestPresentNotReportedWhileGCDeletesClosure818=== CONT TestClientPushesUseOnePush819=== CONT TestGCTaskStore_PhaseUpdates820=== CONT TestCompletedNarNotReofferedAcrossClosures821=== CONT TestParseSize8222026/09/24 18:05:51 INFO Starting HTTP server address=127.0.0.1:34129823=== RUN TestIsValidUploadKey/narinfo824=== RUN TestPendingClosureWriteTimeout/empty825=== CONT TestGCTaskStore_GetEmpty826=== CONT TestRedundantMultipartUpload827=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info828--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)829=== PAUSE TestProxyWriteTimeout/narinfo830--- PASS: TestParseSize (0.00s)831--- PASS: TestGCTaskStore_GetEmpty (0.00s)832=== CONT TestReadProxyInvalidPath833=== PAUSE TestIsValidUploadKey/narinfo834=== PAUSE TestPendingClosureWriteTimeout/empty835=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info836=== RUN TestProxyWriteTimeout/1_GiB_nar837=== RUN TestIsValidUploadKey/nar_zst838=== PAUSE TestIsValidUploadKey/nar_zst839=== RUN TestPendingClosureWriteTimeout/negative840=== PAUSE TestProxyWriteTimeout/1_GiB_nar841=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal842=== RUN TestIsValidUploadKey/nar_xz843=== RUN TestProxyWriteTimeout/10_GiB_nar8442026/09/24 18:05:51 INFO Shutdown signal received, draining in-flight requests timeout=10s845=== PAUSE TestProxyWriteTimeout/10_GiB_nar846=== PAUSE TestPendingClosureWriteTimeout/negative847=== PAUSE TestIsValidUploadKey/nar_xz848=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal849=== RUN TestProxyWriteTimeout/unknown_size850=== PAUSE TestProxyWriteTimeout/unknown_size851=== RUN TestIsValidUploadKey/nar_plain852=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key853=== RUN TestPendingClosureWriteTimeout/400_objects854=== CONT TestPush_CompleteCommitsEveryRoot855=== PAUSE TestPendingClosureWriteTimeout/400_objects856=== PAUSE TestIsValidUploadKey/nar_plain857=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key858=== RUN TestIsValidUploadKey/listing859=== RUN TestPendingClosureWriteTimeout/670k_objects860=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key861=== PAUSE TestIsValidUploadKey/listing862=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key863=== PAUSE TestPendingClosureWriteTimeout/670k_objects864=== RUN TestIsValidUploadKey/build_log865=== CONT TestGCTaskStore_ConflictDifferentParams866=== PAUSE TestIsValidUploadKey/build_log867=== RUN TestIsValidUploadKey/build_log_home-manager_file868=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline869=== CONT TestPush_OverlappingRootsStoreOneRowPerKey870--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)871=== PAUSE TestIsValidUploadKey/build_log_home-manager_file872=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline873=== RUN TestIsValidUploadKey/build_log_plus_in_name874=== PAUSE TestIsValidUploadKey/build_log_plus_in_name875=== CONT TestReadProxyOutlastsServerWriteTimeout876=== RUN TestIsValidUploadKey/build_log_question_mark877=== PAUSE TestIsValidUploadKey/build_log_question_mark878=== RUN TestIsValidUploadKey/build_log_equals879=== PAUSE TestIsValidUploadKey/build_log_equals880=== RUN TestIsValidUploadKey/realisation881=== PAUSE TestIsValidUploadKey/realisation882=== RUN TestIsValidUploadKey/realisation_plus_in_output883=== PAUSE TestIsValidUploadKey/realisation_plus_in_output884=== RUN TestIsValidUploadKey/nix-cache-info885=== PAUSE TestIsValidUploadKey/nix-cache-info886=== RUN TestIsValidUploadKey/index.html887=== PAUSE TestIsValidUploadKey/index.html888=== RUN TestIsValidUploadKey/narinfo_key,_nar_type889=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type890=== RUN TestIsValidUploadKey/nar_key,_narinfo_type891=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type892=== RUN TestIsValidUploadKey/listing_key,_narinfo_type893=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type894=== RUN TestIsValidUploadKey/traversal895=== PAUSE TestIsValidUploadKey/traversal896=== RUN TestIsValidUploadKey/traversal_nar897=== PAUSE TestIsValidUploadKey/traversal_nar898=== RUN TestIsValidUploadKey/absolute899=== PAUSE TestIsValidUploadKey/absolute900=== RUN TestIsValidUploadKey/empty_key901=== PAUSE TestIsValidUploadKey/empty_key902=== RUN TestIsValidUploadKey/unknown_type903=== PAUSE TestIsValidUploadKey/unknown_type904=== CONT TestReadRedirectUsesPublicS3URL9052026/09/24 18:05:51 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000906--- PASS: TestSkippedUploadsHandler (0.05s)907=== CONT TestReadProxy404908=== CONT TestPushDedupSurvivesConcurrentGC909--- PASS: TestGracefulShutdownDrainsInflight (0.07s)9102026/09/24 18:05:51 INFO Received uploads request method=POST path=/api/pending_closures9112026/09/24 18:05:51 INFO Received uploads request method=POST path=/api/pending_closures9122026/09/24 18:05:51 INFO Received uploads request method=POST path=/api/pending_closures9132026/09/24 18:05:51 INFO Received uploads request method=POST path=/api/pending_closures914=== NAME TestClientMultipleUploads915 client_integration_test.go:480: Created store path 0: /build/TestClientMultipleUploads207990619/001/store/hqcw6hfcpscz2h9d8xf9yilybf6hifip-test-file-0.txt916 client_integration_test.go:480: Created store path 1: /build/TestClientMultipleUploads207990619/001/store/9fva3k15900v63nq1s7qncybjfl40mp6-test-file-1.txt9172026/09/24 18:05:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete918 client_integration_test.go:480: Created store path 2: /build/TestClientMultipleUploads207990619/001/store/69y57ji4yf6jw3c5c85v284vnp8k83sz-test-file-2.txt919--- PASS: TestPresentReportsOnlyClosureRoots (0.49s)920--- PASS: TestService_Rustfstest (0.51s)921=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded922=== CONT TestProxyHeadersOnlyTrustedOnSocket923=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure924=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure925=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart926=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart927=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts928=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts929=== CONT TestService_ReadAuthMiddleware9302026/09/24 18:05:51 INFO Received cleanup request method=DELETE path=/api/pending_closures9312026/09/24 18:05:51 INFO Aborted multipart uploads count=0 kept=09322026/09/24 18:05:51 INFO Received uploads request method=POST path=/api/pending_closures9332026/09/24 18:05:51 INFO Received push request method=POST path=/api/pushes9342026/09/24 18:05:51 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)9352026/09/24 18:05:51 INFO Uploading 9fva3k15900v63nq1s7qncybjfl40mp6-test-file-1.txt (160B)9362026/09/24 18:05:51 INFO Uploading 69y57ji4yf6jw3c5c85v284vnp8k83sz-test-file-2.txt (160B)9372026/09/24 18:05:51 INFO Uploading hqcw6hfcpscz2h9d8xf9yilybf6hifip-test-file-0.txt (160B)9382026/09/24 18:05:51 INFO Received cleanup request method=DELETE path=/api/pending_closures9392026/09/24 18:05:51 INFO Aborted multipart uploads count=1 kept=09402026/09/24 18:05:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9412026-09-24 18:05:51.977 UTC [500] ERROR: Closure does not exist: id=19422026-09-24 18:05:51.977 UTC [500] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 19 at RAISE9432026-09-24 18:05:51.977 UTC [500] STATEMENT: -- name: CommitPendingClosure :exec944 SELECT commit_pending_closure($1::bigint)945 9462026/09/24 18:05:51 INFO Received uploads request method=POST path=/api/pending_closures9472026/09/24 18:05:51 INFO Received push request method=POST path=/api/pushes9482026/09/24 18:05:52 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"9492026/09/24 18:05:52 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"9502026/09/24 18:05:52 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"9512026/09/24 18:05:52 INFO Received uploads request method=POST path=/api/pending_closures9522026/09/24 18:05:52 INFO Received uploads request method=POST path=/api/pending_closures953=== CONT TestMetricsInventory954--- PASS: TestService_cleanupPendingClosuresHandler (0.73s)9552026/09/24 18:05:52 WARN Failed to register uploaded object key=9fva3k15900v63nq1s7qncybjfl40mp6.ls error="server returned 404: 404 page not found\n"9562026/09/24 18:05:52 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)9572026/09/24 18:05:52 WARN Failed to register uploaded object key=hqcw6hfcpscz2h9d8xf9yilybf6hifip.ls error="server returned 404: 404 page not found\n"9582026/09/24 18:05:52 WARN Failed to register uploaded object key=69y57ji4yf6jw3c5c85v284vnp8k83sz.ls error="server returned 404: 404 page not found\n"9592026/09/24 18:05:52 INFO Uploading ak5wklpqxg1sjqa2ds2h9p731q0hhmkp-shared-dep (136B)9602026/09/24 18:05:52 INFO Uploading lvj4jj24lwb87smqzggm37i771a8c3g3-a (216B)9612026/09/24 18:05:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9622026/09/24 18:05:52 INFO Signed narinfos id=1 count=39632026/09/24 18:05:52 INFO Uploading 3 narinfos9642026/09/24 18:05:52 WARN Failed to register uploaded object key=nar/0rw7mskynqmyij83szq4allixrx82m9kdshd9na3343sgslv2vkl.nar.zst error="server returned 404: 404 page not found\n"9652026/09/24 18:05:52 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"9662026/09/24 18:05:52 WARN Failed to register uploaded object key=ak5wklpqxg1sjqa2ds2h9p731q0hhmkp.ls error="server returned 404: 404 page not found\n"9672026/09/24 18:05:52 WARN Failed to register uploaded object key=jqz1bwjjvdvl43lx8g0wf3sanfxyknyd.ls error="server returned 404: 404 page not found\n"9682026/09/24 18:05:52 WARN Failed to register uploaded object key=lvj4jj24lwb87smqzggm37i771a8c3g3.ls error="server returned 404: 404 page not found\n"9692026/09/24 18:05:52 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign9702026/09/24 18:05:52 INFO Signed narinfos id=2 count=29712026/09/24 18:05:52 WARN Failed to register uploaded object key=9fva3k15900v63nq1s7qncybjfl40mp6.narinfo error="server returned 404: 404 page not found\n"9722026/09/24 18:05:52 WARN Failed to register uploaded object key=hqcw6hfcpscz2h9d8xf9yilybf6hifip.narinfo error="server returned 404: 404 page not found\n"9732026/09/24 18:05:52 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9742026/09/24 18:05:52 INFO Received complete push request method=POST path=/api/pushes/1/complete9752026/09/24 18:05:52 WARN Failed to register uploaded object key=69y57ji4yf6jw3c5c85v284vnp8k83sz.narinfo error="server returned 404: 404 page not found\n"9762026/09/24 18:05:52 INFO Signed narinfos id=1 count=29772026/09/24 18:05:52 INFO Uploading 4 narinfos9782026/09/24 18:05:52 WARN Failed to register uploaded object key=jqz1bwjjvdvl43lx8g0wf3sanfxyknyd.narinfo error="server returned 404: 404 page not found\n"9792026/09/24 18:05:52 INFO Upload complete. (251ms)980=== NAME TestClientMultipleUploads981 client_integration_test.go:491: Uploaded 3 paths in 289.784347ms982=== CONT TestNARDeduplicationMetadataUploadBug983--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.77s)9842026/09/24 18:05:52 WARN Failed to register uploaded object key=ak5wklpqxg1sjqa2ds2h9p731q0hhmkp.narinfo error="server returned 404: 404 page not found\n"9852026/09/24 18:05:52 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete9862026/09/24 18:05:52 WARN Failed to register uploaded object key=lvj4jj24lwb87smqzggm37i771a8c3g3.narinfo error="server returned 404: 404 page not found\n"9872026/09/24 18:05:52 WARN Failed to register uploaded object key=ak5wklpqxg1sjqa2ds2h9p731q0hhmkp.narinfo error="server returned 404: 404 page not found\n"9882026/09/24 18:05:52 INFO Completed upload id=29892026/09/24 18:05:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9902026/09/24 18:05:52 INFO Completed upload id=19912026/09/24 18:05:52 INFO Upload complete. (212ms)992--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.81s)993=== CONT TestService_RequireScope_OIDC994=== NAME TestClientFallsBackToClosures995 client_pushes_test.go:112: Retrieved narinfo from S3:996 StorePath: /build/TestClientFallsBackToClosures1846623540/001/store/ak5wklpqxg1sjqa2ds2h9p731q0hhmkp-shared-dep997 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst998 Compression: zstd999 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821000 NarSize: 1361001 References: 1002 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n10032026/09/24 18:05:52 INFO Received uploads request method=POST path=/api/pending_closures1004 client_pushes_test.go:112: Retrieved narinfo from S3:1005 StorePath: /build/TestClientFallsBackToClosures1846623540/001/store/lvj4jj24lwb87smqzggm37i771a8c3g3-a1006 URL: nar/0rw7mskynqmyij83szq4allixrx82m9kdshd9na3343sgslv2vkl.nar.zst1007 Compression: zstd1008 NarHash: sha256:0rw7mskynqmyij83szq4allixrx82m9kdshd9na3343sgslv2vkl1009 NarSize: 2161010 References: /build/TestClientFallsBackToClosures1846623540/001/store/ak5wklpqxg1sjqa2ds2h9p731q0hhmkp-shared-dep1011 CA: text:sha256:1gwvw1586hmvq6ib8qg63n3li1390jx95k91imjmp6wpca3hlb3a1012 client_pushes_test.go:112: Retrieved narinfo from S3:1013 StorePath: /build/TestClientFallsBackToClosures1846623540/001/store/jqz1bwjjvdvl43lx8g0wf3sanfxyknyd-b1014 URL: nar/0rw7mskynqmyij83szq4allixrx82m9kdshd9na3343sgslv2vkl.nar.zst1015 Compression: zstd1016 NarHash: sha256:0rw7mskynqmyij83szq4allixrx82m9kdshd9na3343sgslv2vkl1017 NarSize: 2161018 References: /build/TestClientFallsBackToClosures1846623540/001/store/ak5wklpqxg1sjqa2ds2h9p731q0hhmkp-shared-dep1019 CA: text:sha256:1gwvw1586hmvq6ib8qg63n3li1390jx95k91imjmp6wpca3hlb3a1020=== CONT TestCacheStatsHandler1021--- PASS: TestClientMultipleUploads (0.84s)10222026/09/24 18:05:52 INFO Received uploads request method=POST path=/api/pending_closures1023=== CONT TestServerTLSConfig1024--- PASS: TestClientFallsBackToClosures (0.86s)1025=== RUN TestServerTLSConfig/no_client_CA1026=== PAUSE TestServerTLSConfig/no_client_CA1027=== RUN TestServerTLSConfig/missing_CA_file1028=== PAUSE TestServerTLSConfig/missing_CA_file1029=== RUN TestServerTLSConfig/not_a_PEM_file1030=== PAUSE TestServerTLSConfig/not_a_PEM_file1031=== CONT TestGenerateLandingPage10322026/09/24 18:05:52 INFO Received push request method=POST path=/api/pushes10332026/09/24 18:05:52 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10342026/09/24 18:05:52 INFO Uploading 2yj9zm3wdaqalpdgz1ghiizclq4q762q-shared-dep (136B)10352026/09/24 18:05:52 INFO Uploading 4wm4sg8phkvvlhc2h6g4csnnhp0hlfq3-a (216B)10362026/09/24 18:05:52 WARN Failed to register uploaded object key=nar/006akhisin0pkqh2r4a42na2aas4qjvfhfv1xwvrwizk7c1a3dkn.nar.zst error="server returned 404: 404 page not found\n"10372026/09/24 18:05:52 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1038--- PASS: TestGenerateLandingPage (0.04s)1039=== CONT TestReadProxyRootRedirectsToIndexHTML10402026/09/24 18:05:52 WARN Failed to register uploaded object key=ywfdny7b438v78a1v3xjmdary1m9vh1f.ls error="server returned 404: 404 page not found\n"10412026/09/24 18:05:52 WARN Failed to register uploaded object key=4wm4sg8phkvvlhc2h6g4csnnhp0hlfq3.ls error="server returned 404: 404 page not found\n"10422026/09/24 18:05:52 WARN Failed to register uploaded object key=2yj9zm3wdaqalpdgz1ghiizclq4q762q.ls error="server returned 404: 404 page not found\n"10432026/09/24 18:05:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10442026/09/24 18:05:52 INFO Signed narinfos id=1 count=310452026/09/24 18:05:52 INFO Uploading 3 narinfos10462026/09/24 18:05:52 WARN Failed to register uploaded object key=2yj9zm3wdaqalpdgz1ghiizclq4q762q.narinfo error="server returned 404: 404 page not found\n"10472026/09/24 18:05:52 INFO Received complete push request method=POST path=/api/pushes/1/complete10482026/09/24 18:05:52 WARN Failed to register uploaded object key=ywfdny7b438v78a1v3xjmdary1m9vh1f.narinfo error="server returned 404: 404 page not found\n"10492026/09/24 18:05:52 WARN Failed to register uploaded object key=4wm4sg8phkvvlhc2h6g4csnnhp0hlfq3.narinfo error="server returned 404: 404 page not found\n"10502026/09/24 18:05:52 INFO Received uploads request method=POST path=/api/pending_closures10512026/09/24 18:05:52 INFO Upload complete. (100ms)10522026/09/24 18:05:52 INFO Received push request method=POST path=/api/pushes1053=== NAME TestClientPushesUseOnePush1054 client_pushes_test.go:97: Retrieved narinfo from S3:1055 StorePath: /build/TestClientPushesUseOnePush2336845179/001/store/2yj9zm3wdaqalpdgz1ghiizclq4q762q-shared-dep1056 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1057 Compression: zstd1058 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821059 NarSize: 1361060 References: 1061 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1062 client_pushes_test.go:97: Retrieved narinfo from S3:1063 StorePath: /build/TestClientPushesUseOnePush2336845179/001/store/4wm4sg8phkvvlhc2h6g4csnnhp0hlfq3-a1064 URL: nar/006akhisin0pkqh2r4a42na2aas4qjvfhfv1xwvrwizk7c1a3dkn.nar.zst1065 Compression: zstd1066 NarHash: sha256:006akhisin0pkqh2r4a42na2aas4qjvfhfv1xwvrwizk7c1a3dkn1067 NarSize: 2161068 References: /build/TestClientPushesUseOnePush2336845179/001/store/2yj9zm3wdaqalpdgz1ghiizclq4q762q-shared-dep1069 CA: text:sha256:0i72lfa20kzbsrvm1gxp9i2mcvqkgp822lhvp89cvw0rvmk2kgil1070 client_pushes_test.go:97: Retrieved narinfo from S3:1071 StorePath: /build/TestClientPushesUseOnePush2336845179/001/store/ywfdny7b438v78a1v3xjmdary1m9vh1f-b1072 URL: nar/006akhisin0pkqh2r4a42na2aas4qjvfhfv1xwvrwizk7c1a3dkn.nar.zst1073 Compression: zstd1074 NarHash: sha256:006akhisin0pkqh2r4a42na2aas4qjvfhfv1xwvrwizk7c1a3dkn1075 NarSize: 2161076 References: /build/TestClientPushesUseOnePush2336845179/001/store/2yj9zm3wdaqalpdgz1ghiizclq4q762q-shared-dep1077 CA: text:sha256:0i72lfa20kzbsrvm1gxp9i2mcvqkgp822lhvp89cvw0rvmk2kgil10782026/09/24 18:05:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39777/oidc1079=== CONT TestClientWithDependencies1080--- PASS: TestClientPushesUseOnePush (0.99s)1081--- PASS: TestReadProxyInvalidPath (0.99s)1082=== CONT TestGCTaskStore_GetReturnsLatest1083--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1084=== CONT TestGCTaskStore_Fail1085--- PASS: TestGCTaskStore_Fail (0.00s)1086=== CONT TestCacheConfigHandlerMaxNarSize1087--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1088=== CONT TestService_healthCheckHandler1089=== CONT TestPresignedUploadRegisteredBeforeCommit1090--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.99s)10912026/09/24 18:05:52 INFO Received uploads request method=POST path=/api/pending_closures10922026/09/24 18:05:52 INFO Aborted multipart uploads count=0 kept=010932026/09/24 18:05:52 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=010942026/09/24 18:05:52 INFO Vacuumed table table=pending_closures10952026/09/24 18:05:52 INFO Vacuumed table table=pending_objects10962026/09/24 18:05:52 INFO Vacuumed table table=multipart_uploads10972026/09/24 18:05:52 INFO Vacuumed table table=closures10982026/09/24 18:05:52 INFO Vacuumed table table=objects10992026/09/24 18:05:52 INFO Aborted multipart uploads count=0 kept=011002026/09/24 18:05:52 WARN Force mode enabled - objects will be deleted immediately without grace period11012026/09/24 18:05:52 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=011022026/09/24 18:05:52 INFO Vacuumed table table=pending_closures11032026/09/24 18:05:52 INFO Received uploads request method=POST path=/api/pending_closures11042026/09/24 18:05:52 INFO Vacuumed table table=pending_objects11052026/09/24 18:05:52 INFO Vacuumed table table=multipart_uploads11062026/09/24 18:05:52 INFO Vacuumed table table=closures11072026/09/24 18:05:52 INFO Vacuumed table table=objects11082026/09/24 18:05:52 INFO Received uploads request method=POST path=/api/pending_closures1109--- PASS: TestPushDedupSurvivesConcurrentGC (1.03s)1110=== CONT TestService_readinessHandler11112026/09/24 18:05:52 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket1350458655/001/proxy.sock11122026/09/24 18:05:52 INFO Starting HTTP server address=127.0.0.1:3431311132026/09/24 18:05:52 WARN mTLS auth: subject not in bound subjects subject="CN=someone"11142026/09/24 18:05:52 INFO Shutdown signal received, draining in-flight requests timeout=10s1115--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.65s)1116=== CONT TestResolveDBConnectionString1117=== RUN TestResolveDBConnectionString/flag_wins1118=== PAUSE TestResolveDBConnectionString/flag_wins1119=== RUN TestResolveDBConnectionString/file_when_flag_empty1120=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1121=== RUN TestResolveDBConnectionString/missing_file_is_an_error1122=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1123=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1124=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1125=== RUN TestResolveDBConnectionString/nothing_configured1126=== PAUSE TestResolveDBConnectionString/nothing_configured1127=== CONT TestPush_SignsNarinfosOfItsPendingObjects1128=== CONT TestGCTaskStore_CompletedAllowsNewTask1129--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.66s)1130--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1131=== CONT TestGCTaskStore_DeduplicateSameParams1132=== CONT TestPush_RejectsBadRequests1133--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)11342026/09/24 18:05:52 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"11352026/09/24 18:05:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1136=== CONT TestPinProtectsFromGC1137--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (1.23s)1138--- PASS: TestService_ReadAuthMiddleware (0.68s)1139=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit11402026/09/24 18:05:52 WARN Rate limiter enabled after throttle name=s3-test rate=511412026/09/24 18:05:52 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."11422026/09/24 18:05:52 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=YTU2OGIwYTUtMTE0YS00YWVmLTk5NDItYmZkYTI0ZTI3OWM2LmE2YzFhODU2LThjNGEtNGFhYS05YTI4LTU2YzlmNGM3YTczMngxNzkwMjczMTUxNjYxNTU0MzU2 parts=1011432026/09/24 18:05:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11442026/09/24 18:05:52 INFO Completed upload id=111452026/09/24 18:05:52 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011462026/09/24 18:05:52 INFO Received uploads request method=POST path=/api/pending_closures11472026/09/24 18:05:52 WARN Rate limiter backed off name=s3-test rate=511482026/09/24 18:05:52 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."11492026/09/24 18:05:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures1150=== CONT TestGCTaskStore_StartNew1151--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.27s)1152=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1153--- PASS: TestGCTaskStore_StartNew (0.00s)11542026/09/24 18:05:52 INFO Aborted multipart uploads count=0 kept=011552026/09/24 18:05:52 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=01156--- PASS: TestReadProxy404 (1.24s)1157=== CONT TestConnectSerialisesConcurrentMigrations11582026/09/24 18:05:52 INFO Vacuumed table table=pending_closures11592026/09/24 18:05:52 INFO Vacuumed table table=pending_objects11602026/09/24 18:05:52 INFO Vacuumed table table=multipart_uploads11612026/09/24 18:05:52 INFO Vacuumed table table=closures11622026/09/24 18:05:52 INFO Vacuumed table table=objects11632026/09/24 18:05:52 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001164--- PASS: TestReadRedirectUsesPublicS3URL (1.31s)1165=== CONT TestReadProxyDisabled1166--- PASS: TestMetricsInventory (0.60s)1167=== CONT TestReadProxyConditionalGet1168=== NAME TestNARDeduplicationMetadataUploadBug1169 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug912825244/001/store/aznqsqv8c1y8p6kw3a87hlan7x5hidpq-file1.txt1170=== CONT TestReadProxyHead1171--- PASS: TestService_createPendingClosureHandler (1.34s)1172=== CONT TestLeadEndsOnShutdown1173--- PASS: TestCacheStatsHandler (0.54s)11742026-09-24 18:05:52.694 UTC [943] ERROR: duplicate key value violates unique constraint "pg_type_typname_nsp_index"11752026-09-24 18:05:52.694 UTC [943] DETAIL: Key (typname, typnamespace)=(goose_db_version, 2200) already exists.11762026-09-24 18:05:52.694 UTC [943] STATEMENT: CREATE TABLE goose_db_version (1177 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1178 version_id bigint NOT NULL,1179 is_applied boolean NOT NULL,1180 tstamp timestamp NOT NULL DEFAULT now()1181 )1182--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.49s)1183=== CONT TestReadRedirectKeepsNarinfoProxied11842026/09/24 18:05:52 INFO Received push request method=POST path=/api/pushes1185=== RUN TestService_RequireScope_OIDC/builder_may_write1186=== PAUSE TestService_RequireScope_OIDC/builder_may_write1187=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1188=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1189=== RUN TestService_RequireScope_OIDC/ops_may_admin1190=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1191=== RUN TestService_RequireScope_OIDC/ops_may_not_write1192=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1193=== RUN TestService_RequireScope_OIDC/reader_may_not_write1194=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1195=== RUN TestService_RequireScope_OIDC/static_token_may_admin1196=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1197=== RUN TestService_RequireScope_OIDC/static_token_may_write1198=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1199=== RUN TestService_RequireScope_OIDC/reader_may_read1200=== PAUSE TestService_RequireScope_OIDC/reader_may_read1201=== RUN TestService_RequireScope_OIDC/writer_implies_read1202=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1203=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1204=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1205=== CONT TestGCSweepDeliversEachKeyOnce12062026/09/24 18:05:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12072026/09/24 18:05:52 INFO Uploading aznqsqv8c1y8p6kw3a87hlan7x5hidpq-file1.txt (160B)12082026/09/24 18:05:52 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12092026/09/24 18:05:52 WARN Failed to register uploaded object key=aznqsqv8c1y8p6kw3a87hlan7x5hidpq.ls error="server returned 404: 404 page not found\n"12102026/09/24 18:05:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1211--- PASS: TestService_healthCheckHandler (0.46s)1212=== CONT TestReadProxyRangeRequest12132026/09/24 18:05:52 INFO Signed narinfos id=1 count=112142026/09/24 18:05:52 INFO Uploading 1 narinfos12152026/09/24 18:05:52 INFO Received complete push request method=POST path=/api/pushes/1/complete12162026/09/24 18:05:52 WARN Failed to register uploaded object key=aznqsqv8c1y8p6kw3a87hlan7x5hidpq.narinfo error="server returned 404: 404 page not found\n"12172026/09/24 18:05:52 INFO Upload complete. (106ms)1218=== NAME TestNARDeduplicationMetadataUploadBug1219 metadata_upload_test.go:54: Retrieved narinfo from S3:1220 StorePath: /build/TestNARDeduplicationMetadataUploadBug912825244/001/store/aznqsqv8c1y8p6kw3a87hlan7x5hidpq-file1.txt1221 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1222 Compression: zstd1223 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1224 NarSize: 1601225 References: 1226 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1227 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)12282026/09/24 18:05:52 INFO Received uploads request method=POST path=/api/pending_closures1229 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1230 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12312026/09/24 18:05:52 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12322026/09/24 18:05:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12332026/09/24 18:05:52 INFO Received uploads request method=POST path=/api/pending_closures1234 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug912825244/001/store/8ay5bi15vp4vv8xlgyqz853snl67c8qw-file2.txt1235=== CONT TestSweepSparesObjectReuploadedMidSweep1236--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.56s)12372026/09/24 18:05:52 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=YTU2OGIwYTUtMTE0YS00YWVmLTk5NDItYmZkYTI0ZTI3OWM2LmI0MDUwNTM2LTcxMWEtNDJlMi1hMWE1LWFlYjE0MDc4NjIzMXgxNzkwMjczMTUyMDIwOTgyMjIz parts=1012382026/09/24 18:05:52 WARN readiness check failed error="closed pool"1239--- PASS: TestService_readinessHandler (0.48s)1240=== CONT TestGCEndsOnShutdown1241=== RUN TestGCEndsOnShutdown/before_the_run1242=== PAUSE TestGCEndsOnShutdown/before_the_run1243=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1244=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1245=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1246=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1247=== CONT TestCommitRacingPendingCleanupKeepsObjects12482026/09/24 18:05:52 INFO Received push request method=POST path=/api/pushes12492026/09/24 18:05:52 INFO Received push request method=POST path=/api/pushes12502026/09/24 18:05:52 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1251=== NAME TestClientWithDependencies1252 client_integration_test.go:735: Built derivation: /build/TestClientWithDependencies3739481816/001/store/993ihv94p1bllxqyfgfjd31qj4blgsq8-test-script12532026/09/24 18:05:52 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12542026/09/24 18:05:52 INFO Signed narinfos id=2 count=112552026/09/24 18:05:52 WARN Failed to register uploaded object key=8ay5bi15vp4vv8xlgyqz853snl67c8qw.ls error="server returned 404: 404 page not found\n"12562026/09/24 18:05:52 INFO Uploading 1 narinfos12572026/09/24 18:05:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12582026/09/24 18:05:52 INFO Signed narinfos id=1 count=11259=== RUN TestPush_RejectsBadRequests/no_roots1260=== PAUSE TestPush_RejectsBadRequests/no_roots1261=== RUN TestPush_RejectsBadRequests/no_objects1262=== PAUSE TestPush_RejectsBadRequests/no_objects1263=== RUN TestPush_RejectsBadRequests/bad_root1264=== PAUSE TestPush_RejectsBadRequests/bad_root1265=== RUN TestPush_RejectsBadRequests/root_not_in_objects1266=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1267=== CONT TestForceGCDuringPushOffersSweptObject1268=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1269=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1270=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1271=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1272=== CONT TestReadProxyNarinfo12732026/09/24 18:05:52 INFO Received complete push request method=POST path=/api/pushes/2/complete12742026/09/24 18:05:52 WARN Failed to register uploaded object key=8ay5bi15vp4vv8xlgyqz853snl67c8qw.narinfo error="server returned 404: 404 page not found\n"12752026/09/24 18:05:52 INFO Upload complete. (77ms)1276=== NAME TestNARDeduplicationMetadataUploadBug1277 metadata_upload_test.go:76: Retrieved narinfo from S3:1278 StorePath: /build/TestNARDeduplicationMetadataUploadBug912825244/001/store/8ay5bi15vp4vv8xlgyqz853snl67c8qw-file2.txt1279 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1280 Compression: zstd1281 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1282 NarSize: 1601283 References: 1284 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1285=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1286--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.49s)1287=== NAME TestNARDeduplicationMetadataUploadBug1288 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1289=== NAME TestClientWithDependencies1290 client_integration_test.go:737: Found 1 dependencies (including self)1291=== NAME TestNARDeduplicationMetadataUploadBug1292 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1293 {"version":1,"root":{"type":"regular","size":44}}12942026/09/24 18:05:52 INFO Received push request method=POST path=/api/pushes1295=== CONT TestCompleteMultipartUnregistered1296--- PASS: TestNARDeduplicationMetadataUploadBug (0.92s)12972026/09/24 18:05:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12982026/09/24 18:05:53 INFO Received push request method=POST path=/api/pushes12992026/09/24 18:05:53 INFO Received uploads request method=POST path=/api/pending_closures13002026/09/24 18:05:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13012026/09/24 18:05:53 INFO Uploading 993ihv94p1bllxqyfgfjd31qj4blgsq8-test-script (136B)13022026/09/24 18:05:53 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=YTU2OGIwYTUtMTE0YS00YWVmLTk5NDItYmZkYTI0ZTI3OWM2LjlkZjU2MDNhLWE3YjktNDRmOS1hMDQ2LTE2N2RkMjQwZWE5NngxNzkwMjczMTUyMTMxMTU3ODE4 parts=1213032026/09/24 18:05:53 INFO Received uploads request method=POST path=/api/pending_closures13042026/09/24 18:05:53 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13052026/09/24 18:05:53 WARN Failed to register uploaded object key=log/3mpvilgd3w7fq021ds8xgzswaf3gx85c-test-script.drv error="server returned 404: 404 page not found\n"13062026/09/24 18:05:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13072026/09/24 18:05:53 WARN Failed to register uploaded object key=993ihv94p1bllxqyfgfjd31qj4blgsq8.ls error="server returned 404: 404 page not found\n"13082026/09/24 18:05:53 INFO Signed narinfos id=1 count=113092026/09/24 18:05:53 INFO Uploading 1 narinfos1310=== NAME TestPinProtectsFromGC1311 client_integration_test.go:867: Pinned store path: /build/TestPinProtectsFromGC50518958/001/store/as0x10f3qfd3qmyj8ip5s57zkr8r01ck-pinned-file.txt1312 client_integration_test.go:868: Unpinned store path: /build/TestPinProtectsFromGC50518958/001/store/5iasa5syqri033diqjm9gq1jvm46px69-unpinned-file.txt13132026/09/24 18:05:53 INFO Received complete push request method=POST path=/api/pushes/1/complete13142026/09/24 18:05:53 WARN Failed to register uploaded object key=993ihv94p1bllxqyfgfjd31qj4blgsq8.narinfo error="server returned 404: 404 page not found\n"13152026/09/24 18:05:53 INFO Received uploads request method=POST path=/api/pending_closures1316--- PASS: TestReadProxyDisabled (0.48s)1317=== CONT TestTombstonedObjectOfferedWithoutWaiting13182026/09/24 18:05:53 INFO Upload complete. (114ms)13192026/09/24 18:05:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13202026/09/24 18:05:53 INFO Aborted multipart uploads count=0 kept=013212026/09/24 18:05:53 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTU2OGIwYTUtMTE0YS00YWVmLTk5NDItYmZkYTI0ZTI3OWM2LjUxMTQyNzEzLWU2ODYtNGYxMy05NWFhLTE4NTg3YTAxMDBjYngxNzkwMjczMTUzMDY3MjUwOTEw13222026/09/24 18:05:53 WARN Force mode enabled - objects will be deleted immediately without grace period13232026/09/24 18:05:53 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=013242026/09/24 18:05:53 INFO lead: acquired remote=192.0.2.1:123413252026/09/24 18:05:53 INFO Vacuumed table table=pending_closures13262026/09/24 18:05:53 INFO Vacuumed table table=pending_objects13272026/09/24 18:05:53 INFO Vacuumed table table=multipart_uploads13282026/09/24 18:05:53 INFO Vacuumed table table=closures13292026/09/24 18:05:53 INFO Vacuumed table table=objects1330=== NAME TestClientWithDependencies1331 client_integration_test.go:753: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3739481816/001/store) requires matching store prefix13322026/09/24 18:05:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13332026/09/24 18:05:53 INFO Received push request method=POST path=/api/pushes13342026/09/24 18:05:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13352026/09/24 18:05:53 INFO Uploading as0x10f3qfd3qmyj8ip5s57zkr8r01ck-pinned-file.txt (128B)13362026/09/24 18:05:53 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=YTU2OGIwYTUtMTE0YS00YWVmLTk5NDItYmZkYTI0ZTI3OWM2LjBjNjc5YWVjLTQ0ZDktNDI0Mi04YTVkLWU0MWRlZTg1MTM0YXgxNzkwMjczMTUyMzMzMDA0OTI3 parts=1013372026/09/24 18:05:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1338--- PASS: TestClientWithDependencies (0.89s)1339=== CONT TestGCSweepSkipsPendingObjects13402026/09/24 18:05:53 INFO Completed upload id=113412026/09/24 18:05:53 INFO Received uploads request method=POST path=/api/pending_closures13422026/09/24 18:05:53 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13432026/09/24 18:05:53 INFO Received uploads request method=POST path=/api/pending_closures13442026/09/24 18:05:53 WARN Failed to register uploaded object key=as0x10f3qfd3qmyj8ip5s57zkr8r01ck.ls error="server returned 404: 404 page not found\n"13452026/09/24 18:05:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13462026/09/24 18:05:53 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTU2OGIwYTUtMTE0YS00YWVmLTk5NDItYmZkYTI0ZTI3OWM2LjUxMTQyNzEzLWU2ODYtNGYxMy05NWFhLTE4NTg3YTAxMDBjYngxNzkwMjczMTUzMDY3MjUwOTEw error="Delete \"http://localhost:36873/bucket43/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=YTU2OGIwYTUtMTE0YS00YWVmLTk5NDItYmZkYTI0ZTI3OWM2LjUxMTQyNzEzLWU2ODYtNGYxMy05NWFhLTE4NTg3YTAxMDBjYngxNzkwMjczMTUzMDY3MjUwOTEw\": injected: abort refused"13472026/09/24 18:05:53 INFO Signed narinfos id=1 count=113482026/09/24 18:05:53 INFO Uploading 1 narinfos13492026/09/24 18:05:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13502026/09/24 18:05:53 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13512026/09/24 18:05:53 WARN Found objects in DB but missing from S3, will re-upload count=11352=== CONT TestSweepRowDeleteSparesResurrectedObject1353--- PASS: TestReadProxyHead (0.58s)13542026/09/24 18:05:53 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTU2OGIwYTUtMTE0YS00YWVmLTk5NDItYmZkYTI0ZTI3OWM2LjUxMTQyNzEzLWU2ODYtNGYxMy05NWFhLTE4NTg3YTAxMDBjYngxNzkwMjczMTUzMDY3MjUwOTEw13552026/09/24 18:05:53 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete13562026/09/24 18:05:53 INFO Received complete push request method=POST path=/api/pushes/1/complete13572026/09/24 18:05:53 WARN Failed to register uploaded object key=as0x10f3qfd3qmyj8ip5s57zkr8r01ck.narinfo error="server returned 404: 404 page not found\n"13582026/09/24 18:05:53 INFO Completed upload id=313592026/09/24 18:05:53 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=YTU2OGIwYTUtMTE0YS00YWVmLTk5NDItYmZkYTI0ZTI3OWM2LjUxMTQyNzEzLWU2ODYtNGYxMy05NWFhLTE4NTg3YTAxMDBjYngxNzkwMjczMTUzMDY3MjUwOTEw parts=113602026/09/24 18:05:53 INFO Upload complete. (105ms)1361--- PASS: TestService_verifyS3Integrity (1.95s)1362=== CONT TestDeduplicatedObjectsRecordedAsPending1363=== CONT TestObjectStatsTrigger1364--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.69s)13652026/09/24 18:05:53 INFO Aborted multipart uploads count=0 kept=013662026/09/24 18:05:53 WARN Force mode enabled - objects will be deleted immediately without grace period13672026/09/24 18:05:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13682026/09/24 18:05:53 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=013692026/09/24 18:05:53 INFO Vacuumed table table=pending_closures13702026/09/24 18:05:53 INFO Vacuumed table table=pending_objects13712026/09/24 18:05:53 INFO Vacuumed table table=multipart_uploads13722026/09/24 18:05:53 INFO Vacuumed table table=closures13732026/09/24 18:05:53 INFO Received push request method=POST path=/api/pushes13742026/09/24 18:05:53 INFO Vacuumed table table=objects13752026/09/24 18:05:53 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13762026/09/24 18:05:53 INFO Uploading 5iasa5syqri033diqjm9gq1jvm46px69-unpinned-file.txt (128B)1377--- PASS: TestReadProxyRangeRequest (0.57s)1378=== CONT TestConnectWaitsForAPeerMigration13792026/09/24 18:05:53 INFO Aborted multipart uploads count=0 kept=013802026/09/24 18:05:53 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=YTU2OGIwYTUtMTE0YS00YWVmLTk5NDItYmZkYTI0ZTI3OWM2LmZlNTc4NzhlLTczMDctNDkyNy1hM2RmLWQxYWI5YjIxOGFmNngxNzkwMjczMTUyMzkzOTY0NjYx parts=1213812026/09/24 18:05:53 INFO Received uploads request method=POST path=/api/pending_closures13822026/09/24 18:05:53 INFO Received uploads request method=POST path=/api/pending_closures1383--- PASS: TestGCSweepDeliversEachKeyOnce (0.60s)1384=== CONT TestGCMetrics13852026/09/24 18:05:53 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"13862026/09/24 18:05:53 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13872026/09/24 18:05:53 WARN Failed to register uploaded object key=5iasa5syqri033diqjm9gq1jvm46px69.ls error="server returned 404: 404 page not found\n"13882026/09/24 18:05:53 INFO Signed narinfos id=2 count=11389=== CONT TestLeadElectsOneAndHandsOver13902026/09/24 18:05:53 INFO Uploading 1 narinfos1391--- PASS: TestReadRedirectKeepsNarinfoProxied (0.64s)13922026/09/24 18:05:53 INFO Received complete push request method=POST path=/api/pushes/2/complete13932026/09/24 18:05:53 WARN Failed to register uploaded object key=5iasa5syqri033diqjm9gq1jvm46px69.narinfo error="server returned 404: 404 page not found\n"13942026/09/24 18:05:53 INFO Upload complete. (80ms)1395=== CONT TestIsValidCachePath1396=== RUN TestIsValidCachePath/narinfo1397--- PASS: TestCompletedNarNotReofferedAcrossClosures (2.06s)1398=== PAUSE TestIsValidCachePath/narinfo1399=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1400=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1401=== RUN TestIsValidCachePath/nar_zst1402=== PAUSE TestIsValidCachePath/nar_zst1403=== RUN TestIsValidCachePath/nar_xz1404=== PAUSE TestIsValidCachePath/nar_xz1405=== RUN TestIsValidCachePath/nar_bz21406=== PAUSE TestIsValidCachePath/nar_bz21407=== RUN TestIsValidCachePath/nar_uncompressed1408=== PAUSE TestIsValidCachePath/nar_uncompressed1409=== RUN TestIsValidCachePath/ls1410=== PAUSE TestIsValidCachePath/ls1411=== RUN TestIsValidCachePath/log1412=== PAUSE TestIsValidCachePath/log1413=== RUN TestIsValidCachePath/realisation1414=== PAUSE TestIsValidCachePath/realisation1415=== RUN TestIsValidCachePath/nix-cache-info1416=== PAUSE TestIsValidCachePath/nix-cache-info1417=== RUN TestIsValidCachePath/index.html1418=== PAUSE TestIsValidCachePath/index.html1419=== RUN TestIsValidCachePath/traversal_parent1420=== PAUSE TestIsValidCachePath/traversal_parent1421=== RUN TestIsValidCachePath/traversal_in_middle1422=== PAUSE TestIsValidCachePath/traversal_in_middle1423=== RUN TestIsValidCachePath/invalid_char_e1424=== PAUSE TestIsValidCachePath/invalid_char_e1425=== RUN TestIsValidCachePath/invalid_char_u1426=== PAUSE TestIsValidCachePath/invalid_char_u1427=== RUN TestIsValidCachePath/random_path1428=== PAUSE TestIsValidCachePath/random_path1429=== RUN TestIsValidCachePath/empty1430=== PAUSE TestIsValidCachePath/empty1431=== RUN TestIsValidCachePath/leading_slash1432=== PAUSE TestIsValidCachePath/leading_slash1433=== RUN TestIsValidCachePath/wrong_extension1434=== PAUSE TestIsValidCachePath/wrong_extension1435=== RUN TestIsValidCachePath/short_hash1436=== PAUSE TestIsValidCachePath/short_hash1437=== CONT TestGCBugBareHashReferences1438--- PASS: TestReadProxyConditionalGet (0.75s)1439=== CONT TestReadRedirectNar14402026/09/24 18:05:53 INFO Starting cleanup of old closures method=DELETE path=/api/closures14412026/09/24 18:05:53 INFO Garbage collection started14422026/09/24 18:05:53 INFO Aborted multipart uploads count=0 kept=014432026/09/24 18:05:53 WARN Force mode enabled - objects will be deleted immediately without grace period14442026/09/24 18:05:53 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/09/24 18:05:53 INFO Vacuumed table table=pending_closures14462026/09/24 18:05:53 INFO Aborted multipart uploads count=0 kept=014472026/09/24 18:05:53 INFO Vacuumed table table=pending_objects14482026/09/24 18:05:53 INFO Vacuumed table table=multipart_uploads14492026/09/24 18:05:53 WARN Force mode enabled - objects will be deleted immediately without grace period14502026/09/24 18:05:53 INFO Vacuumed table table=closures14512026/09/24 18:05:53 INFO Vacuumed table table=objects14522026/09/24 18:05:53 INFO Received uploads request method=POST path=/api/pending_closures14532026/09/24 18:05:53 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=014542026/09/24 18:05:53 INFO Vacuumed table table=pending_closures14552026/09/24 18:05:53 INFO Vacuumed table table=pending_objects14562026/09/24 18:05:53 INFO Vacuumed table table=multipart_uploads1457=== CONT TestMultipartCleanup1458--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.56s)14592026/09/24 18:05:53 INFO Vacuumed table table=closures14602026/09/24 18:05:53 INFO Vacuumed table table=objects14612026/09/24 18:05:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14622026/09/24 18:05:53 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1463--- PASS: TestCompleteMultipartUnregistered (0.48s)1464=== CONT TestParseSingleRange1465=== RUN TestParseSingleRange/none1466=== PAUSE TestParseSingleRange/none1467=== RUN TestParseSingleRange/unknown_unit1468=== PAUSE TestParseSingleRange/unknown_unit1469=== RUN TestParseSingleRange/multi-range_ignored1470=== PAUSE TestParseSingleRange/multi-range_ignored1471=== RUN TestParseSingleRange/malformed_no_dash1472=== PAUSE TestParseSingleRange/malformed_no_dash1473=== RUN TestParseSingleRange/malformed_both_empty1474=== PAUSE TestParseSingleRange/malformed_both_empty1475=== RUN TestParseSingleRange/malformed_end_before_start1476=== PAUSE TestParseSingleRange/malformed_end_before_start1477=== RUN TestParseSingleRange/closed1478=== PAUSE TestParseSingleRange/closed1479=== RUN TestParseSingleRange/open-ended1480=== PAUSE TestParseSingleRange/open-ended1481=== RUN TestParseSingleRange/end_clamped_to_size1482=== PAUSE TestParseSingleRange/end_clamped_to_size1483=== RUN TestParseSingleRange/suffix1484=== PAUSE TestParseSingleRange/suffix1485=== RUN TestParseSingleRange/suffix_exceeds_size1486=== PAUSE TestParseSingleRange/suffix_exceeds_size1487=== RUN TestParseSingleRange/single_byte1488=== PAUSE TestParseSingleRange/single_byte1489=== RUN TestParseSingleRange/start_past_EOF1490=== PAUSE TestParseSingleRange/start_past_EOF1491=== RUN TestParseSingleRange/start_far_past_EOF1492=== PAUSE TestParseSingleRange/start_far_past_EOF1493=== CONT TestResurrectedObjectNotDeleted14942026/09/24 18:05:53 INFO Received uploads request method=POST path=/api/pending_closures1495--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.42s)1496=== CONT TestCreatePinRejectsBadInput14972026/09/24 18:05:53 INFO Received uploads request method=POST path=/api/pending_closures14982026/09/24 18:05:53 INFO Aborted multipart uploads count=0 kept=014992026/09/24 18:05:53 WARN Force mode enabled - objects will be deleted immediately without grace period15002026/09/24 18:05:53 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=015012026/09/24 18:05:53 INFO Vacuumed table table=pending_closures15022026/09/24 18:05:53 INFO Vacuumed table table=pending_objects15032026/09/24 18:05:53 INFO Vacuumed table table=multipart_uploads15042026/09/24 18:05:53 INFO Vacuumed table table=closures15052026/09/24 18:05:53 INFO Vacuumed table table=objects1506--- PASS: TestSweepRowDeleteSparesResurrectedObject (0.37s)1507=== CONT TestConcurrentPinUpdatesAgree1508--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (2.30s)1509=== CONT TestCreatePin_ReservedPins15102026/09/24 18:05:53 INFO Received uploads request method=POST path=/api/pending_closures1511--- PASS: TestGCSweepSkipsPendingObjects (0.43s)1512=== CONT TestPendingClosureFailureAbortsItsUploads1513=== CONT TestOrphanedObjectsGCStressTest1514--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.38s)1515=== CONT TestSweepKeepsTombstoneWhenDeleteOutcomeUnknown1516--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.72s)15172026/09/24 18:05:53 INFO Aborted multipart uploads count=0 kept=015182026/09/24 18:05:53 WARN Force mode enabled - objects will be deleted immediately without grace period15192026/09/24 18:05:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15202026/09/24 18:05:53 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=015212026/09/24 18:05:53 INFO Vacuumed table table=pending_closures15222026/09/24 18:05:53 INFO Vacuumed table table=pending_objects15232026/09/24 18:05:53 INFO Vacuumed table table=multipart_uploads15242026/09/24 18:05:53 INFO Vacuumed table table=closures15252026/09/24 18:05:53 INFO Vacuumed table table=objects1526--- PASS: TestObjectStatsTrigger (0.43s)1527=== CONT TestDeletePinKeepsRowWhenS3Fails15282026/09/24 18:05:53 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=YTU2OGIwYTUtMTE0YS00YWVmLTk5NDItYmZkYTI0ZTI3OWM2LjQ3YzdiNjFjLWU2MDAtNGE2MC05NDdmLWVkMTcyMzc5YjQ0NHgxNzkwMjczMTUyMDExNTExMDkw parts=1015292026/09/24 18:05:53 INFO lead: acquired remote=192.0.2.1:12341530--- PASS: TestConnectSerialisesConcurrentMigrations (1.13s)1531=== CONT TestPendingClosureFailureTracksEveryUpload1532--- PASS: TestGCMetrics (0.42s)1533=== CONT TestOrphanedObjectsGC15342026/09/24 18:05:53 INFO Received uploads request method=POST path=/api/pending_closures15352026/09/24 18:05:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1536=== CONT TestPendingCleanupUsesOneCutoff1537--- PASS: TestReadRedirectNar (0.47s)15382026/09/24 18:05:53 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=YTU2OGIwYTUtMTE0YS00YWVmLTk5NDItYmZkYTI0ZTI3OWM2LjZhOTU0OTFkLTE2MzAtNDBkMS04ZGVmLWJiNGY3MTljM2M0MXgxNzkwMjczMTUyOTk0NzczMDYz parts=1015392026/09/24 18:05:53 INFO Received create pin request method=POST path=/api/pins/deploy15402026/09/24 18:05:53 INFO Received create pin request method=POST path=/api/pins/deploy15412026/09/24 18:05:53 INFO Received create pin request method=POST path=/api/pins/deploy15422026/09/24 18:05:53 INFO Received create pin request method=POST path=/api/pins/deploy15432026/09/24 18:05:53 INFO Received create pin request method=POST path=/api/pins/deploy15442026/09/24 18:05:53 INFO Received create pin request method=POST path=/api/pins/deploy15452026/09/24 18:05:53 INFO Received create pin request method=POST path=/api/pins/deploy15462026/09/24 18:05:53 INFO Received create pin request method=POST path=/api/pins/deploy15472026/09/24 18:05:53 INFO Received create pin request method=POST path=/api/pins/app15482026/09/24 18:05:53 INFO Received create pin request method=POST path=/api/pins/app15492026/09/24 18:05:53 INFO Received uploads request method=POST path=/api/pending_closures1550--- PASS: TestResurrectedObjectNotDeleted (0.47s)1551=== CONT TestValidateS3Concurrency1552=== CONT TestReadProxyNarStreaming1553--- PASS: TestValidateS3Concurrency (0.00s)15542026/09/24 18:05:53 INFO Received create pin request method=POST path=/api/pins/deploy15552026/09/24 18:05:53 INFO Received cleanup request method=DELETE path=/api/pending_closures15562026/09/24 18:05:53 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket65/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""15572026/09/24 18:05:53 INFO Aborted multipart uploads count=0 kept=115582026/09/24 18:05:53 INFO Received cleanup request method=DELETE path=/api/pending_closures15592026/09/24 18:05:53 INFO Aborted multipart uploads count=1 kept=01560--- PASS: TestMultipartCleanup (0.55s)1561=== CONT TestService_ReadScope_PublicByDefault1562--- PASS: TestPendingClosureFailureAbortsItsUploads (0.39s)1563=== CONT TestCacheConfigHandler1564=== RUN TestCacheConfigHandler/full_config,_no_issuer1565=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1566=== RUN TestCacheConfigHandler/no_cache_url_configured1567=== PAUSE TestCacheConfigHandler/no_cache_url_configured1568=== RUN TestCacheConfigHandler/no_signing_keys1569=== PAUSE TestCacheConfigHandler/no_signing_keys1570=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1571=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1572=== CONT TestService_NativeMTLS15732026/09/24 18:05:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1574=== CONT TestClientIntegration1575--- PASS: TestGCBugBareHashReferences (0.65s)15762026/09/24 18:05:54 INFO Aborted multipart uploads count=0 kept=015772026/09/24 18:05:54 WARN Force mode enabled - objects will be deleted immediately without grace period15782026/09/24 18:05:54 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YTU2OGIwYTUtMTE0YS00YWVmLTk5NDItYmZkYTI0ZTI3OWM2LjQxMzYwNzBhLTJjNGMtNDI1YS1iYzVlLTBiMjM4NjQ3ZWM5N3gxNzkwMjczMTUzMTEyNTI0NTEy error="Get \"http://127.0.0.1:1/bucket17/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"15792026/09/24 18:05:54 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=YTU2OGIwYTUtMTE0YS00YWVmLTk5NDItYmZkYTI0ZTI3OWM2LmM1YzQ2MTFlLTA4MDktNGQwMC05MDk4LTg0YTBlYjljNDAzZHgxNzkwMjczMTUzMDg0NDAyODE4 parts=1215802026/09/24 18:05:54 INFO Received cleanup request method=DELETE path=/api/pending_closures15812026/09/24 18:05:54 INFO Received create pin request method=POST path=/api/pins/app15822026/09/24 18:05:54 INFO Aborted multipart uploads count=1 kept=015832026/09/24 18:05:54 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo15842026/09/24 18:05:54 INFO Received delete pin request method=DELETE path=/api/pins/app15852026/09/24 18:05:54 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket72/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"15862026/09/24 18:05:54 INFO Received delete pin request method=DELETE path=/api/pins/app15872026/09/24 18:05:54 INFO Received uploads request method=POST path=/api/pending_closures15882026/09/24 18:05:54 INFO Deleted pin name=app1589--- PASS: TestRedundantMultipartUpload (2.78s)1590=== CONT TestClientErrorHandling1591=== RUN TestClientErrorHandling/InvalidStorePath1592=== PAUSE TestClientErrorHandling/InvalidStorePath1593=== RUN TestClientErrorHandling/InvalidAuthToken1594=== PAUSE TestClientErrorHandling/InvalidAuthToken1595=== RUN TestClientErrorHandling/ServerNotAvailable1596=== PAUSE TestClientErrorHandling/ServerNotAvailable1597=== CONT TestReconnectLeavesObjectsUnlocked15982026/09/24 18:05:54 ERROR failed to remove object object=nar/nnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnnn.nar.zst error="We encountered an internal error."15992026/09/24 18:05:54 INFO Received uploads request method=POST path=/api/pending_closures1600--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.41s)1601=== CONT TestClientCADerivations16022026/09/24 18:05:54 INFO Aborted multipart uploads count=0 kept=016032026/09/24 18:05:54 WARN Force mode enabled - objects will be deleted immediately without grace period16042026/09/24 18:05:54 INFO Garbage collection completed failed-uploads-deleted=1 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=2 objects-failed-to-delete=016052026/09/24 18:05:54 INFO Vacuumed table table=pending_closures16062026/09/24 18:05:54 INFO Received uploads request method=POST path=/api/pending_closures16072026/09/24 18:05:54 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"16082026/09/24 18:05:54 INFO Vacuumed table table=pending_objects16092026/09/24 18:05:54 INFO Vacuumed table table=multipart_uploads16102026/09/24 18:05:54 INFO Vacuumed table table=closures16112026/09/24 18:05:54 INFO Vacuumed table table=objects16122026/09/24 18:05:54 INFO Received uploads request method=POST path=/api/pending_closures1613=== CONT TestReadProxyNarinfoAlreadyDecompressed1614--- PASS: TestSweepKeepsTombstoneWhenDeleteOutcomeUnknown (0.50s)16152026/09/24 18:05:54 INFO lead: released remote=192.0.2.1:123416162026/09/24 18:05:54 INFO Received cleanup request method=DELETE path=/api/pending_closures16172026/09/24 18:05:54 WARN mTLS auth: subject not in bound subjects subject="CN=reader"16182026/09/24 18:05:54 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1619--- PASS: TestLeadEndsOnShutdown (1.54s)1620=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1621--- PASS: TestReadProxyNarStreaming (0.27s)1622=== CONT TestService_AuthMiddleware_OIDC1623--- PASS: TestService_NativeMTLS (0.22s)1624=== CONT TestClientSharedPathCommittedMidPush1625--- PASS: TestService_ReadScope_PublicByDefault (0.26s)1626=== CONT TestService_AuthMiddleware16272026/09/24 18:05:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44985/oidc1628=== NAME TestClientIntegration1629 client_integration_test.go:334: Created store path: /build/TestClientIntegration2622554995/002/store/k3ndrlbbmaa21swk0pvnya6vkk3b3syj-test-file.txt16302026/09/24 18:05:54 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=016312026/09/24 18:05:54 INFO Vacuumed table table=pending_closures16322026/09/24 18:05:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45591/oidc16332026/09/24 18:05:54 INFO Vacuumed table table=pending_objects16342026/09/24 18:05:54 INFO Vacuumed table table=multipart_uploads16352026/09/24 18:05:54 INFO Vacuumed table table=closures16362026/09/24 18:05:54 INFO Vacuumed table table=objects1637=== CONT TestCreatePendingClosureRejectsOversizedNAR1638--- PASS: TestReconnectLeavesObjectsUnlocked (0.31s)16392026/09/24 18:05:54 INFO Received uploads request method=POST path=/api/pending_closures1640--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1641=== CONT TestProxyWriteTimeout/narinfo1642=== CONT TestProxyWriteTimeout/10_GiB_nar1643=== CONT TestProxyWriteTimeout/1_GiB_nar1644=== CONT TestProxyWriteTimeout/unknown_size1645=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1646--- PASS: TestProxyWriteTimeout (0.01s)1647 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1648 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1649 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1650 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)16512026/09/24 18:05:54 INFO Received complete multipart upload request method=POST path=/1652=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal16532026/09/24 18:05:54 INFO Received uploads request method=POST path=/1654=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key16552026/09/24 18:05:54 INFO Received request for more parts method=POST path=/1656=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info16572026/09/24 18:05:54 INFO Received uploads request method=POST path=/1658=== CONT TestPendingClosureWriteTimeout/empty1659--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)1660 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1661 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1662 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1663 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1664=== CONT TestPendingClosureWriteTimeout/670k_objects1665=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1666=== CONT TestPendingClosureWriteTimeout/negative1667--- PASS: TestSweepSparesObjectReuploadedMidSweep (1.56s)1668=== CONT TestPendingClosureWriteTimeout/400_objects1669=== CONT TestIsValidUploadKey/nar_zst1670=== CONT TestIsValidUploadKey/unknown_type1671=== CONT TestIsValidUploadKey/realisation_plus_in_output1672=== CONT TestIsValidUploadKey/empty_key1673=== CONT TestIsValidUploadKey/absolute1674=== CONT TestIsValidUploadKey/traversal_nar1675=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1676=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1677=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1678=== CONT TestIsValidUploadKey/traversal1679=== CONT TestIsValidUploadKey/nix-cache-info1680=== CONT TestIsValidUploadKey/index.html1681=== CONT TestIsValidUploadKey/realisation1682=== CONT TestIsValidUploadKey/build_log_plus_in_name1683=== CONT TestIsValidUploadKey/build_log_home-manager_file1684=== CONT TestIsValidUploadKey/nar_xz1685=== CONT TestIsValidUploadKey/listing1686=== CONT TestIsValidUploadKey/nar_plain1687=== CONT TestIsValidUploadKey/build_log1688=== CONT TestIsValidUploadKey/build_log_question_mark1689=== CONT TestIsValidUploadKey/build_log_equals1690=== CONT TestIsValidUploadKey/narinfo1691=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart1692--- PASS: TestIsValidUploadKey (0.01s)1693 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1694 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1695 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1696 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1697 --- PASS: TestIsValidUploadKey/absolute (0.00s)1698 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1699 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1700 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1701 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1702 --- PASS: TestIsValidUploadKey/traversal (0.00s)1703 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1704 --- PASS: TestIsValidUploadKey/index.html (0.00s)1705 --- PASS: TestIsValidUploadKey/realisation (0.00s)1706 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1707 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1708 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1709 --- PASS: TestIsValidUploadKey/listing (0.00s)1710 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1711 --- PASS: TestIsValidUploadKey/build_log (0.00s)1712 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1713 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1714 --- PASS: TestIsValidUploadKey/narinfo (0.00s)17152026/09/24 18:05:54 INFO Received complete multipart upload request method=POST path=/17162026/09/24 18:05:54 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17172026/09/24 18:05:54 WARN mTLS auth: bound subjects configured but subject DN unavailable17182026/09/24 18:05:54 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1719=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts1720--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.26s)17212026/09/24 18:05:54 INFO Received request for more parts method=POST path=/17222026/09/24 18:05:54 INFO Received push request method=POST path=/api/pushes1723=== NAME TestClientCADerivations1724 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations4112215898/001/store/zy9w27mj0n04862nl99hrn88wdp3lv3s-ca-test17252026/09/24 18:05:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17262026/09/24 18:05:54 INFO Uploading k3ndrlbbmaa21swk0pvnya6vkk3b3syj-test-file.txt (152B)17272026/09/24 18:05:54 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo1728--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.23s)1729=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17302026/09/24 18:05:54 INFO Received uploads request method=POST path=/17312026/09/24 18:05:54 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17322026/09/24 18:05:54 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo17332026/09/24 18:05:54 WARN Failed to register uploaded object key=k3ndrlbbmaa21swk0pvnya6vkk3b3syj.ls error="server returned 404: 404 page not found\n"17342026/09/24 18:05:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17352026/09/24 18:05:54 INFO Signed narinfos id=1 count=117362026/09/24 18:05:54 INFO Uploading 1 narinfos1737=== NAME TestClientCADerivations1738 client_ca_test.go:139: Found 1 dependencies (including self)17392026/09/24 18:05:54 INFO Received complete push request method=POST path=/api/pushes/1/complete17402026/09/24 18:05:54 WARN Failed to register uploaded object key=k3ndrlbbmaa21swk0pvnya6vkk3b3syj.narinfo error="server returned 404: 404 page not found\n"1741=== CONT TestServerTLSConfig/no_client_CA1742--- PASS: TestConcurrentPinUpdatesAgree (0.89s)1743=== CONT TestServerTLSConfig/not_a_PEM_file1744=== CONT TestServerTLSConfig/missing_CA_file17452026/09/24 18:05:54 INFO Upload complete. (104ms)1746=== CONT TestResolveDBConnectionString/flag_wins1747=== CONT TestResolveDBConnectionString/nothing_configured17482026/09/24 18:05:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1749--- PASS: TestServerTLSConfig (0.00s)1750 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1751 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1752 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1753=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1754=== CONT TestResolveDBConnectionString/missing_file_is_an_error1755=== CONT TestResolveDBConnectionString/file_when_flag_empty1756=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1757--- PASS: TestResolveDBConnectionString (0.00s)1758 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1759 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1760 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1761 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1762 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1763=== CONT TestService_RequireScope_OIDC/static_token_may_admin1764=== CONT TestService_RequireScope_OIDC/writer_implies_read17652026/09/24 18:05:54 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1766=== CONT TestService_RequireScope_OIDC/reader_may_read1767=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1768=== CONT TestService_RequireScope_OIDC/static_token_may_write1769=== CONT TestService_RequireScope_OIDC/ops_may_admin1770=== NAME TestOrphanedObjectsGC1771 orphaned_objects_gc_test.go:296: GC Test Summary:1772 orphaned_objects_gc_test.go:297: - Kept: 2 objects from closure A1773 orphaned_objects_gc_test.go:298: - Deleted: 2 objects from closure B1774=== CONT TestService_RequireScope_OIDC/reader_may_not_write1775=== NAME TestOrphanedObjectsGC1776 orphaned_objects_gc_test.go:299: - Deleted: 6 orphaned chain objects (X1->X2->X3)1777 orphaned_objects_gc_test.go:300: - Deleted: 2 orphaned single objects (Y)1778 orphaned_objects_gc_test.go:301: - Total deleted: 10 objects1779=== CONT TestService_RequireScope_OIDC/ops_may_not_write1780=== CONT TestService_RequireScope_OIDC/builder_may_write1781=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete17822026/09/24 18:05:54 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=YTU2OGIwYTUtMTE0YS00YWVmLTk5NDItYmZkYTI0ZTI3OWM2LjY1ZjM5MTNkLTA1YmEtNDU2MS05ZmI3LTE5MzgxMGY1ODYwNngxNzkwMjczMTUyMDIwNDM1MTE3 parts=1017832026/09/24 18:05:54 INFO Received complete push request method=POST path=/api/pushes/1/complete1784--- PASS: TestService_AuthMiddleware (0.26s)1785=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1786=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1787=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1788=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1789=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1790=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1791=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1792=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1793=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1794=== CONT TestGCEndsOnShutdown/before_the_run1795--- PASS: TestOrphanedObjectsGC (0.77s)1796=== CONT TestPush_RejectsBadRequests/no_roots17972026/09/24 18:05:54 INFO Received push request method=POST path=/api/pushes1798=== CONT TestPush_RejectsBadRequests/root_not_in_objects17992026/09/24 18:05:54 INFO Received push request method=POST path=/api/pushes1800=== CONT TestPush_RejectsBadRequests/no_objects18012026/09/24 18:05:54 INFO Received push request method=POST path=/api/pushes1802=== CONT TestPush_RejectsBadRequests/bad_root18032026/09/24 18:05:54 INFO Received push request method=POST path=/api/pushes1804=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check18052026/09/24 18:05:54 INFO All 1 paths already cached1806=== NAME TestClientIntegration1807 client_integration_test.go:360: Retrieved narinfo from S3:1808 StorePath: /build/TestClientIntegration2622554995/002/store/k3ndrlbbmaa21swk0pvnya6vkk3b3syj-test-file.txt1809 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1810 Compression: zstd1811 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11812 NarSize: 1521813 References: 1814 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11815--- PASS: TestService_RequireScope_OIDC (0.65s)1816 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1817 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1818 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1819 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1820 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1821 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1822 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1823 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1824 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1825 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1826=== NAME TestClientIntegration1827 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)1828 client_integration_test.go:361: Decompressed .ls content (64 bytes):1829 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1830--- PASS: TestPush_CompleteCommitsEveryRoot (3.24s)1831=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1832--- PASS: TestPush_RejectsBadRequests (0.49s)1833 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1834 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1835 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1836 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)18372026/09/24 18:05:54 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18382026/09/24 18:05:54 WARN Refused reserved pin name=worker-x86_64-linux18392026/09/24 18:05:54 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18402026/09/24 18:05:54 INFO Received push request method=POST path=/api/pushes18412026/09/24 18:05:54 INFO Received create pin request method=POST path=/api/pins/my-app18422026/09/24 18:05:54 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18432026/09/24 18:05:54 INFO Received uploads request method=POST path=/api/pending_closures18442026/09/24 18:05:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18452026/09/24 18:05:54 INFO Uploading zy9w27mj0n04862nl99hrn88wdp3lv3s-ca-test (144B)18462026/09/24 18:05:54 INFO Received push request method=POST path=/api/pushes18472026/09/24 18:05:54 INFO Received push request method=POST path=/api/pushes1848=== CONT TestIsValidCachePath/narinfo1849--- PASS: TestCreatePin_ReservedPins (1.05s)1850=== CONT TestIsValidCachePath/nix-cache-info1851=== CONT TestIsValidCachePath/wrong_extension1852=== CONT TestIsValidCachePath/invalid_char_e1853=== CONT TestIsValidCachePath/traversal_in_middle1854=== CONT TestIsValidCachePath/invalid_char_u1855=== CONT TestIsValidCachePath/index.html1856=== CONT TestIsValidCachePath/short_hash18572026/09/24 18:05:54 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"1858=== CONT TestIsValidCachePath/nar_uncompressed1859=== CONT TestIsValidCachePath/realisation1860=== CONT TestIsValidCachePath/leading_slash18612026/09/24 18:05:54 WARN Failed to register uploaded object key=log/1mypdrgkyfd9j29pwg164zb6xjigjsdb-ca-test.drv error="server returned 404: 404 page not found\n"1862=== CONT TestIsValidCachePath/traversal_parent1863=== CONT TestIsValidCachePath/nar_xz1864=== CONT TestIsValidCachePath/ls1865=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1866=== CONT TestIsValidCachePath/log1867=== CONT TestIsValidCachePath/random_path1868=== CONT TestIsValidCachePath/empty1869=== CONT TestIsValidCachePath/nar_bz21870=== CONT TestIsValidCachePath/nar_zst1871=== CONT TestParseSingleRange/none1872--- PASS: TestIsValidCachePath (0.00s)1873 --- PASS: TestIsValidCachePath/narinfo (0.00s)1874 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1875 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1876 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1877 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1878 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1879 --- PASS: TestIsValidCachePath/index.html (0.00s)1880 --- PASS: TestIsValidCachePath/short_hash (0.00s)1881 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1882 --- PASS: TestIsValidCachePath/realisation (0.00s)1883 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1884 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1885 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1886 --- PASS: TestIsValidCachePath/ls (0.00s)1887 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1888 --- PASS: TestIsValidCachePath/log (0.00s)1889 --- PASS: TestIsValidCachePath/random_path (0.00s)1890 --- PASS: TestIsValidCachePath/empty (0.00s)1891 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1892 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1893=== CONT TestParseSingleRange/single_byte1894=== CONT TestParseSingleRange/malformed_both_empty1895=== CONT TestParseSingleRange/end_clamped_to_size1896=== CONT TestParseSingleRange/suffix1897=== CONT TestParseSingleRange/unknown_unit1898=== CONT TestParseSingleRange/closed1899=== CONT TestParseSingleRange/suffix_exceeds_size1900=== CONT TestParseSingleRange/malformed_no_dash1901=== CONT TestParseSingleRange/malformed_end_before_start1902=== CONT TestParseSingleRange/open-ended1903=== CONT TestParseSingleRange/multi-range_ignored19042026/09/24 18:05:54 INFO Object in database but missing from S3 key=k3ndrlbbmaa21swk0pvnya6vkk3b3syj.ls19052026/09/24 18:05:54 WARN Found objects in DB but missing from S3, will re-upload count=11906=== CONT TestParseSingleRange/start_far_past_EOF1907=== CONT TestParseSingleRange/start_past_EOF1908=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1909--- PASS: TestParseSingleRange (0.00s)1910 --- PASS: TestParseSingleRange/none (0.00s)1911 --- PASS: TestParseSingleRange/single_byte (0.00s)1912 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1913 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1914 --- PASS: TestParseSingleRange/suffix (0.00s)1915 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1916 --- PASS: TestParseSingleRange/closed (0.00s)1917 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1918 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1919 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1920 --- PASS: TestParseSingleRange/open-ended (0.00s)1921 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1922 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1923 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1924=== CONT TestCacheConfigHandler/no_cache_url_configured1925=== CONT TestCacheConfigHandler/no_signing_keys1926=== CONT TestCacheConfigHandler/full_config,_no_issuer1927=== CONT TestClientErrorHandling/ServerNotAvailable1928--- PASS: TestCacheConfigHandler (0.00s)1929 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1930 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1931 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1932 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)19332026/09/24 18:05:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19342026/09/24 18:05:54 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19352026/09/24 18:05:54 WARN Failed to register uploaded object key=zy9w27mj0n04862nl99hrn88wdp3lv3s.ls error="server returned 404: 404 page not found\n"19362026/09/24 18:05:54 INFO Signed narinfos id=1 count=119372026/09/24 18:05:54 INFO Uploading 1 narinfos19382026/09/24 18:05:54 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)19392026/09/24 18:05:54 INFO Uploading 46sxs0pi14vi8jkr6swcw2bdcbl0hvmp-top (224B)19402026/09/24 18:05:54 INFO Uploading 2pf587n381hfl0naafyssrx3hza4q5gw-shared-dep (136B)1941=== CONT TestClientErrorHandling/InvalidAuthToken1942--- PASS: TestPendingClosureFailureTracksEveryUpload (0.95s)19432026/09/24 18:05:54 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19442026/09/24 18:05:54 INFO Received complete push request method=POST path=/api/pushes/1/complete19452026/09/24 18:05:54 WARN Failed to register uploaded object key=zy9w27mj0n04862nl99hrn88wdp3lv3s.narinfo error="server returned 404: 404 page not found\n"19462026/09/24 18:05:54 WARN Failed to register uploaded object key=nar/0v04hn2l089b0sslkmdy5crgjkw1r66cqhi680v9flv0k1nnywjb.nar.zst error="server returned 404: 404 page not found\n"19472026/09/24 18:05:54 INFO Received complete push request method=POST path=/api/pushes/2/complete19482026/09/24 18:05:54 WARN Failed to register uploaded object key=2pf587n381hfl0naafyssrx3hza4q5gw.ls error="server returned 404: 404 page not found\n"19492026/09/24 18:05:54 WARN Failed to register uploaded object key=k3ndrlbbmaa21swk0pvnya6vkk3b3syj.ls error="server returned 404: 404 page not found\n"19502026/09/24 18:05:54 WARN Failed to register uploaded object key=46sxs0pi14vi8jkr6swcw2bdcbl0hvmp.ls error="server returned 404: 404 page not found\n"19512026/09/24 18:05:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19522026/09/24 18:05:54 INFO Upload complete. (180ms)19532026/09/24 18:05:54 INFO Upload complete. (110ms)19542026/09/24 18:05:54 INFO Signed narinfos id=1 count=219552026/09/24 18:05:54 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=1677721619562026/09/24 18:05:54 INFO Uploading 2 narinfos1957=== NAME TestClientIntegration1958 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)1959 client_integration_test.go:389: Decompressed .ls content (49 bytes):1960 {"version":1,"root":{"type":"regular","size":39}}19612026/09/24 18:05:54 WARN Failed to register uploaded object key=2pf587n381hfl0naafyssrx3hza4q5gw.narinfo error="server returned 404: 404 page not found\n"19622026/09/24 18:05:54 INFO Received complete push request method=POST path=/api/pushes/1/complete19632026/09/24 18:05:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19642026/09/24 18:05:54 WARN Failed to register uploaded object key=46sxs0pi14vi8jkr6swcw2bdcbl0hvmp.narinfo error="server returned 404: 404 page not found\n"1965=== NAME TestClientCADerivations1966 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations4112215898/001/store/zy9w27mj0n04862nl99hrn88wdp3lv3s-ca-test1967 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1968 Compression: zstd1969 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1970 NarSize: 1441971 References: 1972 Deriver: /build/TestClientCADerivations4112215898/001/store/1mypdrgkyfd9j29pwg164zb6xjigjsdb-ca-test.drv1973 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1974 client_ca_test.go:185: Checking for realisation files in S3...1975 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1976 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache19772026/09/24 18:05:54 INFO Upload complete. (114ms)1978=== NAME TestClientSharedPathCommittedMidPush1979 client_integration_test.go:816: Retrieved narinfo from S3:1980 StorePath: /build/TestClientSharedPathCommittedMidPush2380743308/001/store/2pf587n381hfl0naafyssrx3hza4q5gw-shared-dep1981 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1982 Compression: zstd1983 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821984 NarSize: 1361985 References: 1986 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1987--- PASS: TestReadProxyNarinfo (1.78s)1988=== CONT TestClientErrorHandling/InvalidStorePath1989=== NAME TestClientSharedPathCommittedMidPush1990 client_integration_test.go:816: Retrieved narinfo from S3:19912026/09/24 18:05:54 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=YTU2OGIwYTUtMTE0YS00YWVmLTk5NDItYmZkYTI0ZTI3OWM2LjQ4NWZiM2E1LTc4MzYtNDA0OC04N2JjLTg0Nzk0NjhiYjY0NngxNzkwMjczMTUyOTk2MTgxNDE3 parts=101992 StorePath: /build/TestClientSharedPathCommittedMidPush2380743308/001/store/46sxs0pi14vi8jkr6swcw2bdcbl0hvmp-top1993 URL: nar/0v04hn2l089b0sslkmdy5crgjkw1r66cqhi680v9flv0k1nnywjb.nar.zst1994 Compression: zstd19952026/09/24 18:05:54 INFO Received complete push request method=POST path=/api/pushes/1/complete1996 NarHash: sha256:0v04hn2l089b0sslkmdy5crgjkw1r66cqhi680v9flv0k1nnywjb1997 NarSize: 2241998 References: /build/TestClientSharedPathCommittedMidPush2380743308/001/store/2pf587n381hfl0naafyssrx3hza4q5gw-shared-dep1999 CA: text:sha256:033kln7rf2vrdih44cvij87jbpdvis47mc676p1v50c1n9is241720002026/09/24 18:05:54 INFO Received push request method=POST path=/api/pushes20012026/09/24 18:05:54 INFO Aborted multipart uploads count=0 kept=020022026/09/24 18:05:54 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20032026/09/24 18:05:54 WARN Force mode enabled - objects will be deleted immediately without grace period20042026/09/24 18:05:54 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:36873/bucket89/?delete=\": context canceled"2005--- PASS: TestClientSharedPathCommittedMidPush (0.53s)2006=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2007=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2008=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20092026/09/24 18:05:54 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2010=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20112026/09/24 18:05:54 WARN Authentication failed token_preview=eyJhbGciOi...Rygy9trlsw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]20122026/09/24 18:05:54 INFO Aborted multipart uploads count=0 kept=020132026/09/24 18:05:54 INFO Received push request method=POST path=/api/pushes20142026/09/24 18:05:54 WARN Force mode enabled - objects will be deleted immediately without grace period2015--- PASS: TestService_AuthMiddleware_OIDC (0.32s)2016 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2017 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2018 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2019 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)20202026/09/24 18:05:54 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)2021=== NAME TestClientCADerivations2022 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2023 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2024 error: binary cache 's3://bucket80?endpoint=http://localhost:36873®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations4112215898/001/store'2025 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 120262026/09/24 18:05:54 INFO Received uploads request method=POST path=/api/pending_closures20272026/09/24 18:05:54 WARN Failed to register uploaded object key=k3ndrlbbmaa21swk0pvnya6vkk3b3syj.ls error="server returned 404: 404 page not found\n"20282026/09/24 18:05:54 INFO Received complete push request method=POST path=/api/pushes/3/complete20292026-09-24 18:05:54.806 UTC [1844] ERROR: canceling statement due to user request20302026-09-24 18:05:54.806 UTC [1844] CONTEXT: PL/pgSQL function object_stats_apply() line 5 at statement block20312026-09-24 18:05:54.806 UTC [1844] STATEMENT: -- name: MarkStaleObjects :execrows2032 WITH RECURSIVE ct AS (2033 SELECT timezone('UTC', now()) AS now2034 ),2035 closure_reach AS (2036 -- Start with all closure keys2037 SELECT o.key, o.refs2038 FROM objects o2039 INNER JOIN closures c ON o.key = c.key2040 UNION2041 -- Recursively add all referenced objects2042 SELECT o.key, o.refs2043 FROM objects o2044 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2045 ),2046 reachable_objects AS (2047 SELECT DISTINCT key FROM closure_reach2048 ),2049 stale_objects AS (2050 SELECT o.key2051 FROM objects AS o, ct2052 WHERE2053 NOT EXISTS (2054 SELECT 12055 FROM reachable_objects ro2056 WHERE ro.key = o.key2057 )2058 AND NOT EXISTS (2059 SELECT 12060 FROM pending_objects AS po2061 WHERE po.key = o.key2062 )2063 AND o.deleted_at IS NULL -- Only mark fresh objects2064 ORDER BY o.key -- lock in key order, like commit_pending_closure2065 FOR UPDATE2066 )2067 UPDATE objects2068 SET2069 deleted_at = ct.now,2070 first_deleted_at = COALESCE(first_deleted_at, ct.now)2071 FROM stale_objects, ct2072 WHERE objects.key = stale_objects.key2073 20742026/09/24 18:05:54 INFO Upload complete. (63ms)2075=== NAME TestClientIntegration2076 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)2077 client_integration_test.go:405: Decompressed .ls content (49 bytes):2078 {"version":1,"root":{"type":"regular","size":39}}20792026/09/24 18:05:54 INFO Aborted multipart uploads count=0 kept=020802026/09/24 18:05:54 WARN Force mode enabled - objects will be deleted immediately without grace period20812026/09/24 18:05:54 INFO Aborted multipart uploads count=0 kept=020822026/09/24 18:05:54 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020832026/09/24 18:05:54 INFO Vacuumed table table=pending_closures20842026/09/24 18:05:54 WARN Force mode enabled - objects will be deleted immediately without grace period20852026/09/24 18:05:54 INFO Vacuumed table table=pending_objects20862026/09/24 18:05:54 INFO Received uploads request method=POST path=/api/pending_closures20872026/09/24 18:05:54 INFO Vacuumed table table=multipart_uploads20882026/09/24 18:05:54 INFO Vacuumed table table=closures20892026/09/24 18:05:54 INFO Vacuumed table table=objects2090--- PASS: TestClientCADerivations (0.72s)20912026/09/24 18:05:54 INFO Aborted multipart uploads count=0 kept=020922026/09/24 18:05:54 WARN Force mode enabled - objects will be deleted immediately without grace period20932026/09/24 18:05:54 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=217.884601ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20942026/09/24 18:05:54 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=020952026/09/24 18:05:54 INFO Vacuumed table table=pending_closures20962026/09/24 18:05:54 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=020972026/09/24 18:05:54 INFO Vacuumed table table=pending_closures20982026/09/24 18:05:54 INFO Vacuumed table table=pending_objects20992026/09/24 18:05:54 INFO Vacuumed table table=pending_objects21002026/09/24 18:05:54 INFO Vacuumed table table=multipart_uploads21012026/09/24 18:05:54 INFO Vacuumed table table=closures21022026/09/24 18:05:54 INFO Vacuumed table table=multipart_uploads21032026/09/24 18:05:54 INFO Vacuumed table table=objects21042026/09/24 18:05:54 INFO Vacuumed table table=closures21052026/09/24 18:05:54 INFO Vacuumed table table=objects2106--- PASS: TestGCEndsOnShutdown (0.00s)2107 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.27s)2108 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.31s)2109 --- PASS: TestGCEndsOnShutdown/before_the_run (0.35s)2110--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2111 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.34s)2112 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.35s)21132026/09/24 18:05:54 INFO Received push request method=POST path=/api/pushes21142026/09/24 18:05:54 INFO lead: released remote=192.0.2.1:123421152026/09/24 18:05:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21162026/09/24 18:05:54 INFO Uploading jy5i9izrs25dckc7fps50xp54f8xyn7n-lost-commit.txt (152B)21172026/09/24 18:05:54 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"21182026/09/24 18:05:54 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign21192026/09/24 18:05:54 WARN Failed to register uploaded object key=jy5i9izrs25dckc7fps50xp54f8xyn7n.ls error="server returned 404: 404 page not found\n"21202026/09/24 18:05:54 INFO Signed narinfos id=4 count=121212026/09/24 18:05:54 INFO Uploading 1 narinfos21222026/09/24 18:05:54 INFO Received complete push request method=POST path=/api/pushes/4/complete21232026/09/24 18:05:54 WARN Failed to register uploaded object key=jy5i9izrs25dckc7fps50xp54f8xyn7n.narinfo error="server returned 404: 404 page not found\n"21242026/09/24 18:05:54 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://127.0.0.1:36623/api/pushes/4/complete\": EOF" url=http://127.0.0.1:36623/api/pushes/4/complete21252026/09/24 18:05:54 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21262026/09/24 18:05:54 INFO lead: acquired remote=192.0.2.1:123421272026/09/24 18:05:54 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21282026/09/24 18:05:55 INFO Received complete push request method=POST path=/api/pushes/4/complete21292026-09-24 18:05:55.062 UTC [1393] ERROR: Push does not exist: id=421302026-09-24 18:05:55.062 UTC [1393] CONTEXT: PL/pgSQL function commit_push(bigint) line 9 at RAISE21312026-09-24 18:05:55.062 UTC [1393] STATEMENT: -- name: CommitPush :exec2132 SELECT commit_push($1::bigint)2133 21342026/09/24 18:05:55 INFO Upload complete. (180ms)21352026/09/24 18:05:55 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=426.850398ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2136=== NAME TestClientIntegration2137 client_integration_test.go:435: Retrieved narinfo from S3:2138 StorePath: /build/TestClientIntegration2622554995/002/store/jy5i9izrs25dckc7fps50xp54f8xyn7n-lost-commit.txt2139 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst2140 Compression: zstd2141 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2142 NarSize: 1522143 References: 2144 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2145 client_integration_test.go:438: Testing garbage collection...21462026/09/24 18:05:55 INFO Starting cleanup of old closures method=DELETE path=/api/closures21472026/09/24 18:05:55 INFO Garbage collection started21482026/09/24 18:05:55 INFO Aborted multipart uploads count=0 kept=021492026/09/24 18:05:55 WARN Force mode enabled - objects will be deleted immediately without grace period21502026/09/24 18:05:55 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=021512026/09/24 18:05:55 INFO Vacuumed table table=pending_closures21522026/09/24 18:05:55 INFO Vacuumed table table=pending_objects21532026/09/24 18:05:55 INFO Vacuumed table table=multipart_uploads21542026/09/24 18:05:55 INFO Vacuumed table table=closures21552026/09/24 18:05:55 INFO Vacuumed table table=objects21562026/09/24 18:05:55 INFO Received create pin request method=POST path=/api/pins/deploy21572026/09/24 18:05:55 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo2158--- PASS: TestCreatePinRejectsBadInput (1.70s)21592026/09/24 18:05:55 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021602026/09/24 18:05:55 INFO Received create pin request method=POST path=/api/pins/myapp21612026/09/24 18:05:55 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC50518958/001/store/as0x10f3qfd3qmyj8ip5s57zkr8r01ck-pinned-file.txt narinfo_key=as0x10f3qfd3qmyj8ip5s57zkr8r01ck.narinfo21622026/09/24 18:05:55 INFO Starting cleanup of old closures method=DELETE path=/api/closures21632026/09/24 18:05:55 INFO Garbage collection started2164--- PASS: TestPendingClosureWriteTimeout (0.01s)2165 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2166 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2167 --- PASS: TestPendingClosureWriteTimeout/negative (0.00s)2168 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2169 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.02s)21702026/09/24 18:05:55 INFO Aborted multipart uploads count=0 kept=021712026/09/24 18:05:55 WARN Force mode enabled - objects will be deleted immediately without grace period21722026/09/24 18:05:55 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=021732026/09/24 18:05:55 INFO Vacuumed table table=pending_closures21742026/09/24 18:05:55 INFO Vacuumed table table=pending_objects21752026/09/24 18:05:55 INFO Vacuumed table table=multipart_uploads21762026/09/24 18:05:55 INFO Vacuumed table table=closures21772026/09/24 18:05:55 INFO Vacuumed table table=objects21782026/09/24 18:05:55 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=725.18936ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21792026/09/24 18:05:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21802026/09/24 18:05:55 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=YTU2OGIwYTUtMTE0YS00YWVmLTk5NDItYmZkYTI0ZTI3OWM2LjIwNDJjYTFkLTc4NjItNDg4Yy05ZDIwLWU5ZDJiY2ZiYmU2MXgxNzkwMjczMTU0NzQ5MjY5MTQw parts=1021812026/09/24 18:05:55 INFO Received complete push request method=POST path=/api/pushes/2/complete2182--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.06s)2183=== NAME TestOrphanedObjectsGCStressTest2184 orphaned_objects_gc_test.go:431: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2185 orphaned_objects_gc_test.go:452: Marked 210 objects for deletion21862026/09/24 18:05:56 INFO lead: released remote=192.0.2.1:12342187--- PASS: TestLeadElectsOneAndHandsOver (2.70s)21882026/09/24 18:05:56 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.727187478s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21892026/09/24 18:05:56 WARN Rate limiter enabled after throttle name=s3-test rate=521902026/09/24 18:05:56 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2191=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2192 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102193 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002194=== NAME TestOrphanedObjectsGCStressTest2195 orphaned_objects_gc_test.go:515: Stress test completed successfully:2196 orphaned_objects_gc_test.go:516: - Active objects preserved: 202197 orphaned_objects_gc_test.go:517: - Objects deleted: 2102198 orphaned_objects_gc_test.go:518: - Total GC'd: 2102199--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.07s)2200--- PASS: TestOrphanedObjectsGCStressTest (2.77s)2201--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.26s)22022026/09/24 18:05:57 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02203=== NAME TestClientIntegration2204 client_integration_test.go:445: Objects in database after GC:2205 client_integration_test.go:445: Successfully deleted all objects with GC --force2206--- PASS: TestClientIntegration (3.12s)2207=== NAME TestPinProtectsFromGC2208 client_integration_test.go:981: Pin successfully protected closure from garbage collection2209--- PASS: TestPinProtectsFromGC (4.93s)22102026/09/24 18:05:57 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22112026/09/24 18:05:58 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=194.14002ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22122026/09/24 18:05:58 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=382.554582ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2213--- PASS: TestConnectWaitsForAPeerMigration (5.16s)22142026/09/24 18:05:58 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=857.608316ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22152026/09/24 18:05:59 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.550910231s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22162026/09/24 18:06:00 INFO Aborted multipart uploads count=1 kept=022172026/09/24 18:06:00 INFO Received cleanup request method=DELETE path=/api/pending_closures22182026/09/24 18:06:00 INFO Aborted multipart uploads count=1 kept=02219--- PASS: TestPendingCleanupUsesOneCutoff (6.39s)22202026/09/24 18:06:01 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"22212026/09/24 18:06:01 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22222026/09/24 18:06:01 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=199.272025ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22232026/09/24 18:06:01 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=411.647267ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22242026/09/24 18:06:01 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=814.504352ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22252026/09/24 18:06:02 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.698238525s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22262026/09/24 18:06:04 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22272026/09/24 18:06:04 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=188.880246ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22282026/09/24 18:06:04 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=374.156587ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22292026/09/24 18:06:04 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=831.041399ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22302026/09/24 18:06:05 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.56877868s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2231--- PASS: TestUploadHandlersRejectOversizedBody (0.56s)2232 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (1.20s)2233 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (1.29s)2234 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (11.95s)2235--- PASS: TestClientErrorHandling (0.00s)2236 --- PASS: TestClientErrorHandling/InvalidStorePath (0.23s)2237 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.35s)2238 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.73s)2239PASS2240{"timestamp":"2026-09-24T18:06:07.402994504Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:48402","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2260,"threadName":"rustfs-worker","threadId":"ThreadId(198)"}2241{"timestamp":"2026-09-24T18:06:07.402809362Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:48158","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2260,"threadName":"rustfs-worker","threadId":"ThreadId(203)"}22422026-09-24 18:06:07.847 UTC [170] LOG: received smart shutdown request22432026-09-24 18:06:07.852 UTC [170] LOG: background worker "logical replication launcher" (PID 180) exited with exit code 122442026-09-24 18:06:07.872 UTC [175] LOG: shutting down22452026-09-24 18:06:07.872 UTC [175] LOG: checkpoint starting: shutdown immediate22462026-09-24 18:06:09.189 UTC [175] LOG: checkpoint complete: wrote 10311 buffers (62.9%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 28 recycled; write=0.249 s, sync=1.024 s, total=1.318 s; sync files=32694, longest=0.020 s, average=0.001 s; distance=463560 kB, estimate=463560 kB; lsn=0/1DC17F80, redo lsn=0/1DC17F8022472026-09-24 18:06:09.304 UTC [170] LOG: database system is shut down2248Running OIDC tests...2249=== RUN TestAudienceForIssuer2250=== PAUSE TestAudienceForIssuer2251=== RUN TestHTTPClientForHasTimeouts2252=== PAUSE TestHTTPClientForHasTimeouts2253=== RUN TestGlobMatch2254=== PAUSE TestGlobMatch2255=== RUN TestValidateToken_ValidToken2256=== PAUSE TestValidateToken_ValidToken2257=== RUN TestValidateToken_WrongAudience2258=== PAUSE TestValidateToken_WrongAudience2259=== RUN TestValidateToken_Expired2260=== PAUSE TestValidateToken_Expired2261=== RUN TestValidateToken_BoundClaimsMismatch2262=== PAUSE TestValidateToken_BoundClaimsMismatch2263=== RUN TestValidateToken_BoundSubjectMismatch2264=== PAUSE TestValidateToken_BoundSubjectMismatch2265=== RUN TestValidateToken_MultipleProviders2266=== PAUSE TestValidateToken_MultipleProviders2267=== RUN TestValidateToken_NoMatchingProvider2268=== PAUSE TestValidateToken_NoMatchingProvider2269=== RUN TestValidateToken_KubernetesServiceAccount2270=== PAUSE TestValidateToken_KubernetesServiceAccount2271=== RUN TestNewValidator_KubernetesRequiresCA2272=== PAUSE TestNewValidator_KubernetesRequiresCA2273=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2274=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2275=== RUN TestPins_ReservedForMatchingRule2276=== PAUSE TestPins_ReservedForMatchingRule2277=== RUN TestPins_TopLevelShorthand2278=== PAUSE TestPins_TopLevelShorthand2279=== RUN TestPins_ConfigValidation2280=== PAUSE TestPins_ConfigValidation2281=== RUN TestScopes_LegacyProviderDefaultsToWrite2282=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2283=== RUN TestScopes_Rules2284=== PAUSE TestScopes_Rules2285=== RUN TestScopes_ConfigValidation2286=== PAUSE TestScopes_ConfigValidation2287=== CONT TestAudienceForIssuer2288=== CONT TestValidateToken_WrongAudience2289=== CONT TestPins_ReservedForMatchingRule2290--- PASS: TestAudienceForIssuer (0.00s)2291=== CONT TestValidateToken_Expired2292=== CONT TestValidateToken_MultipleProviders2293=== CONT TestScopes_ConfigValidation2294=== CONT TestValidateToken_BoundClaimsMismatch2295=== CONT TestValidateToken_BoundSubjectMismatch2296=== CONT TestScopes_Rules2297=== CONT TestScopes_LegacyProviderDefaultsToWrite2298=== CONT TestPins_ConfigValidation2299=== CONT TestPins_TopLevelShorthand2300=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2301=== CONT TestGlobMatch2302=== RUN TestGlobMatch/foo_foo2303--- PASS: TestScopes_ConfigValidation (0.00s)2304=== PAUSE TestGlobMatch/foo_foo2305=== RUN TestGlobMatch/foo_bar2306=== CONT TestValidateToken_ValidToken2307=== CONT TestHTTPClientForHasTimeouts2308=== CONT TestValidateToken_NoMatchingProvider2309=== CONT TestNewValidator_KubernetesRequiresCA2310=== CONT TestValidateToken_KubernetesServiceAccount2311=== PAUSE TestGlobMatch/foo_bar2312=== RUN TestGlobMatch/*_2313=== PAUSE TestGlobMatch/*_2314=== RUN TestGlobMatch/*_anything2315=== PAUSE TestGlobMatch/*_anything2316=== RUN TestGlobMatch/foo*_foo2317=== PAUSE TestGlobMatch/foo*_foo2318=== RUN TestGlobMatch/foo*_foobar2319=== PAUSE TestGlobMatch/foo*_foobar2320=== RUN TestGlobMatch/foo*_bar2321=== PAUSE TestGlobMatch/foo*_bar2322=== RUN TestGlobMatch/*bar_bar2323=== PAUSE TestGlobMatch/*bar_bar2324=== RUN TestGlobMatch/*bar_foobar2325=== PAUSE TestGlobMatch/*bar_foobar2326--- PASS: TestPins_ConfigValidation (0.00s)2327=== RUN TestGlobMatch/*bar_foo2328=== PAUSE TestGlobMatch/*bar_foo2329=== RUN TestGlobMatch/foo*bar_foobar2330=== PAUSE TestGlobMatch/foo*bar_foobar2331=== RUN TestGlobMatch/foo*bar_foo123bar2332=== PAUSE TestGlobMatch/foo*bar_foo123bar2333=== RUN TestGlobMatch/foo*bar_foobarbaz2334=== PAUSE TestGlobMatch/foo*bar_foobarbaz2335=== RUN TestGlobMatch/*/*_foo/bar2336=== PAUSE TestGlobMatch/*/*_foo/bar2337=== RUN TestGlobMatch/*/*_foo2338=== PAUSE TestGlobMatch/*/*_foo2339=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2340=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2341=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02342=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02343=== RUN TestGlobMatch/refs/*/main_refs/heads/main2344=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2345=== RUN TestGlobMatch/fo?_foo2346=== PAUSE TestGlobMatch/fo?_foo2347=== RUN TestGlobMatch/fo?_fo2348=== PAUSE TestGlobMatch/fo?_fo2349=== RUN TestGlobMatch/fo?_fooo2350=== PAUSE TestGlobMatch/fo?_fooo2351=== RUN TestGlobMatch/?oo_foo2352=== PAUSE TestGlobMatch/?oo_foo2353=== RUN TestGlobMatch/?oo_boo2354=== PAUSE TestGlobMatch/?oo_boo2355=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2356=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2357=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2358=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2359=== CONT TestGlobMatch/*_anything2360=== CONT TestGlobMatch/foo*bar_foobarbaz2361=== CONT TestGlobMatch/*/*_foo/bar2362=== CONT TestGlobMatch/foo*bar_foo123bar2363=== CONT TestGlobMatch/foo*bar_foobar2364=== CONT TestGlobMatch/*_2365=== CONT TestGlobMatch/foo*_foobar2366=== CONT TestGlobMatch/foo*_bar2367=== CONT TestGlobMatch/foo*_foo2368=== CONT TestGlobMatch/fo?_fo2369=== CONT TestGlobMatch/*bar_foobar2370=== CONT TestGlobMatch/refs/*/main_refs/heads/main2371=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02372=== CONT TestGlobMatch/fo?_foo2373=== CONT TestGlobMatch/foo_foo2374=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2375=== CONT TestGlobMatch/?oo_boo2376=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2377=== CONT TestGlobMatch/*bar_foo2378=== CONT TestGlobMatch/?oo_foo2379=== CONT TestGlobMatch/fo?_fooo2380=== CONT TestGlobMatch/*bar_bar2381=== CONT TestGlobMatch/foo_bar2382=== CONT TestGlobMatch/*/*_foo2383=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2384--- PASS: TestGlobMatch (0.00s)2385 --- PASS: TestGlobMatch/*_anything (0.00s)2386 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2387 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2388 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2389 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2390 --- PASS: TestGlobMatch/*_ (0.00s)2391 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2392 --- PASS: TestGlobMatch/foo*_bar (0.00s)2393 --- PASS: TestGlobMatch/foo*_foo (0.00s)2394 --- PASS: TestGlobMatch/fo?_fo (0.00s)2395 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2396 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2397 --- PASS: TestGlobMatch/fo?_foo (0.00s)2398 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2399 --- PASS: TestGlobMatch/foo_foo (0.00s)2400 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2401 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2402 --- PASS: TestGlobMatch/?oo_boo (0.00s)2403 --- PASS: TestGlobMatch/*bar_foo (0.00s)2404 --- PASS: TestGlobMatch/?oo_foo (0.00s)2405 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2406 --- PASS: TestGlobMatch/*bar_bar (0.00s)2407 --- PASS: TestGlobMatch/foo_bar (0.00s)2408 --- PASS: TestGlobMatch/*/*_foo (0.00s)2409 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)24102026/09/24 18:06:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44341/oidc2411--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.09s)24122026/09/24 18:06:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43693/oidc24132026/09/24 18:06:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35129/oidc2414--- PASS: TestValidateToken_Expired (0.13s)2415--- PASS: TestValidateToken_BoundClaimsMismatch (0.13s)24162026/09/24 18:06:12 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12324172026/09/24 18:06:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38145/oidc24182026/09/24 18:06:12 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:427752419--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.17s)2420--- PASS: TestPins_TopLevelShorthand (0.18s)2421--- PASS: TestValidateToken_KubernetesServiceAccount (0.19s)2422--- PASS: TestHTTPClientForHasTimeouts (0.20s)24232026/09/24 18:06:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45255/oidc2424--- PASS: TestPins_ReservedForMatchingRule (0.27s)24252026/09/24 18:06:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34925/oidc24262026/09/24 18:06:12 http: TLS handshake error from 127.0.0.1:58706: remote error: tls: bad certificate2427--- PASS: TestNewValidator_KubernetesRequiresCA (0.28s)2428--- PASS: TestValidateToken_WrongAudience (0.30s)24292026/09/24 18:06:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38941/oidc24302026/09/24 18:06:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36609/oidc2431--- PASS: TestScopes_Rules (0.32s)2432--- PASS: TestValidateToken_ValidToken (0.33s)24332026/09/24 18:06:12 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:39547/oidc24342026/09/24 18:06:12 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33783/oidc2435--- PASS: TestValidateToken_MultipleProviders (0.38s)24362026/09/24 18:06:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33251/oidc2437--- PASS: TestValidateToken_BoundSubjectMismatch (0.40s)24382026/09/24 18:06:12 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:40731/oidc2439--- PASS: TestValidateToken_NoMatchingProvider (0.75s)2440PASS2441Running signing tests...2442=== RUN TestGenerateFingerprint2443=== PAUSE TestGenerateFingerprint2444=== RUN TestParseSigningKey2445=== PAUSE TestParseSigningKey2446=== RUN TestSignMessage2447=== PAUSE TestSignMessage2448=== RUN TestSignNarinfo2449=== PAUSE TestSignNarinfo2450=== CONT TestSignNarinfo2451=== CONT TestGenerateFingerprint2452=== CONT TestSignMessage2453=== CONT TestParseSigningKey2454=== RUN TestParseSigningKey/valid_32-byte_key2455=== RUN TestGenerateFingerprint/basic_with_references2456=== PAUSE TestParseSigningKey/valid_32-byte_key2457=== PAUSE TestGenerateFingerprint/basic_with_references2458=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2459=== RUN TestGenerateFingerprint/no_references2460=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2461=== PAUSE TestGenerateFingerprint/no_references2462=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2463=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2464=== RUN TestParseSigningKey/no_colon2465=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2466=== PAUSE TestParseSigningKey/no_colon2467=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2468=== RUN TestParseSigningKey/empty_name2469=== RUN TestGenerateFingerprint/invalid_nar_hash_length2470=== PAUSE TestParseSigningKey/empty_name2471=== RUN TestParseSigningKey/invalid_base642472=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2473=== PAUSE TestParseSigningKey/invalid_base642474=== RUN TestGenerateFingerprint/invalid_store_path_prefix2475=== RUN TestParseSigningKey/wrong_length2476=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2477=== PAUSE TestParseSigningKey/wrong_length2478=== RUN TestGenerateFingerprint/invalid_reference_prefix2479=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2480=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2481=== CONT TestParseSigningKey/empty_name2482=== CONT TestParseSigningKey/no_colon2483=== CONT TestParseSigningKey/valid_32-byte_key2484=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2485=== CONT TestGenerateFingerprint/invalid_reference_prefix2486=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2487=== CONT TestGenerateFingerprint/no_references2488=== CONT TestGenerateFingerprint/basic_with_references2489=== CONT TestGenerateFingerprint/invalid_nar_hash_length2490=== CONT TestGenerateFingerprint/invalid_store_path_prefix2491=== CONT TestParseSigningKey/invalid_base642492=== CONT TestParseSigningKey/wrong_length2493--- PASS: TestGenerateFingerprint (0.00s)2494 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2495 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2496 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2497 --- PASS: TestGenerateFingerprint/no_references (0.00s)2498 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2499 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2500 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2501--- PASS: TestParseSigningKey (0.00s)2502 --- PASS: TestParseSigningKey/empty_name (0.00s)2503 --- PASS: TestParseSigningKey/no_colon (0.00s)2504 --- PASS: TestParseSigningKey/wrong_length (0.00s)2505 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2506 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.01s)2507 --- PASS: TestParseSigningKey/valid_32-byte_key (0.01s)2508--- PASS: TestSignMessage (0.01s)2509--- PASS: TestSignNarinfo (0.02s)2510PASS2511Running hook tests...2512=== RUN TestSendPathsEmpty2513=== PAUSE TestSendPathsEmpty2514=== RUN TestQueueEnqueueAndFetch2515=== PAUSE TestQueueEnqueueAndFetch2516=== RUN TestQueueDeduplication2517=== PAUSE TestQueueDeduplication2518=== RUN TestQueueRemove2519=== PAUSE TestQueueRemove2520=== RUN TestQueueFetchBatchLimit2521=== PAUSE TestQueueFetchBatchLimit2522=== RUN TestQueueRetryMovesToBack2523=== PAUSE TestQueueRetryMovesToBack2524=== RUN TestQueueFetchRemoveLifecycle2525=== PAUSE TestQueueFetchRemoveLifecycle2526=== RUN TestQueueConcurrentWriters2527=== PAUSE TestQueueConcurrentWriters2528=== RUN TestQueueEnqueueWaitsOutSlowWriter2529=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2530=== RUN TestQueueRemoveLargeClosure2531=== PAUSE TestQueueRemoveLargeClosure2532=== RUN TestServerClientIntegration2533=== PAUSE TestServerClientIntegration2534=== RUN TestServerQueueError2535=== PAUSE TestServerQueueError2536=== RUN TestServerRefusesOversizedAndNonStoreRequests2537=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2538=== RUN TestGetListenerSocketActivation2539 server_test.go:317: === RUN TestGetListenerSocketActivation2540 --- PASS: TestGetListenerSocketActivation (0.00s)2541 PASS2542 2543--- PASS: TestGetListenerSocketActivation (1.02s)2544=== RUN TestServerStalledClientDoesNotBlockShutdown2545=== PAUSE TestServerStalledClientDoesNotBlockShutdown2546=== RUN TestServerBacksOffOnAcceptErrors2547=== PAUSE TestServerBacksOffOnAcceptErrors2548=== RUN TestDrainIsolatesPoisonPath2549=== PAUSE TestDrainIsolatesPoisonPath2550=== RUN TestRunNotBlockedByPoisonHead2551=== PAUSE TestRunNotBlockedByPoisonHead2552=== RUN TestDrainGivesUpWhenServerDown2553=== PAUSE TestDrainGivesUpWhenServerDown2554=== RUN TestFailedPathPrunedByLaterClosure2555=== PAUSE TestFailedPathPrunedByLaterClosure2556=== RUN TestWorkerUploadsAndRemoves2557=== PAUSE TestWorkerUploadsAndRemoves2558=== RUN TestWorkerSkipsGCdPaths2559=== PAUSE TestWorkerSkipsGCdPaths2560=== RUN TestWorkerPrunesClosureDeps2561=== PAUSE TestWorkerPrunesClosureDeps2562=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2563=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2564=== RUN TestDrainTimeout2565=== PAUSE TestDrainTimeout2566=== RUN TestDrainTimeoutDuringIsolation2567=== PAUSE TestDrainTimeoutDuringIsolation2568=== RUN TestShutdownFinishesInFlightPush2569=== PAUSE TestShutdownFinishesInFlightPush2570=== RUN TestWorkerRemoveFailureIsNotProgress2571=== PAUSE TestWorkerRemoveFailureIsNotProgress2572=== RUN TestWorkerKeepsPathItCannotStat2573=== PAUSE TestWorkerKeepsPathItCannotStat2574=== CONT TestSendPathsEmpty2575=== CONT TestDrainTimeoutDuringIsolation2576--- PASS: TestSendPathsEmpty (0.00s)2577=== CONT TestWorkerSkipsGCdPaths2578=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2579=== CONT TestWorkerKeepsPathItCannotStat2580=== CONT TestServerBacksOffOnAcceptErrors2581=== CONT TestShutdownFinishesInFlightPush2582=== CONT TestQueueRemove2583=== CONT TestQueueFetchRemoveLifecycle2584=== RUN TestShutdownFinishesInFlightPush/completes2585=== PAUSE TestShutdownFinishesInFlightPush/completes2586=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2587=== CONT TestWorkerRemoveFailureIsNotProgress2588=== CONT TestQueueRetryMovesToBack2589=== CONT TestServerClientIntegration25902026/09/24 18:06:15 ERROR Accept failed error="too many open files"2591=== CONT TestQueueDeduplication2592=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2593=== CONT TestQueueEnqueueWaitsOutSlowWriter2594=== CONT TestQueueConcurrentWriters2595=== CONT TestServerStalledClientDoesNotBlockShutdown2596=== CONT TestServerRefusesOversizedAndNonStoreRequests2597=== CONT TestWorkerUploadsAndRemoves2598=== CONT TestQueueFetchBatchLimit2599=== CONT TestFailedPathPrunedByLaterClosure2600=== CONT TestDrainGivesUpWhenServerDown2601=== CONT TestRunNotBlockedByPoisonHead2602=== CONT TestDrainIsolatesPoisonPath2603=== CONT TestQueueEnqueueAndFetch2604=== CONT TestDrainTimeout2605=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2606=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2607=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2608=== CONT TestQueueRemoveLargeClosure2609=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2610=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2611=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2612=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2613=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2614=== CONT TestWorkerPrunesClosureDeps2615=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2616=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2617=== CONT TestServerQueueError26182026/09/24 18:06:15 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store26192026/09/24 18:06:15 ERROR Failed to queue paths error="permission denied" count=12620=== CONT TestShutdownFinishesInFlightPush/completes2621--- PASS: TestServerClientIntegration (0.00s)2622--- PASS: TestServerQueueError (0.00s)2623=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout26242026/09/24 18:06:15 ERROR Accept failed error="too many open files"26252026/09/24 18:06:15 ERROR Refusing path outside the store path=/nix/store store=/nix/store26262026/09/24 18:06:15 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store26272026/09/24 18:06:15 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store26282026/09/24 18:06:15 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store26292026/09/24 18:06:15 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26302026/09/24 18:06:15 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26312026/09/24 18:06:15 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store26322026/09/24 18:06:15 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store26332026/09/24 18:06:15 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store26342026/09/24 18:06:15 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store26352026/09/24 18:06:15 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store26362026/09/24 18:06:15 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store26372026/09/24 18:06:15 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store26382026/09/24 18:06:15 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store26392026/09/24 18:06:15 ERROR Failed to decode request error="unexpected EOF"2640--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2641=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path26422026/09/24 18:06:15 ERROR Accept failed error="too many open files"26432026/09/24 18:06:16 ERROR Accept failed error="too many open files"26442026/09/24 18:06:16 ERROR Accept failed error="too many open files"26452026/09/24 18:06:16 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat699809611/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat699809611/002/locked/aaa: permission denied"26462026/09/24 18:06:16 INFO Upload queue status pending=326472026/09/24 18:06:16 INFO Uploading batch count=126482026/09/24 18:06:16 ERROR Upload failed error="upload failed" count=126492026/09/24 18:06:16 INFO Uploading batch count=226502026/09/24 18:06:16 INFO Upload queue status pending=226512026/09/24 18:06:16 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat699809611/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat699809611/002/locked/aaa: permission denied"26522026/09/24 18:06:16 INFO Uploading batch count=226532026/09/24 18:06:16 INFO Uploading batch count=226542026/09/24 18:06:16 ERROR Upload failed error="upload failed" count=226552026/09/24 18:06:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown9403174/002/a26562026/09/24 18:06:16 INFO Upload queue status pending=226572026/09/24 18:06:16 INFO Uploading batch count=126582026/09/24 18:06:16 ERROR Upload failed error="upload failed" count=126592026/09/24 18:06:16 INFO Upload queue status pending=226602026/09/24 18:06:16 INFO Uploading batch count=426612026/09/24 18:06:16 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat699809611/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat699809611/002/locked/aaa: permission denied"26622026/09/24 18:06:16 ERROR Upload failed error="upload failed" count=426632026/09/24 18:06:16 INFO Upload queue status pending=226642026/09/24 18:06:16 INFO Uploading batch count=126652026/09/24 18:06:16 INFO Uploading batch count=22666--- PASS: TestQueueEnqueueAndFetch (0.09s)2667=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch26682026/09/24 18:06:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown9403174/002/b26692026/09/24 18:06:16 INFO Upload queue status pending=226702026/09/24 18:06:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1339143832/002/bbb26712026/09/24 18:06:16 INFO Uploading batch count=226722026/09/24 18:06:16 INFO Uploading batch count=126732026/09/24 18:06:16 ERROR Drain finished with paths left in queue remaining=126742026/09/24 18:06:16 INFO Uploading batch count=22675=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths2676--- PASS: TestQueueRetryMovesToBack (0.10s)2677=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short2678--- PASS: TestQueueDeduplication (0.10s)26792026/09/24 18:06:16 INFO Upload queue status pending=32680=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2681--- PASS: TestQueueFetchBatchLimit (0.10s)2682--- PASS: TestQueueFetchRemoveLifecycle (0.10s)26832026/09/24 18:06:16 INFO Uploading batch count=226842026/09/24 18:06:16 ERROR Upload failed error="upload failed" count=226852026/09/24 18:06:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown9403174/002/c26862026/09/24 18:06:16 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2891538571/002/nonexistent26872026/09/24 18:06:16 INFO Uploading batch count=126882026/09/24 18:06:16 INFO Uploading batch count=126892026/09/24 18:06:16 ERROR Upload failed error="upload failed" count=126902026/09/24 18:06:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown9403174/002/d26912026/09/24 18:06:16 INFO Uploading batch count=22692--- PASS: TestWorkerKeepsPathItCannotStat (0.11s)26932026/09/24 18:06:16 INFO Uploading batch count=126942026/09/24 18:06:16 ERROR Upload failed error="upload failed" count=126952026/09/24 18:06:16 INFO Uploading batch count=226962026/09/24 18:06:16 ERROR Upload failed error="upload failed" count=226972026/09/24 18:06:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown9403174/002/e26982026/09/24 18:06:16 INFO Uploading batch count=126992026/09/24 18:06:16 ERROR Upload failed error="upload failed" count=127002026/09/24 18:06:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown9403174/002/f2701--- PASS: TestQueueRemove (0.13s)27022026/09/24 18:06:16 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path1659272211/001/nonexistent2703--- PASS: TestWorkerPrunesClosureDeps (0.13s)27042026/09/24 18:06:16 ERROR Drain finished with paths left in queue remaining=127052026/09/24 18:06:16 ERROR Drain finished with paths left in queue remaining=1027062026/09/24 18:06:16 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=12707--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.13s)27082026/09/24 18:06:16 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path1659272211/001/nonexistent2709--- PASS: TestFailedPathPrunedByLaterClosure (0.13s)2710--- PASS: TestWorkerSkipsGCdPaths (0.14s)27112026/09/24 18:06:16 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=12712--- PASS: TestWorkerUploadsAndRemoves (0.14s)27132026/09/24 18:06:16 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path1659272211/001/nonexistent2714--- PASS: TestDrainIsolatesPoisonPath (0.14s)27152026/09/24 18:06:16 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=12716--- PASS: TestDrainGivesUpWhenServerDown (0.14s)27172026/09/24 18:06:16 ERROR Drain finished with paths left in queue remaining=127182026/09/24 18:06:16 INFO Uploading batch count=427192026/09/24 18:06:16 INFO Uploading batch count=427202026/09/24 18:06:16 ERROR Upload failed error="upload failed" count=427212026/09/24 18:06:16 ERROR Upload failed error="upload failed" count=427222026/09/24 18:06:16 ERROR Accept failed error="too many open files"27232026/09/24 18:06:16 INFO Uploading batch count=227242026/09/24 18:06:16 ERROR Upload failed error="upload failed" count=227252026/09/24 18:06:16 INFO Uploading batch count=227262026/09/24 18:06:16 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127272026/09/24 18:06:16 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227282026/09/24 18:06:16 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127292026/09/24 18:06:16 INFO Uploading batch count=227302026/09/24 18:06:16 INFO Uploading batch count=227312026/09/24 18:06:16 ERROR Upload failed error="upload failed" count=227322026/09/24 18:06:16 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227332026/09/24 18:06:16 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127342026/09/24 18:06:16 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127352026/09/24 18:06:16 INFO Uploading batch count=227362026/09/24 18:06:16 INFO Uploading batch count=227372026/09/24 18:06:16 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227382026/09/24 18:06:16 ERROR Upload failed error="upload failed" count=227392026/09/24 18:06:16 ERROR Drain finished with paths left in queue remaining=227402026/09/24 18:06:16 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127412026/09/24 18:06:16 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127422026/09/24 18:06:16 ERROR Drain finished with paths left in queue remaining=22743--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2744 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.13s)2745 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.08s)2746 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.08s)27472026/09/24 18:06:16 ERROR Failed to decode request error="read unix /build/hook1466667892/test.sock->@: i/o timeout"27482026/09/24 18:06:16 ERROR Failed to write response error="write unix /build/hook1466667892/test.sock->@: i/o timeout"2749--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)27502026/09/24 18:06:16 ERROR Upload failed error="context canceled" count=227512026/09/24 18:06:16 ERROR Drain finished with paths left in queue remaining=42752--- PASS: TestDrainTimeout (0.28s)27532026/09/24 18:06:16 ERROR Upload failed error="context canceled" count=227542026/09/24 18:06:16 ERROR Drain finished with paths left in queue remaining=22755--- PASS: TestShutdownFinishesInFlightPush (0.00s)2756 --- PASS: TestShutdownFinishesInFlightPush/completes (0.19s)2757 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.29s)27582026/09/24 18:06:16 ERROR Accept failed error="too many open files"27592026/09/24 18:06:16 ERROR Drain finished with paths left in queue remaining=427602026/09/24 18:06:16 ERROR Drain finished with paths left in queue remaining=32761--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2762 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.25s)2763 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.36s)27642026/09/24 18:06:16 ERROR Accept failed error="too many open files"2765--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)2766--- PASS: TestQueueConcurrentWriters (0.86s)27672026/09/24 18:06:17 INFO Uploading batch count=127682026/09/24 18:06:17 INFO Uploading batch count=127692026/09/24 18:06:17 INFO Uploading batch count=127702026/09/24 18:06:17 ERROR Upload failed error="upload failed" count=127712026/09/24 18:06:17 INFO Uploading batch count=127722026/09/24 18:06:17 ERROR Upload failed error="upload failed" count=127732026/09/24 18:06:17 INFO Uploading batch count=127742026/09/24 18:06:17 ERROR Upload failed error="upload failed" count=127752026/09/24 18:06:17 INFO Uploading batch count=127762026/09/24 18:06:17 ERROR Upload failed error="upload failed" count=127772026/09/24 18:06:17 ERROR Drain finished with paths left in queue remaining=12778--- PASS: TestRunNotBlockedByPoisonHead (1.12s)2779--- PASS: TestQueueRemoveLargeClosure (4.07s)2780--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.08s)2781PASS2782Running niks3-hook command tests...2783=== RUN TestServeSecondSignalEndsDrain2784=== PAUSE TestServeSecondSignalEndsDrain2785=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown2786=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown2787=== CONT TestServeSecondSignalEndsDrain2788=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown2789--- PASS: TestServeSecondSignalEndsDrain (0.07s)27902026/09/24 18:06:23 INFO Upload queue status pending=127912026/09/24 18:06:23 INFO Uploading batch count=12792--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.13s)2793PASS2794Running rate limiter tests...2795=== RUN TestAdaptiveRateLimiter_ThreadSafety2796=== PAUSE TestAdaptiveRateLimiter_ThreadSafety2797=== CONT TestAdaptiveRateLimiter_ThreadSafety27982026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=102.4870000000000527992026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=71.7409000000000228002026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=50.2186300000000128012026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=35.1530410000000128022026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=24.60712870000000428032026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=17.22499009000000228042026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=12.05749306328052026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=8.440245144128062026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=5.9081716008728072026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528082026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528092026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528102026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528112026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528122026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528132026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528142026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528152026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528162026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528172026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528182026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528192026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528202026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528212026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528222026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528232026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528242026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528252026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528262026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528272026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528282026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528292026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528302026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528312026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528322026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=6.200463500000001528332026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528342026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528352026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528362026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528372026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528382026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528392026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528402026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528412026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528422026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528432026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528442026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528452026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528462026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528472026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528482026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528492026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528502026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528512026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528522026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528532026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528542026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528552026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528562026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528572026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=8.25281691850000428582026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=5.77697184295000328592026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528602026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528612026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528622026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528632026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528642026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528652026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528662026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528672026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528682026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528692026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528702026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=5.63678500000000128712026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528722026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528732026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528742026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=5.12435000000000128752026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528762026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528772026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528782026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528792026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528802026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528812026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528822026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528832026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528842026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528852026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528862026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528872026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528882026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528892026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528902026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528912026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528922026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528932026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528942026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528952026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528962026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=528972026/09/24 18:06:24 WARN Rate limiter backed off name=test rate=52898--- PASS: TestAdaptiveRateLimiter_ThreadSafety (0.11s)2899PASS