niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #404
· raw
1tribuchet: building on jamie2Running 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.73s)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.03s)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_ClosesBodyWhenNoAttemptIsMade79=== PAUSE TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade80=== RUN TestRetryTimeoutOutlastsMaxRetries81=== PAUSE TestRetryTimeoutOutlastsMaxRetries82=== RUN TestDoWithRetry_FinalResponseBodyReadable83=== PAUSE TestDoWithRetry_FinalResponseBodyReadable84=== RUN TestShellSplit85=== PAUSE TestShellSplit86=== RUN TestShellSplitErrors87=== PAUSE TestShellSplitErrors88=== RUN TestStreamPushReportsEveryPath89=== PAUSE TestStreamPushReportsEveryPath90=== RUN TestStreamPushBatchesUnderLoad91=== PAUSE TestStreamPushBatchesUnderLoad92=== RUN TestStreamPushIsolatesFailures93=== PAUSE TestStreamPushIsolatesFailures94=== RUN TestStreamPushGivesUpOnDeadServer95=== PAUSE TestStreamPushGivesUpOnDeadServer96=== RUN TestStreamPushRequestLine97=== PAUSE TestStreamPushRequestLine98=== RUN TestStreamPushReportsSignatures99=== PAUSE TestStreamPushReportsSignatures100=== RUN TestStreamPushReportsSkippedPaths101=== PAUSE TestStreamPushReportsSkippedPaths102=== RUN TestClientSignaturesByStorePath103=== PAUSE TestClientSignaturesByStorePath104=== RUN TestStreamPushStopsWhenCanceled105=== PAUSE TestStreamPushStopsWhenCanceled106=== RUN TestStreamPushStopsOnCancel107=== PAUSE TestStreamPushStopsOnCancel108=== RUN TestSetClientTLS109=== PAUSE TestSetClientTLS110=== RUN TestSetClientTLSDoesNotMutateDefaultTransport111=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport112=== RUN TestSetClientTLSErrors113=== PAUSE TestSetClientTLSErrors114=== RUN TestStaticToken115=== PAUSE TestStaticToken116=== RUN TestFileTokenReadsAndCaches117=== PAUSE TestFileTokenReadsAndCaches118=== RUN TestFileTokenMissing119=== PAUSE TestFileTokenMissing120=== RUN TestFileTokenEmpty121=== PAUSE TestFileTokenEmpty122=== RUN TestScriptTokenNoExpiryRerunsEveryCall123=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall124=== RUN TestScriptTokenCachesUntilRefresh125=== PAUSE TestScriptTokenCachesUntilRefresh126=== RUN TestScriptTokenEmptyToken127=== PAUSE TestScriptTokenEmptyToken128=== RUN TestScriptTokenBadJSON129=== PAUSE TestScriptTokenBadJSON130=== RUN TestScriptTokenScriptFails131=== PAUSE TestScriptTokenScriptFails132=== RUN TestScriptTokenEmptyCommand133=== PAUSE TestScriptTokenEmptyCommand134=== RUN TestScriptTokenDoesNotWaitForItsChildren135=== PAUSE TestScriptTokenDoesNotWaitForItsChildren136=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry137=== CONT TestRetryTimeoutOutlastsMaxRetries138=== CONT TestStreamPushStopsWhenCanceled139=== CONT TestParsePathInfoJSON140=== CONT TestScriptTokenEmptyCommand141=== CONT TestScriptTokenDoesNotWaitForItsChildren142=== CONT TestScriptTokenBadJSON143=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs144=== CONT TestStreamPushBatchesUnderLoad145=== CONT TestScriptTokenEmptyToken146=== CONT TestStreamPushGivesUpOnDeadServer147=== CONT TestScriptTokenCachesUntilRefresh148=== CONT TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade149=== CONT TestSetClientTLS150=== CONT TestPartSizeForNAR151=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica152=== CONT TestTruncatedNARDumpIsNotCompleted153=== CONT TestUploadMultipart_SupersededByPeer154=== RUN TestUploadMultipart_SupersededByPeer/exists155=== PAUSE TestUploadMultipart_SupersededByPeer/exists156=== RUN TestUploadMultipart_SupersededByPeer/missing157=== CONT TestUploadMultipart_FailedPartBufferNotReused158=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun159=== CONT TestStreamPushReportsSignatures160=== CONT TestUploadMultipart_PartsInParallel161=== CONT TestCaseHackSuffix162=== CONT TestSetClientTLSErrors163=== CONT TestResolveStorePath164=== RUN TestParsePathInfoJSON/Nix_format165--- PASS: TestScriptTokenEmptyCommand (0.00s)166=== CONT TestRegisterUploadedObjectReusesConnections167=== RUN TestStreamPushBatchesUnderLoad/together168=== CONT TestStreamPushIsolatesFailures169=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs170=== RUN TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0171=== RUN TestPartSizeForNAR/zero_stays_at_minimum172=== PAUSE TestUploadMultipart_SupersededByPeer/missing173=== PAUSE TestParsePathInfoJSON/Nix_format174--- PASS: TestStreamPushStopsWhenCanceled (0.00s)175=== PAUSE TestStreamPushBatchesUnderLoad/together176=== PAUSE TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0177=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum178=== CONT TestScriptTokenScriptFails179=== RUN TestPartSizeForNAR/small_stays_at_minimum180=== CONT TestFileTokenMissing181=== CONT TestDoWithRetry_FinalResponseBodyReadable182=== RUN TestSetClientTLSErrors/missing_cert_file183=== PAUSE TestPartSizeForNAR/small_stays_at_minimum184=== CONT TestStreamPushRequestLine185=== PAUSE TestSetClientTLSErrors/missing_cert_file186=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum187=== RUN TestParsePathInfoJSON/Lix_format188=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum189=== RUN TestSetClientTLSErrors/missing_key_file190=== CONT TestDoServerRequestAttachesToken191=== CONT TestFileTokenReadsAndCaches192=== CONT TestClientSignaturesByStorePath193=== CONT TestStreamPushReportsEveryPath194=== CONT TestSetClientTLSDoesNotMutateDefaultTransport195=== RUN TestSetClientTLS/rejects_connection_without_client_cert196=== CONT TestEncodeNixBase32197=== RUN TestEncodeNixBase32/test_string_hash198=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert199=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA200=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA201=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts202=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts203=== RUN TestPartSizeForNAR/1_TiB204=== PAUSE TestSetClientTLSErrors/missing_key_file205=== RUN TestSetClientTLSErrors/missing_ca_file206=== RUN TestSetClientTLS/preserves_debug_logging_transport207=== PAUSE TestSetClientTLSErrors/missing_ca_file208=== RUN TestSetClientTLSErrors/invalid_ca_file209=== PAUSE TestSetClientTLSErrors/invalid_ca_file210=== PAUSE TestPartSizeForNAR/1_TiB211=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time212=== PAUSE TestParsePathInfoJSON/Lix_format213=== PAUSE TestSetClientTLS/preserves_debug_logging_transport214=== RUN TestParsePathInfoJSON/empty_input215=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time216=== CONT TestStreamPushStopsOnCancel217=== RUN TestPartSizeForNAR/5_TiB_S3_max_object218=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess219=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object220=== RUN TestStreamPushStopsOnCancel/waiting_for_input221=== RUN TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=5222=== PAUSE TestEncodeNixBase32/test_string_hash223=== CONT TestScriptTokenNoExpiryRerunsEveryCall224=== PAUSE TestParsePathInfoJSON/empty_input225=== CONT TestStreamPushReportsSkippedPaths226=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout227=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer228=== RUN TestPartSizeForNAR/capped_at_5_GiB229=== CONT TestPathInfoHashCompatibility230=== CONT TestShellSplit231=== CONT TestStaticToken232=== CONT TestParsePathInfoJSONMultiplePaths233=== PAUSE TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=5234=== RUN TestEncodeNixBase32/empty_input235=== CONT TestCompletePendingClosure_NotFoundWithoutKey236=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input237=== RUN TestParsePathInfoJSON/whitespace_only238=== PAUSE TestPartSizeForNAR/capped_at_5_GiB239=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths240=== CONT TestRateLimiterFeedback241=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot242=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths243=== CONT TestPathInfoCACompatibility244=== PAUSE TestEncodeNixBase32/empty_input245=== PAUSE TestParsePathInfoJSON/whitespace_only246=== CONT TestEncodeNixBase32WithRealHash247=== RUN TestParsePathInfoJSON/invalid_JSON248=== CONT TestShellSplitErrors249=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths250=== CONT TestDumpPathSingleFile251=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths252=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)253=== CONT TestFilterOversizedClosures254=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)255=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout256=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent257=== CONT TestDoWithRetry_BodyReplayedViaGetBody258=== CONT TestConvertHashToNix32259--- PASS: TestStreamPushReportsSignatures (0.17s)260=== RUN TestRateLimiterFeedback/429_enables_limiter261=== CONT TestGetStorePathHash262=== RUN TestPathInfoCACompatibility/null_ca_field263=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot264=== PAUSE TestParsePathInfoJSON/invalid_JSON265=== CONT TestDumpPathWriterError266=== RUN TestFilterOversizedClosures/no_limit_keeps_everything267=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon268=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure269=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier270=== RUN TestGetStorePathHash/valid_store_path271=== CONT TestSupersededNARStillUploadsListing272=== RUN TestConvertHashToNix32/SRI_format_to_Nix32273=== RUN TestSupersededNARStillUploadsListing/small_NAR274=== PAUSE TestSupersededNARStillUploadsListing/small_NAR275=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier276--- PASS: TestScriptTokenEmptyToken (0.18s)277=== PAUSE TestRateLimiterFeedback/429_enables_limiter278=== PAUSE TestPathInfoCACompatibility/null_ca_field279=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon280=== RUN TestPathInfoCACompatibility/old_string_format_-_text281=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI282=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text283=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI284=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive285=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot286=== PAUSE TestGetStorePathHash/valid_store_path287=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32288=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything289=== RUN TestSupersededNARStillUploadsListing/dump_cut_short290=== RUN TestConvertHashToNix32/already_Nix32_format291=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short292--- PASS: TestResolveStorePath (0.00s)293=== RUN TestRateLimiterFeedback/503_enables_limiter294=== CONT TestDumpPathMatchesNix295=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512296=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive297=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512298=== RUN TestPathInfoCACompatibility/new_structured_format_-_text299=== CONT TestFileTokenEmpty300=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text301=== RUN TestGetStorePathHash/basename_without_hyphen_should_error302=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method303=== CONT TestUploadMultipart_ProducerErrorIsNotEOF304=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot305=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error306=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part307=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped308=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part309=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary310=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary311=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up312=== PAUSE TestConvertHashToNix32/already_Nix32_format313--- PASS: TestScriptTokenBadJSON (0.19s)314=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails315=== PAUSE TestRateLimiterFeedback/503_enables_limiter316=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method317=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot318=== CONT TestUploadMultipart_SupersededByPeer/missing319=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails320=== CONT TestSetClientTLSErrors/missing_cert_file321=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter322=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped323=== RUN TestFilterOversizedClosures/all_closures_skipped324=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up325=== RUN TestConvertHashToNix32/invalid_format326--- PASS: TestStreamPushIsolatesFailures (0.00s)327=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error328=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot329=== CONT TestSetClientTLS/preserves_debug_logging_transport330=== CONT TestUploadMultipart_SupersededByPeer/exists331=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter332=== CONT TestStreamPushBatchesUnderLoad/together333=== PAUSE TestFilterOversizedClosures/all_closures_skipped334=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier335--- PASS: TestStreamPushGivesUpOnDeadServer (0.18s)336--- PASS: TestFileTokenMissing (0.00s)337=== PAUSE TestConvertHashToNix32/invalid_format338=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error339=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot340=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter341=== CONT TestSetClientTLSErrors/invalid_ca_file342=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier343=== CONT TestSetClientTLSErrors/missing_ca_file344=== CONT TestSetClientTLSErrors/missing_key_file345--- PASS: TestScriptTokenScriptFails (0.00s)346=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time347=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error348=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot349=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter350=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA351=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client352=== CONT TestSetClientTLS/rejects_connection_without_client_cert353--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.19s)354=== CONT TestPartSizeForNAR/small_stays_at_minimum355=== CONT TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=5356=== CONT TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0357=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error358=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken359=== CONT TestPartSizeForNAR/5_TiB_S3_max_object360=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client361=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum362=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client363--- PASS: TestFileTokenReadsAndCaches (0.00s)364--- PASS: TestClientSignaturesByStorePath (0.00s)365=== CONT TestEncodeNixBase32/test_string_hash366=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts367=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths368=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken369=== CONT TestPartSizeForNAR/capped_at_5_GiB370=== CONT TestPartSizeForNAR/zero_stays_at_minimum371=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client372=== CONT TestPartSizeForNAR/1_TiB373=== CONT TestEncodeNixBase32/empty_input374--- PASS: TestScriptTokenCachesUntilRefresh (0.18s)375=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths376=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout377=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs378=== CONT TestParsePathInfoJSON/Nix_format379=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)380=== CONT TestParsePathInfoJSON/whitespace_only381=== CONT TestParsePathInfoJSON/empty_input382=== CONT TestParsePathInfoJSON/invalid_JSON383--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.18s)384=== CONT TestParsePathInfoJSON/Lix_format385=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI386=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon387=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512388=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part389=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary390--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)391=== CONT TestPathInfoCACompatibility/new_structured_format_-_text392=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method393=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive394=== CONT TestPathInfoCACompatibility/old_string_format_-_text395--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.18s)396=== CONT TestPathInfoCACompatibility/null_ca_field397=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails398=== CONT TestFilterOversizedClosures/all_closures_skipped399=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped400=== CONT TestFilterOversizedClosures/no_limit_keeps_everything401=== CONT TestConvertHashToNix32/invalid_format402--- PASS: TestStreamPushReportsEveryPath (0.00s)403=== CONT TestConvertHashToNix32/SRI_format_to_Nix32404=== CONT TestRateLimiterFeedback/429_enables_limiter405--- PASS: TestShellSplit (0.00s)406--- PASS: TestStreamPushReportsSkippedPaths (0.00s)407=== CONT TestSupersededNARStillUploadsListing/dump_cut_short408=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter409--- PASS: TestStaticToken (0.00s)410--- PASS: TestDoServerRequestAttachesToken (0.01s)411--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)412--- PASS: TestEncodeNixBase32WithRealHash (0.00s)413--- PASS: TestShellSplitErrors (0.00s)414--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.00s)415--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)416--- PASS: TestFileTokenEmpty (0.00s)417--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)418--- PASS: TestUploadMultipart_SupersededByPeer (0.18s)419 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)420 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)421--- PASS: TestStreamPushBatchesUnderLoad (0.19s)422 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)423 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)424=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter425--- PASS: TestSetClientTLSErrors (0.01s)426 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)427 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)428 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)429 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)430=== CONT TestSupersededNARStillUploadsListing/small_NAR431--- PASS: TestEncodeNixBase32 (0.01s)432 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)433 --- PASS: TestEncodeNixBase32/empty_input (0.00s)434--- PASS: TestPartSizeForNAR (0.19s)435 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)436 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)437 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)438 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)439 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)440 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)441 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)442=== CONT TestRateLimiterFeedback/503_enables_limiter443--- PASS: TestParsePathInfoJSON (0.20s)444 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)445 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)446 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)447 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)448 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)449--- PASS: TestDumpPathSingleFile (0.16s)450--- PASS: TestCaseHackSuffix (0.35s)451--- PASS: TestPathInfoHashCompatibility (0.01s)452 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)453 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)454 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)455 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)456=== CONT TestGetStorePathHash/valid_store_path457=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error458--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)459 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)460 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)461=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error462--- PASS: TestPathInfoCACompatibility (0.01s)463 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)464 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)465 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.13s)466 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)467 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)468=== CONT TestGetStorePathHash/basename_without_hyphen_should_error469=== CONT TestStreamPushStopsOnCancel/waiting_for_input470--- PASS: TestFilterOversizedClosures (0.01s)471 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)472 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)473 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)474--- PASS: TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade (0.19s)475 --- PASS: TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=5 (0.00s)476 --- PASS: TestDoWithRetry_ClosesBodyWhenNoAttemptIsMade/retries=0 (0.00s)477=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot478=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot479=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken480=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot481--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.38s)482--- PASS: TestGetStorePathHash (0.01s)483 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)484 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)485 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)486 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)487--- PASS: TestRateLimiterFeedback (0.02s)488 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)489 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)490 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)491 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)492=== CONT TestConvertHashToNix32/already_Nix32_format493--- PASS: TestConvertHashToNix32 (0.01s)494 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)495 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)496 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)497=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot498=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier499=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client500=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client501=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up502=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier503--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.02s)504 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.01s)505 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.01s)506 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.01s)507 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.00s)508 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.01s)509--- PASS: TestStreamPushStopsOnCancel (0.02s)510 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.17s)511 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.17s)512 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.19s)513 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.19s)514 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.19s)515 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.20s)516--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.39s)517--- PASS: TestDumpPathWriterError (0.41s)518--- PASS: TestSetClientTLS (0.19s)519 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.17s)520 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.16s)521 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.42s)522--- PASS: TestRegisterUploadedObjectReusesConnections (0.52s)523--- PASS: TestStreamPushRequestLine (0.55s)524--- PASS: TestDumpPathMatchesNix (0.61s)525--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.00s)526 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.57s)527 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.60s)528--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)529--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.38s)530--- PASS: TestTruncatedNARDumpIsNotCompleted (1.46s)531--- PASS: TestSupersededNARStillUploadsListing (0.00s)532 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.20s)533 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.22s)534 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.25s)535--- PASS: TestUploadMultipart_PartsInParallel (1.46s)536--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (2.00s)537--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.20s)538 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.01s)539 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.33s)540PASS541Running server tests...542The files belonging to this database system will be owned by user "nixbld".543This user must also own the server process.544545The database cluster will be initialized with locale "C".546The default database encoding has accordingly been set to "SQL_ASCII".547The default text search configuration will be set to "english".548549Data page checksums are enabled.550551creating directory /build/postgres4055310639/data ... ok552creating subdirectories ... ok553selecting dynamic shared memory implementation ... posix554selecting default "max_connections" ... 100555selecting default "shared_buffers" ... 128MB556selecting default time zone ... UTC557creating configuration files ... ok558running bootstrap script ... ok559performing post-bootstrap initialization ... ok560syncing data to disk ... ok561562initdb: warning: enabling "trust" authentication for local connections563initdb: 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.564565Success. You can now start the database server using:566567 pg_ctl -D /build/postgres4055310639/data -l logfile start568569/build/postgres4055310639:5432 - no response5702026-10-09 18:07:01.551 UTC [171] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit5712026-10-09 18:07:01.551 UTC [171] LOG: listening on Unix socket "/build/postgres4055310639/.s.PGSQL.5432"5722026-10-09 18:07:01.556 UTC [178] LOG: database system was shut down at 2026-10-09 18:07:01 UTC5732026-10-09 18:07:01.560 UTC [171] LOG: database system is ready to accept connections574/build/postgres4055310639:5432 - accepting connections575=== RUN TestService_AuthMiddleware576=== PAUSE TestService_AuthMiddleware577=== RUN TestService_AuthMiddleware_MTLSProxyHeader578=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader579=== RUN TestService_AuthMiddleware_MTLSBoundSubjects580=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects581=== RUN TestService_ReadAuthMiddleware582=== PAUSE TestService_ReadAuthMiddleware583=== RUN TestService_AuthMiddleware_OIDC584=== PAUSE TestService_AuthMiddleware_OIDC585=== RUN TestService_RequireScope_OIDC586=== PAUSE TestService_RequireScope_OIDC587=== RUN TestService_ReadScope_PublicByDefault588=== PAUSE TestService_ReadScope_PublicByDefault589=== RUN TestCacheConfigHandler590=== PAUSE TestCacheConfigHandler591=== RUN TestCacheStatsHandler592=== PAUSE TestCacheStatsHandler593=== RUN TestClientCADerivations594=== PAUSE TestClientCADerivations595=== RUN TestClientErrorHandling596=== PAUSE TestClientErrorHandling597=== RUN TestClientIntegration598=== PAUSE TestClientIntegration599=== RUN TestClientMultipleUploads600=== PAUSE TestClientMultipleUploads601=== RUN TestClientWithDependencies602=== PAUSE TestClientWithDependencies603=== RUN TestClientSharedPathCommittedMidPush604=== PAUSE TestClientSharedPathCommittedMidPush605=== RUN TestPinProtectsFromGC606=== PAUSE TestPinProtectsFromGC607=== RUN TestClientPushesUseOnePush608=== PAUSE TestClientPushesUseOnePush609=== RUN TestClientFallsBackToClosures610=== PAUSE TestClientFallsBackToClosures611=== RUN TestDeleteClosuresRacingPins612=== PAUSE TestDeleteClosuresRacingPins613=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock614=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock615=== RUN TestResolveDBConnectionString616=== PAUSE TestResolveDBConnectionString617=== RUN TestConnectWaitsForAPeerMigration618=== PAUSE TestConnectWaitsForAPeerMigration619=== RUN TestConnectSerialisesConcurrentMigrations620=== PAUSE TestConnectSerialisesConcurrentMigrations621=== RUN TestLeadElectsOneAndHandsOver622=== PAUSE TestLeadElectsOneAndHandsOver623=== RUN TestLeadIncumbentWinsAfterRestart6242026/10/09 18:07:02 INFO lead: acquired remote=192.0.2.1:12346252026/10/09 18:07:02 INFO lead: released remote=192.0.2.1:12346262026/10/09 18:07:02 INFO lead: acquired remote=192.0.2.1:12346272026/10/09 18:07:03 INFO lead: released remote=192.0.2.1:1234628--- PASS: TestLeadIncumbentWinsAfterRestart (1.93s)629=== RUN TestLeadIncumbentAnnouncesAtOnce630=== PAUSE TestLeadIncumbentAnnouncesAtOnce631=== RUN TestLeadEndsOnShutdown632=== PAUSE TestLeadEndsOnShutdown633=== RUN TestLeadEndsWhenItsConnectionHangs6342026/10/09 18:07:03 INFO lead: acquired remote=192.0.2.1:12346352026-10-09 18:07:05.347 UTC [620] FATAL: terminating connection due to administrator command6362026/10/09 18:07:05 INFO lead: acquired remote=192.0.2.1:12346372026/10/09 18:07:06 WARN lead: lock connection lost error="timeout: context deadline exceeded"6382026/10/09 18:07:06 INFO lead: released remote=192.0.2.1:12346392026/10/09 18:07:06 INFO lead: released remote=192.0.2.1:1234640--- PASS: TestLeadEndsWhenItsConnectionHangs (2.96s)641=== RUN TestGCAdvisoryLockBlocksConcurrentRun642=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun643=== RUN TestGCBugBareHashReferences644=== PAUSE TestGCBugBareHashReferences645=== RUN TestGCMetrics646=== PAUSE TestGCMetrics647=== RUN TestPushDedupSurvivesConcurrentGC648=== PAUSE TestPushDedupSurvivesConcurrentGC649=== RUN TestDeduplicatedObjectsRecordedAsPending650=== PAUSE TestDeduplicatedObjectsRecordedAsPending651=== RUN TestGCSweepSkipsPendingObjects652=== PAUSE TestGCSweepSkipsPendingObjects653=== RUN TestTombstonedObjectOfferedWithoutWaiting654=== PAUSE TestTombstonedObjectOfferedWithoutWaiting655=== RUN TestGCSweepDeliversEachKeyOnce656=== PAUSE TestGCSweepDeliversEachKeyOnce657=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection658=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection659=== RUN TestForceGCDuringPushOffersSweptObject660=== PAUSE TestForceGCDuringPushOffersSweptObject661=== RUN TestFailedS3DeleteKeepsTombstone662=== PAUSE TestFailedS3DeleteKeepsTombstone663=== RUN TestSweepSkipsRowsLockedByPush664=== PAUSE TestSweepSkipsRowsLockedByPush665=== RUN TestRegisterCompletedObjectNeedsPendingRow666=== PAUSE TestRegisterCompletedObjectNeedsPendingRow667=== RUN TestGetExistingObjectsLocksRows668=== PAUSE TestGetExistingObjectsLocksRows669=== RUN TestSweepRechecksPendingAfterLocking670=== PAUSE TestSweepRechecksPendingAfterLocking671=== RUN TestPushWaitsForSweepHoldingRow672=== PAUSE TestPushWaitsForSweepHoldingRow673=== RUN TestCommitRacingPendingCleanupKeepsObjects674=== PAUSE TestCommitRacingPendingCleanupKeepsObjects675=== RUN TestGCEndsOnShutdown676=== PAUSE TestGCEndsOnShutdown677=== RUN TestGCTaskStore_StartNew678=== PAUSE TestGCTaskStore_StartNew679=== RUN TestGCTaskStore_DeduplicateSameParams680=== PAUSE TestGCTaskStore_DeduplicateSameParams681=== RUN TestGCTaskStore_ConflictDifferentParams682=== PAUSE TestGCTaskStore_ConflictDifferentParams683=== RUN TestGCTaskStore_GetEmpty684=== PAUSE TestGCTaskStore_GetEmpty685=== RUN TestGCTaskStore_GetReturnsLatest686=== PAUSE TestGCTaskStore_GetReturnsLatest687=== RUN TestGCTaskStore_CompletedAllowsNewTask688=== PAUSE TestGCTaskStore_CompletedAllowsNewTask689=== RUN TestGCTaskStore_PhaseUpdates690=== PAUSE TestGCTaskStore_PhaseUpdates691=== RUN TestGCTaskStore_Fail692=== PAUSE TestGCTaskStore_Fail693=== RUN TestGracefulShutdownDrainsInflight694=== PAUSE TestGracefulShutdownDrainsInflight695=== RUN TestService_healthCheckHandler696=== PAUSE TestService_healthCheckHandler697=== RUN TestService_readinessHandler698=== PAUSE TestService_readinessHandler699=== RUN TestGenerateLandingPage700=== PAUSE TestGenerateLandingPage701=== RUN TestChildrenInheritRaisedFileLimit702=== PAUSE TestChildrenInheritRaisedFileLimit703=== RUN TestCacheConfigHandlerMaxNarSize704=== PAUSE TestCacheConfigHandlerMaxNarSize705=== RUN TestCreatePendingClosureRejectsOversizedNAR706=== PAUSE TestCreatePendingClosureRejectsOversizedNAR707=== RUN TestNARDeduplicationMetadataUploadBug708=== PAUSE TestNARDeduplicationMetadataUploadBug709=== RUN TestMetricsInventory710=== PAUSE TestMetricsInventory711=== RUN TestMetricsCommit712=== PAUSE TestMetricsCommit713=== RUN TestService_NativeMTLS714=== PAUSE TestService_NativeMTLS715=== RUN TestServerTLSConfig716=== PAUSE TestServerTLSConfig717=== RUN TestMultipartCleanup718=== PAUSE TestMultipartCleanup719=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded720=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded721=== RUN TestPendingCleanupUsesOneCutoff722=== PAUSE TestPendingCleanupUsesOneCutoff723=== RUN TestPendingClosureFailureTracksEveryUpload724=== PAUSE TestPendingClosureFailureTracksEveryUpload725=== RUN TestPendingClosureFailureAbortsItsUploads726=== PAUSE TestPendingClosureFailureAbortsItsUploads727=== RUN TestObjectStatsTrigger728=== PAUSE TestObjectStatsTrigger729=== RUN TestObjectStatsLargeCommit730=== PAUSE TestObjectStatsLargeCommit731=== RUN TestReconnectLeavesObjectsUnlocked732=== PAUSE TestReconnectLeavesObjectsUnlocked733=== RUN TestOrphanedObjectsGC734=== PAUSE TestOrphanedObjectsGC735=== RUN TestOrphanedObjectsGCStressTest736=== PAUSE TestOrphanedObjectsGCStressTest737=== RUN TestCreatePin_ReservedPins738=== PAUSE TestCreatePin_ReservedPins739=== RUN TestConcurrentPinUpdatesAgree740=== PAUSE TestConcurrentPinUpdatesAgree741=== RUN TestCreatePinRejectsBadInput742=== PAUSE TestCreatePinRejectsBadInput743=== RUN TestDeletePinKeepsRowWhenS3Fails744=== PAUSE TestDeletePinKeepsRowWhenS3Fails745=== RUN TestPresentReportsOnlyClosureRoots746=== PAUSE TestPresentReportsOnlyClosureRoots747=== RUN TestPresentRefreshesOnlyStaleClosures748=== PAUSE TestPresentRefreshesOnlyStaleClosures749=== RUN TestPresentNotReportedWhileGCDeletesClosure750=== PAUSE TestPresentNotReportedWhileGCDeletesClosure751=== RUN TestParseSingleRange752=== PAUSE TestParseSingleRange753=== RUN TestProxyHeadersOnlyTrustedOnSocket7542026/10/09 18:07:06 INFO Starting HTTP server address=127.0.0.1:391337552026/10/09 18:07:06 INFO Starting HTTP server address=proxy.sock7562026/10/09 18:07:06 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7572026/10/09 18:07:06 INFO Shutdown signal received, draining in-flight requests timeout=10s758--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.16s)759=== RUN TestIsValidCachePath760=== PAUSE TestIsValidCachePath761=== RUN TestReadProxyNarinfo762=== PAUSE TestReadProxyNarinfo763=== RUN TestReadProxyNarinfoAlreadyDecompressed764=== PAUSE TestReadProxyNarinfoAlreadyDecompressed765=== RUN TestReadProxyContentNegotiation766=== PAUSE TestReadProxyContentNegotiation767=== RUN TestReadProxyNarStreaming768=== PAUSE TestReadProxyNarStreaming769=== RUN TestReadProxy404770=== PAUSE TestReadProxy404771=== RUN TestReadProxyInvalidPath772=== PAUSE TestReadProxyInvalidPath773=== RUN TestReadProxyHead774=== PAUSE TestReadProxyHead775=== RUN TestReadProxyOutlastsServerWriteTimeout776=== PAUSE TestReadProxyOutlastsServerWriteTimeout777=== RUN TestReadProxyConditionalGet778=== PAUSE TestReadProxyConditionalGet779=== RUN TestReadProxyRootRedirectsToIndexHTML780=== PAUSE TestReadProxyRootRedirectsToIndexHTML781=== RUN TestReadProxyDisabled782=== PAUSE TestReadProxyDisabled783=== RUN TestReadRedirectNar784=== PAUSE TestReadRedirectNar785=== RUN TestReadRedirectKeepsNarinfoProxied786=== PAUSE TestReadRedirectKeepsNarinfoProxied787=== RUN TestReadProxyRangeRequest788=== PAUSE TestReadProxyRangeRequest789=== RUN TestReadRedirectUsesPublicS3URL790=== PAUSE TestReadRedirectUsesPublicS3URL791=== RUN TestPush_OverlappingRootsStoreOneRowPerKey792=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey793=== RUN TestPush_CompleteCommitsEveryRoot794=== PAUSE TestPush_CompleteCommitsEveryRoot795=== RUN TestPush_RepeatedRootCommitsOnce796=== PAUSE TestPush_RepeatedRootCommitsOnce797=== RUN TestPush_CompleteWaitsForCleanupOfThePush798=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush799=== RUN TestPush_RootsAreLockedInByteOrder800=== PAUSE TestPush_RootsAreLockedInByteOrder801=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit802=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit803=== RUN TestPush_RejectsBadRequests804=== PAUSE TestPush_RejectsBadRequests805=== RUN TestPush_SignsNarinfosOfItsPendingObjects806=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects807=== RUN TestRedundantMultipartUpload808=== PAUSE TestRedundantMultipartUpload809=== RUN TestCompleteMultipartUpload_ErrorButObjectExists810=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists811=== RUN TestCompletedNarNotReofferedAcrossClosures812=== PAUSE TestCompletedNarNotReofferedAcrossClosures813=== RUN TestPresignedUploadRegisteredBeforeCommit814=== PAUSE TestPresignedUploadRegisteredBeforeCommit815=== RUN TestService_Rustfstest816=== PAUSE TestService_Rustfstest817=== RUN TestParseSize818=== PAUSE TestParseSize819=== RUN TestSkippedUploadsHandler820=== PAUSE TestSkippedUploadsHandler821=== RUN TestSystemdListenerNotActivated822--- PASS: TestSystemdListenerNotActivated (0.00s)823=== RUN TestWatchdogBeatsWhenHealthy824--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)825=== RUN TestWatchdogSkipsWhenUnhealthy8262026/10/09 18:07:06 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8272026/10/09 18:07:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8282026/10/09 18:07:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8292026/10/09 18:07:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8302026/10/09 18:07:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8312026/10/09 18:07:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8322026/10/09 18:07:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8332026/10/09 18:07:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8342026/10/09 18:07:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8352026/10/09 18:07:07 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"836--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)837=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle838=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle839=== RUN TestProxyWriteTimeout840=== PAUSE TestProxyWriteTimeout841=== RUN TestPendingClosureWriteTimeout842=== PAUSE TestPendingClosureWriteTimeout843=== RUN TestIsValidUploadKey844=== PAUSE TestIsValidUploadKey845=== RUN TestUploadHandlersRejectInvalidKeys846=== PAUSE TestUploadHandlersRejectInvalidKeys847=== RUN TestUploadHandlersRejectOversizedBody848=== PAUSE TestUploadHandlersRejectOversizedBody849=== RUN TestService_cleanupPendingClosuresHandler850=== PAUSE TestService_cleanupPendingClosuresHandler851=== RUN TestService_createPendingClosureHandler852=== PAUSE TestService_createPendingClosureHandler853=== RUN TestService_verifyS3Integrity854=== PAUSE TestService_verifyS3Integrity855=== RUN TestCompleteMultipartUnregistered856=== PAUSE TestCompleteMultipartUnregistered857=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT858=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT859=== CONT TestReadProxy404860=== CONT TestService_AuthMiddleware861=== CONT TestReadProxyNarinfoAlreadyDecompressed862=== CONT TestReadProxyNarinfo863=== CONT TestIsValidCachePath864=== CONT TestParseSingleRange865=== CONT TestReadProxyContentNegotiation866=== RUN TestParseSingleRange/none867=== CONT TestPresentNotReportedWhileGCDeletesClosure868=== CONT TestPresentRefreshesOnlyStaleClosures869=== CONT TestPresentReportsOnlyClosureRoots870=== CONT TestCreatePinRejectsBadInput871=== CONT TestConcurrentPinUpdatesAgree872=== CONT TestDeletePinKeepsRowWhenS3Fails873=== CONT TestCreatePin_ReservedPins874=== CONT TestOrphanedObjectsGCStressTest875=== CONT TestReconnectLeavesObjectsUnlocked876=== CONT TestOrphanedObjectsGC877=== CONT TestObjectStatsTrigger878=== CONT TestObjectStatsLargeCommit879=== CONT TestPendingClosureFailureAbortsItsUploads880=== CONT TestPendingClosureFailureTracksEveryUpload881=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded882=== CONT TestServerTLSConfig883=== CONT TestPush_RejectsBadRequests884=== RUN TestIsValidCachePath/narinfo885=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale886=== PAUSE TestParseSingleRange/none887=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false888=== RUN TestServerTLSConfig/no_client_CA889=== PAUSE TestIsValidCachePath/narinfo890=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale891=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh892=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false893=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh894=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true895=== PAUSE TestServerTLSConfig/no_client_CA896=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars897=== RUN TestParseSingleRange/unknown_unit898=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars899=== CONT TestService_NativeMTLS900=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true901=== RUN TestServerTLSConfig/missing_CA_file902=== CONT TestMetricsCommit903=== PAUSE TestParseSingleRange/unknown_unit904=== RUN TestIsValidCachePath/nar_zst905=== PAUSE TestIsValidCachePath/nar_zst906=== PAUSE TestServerTLSConfig/missing_CA_file907=== RUN TestParseSingleRange/multi-range_ignored908=== RUN TestIsValidCachePath/nar_xz909=== RUN TestServerTLSConfig/not_a_PEM_file910=== PAUSE TestIsValidCachePath/nar_xz911=== PAUSE TestParseSingleRange/multi-range_ignored912=== RUN TestParseSingleRange/malformed_no_dash913=== PAUSE TestServerTLSConfig/not_a_PEM_file914=== RUN TestIsValidCachePath/nar_bz2915=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT916=== PAUSE TestParseSingleRange/malformed_no_dash917=== PAUSE TestIsValidCachePath/nar_bz2918=== RUN TestIsValidCachePath/nar_uncompressed919=== RUN TestParseSingleRange/malformed_both_empty920=== PAUSE TestIsValidCachePath/nar_uncompressed921=== PAUSE TestParseSingleRange/malformed_both_empty922=== RUN TestIsValidCachePath/ls923=== RUN TestParseSingleRange/malformed_end_before_start924=== PAUSE TestParseSingleRange/malformed_end_before_start925=== PAUSE TestIsValidCachePath/ls926=== RUN TestParseSingleRange/closed927=== RUN TestIsValidCachePath/log928=== PAUSE TestParseSingleRange/closed929=== PAUSE TestIsValidCachePath/log930=== RUN TestParseSingleRange/open-ended931=== RUN TestIsValidCachePath/realisation932=== PAUSE TestParseSingleRange/open-ended933=== PAUSE TestIsValidCachePath/realisation934=== RUN TestParseSingleRange/end_clamped_to_size935=== RUN TestIsValidCachePath/nix-cache-info936=== PAUSE TestIsValidCachePath/nix-cache-info937=== PAUSE TestParseSingleRange/end_clamped_to_size938=== RUN TestIsValidCachePath/index.html939=== RUN TestParseSingleRange/suffix940=== PAUSE TestParseSingleRange/suffix941=== PAUSE TestIsValidCachePath/index.html942=== RUN TestParseSingleRange/suffix_exceeds_size943=== PAUSE TestParseSingleRange/suffix_exceeds_size944=== RUN TestIsValidCachePath/traversal_parent945=== RUN TestParseSingleRange/single_byte946=== PAUSE TestIsValidCachePath/traversal_parent947=== RUN TestIsValidCachePath/traversal_in_middle948=== PAUSE TestParseSingleRange/single_byte949=== RUN TestParseSingleRange/start_past_EOF950=== PAUSE TestParseSingleRange/start_past_EOF951=== PAUSE TestIsValidCachePath/traversal_in_middle952=== RUN TestParseSingleRange/start_far_past_EOF953=== RUN TestIsValidCachePath/invalid_char_e954=== PAUSE TestParseSingleRange/start_far_past_EOF955=== PAUSE TestIsValidCachePath/invalid_char_e956=== RUN TestIsValidCachePath/invalid_char_u957=== PAUSE TestIsValidCachePath/invalid_char_u958=== RUN TestIsValidCachePath/random_path959=== PAUSE TestIsValidCachePath/random_path960=== RUN TestIsValidCachePath/empty961=== CONT TestMultipartCleanup962=== PAUSE TestIsValidCachePath/empty963=== RUN TestIsValidCachePath/leading_slash964=== PAUSE TestIsValidCachePath/leading_slash965=== RUN TestIsValidCachePath/wrong_extension966=== PAUSE TestIsValidCachePath/wrong_extension967=== RUN TestIsValidCachePath/short_hash968=== PAUSE TestIsValidCachePath/short_hash969=== CONT TestCompleteMultipartUnregistered9702026/10/09 18:07:07 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36473/oidc9712026/10/09 18:07:07 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"972--- PASS: TestService_AuthMiddleware (0.47s)973=== CONT TestMetricsInventory974=== CONT TestService_verifyS3Integrity975--- PASS: TestPresentRefreshesOnlyStaleClosures (0.50s)9762026/10/09 18:07:07 INFO Received create pin request method=POST path=/api/pins/app9772026/10/09 18:07:07 INFO Received create pin request method=POST path=/api/pins/app978--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.55s)979=== CONT TestNARDeduplicationMetadataUploadBug9802026/10/09 18:07:07 INFO Received create pin request method=POST path=/api/pins/deploy9812026/10/09 18:07:07 INFO Received create pin request method=POST path=/api/pins/deploy9822026/10/09 18:07:07 INFO Received create pin request method=POST path=/api/pins/deploy9832026/10/09 18:07:07 INFO Received create pin request method=POST path=/api/pins/deploy9842026/10/09 18:07:07 INFO Received create pin request method=POST path=/api/pins/deploy9852026/10/09 18:07:07 INFO Received create pin request method=POST path=/api/pins/deploy9862026/10/09 18:07:07 INFO Received create pin request method=POST path=/api/pins/deploy9872026/10/09 18:07:07 INFO Received create pin request method=POST path=/api/pins/deploy988=== CONT TestService_createPendingClosureHandler989--- PASS: TestObjectStatsTrigger (0.66s)9902026/10/09 18:07:07 INFO Received create pin request method=POST path=/api/pins/deploy9912026/10/09 18:07:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9922026/10/09 18:07:07 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst993--- PASS: TestReconnectLeavesObjectsUnlocked (0.77s)994=== CONT TestCreatePendingClosureRejectsOversizedNAR995--- PASS: TestCompleteMultipartUnregistered (0.76s)9962026/10/09 18:07:07 INFO Received uploads request method=POST path=/api/pending_closures997=== CONT TestService_cleanupPendingClosuresHandler998=== CONT TestCacheConfigHandlerMaxNarSize999--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1000--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1001=== CONT TestUploadHandlersRejectInvalidKeys1002=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1003=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1004=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1005=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1006=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1007=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1008=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1009=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1010=== CONT TestChildrenInheritRaisedFileLimit1011=== CONT TestUploadHandlersRejectOversizedBody1012--- PASS: TestChildrenInheritRaisedFileLimit (0.00s)10132026/10/09 18:07:07 INFO Received uploads request method=POST path=/api/pending_closures10142026/10/09 18:07:08 INFO Received uploads request method=POST path=/api/pending_closures1015--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.88s)1016=== CONT TestService_readinessHandler10172026/10/09 18:07:08 INFO Received create pin request method=POST path=/api/pins/app10182026/10/09 18:07:08 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo10192026/10/09 18:07:08 INFO Received delete pin request method=DELETE path=/api/pins/app10202026/10/09 18:07:08 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket20/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"10212026/10/09 18:07:08 INFO Received delete pin request method=DELETE path=/api/pins/app10222026/10/09 18:07:08 INFO Received push request method=POST path=/api/pushes10232026/10/09 18:07:08 INFO Deleted pin name=app10242026/10/09 18:07:08 INFO Received cleanup request method=DELETE path=/api/pending_closures10252026/10/09 18:07:08 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket17/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10262026/10/09 18:07:08 INFO Aborted multipart uploads count=0 kept=11027=== CONT TestProxyWriteTimeout1028--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.96s)1029=== RUN TestProxyWriteTimeout/narinfo1030=== PAUSE TestProxyWriteTimeout/narinfo1031=== RUN TestProxyWriteTimeout/1_GiB_nar1032=== PAUSE TestProxyWriteTimeout/1_GiB_nar1033=== RUN TestProxyWriteTimeout/10_GiB_nar1034=== PAUSE TestProxyWriteTimeout/10_GiB_nar1035=== RUN TestProxyWriteTimeout/unknown_size1036=== PAUSE TestProxyWriteTimeout/unknown_size1037=== CONT TestService_healthCheckHandler10382026/10/09 18:07:08 INFO Received cleanup request method=DELETE path=/api/pending_closures10392026/10/09 18:07:08 INFO Aborted multipart uploads count=1 kept=010402026/10/09 18:07:08 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10412026/10/09 18:07:08 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1042--- PASS: TestPresentReportsOnlyClosureRoots (1.00s)1043=== CONT TestIsValidUploadKey1044=== RUN TestIsValidUploadKey/narinfo1045=== PAUSE TestIsValidUploadKey/narinfo1046=== RUN TestIsValidUploadKey/nar_zst1047=== PAUSE TestIsValidUploadKey/nar_zst1048=== RUN TestIsValidUploadKey/nar_xz1049=== PAUSE TestIsValidUploadKey/nar_xz1050=== RUN TestIsValidUploadKey/nar_plain1051=== PAUSE TestIsValidUploadKey/nar_plain1052=== RUN TestIsValidUploadKey/listing1053=== PAUSE TestIsValidUploadKey/listing1054=== RUN TestIsValidUploadKey/build_log1055=== PAUSE TestIsValidUploadKey/build_log1056=== RUN TestIsValidUploadKey/build_log_home-manager_file1057=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1058=== RUN TestIsValidUploadKey/build_log_plus_in_name1059=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1060=== RUN TestIsValidUploadKey/build_log_question_mark1061=== PAUSE TestIsValidUploadKey/build_log_question_mark1062=== RUN TestIsValidUploadKey/build_log_equals1063=== PAUSE TestIsValidUploadKey/build_log_equals1064=== RUN TestIsValidUploadKey/realisation1065=== PAUSE TestIsValidUploadKey/realisation1066=== RUN TestIsValidUploadKey/realisation_plus_in_output1067=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1068=== RUN TestIsValidUploadKey/nix-cache-info1069=== PAUSE TestIsValidUploadKey/nix-cache-info1070=== RUN TestIsValidUploadKey/index.html1071=== PAUSE TestIsValidUploadKey/index.html1072=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1073=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1074=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1075=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1076=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1077=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1078=== RUN TestIsValidUploadKey/traversal1079=== PAUSE TestIsValidUploadKey/traversal1080=== RUN TestIsValidUploadKey/traversal_nar1081=== PAUSE TestIsValidUploadKey/traversal_nar1082=== RUN TestIsValidUploadKey/absolute1083--- PASS: TestMultipartCleanup (0.99s)1084=== PAUSE TestIsValidUploadKey/absolute1085=== CONT TestGracefulShutdownDrainsInflight1086=== RUN TestIsValidUploadKey/empty_key1087=== PAUSE TestIsValidUploadKey/empty_key1088=== RUN TestIsValidUploadKey/unknown_type10892026/10/09 18:07:08 INFO Starting HTTP server address=127.0.0.1:352311090=== PAUSE TestIsValidUploadKey/unknown_type1091=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle10922026/10/09 18:07:08 INFO Shutdown signal received, draining in-flight requests timeout=10s1093=== CONT TestGCTaskStore_Fail1094--- PASS: TestService_NativeMTLS (1.00s)1095=== CONT TestParseSize1096--- PASS: TestGCTaskStore_Fail (0.00s)1097=== CONT TestGCTaskStore_PhaseUpdates1098--- PASS: TestParseSize (0.00s)1099=== CONT TestService_Rustfstest1100--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)11012026/10/09 18:07:08 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11022026/10/09 18:07:08 WARN Refused reserved pin name=worker-x86_64-linux11032026/10/09 18:07:08 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11042026/10/09 18:07:08 INFO Received create pin request method=POST path=/api/pins/my-app11052026/10/09 18:07:08 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1106=== RUN TestPush_RejectsBadRequests/no_roots1107=== PAUSE TestPush_RejectsBadRequests/no_roots1108=== RUN TestPush_RejectsBadRequests/no_objects1109=== PAUSE TestPush_RejectsBadRequests/no_objects1110=== RUN TestPush_RejectsBadRequests/bad_root1111=== PAUSE TestPush_RejectsBadRequests/bad_root1112=== RUN TestPush_RejectsBadRequests/root_not_in_objects1113=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1114=== CONT TestGenerateLandingPage11152026/10/09 18:07:08 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo1116--- PASS: TestCreatePin_ReservedPins (1.06s)1117=== CONT TestSkippedUploadsHandler11182026/10/09 18:07:08 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo11192026/10/09 18:07:08 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001120=== CONT TestCompletedNarNotReofferedAcrossClosures1121--- PASS: TestGenerateLandingPage (0.02s)11222026/10/09 18:07:08 INFO Received uploads request method=POST path=/api/pending_closures1123--- PASS: TestGracefulShutdownDrainsInflight (0.08s)1124=== CONT TestGCTaskStore_CompletedAllowsNewTask1125--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1126=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1127=== CONT TestGCTaskStore_GetReturnsLatest1128--- PASS: TestConcurrentPinUpdatesAgree (1.10s)1129=== CONT TestPush_SignsNarinfosOfItsPendingObjects1130--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)11312026/10/09 18:07:08 INFO Received uploads request method=POST path=/api/pending_closures11322026/10/09 18:07:08 WARN Rate limiter enabled after throttle name=s3-test rate=511332026/10/09 18:07:08 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."1134--- PASS: TestSkippedUploadsHandler (0.10s)1135=== CONT TestGCTaskStore_GetEmpty1136--- PASS: TestGCTaskStore_GetEmpty (0.00s)1137=== CONT TestReadProxyRangeRequest1138--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (1.18s)1139=== CONT TestGCTaskStore_DeduplicateSameParams1140=== CONT TestPresignedUploadRegisteredBeforeCommit1141--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)11422026/10/09 18:07:08 INFO Received uploads request method=POST path=/api/pending_closures1143=== NAME TestOrphanedObjectsGC1144 orphaned_objects_gc_test.go:287: GC Test Summary:1145 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1146 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1147 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1148 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1149 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1150--- PASS: TestOrphanedObjectsGC (1.22s)1151=== CONT TestGCTaskStore_StartNew1152--- PASS: TestGCTaskStore_StartNew (0.00s)1153=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit11542026/10/09 18:07:08 WARN Rate limiter backed off name=s3-test rate=511552026/10/09 18:07:08 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."1156=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1157--- PASS: TestPendingClosureFailureAbortsItsUploads (1.23s)1158--- PASS: TestReadProxy404 (1.26s)11592026/10/09 18:07:08 INFO Received uploads request method=POST path=/api/pending_closures1160=== CONT TestPush_CompleteWaitsForCleanupOfThePush11612026/10/09 18:07:08 INFO Received uploads request method=POST path=/api/pending_closures11622026/10/09 18:07:08 INFO Received uploads request method=POST path=/api/pending_closures1163--- PASS: TestMetricsInventory (0.80s)1164=== CONT TestDeleteClosuresRacingPins1165=== NAME TestNARDeduplicationMetadataUploadBug1166 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug739174705/001/store/8mmz0yfky3rlab9jjmidq4arbn0qnl41-file1.txt11672026/10/09 18:07:08 INFO Received cleanup request method=DELETE path=/api/pending_closures11682026/10/09 18:07:08 INFO Aborted multipart uploads count=0 kept=011692026/10/09 18:07:08 INFO Received uploads request method=POST path=/api/pending_closures11702026/10/09 18:07:08 WARN readiness check failed error="closed pool"11712026/10/09 18:07:08 INFO Received cleanup request method=DELETE path=/api/pending_closures11722026/10/09 18:07:08 INFO Aborted multipart uploads count=1 kept=01173=== CONT TestPush_RepeatedRootCommitsOnce1174--- PASS: TestService_readinessHandler (0.45s)11752026/10/09 18:07:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11762026-10-09 18:07:08.515 UTC [752] ERROR: Closure does not exist: id=111772026-10-09 18:07:08.515 UTC [752] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE11782026-10-09 18:07:08.515 UTC [752] STATEMENT: -- name: CommitPendingClosure :one1179 SELECT commit_pending_closure($1::bigint)::bigint1180 11812026/10/09 18:07:08 INFO Received push request method=POST path=/api/pushes1182--- PASS: TestService_cleanupPendingClosuresHandler (0.59s)1183=== CONT TestClientFallsBackToClosures1184--- PASS: TestService_healthCheckHandler (0.41s)1185=== CONT TestPush_CompleteCommitsEveryRoot11862026/10/09 18:07:08 INFO Received uploads request method=POST path=/api/pending_closures11872026/10/09 18:07:08 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11882026/10/09 18:07:08 INFO Uploading 8mmz0yfky3rlab9jjmidq4arbn0qnl41-file1.txt (160B)11892026/10/09 18:07:08 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11902026/10/09 18:07:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11912026/10/09 18:07:08 WARN Failed to register uploaded object key=8mmz0yfky3rlab9jjmidq4arbn0qnl41.ls error="server returned 404: 404 page not found\n"11922026/10/09 18:07:08 INFO Signed narinfos id=1 count=111932026/10/09 18:07:08 INFO Uploading 1 narinfos1194--- PASS: TestService_Rustfstest (0.46s)11952026/10/09 18:07:08 INFO Received uploads request method=POST path=/api/pending_closures1196=== CONT TestPush_RootsAreLockedInByteOrder11972026/10/09 18:07:08 INFO Received complete push request method=POST path=/api/pushes/1/complete11982026/10/09 18:07:08 WARN Failed to register uploaded object key=8mmz0yfky3rlab9jjmidq4arbn0qnl41.narinfo error="server returned 404: 404 page not found\n"11992026/10/09 18:07:08 INFO Completed push id=1 objects=3 duration=6.845217ms12002026/10/09 18:07:08 INFO Upload complete. (167ms)1201=== NAME TestNARDeduplicationMetadataUploadBug1202 metadata_upload_test.go:54: Retrieved narinfo from S3:1203 StorePath: /build/TestNARDeduplicationMetadataUploadBug739174705/001/store/8mmz0yfky3rlab9jjmidq4arbn0qnl41-file1.txt1204 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1205 Compression: zstd1206 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1207 NarSize: 1601208 References: 1209 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1210 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1211 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1212 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12132026/10/09 18:07:08 INFO Received uploads request method=POST path=/api/pending_closures12142026/10/09 18:07:08 INFO Received push request method=POST path=/api/pushes12152026/10/09 18:07:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1216 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug739174705/001/store/iwikkpmw1p23bpdqzi9m3y2kbbd7bkdj-file2.txt12172026/10/09 18:07:08 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLmJhYzZiNGY2LTU1MjItNDNhYi04NWMzLWNhNjYyNmU3NTBmZngxNzkxNTY5MjI4NjUyMzM3Nzcy12182026/10/09 18:07:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12192026/10/09 18:07:08 INFO Signed narinfos id=1 count=112202026/10/09 18:07:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12212026/10/09 18:07:08 INFO Received uploads request method=POST path=/api/pending_closures12222026/10/09 18:07:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12232026/10/09 18:07:08 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"12242026/10/09 18:07:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12252026/10/09 18:07:08 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"12262026/10/09 18:07:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12272026/10/09 18:07:08 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=112282026/10/09 18:07:08 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12292026/10/09 18:07:08 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo12302026/10/09 18:07:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1231--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.48s)1232=== CONT TestPush_OverlappingRootsStoreOneRowPerKey12332026/10/09 18:07:08 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12342026/10/09 18:07:08 INFO Received uploads request method=POST path=/api/pending_closures12352026/10/09 18:07:08 INFO Received push request method=POST path=/api/pushes1236--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.42s)1237=== CONT TestResolveDBConnectionString1238=== RUN TestResolveDBConnectionString/flag_wins1239=== PAUSE TestResolveDBConnectionString/flag_wins1240=== RUN TestResolveDBConnectionString/file_when_flag_empty1241=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1242=== RUN TestResolveDBConnectionString/missing_file_is_an_error1243=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1244=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1245=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1246=== RUN TestResolveDBConnectionString/nothing_configured1247=== PAUSE TestResolveDBConnectionString/nothing_configured1248=== CONT TestPinProtectsFromGC12492026/10/09 18:07:08 INFO Received push request method=POST path=/api/pushes12502026/10/09 18:07:08 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1251--- PASS: TestReadProxyContentNegotiation (1.63s)1252=== CONT TestReadProxyRootRedirectsToIndexHTML12532026/10/09 18:07:08 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12542026/10/09 18:07:08 INFO Signed narinfos id=2 count=112552026/10/09 18:07:08 WARN Failed to register uploaded object key=iwikkpmw1p23bpdqzi9m3y2kbbd7bkdj.ls error="server returned 404: 404 page not found\n"12562026/10/09 18:07:08 INFO Uploading 1 narinfos12572026/10/09 18:07:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12582026/10/09 18:07:08 INFO Received complete push request method=POST path=/api/pushes/2/complete12592026/10/09 18:07:08 WARN Failed to register uploaded object key=iwikkpmw1p23bpdqzi9m3y2kbbd7bkdj.narinfo error="server returned 404: 404 page not found\n"12602026/10/09 18:07:08 INFO Completed push id=2 objects=3 duration=3.589833ms12612026/10/09 18:07:08 INFO Upload complete. (98ms)1262=== NAME TestNARDeduplicationMetadataUploadBug1263 metadata_upload_test.go:76: Retrieved narinfo from S3:1264 StorePath: /build/TestNARDeduplicationMetadataUploadBug739174705/001/store/iwikkpmw1p23bpdqzi9m3y2kbbd7bkdj-file2.txt1265 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1266 Compression: zstd1267 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1268 NarSize: 1601269 References: 1270 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf12712026/10/09 18:07:08 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLmJhYzZiNGY2LTU1MjItNDNhYi04NWMzLWNhNjYyNmU3NTBmZngxNzkxNTY5MjI4NjUyMzM3Nzcy error="Delete \"http://localhost:45145/bucket37/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLmJhYzZiNGY2LTU1MjItNDNhYi04NWMzLWNhNjYyNmU3NTBmZngxNzkxNTY5MjI4NjUyMzM3Nzcy\": injected: abort refused"12722026/10/09 18:07:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1273 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1274 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1275 {"version":1,"root":{"type":"regular","size":44}}12762026/10/09 18:07:08 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLmJhYzZiNGY2LTU1MjItNDNhYi04NWMzLWNhNjYyNmU3NTBmZngxNzkxNTY5MjI4NjUyMzM3Nzcy12772026/10/09 18:07:08 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLjA1NTFiYTg2LTQ2MTAtNGNkYi1hODU3LTZlZGQxYTBmMzU3NHgxNzkxNTY5MjI4MTEyNTYzOTY2 parts=101278--- PASS: TestReadProxyRangeRequest (0.53s)1279=== CONT TestClientSharedPathCommittedMidPush12802026/10/09 18:07:08 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLmJhYzZiNGY2LTU1MjItNDNhYi04NWMzLWNhNjYyNmU3NTBmZngxNzkxNTY5MjI4NjUyMzM3Nzcy parts=11281=== CONT TestClientPushesUseOnePush1282--- PASS: TestNARDeduplicationMetadataUploadBug (1.16s)12832026/10/09 18:07:08 INFO Received push request method=POST path=/api/pushes1284--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.64s)1285=== CONT TestGCTaskStore_ConflictDifferentParams1286=== CONT TestReadRedirectKeepsNarinfoProxied1287--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)12882026/10/09 18:07:08 INFO Received push request method=POST path=/api/pushes12892026/10/09 18:07:08 INFO Received push request method=POST path=/api/pushes12902026/10/09 18:07:08 INFO Received create pin request method=POST path=/api/pins/deploy12912026/10/09 18:07:08 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo12922026/10/09 18:07:09 INFO Received push request method=POST path=/api/pushes1293--- PASS: TestCreatePinRejectsBadInput (1.85s)1294=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection12952026/10/09 18:07:09 INFO Received push request method=POST path=/api/pushes12962026/10/09 18:07:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1297--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.31s)1298=== CONT TestClientIntegration1299=== CONT TestPushWaitsForSweepHoldingRow1300--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.37s)13012026/10/09 18:07:09 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLmU3ZjU1YjI0LWNkOWMtNGQxMy05OWFiLTU5MzRjMWFjYWNhOXgxNzkxNTY5MjI4MzcyMDgxNDU5 parts=1013022026/10/09 18:07:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13032026/10/09 18:07:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13042026/10/09 18:07:09 INFO Completed upload id=1 objects=2 duration=5.45722ms13052026/10/09 18:07:09 INFO Received uploads request method=POST path=/api/pending_closures13062026/10/09 18:07:09 INFO Received uploads request method=POST path=/api/pending_closures13072026/10/09 18:07:09 INFO Received uploads request method=POST path=/api/pending_closures13082026/10/09 18:07:09 INFO Received uploads request method=POST path=/api/pending_closures13092026/10/09 18:07:09 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13102026/10/09 18:07:09 INFO Uploading jnfvv8sq85dk0vrscydzdiq7sc6pdcaq-shared-dep (136B)13112026/10/09 18:07:09 INFO Uploading 9gkb2i0hsb51j94iqz0nsscydr5q37ar-a (216B)13122026/10/09 18:07:09 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13132026/10/09 18:07:09 WARN Found objects in DB but missing from S3, will re-upload count=113142026/10/09 18:07:09 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLjZkMzIxZmU2LTM0NmYtNGEyNy1hZTJhLTRiNTdlMTc4YjU3NHgxNzkxNTY5MjI4NDM4OTYxMjUx parts=1013152026/10/09 18:07:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13162026/10/09 18:07:09 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete13172026/10/09 18:07:09 INFO Completed upload id=3 objects=2 duration=3.074054ms13182026/10/09 18:07:09 INFO Completed upload id=1 objects=2 duration=5.633709ms13192026/10/09 18:07:09 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013202026/10/09 18:07:09 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13212026/10/09 18:07:09 INFO Received uploads request method=POST path=/api/pending_closures13222026/10/09 18:07:09 WARN Failed to register uploaded object key=6848skknshbkk0acxiw5ij3p4wcpkajz.ls error="server returned 404: 404 page not found\n"13232026/10/09 18:07:09 WARN Failed to register uploaded object key=nar/1qlnxdgd7dq3y5p4r2dl8bw4p6ignj9v4d9b663ji4wjl0yif8ga.nar.zst error="server returned 404: 404 page not found\n"13242026/10/09 18:07:09 INFO Starting cleanup of old closures method=DELETE path=/api/closures13252026/10/09 18:07:09 WARN Failed to register uploaded object key=jnfvv8sq85dk0vrscydzdiq7sc6pdcaq.ls error="server returned 404: 404 page not found\n"13262026/10/09 18:07:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13272026/10/09 18:07:09 WARN Failed to register uploaded object key=9gkb2i0hsb51j94iqz0nsscydr5q37ar.ls error="server returned 404: 404 page not found\n"13282026/10/09 18:07:09 INFO Aborted multipart uploads count=0 kept=013292026/10/09 18:07:09 INFO Signed narinfos id=1 count=213302026/10/09 18:07:09 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13312026/10/09 18:07:09 INFO Signed narinfos id=2 count=213322026/10/09 18:07:09 INFO Uploading 4 narinfos1333--- PASS: TestService_verifyS3Integrity (1.52s)1334=== CONT TestGCSweepSkipsPendingObjects1335=== NAME TestPinProtectsFromGC1336 client_integration_test.go:867: Pinned store path: /build/TestPinProtectsFromGC2473063669/001/store/kmmaaahwfn9s1cbvqzbfd4ayhmkl0kiz-pinned-file.txt1337 client_integration_test.go:868: Unpinned store path: /build/TestPinProtectsFromGC2473063669/001/store/gql5laqks33asamqazik0kdlhv8p4i5a-unpinned-file.txt13382026/10/09 18:07:09 WARN Failed to register uploaded object key=6848skknshbkk0acxiw5ij3p4wcpkajz.narinfo error="server returned 404: 404 page not found\n"13392026/10/09 18:07:09 WARN Failed to register uploaded object key=jnfvv8sq85dk0vrscydzdiq7sc6pdcaq.narinfo error="server returned 404: 404 page not found\n"13402026/10/09 18:07:09 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=01341=== CONT TestRegisterCompletedObjectNeedsPendingRow1342--- PASS: TestObjectStatsLargeCommit (2.03s)13432026/10/09 18:07:09 WARN Failed to register uploaded object key=jnfvv8sq85dk0vrscydzdiq7sc6pdcaq.narinfo error="server returned 404: 404 page not found\n"13442026/10/09 18:07:09 INFO Vacuumed table table=pending_closures13452026/10/09 18:07:09 INFO Vacuumed table table=pending_objects13462026/10/09 18:07:09 INFO Vacuumed table table=multipart_uploads13472026/10/09 18:07:09 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13482026/10/09 18:07:09 WARN Failed to register uploaded object key=9gkb2i0hsb51j94iqz0nsscydr5q37ar.narinfo error="server returned 404: 404 page not found\n"13492026/10/09 18:07:09 INFO Vacuumed table table=closures13502026/10/09 18:07:09 INFO Vacuumed table table=objects13512026/10/09 18:07:09 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013522026/10/09 18:07:09 INFO Completed upload id=2 objects=6 duration=22.500887ms13532026/10/09 18:07:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1354=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1355=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1356=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1357=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1358=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1359=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1360=== CONT TestService_AuthMiddleware_OIDC13612026/10/09 18:07:09 INFO Completed upload id=1 objects=6 duration=2.951604ms13622026/10/09 18:07:09 INFO Upload complete. (146ms)1363=== NAME TestClientFallsBackToClosures1364 client_pushes_test.go:112: Retrieved narinfo from S3:1365 StorePath: /build/TestClientFallsBackToClosures2766494038/001/store/jnfvv8sq85dk0vrscydzdiq7sc6pdcaq-shared-dep1366 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1367 Compression: zstd1368 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821369 NarSize: 1361370 References: 1371 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13722026/10/09 18:07:09 INFO Received uploads request method=POST path=/api/pending_closures1373--- PASS: TestService_createPendingClosureHandler (1.42s)1374=== CONT TestPushDedupSurvivesConcurrentGC1375=== NAME TestClientFallsBackToClosures1376 client_pushes_test.go:112: Retrieved narinfo from S3:1377 StorePath: /build/TestClientFallsBackToClosures2766494038/001/store/9gkb2i0hsb51j94iqz0nsscydr5q37ar-a1378 URL: nar/1qlnxdgd7dq3y5p4r2dl8bw4p6ignj9v4d9b663ji4wjl0yif8ga.nar.zst1379 Compression: zstd1380 NarHash: sha256:1qlnxdgd7dq3y5p4r2dl8bw4p6ignj9v4d9b663ji4wjl0yif8ga1381 NarSize: 2161382 References: /build/TestClientFallsBackToClosures2766494038/001/store/jnfvv8sq85dk0vrscydzdiq7sc6pdcaq-shared-dep1383 CA: text:sha256:0kn84phhkig4wf1xmqv0k24kzaz7618c10ns8mp1jmaislzwxnwi1384 client_pushes_test.go:112: Retrieved narinfo from S3:1385 StorePath: /build/TestClientFallsBackToClosures2766494038/001/store/6848skknshbkk0acxiw5ij3p4wcpkajz-b1386 URL: nar/1qlnxdgd7dq3y5p4r2dl8bw4p6ignj9v4d9b663ji4wjl0yif8ga.nar.zst1387 Compression: zstd1388 NarHash: sha256:1qlnxdgd7dq3y5p4r2dl8bw4p6ignj9v4d9b663ji4wjl0yif8ga1389 NarSize: 2161390 References: /build/TestClientFallsBackToClosures2766494038/001/store/jnfvv8sq85dk0vrscydzdiq7sc6pdcaq-shared-dep1391 CA: text:sha256:0kn84phhkig4wf1xmqv0k24kzaz7618c10ns8mp1jmaislzwxnwi13922026/10/09 18:07:09 INFO Received push request method=POST path=/api/pushes13932026/10/09 18:07:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13942026/10/09 18:07:09 INFO Uploading kmmaaahwfn9s1cbvqzbfd4ayhmkl0kiz-pinned-file.txt (128B)1395=== CONT TestSweepSkipsRowsLockedByPush1396--- PASS: TestClientFallsBackToClosures (0.76s)13972026/10/09 18:07:09 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13982026/10/09 18:07:09 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13992026/10/09 18:07:09 WARN Failed to register uploaded object key=kmmaaahwfn9s1cbvqzbfd4ayhmkl0kiz.ls error="server returned 404: 404 page not found\n"14002026/10/09 18:07:09 INFO Signed narinfos id=1 count=114012026/10/09 18:07:09 INFO Received push request method=POST path=/api/pushes14022026/10/09 18:07:09 INFO Uploading 1 narinfos14032026/10/09 18:07:09 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14042026/10/09 18:07:09 INFO Uploading xdf50y5dfghshf29rlq7s5m9s06jnfpf-top (224B)14052026/10/09 18:07:09 INFO Uploading 405sahf379h6257acxbz5xaq95aix69i-shared-dep (136B)14062026/10/09 18:07:09 INFO Received complete push request method=POST path=/api/pushes/1/complete14072026/10/09 18:07:09 WARN Failed to register uploaded object key=kmmaaahwfn9s1cbvqzbfd4ayhmkl0kiz.narinfo error="server returned 404: 404 page not found\n"14082026/10/09 18:07:09 WARN Failed to register uploaded object key=nar/0ci3ip423sk6pd779vi9jldsqw3vc55pyjmz462564mms0cp54fz.nar.zst error="server returned 404: 404 page not found\n"14092026/10/09 18:07:09 INFO Completed push id=1 objects=3 duration=19.629933ms14102026/10/09 18:07:09 INFO Upload complete. (116ms)14112026/10/09 18:07:09 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14122026/10/09 18:07:09 INFO Received uploads request method=POST path=/api/pending_closures14132026/10/09 18:07:09 WARN Failed to register uploaded object key=405sahf379h6257acxbz5xaq95aix69i.ls error="server returned 404: 404 page not found\n"14142026/10/09 18:07:09 WARN Failed to register uploaded object key=xdf50y5dfghshf29rlq7s5m9s06jnfpf.ls error="server returned 404: 404 page not found\n"14152026/10/09 18:07:09 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14162026/10/09 18:07:09 INFO Signed narinfos id=1 count=214172026/10/09 18:07:09 INFO Uploading 2 narinfos1418=== NAME TestClientIntegration1419 client_integration_test.go:334: Created store path: /build/TestClientIntegration193468516/002/store/lngwf3pbjvl8hmclhls4s3sl7f85vdi5-test-file.txt14202026/10/09 18:07:09 WARN Failed to register uploaded object key=xdf50y5dfghshf29rlq7s5m9s06jnfpf.narinfo error="server returned 404: 404 page not found\n"14212026/10/09 18:07:09 INFO Received push request method=POST path=/api/pushes14222026/10/09 18:07:09 INFO Received complete push request method=POST path=/api/pushes/1/complete14232026/10/09 18:07:09 WARN Failed to register uploaded object key=405sahf379h6257acxbz5xaq95aix69i.narinfo error="server returned 404: 404 page not found\n"14242026/10/09 18:07:09 INFO Received uploads request method=POST path=/api/pending_closures14252026/10/09 18:07:09 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>14262026/10/09 18:07:09 INFO Completed push id=1 objects=6 duration=9.821031ms14272026/10/09 18:07:09 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14282026/10/09 18:07:09 INFO Upload complete. (153ms)14292026/10/09 18:07:09 INFO Uploading pjlg82xhn3afz81c17mi954x1f9skmna-b (216B)14302026/10/09 18:07:09 INFO Uploading bj4rv31ksm19wn4lmipvihpldz7avq32-shared-dep (136B)14312026/10/09 18:07:09 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44961/oidc1432=== NAME TestClientSharedPathCommittedMidPush1433 client_integration_test.go:816: Retrieved narinfo from S3:1434 StorePath: /build/TestClientSharedPathCommittedMidPush1715321933/001/store/405sahf379h6257acxbz5xaq95aix69i-shared-dep1435 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1436 Compression: zstd1437 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821438 NarSize: 1361439 References: 1440 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n14412026/10/09 18:07:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1442 client_integration_test.go:816: Retrieved narinfo from S3:1443 StorePath: /build/TestClientSharedPathCommittedMidPush1715321933/001/store/xdf50y5dfghshf29rlq7s5m9s06jnfpf-top1444 URL: nar/0ci3ip423sk6pd779vi9jldsqw3vc55pyjmz462564mms0cp54fz.nar.zst1445 Compression: zstd1446 NarHash: sha256:0ci3ip423sk6pd779vi9jldsqw3vc55pyjmz462564mms0cp54fz1447 NarSize: 22414482026/10/09 18:07:09 INFO Received push request method=POST path=/api/pushes1449 References: /build/TestClientSharedPathCommittedMidPush1715321933/001/store/405sahf379h6257acxbz5xaq95aix69i-shared-dep1450 CA: text:sha256:1hygps19k1xd807v6hcfkn10ardm429isqz08n5dwvcba3j48gyg14512026/10/09 18:07:09 INFO Received push request method=POST path=/api/pushes14522026/10/09 18:07:09 INFO Aborted multipart uploads count=0 kept=014532026/10/09 18:07:09 WARN Failed to register uploaded object key=nar/06c9hipnjrgxswqhzhd07xmg4vqlbf59v0aswyq2rnzk6lhlhmzn.nar.zst error="server returned 404: 404 page not found\n"14542026/10/09 18:07:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14552026/10/09 18:07:09 INFO Uploading gql5laqks33asamqazik0kdlhv8p4i5a-unpinned-file.txt (128B)14562026/10/09 18:07:09 WARN Force mode enabled - objects will be deleted immediately without grace period14572026/10/09 18:07:09 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14582026/10/09 18:07:09 INFO Uploading lngwf3pbjvl8hmclhls4s3sl7f85vdi5-test-file.txt (152B)14592026/10/09 18:07:09 WARN Failed to register uploaded object key=l7y7l5d2qk7wgs96vfpj2ryy32afxzhs.ls error="server returned 404: 404 page not found\n"1460--- PASS: TestReadProxyNarinfo (2.29s)14612026/10/09 18:07:09 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=01462=== CONT TestForceGCDuringPushOffersSweptObject1463=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1464=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1465=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1466=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1467=== CONT TestDeduplicatedObjectsRecordedAsPending14682026/10/09 18:07:09 INFO Vacuumed table table=pending_closures14692026/10/09 18:07:09 INFO Vacuumed table table=pending_objects14702026/10/09 18:07:09 INFO Vacuumed table table=multipart_uploads14712026/10/09 18:07:09 INFO Vacuumed table table=closures14722026/10/09 18:07:09 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14732026/10/09 18:07:09 WARN Failed to register uploaded object key=pjlg82xhn3afz81c17mi954x1f9skmna.ls error="server returned 404: 404 page not found\n"14742026/10/09 18:07:09 INFO Vacuumed table table=objects14752026/10/09 18:07:09 WARN Failed to register uploaded object key=gql5laqks33asamqazik0kdlhv8p4i5a.ls error="server returned 404: 404 page not found\n"14762026/10/09 18:07:09 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14772026/10/09 18:07:09 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"1478=== CONT TestPendingClosureWriteTimeout1479--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.46s)1480=== RUN TestPendingClosureWriteTimeout/empty1481=== PAUSE TestPendingClosureWriteTimeout/empty14822026/10/09 18:07:09 INFO Signed narinfos id=2 count=11483=== RUN TestPendingClosureWriteTimeout/400_objects1484=== PAUSE TestPendingClosureWriteTimeout/400_objects1485=== RUN TestPendingClosureWriteTimeout/670k_objects1486=== PAUSE TestPendingClosureWriteTimeout/670k_objects1487=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1488=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1489=== CONT TestGCMetrics14902026/10/09 18:07:09 INFO Uploading 1 narinfos1491--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.28s)14922026/10/09 18:07:09 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"1493=== CONT TestReadProxyNarStreaming1494=== CONT TestConnectWaitsForAPeerMigration14952026/10/09 18:07:09 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1496--- PASS: TestClientSharedPathCommittedMidPush (0.62s)14972026/10/09 18:07:09 WARN Failed to register uploaded object key=bj4rv31ksm19wn4lmipvihpldz7avq32.ls error="server returned 404: 404 page not found\n"14982026/10/09 18:07:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14992026/10/09 18:07:09 INFO Received complete push request method=POST path=/api/pushes/2/complete15002026/10/09 18:07:09 INFO Signed narinfos id=1 count=315012026/10/09 18:07:09 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLjZjOWZiNWE1LTk5YTMtNDljNC05OWM3LTMwYTNmMjQxMjE5OHgxNzkxNTY5MjI4Njc2NzA5MzY2 parts=1215022026/10/09 18:07:09 WARN Failed to register uploaded object key=gql5laqks33asamqazik0kdlhv8p4i5a.narinfo error="server returned 404: 404 page not found\n"15032026/10/09 18:07:09 INFO Uploading 3 narinfos15042026/10/09 18:07:09 INFO Received uploads request method=POST path=/api/pending_closures15052026/10/09 18:07:09 INFO Completed push id=2 objects=3 duration=3.169464ms15062026/10/09 18:07:09 INFO Upload complete. (93ms)15072026/10/09 18:07:09 WARN Failed to register uploaded object key=bj4rv31ksm19wn4lmipvihpldz7avq32.narinfo error="server returned 404: 404 page not found\n"15082026/10/09 18:07:09 WARN Failed to register uploaded object key=lngwf3pbjvl8hmclhls4s3sl7f85vdi5.ls error="server returned 404: 404 page not found\n"15092026/10/09 18:07:09 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15102026/10/09 18:07:09 INFO Signed narinfos id=1 count=115112026/10/09 18:07:09 INFO Uploading 1 narinfos1512--- PASS: TestGCSweepSkipsPendingObjects (0.31s)1513=== CONT TestGCAdvisoryLockBlocksConcurrentRun15142026/10/09 18:07:09 WARN Failed to register uploaded object key=l7y7l5d2qk7wgs96vfpj2ryy32afxzhs.narinfo error="server returned 404: 404 page not found\n"15152026/10/09 18:07:09 INFO Received complete push request method=POST path=/api/pushes/1/complete15162026/10/09 18:07:09 WARN Failed to register uploaded object key=pjlg82xhn3afz81c17mi954x1f9skmna.narinfo error="server returned 404: 404 page not found\n"15172026/10/09 18:07:09 INFO Received complete push request method=POST path=/api/pushes/1/complete15182026/10/09 18:07:09 WARN Failed to register uploaded object key=lngwf3pbjvl8hmclhls4s3sl7f85vdi5.narinfo error="server returned 404: 404 page not found\n"15192026/10/09 18:07:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15202026/10/09 18:07:09 INFO Completed push id=1 objects=8 duration=11.764777ms15212026/10/09 18:07:09 INFO Upload complete. (201ms)1522=== CONT TestCommitRacingPendingCleanupKeepsObjects15232026/10/09 18:07:09 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLmFkZTI1NjFjLWM4NTYtNGY4NC05ZWEzLWNhZTg4NmJlNDI3OXgxNzkxNTY5MjI4ODE1NTU3MTEw parts=101524--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.29s)1525=== NAME TestClientPushesUseOnePush1526 client_pushes_test.go:97: Retrieved narinfo from S3:1527 StorePath: /build/TestClientPushesUseOnePush3323630121/001/store/bj4rv31ksm19wn4lmipvihpldz7avq32-shared-dep1528 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1529 Compression: zstd1530 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821531 NarSize: 1361532 References: 1533 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1534=== CONT TestGCEndsOnShutdown1535=== RUN TestGCEndsOnShutdown/before_the_run1536--- PASS: TestReadRedirectKeepsNarinfoProxied (0.64s)1537=== PAUSE TestGCEndsOnShutdown/before_the_run15382026/10/09 18:07:09 INFO Completed push id=1 objects=3 duration=10.64957ms1539=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1540=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1541=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1542=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1543=== CONT TestConnectSerialisesConcurrentMigrations15442026/10/09 18:07:09 INFO Upload complete. (129ms)15452026/10/09 18:07:09 INFO Starting cleanup of old closures method=DELETE path=/api/closures15462026/10/09 18:07:09 INFO Garbage collection started1547=== NAME TestClientPushesUseOnePush1548 client_pushes_test.go:97: Retrieved narinfo from S3:1549 StorePath: /build/TestClientPushesUseOnePush3323630121/001/store/l7y7l5d2qk7wgs96vfpj2ryy32afxzhs-a1550 URL: nar/06c9hipnjrgxswqhzhd07xmg4vqlbf59v0aswyq2rnzk6lhlhmzn.nar.zst1551 Compression: zstd1552 NarHash: sha256:06c9hipnjrgxswqhzhd07xmg4vqlbf59v0aswyq2rnzk6lhlhmzn1553 NarSize: 2161554 References: /build/TestClientPushesUseOnePush3323630121/001/store/bj4rv31ksm19wn4lmipvihpldz7avq32-shared-dep1555 CA: text:sha256:1scm7mk8n7l5ivl32dqgs7y7f08ck8bapdlpmr9fbchp2sf3f8wy1556 client_pushes_test.go:97: Retrieved narinfo from S3:1557 StorePath: /build/TestClientPushesUseOnePush3323630121/001/store/pjlg82xhn3afz81c17mi954x1f9skmna-b1558 URL: nar/06c9hipnjrgxswqhzhd07xmg4vqlbf59v0aswyq2rnzk6lhlhmzn.nar.zst1559 Compression: zstd1560 NarHash: sha256:06c9hipnjrgxswqhzhd07xmg4vqlbf59v0aswyq2rnzk6lhlhmzn1561 NarSize: 2161562 References: /build/TestClientPushesUseOnePush3323630121/001/store/bj4rv31ksm19wn4lmipvihpldz7avq32-shared-dep1563 CA: text:sha256:1scm7mk8n7l5ivl32dqgs7y7f08ck8bapdlpmr9fbchp2sf3f8wy15642026/10/09 18:07:09 INFO Received uploads request method=POST path=/api/pending_closures15652026/10/09 18:07:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15662026/10/09 18:07:09 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLjQ5MmExMDc2LTJiY2MtNDk2NC1iNDgzLWI0YjYxNDEzMmQzM3gxNzkxNTY5MjI4MTE1MTM3MDMx parts=1015672026/10/09 18:07:09 INFO Received complete push request method=POST path=/api/pushes/1/complete15682026/10/09 18:07:09 INFO Aborted multipart uploads count=0 kept=015692026/10/09 18:07:09 INFO Aborted multipart uploads count=0 kept=015702026/10/09 18:07:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15712026/10/09 18:07:09 WARN Force mode enabled - objects will be deleted immediately without grace period15722026/10/09 18:07:09 WARN Force mode enabled - objects will be deleted immediately without grace period15732026/10/09 18:07:09 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015742026/10/09 18:07:09 INFO Vacuumed table table=pending_closures15752026/10/09 18:07:09 INFO Vacuumed table table=pending_objects15762026/10/09 18:07:09 INFO Vacuumed table table=multipart_uploads15772026/10/09 18:07:09 INFO Vacuumed table table=closures1578--- PASS: TestClientPushesUseOnePush (0.70s)1579=== CONT TestRedundantMultipartUpload15802026/10/09 18:07:09 INFO Completed push id=1 objects=4 duration=27.203508ms15812026/10/09 18:07:09 INFO Vacuumed table table=objects15822026/10/09 18:07:09 INFO All 1 paths already cached1583=== NAME TestClientIntegration1584 client_integration_test.go:360: Retrieved narinfo from S3:1585 StorePath: /build/TestClientIntegration193468516/002/store/lngwf3pbjvl8hmclhls4s3sl7f85vdi5-test-file.txt1586 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1587 Compression: zstd1588 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11589 NarSize: 1521590 References: 1591 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk115922026/10/09 18:07:09 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15932026/10/09 18:07:09 INFO Completed upload id=2 objects=2 duration=3.396063ms15942026/10/09 18:07:09 INFO Aborted multipart uploads count=0 kept=01595 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)1596 client_integration_test.go:361: Decompressed .ls content (64 bytes):1597 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}15982026/10/09 18:07:09 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLjQ4NzA3NzgzLWY3YWItNGNjYy1iZDkyLTJkMTkxNjcwNjZmMngxNzkxNTY5MjI4OTAzMTgyMDEy parts=1015992026/10/09 18:07:09 WARN Force mode enabled - objects will be deleted immediately without grace period16002026/10/09 18:07:09 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=016012026/10/09 18:07:09 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLjE2MmM3NmRiLTlkYTctNDZhNy1iZjVhLTRlY2ZkZDQ2OTQ3MHgxNzkxNTY5MjI4OTI1NjgyNjc5 parts=1016022026/10/09 18:07:09 INFO Vacuumed table table=pending_closures16032026/10/09 18:07:09 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=016042026/10/09 18:07:09 INFO Vacuumed table table=pending_closures16052026/10/09 18:07:09 INFO Vacuumed table table=pending_objects16062026/10/09 18:07:09 INFO Vacuumed table table=pending_objects16072026/10/09 18:07:09 INFO Vacuumed table table=multipart_uploads16082026/10/09 18:07:09 INFO Vacuumed table table=multipart_uploads16092026/10/09 18:07:09 INFO Vacuumed table table=closures16102026/10/09 18:07:09 INFO Aborted multipart uploads count=0 kept=016112026/10/09 18:07:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16122026/10/09 18:07:09 INFO Vacuumed table table=closures16132026/10/09 18:07:09 INFO Vacuumed table table=objects16142026/10/09 18:07:09 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=016152026/10/09 18:07:09 INFO Vacuumed table table=objects16162026/10/09 18:07:09 INFO Vacuumed table table=pending_closures16172026/10/09 18:07:09 INFO Vacuumed table table=pending_objects16182026/10/09 18:07:09 INFO Vacuumed table table=multipart_uploads16192026/10/09 18:07:09 INFO Vacuumed table table=closures16202026/10/09 18:07:09 INFO Vacuumed table table=objects16212026/10/09 18:07:09 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLmNjNDY4MmNmLWVmOTMtNDg0MS1iYmRlLTg4ZjZiZjMzZmVmYngxNzkxNTY5MjI4OTkyOTA3NDUw parts=101622--- PASS: TestSweepSkipsRowsLockedByPush (0.36s)16232026/10/09 18:07:09 INFO Aborted multipart uploads count=0 kept=01624=== CONT TestReadRedirectNar16252026-10-09 18:07:09.660 UTC [1545] ERROR: duplicate key value violates unique constraint "pg_class_relname_nsp_index"16262026-10-09 18:07:09.660 UTC [1545] DETAIL: Key (relname, relnamespace)=(goose_db_version_id_seq, 2200) already exists.16272026-10-09 18:07:09.660 UTC [1545] STATEMENT: CREATE TABLE goose_db_version (1628 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1629 version_id bigint NOT NULL,1630 is_applied boolean NOT NULL,1631 tstamp timestamp NOT NULL DEFAULT now()1632 )16332026/10/09 18:07:09 WARN Force mode enabled - objects will be deleted immediately without grace period16342026/10/09 18:07:09 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016352026/10/09 18:07:09 INFO Vacuumed table table=pending_closures16362026/10/09 18:07:09 INFO Vacuumed table table=pending_objects1637--- PASS: TestMetricsCommit (2.50s)16382026/10/09 18:07:09 INFO Vacuumed table table=multipart_uploads1639=== CONT TestReadProxyDisabled1640--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.27s)1641=== CONT TestReadProxyConditionalGet16422026/10/09 18:07:09 INFO Vacuumed table table=closures16432026/10/09 18:07:09 INFO Vacuumed table table=objects16442026/10/09 18:07:09 INFO Received push request method=POST path=/api/pushes16452026/10/09 18:07:09 INFO Object in database but missing from S3 key=lngwf3pbjvl8hmclhls4s3sl7f85vdi5.ls16462026/10/09 18:07:09 WARN Found objects in DB but missing from S3, will re-upload count=11647=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1648=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1649=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1650=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1651=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1652=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1653=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1654=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1655=== CONT TestClientMultipleUploads16562026/10/09 18:07:09 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16572026/10/09 18:07:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1658--- PASS: TestPushDedupSurvivesConcurrentGC (0.49s)1659=== CONT TestReadProxyOutlastsServerWriteTimeout16602026/10/09 18:07:09 INFO Received complete push request method=POST path=/api/pushes/2/complete16612026/10/09 18:07:09 WARN Failed to register uploaded object key=lngwf3pbjvl8hmclhls4s3sl7f85vdi5.ls error="server returned 404: 404 page not found\n"16622026/10/09 18:07:09 INFO Completed push id=2 objects=3 duration=3.971682ms16632026/10/09 18:07:09 INFO Upload complete. (111ms)1664=== NAME TestClientIntegration1665 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)1666 client_integration_test.go:389: Decompressed .ls content (49 bytes):1667 {"version":1,"root":{"type":"regular","size":39}}16682026/10/09 18:07:09 INFO Received uploads request method=POST path=/api/pending_closures16692026/10/09 18:07:09 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLjBmODJjODE1LWM2MTQtNDNjYy05ZTI5LWM0MTcyMzE2NWIxNXgxNzkxNTY5MjI5MDIzMTUyNDMz parts=101670--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.35s)1671=== CONT TestClientErrorHandling1672=== RUN TestClientErrorHandling/InvalidStorePath1673=== PAUSE TestClientErrorHandling/InvalidStorePath1674=== RUN TestClientErrorHandling/InvalidAuthToken1675=== PAUSE TestClientErrorHandling/InvalidAuthToken1676=== RUN TestClientErrorHandling/ServerNotAvailable1677=== PAUSE TestClientErrorHandling/ServerNotAvailable1678=== CONT TestCacheStatsHandler16792026/10/09 18:07:09 INFO Aborted multipart uploads count=0 kept=016802026/10/09 18:07:09 WARN Force mode enabled - objects will be deleted immediately without grace period16812026/10/09 18:07:09 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016822026/10/09 18:07:09 INFO Vacuumed table table=pending_closures16832026/10/09 18:07:09 INFO Vacuumed table table=pending_objects16842026/10/09 18:07:09 INFO Vacuumed table table=multipart_uploads16852026/10/09 18:07:09 INFO Vacuumed table table=closures16862026/10/09 18:07:09 INFO Vacuumed table table=objects16872026/10/09 18:07:09 INFO Received push request method=POST path=/api/pushes16882026/10/09 18:07:09 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)16892026/10/09 18:07:09 INFO Received complete push request method=POST path=/api/pushes/3/complete16902026/10/09 18:07:09 WARN Failed to register uploaded object key=lngwf3pbjvl8hmclhls4s3sl7f85vdi5.ls error="server returned 404: 404 page not found\n"1691=== CONT TestClientCADerivations1692--- PASS: TestPushWaitsForSweepHoldingRow (0.77s)16932026/10/09 18:07:09 INFO Completed push id=3 objects=3 duration=2.505115ms16942026/10/09 18:07:09 INFO Upload complete. (74ms)1695=== NAME TestClientIntegration1696 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)1697 client_integration_test.go:405: Decompressed .ls content (49 bytes):1698 {"version":1,"root":{"type":"regular","size":39}}16992026-10-09 18:07:09.896 UTC [1516] ERROR: Push does not exist: id=117002026-10-09 18:07:09.896 UTC [1516] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE17012026-10-09 18:07:09.896 UTC [1516] STATEMENT: SELECT commit_push($1)1702--- PASS: TestGCMetrics (0.41s)1703=== CONT TestReadProxyHead17042026/10/09 18:07:09 INFO Received uploads request method=POST path=/api/pending_closures17052026/10/09 18:07:09 INFO Aborted multipart uploads count=0 kept=017062026/10/09 18:07:09 WARN Force mode enabled - objects will be deleted immediately without grace period17072026/10/09 18:07:09 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=017082026/10/09 18:07:09 INFO Vacuumed table table=pending_closures1709--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.51s)17102026/10/09 18:07:09 INFO Received uploads request method=POST path=/api/pending_closures1711=== CONT TestCacheConfigHandler1712=== RUN TestCacheConfigHandler/full_config,_no_issuer1713=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1714=== RUN TestCacheConfigHandler/no_cache_url_configured1715=== PAUSE TestCacheConfigHandler/no_cache_url_configured1716=== RUN TestCacheConfigHandler/no_signing_keys1717=== PAUSE TestCacheConfigHandler/no_signing_keys1718=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1719=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1720=== CONT TestLeadEndsOnShutdown17212026/10/09 18:07:09 INFO Vacuumed table table=pending_objects17222026/10/09 18:07:09 INFO Vacuumed table table=multipart_uploads17232026/10/09 18:07:09 INFO Vacuumed table table=closures17242026/10/09 18:07:09 INFO Vacuumed table table=objects1725--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.45s)1726=== CONT TestService_RequireScope_OIDC1727=== CONT TestService_ReadScope_PublicByDefault1728--- PASS: TestReadProxyNarStreaming (0.51s)1729=== CONT TestSweepRechecksPendingAfterLocking1730--- PASS: TestReadProxyDisabled (0.33s)17312026/10/09 18:07:10 INFO Received push request method=POST path=/api/pushes17322026/10/09 18:07:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17332026/10/09 18:07:10 INFO Uploading yicm6f7s50sxgg6fy6yahcnmi9r409fp-lost-commit.txt (152B)1734--- PASS: TestReadRedirectNar (0.42s)1735=== CONT TestService_ReadAuthMiddleware17362026/10/09 18:07:10 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"17372026/10/09 18:07:10 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign17382026/10/09 18:07:10 WARN Failed to register uploaded object key=yicm6f7s50sxgg6fy6yahcnmi9r409fp.ls error="server returned 404: 404 page not found\n"17392026/10/09 18:07:10 INFO Signed narinfos id=4 count=117402026/10/09 18:07:10 INFO Uploading 1 narinfos17412026/10/09 18:07:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41415/oidc17422026/10/09 18:07:10 INFO Received complete push request method=POST path=/api/pushes/4/complete17432026/10/09 18:07:10 WARN Failed to register uploaded object key=yicm6f7s50sxgg6fy6yahcnmi9r409fp.narinfo error="server returned 404: 404 page not found\n"17442026/10/09 18:07:10 INFO Completed push id=4 objects=3 duration=3.831122ms17452026/10/09 18:07:10 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:43805/api/pushes/4/complete\": EOF" url=http://127.0.0.1:43805/api/pushes/4/complete1746=== NAME TestClientMultipleUploads1747 client_integration_test.go:480: Created store path 0: /build/TestClientMultipleUploads1561568505/001/store/i2d08cajyyj5z8j5jsxxwr8vyxvbn60a-test-file-0.txt17482026/10/09 18:07:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17492026/10/09 18:07:10 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLjY5ZjMyNDE1LTE4MzMtNDFkZC1iYTljLTIwN2NkZTFkYmFiNHgxNzkxNTY5MjI4ODEyNDc2OTk2 parts=101750 client_integration_test.go:480: Created store path 1: /build/TestClientMultipleUploads1561568505/001/store/13mpwhyjcy2gmf24b3lmbq89mj5fqq6n-test-file-1.txt17512026/10/09 18:07:10 INFO Received complete push request method=POST path=/api/pushes/1/complete17522026/10/09 18:07:10 INFO Completed push id=1 objects=4 duration=12.624635ms17532026/10/09 18:07:10 INFO Received push request method=POST path=/api/pushes1754--- PASS: TestCacheStatsHandler (0.38s)1755=== CONT TestGetExistingObjectsLocksRows1756=== NAME TestClientMultipleUploads1757 client_integration_test.go:480: Created store path 2: /build/TestClientMultipleUploads1561568505/001/store/czs7xh8cg10x194fa0s1i69xssacfxw2-test-file-2.txt17582026/10/09 18:07:10 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"17592026/10/09 18:07:10 INFO Received complete push request method=POST path=/api/pushes/4/complete17602026-10-09 18:07:10.226 UTC [1156] ERROR: Push does not exist: id=417612026-10-09 18:07:10.226 UTC [1156] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE17622026-10-09 18:07:10.226 UTC [1156] STATEMENT: -- name: CommitPush :one1763 SELECT commit_push($1::bigint)::bigint1764 17652026/10/09 18:07:10 WARN Push not found id=417662026/10/09 18:07:10 INFO Upload complete. (248ms)1767=== NAME TestClientIntegration1768 client_integration_test.go:435: Retrieved narinfo from S3:1769 StorePath: /build/TestClientIntegration193468516/002/store/yicm6f7s50sxgg6fy6yahcnmi9r409fp-lost-commit.txt1770 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1771 Compression: zstd1772 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1773 NarSize: 1521774 References: 1775 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1776 client_integration_test.go:438: Testing garbage collection...17772026/10/09 18:07:10 INFO Aborted multipart uploads count=0 kept=017782026/10/09 18:07:10 INFO Starting cleanup of old closures method=DELETE path=/api/closures1779--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.77s)17802026/10/09 18:07:10 INFO Garbage collection started1781=== CONT TestFailedS3DeleteKeepsTombstone17822026/10/09 18:07:10 WARN Force mode enabled - objects will be deleted immediately without grace period17832026/10/09 18:07:10 INFO Received push request method=POST path=/api/pushes1784--- PASS: TestReadProxyConditionalGet (0.61s)1785=== CONT TestReadRedirectUsesPublicS3URL17862026/10/09 18:07:10 INFO lead: acquired remote=192.0.2.1:123417872026/10/09 18:07:10 INFO Aborted multipart uploads count=0 kept=01788=== NAME TestClientCADerivations1789 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1379383485/001/store/r32w3b0gvq3dlihbdaz3w9hqa2bhz9d5-ca-test17902026/10/09 18:07:10 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=017912026/10/09 18:07:10 WARN Force mode enabled - objects will be deleted immediately without grace period17922026/10/09 18:07:10 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)17932026/10/09 18:07:10 INFO Uploading i2d08cajyyj5z8j5jsxxwr8vyxvbn60a-test-file-0.txt (160B)17942026/10/09 18:07:10 INFO Uploading 13mpwhyjcy2gmf24b3lmbq89mj5fqq6n-test-file-1.txt (160B)17952026/10/09 18:07:10 INFO Uploading czs7xh8cg10x194fa0s1i69xssacfxw2-test-file-2.txt (160B)17962026/10/09 18:07:10 INFO Vacuumed table table=pending_closures17972026/10/09 18:07:10 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"17982026/10/09 18:07:10 INFO Vacuumed table table=pending_objects17992026/10/09 18:07:10 INFO Vacuumed table table=multipart_uploads18002026/10/09 18:07:10 INFO Vacuumed table table=closures18012026/10/09 18:07:10 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18022026/10/09 18:07:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18032026/10/09 18:07:10 INFO Vacuumed table table=objects1804 client_ca_test.go:139: Found 1 dependencies (including self)18052026/10/09 18:07:10 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18062026/10/09 18:07:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18072026/10/09 18:07:10 WARN Failed to register uploaded object key=i2d08cajyyj5z8j5jsxxwr8vyxvbn60a.ls error="server returned 404: 404 page not found\n"18082026/10/09 18:07:10 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=018092026/10/09 18:07:10 WARN Failed to register uploaded object key=czs7xh8cg10x194fa0s1i69xssacfxw2.ls error="server returned 404: 404 page not found\n"18102026/10/09 18:07:10 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLjhjNzQ4ZTg1LTM2OWUtNDhmYy05ODBjLWVmODhmNDQ1OWM3ZXgxNzkxNTY5MjI4OTI3NTYxMDI1 parts=1018112026/10/09 18:07:10 INFO Received complete push request method=POST path=/api/pushes/1/complete18122026/10/09 18:07:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18132026/10/09 18:07:10 WARN Failed to register uploaded object key=13mpwhyjcy2gmf24b3lmbq89mj5fqq6n.ls error="server returned 404: 404 page not found\n"18142026/10/09 18:07:10 INFO Signed narinfos id=1 count=318152026/10/09 18:07:10 INFO Uploading 3 narinfos1816=== CONT TestClientWithDependencies1817--- PASS: TestDeleteClosuresRacingPins (1.92s)18182026/10/09 18:07:10 INFO Vacuumed table table=pending_closures1819--- PASS: TestService_ReadScope_PublicByDefault (0.36s)1820=== CONT TestGCSweepDeliversEachKeyOnce18212026/10/09 18:07:10 INFO Vacuumed table table=pending_objects18222026/10/09 18:07:10 WARN Failed to register uploaded object key=czs7xh8cg10x194fa0s1i69xssacfxw2.narinfo error="server returned 404: 404 page not found\n"18232026/10/09 18:07:10 INFO Vacuumed table table=multipart_uploads18242026/10/09 18:07:10 INFO Completed push id=1 objects=4 duration=12.421306ms18252026/10/09 18:07:10 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLmMwYTU2ZDljLTE4ODgtNDEyYi1hN2I5LTcxMzA3YWEyOTZkZHgxNzkxNTY5MjI4OTkxNzYwNTMz parts=1018262026/10/09 18:07:10 INFO Vacuumed table table=closures18272026/10/09 18:07:10 INFO Vacuumed table table=objects18282026/10/09 18:07:10 INFO Aborted multipart uploads count=0 kept=018292026/10/09 18:07:10 WARN Failed to register uploaded object key=13mpwhyjcy2gmf24b3lmbq89mj5fqq6n.narinfo error="server returned 404: 404 page not found\n"18302026/10/09 18:07:10 INFO Received complete push request method=POST path=/api/pushes/1/complete18312026/10/09 18:07:10 WARN Force mode enabled - objects will be deleted immediately without grace period1832=== NAME TestOrphanedObjectsGCStressTest18332026/10/09 18:07:10 WARN Failed to register uploaded object key=i2d08cajyyj5z8j5jsxxwr8vyxvbn60a.narinfo error="server returned 404: 404 page not found\n"1834 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains18352026/10/09 18:07:10 INFO Completed push id=1 objects=9 duration=12.668745ms18362026/10/09 18:07:10 INFO Upload complete. (149ms)1837=== NAME TestClientMultipleUploads1838 client_integration_test.go:491: Uploaded 3 paths in 181.400943ms1839=== CONT TestLeadIncumbentAnnouncesAtOnce1840--- PASS: TestPush_RepeatedRootCommitsOnce (1.88s)18412026/10/09 18:07:10 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=018422026/10/09 18:07:10 INFO Vacuumed table table=pending_closures18432026/10/09 18:07:10 INFO Vacuumed table table=pending_objects18442026/10/09 18:07:10 INFO Vacuumed table table=multipart_uploads1845--- PASS: TestService_ReadAuthMiddleware (0.32s)1846=== CONT TestReadProxyInvalidPath18472026/10/09 18:07:10 INFO Vacuumed table table=closures18482026/10/09 18:07:10 INFO Vacuumed table table=objects1849=== NAME TestOrphanedObjectsGCStressTest1850 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion1851--- PASS: TestSweepRechecksPendingAfterLocking (0.42s)1852=== CONT TestTombstonedObjectOfferedWithoutWaiting1853=== RUN TestService_RequireScope_OIDC/builder_may_write1854=== PAUSE TestService_RequireScope_OIDC/builder_may_write1855=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1856=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1857=== RUN TestService_RequireScope_OIDC/ops_may_admin1858=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1859=== RUN TestService_RequireScope_OIDC/ops_may_not_write1860=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1861=== RUN TestService_RequireScope_OIDC/reader_may_not_write1862=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1863=== RUN TestService_RequireScope_OIDC/static_token_may_admin1864=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1865=== RUN TestService_RequireScope_OIDC/static_token_may_write1866=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1867=== RUN TestService_RequireScope_OIDC/reader_may_read1868=== PAUSE TestService_RequireScope_OIDC/reader_may_read1869=== RUN TestService_RequireScope_OIDC/writer_implies_read1870=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1871=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1872=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1873=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1874=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1875=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1876=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1877=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1878=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1879=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1880=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1881=== CONT TestGCBugBareHashReferences1882--- PASS: TestClientMultipleUploads (0.73s)1883=== CONT TestService_AuthMiddleware_MTLSBoundSubjects18842026/10/09 18:07:10 INFO Received push request method=POST path=/api/pushes18852026/10/09 18:07:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18862026/10/09 18:07:10 INFO Uploading r32w3b0gvq3dlihbdaz3w9hqa2bhz9d5-ca-test (144B)1887--- PASS: TestReadProxyHead (0.57s)1888=== CONT TestPendingCleanupUsesOneCutoff18892026/10/09 18:07:10 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18902026/10/09 18:07:10 WARN Failed to register uploaded object key=r32w3b0gvq3dlihbdaz3w9hqa2bhz9d5.ls error="server returned 404: 404 page not found\n"18912026/10/09 18:07:10 INFO Received uploads request method=POST path=/api/pending_closures18922026/10/09 18:07:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18932026/10/09 18:07:10 WARN Failed to register uploaded object key=log/z9z97m67n9fx5437jdvbs4cvlwdgrfn1-ca-test.drv error="server returned 404: 404 page not found\n"1894--- PASS: TestGetExistingObjectsLocksRows (0.29s)1895=== CONT TestService_AuthMiddleware_MTLSProxyHeader18962026/10/09 18:07:10 INFO Signed narinfos id=1 count=118972026/10/09 18:07:10 INFO Uploading 1 narinfos18982026/10/09 18:07:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18992026/10/09 18:07:10 INFO Received complete push request method=POST path=/api/pushes/1/complete19002026/10/09 18:07:10 WARN Failed to register uploaded object key=r32w3b0gvq3dlihbdaz3w9hqa2bhz9d5.narinfo error="server returned 404: 404 page not found\n"19012026/10/09 18:07:10 INFO Completed push id=1 objects=4 duration=11.051728ms19022026/10/09 18:07:10 INFO Upload complete. (130ms)1903=== NAME TestClientCADerivations1904 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1379383485/001/store/r32w3b0gvq3dlihbdaz3w9hqa2bhz9d5-ca-test1905 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1906 Compression: zstd1907 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1908 NarSize: 1441909 References: 1910 Deriver: /build/TestClientCADerivations1379383485/001/store/z9z97m67n9fx5437jdvbs4cvlwdgrfn1-ca-test.drv1911 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1912 client_ca_test.go:185: Checking for realisation files in S3...19132026/10/09 18:07:10 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLmZiNDc3YWUyLWQ2NTEtNDQzOC05M2Y3LTgzOWQ2NzFkZWFmY3gxNzkxNTY5MjI5MDIxNDY5MTQ2 parts=101914 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1915 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache19162026/10/09 18:07:10 INFO Aborted multipart uploads count=0 kept=019172026/10/09 18:07:10 WARN Force mode enabled - objects will be deleted immediately without grace period19182026/10/09 18:07:10 INFO Aborted multipart uploads count=0 kept=019192026/10/09 18:07:10 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."19202026/10/09 18:07:10 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."19212026/10/09 18:07:10 WARN Force mode enabled - objects will be deleted immediately without grace period1922 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1923 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1924 error: binary cache 's3://bucket76?endpoint=http://localhost:45145®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1379383485/001/store'1925 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 119262026/10/09 18:07:10 INFO lead: acquired remote=192.0.2.1:123419272026/10/09 18:07:10 INFO lead: released remote=192.0.2.1:12341928=== CONT TestLeadElectsOneAndHandsOver1929--- PASS: TestFailedS3DeleteKeepsTombstone (0.36s)19302026/10/09 18:07:10 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=019312026/10/09 18:07:10 INFO Vacuumed table table=pending_closures19322026/10/09 18:07:10 INFO Vacuumed table table=pending_objects19332026/10/09 18:07:10 INFO Vacuumed table table=multipart_uploads19342026/10/09 18:07:10 INFO Vacuumed table table=closures19352026/10/09 18:07:10 INFO Vacuumed table table=objects1936--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.25s)1937=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1938--- PASS: TestClientCADerivations (0.77s)1939=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1940--- PASS: TestGCSweepDeliversEachKeyOnce (0.30s)1941=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1942--- PASS: TestReadProxyInvalidPath (0.27s)1943=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1944--- PASS: TestReadRedirectUsesPublicS3URL (0.40s)1945=== CONT TestServerTLSConfig/not_a_PEM_file1946=== CONT TestServerTLSConfig/missing_CA_file1947=== NAME TestClientWithDependencies1948 client_integration_test.go:735: Built derivation: /build/TestClientWithDependencies2826242772/001/store/mg87yr7binpszhmnpag47ymh6r7c6n2q-test-script1949=== CONT TestServerTLSConfig/no_client_CA1950=== CONT TestParseSingleRange/none1951--- PASS: TestServerTLSConfig (0.01s)1952 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1953 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1954 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1955=== CONT TestParseSingleRange/start_far_past_EOF1956=== CONT TestParseSingleRange/start_past_EOF1957=== CONT TestParseSingleRange/suffix_exceeds_size1958=== CONT TestParseSingleRange/suffix1959=== CONT TestParseSingleRange/single_byte1960=== CONT TestParseSingleRange/end_clamped_to_size1961=== CONT TestParseSingleRange/closed1962=== CONT TestParseSingleRange/malformed_end_before_start19632026/10/09 18:07:10 INFO Received uploads request method=POST path=/api/pending_closures1964=== CONT TestParseSingleRange/open-ended1965=== CONT TestParseSingleRange/malformed_both_empty1966=== CONT TestParseSingleRange/malformed_no_dash1967=== CONT TestParseSingleRange/multi-range_ignored1968=== CONT TestParseSingleRange/unknown_unit1969=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1970--- PASS: TestParseSingleRange (0.01s)1971 --- PASS: TestParseSingleRange/none (0.00s)1972 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1973 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1974 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1975 --- PASS: TestParseSingleRange/suffix (0.00s)1976 --- PASS: TestParseSingleRange/single_byte (0.00s)1977 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1978 --- PASS: TestParseSingleRange/closed (0.00s)1979 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1980 --- PASS: TestParseSingleRange/open-ended (0.00s)1981 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1982 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1983 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1984 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1985=== CONT TestIsValidCachePath/short_hash1986=== CONT TestIsValidCachePath/empty1987=== CONT TestIsValidCachePath/leading_slash1988=== CONT TestIsValidCachePath/invalid_char_u1989=== CONT TestIsValidCachePath/random_path1990=== CONT TestIsValidCachePath/traversal_in_middle1991=== CONT TestIsValidCachePath/invalid_char_e1992=== CONT TestIsValidCachePath/traversal_parent1993=== CONT TestIsValidCachePath/nix-cache-info1994=== CONT TestIsValidCachePath/realisation1995=== CONT TestIsValidCachePath/index.html1996=== CONT TestIsValidCachePath/log1997=== CONT TestIsValidCachePath/nar_uncompressed1998=== CONT TestIsValidCachePath/nar_bz21999=== CONT TestIsValidCachePath/ls2000=== CONT TestIsValidCachePath/nar_zst2001=== CONT TestIsValidCachePath/nar_xz2002=== CONT TestIsValidCachePath/narinfo2003=== CONT TestIsValidCachePath/wrong_extension2004=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal2005--- PASS: TestIsValidCachePath (0.02s)2006 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2007 --- PASS: TestIsValidCachePath/short_hash (0.00s)2008 --- PASS: TestIsValidCachePath/empty (0.00s)2009 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2010 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2011 --- PASS: TestIsValidCachePath/random_path (0.00s)2012 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2013 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2014 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2015 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2016 --- PASS: TestIsValidCachePath/realisation (0.00s)2017 --- PASS: TestIsValidCachePath/index.html (0.00s)2018 --- PASS: TestIsValidCachePath/log (0.00s)2019 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2020 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2021 --- PASS: TestIsValidCachePath/ls (0.00s)2022 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2023 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2024 --- PASS: TestIsValidCachePath/narinfo (0.00s)2025 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)20262026/10/09 18:07:10 INFO Received uploads request method=POST path=/2027=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info20282026/10/09 18:07:10 INFO Received uploads request method=POST path=/2029=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key20302026/10/09 18:07:10 INFO Received request for more parts method=POST path=/2031=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key20322026/10/09 18:07:10 INFO Received complete multipart upload request method=POST path=/2033=== CONT TestProxyWriteTimeout/1_GiB_nar2034--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2035 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2036 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2037 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2038 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2039=== CONT TestProxyWriteTimeout/narinfo2040=== CONT TestProxyWriteTimeout/10_GiB_nar2041=== CONT TestProxyWriteTimeout/unknown_size2042=== CONT TestIsValidUploadKey/narinfo2043=== CONT TestIsValidUploadKey/realisation_plus_in_output2044--- PASS: TestConnectSerialisesConcurrentMigrations (1.16s)2045=== CONT TestIsValidUploadKey/unknown_type2046=== CONT TestIsValidUploadKey/absolute2047=== CONT TestIsValidUploadKey/traversal2048--- PASS: TestProxyWriteTimeout (0.00s)2049 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2050 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2051 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2052 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2053=== CONT TestIsValidUploadKey/build_log_plus_in_name2054=== CONT TestIsValidUploadKey/realisation2055=== CONT TestIsValidUploadKey/empty_key2056=== CONT TestIsValidUploadKey/build_log_equals2057=== CONT TestIsValidUploadKey/index.html2058=== CONT TestIsValidUploadKey/nix-cache-info2059=== CONT TestIsValidUploadKey/nar_zst2060=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2061=== CONT TestIsValidUploadKey/nar_plain2062=== CONT TestIsValidUploadKey/build_log2063=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2064=== CONT TestIsValidUploadKey/build_log_question_mark2065=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2066=== CONT TestIsValidUploadKey/build_log_home-manager_file2067=== CONT TestIsValidUploadKey/traversal_nar2068=== CONT TestIsValidUploadKey/listing2069=== CONT TestIsValidUploadKey/nar_xz2070=== CONT TestPush_RejectsBadRequests/no_roots2071=== CONT TestPush_RejectsBadRequests/root_not_in_objects2072--- PASS: TestIsValidUploadKey (0.01s)2073 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2074 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2075 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2076 --- PASS: TestIsValidUploadKey/absolute (0.00s)2077 --- PASS: TestIsValidUploadKey/traversal (0.00s)2078 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2079 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2080 --- PASS: TestIsValidUploadKey/realisation (0.00s)2081 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2082 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2083 --- PASS: TestIsValidUploadKey/index.html (0.00s)2084 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2085 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2086 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2087 --- PASS: TestIsValidUploadKey/build_log (0.00s)2088 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2089 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2090 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2091 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2092 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2093 --- PASS: TestIsValidUploadKey/listing (0.00s)2094 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)20952026/10/09 18:07:10 INFO Received push request method=POST path=/api/pushes20962026/10/09 18:07:10 INFO Received push request method=POST path=/api/pushes2097=== CONT TestPush_RejectsBadRequests/bad_root20982026/10/09 18:07:10 INFO Received push request method=POST path=/api/pushes2099=== CONT TestPush_RejectsBadRequests/no_objects2100=== CONT TestResolveDBConnectionString/missing_file_is_an_error21012026/10/09 18:07:10 INFO Received push request method=POST path=/api/pushes2102=== CONT TestResolveDBConnectionString/nothing_configured2103=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2104=== CONT TestResolveDBConnectionString/file_when_flag_empty2105=== CONT TestResolveDBConnectionString/flag_wins2106=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure21072026/10/09 18:07:10 INFO Received uploads request method=POST path=/2108=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart21092026/10/09 18:07:10 INFO Received complete multipart upload request method=POST path=/2110--- PASS: TestResolveDBConnectionString (0.00s)2111 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2112 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2113 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2114 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2115 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2116--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.28s)2117=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts21182026/10/09 18:07:10 INFO Received request for more parts method=POST path=/2119=== NAME TestClientWithDependencies2120 client_integration_test.go:737: Found 1 dependencies (including self)21212026-10-09 18:07:10.721 UTC [176] LOG: checkpoints are occurring too frequently (9 seconds apart)21222026-10-09 18:07:10.721 UTC [176] HINT: Consider increasing the configuration parameter "max_wal_size".21232026-10-09 18:07:10.721 UTC [176] LOG: checkpoint starting: wal2124--- PASS: TestPush_RejectsBadRequests (1.07s)2125 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2126 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2127 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2128 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)21292026/10/09 18:07:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21302026/10/09 18:07:10 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21312026/10/09 18:07:10 WARN mTLS auth: bound subjects configured but subject DN unavailable21322026/10/09 18:07:10 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2133--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.32s)2134=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows21352026/10/09 18:07:10 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLjFmZTU0ZmM3LTc5MmEtNGJjNy05ZmU5LTM0MGI2MGFhZTE5YngxNzkxNTY5MjI5OTIwNDgxMjM1 parts=1221362026/10/09 18:07:10 INFO Received uploads request method=POST path=/api/pending_closures21372026/10/09 18:07:10 INFO Received uploads request method=POST path=/api/pending_closures21382026/10/09 18:07:10 INFO Received uploads request method=POST path=/api/pending_closures21392026/10/09 18:07:10 INFO Received push request method=POST path=/api/pushes21402026/10/09 18:07:10 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21412026/10/09 18:07:10 INFO Uploading mg87yr7binpszhmnpag47ymh6r7c6n2q-test-script (136B)21422026/10/09 18:07:10 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"21432026/10/09 18:07:10 INFO Received uploads request method=POST path=/api/pending_closures21442026/10/09 18:07:10 WARN Failed to register uploaded object key=mg87yr7binpszhmnpag47ymh6r7c6n2q.ls error="server returned 404: 404 page not found\n"21452026/10/09 18:07:10 WARN Failed to register uploaded object key=log/za1id8g0n45f51hfx7v8jzdxpgrh2x5l-test-script.drv error="server returned 404: 404 page not found\n"21462026/10/09 18:07:10 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21472026/10/09 18:07:10 INFO Signed narinfos id=1 count=121482026/10/09 18:07:10 INFO Uploading 1 narinfos2149--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.36s)2150=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check21512026/10/09 18:07:10 INFO Received cleanup request method=DELETE path=/api/pending_closures21522026/10/09 18:07:10 INFO lead: acquired remote=192.0.2.1:123421532026/10/09 18:07:10 INFO Received complete push request method=POST path=/api/pushes/1/complete21542026/10/09 18:07:10 WARN Failed to register uploaded object key=mg87yr7binpszhmnpag47ymh6r7c6n2q.narinfo error="server returned 404: 404 page not found\n"21552026/10/09 18:07:10 INFO Completed push id=1 objects=4 duration=14.643232ms21562026/10/09 18:07:10 INFO Upload complete. (126ms)21572026/10/09 18:07:10 INFO Received uploads request method=POST path=/api/pending_closures21582026/10/09 18:07:10 INFO Aborted multipart uploads count=0 kept=021592026/10/09 18:07:10 WARN Force mode enabled - objects will be deleted immediately without grace period21602026/10/09 18:07:10 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=021612026/10/09 18:07:10 INFO Vacuumed table table=pending_closures21622026/10/09 18:07:10 INFO Vacuumed table table=pending_objects21632026/10/09 18:07:10 INFO Vacuumed table table=multipart_uploads21642026/10/09 18:07:10 INFO Vacuumed table table=closures21652026/10/09 18:07:10 INFO Vacuumed table table=objects2166=== NAME TestClientWithDependencies2167 client_integration_test.go:753: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2826242772/001/store) requires matching store prefix2168=== NAME TestOrphanedObjectsGCStressTest2169 orphaned_objects_gc_test.go:503: Stress test completed successfully:2170 orphaned_objects_gc_test.go:504: - Active objects preserved: 202171 orphaned_objects_gc_test.go:505: - Objects deleted: 2102172 orphaned_objects_gc_test.go:506: - Total GC'd: 2102173--- PASS: TestClientWithDependencies (0.59s)2174=== CONT TestPendingClosureWriteTimeout/empty2175=== CONT TestPendingClosureWriteTimeout/400_objects2176=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline21772026/10/09 18:07:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2178=== CONT TestPendingClosureWriteTimeout/670k_objects2179--- PASS: TestOrphanedObjectsGCStressTest (3.81s)2180=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark21812026/10/09 18:07:10 INFO Received uploads request method=POST path=/api/pending_closures2182=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete2183--- PASS: TestGCBugBareHashReferences (0.55s)21842026/10/09 18:07:10 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLjExODg3YWEzLTMzYWItNGFjMi04OGJhLTkxMGQ0MzA0OGQxNngxNzkxNTY5MjMwMTk4OTk1MDIy parts=1021852026/10/09 18:07:11 INFO Received complete push request method=POST path=/api/pushes/2/complete21862026/10/09 18:07:11 INFO Completed push id=2 objects=4 duration=3.617533ms21872026/10/09 18:07:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21882026/10/09 18:07:11 INFO Received uploads request method=POST path=/api/pending_closures21892026/10/09 18:07:11 INFO Aborted multipart uploads count=0 kept=02190=== CONT TestGCEndsOnShutdown/before_the_run2191--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.64s)21922026/10/09 18:07:11 WARN Force mode enabled - objects will be deleted immediately without grace period21932026/10/09 18:07:11 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLjNhOTY5YmY4LWRlMTYtNGYyNy04NzY5LTBlN2Q3OTU1ZGQ1YngxNzkxNTY5MjI4OTkzNDM5MzY5 parts=1021942026/10/09 18:07:11 INFO Received complete push request method=POST path=/api/pushes/1/complete21952026/10/09 18:07:11 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=021962026/10/09 18:07:11 INFO Vacuumed table table=pending_closures21972026/10/09 18:07:11 INFO Vacuumed table table=pending_objects21982026/10/09 18:07:11 INFO Vacuumed table table=multipart_uploads21992026/10/09 18:07:11 INFO Vacuumed table table=closures22002026/10/09 18:07:11 INFO Received uploads request method=POST path=/api/pending_closures22012026/10/09 18:07:11 INFO Completed push id=1 objects=6 duration=19.540133ms22022026/10/09 18:07:11 INFO Vacuumed table table=objects22032026/10/09 18:07:11 INFO Aborted multipart uploads count=0 kept=022042026/10/09 18:07:11 WARN Force mode enabled - objects will be deleted immediately without grace period22052026/10/09 18:07:11 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=02206--- PASS: TestPush_CompleteCommitsEveryRoot (2.55s)2207=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected22082026/10/09 18:07:11 INFO Vacuumed table table=pending_closures22092026/10/09 18:07:11 INFO Vacuumed table table=pending_objects22102026/10/09 18:07:11 INFO Vacuumed table table=multipart_uploads22112026/10/09 18:07:11 INFO Vacuumed table table=closures22122026/10/09 18:07:11 WARN Authentication failed token_preview=eyJhbGciOi...qYUqYCFYPg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2213=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected22142026/10/09 18:07:11 INFO Vacuumed table table=objects22152026/10/09 18:07:11 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]2216=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2217=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2218=== CONT TestClientErrorHandling/InvalidStorePath2219=== CONT TestClientErrorHandling/ServerNotAvailable2220--- PASS: TestService_AuthMiddleware_OIDC (0.51s)2221 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2222 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2223 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2224 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)22252026/10/09 18:07:11 INFO Received uploads request method=POST path=/api/pending_closures2226=== CONT TestClientErrorHandling/InvalidAuthToken2227--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2228 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.35s)2229 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.29s)22302026/10/09 18:07:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22312026/10/09 18:07:11 WARN Rate limiter enabled after throttle name=s3-test rate=522322026/10/09 18:07:11 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2233=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2234 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102235 throttle_test.go:215: Rate limiter: enabled=true, rate=5.0022362026/10/09 18:07:11 INFO Aborted multipart uploads count=0 kept=022372026/10/09 18:07:11 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22382026/10/09 18:07:11 WARN Force mode enabled - objects will be deleted immediately without grace period22392026/10/09 18:07:11 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLjcxZWI3YTExLWRhMWYtNDBkYS1hNDc3LTUxYjdlN2VhNThiZHgxNzkxNTY5MjI5MDIzNDIyMTUy parts=1022402026/10/09 18:07:11 INFO Aborted multipart uploads count=0 kept=02241--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.04s)2242=== CONT TestCacheConfigHandler/no_cache_url_configured2243=== CONT TestCacheConfigHandler/no_signing_keys2244=== CONT TestCacheConfigHandler/full_config,_no_issuer2245=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2246--- PASS: TestCacheConfigHandler (0.00s)2247 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2248 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2249 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2250 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2251=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read22522026/10/09 18:07:11 WARN Authentication failed token_preview=wrong token_length=5 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2253=== CONT TestService_RequireScope_OIDC/builder_may_not_admin22542026/10/09 18:07:11 WARN Force mode enabled - objects will be deleted immediately without grace period2255=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2256=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2257=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2258=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2259=== CONT TestService_RequireScope_OIDC/reader_may_not_write2260=== CONT TestService_RequireScope_OIDC/static_token_may_admin2261=== CONT TestService_RequireScope_OIDC/static_token_may_write2262=== CONT TestService_RequireScope_OIDC/ops_may_not_write2263=== CONT TestService_RequireScope_OIDC/writer_implies_read2264=== CONT TestService_RequireScope_OIDC/builder_may_write2265=== CONT TestService_RequireScope_OIDC/reader_may_read22662026/10/09 18:07:11 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:45145/bucket105/?delete=\": context canceled"2267=== CONT TestService_RequireScope_OIDC/ops_may_admin2268--- PASS: TestGCEndsOnShutdown (0.00s)2269 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.25s)2270 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.26s)2271 --- PASS: TestGCEndsOnShutdown/before_the_run (0.22s)2272--- PASS: TestService_RequireScope_OIDC (0.49s)2273 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2274 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2275 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2276 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2277 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2278 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2279 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2280 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2281 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2282 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2283 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2284 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2285 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2286 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)22872026/10/09 18:07:11 WARN Request failed, retrying attempt=2 backoff=186.897938ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22882026/10/09 18:07:11 INFO lead: released remote=192.0.2.1:123422892026/10/09 18:07:11 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLjc4YWZlNDk0LTJmM2ItNDZjMS1iODU3LTU0NjQyNTNjMjc2YngxNzkxNTY5MjMwOTA2MDk3NTg4 error="Access Denied"22902026/10/09 18:07:11 WARN keeping failed pending closure for cleanup to retry the abort id=12291--- PASS: TestLeadEndsOnShutdown (1.48s)22922026/10/09 18:07:11 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2293--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.01s)2294 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.80s)2295 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.82s)22962026/10/09 18:07:11 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22972026/10/09 18:07:11 WARN Request failed, retrying attempt=3 backoff=407.802067ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2298--- PASS: TestPendingClosureFailureTracksEveryUpload (0.00s)2299 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (0.79s)2300 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (0.86s)23012026/10/09 18:07:11 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=023022026/10/09 18:07:11 INFO Received create pin request method=POST path=/api/pins/myapp23032026/10/09 18:07:11 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2473063669/001/store/kmmaaahwfn9s1cbvqzbfd4ayhmkl0kiz-pinned-file.txt narinfo_key=kmmaaahwfn9s1cbvqzbfd4ayhmkl0kiz.narinfo23042026/10/09 18:07:11 INFO Starting cleanup of old closures method=DELETE path=/api/closures23052026/10/09 18:07:11 INFO Garbage collection started23062026/10/09 18:07:11 INFO Aborted multipart uploads count=0 kept=023072026/10/09 18:07:11 WARN Force mode enabled - objects will be deleted immediately without grace period23082026/10/09 18:07:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23092026/10/09 18:07:11 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=023102026/10/09 18:07:11 INFO Vacuumed table table=pending_closures23112026/10/09 18:07:11 INFO Vacuumed table table=pending_objects23122026/10/09 18:07:11 INFO Vacuumed table table=multipart_uploads23132026/10/09 18:07:11 INFO Vacuumed table table=closures23142026/10/09 18:07:11 INFO Vacuumed table table=objects23152026/10/09 18:07:11 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLjFiMGVjMjBhLTllZDctNDE5YS05NjAyLTNmMzJlODEzNWQwOXgxNzkxNTY5MjMwNzk5NDE0ODIy error="Get \"http://127.0.0.1:1/bucket68/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"23162026/10/09 18:07:11 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLjc5YTI4YTk3LWJjYjgtNGE2Yy1iYzk2LTg2NzUzZDlmODM0MngxNzkxNTY5MjMwNzc5NjgxNzMw parts=1223172026/10/09 18:07:11 INFO Received cleanup request method=DELETE path=/api/pending_closures23182026/10/09 18:07:11 INFO Aborted multipart uploads count=1 kept=02319--- PASS: TestRedundantMultipartUpload (2.07s)23202026/10/09 18:07:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23212026/10/09 18:07:11 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLjkwZmVmMGM0LWMxMWQtNDVmZS04MTYzLWZlYTliNmIyN2Q0MHgxNzkxNTY5MjI5MDIyOTAzMTkz parts=1023222026/10/09 18:07:11 WARN Request failed, retrying attempt=4 backoff=788.091478ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2323--- PASS: TestPendingClosureWriteTimeout (0.00s)2324 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2325 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2326 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2327 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.02s)23282026/10/09 18:07:12 INFO lead: released remote=192.0.2.1:123423292026/10/09 18:07:12 INFO lead: acquired remote=192.0.2.1:123423302026/10/09 18:07:12 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02331=== NAME TestClientIntegration2332 client_integration_test.go:445: Objects in database after GC:2333 client_integration_test.go:445: Successfully deleted all objects with GC --force2334--- PASS: TestClientIntegration (3.21s)23352026/10/09 18:07:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23362026/10/09 18:07:12 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLjE5OGEyN2QyLWRhNmItNGZmNi04ODJmLWY3ZmY5Njc2NTNjY3gxNzkxNTY5MjI5MDIzNzY2MDkx parts=1023372026/10/09 18:07:12 WARN Request failed, retrying attempt=5 backoff=1.711149732s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23382026/10/09 18:07:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23392026/10/09 18:07:13 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=ZjE3YTdmZjItYjM1ZS00NTA2LTg0ZDgtYTAxMTk5ZTYzYzlmLjY4OWRmNTVjLTBkMzUtNDk1OC05MGQ4LTk3NDVjZmIwNjJmZHgxNzkxNTY5MjI5MDIzOTQxNDUx parts=1023402026/10/09 18:07:13 INFO lead: released remote=192.0.2.1:123423412026-10-09 18:07:13.257 UTC [1032] ERROR: could not obtain lock on row in relation "closures"23422026-10-09 18:07:13.257 UTC [1032] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23432026-10-09 18:07:13.259 UTC [1032] ERROR: could not obtain lock on row in relation "closures"23442026-10-09 18:07:13.259 UTC [1032] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23452026-10-09 18:07:13.259 UTC [1032] ERROR: could not obtain lock on row in relation "closures"23462026-10-09 18:07:13.259 UTC [1032] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23472026-10-09 18:07:13.260 UTC [1032] ERROR: could not obtain lock on row in relation "closures"23482026-10-09 18:07:13.260 UTC [1032] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23492026-10-09 18:07:13.261 UTC [1032] ERROR: could not obtain lock on row in relation "closures"23502026-10-09 18:07:13.261 UTC [1032] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT2351--- PASS: TestLeadElectsOneAndHandsOver (2.64s)2352--- PASS: TestPush_RootsAreLockedInByteOrder (4.66s)2353=== NAME TestPinProtectsFromGC2354 client_integration_test.go:976: Pin successfully protected closure from garbage collection2355--- PASS: TestPinProtectsFromGC (4.81s)23562026/10/09 18:07:14 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2357--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.80s)23582026/10/09 18:07:14 WARN Request failed, retrying attempt=2 backoff=192.280781ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2359--- PASS: TestConnectWaitsForAPeerMigration (5.25s)23602026/10/09 18:07:14 WARN Request failed, retrying attempt=3 backoff=392.445441ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23612026/10/09 18:07:15 WARN Request failed, retrying attempt=4 backoff=757.164027ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23622026/10/09 18:07:15 WARN Request failed, retrying attempt=5 backoff=1.6229817s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23632026/10/09 18:07:16 INFO Aborted multipart uploads count=1 kept=023642026/10/09 18:07:16 INFO Received cleanup request method=DELETE path=/api/pending_closures23652026/10/09 18:07:16 INFO Aborted multipart uploads count=1 kept=02366--- PASS: TestPendingCleanupUsesOneCutoff (6.43s)23672026/10/09 18:07:17 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"23682026/10/09 18:07:17 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23692026/10/09 18:07:17 WARN Request failed, retrying attempt=2 backoff=216.529649ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23702026/10/09 18:07:17 WARN Request failed, retrying attempt=3 backoff=391.662969ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2371--- PASS: TestUploadHandlersRejectOversizedBody (1.28s)2372 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.70s)2373 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.71s)2374 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (7.59s)23752026/10/09 18:07:18 WARN Request failed, retrying attempt=4 backoff=733.112721ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23762026/10/09 18:07:19 WARN Request failed, retrying attempt=5 backoff=1.688384847s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23772026/10/09 18:07:20 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23782026/10/09 18:07:20 WARN Request failed, retrying attempt=2 backoff=181.730525ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23792026/10/09 18:07:21 WARN Request failed, retrying attempt=3 backoff=364.231182ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23802026/10/09 18:07:21 WARN Request failed, retrying attempt=4 backoff=791.162516ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23812026/10/09 18:07:22 WARN Request failed, retrying attempt=5 backoff=1.624030944s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2382--- PASS: TestClientErrorHandling (0.00s)2383 --- PASS: TestClientErrorHandling/InvalidStorePath (0.23s)2384 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.37s)2385 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.69s)2386PASS2387{"timestamp":"2026-10-09T18:07:23.809284791Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:56548","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(399)"}2388{"timestamp":"2026-10-09T18:07:23.81006766Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:56550","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(390)"}23892026-10-09 18:07:24.284 UTC [171] LOG: received smart shutdown request23902026-10-09 18:07:24.290 UTC [171] LOG: background worker "logical replication launcher" (PID 181) exited with exit code 123912026-10-09 18:07:25.096 UTC [176] LOG: checkpoint complete: wrote 4569 buffers (27.9%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=13.646 s, sync=0.657 s, total=14.376 s; sync files=37078, longest=0.001 s, average=0.001 s; distance=534047 kB, estimate=534047 kB; lsn=0/24F0B3B8, redo lsn=0/220EDC9823922026-10-09 18:07:25.099 UTC [176] LOG: shutting down23932026-10-09 18:07:25.099 UTC [176] LOG: checkpoint starting: shutdown immediate23942026-10-09 18:07:25.719 UTC [176] LOG: checkpoint complete: wrote 6201 buffers (37.8%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 2 recycled; write=0.108 s, sync=0.506 s, total=0.621 s; sync files=1899, longest=0.002 s, average=0.001 s; distance=47221 kB, estimate=485365 kB; lsn=0/24F0B430, redo lsn=0/24F0B43023952026-10-09 18:07:25.802 UTC [171] LOG: database system is shut down2396Running OIDC tests...2397=== RUN TestAudienceForIssuer2398=== PAUSE TestAudienceForIssuer2399=== RUN TestHTTPClientForHasTimeouts2400=== PAUSE TestHTTPClientForHasTimeouts2401=== RUN TestGlobMatch2402=== PAUSE TestGlobMatch2403=== RUN TestValidateToken_ValidToken2404=== PAUSE TestValidateToken_ValidToken2405=== RUN TestValidateToken_WrongAudience2406=== PAUSE TestValidateToken_WrongAudience2407=== RUN TestValidateToken_Expired2408=== PAUSE TestValidateToken_Expired2409=== RUN TestValidateToken_BoundClaimsMismatch2410=== PAUSE TestValidateToken_BoundClaimsMismatch2411=== RUN TestValidateToken_BoundSubjectMismatch2412=== PAUSE TestValidateToken_BoundSubjectMismatch2413=== RUN TestValidateToken_MultipleProviders2414=== PAUSE TestValidateToken_MultipleProviders2415=== RUN TestValidateToken_NoMatchingProvider2416=== PAUSE TestValidateToken_NoMatchingProvider2417=== RUN TestValidateToken_KubernetesServiceAccount2418=== PAUSE TestValidateToken_KubernetesServiceAccount2419=== RUN TestNewValidator_KubernetesRequiresCA2420=== PAUSE TestNewValidator_KubernetesRequiresCA2421=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2422=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2423=== RUN TestPins_ReservedForMatchingRule2424=== PAUSE TestPins_ReservedForMatchingRule2425=== RUN TestPins_TopLevelShorthand2426=== PAUSE TestPins_TopLevelShorthand2427=== RUN TestPins_ConfigValidation2428=== PAUSE TestPins_ConfigValidation2429=== RUN TestScopes_LegacyProviderDefaultsToWrite2430=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2431=== RUN TestScopes_Rules2432=== PAUSE TestScopes_Rules2433=== RUN TestScopes_ConfigValidation2434=== PAUSE TestScopes_ConfigValidation2435=== CONT TestAudienceForIssuer2436=== CONT TestPins_TopLevelShorthand2437=== CONT TestValidateToken_NoMatchingProvider2438=== CONT TestPins_ConfigValidation2439=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2440=== CONT TestNewValidator_KubernetesRequiresCA2441=== CONT TestPins_ReservedForMatchingRule2442=== CONT TestValidateToken_ValidToken2443=== CONT TestValidateToken_WrongAudience2444=== CONT TestHTTPClientForHasTimeouts2445=== CONT TestGlobMatch2446=== RUN TestGlobMatch/foo_foo2447=== CONT TestValidateToken_MultipleProviders2448=== CONT TestValidateToken_KubernetesServiceAccount2449=== CONT TestValidateToken_BoundSubjectMismatch2450=== CONT TestScopes_LegacyProviderDefaultsToWrite2451=== CONT TestScopes_Rules2452=== CONT TestValidateToken_BoundClaimsMismatch2453=== CONT TestScopes_ConfigValidation2454--- PASS: TestAudienceForIssuer (0.00s)2455--- PASS: TestPins_ConfigValidation (0.00s)2456=== CONT TestValidateToken_Expired2457=== PAUSE TestGlobMatch/foo_foo2458--- PASS: TestScopes_ConfigValidation (0.00s)2459=== RUN TestGlobMatch/foo_bar2460=== PAUSE TestGlobMatch/foo_bar2461=== RUN TestGlobMatch/*_2462=== PAUSE TestGlobMatch/*_2463=== RUN TestGlobMatch/*_anything2464=== PAUSE TestGlobMatch/*_anything2465=== RUN TestGlobMatch/foo*_foo2466=== PAUSE TestGlobMatch/foo*_foo2467=== RUN TestGlobMatch/foo*_foobar2468=== PAUSE TestGlobMatch/foo*_foobar2469=== RUN TestGlobMatch/foo*_bar2470=== PAUSE TestGlobMatch/foo*_bar2471=== RUN TestGlobMatch/*bar_bar2472=== PAUSE TestGlobMatch/*bar_bar2473=== RUN TestGlobMatch/*bar_foobar2474=== PAUSE TestGlobMatch/*bar_foobar2475=== RUN TestGlobMatch/*bar_foo2476=== PAUSE TestGlobMatch/*bar_foo2477=== RUN TestGlobMatch/foo*bar_foobar2478=== PAUSE TestGlobMatch/foo*bar_foobar2479=== RUN TestGlobMatch/foo*bar_foo123bar2480=== PAUSE TestGlobMatch/foo*bar_foo123bar2481=== RUN TestGlobMatch/foo*bar_foobarbaz2482=== PAUSE TestGlobMatch/foo*bar_foobarbaz2483=== RUN TestGlobMatch/*/*_foo/bar2484=== PAUSE TestGlobMatch/*/*_foo/bar2485=== RUN TestGlobMatch/*/*_foo2486=== PAUSE TestGlobMatch/*/*_foo2487=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2488=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2489=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02490=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02491=== RUN TestGlobMatch/refs/*/main_refs/heads/main2492=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2493=== RUN TestGlobMatch/fo?_foo2494=== PAUSE TestGlobMatch/fo?_foo2495=== RUN TestGlobMatch/fo?_fo2496=== PAUSE TestGlobMatch/fo?_fo2497=== RUN TestGlobMatch/fo?_fooo2498=== PAUSE TestGlobMatch/fo?_fooo2499=== RUN TestGlobMatch/?oo_foo2500=== PAUSE TestGlobMatch/?oo_foo2501=== RUN TestGlobMatch/?oo_boo2502=== PAUSE TestGlobMatch/?oo_boo2503=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2504=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2505=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2506=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2507=== CONT TestGlobMatch/foo_foo2508=== CONT TestGlobMatch/*/*_foo/bar2509=== CONT TestGlobMatch/refs/*/main_refs/heads/main2510=== CONT TestGlobMatch/fo?_foo2511=== CONT TestGlobMatch/fo?_fooo2512=== CONT TestGlobMatch/foo*bar_foobarbaz2513=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2514=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2515=== CONT TestGlobMatch/?oo_boo2516=== CONT TestGlobMatch/?oo_foo2517=== CONT TestGlobMatch/fo?_fo2518=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02519=== CONT TestGlobMatch/*_anything2520=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2521=== CONT TestGlobMatch/foo*_foobar2522=== CONT TestGlobMatch/foo*_foo2523=== CONT TestGlobMatch/foo*bar_foobar2524=== CONT TestGlobMatch/*_2525=== CONT TestGlobMatch/*bar_foo2526=== CONT TestGlobMatch/foo*bar_foo123bar2527=== CONT TestGlobMatch/*bar_foobar2528=== CONT TestGlobMatch/foo*_bar2529=== CONT TestGlobMatch/*bar_bar2530=== CONT TestGlobMatch/*/*_foo2531=== CONT TestGlobMatch/foo_bar2532--- PASS: TestGlobMatch (0.01s)2533 --- PASS: TestGlobMatch/foo_foo (0.00s)2534 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2535 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2536 --- PASS: TestGlobMatch/fo?_foo (0.00s)2537 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2538 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2539 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2540 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2541 --- PASS: TestGlobMatch/?oo_boo (0.00s)2542 --- PASS: TestGlobMatch/?oo_foo (0.00s)2543 --- PASS: TestGlobMatch/fo?_fo (0.00s)2544 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2545 --- PASS: TestGlobMatch/*_anything (0.00s)2546 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2547 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2548 --- PASS: TestGlobMatch/foo*_foo (0.00s)2549 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2550 --- PASS: TestGlobMatch/*_ (0.00s)2551 --- PASS: TestGlobMatch/*bar_foo (0.00s)2552 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2553 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2554 --- PASS: TestGlobMatch/foo*_bar (0.00s)2555 --- PASS: TestGlobMatch/*bar_bar (0.00s)2556 --- PASS: TestGlobMatch/*/*_foo (0.00s)2557 --- PASS: TestGlobMatch/foo_bar (0.00s)25582026/10/09 18:07:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38299/oidc2559--- PASS: TestValidateToken_BoundClaimsMismatch (0.05s)25602026/10/09 18:07:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34111/oidc2561--- PASS: TestPins_TopLevelShorthand (0.07s)25622026/10/09 18:07:29 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12325632026/10/09 18:07:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44843/oidc25642026/10/09 18:07:29 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:43557/oidc25652026/10/09 18:07:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34195/oidc25662026/10/09 18:07:29 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:45833/oidc2567--- PASS: TestValidateToken_BoundSubjectMismatch (0.07s)2568--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.07s)2569--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.08s)2570--- PASS: TestValidateToken_MultipleProviders (0.08s)25712026/10/09 18:07:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36231/oidc25722026/10/09 18:07:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36751/oidc2573--- PASS: TestValidateToken_ValidToken (0.09s)25742026/10/09 18:07:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39319/oidc25752026/10/09 18:07:29 http: TLS handshake error from 127.0.0.1:50090: remote error: tls: bad certificate2576--- PASS: TestNewValidator_KubernetesRequiresCA (0.10s)2577--- PASS: TestScopes_Rules (0.09s)2578--- PASS: TestValidateToken_WrongAudience (0.10s)25792026/10/09 18:07:29 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40927/oidc2580--- PASS: TestValidateToken_Expired (0.13s)25812026/10/09 18:07:30 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:394552582--- PASS: TestValidateToken_KubernetesServiceAccount (0.16s)25832026/10/09 18:07:30 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44023/oidc2584--- PASS: TestPins_ReservedForMatchingRule (0.18s)2585--- PASS: TestHTTPClientForHasTimeouts (0.20s)25862026/10/09 18:07:30 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34083/oidc2587--- PASS: TestValidateToken_NoMatchingProvider (0.30s)2588PASS2589Running hook tests...2590=== RUN TestSendPathsEmpty2591=== PAUSE TestSendPathsEmpty2592=== RUN TestQueueEnqueueAndFetch2593=== PAUSE TestQueueEnqueueAndFetch2594=== RUN TestQueueDeduplication2595=== PAUSE TestQueueDeduplication2596=== RUN TestQueueRemove2597=== PAUSE TestQueueRemove2598=== RUN TestQueueFetchBatchLimit2599=== PAUSE TestQueueFetchBatchLimit2600=== RUN TestQueueRetryMovesToBack2601=== PAUSE TestQueueRetryMovesToBack2602=== RUN TestQueueFetchRemoveLifecycle2603=== PAUSE TestQueueFetchRemoveLifecycle2604=== RUN TestQueueConcurrentWriters2605=== PAUSE TestQueueConcurrentWriters2606=== RUN TestQueueEnqueueWaitsOutSlowWriter2607=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2608=== RUN TestQueueRemoveLargeClosure2609=== PAUSE TestQueueRemoveLargeClosure2610=== RUN TestServerClientIntegration2611--- PASS: TestServerClientIntegration (0.00s)2612=== RUN TestServerQueueError26132026/10/09 18:07:31 ERROR Failed to queue paths error="permission denied" count=12614--- PASS: TestServerQueueError (0.00s)2615=== RUN TestServerRefusesOversizedAndNonStoreRequests2616=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2617=== RUN TestGetListenerSocketActivation2618 server_test.go:329: === RUN TestGetListenerSocketActivation2619 --- PASS: TestGetListenerSocketActivation (0.00s)2620 PASS2621 2622--- PASS: TestGetListenerSocketActivation (1.02s)2623=== RUN TestServerStalledClientDoesNotBlockShutdown2624=== PAUSE TestServerStalledClientDoesNotBlockShutdown2625=== RUN TestServerBacksOffOnAcceptErrors2626=== PAUSE TestServerBacksOffOnAcceptErrors2627=== RUN TestDrainIsolatesPoisonPath2628=== PAUSE TestDrainIsolatesPoisonPath2629=== RUN TestRunNotBlockedByPoisonHead2630=== PAUSE TestRunNotBlockedByPoisonHead2631=== RUN TestDrainGivesUpWhenServerDown2632=== PAUSE TestDrainGivesUpWhenServerDown2633=== RUN TestFailedPathPrunedByLaterClosure2634=== PAUSE TestFailedPathPrunedByLaterClosure2635=== RUN TestWorkerUploadsAndRemoves2636=== PAUSE TestWorkerUploadsAndRemoves2637=== RUN TestWorkerSkipsGCdPaths2638=== PAUSE TestWorkerSkipsGCdPaths2639=== RUN TestWorkerPrunesClosureDeps2640=== PAUSE TestWorkerPrunesClosureDeps2641=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2642=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2643=== RUN TestDrainTimeout2644=== PAUSE TestDrainTimeout2645=== RUN TestDrainTimeoutDuringIsolation2646=== PAUSE TestDrainTimeoutDuringIsolation2647=== RUN TestShutdownFinishesInFlightPush2648=== PAUSE TestShutdownFinishesInFlightPush2649=== RUN TestWorkerRemoveFailureIsNotProgress2650=== PAUSE TestWorkerRemoveFailureIsNotProgress2651=== RUN TestWorkerKeepsPathItCannotStat2652=== PAUSE TestWorkerKeepsPathItCannotStat2653=== CONT TestSendPathsEmpty2654=== CONT TestServerBacksOffOnAcceptErrors2655--- PASS: TestSendPathsEmpty (0.00s)26562026/10/09 18:07:32 ERROR Accept failed error="too many open files"2657=== CONT TestServerRefusesOversizedAndNonStoreRequests2658=== CONT TestQueueRetryMovesToBack2659=== CONT TestQueueFetchBatchLimit2660=== CONT TestQueueDeduplication2661=== CONT TestQueueEnqueueAndFetch26622026/10/09 18:07:32 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2663=== CONT TestQueueRemove2664=== CONT TestWorkerKeepsPathItCannotStat2665=== CONT TestDrainTimeoutDuringIsolation2666=== CONT TestWorkerRemoveFailureIsNotProgress2667=== CONT TestShutdownFinishesInFlightPush2668=== CONT TestDrainTimeout26692026/10/09 18:07:32 ERROR Refusing path outside the store path=/nix/store store=/nix/store2670=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2671=== CONT TestQueueFetchRemoveLifecycle26722026/10/09 18:07:32 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store2673=== CONT TestQueueRemoveLargeClosure2674=== CONT TestServerStalledClientDoesNotBlockShutdown2675=== CONT TestQueueEnqueueWaitsOutSlowWriter2676=== CONT TestRunNotBlockedByPoisonHead2677=== CONT TestWorkerSkipsGCdPaths26782026/10/09 18:07:32 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store2679=== CONT TestQueueConcurrentWriters2680=== CONT TestDrainGivesUpWhenServerDown2681=== CONT TestWorkerUploadsAndRemoves2682=== CONT TestFailedPathPrunedByLaterClosure2683=== CONT TestWorkerPrunesClosureDeps2684=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2685=== RUN TestShutdownFinishesInFlightPush/completes26862026/10/09 18:07:32 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store2687=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2688=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2689=== PAUSE TestShutdownFinishesInFlightPush/completes26902026/10/09 18:07:32 ERROR Accept failed error="too many open files"2691=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2692=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2693=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2694=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path26952026/10/09 18:07:32 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store2696=== CONT TestDrainIsolatesPoisonPath2697=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2698=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout26992026/10/09 18:07:32 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store2700=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2701=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short2702=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2703=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2704=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline27052026/10/09 18:07:32 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store27062026/10/09 18:07:32 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store27072026/10/09 18:07:32 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store27082026/10/09 18:07:32 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store27092026/10/09 18:07:32 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store27102026/10/09 18:07:32 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store27112026/10/09 18:07:32 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store27122026/10/09 18:07:32 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store27132026/10/09 18:07:32 ERROR Accept failed error="too many open files"27142026/10/09 18:07:32 ERROR Failed to decode request error="unexpected EOF"2715--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.02s)2716=== CONT TestShutdownFinishesInFlightPush/completes27172026/10/09 18:07:32 ERROR Accept failed error="too many open files"27182026/10/09 18:07:32 INFO Upload queue status pending=227192026/10/09 18:07:32 INFO Uploading batch count=227202026/10/09 18:07:32 INFO Uploading batch count=427212026/10/09 18:07:32 ERROR Upload failed error="upload failed" count=427222026/10/09 18:07:32 ERROR Accept failed error="too many open files"27232026/10/09 18:07:32 INFO Uploading batch count=427242026/10/09 18:07:32 ERROR Upload failed error="upload failed" count=427252026/10/09 18:07:32 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2891838268/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2891838268/002/locked/aaa: permission denied"27262026/10/09 18:07:32 INFO Uploading batch count=127272026/10/09 18:07:32 ERROR Upload failed error="upload failed" count=127282026/10/09 18:07:32 INFO Upload queue status pending=327292026/10/09 18:07:32 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths4255616248/002/nonexistent27302026/10/09 18:07:32 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3584178436/002/bbb27312026/10/09 18:07:32 INFO Upload queue status pending=327322026/10/09 18:07:32 INFO Upload queue status pending=227332026/10/09 18:07:32 INFO Uploading batch count=127342026/10/09 18:07:32 ERROR Upload failed error="upload failed" count=127352026/10/09 18:07:32 INFO Uploading batch count=227362026/10/09 18:07:32 INFO Upload queue status pending=227372026/10/09 18:07:32 INFO Uploading batch count=22738--- PASS: TestQueueFetchBatchLimit (0.08s)2739=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout27402026/10/09 18:07:32 INFO Uploading batch count=227412026/10/09 18:07:32 INFO Uploading batch count=127422026/10/09 18:07:32 INFO Uploading batch count=127432026/10/09 18:07:32 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2891838268/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2891838268/002/locked/aaa: permission denied"27442026/10/09 18:07:32 ERROR Upload failed error="upload failed" count=227452026/10/09 18:07:32 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1601028870/002/a27462026/10/09 18:07:32 INFO Uploading batch count=22747--- PASS: TestQueueDeduplication (0.09s)2748=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch2749--- PASS: TestQueueRemove (0.09s)2750=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths27512026/10/09 18:07:32 INFO Uploading batch count=427522026/10/09 18:07:32 ERROR Upload failed error="upload failed" count=427532026/10/09 18:07:32 INFO Upload queue status pending=227542026/10/09 18:07:32 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1601028870/002/b27552026/10/09 18:07:32 INFO Uploading batch count=227562026/10/09 18:07:32 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2891838268/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2891838268/002/locked/aaa: permission denied"2757--- PASS: TestQueueRetryMovesToBack (0.09s)2758=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27592026/10/09 18:07:32 INFO Uploading batch count=227602026/10/09 18:07:32 ERROR Upload failed error="upload failed" count=227612026/10/09 18:07:32 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1601028870/002/c27622026/10/09 18:07:32 INFO Uploading batch count=127632026/10/09 18:07:32 INFO Uploading batch count=127642026/10/09 18:07:32 ERROR Upload failed error="upload failed" count=12765--- PASS: TestQueueFetchRemoveLifecycle (0.09s)2766--- PASS: TestQueueEnqueueAndFetch (0.10s)27672026/10/09 18:07:32 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1601028870/002/d27682026/10/09 18:07:32 ERROR Drain finished with paths left in queue remaining=127692026/10/09 18:07:32 INFO Uploading batch count=227702026/10/09 18:07:32 ERROR Upload failed error="upload failed" count=227712026/10/09 18:07:32 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1601028870/002/e27722026/10/09 18:07:32 INFO Uploading batch count=127732026/10/09 18:07:32 ERROR Upload failed error="upload failed" count=12774--- PASS: TestWorkerUploadsAndRemoves (0.10s)27752026/10/09 18:07:32 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown1601028870/002/f2776--- PASS: TestWorkerSkipsGCdPaths (0.10s)27772026/10/09 18:07:32 INFO Uploading batch count=127782026/10/09 18:07:32 ERROR Upload failed error="upload failed" count=12779--- PASS: TestWorkerKeepsPathItCannotStat (0.11s)2780--- PASS: TestFailedPathPrunedByLaterClosure (0.10s)2781--- PASS: TestWorkerPrunesClosureDeps (0.10s)27822026/10/09 18:07:32 ERROR Drain finished with paths left in queue remaining=1027832026/10/09 18:07:32 ERROR Drain finished with paths left in queue remaining=12784--- PASS: TestDrainGivesUpWhenServerDown (0.11s)27852026/10/09 18:07:32 INFO Upload queue status pending=22786--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.11s)27872026/10/09 18:07:32 INFO Uploading batch count=22788--- PASS: TestDrainIsolatesPoisonPath (0.11s)27892026/10/09 18:07:32 INFO Uploading batch count=227902026/10/09 18:07:32 ERROR Upload failed error="upload failed" count=227912026/10/09 18:07:32 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127922026/10/09 18:07:32 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path1518256254/001/nonexistent27932026/10/09 18:07:32 INFO Uploading batch count=227942026/10/09 18:07:32 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127952026/10/09 18:07:32 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127962026/10/09 18:07:32 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path1518256254/001/nonexistent27972026/10/09 18:07:32 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227982026/10/09 18:07:32 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127992026/10/09 18:07:32 INFO Uploading batch count=228002026/10/09 18:07:32 ERROR Upload failed error="upload failed" count=228012026/10/09 18:07:32 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path1518256254/001/nonexistent28022026/10/09 18:07:32 INFO Uploading batch count=228032026/10/09 18:07:32 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128042026/10/09 18:07:32 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128052026/10/09 18:07:32 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228062026/10/09 18:07:32 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128072026/10/09 18:07:32 ERROR Drain finished with paths left in queue remaining=128082026/10/09 18:07:32 INFO Uploading batch count=228092026/10/09 18:07:32 ERROR Upload failed error="upload failed" count=228102026/10/09 18:07:32 INFO Uploading batch count=228112026/10/09 18:07:32 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128122026/10/09 18:07:32 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228132026/10/09 18:07:32 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128142026/10/09 18:07:32 ERROR Drain finished with paths left in queue remaining=228152026/10/09 18:07:32 ERROR Drain finished with paths left in queue remaining=22816--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2817 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.04s)2818 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.05s)2819 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.05s)28202026/10/09 18:07:32 ERROR Accept failed error="too many open files"28212026/10/09 18:07:32 ERROR Failed to decode request error="read unix /build/hook2109691464/test.sock->@: i/o timeout"28222026/10/09 18:07:32 ERROR Failed to write response error="write unix /build/hook2109691464/test.sock->@: i/o timeout"2823--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)28242026/10/09 18:07:32 ERROR Upload failed error="context canceled" count=228252026/10/09 18:07:32 ERROR Drain finished with paths left in queue remaining=42826--- PASS: TestDrainTimeout (0.29s)28272026/10/09 18:07:32 ERROR Drain finished with paths left in queue remaining=428282026/10/09 18:07:32 ERROR Upload failed error="context canceled" count=228292026/10/09 18:07:32 ERROR Drain finished with paths left in queue remaining=228302026/10/09 18:07:32 ERROR Accept failed error="too many open files"2831--- PASS: TestShutdownFinishesInFlightPush (0.00s)2832 --- PASS: TestShutdownFinishesInFlightPush/completes (0.17s)2833 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.23s)28342026/10/09 18:07:32 ERROR Drain finished with paths left in queue remaining=32835--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2836 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.29s)2837 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.37s)28382026/10/09 18:07:32 ERROR Accept failed error="too many open files"2839--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)2840--- PASS: TestQueueConcurrentWriters (0.71s)28412026/10/09 18:07:33 INFO Uploading batch count=128422026/10/09 18:07:33 INFO Uploading batch count=128432026/10/09 18:07:33 INFO Uploading batch count=128442026/10/09 18:07:33 ERROR Upload failed error="upload failed" count=128452026/10/09 18:07:33 INFO Uploading batch count=128462026/10/09 18:07:33 ERROR Upload failed error="upload failed" count=128472026/10/09 18:07:33 INFO Uploading batch count=128482026/10/09 18:07:33 ERROR Upload failed error="upload failed" count=128492026/10/09 18:07:33 INFO Uploading batch count=128502026/10/09 18:07:33 ERROR Upload failed error="upload failed" count=128512026/10/09 18:07:33 ERROR Drain finished with paths left in queue remaining=12852--- PASS: TestRunNotBlockedByPoisonHead (1.11s)2853--- PASS: TestQueueRemoveLargeClosure (1.57s)2854--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.08s)2855PASS2856Running signing tests...2857=== RUN TestExternalSigner2858=== PAUSE TestExternalSigner2859=== RUN TestExternalSignerWrongPublicKey2860=== PAUSE TestExternalSignerWrongPublicKey2861=== RUN TestExternalSignerErrors2862=== PAUSE TestExternalSignerErrors2863=== RUN TestExternalSignerRestartsAfterCrash2864=== PAUSE TestExternalSignerRestartsAfterCrash2865=== RUN TestExternalSignerProgramErrorKeepsProcess2866=== PAUSE TestExternalSignerProgramErrorKeepsProcess2867=== RUN TestExternalSignerClose2868=== PAUSE TestExternalSignerClose2869=== RUN TestExternalSignerRejectsInvalidPublicKey2870=== PAUSE TestExternalSignerRejectsInvalidPublicKey2871=== RUN TestExternalSignerCancellation2872=== PAUSE TestExternalSignerCancellation2873=== RUN TestGenerateFingerprint2874=== PAUSE TestGenerateFingerprint2875=== RUN TestParseSigningKey2876=== PAUSE TestParseSigningKey2877=== RUN TestSign2878=== PAUSE TestSign2879=== RUN TestSignBatch2880=== PAUSE TestSignBatch2881=== RUN TestNilKeyPublicKey2882=== PAUSE TestNilKeyPublicKey2883=== RUN TestSignErrors2884=== PAUSE TestSignErrors2885=== CONT TestExternalSigner2886=== CONT TestGenerateFingerprint2887=== CONT TestSign2888=== CONT TestNilKeyPublicKey2889=== CONT TestParseSigningKey2890=== CONT TestSignBatch2891=== CONT TestExternalSignerRestartsAfterCrash2892=== CONT TestExternalSignerClose2893=== CONT TestExternalSignerProgramErrorKeepsProcess2894=== CONT TestExternalSignerErrors2895=== RUN TestExternalSignerErrors/null_signatures2896=== PAUSE TestExternalSignerErrors/null_signatures2897=== CONT TestExternalSignerRejectsInvalidPublicKey2898=== RUN TestExternalSignerRejectsInvalidPublicKey/#002899=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002900=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2901=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2902=== CONT TestExternalSignerWrongPublicKey2903=== CONT TestExternalSignerCancellation2904=== CONT TestSignErrors2905=== RUN TestGenerateFingerprint/basic_with_references2906--- PASS: TestNilKeyPublicKey (0.00s)2907=== RUN TestParseSigningKey/valid_32-byte_key2908=== PAUSE TestGenerateFingerprint/basic_with_references2909=== RUN TestExternalSignerErrors/wrong_signature_name2910=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2911=== RUN TestSignErrors/nil_key2912=== RUN TestGenerateFingerprint/no_references2913=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2914=== PAUSE TestGenerateFingerprint/no_references2915=== PAUSE TestParseSigningKey/valid_32-byte_key2916=== PAUSE TestExternalSignerErrors/wrong_signature_name2917=== PAUSE TestSignErrors/nil_key2918=== RUN TestSignErrors/nil_narinfo2919--- PASS: TestSign (0.00s)2920=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2921=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2922=== RUN TestExternalSignerErrors/program_error2923=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2924=== PAUSE TestExternalSignerErrors/program_error2925=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2926=== PAUSE TestSignErrors/nil_narinfo2927=== RUN TestExternalSignerErrors/invalid_JSON2928=== PAUSE TestExternalSignerErrors/invalid_JSON2929=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2930=== RUN TestSignErrors/invalid_narinfo2931=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2932=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2933--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2934=== RUN TestExternalSignerErrors/wrong_id2935=== PAUSE TestSignErrors/invalid_narinfo2936=== PAUSE TestExternalSignerErrors/wrong_id2937=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2938=== RUN TestExternalSignerErrors/missing_signatures2939=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2940=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2941=== RUN TestGenerateFingerprint/invalid_nar_hash_length2942--- PASS: TestExternalSignerClose (0.01s)2943--- PASS: TestSignBatch (0.01s)2944=== RUN TestSignErrors/canceled2945=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2946=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2947--- PASS: TestExternalSignerWrongPublicKey (0.00s)2948=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2949=== PAUSE TestSignErrors/canceled2950=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2951=== CONT TestSignErrors/nil_narinfo2952=== CONT TestSignErrors/canceled2953=== PAUSE TestExternalSignerErrors/missing_signatures2954=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2955=== CONT TestSignErrors/invalid_narinfo2956=== RUN TestParseSigningKey/no_colon2957=== CONT TestExternalSignerRejectsInvalidPublicKey/#002958=== PAUSE TestParseSigningKey/no_colon2959=== CONT TestSignErrors/nil_key2960=== RUN TestExternalSignerErrors/wrong_signature_length2961=== RUN TestGenerateFingerprint/invalid_store_path_prefix2962=== RUN TestParseSigningKey/empty_name2963--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2964 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2965 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2966 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2967 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2968 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2969=== PAUSE TestExternalSignerErrors/wrong_signature_length2970=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2971=== PAUSE TestParseSigningKey/empty_name2972--- PASS: TestSignErrors (0.00s)2973 --- PASS: TestSignErrors/canceled (0.00s)2974 --- PASS: TestSignErrors/nil_narinfo (0.00s)2975 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2976 --- PASS: TestSignErrors/nil_key (0.00s)2977=== RUN TestParseSigningKey/invalid_base642978=== RUN TestExternalSignerErrors/exit_at_startup2979=== PAUSE TestExternalSignerErrors/exit_at_startup2980=== PAUSE TestParseSigningKey/invalid_base642981=== RUN TestGenerateFingerprint/invalid_reference_prefix2982=== RUN TestExternalSignerErrors/exit_on_request2983=== RUN TestParseSigningKey/wrong_length2984=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2985=== PAUSE TestParseSigningKey/wrong_length2986=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2987=== CONT TestParseSigningKey/valid_32-byte_key2988=== CONT TestParseSigningKey/no_colon2989=== CONT TestParseSigningKey/invalid_base642990=== PAUSE TestExternalSignerErrors/exit_on_request2991=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2992=== RUN TestExternalSignerErrors/wrong_shape2993=== CONT TestGenerateFingerprint/no_references2994=== CONT TestGenerateFingerprint/invalid_store_path_prefix2995=== CONT TestGenerateFingerprint/invalid_reference_prefix2996=== CONT TestGenerateFingerprint/invalid_nar_hash_length2997=== CONT TestParseSigningKey/empty_name2998=== CONT TestGenerateFingerprint/basic_with_references2999=== CONT TestParseSigningKey/wrong_length3000=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name3001=== PAUSE TestExternalSignerErrors/wrong_shape3002=== RUN TestExternalSignerErrors/unrequested_key3003--- PASS: TestGenerateFingerprint (0.01s)3004 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)3005 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)3006 --- PASS: TestGenerateFingerprint/no_references (0.00s)3007 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)3008 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)3009 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)3010 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)3011=== PAUSE TestExternalSignerErrors/unrequested_key3012=== RUN TestExternalSignerErrors/missing_signature_name3013=== PAUSE TestExternalSignerErrors/missing_signature_name3014=== RUN TestExternalSignerErrors/null3015=== PAUSE TestExternalSignerErrors/null3016=== RUN TestExternalSignerErrors/wrong_signatures_shape3017=== PAUSE TestExternalSignerErrors/wrong_signatures_shape3018=== RUN TestExternalSignerErrors/too_few_signatures3019--- PASS: TestParseSigningKey (0.01s)3020 --- PASS: TestParseSigningKey/no_colon (0.00s)3021 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)3022 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)3023 --- PASS: TestParseSigningKey/empty_name (0.00s)3024 --- PASS: TestParseSigningKey/wrong_length (0.00s)3025 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)3026=== PAUSE TestExternalSignerErrors/too_few_signatures3027=== RUN TestExternalSignerErrors/invalid_signature_base643028=== PAUSE TestExternalSignerErrors/invalid_signature_base643029=== CONT TestExternalSignerErrors/null_signatures3030=== CONT TestExternalSignerErrors/exit_on_request3031=== CONT TestExternalSignerErrors/wrong_signature_name3032=== CONT TestExternalSignerErrors/exit_at_startup3033=== CONT TestExternalSignerErrors/invalid_signature_base643034=== CONT TestExternalSignerErrors/too_few_signatures3035=== CONT TestExternalSignerErrors/wrong_signatures_shape3036=== CONT TestExternalSignerErrors/null3037=== CONT TestExternalSignerErrors/unrequested_key3038=== CONT TestExternalSignerErrors/missing_signatures3039=== CONT TestExternalSignerErrors/wrong_signature_length3040=== CONT TestExternalSignerErrors/wrong_shape3041=== CONT TestExternalSignerErrors/program_error3042=== CONT TestExternalSignerErrors/missing_signature_name3043=== CONT TestExternalSignerErrors/invalid_JSON3044=== CONT TestExternalSignerErrors/wrong_id3045--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)3046--- PASS: TestExternalSigner (0.02s)3047--- PASS: TestExternalSignerErrors (0.01s)3048 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)3049 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)3050 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)3051 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)3052 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)3053 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)3054 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)3055 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)3056 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)3057 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)3058 --- PASS: TestExternalSignerErrors/null (0.01s)3059 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)3060 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)3061 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)3062 --- PASS: TestExternalSignerErrors/program_error (0.01s)3063 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)3064--- PASS: TestExternalSignerCancellation (0.02s)3065PASS3066Running OpenBao signer tests...3067=== RUN TestSign3068=== PAUSE TestSign3069=== RUN TestSignErrors3070=== PAUSE TestSignErrors3071=== RUN TestServe3072=== PAUSE TestServe3073=== RUN TestServeRejectsGarbage3074=== PAUSE TestServeRejectsGarbage3075=== CONT TestSign3076=== CONT TestSignErrors3077=== CONT TestServeRejectsGarbage3078=== CONT TestServe3079=== RUN TestSignErrors/no_prefix3080--- PASS: TestServeRejectsGarbage (0.00s)3081=== PAUSE TestSignErrors/no_prefix3082=== RUN TestSignErrors/invalid_base643083=== PAUSE TestSignErrors/invalid_base643084=== RUN TestSignErrors/http_error3085=== PAUSE TestSignErrors/http_error3086--- PASS: TestServe (0.00s)3087=== RUN TestSignErrors/invalid_json3088=== PAUSE TestSignErrors/invalid_json3089=== CONT TestSignErrors/invalid_base643090=== CONT TestSignErrors/invalid_json3091=== CONT TestSignErrors/http_error3092=== CONT TestSignErrors/no_prefix3093--- PASS: TestSign (0.01s)3094--- PASS: TestSignErrors (0.00s)3095 --- PASS: TestSignErrors/no_prefix (0.00s)3096 --- PASS: TestSignErrors/invalid_base64 (0.00s)3097 --- PASS: TestSignErrors/invalid_json (0.00s)3098 --- PASS: TestSignErrors/http_error (0.00s)3099PASS3100Running niks3-hook command tests...3101=== RUN TestServeSecondSignalEndsDrain3102=== PAUSE TestServeSecondSignalEndsDrain3103=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown3104=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown3105=== CONT TestServeSecondSignalEndsDrain3106=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown3107--- PASS: TestServeSecondSignalEndsDrain (0.08s)31082026/10/09 18:07:41 INFO Upload queue status pending=131092026/10/09 18:07:41 INFO Uploading batch count=13110--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.13s)3111PASS3112Running rate limiter tests...3113=== RUN TestAdaptiveRateLimiter_ThreadSafety3114=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3115=== CONT TestAdaptiveRateLimiter_ThreadSafety31162026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=112.7357000000000731172026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=78.9149900000000531182026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=55.2404930000000331192026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=38.6683451000000231202026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=27.0678415700000131212026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=18.94748909900000631222026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=13.26324236930000431232026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=9.28426965851000231242026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=6.49898876095700131252026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531262026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531272026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531282026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531292026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531302026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531312026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531322026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531332026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531342026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531352026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531362026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531372026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531382026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531392026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531402026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531412026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531422026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531432026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531442026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531452026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531462026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531472026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531482026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531492026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531502026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531512026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531522026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531532026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531542026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531552026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531562026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531572026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531582026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531592026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531602026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531612026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531622026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531632026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531642026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531652026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531662026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531672026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531682026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531692026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531702026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=6.200463500000001531712026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531722026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531732026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531742026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531752026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531762026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531772026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531782026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531792026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531802026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531812026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531822026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531832026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531842026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531852026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531862026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531872026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531882026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531892026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=12.0829492503758631902026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=8.45806447526310231912026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=5.92064513268417131922026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531932026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531942026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=5.12435000000000131952026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531962026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531972026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531982026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=531992026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=532002026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=532012026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=532022026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=532032026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=532042026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=532052026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=532062026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=5.63678500000000132072026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=532082026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=532092026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=532102026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=532112026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=532122026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=532132026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=532142026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=532152026/10/09 18:07:42 WARN Rate limiter backed off name=test rate=53216--- PASS: TestAdaptiveRateLimiter_ThreadSafety (0.09s)3217PASS