niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #437
· 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_FailedPartBufferNotReused22=== PAUSE TestUploadMultipart_FailedPartBufferNotReused23=== RUN TestUploadMultipart_ProducerErrorIsNotEOF24=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestUploadMultipart_SupersededByPeer28=== PAUSE TestUploadMultipart_SupersededByPeer29=== RUN TestDumpPathCaseHackMatchesNix30--- PASS: TestDumpPathCaseHackMatchesNix (0.06s)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 121 of 32768000 bytes45--- PASS: TestDumpPathWriterErrorStopsReading (0.55s)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 TestRetryTimeoutOutlastsMaxRetries79=== PAUSE TestRetryTimeoutOutlastsMaxRetries80=== RUN TestDoWithRetry_FinalResponseBodyReadable81=== PAUSE TestDoWithRetry_FinalResponseBodyReadable82=== RUN TestShellSplit83=== PAUSE TestShellSplit84=== RUN TestShellSplitErrors85=== PAUSE TestShellSplitErrors86=== RUN TestStreamPushReportsEveryPath87=== PAUSE TestStreamPushReportsEveryPath88=== RUN TestStreamPushBatchesUnderLoad89=== PAUSE TestStreamPushBatchesUnderLoad90=== RUN TestStreamPushIsolatesFailures91=== PAUSE TestStreamPushIsolatesFailures92=== RUN TestStreamPushGivesUpOnDeadServer93=== PAUSE TestStreamPushGivesUpOnDeadServer94=== RUN TestStreamPushRequestLine95=== PAUSE TestStreamPushRequestLine96=== RUN TestStreamPushReportsSignatures97=== PAUSE TestStreamPushReportsSignatures98=== RUN TestStreamPushReportsSkippedPaths99=== PAUSE TestStreamPushReportsSkippedPaths100=== RUN TestClientSignaturesByStorePath101=== PAUSE TestClientSignaturesByStorePath102=== RUN TestStreamPushStopsWhenCanceled103=== PAUSE TestStreamPushStopsWhenCanceled104=== RUN TestStreamPushStopsOnCancel105=== PAUSE TestStreamPushStopsOnCancel106=== RUN TestStreamPushStartsNothingOnSlotFreedByCancel107=== PAUSE TestStreamPushStartsNothingOnSlotFreedByCancel108=== 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 TestRegisterUploadedObjectReusesConnections137=== CONT TestStreamPushStopsOnCancel138=== RUN TestStreamPushStopsOnCancel/waiting_for_input139=== CONT TestScriptTokenEmptyCommand140=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input141--- PASS: TestScriptTokenEmptyCommand (0.00s)142=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot143=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess144=== CONT TestScriptTokenScriptFails145=== CONT TestClientSignaturesByStorePath146=== CONT TestScriptTokenBadJSON147=== CONT TestStreamPushStopsWhenCanceled148=== CONT TestScriptTokenDoesNotWaitForItsChildren149=== CONT TestStreamPushReportsSignatures150=== CONT TestScriptTokenEmptyToken151=== CONT TestStreamPushRequestLine152=== CONT TestScriptTokenCachesUntilRefresh153=== CONT TestStreamPushGivesUpOnDeadServer154=== CONT TestFileTokenMissing155=== CONT TestScriptTokenNoExpiryRerunsEveryCall156=== CONT TestStaticToken157=== CONT TestConvertHashToNix32158=== CONT TestParsePathInfoJSON159=== CONT TestParsePathInfoJSONMultiplePaths160=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths161=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer162=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths163=== CONT TestSetClientTLSErrors164=== CONT TestPathInfoHashCompatibility165=== CONT TestRetryTimeoutOutlastsMaxRetries166=== CONT TestStreamPushReportsSkippedPaths167=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot168--- PASS: TestClientSignaturesByStorePath (0.00s)169=== CONT TestSetClientTLS170=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs171=== CONT TestEncodeNixBase32172=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun173=== CONT TestPathInfoCACompatibility174=== RUN TestPathInfoCACompatibility/null_ca_field175=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths176=== CONT TestCaseHackSuffix177=== CONT TestSupersededNARStillUploadsListing178=== RUN TestParsePathInfoJSON/Nix_format179=== RUN TestConvertHashToNix32/SRI_format_to_Nix32180=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry181=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)182=== CONT TestShellSplitErrors183=== CONT TestShellSplit184=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot185--- PASS: TestStreamPushStopsWhenCanceled (0.00s)186=== RUN TestEncodeNixBase32/test_string_hash187=== PAUSE TestPathInfoCACompatibility/null_ca_field188=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths189=== CONT TestResolveStorePath190=== PAUSE TestParsePathInfoJSON/Nix_format191=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot192=== RUN TestParsePathInfoJSON/Lix_format193=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)194=== PAUSE TestParsePathInfoJSON/Lix_format195=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot196=== RUN TestParsePathInfoJSON/empty_input197=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot198=== CONT TestStreamPushIsolatesFailures199=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32200--- PASS: TestShellSplitErrors (0.00s)201=== PAUSE TestEncodeNixBase32/test_string_hash202=== PAUSE TestParsePathInfoJSON/empty_input203=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon204=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot205=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot206=== RUN TestSupersededNARStillUploadsListing/small_NAR207--- PASS: TestScriptTokenScriptFails (0.01s)208=== PAUSE TestSupersededNARStillUploadsListing/small_NAR209=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon210--- PASS: TestStaticToken (0.00s)211--- PASS: TestFileTokenMissing (0.00s)212--- PASS: TestStreamPushReportsSkippedPaths (0.00s)213--- PASS: TestStreamPushReportsSignatures (0.01s)214--- PASS: TestScriptTokenEmptyToken (0.02s)215--- PASS: TestScriptTokenBadJSON (0.02s)216--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)217--- PASS: TestShellSplit (0.00s)218=== CONT TestGetStorePathHash219=== RUN TestPathInfoCACompatibility/old_string_format_-_text220=== RUN TestGetStorePathHash/valid_store_path221=== PAUSE TestGetStorePathHash/valid_store_path222=== RUN TestConvertHashToNix32/already_Nix32_format223=== RUN TestEncodeNixBase32/empty_input224=== PAUSE TestConvertHashToNix32/already_Nix32_format225=== RUN TestParsePathInfoJSON/whitespace_only226=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text227=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs228=== CONT TestDoServerRequestAttachesToken229--- PASS: TestResolveStorePath (0.00s)230=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken231=== RUN TestSetClientTLSErrors/missing_cert_file232=== PAUSE TestEncodeNixBase32/empty_input233=== PAUSE TestSetClientTLSErrors/missing_cert_file234=== RUN TestConvertHashToNix32/invalid_format235=== RUN TestSetClientTLSErrors/missing_key_file236=== CONT TestSetClientTLSDoesNotMutateDefaultTransport237=== PAUSE TestSetClientTLSErrors/missing_key_file238=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive239=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout240=== PAUSE TestConvertHashToNix32/invalid_format241=== PAUSE TestParsePathInfoJSON/whitespace_only242=== RUN TestSupersededNARStillUploadsListing/dump_cut_short243=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken244=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI245=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout246=== RUN TestSetClientTLSErrors/missing_ca_file247=== CONT TestDumpPathSingleFile248--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.03s)249=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short250=== PAUSE TestSetClientTLSErrors/missing_ca_file251=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent252=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive253=== CONT TestCompletePendingClosure_NotFoundWithoutKey254=== CONT TestFileTokenReadsAndCaches255=== RUN TestGetStorePathHash/basename_without_hyphen_should_error256=== RUN TestParsePathInfoJSON/invalid_JSON257=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI258--- PASS: TestStreamPushGivesUpOnDeadServer (0.03s)259=== CONT TestFileTokenEmpty260=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error261=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512262=== RUN TestPathInfoCACompatibility/new_structured_format_-_text263=== CONT TestRateLimiterFeedback264=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails265=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text266=== PAUSE TestParsePathInfoJSON/invalid_JSON267=== RUN TestRateLimiterFeedback/429_enables_limiter268=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier269=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier270=== CONT TestUploadMultipart_SupersededByPeer271=== RUN TestUploadMultipart_SupersededByPeer/exists272=== PAUSE TestUploadMultipart_SupersededByPeer/exists273=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up274=== PAUSE TestRateLimiterFeedback/429_enables_limiter275=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure276--- PASS: TestStreamPushIsolatesFailures (0.01s)277=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error278=== CONT TestDumpPathWriterError279=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512280=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails281=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method282=== RUN TestSetClientTLSErrors/invalid_ca_file283=== CONT TestTruncatedNARDumpIsNotCompleted284=== RUN TestSetClientTLS/rejects_connection_without_client_cert285--- PASS: TestFileTokenEmpty (0.00s)286=== RUN TestUploadMultipart_SupersededByPeer/missing287=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error288=== CONT TestEncodeNixBase32WithRealHash289=== RUN TestRateLimiterFeedback/503_enables_limiter290=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up291=== CONT TestDumpPathMatchesNix292=== CONT TestStreamPushBatchesUnderLoad293=== RUN TestStreamPushBatchesUnderLoad/together294=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert295--- PASS: TestFileTokenReadsAndCaches (0.00s)296=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA297=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA298=== RUN TestSetClientTLS/preserves_debug_logging_transport299=== PAUSE TestSetClientTLS/preserves_debug_logging_transport300--- PASS: TestDoServerRequestAttachesToken (0.01s)301=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method302=== PAUSE TestSetClientTLSErrors/invalid_ca_file303--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.03s)304--- PASS: TestDumpPathSingleFile (0.15s)305=== CONT TestFilterOversizedClosures306=== PAUSE TestUploadMultipart_SupersededByPeer/missing307=== RUN TestFilterOversizedClosures/no_limit_keeps_everything308=== CONT TestDoWithRetry_FinalResponseBodyReadable309=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything310=== CONT TestUploadMultipart_FailedPartBufferNotReused311--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.02s)312--- PASS: TestEncodeNixBase32WithRealHash (0.00s)313--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.17s)314--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.02s)315=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica316=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error317=== PAUSE TestRateLimiterFeedback/503_enables_limiter318=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier319=== CONT TestUploadMultipart_ProducerErrorIsNotEOF320=== CONT TestStreamPushReportsEveryPath321=== PAUSE TestStreamPushBatchesUnderLoad/together322=== CONT TestPartSizeForNAR323=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths324=== CONT TestStreamPushStartsNothingOnSlotFreedByCancel325=== CONT TestDoWithRetry_BodyReplayedViaGetBody326=== CONT TestUploadMultipart_PartsInParallel327=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped328--- PASS: TestCaseHackSuffix (0.03s)329=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error330=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier331=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part332=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter333=== RUN TestPartSizeForNAR/zero_stays_at_minimum334=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time335=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped336--- PASS: TestStreamPushReportsEveryPath (0.00s)337=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths338=== CONT TestEncodeNixBase32/empty_input339=== CONT TestEncodeNixBase32/test_string_hash340=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter341=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum342=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client343=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part344=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary345=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time346=== RUN TestFilterOversizedClosures/all_closures_skipped347=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client348=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot349=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken350=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter351--- PASS: TestEncodeNixBase32 (0.01s)352 --- PASS: TestEncodeNixBase32/empty_input (0.00s)353 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)354=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter355=== RUN TestPartSizeForNAR/small_stays_at_minimum356=== PAUSE TestPartSizeForNAR/small_stays_at_minimum357=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary358=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum359=== PAUSE TestFilterOversizedClosures/all_closures_skipped360=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot361=== CONT TestStreamPushStopsOnCancel/waiting_for_input362=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot363=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client364=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot365--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.02s)366=== CONT TestConvertHashToNix32/invalid_format367=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum368=== CONT TestConvertHashToNix32/already_Nix32_format369=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client370=== CONT TestConvertHashToNix32/SRI_format_to_Nix32371--- PASS: TestParsePathInfoJSONMultiplePaths (0.02s)372 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)373 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)374=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts375=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout376=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs377=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts378=== CONT TestParsePathInfoJSON/invalid_JSON379=== RUN TestPartSizeForNAR/1_TiB380--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)381=== CONT TestParsePathInfoJSON/empty_input382=== CONT TestParsePathInfoJSON/whitespace_only383--- PASS: TestConvertHashToNix32 (0.02s)384 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)385 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)386 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)387=== CONT TestParsePathInfoJSON/Lix_format388=== CONT TestParsePathInfoJSON/Nix_format389=== PAUSE TestPartSizeForNAR/1_TiB390=== RUN TestPartSizeForNAR/5_TiB_S3_max_object391=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object392=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)393=== RUN TestPartSizeForNAR/capped_at_5_GiB394--- PASS: TestParsePathInfoJSON (0.03s)395 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)396 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)397 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)398 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)399 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)400=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512401=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon402=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI403=== CONT TestSupersededNARStillUploadsListing/small_NAR404=== PAUSE TestPartSizeForNAR/capped_at_5_GiB405--- PASS: TestPathInfoHashCompatibility (0.04s)406 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)407 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)408 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)409 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)410=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails411=== CONT TestSupersededNARStillUploadsListing/dump_cut_short412--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.04s)413=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA414--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.22s)415=== CONT TestSetClientTLSErrors/missing_cert_file416--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.18s)417=== CONT TestSetClientTLS/preserves_debug_logging_transport418=== CONT TestSetClientTLS/rejects_connection_without_client_cert419=== CONT TestPathInfoCACompatibility/null_ca_field420=== CONT TestUploadMultipart_SupersededByPeer/missing421=== CONT TestPathInfoCACompatibility/new_structured_format_-_text422=== CONT TestSetClientTLSErrors/invalid_ca_file423=== CONT TestSetClientTLSErrors/missing_ca_file424--- PASS: TestStreamPushStopsOnCancel (0.03s)425 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.21s)426 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.21s)427 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.21s)428 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.21s)429 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.21s)430 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.21s)431=== CONT TestUploadMultipart_SupersededByPeer/exists432=== CONT TestSetClientTLSErrors/missing_key_file433=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error434=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error435=== CONT TestPathInfoCACompatibility/old_string_format_-_text436=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive437=== CONT TestRateLimiterFeedback/503_enables_limiter438=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method439--- PASS: TestSetClientTLSErrors (0.18s)440 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)441 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)442 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)443 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)444=== CONT TestGetStorePathHash/valid_store_path445=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time446=== CONT TestStreamPushBatchesUnderLoad/together447=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter448=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part449=== CONT TestGetStorePathHash/basename_without_hyphen_should_error450=== CONT TestFilterOversizedClosures/all_closures_skipped451=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter452=== CONT TestRateLimiterFeedback/429_enables_limiter453--- PASS: TestPathInfoCACompatibility (0.16s)454 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)455 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)456 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)457 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)458 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)459=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary460=== CONT TestFilterOversizedClosures/no_limit_keeps_everything461=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client462=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier463=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client464=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped465=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier466=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up467=== CONT TestPartSizeForNAR/small_stays_at_minimum468--- PASS: TestUploadMultipart_SupersededByPeer (0.15s)469 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.17s)470 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)471=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts472--- PASS: TestGetStorePathHash (0.16s)473 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)474 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)475 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)476 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)477=== CONT TestPartSizeForNAR/capped_at_5_GiB478=== CONT TestPartSizeForNAR/5_TiB_S3_max_object479=== CONT TestPartSizeForNAR/zero_stays_at_minimum480=== CONT TestPartSizeForNAR/1_TiB481--- PASS: TestFilterOversizedClosures (0.02s)482 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)483 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)484 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)485=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum486--- PASS: TestStreamPushBatchesUnderLoad (0.02s)487 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)488 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)489--- PASS: TestRateLimiterFeedback (0.17s)490 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)491 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)492 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)493 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)494--- PASS: TestPartSizeForNAR (0.03s)495 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)496 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)497 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)498 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)499 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)500 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)501 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)502--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.18s)503 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.01s)504 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.01s)505 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.01s)506 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.01s)507 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.01s)508--- PASS: TestDumpPathWriterError (0.39s)509--- PASS: TestSetClientTLS (0.17s)510 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.03s)511 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)512 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.23s)513--- PASS: TestStreamPushStartsNothingOnSlotFreedByCancel (0.29s)514--- PASS: TestStreamPushRequestLine (0.56s)515--- PASS: TestRegisterUploadedObjectReusesConnections (0.57s)516--- PASS: TestDumpPathMatchesNix (0.60s)517--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.02s)518 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.24s)519 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.29s)520--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)521--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.01s)522--- PASS: TestTruncatedNARDumpIsNotCompleted (1.35s)523--- PASS: TestUploadMultipart_PartsInParallel (1.33s)524--- PASS: TestSupersededNARStillUploadsListing (0.03s)525 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.20s)526 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.23s)527 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.30s)528--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.40s)529--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.03s)530 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.01s)531 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.20s)532PASS533Running server tests...534The files belonging to this database system will be owned by user "nixbld".535This user must also own the server process.536537The database cluster will be initialized with locale "C".538The default database encoding has accordingly been set to "SQL_ASCII".539The default text search configuration will be set to "english".540541Data page checksums are enabled.542543creating directory /build/postgres4045361108/data ... ok544creating subdirectories ... ok545selecting dynamic shared memory implementation ... posix546selecting default "max_connections" ... 100547selecting default "shared_buffers" ... 128MB548selecting default time zone ... UTC549creating configuration files ... ok550running bootstrap script ... ok551performing post-bootstrap initialization ... ok552syncing data to disk ... ok553554initdb: warning: enabling "trust" authentication for local connections555initdb: 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.556557Success. You can now start the database server using:558559 pg_ctl -D /build/postgres4045361108/data -l logfile start560561/build/postgres4045361108:5432 - no response5622026-10-26 22:36:11.189 UTC [168] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit5632026-10-26 22:36:11.190 UTC [168] LOG: listening on Unix socket "/build/postgres4045361108/.s.PGSQL.5432"5642026-10-26 22:36:11.196 UTC [175] LOG: database system was shut down at 2026-10-26 22:36:10 UTC5652026-10-26 22:36:11.199 UTC [168] LOG: database system is ready to accept connections566/build/postgres4045361108:5432 - accepting connections567{"timestamp":"2026-10-26T22:36:11.501463839Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"3cbf348e-25ad-46e4-abfc-6a5d57e8e119","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":1,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(400)"}568=== RUN TestService_AuthMiddleware569=== PAUSE TestService_AuthMiddleware570=== RUN TestService_AuthMiddleware_MTLSProxyHeader571=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader572=== RUN TestService_AuthMiddleware_MTLSBoundSubjects573=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects574=== RUN TestService_ReadAuthMiddleware575=== PAUSE TestService_ReadAuthMiddleware576=== RUN TestService_AuthMiddleware_OIDC577=== PAUSE TestService_AuthMiddleware_OIDC578=== RUN TestService_RequireScope_OIDC579=== PAUSE TestService_RequireScope_OIDC580=== RUN TestService_ReadScope_PublicByDefault581=== PAUSE TestService_ReadScope_PublicByDefault582=== RUN TestCacheConfigHandler583=== PAUSE TestCacheConfigHandler584=== RUN TestCacheStatsHandler585=== PAUSE TestCacheStatsHandler586=== RUN TestClientCADerivations587=== PAUSE TestClientCADerivations588=== RUN TestClientErrorHandling589=== PAUSE TestClientErrorHandling590=== RUN TestClientIntegration591=== PAUSE TestClientIntegration592=== RUN TestClientMultipleUploads593=== PAUSE TestClientMultipleUploads594=== RUN TestClientWithDependencies595=== PAUSE TestClientWithDependencies596=== RUN TestClientSharedPathCommittedMidPush597=== PAUSE TestClientSharedPathCommittedMidPush598=== RUN TestPinProtectsFromGC599=== PAUSE TestPinProtectsFromGC600=== RUN TestClientPushesUseOnePush601=== PAUSE TestClientPushesUseOnePush602=== RUN TestClientFallsBackToClosures603=== PAUSE TestClientFallsBackToClosures604=== RUN TestDeleteClosuresRacingPins605=== PAUSE TestDeleteClosuresRacingPins606=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock607=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock608=== RUN TestResolveDBConnectionString609=== PAUSE TestResolveDBConnectionString610=== RUN TestConnectWaitsForAPeerMigration611=== PAUSE TestConnectWaitsForAPeerMigration612=== RUN TestConnectSerialisesConcurrentMigrations613=== PAUSE TestConnectSerialisesConcurrentMigrations614=== RUN TestLeadElectsOneAndHandsOver615=== PAUSE TestLeadElectsOneAndHandsOver616=== RUN TestLeadIncumbentWinsAfterRestart6172026/10/26 22:36:11 INFO lead: acquired remote=192.0.2.1:12346182026/10/26 22:36:12 INFO lead: released remote=192.0.2.1:12346192026/10/26 22:36:12 INFO lead: acquired remote=192.0.2.1:12346202026/10/26 22:36:13 INFO lead: released remote=192.0.2.1:1234621--- PASS: TestLeadIncumbentWinsAfterRestart (1.92s)622=== RUN TestLeadIncumbentAnnouncesAtOnce623=== PAUSE TestLeadIncumbentAnnouncesAtOnce624=== RUN TestLeadEndsOnShutdown625=== PAUSE TestLeadEndsOnShutdown626=== RUN TestLeadEndsWhenItsConnectionHangs6272026/10/26 22:36:13 INFO lead: acquired remote=192.0.2.1:12346282026-10-26 22:36:15.065 UTC [619] FATAL: terminating connection due to administrator command6292026/10/26 22:36:15 INFO lead: acquired remote=192.0.2.1:12346302026/10/26 22:36:16 WARN lead: lock connection lost error="timeout: context deadline exceeded"6312026/10/26 22:36:16 INFO lead: released remote=192.0.2.1:12346322026/10/26 22:36:16 INFO lead: released remote=192.0.2.1:1234633--- PASS: TestLeadEndsWhenItsConnectionHangs (3.15s)634=== RUN TestGCAdvisoryLockBlocksConcurrentRun635=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun636=== RUN TestGCBugBareHashReferences637=== PAUSE TestGCBugBareHashReferences638=== RUN TestGCMetrics639=== PAUSE TestGCMetrics640=== RUN TestPushDedupSurvivesConcurrentGC641=== PAUSE TestPushDedupSurvivesConcurrentGC642=== RUN TestDeduplicatedObjectsRecordedAsPending643=== PAUSE TestDeduplicatedObjectsRecordedAsPending644=== RUN TestGCSweepSkipsPendingObjects645=== PAUSE TestGCSweepSkipsPendingObjects646=== RUN TestTombstonedObjectOfferedWithoutWaiting647=== PAUSE TestTombstonedObjectOfferedWithoutWaiting648=== RUN TestGCSweepDeliversEachKeyOnce649=== PAUSE TestGCSweepDeliversEachKeyOnce650=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection651=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection652=== RUN TestForceGCDuringPushOffersSweptObject653=== PAUSE TestForceGCDuringPushOffersSweptObject654=== RUN TestFailedS3DeleteKeepsTombstone655=== PAUSE TestFailedS3DeleteKeepsTombstone656=== RUN TestSweepSkipsRowsLockedByPush657=== PAUSE TestSweepSkipsRowsLockedByPush658=== RUN TestRegisterCompletedObjectNeedsPendingRow659=== PAUSE TestRegisterCompletedObjectNeedsPendingRow660=== RUN TestGetExistingObjectsLocksRows661=== PAUSE TestGetExistingObjectsLocksRows662=== RUN TestSweepRechecksPendingAfterLocking663=== PAUSE TestSweepRechecksPendingAfterLocking664=== RUN TestPushWaitsForSweepHoldingRow665=== PAUSE TestPushWaitsForSweepHoldingRow666=== RUN TestCommitRacingPendingCleanupKeepsObjects667=== PAUSE TestCommitRacingPendingCleanupKeepsObjects668=== RUN TestGCEndsOnShutdown669=== PAUSE TestGCEndsOnShutdown670=== RUN TestGCTaskStore_StartNew671=== PAUSE TestGCTaskStore_StartNew672=== RUN TestGCTaskStore_DeduplicateSameParams673=== PAUSE TestGCTaskStore_DeduplicateSameParams674=== RUN TestGCTaskStore_ConflictDifferentParams675=== PAUSE TestGCTaskStore_ConflictDifferentParams676=== RUN TestGCTaskStore_GetEmpty677=== PAUSE TestGCTaskStore_GetEmpty678=== RUN TestGCTaskStore_GetReturnsLatest679=== PAUSE TestGCTaskStore_GetReturnsLatest680=== RUN TestGCTaskStore_CompletedAllowsNewTask681=== PAUSE TestGCTaskStore_CompletedAllowsNewTask682=== RUN TestGCTaskStore_PhaseUpdates683=== PAUSE TestGCTaskStore_PhaseUpdates684=== RUN TestGCTaskStore_Fail685=== PAUSE TestGCTaskStore_Fail686=== RUN TestGracefulShutdownDrainsInflight687=== PAUSE TestGracefulShutdownDrainsInflight688=== RUN TestService_healthCheckHandler689=== PAUSE TestService_healthCheckHandler690=== RUN TestService_readinessHandler691=== PAUSE TestService_readinessHandler692=== RUN TestGenerateLandingPage693=== PAUSE TestGenerateLandingPage694=== RUN TestChildrenInheritRaisedFileLimit695=== PAUSE TestChildrenInheritRaisedFileLimit696=== RUN TestCacheConfigHandlerMaxNarSize697=== PAUSE TestCacheConfigHandlerMaxNarSize698=== RUN TestCreatePendingClosureRejectsOversizedNAR699=== PAUSE TestCreatePendingClosureRejectsOversizedNAR700=== RUN TestNARDeduplicationMetadataUploadBug701=== PAUSE TestNARDeduplicationMetadataUploadBug702=== RUN TestMetricsInventory703=== PAUSE TestMetricsInventory704=== RUN TestMetricsCommit705=== PAUSE TestMetricsCommit706=== RUN TestService_NativeMTLS707=== PAUSE TestService_NativeMTLS708=== RUN TestServerTLSConfig709=== PAUSE TestServerTLSConfig710=== RUN TestMultipartCleanup711=== PAUSE TestMultipartCleanup712=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded713=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded714=== RUN TestPendingCleanupUsesOneCutoff715=== PAUSE TestPendingCleanupUsesOneCutoff716=== RUN TestPendingClosureFailureTracksEveryUpload717=== PAUSE TestPendingClosureFailureTracksEveryUpload718=== RUN TestPendingClosureFailureAbortsItsUploads719=== PAUSE TestPendingClosureFailureAbortsItsUploads720=== RUN TestObjectStatsTrigger721=== PAUSE TestObjectStatsTrigger722=== RUN TestObjectStatsUpdatedOncePerCommit723=== PAUSE TestObjectStatsUpdatedOncePerCommit724=== RUN TestReconnectLeavesObjectsUnlocked725=== PAUSE TestReconnectLeavesObjectsUnlocked726=== RUN TestOrphanedObjectsGC727=== PAUSE TestOrphanedObjectsGC728=== RUN TestOrphanedObjectsGCStressTest729=== PAUSE TestOrphanedObjectsGCStressTest730=== RUN TestCreatePin_ReservedPins731=== PAUSE TestCreatePin_ReservedPins732=== RUN TestConcurrentPinUpdatesAgree733=== PAUSE TestConcurrentPinUpdatesAgree734=== RUN TestCreatePinRejectsBadInput735=== PAUSE TestCreatePinRejectsBadInput736=== RUN TestDeletePinKeepsRowWhenS3Fails737=== PAUSE TestDeletePinKeepsRowWhenS3Fails738=== RUN TestPresentReportsOnlyClosureRoots739=== PAUSE TestPresentReportsOnlyClosureRoots740=== RUN TestPresentRefreshesOnlyStaleClosures741=== PAUSE TestPresentRefreshesOnlyStaleClosures742=== RUN TestPresentNotReportedWhileGCDeletesClosure743=== PAUSE TestPresentNotReportedWhileGCDeletesClosure744=== RUN TestParseSingleRange745=== PAUSE TestParseSingleRange746=== RUN TestProxyHeadersOnlyTrustedOnSocket7472026/10/26 22:36:16 INFO Starting HTTP server address=proxy.sock7482026/10/26 22:36:16 INFO Starting HTTP server address=127.0.0.1:390157492026/10/26 22:36:16 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7502026/10/26 22:36:16 INFO Shutdown signal received, draining in-flight requests timeout=10s751--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.15s)752=== RUN TestIsValidCachePath753=== PAUSE TestIsValidCachePath754=== RUN TestReadProxyNarinfo755=== PAUSE TestReadProxyNarinfo756=== RUN TestReadProxyNarinfoAlreadyDecompressed757=== PAUSE TestReadProxyNarinfoAlreadyDecompressed758=== RUN TestReadProxyContentNegotiation759=== PAUSE TestReadProxyContentNegotiation760=== RUN TestReadProxyNarStreaming761=== PAUSE TestReadProxyNarStreaming762=== RUN TestReadProxy404And429763=== PAUSE TestReadProxy404And429764=== RUN TestReadProxyInvalidPath765=== PAUSE TestReadProxyInvalidPath766=== RUN TestReadProxyHead767=== PAUSE TestReadProxyHead768=== RUN TestReadProxyOutlastsServerWriteTimeout769=== PAUSE TestReadProxyOutlastsServerWriteTimeout770=== RUN TestReadProxyConditionalGet771=== PAUSE TestReadProxyConditionalGet772=== RUN TestReadProxyRootRedirectsToIndexHTML773=== PAUSE TestReadProxyRootRedirectsToIndexHTML774=== RUN TestReadProxyDisabled775=== PAUSE TestReadProxyDisabled776=== RUN TestReadRedirectNar777=== PAUSE TestReadRedirectNar778=== RUN TestReadRedirectKeepsNarinfoProxied779=== PAUSE TestReadRedirectKeepsNarinfoProxied780=== RUN TestReadProxyRangeRequest781=== PAUSE TestReadProxyRangeRequest782=== RUN TestReadRedirectUsesPublicS3URL783=== PAUSE TestReadRedirectUsesPublicS3URL784=== RUN TestPush_OverlappingRootsStoreOneRowPerKey785=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey786=== RUN TestPush_CompleteCommitsEveryRoot787=== PAUSE TestPush_CompleteCommitsEveryRoot788=== RUN TestPush_RepeatedRootCommitsOnce789=== PAUSE TestPush_RepeatedRootCommitsOnce790=== RUN TestPush_CompleteWaitsForCleanupOfThePush791=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush792=== RUN TestPush_RootsAreLockedInByteOrder793=== PAUSE TestPush_RootsAreLockedInByteOrder794=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit795=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit796=== RUN TestPush_RejectsBadRequests797=== PAUSE TestPush_RejectsBadRequests798=== RUN TestPush_SignsNarinfosOfItsPendingObjects799=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects800=== RUN TestRedundantMultipartUpload801=== PAUSE TestRedundantMultipartUpload802=== RUN TestCompleteMultipartUpload_ErrorButObjectExists803=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists804=== RUN TestCompletedNarNotReofferedAcrossClosures805=== PAUSE TestCompletedNarNotReofferedAcrossClosures806=== RUN TestPresignedUploadRegisteredBeforeCommit807=== PAUSE TestPresignedUploadRegisteredBeforeCommit808=== RUN TestService_Rustfstest809=== PAUSE TestService_Rustfstest810=== RUN TestParseSize811=== PAUSE TestParseSize812=== RUN TestSkippedUploadsHandler813=== PAUSE TestSkippedUploadsHandler814=== RUN TestSystemdListenerNotActivated815--- PASS: TestSystemdListenerNotActivated (0.00s)816=== RUN TestWatchdogBeatsWhenHealthy817--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)818=== RUN TestWatchdogSkipsWhenUnhealthy8192026/10/26 22:36:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8202026/10/26 22:36:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8212026/10/26 22:36:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8222026/10/26 22:36:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8232026/10/26 22:36:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8242026/10/26 22:36:16 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8252026/10/26 22:36:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8262026/10/26 22:36:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8272026/10/26 22:36:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8282026/10/26 22:36:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"829--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)830=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle831=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle832=== RUN TestProxyWriteTimeout833=== PAUSE TestProxyWriteTimeout834=== RUN TestPendingClosureWriteTimeout835=== PAUSE TestPendingClosureWriteTimeout836=== RUN TestIsValidUploadKey837=== PAUSE TestIsValidUploadKey838=== RUN TestUploadHandlersRejectInvalidKeys839=== PAUSE TestUploadHandlersRejectInvalidKeys840=== RUN TestUploadHandlersRejectOversizedBody841=== PAUSE TestUploadHandlersRejectOversizedBody842=== RUN TestService_cleanupPendingClosuresHandler843=== PAUSE TestService_cleanupPendingClosuresHandler844=== RUN TestService_createPendingClosureHandler845=== PAUSE TestService_createPendingClosureHandler846=== RUN TestService_verifyS3Integrity847=== PAUSE TestService_verifyS3Integrity848=== RUN TestCompleteMultipartUnregistered849=== PAUSE TestCompleteMultipartUnregistered850=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT851=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT852=== CONT TestService_AuthMiddleware_MTLSProxyHeader853=== CONT TestService_cleanupPendingClosuresHandler854=== CONT TestUploadHandlersRejectOversizedBody855=== CONT TestService_Rustfstest856=== CONT TestPush_CompleteWaitsForCleanupOfThePush857=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT858=== CONT TestService_verifyS3Integrity859=== CONT TestCompleteMultipartUnregistered860=== CONT TestUploadHandlersRejectInvalidKeys861=== CONT TestIsValidUploadKey862=== CONT TestRedundantMultipartUpload863=== CONT TestPendingClosureWriteTimeout864=== RUN TestPendingClosureWriteTimeout/empty865=== CONT TestParseSize866=== CONT TestService_createPendingClosureHandler867=== CONT TestCompletedNarNotReofferedAcrossClosures868=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle869=== CONT TestCompleteMultipartUpload_ErrorButObjectExists870=== CONT TestSkippedUploadsHandler871=== CONT TestPresignedUploadRegisteredBeforeCommit872=== CONT TestGCTaskStore_GetEmpty873=== CONT TestProxyWriteTimeout874=== CONT TestParseSingleRange875=== CONT TestPresentNotReportedWhileGCDeletesClosure876=== CONT TestReadProxyNarinfo877=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info878=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info879=== RUN TestIsValidUploadKey/narinfo880=== PAUSE TestPendingClosureWriteTimeout/empty881--- PASS: TestParseSize (0.00s)882=== CONT TestReadProxyConditionalGet883=== CONT TestPresentReportsOnlyClosureRoots884=== RUN TestProxyWriteTimeout/narinfo885=== PAUSE TestIsValidUploadKey/narinfo886=== RUN TestIsValidUploadKey/nar_zst887=== PAUSE TestIsValidUploadKey/nar_zst888=== RUN TestIsValidUploadKey/nar_xz889=== PAUSE TestProxyWriteTimeout/narinfo890=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale891=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal892--- PASS: TestGCTaskStore_GetEmpty (0.00s)893=== RUN TestPendingClosureWriteTimeout/400_objects894=== PAUSE TestIsValidUploadKey/nar_xz895=== RUN TestParseSingleRange/none896=== RUN TestProxyWriteTimeout/1_GiB_nar897=== PAUSE TestParseSingleRange/none898=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal899=== RUN TestParseSingleRange/unknown_unit900=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale901=== RUN TestIsValidUploadKey/nar_plain902=== PAUSE TestPendingClosureWriteTimeout/400_objects903=== PAUSE TestProxyWriteTimeout/1_GiB_nar904=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key905=== RUN TestProxyWriteTimeout/10_GiB_nar906=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key907=== PAUSE TestProxyWriteTimeout/10_GiB_nar908=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key909=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key910=== PAUSE TestParseSingleRange/unknown_unit911=== RUN TestProxyWriteTimeout/unknown_size912=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh913=== PAUSE TestIsValidUploadKey/nar_plain9142026/10/26 22:36:17 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000915=== RUN TestIsValidUploadKey/listing916=== RUN TestPendingClosureWriteTimeout/670k_objects917=== CONT TestPush_RepeatedRootCommitsOnce918=== RUN TestParseSingleRange/multi-range_ignored919=== PAUSE TestParseSingleRange/multi-range_ignored920=== PAUSE TestProxyWriteTimeout/unknown_size921=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh922=== PAUSE TestIsValidUploadKey/listing923=== PAUSE TestPendingClosureWriteTimeout/670k_objects924=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline925=== RUN TestParseSingleRange/malformed_no_dash926=== CONT TestPush_CompleteCommitsEveryRoot927=== RUN TestIsValidUploadKey/build_log928=== PAUSE TestIsValidUploadKey/build_log929=== CONT TestCreatePinRejectsBadInput930=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline931=== PAUSE TestParseSingleRange/malformed_no_dash932=== RUN TestIsValidUploadKey/build_log_home-manager_file933=== CONT TestPresentRefreshesOnlyStaleClosures934=== RUN TestParseSingleRange/malformed_both_empty935=== PAUSE TestIsValidUploadKey/build_log_home-manager_file936=== PAUSE TestParseSingleRange/malformed_both_empty937=== RUN TestIsValidUploadKey/build_log_plus_in_name938=== RUN TestParseSingleRange/malformed_end_before_start939=== PAUSE TestParseSingleRange/malformed_end_before_start940=== PAUSE TestIsValidUploadKey/build_log_plus_in_name941=== RUN TestParseSingleRange/closed942=== RUN TestIsValidUploadKey/build_log_question_mark943=== PAUSE TestParseSingleRange/closed944=== PAUSE TestIsValidUploadKey/build_log_question_mark945=== RUN TestParseSingleRange/open-ended946=== PAUSE TestParseSingleRange/open-ended947=== RUN TestIsValidUploadKey/build_log_equals948=== RUN TestParseSingleRange/end_clamped_to_size949=== PAUSE TestParseSingleRange/end_clamped_to_size950=== RUN TestParseSingleRange/suffix951=== PAUSE TestIsValidUploadKey/build_log_equals952=== PAUSE TestParseSingleRange/suffix953=== RUN TestIsValidUploadKey/realisation954=== RUN TestParseSingleRange/suffix_exceeds_size955=== PAUSE TestParseSingleRange/suffix_exceeds_size956=== RUN TestParseSingleRange/single_byte957=== PAUSE TestParseSingleRange/single_byte958=== RUN TestParseSingleRange/start_past_EOF959=== PAUSE TestParseSingleRange/start_past_EOF960=== PAUSE TestIsValidUploadKey/realisation961=== RUN TestIsValidUploadKey/realisation_plus_in_output962=== PAUSE TestIsValidUploadKey/realisation_plus_in_output963=== RUN TestIsValidUploadKey/nix-cache-info964=== PAUSE TestIsValidUploadKey/nix-cache-info965=== RUN TestParseSingleRange/start_far_past_EOF966=== RUN TestIsValidUploadKey/index.html967=== PAUSE TestParseSingleRange/start_far_past_EOF968=== PAUSE TestIsValidUploadKey/index.html969=== CONT TestReadRedirectKeepsNarinfoProxied970=== RUN TestIsValidUploadKey/narinfo_key,_nar_type971=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type972=== RUN TestIsValidUploadKey/nar_key,_narinfo_type973=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type974=== RUN TestIsValidUploadKey/listing_key,_narinfo_type975=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type976=== RUN TestIsValidUploadKey/traversal977=== PAUSE TestIsValidUploadKey/traversal978=== RUN TestIsValidUploadKey/traversal_nar979=== PAUSE TestIsValidUploadKey/traversal_nar980=== RUN TestIsValidUploadKey/absolute981=== PAUSE TestIsValidUploadKey/absolute982=== RUN TestIsValidUploadKey/empty_key983=== PAUSE TestIsValidUploadKey/empty_key984=== RUN TestIsValidUploadKey/unknown_type985=== PAUSE TestIsValidUploadKey/unknown_type986=== CONT TestPush_RootsAreLockedInByteOrder987=== CONT TestReadProxyRootRedirectsToIndexHTML988--- PASS: TestSkippedUploadsHandler (0.06s)989--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.40s)990=== CONT TestPush_OverlappingRootsStoreOneRowPerKey9912026/10/26 22:36:17 INFO Received cleanup request method=DELETE path=/api/pending_closures9922026/10/26 22:36:17 INFO Aborted multipart uploads count=0 kept=09932026/10/26 22:36:17 INFO Received uploads request method=POST path=/api/pending_closures9942026/10/26 22:36:17 INFO Received push request method=POST path=/api/pushes9952026/10/26 22:36:17 INFO Received cleanup request method=DELETE path=/api/pending_closures9962026/10/26 22:36:17 INFO Aborted multipart uploads count=1 kept=09972026/10/26 22:36:17 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9982026-10-26 22:36:17.533 UTC [688] ERROR: Closure does not exist: id=19992026-10-26 22:36:17.533 UTC [688] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE10002026-10-26 22:36:17.533 UTC [688] STATEMENT: -- name: CommitPendingClosure :one1001 SELECT commit_pending_closure($1::bigint)::bigint1002 1003--- PASS: TestService_cleanupPendingClosuresHandler (0.48s)1004=== CONT TestPush_SignsNarinfosOfItsPendingObjects1005--- PASS: TestService_Rustfstest (0.49s)1006=== CONT TestReadRedirectUsesPublicS3URL10072026/10/26 22:36:17 INFO Received uploads request method=POST path=/api/pending_closures10082026/10/26 22:36:17 INFO Received uploads request method=POST path=/api/pending_closures1009=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1010=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1011=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1012=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1013=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1014=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1015=== CONT TestPushWaitsForSweepHoldingRow10162026/10/26 22:36:17 INFO Received uploads request method=POST path=/api/pending_closures10172026/10/26 22:36:17 INFO Received uploads request method=POST path=/api/pending_closures10182026/10/26 22:36:17 INFO Received uploads request method=POST path=/api/pending_closures10192026/10/26 22:36:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10202026/10/26 22:36:17 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1021--- PASS: TestCompleteMultipartUnregistered (0.73s)1022=== CONT TestCreatePendingClosureRejectsOversizedNAR10232026/10/26 22:36:17 INFO Received uploads request method=POST path=/api/pending_closures1024--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1025=== CONT TestGetExistingObjectsLocksRows10262026/10/26 22:36:17 INFO Received uploads request method=POST path=/api/pending_closures1027--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.77s)1028=== CONT TestPushDedupSurvivesConcurrentGC10292026/10/26 22:36:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1030--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.73s)1031=== CONT TestObjectStatsUpdatedOncePerCommit10322026/10/26 22:36:17 INFO Received push request method=POST path=/api/pushes1033--- PASS: TestPresentRefreshesOnlyStaleClosures (0.85s)1034=== CONT TestDeduplicatedObjectsRecordedAsPending10352026/10/26 22:36:17 INFO Received uploads request method=POST path=/api/pending_closures10362026/10/26 22:36:18 INFO Received uploads request method=POST path=/api/pending_closures10372026/10/26 22:36:18 INFO Received uploads request method=POST path=/api/pending_closures10382026/10/26 22:36:18 INFO Received create pin request method=POST path=/api/pins/deploy10392026/10/26 22:36:18 INFO Received create pin request method=POST path=/api/pins/deploy10402026/10/26 22:36:18 INFO Received create pin request method=POST path=/api/pins/deploy10412026/10/26 22:36:18 INFO Received create pin request method=POST path=/api/pins/deploy10422026/10/26 22:36:18 INFO Received create pin request method=POST path=/api/pins/deploy10432026/10/26 22:36:18 INFO Received create pin request method=POST path=/api/pins/deploy10442026/10/26 22:36:18 INFO Received create pin request method=POST path=/api/pins/deploy10452026/10/26 22:36:18 INFO Received create pin request method=POST path=/api/pins/deploy10462026/10/26 22:36:18 INFO Received uploads request method=POST path=/api/pending_closures10472026/10/26 22:36:18 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10482026/10/26 22:36:18 INFO Received uploads request method=POST path=/api/pending_closures1049--- PASS: TestReadProxyConditionalGet (1.06s)1050=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit10512026/10/26 22:36:18 INFO Received create pin request method=POST path=/api/pins/deploy1052=== CONT TestPendingClosureFailureAbortsItsUploads1053--- PASS: TestPresentReportsOnlyClosureRoots (1.07s)1054=== CONT TestGCAdvisoryLockBlocksConcurrentRun10552026/10/26 22:36:18 INFO Received push request method=POST path=/api/pushes1056--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.08s)10572026/10/26 22:36:18 INFO Received push request method=POST path=/api/pushes10582026/10/26 22:36:18 INFO Received uploads request method=POST path=/api/pending_closures10592026/10/26 22:36:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1060=== CONT TestPendingCleanupUsesOneCutoff1061--- PASS: TestReadRedirectKeepsNarinfoProxied (1.16s)10622026/10/26 22:36:18 INFO Received push request method=POST path=/api/pushes10632026/10/26 22:36:18 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3LjExMzUzZmRlLTQ2MDItNDRhZC1hMjkxLWM1YTZlMTZhMTYzYXgxNzkzMDU0MTc3NTIwMzM0MDU0 parts=1010642026/10/26 22:36:18 INFO Received push request method=POST path=/api/pushes1065--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.88s)1066=== CONT TestLeadEndsOnShutdown10672026/10/26 22:36:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10682026/10/26 22:36:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10692026/10/26 22:36:18 INFO Signed narinfos id=1 count=110702026/10/26 22:36:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10712026/10/26 22:36:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10722026/10/26 22:36:18 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10732026/10/26 22:36:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10742026/10/26 22:36:18 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10752026/10/26 22:36:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10762026/10/26 22:36:18 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110772026/10/26 22:36:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10782026/10/26 22:36:18 INFO Received uploads request method=POST path=/api/pending_closures10792026/10/26 22:36:18 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo10802026/10/26 22:36:18 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3LjNjZDMwOWNjLWUwYTQtNGE1My05NzdlLTkyZGQ2MzNjZWMxZXgxNzkzMDU0MTc3NzY2NTMzNTEw parts=1010812026/10/26 22:36:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10822026/10/26 22:36:18 INFO Completed upload id=1 objects=2 duration=4.219625ms10832026/10/26 22:36:18 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010842026/10/26 22:36:18 INFO Received uploads request method=POST path=/api/pending_closures10852026/10/26 22:36:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures1086--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.85s)10872026/10/26 22:36:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1088=== CONT TestPush_RejectsBadRequests10892026/10/26 22:36:18 INFO Aborted multipart uploads count=0 kept=010902026/10/26 22:36:18 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=010912026/10/26 22:36:18 INFO Vacuumed table table=pending_closures10922026/10/26 22:36:18 INFO Vacuumed table table=pending_objects10932026/10/26 22:36:18 INFO Vacuumed table table=multipart_uploads10942026/10/26 22:36:18 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3LjY4NGY5OGUwLWI1MWUtNDAxYy05Yzc4LTU4MWVkYzE1YTNhN3gxNzkzMDU0MTc3NzYwNDAwMDEz parts=1010952026/10/26 22:36:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10962026/10/26 22:36:18 INFO Vacuumed table table=closures10972026/10/26 22:36:18 INFO Vacuumed table table=objects10982026/10/26 22:36:18 INFO Completed upload id=1 objects=2 duration=4.343795ms10992026/10/26 22:36:18 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001100--- PASS: TestGetExistingObjectsLocksRows (0.64s)1101=== CONT TestMetricsInventory11022026/10/26 22:36:18 INFO Received uploads request method=POST path=/api/pending_closures1103--- PASS: TestService_createPendingClosureHandler (1.39s)1104--- PASS: TestReadRedirectUsesPublicS3URL (0.91s)1105=== CONT TestConnectWaitsForAPeerMigration1106=== CONT TestLeadElectsOneAndHandsOver11072026/10/26 22:36:18 INFO Received uploads request method=POST path=/api/pending_closures11082026/10/26 22:36:18 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11092026/10/26 22:36:18 WARN Found objects in DB but missing from S3, will re-upload count=111102026/10/26 22:36:18 INFO Received uploads request method=POST path=/api/pending_closures11112026/10/26 22:36:18 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete11122026/10/26 22:36:18 INFO Completed upload id=3 objects=2 duration=2.579313ms1113--- PASS: TestService_verifyS3Integrity (1.44s)1114=== CONT TestClientWithDependencies11152026/10/26 22:36:18 INFO Received uploads request method=POST path=/api/pending_closures11162026/10/26 22:36:18 INFO Received push request method=POST path=/api/pushes11172026/10/26 22:36:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1118=== CONT TestMetricsCommit11192026/10/26 22:36:18 INFO Aborted multipart uploads count=0 kept=01120--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.62s)1121=== CONT TestReadProxyInvalidPath1122--- PASS: TestObjectStatsUpdatedOncePerCommit (0.69s)11232026/10/26 22:36:18 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=011242026/10/26 22:36:18 INFO Vacuumed table table=pending_closures11252026/10/26 22:36:18 INFO Vacuumed table table=pending_objects11262026/10/26 22:36:18 INFO Vacuumed table table=multipart_uploads11272026/10/26 22:36:18 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3LjgzYTNmNWY4LWE5YjUtNDMyZi04YjEzLTM1MjJkMzk2ZGNiMngxNzkzMDU0MTc3OTQ2NjU1MzAx parts=1011282026/10/26 22:36:18 INFO Vacuumed table table=closures11292026/10/26 22:36:18 INFO Vacuumed table table=objects11302026/10/26 22:36:18 INFO Aborted multipart uploads count=0 kept=011312026/10/26 22:36:18 WARN Force mode enabled - objects will be deleted immediately without grace period11322026/10/26 22:36:18 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=011332026/10/26 22:36:18 INFO Vacuumed table table=pending_closures11342026/10/26 22:36:18 INFO Vacuumed table table=pending_objects11352026/10/26 22:36:18 INFO Vacuumed table table=multipart_uploads11362026/10/26 22:36:18 INFO Vacuumed table table=closures11372026/10/26 22:36:18 INFO Vacuumed table table=objects11382026/10/26 22:36:18 INFO Received uploads request method=POST path=/api/pending_closures1139=== CONT TestClientErrorHandling1140--- PASS: TestPushDedupSurvivesConcurrentGC (0.78s)1141=== RUN TestClientErrorHandling/InvalidStorePath1142=== PAUSE TestClientErrorHandling/InvalidStorePath1143=== RUN TestClientErrorHandling/InvalidAuthToken1144=== PAUSE TestClientErrorHandling/InvalidAuthToken1145=== RUN TestClientErrorHandling/ServerNotAvailable1146=== PAUSE TestClientErrorHandling/ServerNotAvailable1147=== CONT TestReadProxy404And42911482026-10-26 22:36:18.650 UTC [798] ERROR: Push does not exist: id=111492026-10-26 22:36:18.650 UTC [798] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE11502026-10-26 22:36:18.650 UTC [798] STATEMENT: SELECT commit_push($1)11512026/10/26 22:36:18 INFO Received uploads request method=POST path=/api/pending_closures1152--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.60s)1153=== CONT TestService_healthCheckHandler11542026/10/26 22:36:18 INFO Received uploads request method=POST path=/api/pending_closures1155=== CONT TestService_ReadAuthMiddleware1156--- PASS: TestPendingClosureFailureAbortsItsUploads (0.53s)11572026/10/26 22:36:18 INFO lead: acquired remote=192.0.2.1:123411582026/10/26 22:36:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11592026/10/26 22:36:18 INFO Received cleanup request method=DELETE path=/api/pending_closures11602026/10/26 22:36:18 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3Ljk0M2ViMWY2LTAzN2UtNDYwYi04YmJkLTIyZmM0YTA3OTQ5ZXgxNzkzMDU0MTc4MjM0ODc1Mzc01161=== RUN TestPush_RejectsBadRequests/no_roots1162=== PAUSE TestPush_RejectsBadRequests/no_roots1163=== RUN TestPush_RejectsBadRequests/no_objects1164=== PAUSE TestPush_RejectsBadRequests/no_objects1165=== RUN TestPush_RejectsBadRequests/bad_root1166=== PAUSE TestPush_RejectsBadRequests/bad_root1167=== RUN TestPush_RejectsBadRequests/root_not_in_objects1168=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1169=== CONT TestSweepSkipsRowsLockedByPush11702026/10/26 22:36:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11712026/10/26 22:36:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11722026/10/26 22:36:18 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3LjEwNTM1NTAxLWQwYzgtNDkxMy05NzdhLTFhNmRjZGZmZjE2ZHgxNzkzMDU0MTc4MDU1Mjk3OTYz parts=1211732026/10/26 22:36:18 INFO Received uploads request method=POST path=/api/pending_closures11742026/10/26 22:36:18 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3LmUwMDVkMGRjLTA3MmYtNDZlOC04NWY3LWY2MmY3NzcxZjRjYXgxNzkzMDU0MTc4MDAwNDYzODUy parts=1211752026/10/26 22:36:18 INFO Received uploads request method=POST path=/api/pending_closures11762026/10/26 22:36:18 INFO Received uploads request method=POST path=/api/pending_closures11772026/10/26 22:36:18 INFO lead: acquired remote=192.0.2.1:12341178--- PASS: TestMetricsInventory (0.37s)1179=== CONT TestService_RequireScope_OIDC1180--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.75s)1181=== CONT TestDeletePinKeepsRowWhenS3Fails11822026/10/26 22:36:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11832026/10/26 22:36:18 INFO Received create pin request method=POST path=/api/pins/deploy11842026/10/26 22:36:18 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo11852026/10/26 22:36:18 INFO Received push request method=POST path=/api/pushes11862026/10/26 22:36:18 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3Ljk0M2ViMWY2LTAzN2UtNDYwYi04YmJkLTIyZmM0YTA3OTQ5ZXgxNzkzMDU0MTc4MjM0ODc1Mzc0 error="Delete \"http://localhost:37279/bucket26/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3Ljk0M2ViMWY2LTAzN2UtNDYwYi04YmJkLTIyZmM0YTA3OTQ5ZXgxNzkzMDU0MTc4MjM0ODc1Mzc0\": injected: abort refused"11872026/10/26 22:36:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11882026/10/26 22:36:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11892026/10/26 22:36:18 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3LmZlZTJjMmRjLTk3N2EtNDM1MS04MTEwLWZkMjIzM2E3OTZlMngxNzkzMDU0MTc4MTk2NTc4MTgx parts=1011902026/10/26 22:36:18 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3Ljk0M2ViMWY2LTAzN2UtNDYwYi04YmJkLTIyZmM0YTA3OTQ5ZXgxNzkzMDU0MTc4MjM0ODc1Mzc011912026/10/26 22:36:18 ERROR Failed to register completed object error="get pending object \"nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst\": context canceled" object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst11922026/10/26 22:36:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1193--- PASS: TestCreatePinRejectsBadInput (1.79s)1194=== CONT TestService_AuthMiddleware11952026/10/26 22:36:18 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified multipart upload does not exist. The upload ID may be invalid, or the upload may have been aborted or completed." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3Ljk0M2ViMWY2LTAzN2UtNDYwYi04YmJkLTIyZmM0YTA3OTQ5ZXgxNzkzMDU0MTc4MjM0ODc1Mzc011962026/10/26 22:36:18 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3LjE0OGNkMzZjLWFiZDYtNDgxZS04MjM3LTE2ZmZkZTY2YWYyN3gxNzkzMDU0MTc4MjA0MTYxOTAw parts=101197--- PASS: TestReadProxyInvalidPath (0.33s)1198=== CONT TestGCSweepSkipsPendingObjects11992026/10/26 22:36:18 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3Ljk0M2ViMWY2LTAzN2UtNDYwYi04YmJkLTIyZmM0YTA3OTQ5ZXgxNzkzMDU0MTc4MjM0ODc1Mzc0 parts=112002026/10/26 22:36:18 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"1201=== NAME TestClientWithDependencies1202 client_integration_test.go:722: Built derivation: /build/TestClientWithDependencies2494495046/001/store/72gdnssynqy1i1vhj0fcawz4psi49lsf-test-script1203--- PASS: TestPushWaitsForSweepHoldingRow (1.16s)1204=== CONT TestCacheStatsHandler12052026/10/26 22:36:18 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39259/oidc1206--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.85s)1207=== CONT TestReadProxyDisabled1208=== NAME TestClientWithDependencies1209 client_integration_test.go:724: Found 1 dependencies (including self)1210--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.79s)1211=== CONT TestReadProxyNarinfoAlreadyDecompressed1212--- PASS: TestService_healthCheckHandler (0.31s)1213=== CONT TestClientFallsBackToClosures1214--- PASS: TestService_ReadAuthMiddleware (0.33s)1215=== CONT TestGCEndsOnShutdown1216=== RUN TestGCEndsOnShutdown/before_the_run1217=== PAUSE TestGCEndsOnShutdown/before_the_run1218=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1219=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1220=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1221=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1222=== CONT TestService_ReadScope_PublicByDefault12232026/10/26 22:36:19 INFO Received push request method=POST path=/api/pushes12242026/10/26 22:36:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12252026/10/26 22:36:19 INFO Uploading 72gdnssynqy1i1vhj0fcawz4psi49lsf-test-script (136B)12262026/10/26 22:36:19 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"12272026/10/26 22:36:19 WARN Failed to register uploaded object key=log/6s84p3pkiqhsik38c6jxp34x352n2ddc-test-script.drv error="server returned 404: 404 page not found\n"12282026/10/26 22:36:19 INFO Aborted multipart uploads count=0 kept=012292026/10/26 22:36:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12302026/10/26 22:36:19 WARN Failed to register uploaded object key=72gdnssynqy1i1vhj0fcawz4psi49lsf.ls error="server returned 404: 404 page not found\n"12312026/10/26 22:36:19 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>12322026/10/26 22:36:19 INFO Received create pin request method=POST path=/api/pins/app12332026/10/26 22:36:19 INFO Signed narinfos id=1 count=112342026/10/26 22:36:19 INFO Uploading 1 narinfos12352026/10/26 22:36:19 WARN Force mode enabled - objects will be deleted immediately without grace period12362026/10/26 22:36:19 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=012372026/10/26 22:36:19 INFO Vacuumed table table=pending_closures12382026/10/26 22:36:19 INFO Vacuumed table table=pending_objects12392026/10/26 22:36:19 INFO Vacuumed table table=multipart_uploads12402026/10/26 22:36:19 INFO Vacuumed table table=closures12412026/10/26 22:36:19 INFO Vacuumed table table=objects12422026/10/26 22:36:19 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo12432026/10/26 22:36:19 INFO Received delete pin request method=DELETE path=/api/pins/app12442026/10/26 22:36:19 INFO Aborted multipart uploads count=0 kept=012452026/10/26 22:36:19 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket51/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12462026/10/26 22:36:19 INFO Received complete push request method=POST path=/api/pushes/1/complete12472026/10/26 22:36:19 WARN Force mode enabled - objects will be deleted immediately without grace period12482026/10/26 22:36:19 INFO Received delete pin request method=DELETE path=/api/pins/app12492026/10/26 22:36:19 WARN Failed to register uploaded object key=72gdnssynqy1i1vhj0fcawz4psi49lsf.narinfo error="server returned 404: 404 page not found\n"1250--- PASS: TestReadProxyNarinfo (2.03s)1251=== CONT TestCommitRacingPendingCleanupKeepsObjects12522026/10/26 22:36:19 INFO Completed push id=1 objects=4 duration=10.155651ms12532026/10/26 22:36:19 INFO Upload complete. (145ms)12542026/10/26 22:36:19 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"12552026/10/26 22:36:19 INFO Aborted multipart uploads count=0 kept=012562026/10/26 22:36:19 INFO Deleted pin name=app12572026/10/26 22:36:19 WARN Force mode enabled - objects will be deleted immediately without grace period12582026/10/26 22:36:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12592026/10/26 22:36:19 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=012602026/10/26 22:36:19 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=012612026/10/26 22:36:19 INFO Vacuumed table table=pending_closures12622026/10/26 22:36:19 INFO Vacuumed table table=pending_objects12632026/10/26 22:36:19 INFO Vacuumed table table=multipart_uploads1264--- PASS: TestService_AuthMiddleware (0.27s)1265=== CONT TestReadProxyRangeRequest12662026/10/26 22:36:19 INFO Vacuumed table table=closures12672026/10/26 22:36:19 INFO Vacuumed table table=objects12682026/10/26 22:36:19 INFO Vacuumed table table=pending_closures12692026/10/26 22:36:19 INFO Vacuumed table table=pending_objects12702026/10/26 22:36:19 INFO Vacuumed table table=multipart_uploads12712026/10/26 22:36:19 INFO Vacuumed table table=closures12722026/10/26 22:36:19 INFO Vacuumed table table=objects1273=== NAME TestClientWithDependencies1274 client_integration_test.go:740: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2494495046/001/store) requires matching store prefix1275=== CONT TestReadRedirectNar1276--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.34s)1277--- PASS: TestSweepSkipsRowsLockedByPush (0.46s)1278=== CONT TestCreatePin_ReservedPins12792026/10/26 22:36:19 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3LjJlY2UwYTk0LWMwNzktNGVlNy05OWYxLWJiNDgzMDcxZmU5ZHgxNzkzMDU0MTc4NTUzNDU0MjEy parts=101280=== RUN TestService_RequireScope_OIDC/builder_may_write1281=== PAUSE TestService_RequireScope_OIDC/builder_may_write1282=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1283=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1284=== RUN TestService_RequireScope_OIDC/ops_may_admin1285=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1286=== RUN TestService_RequireScope_OIDC/ops_may_not_write1287=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1288=== RUN TestService_RequireScope_OIDC/reader_may_not_write1289=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1290=== RUN TestService_RequireScope_OIDC/static_token_may_admin1291=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1292=== RUN TestService_RequireScope_OIDC/static_token_may_write1293=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1294=== RUN TestService_RequireScope_OIDC/reader_may_read1295=== PAUSE TestService_RequireScope_OIDC/reader_may_read1296=== RUN TestService_RequireScope_OIDC/writer_implies_read1297=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1298=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1299=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1300=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1301=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1302=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1303=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1304=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1305=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1306=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1307=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1308=== CONT TestIsValidCachePath1309=== RUN TestIsValidCachePath/narinfo1310=== PAUSE TestIsValidCachePath/narinfo1311=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1312=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1313=== RUN TestIsValidCachePath/nar_zst1314=== PAUSE TestIsValidCachePath/nar_zst1315=== RUN TestIsValidCachePath/nar_xz1316=== PAUSE TestIsValidCachePath/nar_xz1317=== RUN TestIsValidCachePath/nar_bz21318=== PAUSE TestIsValidCachePath/nar_bz21319=== RUN TestIsValidCachePath/nar_uncompressed1320=== PAUSE TestIsValidCachePath/nar_uncompressed1321=== RUN TestIsValidCachePath/ls1322=== PAUSE TestIsValidCachePath/ls1323=== RUN TestIsValidCachePath/log1324=== PAUSE TestIsValidCachePath/log1325=== RUN TestIsValidCachePath/realisation1326=== PAUSE TestIsValidCachePath/realisation1327=== RUN TestIsValidCachePath/nix-cache-info1328=== PAUSE TestIsValidCachePath/nix-cache-info1329=== RUN TestIsValidCachePath/index.html1330=== PAUSE TestIsValidCachePath/index.html1331=== RUN TestIsValidCachePath/traversal_parent1332=== PAUSE TestIsValidCachePath/traversal_parent1333=== RUN TestIsValidCachePath/traversal_in_middle1334=== PAUSE TestIsValidCachePath/traversal_in_middle1335=== RUN TestIsValidCachePath/invalid_char_e1336=== PAUSE TestIsValidCachePath/invalid_char_e1337=== RUN TestIsValidCachePath/invalid_char_u1338=== PAUSE TestIsValidCachePath/invalid_char_u1339=== RUN TestIsValidCachePath/random_path1340=== PAUSE TestIsValidCachePath/random_path1341=== RUN TestIsValidCachePath/empty1342=== PAUSE TestIsValidCachePath/empty1343=== RUN TestIsValidCachePath/leading_slash1344=== PAUSE TestIsValidCachePath/leading_slash1345=== RUN TestIsValidCachePath/wrong_extension1346=== PAUSE TestIsValidCachePath/wrong_extension1347=== RUN TestIsValidCachePath/short_hash1348=== PAUSE TestIsValidCachePath/short_hash1349=== CONT TestResolveDBConnectionString1350=== RUN TestResolveDBConnectionString/flag_wins1351=== PAUSE TestResolveDBConnectionString/flag_wins1352=== RUN TestResolveDBConnectionString/file_when_flag_empty1353=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1354=== RUN TestResolveDBConnectionString/missing_file_is_an_error1355=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1356=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1357=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1358=== RUN TestResolveDBConnectionString/nothing_configured1359=== PAUSE TestResolveDBConnectionString/nothing_configured1360=== CONT TestGCTaskStore_ConflictDifferentParams1361--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1362=== CONT TestPinProtectsFromGC1363=== CONT TestClientMultipleUploads1364--- PASS: TestClientWithDependencies (0.68s)13652026/10/26 22:36:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13662026/10/26 22:36:19 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3Ljc4MTlhZjJkLTA4MGUtNGJmMS1iZjMzLWViYWNmMzdmY2UxY3gxNzkzMDU0MTc3OTUwMTQxNjY1 parts=1013672026/10/26 22:36:19 INFO Received complete push request method=POST path=/api/pushes/1/complete13682026/10/26 22:36:19 INFO Received uploads request method=POST path=/api/pending_closures1369=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1370--- PASS: TestCacheStatsHandler (0.31s)13712026/10/26 22:36:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46691/oidc13722026/10/26 22:36:19 INFO Completed push id=1 objects=4 duration=26.60301ms13732026/10/26 22:36:19 INFO Aborted multipart uploads count=0 kept=01374--- PASS: TestReadProxyDisabled (0.34s)1375=== CONT TestLeadIncumbentAnnouncesAtOnce13762026/10/26 22:36:19 WARN Force mode enabled - objects will be deleted immediately without grace period1377--- PASS: TestPush_RepeatedRootCommitsOnce (2.19s)1378=== CONT TestOrphanedObjectsGCStressTest13792026/10/26 22:36:19 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=013802026/10/26 22:36:19 INFO Vacuumed table table=pending_closures13812026/10/26 22:36:19 INFO Vacuumed table table=pending_objects13822026/10/26 22:36:19 INFO Vacuumed table table=multipart_uploads13832026/10/26 22:36:19 INFO Vacuumed table table=closures13842026/10/26 22:36:19 INFO Vacuumed table table=objects1385--- PASS: TestGCSweepSkipsPendingObjects (0.45s)1386=== CONT TestGCSweepDeliversEachKeyOnce1387--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.40s)1388=== CONT TestTombstonedObjectOfferedWithoutWaiting1389--- PASS: TestService_ReadScope_PublicByDefault (0.35s)1390=== CONT TestCacheConfigHandlerMaxNarSize1391=== CONT TestChildrenInheritRaisedFileLimit1392--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1393--- PASS: TestChildrenInheritRaisedFileLimit (0.00s)1394=== CONT TestConcurrentPinUpdatesAgree13952026/10/26 22:36:19 INFO Aborted multipart uploads count=0 kept=013962026/10/26 22:36:19 WARN Force mode enabled - objects will be deleted immediately without grace period13972026/10/26 22:36:19 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=013982026/10/26 22:36:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13992026/10/26 22:36:19 INFO Vacuumed table table=pending_closures14002026/10/26 22:36:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14012026/10/26 22:36:19 INFO Vacuumed table table=pending_objects14022026/10/26 22:36:19 INFO Vacuumed table table=multipart_uploads14032026/10/26 22:36:19 INFO Vacuumed table table=closures14042026/10/26 22:36:19 INFO Vacuumed table table=objects1405--- PASS: TestReadProxyRangeRequest (0.29s)1406=== CONT TestReconnectLeavesObjectsUnlocked14072026/10/26 22:36:19 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3LjlhYTAwOThjLTE3MDEtNGM1Yi04ZmM4LTFiNzBlYWVjYzJkMngxNzkzMDU0MTc4MTk2NTA1MTQx parts=1014082026/10/26 22:36:19 WARN Rate limiter enabled after throttle name=s3-test rate=514092026/10/26 22:36:19 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."14102026/10/26 22:36:19 WARN Rate limiter backed off name=s3-test rate=514112026/10/26 22:36:19 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."14122026/10/26 22:36:19 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3LmQ3YzE1ZmZkLTU4MTUtNDJhNC04NzI1LTI2YzA4NGFiYzFmNngxNzkzMDU0MTc4ODU5OTM1Nzc1 parts=101413--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.35s)1414=== CONT TestOrphanedObjectsGC14152026/10/26 22:36:19 INFO Received uploads request method=POST path=/api/pending_closures1416=== CONT TestSweepRechecksPendingAfterLocking1417--- PASS: TestReadRedirectNar (0.31s)1418=== CONT TestObjectStatsTrigger1419--- PASS: TestReadProxy404And429 (0.85s)14202026/10/26 22:36:19 INFO Received uploads request method=POST path=/api/pending_closures14212026/10/26 22:36:19 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14222026/10/26 22:36:19 INFO Uploading ilrx04ni2a8whsvaz0lagnhnhanf2w9j-shared-dep (136B)14232026/10/26 22:36:19 INFO Uploading sg0pr5hz7lx9p8s98y6mprzrrw2lgd9k-a (216B)14242026/10/26 22:36:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14252026/10/26 22:36:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14262026/10/26 22:36:19 WARN Failed to register uploaded object key=s6kimq8alblpnabgwix739aw20zzsj7w.ls error="server returned 404: 404 page not found\n"14272026/10/26 22:36:19 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14282026/10/26 22:36:19 WARN Failed to register uploaded object key=nar/0xfab3nb7dzzqj208fw5mb3vyccaw917ci86m9j0bl6yh4jpncr2.nar.zst error="server returned 404: 404 page not found\n"14292026/10/26 22:36:19 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3LjE2Y2RhYzg2LWQ2NWYtNGExZi05NzgyLTk0ZDRiMTA4YTIxOHgxNzkzMDU0MTc4MjA2Njk0NDgz parts=1014302026/10/26 22:36:19 WARN Failed to register uploaded object key=ilrx04ni2a8whsvaz0lagnhnhanf2w9j.ls error="server returned 404: 404 page not found\n"14312026/10/26 22:36:19 WARN Failed to register uploaded object key=sg0pr5hz7lx9p8s98y6mprzrrw2lgd9k.ls error="server returned 404: 404 page not found\n"14322026/10/26 22:36:19 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3LjAyNDczM2Q0LTk1ZTQtNDNjYy05YWFhLTZiZGY4YTBjYWU4YngxNzkzMDU0MTc4Nzg3Mjk1MzA0 error="Get \"http://127.0.0.1:1/bucket20/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"14332026/10/26 22:36:19 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14342026/10/26 22:36:19 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3LjFkOTBhMTFiLTc2MTMtNDUzNS1iMWQ1LWY3N2E3NTMyOTA1MngxNzkzMDU0MTc4NzY3OTYyNDEy parts=1214352026/10/26 22:36:19 INFO Signed narinfos id=1 count=214362026/10/26 22:36:19 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14372026/10/26 22:36:19 INFO Signed narinfos id=2 count=214382026/10/26 22:36:19 INFO Received cleanup request method=DELETE path=/api/pending_closures14392026/10/26 22:36:19 INFO Uploading 4 narinfos14402026/10/26 22:36:19 INFO Aborted multipart uploads count=1 kept=014412026/10/26 22:36:19 WARN Failed to register uploaded object key=s6kimq8alblpnabgwix739aw20zzsj7w.narinfo error="server returned 404: 404 page not found\n"14422026/10/26 22:36:19 WARN Failed to register uploaded object key=ilrx04ni2a8whsvaz0lagnhnhanf2w9j.narinfo error="server returned 404: 404 page not found\n"14432026/10/26 22:36:19 WARN Failed to register uploaded object key=sg0pr5hz7lx9p8s98y6mprzrrw2lgd9k.narinfo error="server returned 404: 404 page not found\n"1444=== NAME TestClientMultipleUploads1445 client_integration_test.go:467: Created store path 0: /build/TestClientMultipleUploads2530881517/001/store/qaair4b2fqh5w6qfbq3iv02i0x4c87x9-test-file-0.txt14462026/10/26 22:36:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14472026/10/26 22:36:19 WARN Failed to register uploaded object key=ilrx04ni2a8whsvaz0lagnhnhanf2w9j.narinfo error="server returned 404: 404 page not found\n"1448=== NAME TestPinProtectsFromGC1449 client_integration_test.go:854: Pinned store path: /build/TestPinProtectsFromGC2428210755/001/store/94yndn3szgckrga14gr8y69l3w66vkys-pinned-file.txt1450 client_integration_test.go:855: Unpinned store path: /build/TestPinProtectsFromGC2428210755/001/store/j9mmrccg59qjjsm7rl7w072kxs8kl67z-unpinned-file.txt14512026/10/26 22:36:19 INFO Completed upload id=1 objects=6 duration=8.327549ms14522026/10/26 22:36:19 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14532026/10/26 22:36:19 INFO Completed upload id=2 objects=6 duration=2.049172ms14542026/10/26 22:36:19 INFO Upload complete. (132ms)1455=== NAME TestClientFallsBackToClosures1456 client_pushes_test.go:112: Retrieved narinfo from S3:1457 StorePath: /build/TestClientFallsBackToClosures2870476137/001/store/ilrx04ni2a8whsvaz0lagnhnhanf2w9j-shared-dep1458 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1459 Compression: zstd1460 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821461 NarSize: 1361462 References: 1463 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1464--- PASS: TestRedundantMultipartUpload (2.50s)1465=== CONT TestGCBugBareHashReferences1466=== NAME TestClientFallsBackToClosures1467 client_pushes_test.go:112: Retrieved narinfo from S3:1468 StorePath: /build/TestClientFallsBackToClosures2870476137/001/store/sg0pr5hz7lx9p8s98y6mprzrrw2lgd9k-a1469 URL: nar/0xfab3nb7dzzqj208fw5mb3vyccaw917ci86m9j0bl6yh4jpncr2.nar.zst1470 Compression: zstd1471 NarHash: sha256:0xfab3nb7dzzqj208fw5mb3vyccaw917ci86m9j0bl6yh4jpncr21472 NarSize: 2161473 References: /build/TestClientFallsBackToClosures2870476137/001/store/ilrx04ni2a8whsvaz0lagnhnhanf2w9j-shared-dep1474 CA: text:sha256:105vgawwms18rnz5fwz8zdwl8kxsyakk637gcmwy2fbrhr95aqv11475 client_pushes_test.go:112: Retrieved narinfo from S3:1476 StorePath: /build/TestClientFallsBackToClosures2870476137/001/store/s6kimq8alblpnabgwix739aw20zzsj7w-b1477 URL: nar/0xfab3nb7dzzqj208fw5mb3vyccaw917ci86m9j0bl6yh4jpncr2.nar.zst1478 Compression: zstd1479 NarHash: sha256:0xfab3nb7dzzqj208fw5mb3vyccaw917ci86m9j0bl6yh4jpncr21480 NarSize: 2161481 References: /build/TestClientFallsBackToClosures2870476137/001/store/ilrx04ni2a8whsvaz0lagnhnhanf2w9j-shared-dep1482 CA: text:sha256:105vgawwms18rnz5fwz8zdwl8kxsyakk637gcmwy2fbrhr95aqv114832026/10/26 22:36:19 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14842026/10/26 22:36:19 WARN Refused reserved pin name=worker-x86_64-linux14852026/10/26 22:36:19 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1486=== NAME TestClientMultipleUploads1487 client_integration_test.go:467: Created store path 1: /build/TestClientMultipleUploads2530881517/001/store/h684y907cf4ly2rcbbjvkhls96ggzh6y-test-file-1.txt14882026/10/26 22:36:19 INFO Received create pin request method=POST path=/api/pins/my-app14892026/10/26 22:36:19 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux14902026/10/26 22:36:19 INFO lead: acquired remote=192.0.2.1:123414912026/10/26 22:36:19 INFO lead: released remote=192.0.2.1:12341492=== CONT TestGCMetrics1493--- PASS: TestCreatePin_ReservedPins (0.43s)1494--- PASS: TestClientFallsBackToClosures (0.62s)1495=== CONT TestRegisterCompletedObjectNeedsPendingRow1496--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.35s)1497=== CONT TestPendingClosureFailureTracksEveryUpload1498=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1499=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1500=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1501=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1502=== CONT TestFailedS3DeleteKeepsTombstone15032026/10/26 22:36:19 INFO Received push request method=POST path=/api/pushes1504=== NAME TestClientMultipleUploads1505 client_integration_test.go:467: Created store path 2: /build/TestClientMultipleUploads2530881517/001/store/9p4gf6q5y71rywrhlha9w7hcrgwnkib4-test-file-2.txt15062026/10/26 22:36:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15072026/10/26 22:36:19 INFO Uploading 94yndn3szgckrga14gr8y69l3w66vkys-pinned-file.txt (128B)15082026/10/26 22:36:19 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15092026/10/26 22:36:19 WARN Failed to register uploaded object key=94yndn3szgckrga14gr8y69l3w66vkys.ls error="server returned 404: 404 page not found\n"15102026/10/26 22:36:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15112026/10/26 22:36:19 INFO Signed narinfos id=1 count=115122026/10/26 22:36:19 INFO Uploading 1 narinfos15132026/10/26 22:36:19 INFO Received complete push request method=POST path=/api/pushes/1/complete15142026/10/26 22:36:19 WARN Failed to register uploaded object key=94yndn3szgckrga14gr8y69l3w66vkys.narinfo error="server returned 404: 404 page not found\n"15152026/10/26 22:36:19 INFO Received uploads request method=POST path=/api/pending_closures15162026/10/26 22:36:19 INFO Completed push id=1 objects=3 duration=10.839832ms15172026/10/26 22:36:19 INFO Upload complete. (86ms)1518--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.35s)1519=== CONT TestMultipartCleanup15202026/10/26 22:36:19 INFO Received push request method=POST path=/api/pushes15212026/10/26 22:36:19 INFO Aborted multipart uploads count=0 kept=015222026/10/26 22:36:19 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15232026/10/26 22:36:19 INFO Uploading h684y907cf4ly2rcbbjvkhls96ggzh6y-test-file-1.txt (160B)15242026/10/26 22:36:19 INFO Uploading 9p4gf6q5y71rywrhlha9w7hcrgwnkib4-test-file-2.txt (160B)15252026/10/26 22:36:19 INFO Uploading qaair4b2fqh5w6qfbq3iv02i0x4c87x9-test-file-0.txt (160B)15262026/10/26 22:36:19 INFO Received create pin request method=POST path=/api/pins/app15272026/10/26 22:36:19 WARN Force mode enabled - objects will be deleted immediately without grace period15282026/10/26 22:36:19 INFO Received push request method=POST path=/api/pushes15292026/10/26 22:36:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15302026/10/26 22:36:19 INFO Uploading j9mmrccg59qjjsm7rl7w072kxs8kl67z-unpinned-file.txt (128B)15312026/10/26 22:36:19 INFO Received create pin request method=POST path=/api/pins/app15322026/10/26 22:36:19 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15332026/10/26 22:36:19 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15342026/10/26 22:36:19 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15352026/10/26 22:36:19 WARN Failed to register uploaded object key=9p4gf6q5y71rywrhlha9w7hcrgwnkib4.ls error="server returned 404: 404 page not found\n"15362026/10/26 22:36:19 WARN Failed to register uploaded object key=qaair4b2fqh5w6qfbq3iv02i0x4c87x9.ls error="server returned 404: 404 page not found\n"15372026/10/26 22:36:19 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15382026/10/26 22:36:19 WARN Failed to register uploaded object key=h684y907cf4ly2rcbbjvkhls96ggzh6y.ls error="server returned 404: 404 page not found\n"15392026/10/26 22:36:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15402026/10/26 22:36:19 INFO Signed narinfos id=1 count=315412026/10/26 22:36:19 INFO Uploading 3 narinfos15422026/10/26 22:36:19 WARN Failed to register uploaded object key=j9mmrccg59qjjsm7rl7w072kxs8kl67z.ls error="server returned 404: 404 page not found\n"15432026/10/26 22:36:19 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15442026/10/26 22:36:19 INFO Signed narinfos id=2 count=115452026/10/26 22:36:19 INFO Uploading 1 narinfos15462026/10/26 22:36:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15472026/10/26 22:36:19 WARN Failed to register uploaded object key=qaair4b2fqh5w6qfbq3iv02i0x4c87x9.narinfo error="server returned 404: 404 page not found\n"15482026/10/26 22:36:19 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=015492026/10/26 22:36:19 INFO Vacuumed table table=pending_closures15502026/10/26 22:36:19 INFO Vacuumed table table=pending_objects15512026/10/26 22:36:19 INFO Vacuumed table table=multipart_uploads15522026/10/26 22:36:19 INFO Vacuumed table table=closures15532026/10/26 22:36:19 INFO Vacuumed table table=objects15542026/10/26 22:36:19 INFO Received complete push request method=POST path=/api/pushes/2/complete15552026/10/26 22:36:19 WARN Failed to register uploaded object key=h684y907cf4ly2rcbbjvkhls96ggzh6y.narinfo error="server returned 404: 404 page not found\n"15562026/10/26 22:36:19 INFO Received complete push request method=POST path=/api/pushes/1/complete15572026/10/26 22:36:19 WARN Failed to register uploaded object key=j9mmrccg59qjjsm7rl7w072kxs8kl67z.narinfo error="server returned 404: 404 page not found\n"15582026/10/26 22:36:19 INFO lead: released remote=192.0.2.1:123415592026/10/26 22:36:19 WARN Failed to register uploaded object key=9p4gf6q5y71rywrhlha9w7hcrgwnkib4.narinfo error="server returned 404: 404 page not found\n"15602026/10/26 22:36:19 INFO Completed push id=2 objects=3 duration=3.667674ms15612026/10/26 22:36:19 INFO Upload complete. (88ms)15622026/10/26 22:36:19 INFO Completed push id=1 objects=9 duration=6.288957ms15632026/10/26 22:36:19 INFO Upload complete. (126ms)1564=== NAME TestClientMultipleUploads1565 client_integration_test.go:478: Uploaded 3 paths in 154.495154ms15662026/10/26 22:36:19 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3LmZjZjdiMzkwLTlhZGItNDcwZi05OGZjLWYzMmEzMDVkMTA2OHgxNzkzMDU0MTc4NTUyMTE0ODcw parts=1015672026/10/26 22:36:19 INFO Received complete push request method=POST path=/api/pushes/1/complete1568--- PASS: TestReconnectLeavesObjectsUnlocked (0.36s)1569=== CONT TestForceGCDuringPushOffersSweptObject1570=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1571=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1572=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1573=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1574=== CONT TestServerTLSConfig1575=== RUN TestServerTLSConfig/no_client_CA1576=== PAUSE TestServerTLSConfig/no_client_CA1577=== RUN TestServerTLSConfig/missing_CA_file1578=== PAUSE TestServerTLSConfig/missing_CA_file1579=== RUN TestServerTLSConfig/not_a_PEM_file1580=== PAUSE TestServerTLSConfig/not_a_PEM_file1581=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1582--- PASS: TestGCSweepDeliversEachKeyOnce (0.46s)1583=== CONT TestService_NativeMTLS15842026/10/26 22:36:19 INFO Completed push id=1 objects=4 duration=10.376471ms15852026/10/26 22:36:19 INFO Received push request method=POST path=/api/pushes1586--- PASS: TestLeadEndsOnShutdown (1.46s)1587=== CONT TestConnectSerialisesConcurrentMigrations15882026/10/26 22:36:19 INFO Starting cleanup of old closures method=DELETE path=/api/closures15892026/10/26 22:36:19 INFO Garbage collection started1590=== CONT TestReadProxyNarStreaming1591--- PASS: TestClientMultipleUploads (0.64s)15922026/10/26 22:36:19 INFO Aborted multipart uploads count=0 kept=015932026/10/26 22:36:19 INFO Aborted multipart uploads count=0 kept=015942026/10/26 22:36:19 WARN Force mode enabled - objects will be deleted immediately without grace period15952026/10/26 22:36:19 WARN Force mode enabled - objects will be deleted immediately without grace period15962026/10/26 22:36:19 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=015972026/10/26 22:36:19 INFO Vacuumed table table=pending_closures15982026/10/26 22:36:19 INFO Aborted multipart uploads count=0 kept=015992026/10/26 22:36:19 INFO Vacuumed table table=pending_objects16002026/10/26 22:36:19 INFO Vacuumed table table=multipart_uploads16012026/10/26 22:36:19 INFO Vacuumed table table=closures16022026/10/26 22:36:19 INFO Vacuumed table table=objects16032026/10/26 22:36:19 WARN Force mode enabled - objects will be deleted immediately without grace period16042026/10/26 22:36:19 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=016052026/10/26 22:36:19 INFO Vacuumed table table=pending_closures16062026/10/26 22:36:19 INFO Vacuumed table table=pending_objects16072026/10/26 22:36:19 INFO Vacuumed table table=multipart_uploads1608=== CONT TestNARDeduplicationMetadataUploadBug1609--- PASS: TestObjectStatsTrigger (0.43s)1610--- PASS: TestSweepRechecksPendingAfterLocking (0.44s)1611=== CONT TestReadProxyOutlastsServerWriteTimeout16122026/10/26 22:36:19 INFO Vacuumed table table=closures16132026/10/26 22:36:19 INFO Vacuumed table table=objects16142026-10-26 22:36:19.922 UTC [1403] ERROR: duplicate key value violates unique constraint "pg_type_typname_nsp_index"16152026-10-26 22:36:19.922 UTC [1403] DETAIL: Key (typname, typnamespace)=(goose_db_version, 2200) already exists.16162026-10-26 22:36:19.922 UTC [1403] STATEMENT: CREATE TABLE goose_db_version (1617 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1618 version_id bigint NOT NULL,1619 is_applied boolean NOT NULL,1620 tstamp timestamp NOT NULL DEFAULT now()1621 )16222026/10/26 22:36:19 INFO Aborted multipart uploads count=0 kept=016232026/10/26 22:36:19 WARN Force mode enabled - objects will be deleted immediately without grace period16242026/10/26 22:36:19 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=016252026/10/26 22:36:19 INFO Vacuumed table table=pending_closures16262026/10/26 22:36:19 INFO Vacuumed table table=pending_objects16272026/10/26 22:36:19 INFO Vacuumed table table=multipart_uploads16282026/10/26 22:36:19 INFO Vacuumed table table=closures16292026/10/26 22:36:19 INFO Vacuumed table table=objects16302026/10/26 22:36:19 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=016312026/10/26 22:36:19 INFO Vacuumed table table=pending_closures16322026/10/26 22:36:19 INFO Vacuumed table table=pending_objects16332026/10/26 22:36:19 INFO Vacuumed table table=multipart_uploads1634--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.36s)1635=== CONT TestReadProxyHead16362026/10/26 22:36:19 INFO Vacuumed table table=closures16372026/10/26 22:36:19 INFO Vacuumed table table=objects16382026/10/26 22:36:19 INFO Received uploads request method=POST path=/api/pending_closures1639--- PASS: TestGCMetrics (0.39s)1640=== CONT TestClientSharedPathCommittedMidPush16412026/10/26 22:36:20 INFO Received uploads request method=POST path=/api/pending_closures16422026/10/26 22:36:20 INFO lead: released remote=192.0.2.1:123416432026/10/26 22:36:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16442026/10/26 22:36:20 INFO Received uploads request method=POST path=/api/pending_closures16452026/10/26 22:36:20 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3LjEyOTlkMTEwLTM0YzYtNGE4MS05YzQ3LTIwOWE4NzVmZGVkNXgxNzkzMDU0MTc4ODU4MDAwNzEz parts=1016462026/10/26 22:36:20 INFO Received complete push request method=POST path=/api/pushes/1/complete16472026/10/26 22:36:20 INFO Aborted multipart uploads count=0 kept=016482026/10/26 22:36:20 WARN mTLS auth: subject not in bound subjects subject="CN=reader"16492026/10/26 22:36:20 WARN mTLS auth: subject not in bound subjects subject="CN=reader"16502026/10/26 22:36:20 INFO lead: acquired remote=192.0.2.1:123416512026/10/26 22:36:20 INFO Completed push id=1 objects=4 duration=15.156308ms16522026/10/26 22:36:20 WARN Force mode enabled - objects will be deleted immediately without grace period16532026/10/26 22:36:20 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16542026/10/26 22:36:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16552026/10/26 22:36:20 INFO Completed upload id=2 objects=2 duration=2.338402ms16562026/10/26 22:36:20 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."16572026/10/26 22:36:20 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1658=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1659--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.29s)1660--- PASS: TestService_NativeMTLS (0.30s)1661=== CONT TestGCTaskStore_GetReturnsLatest1662--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1663=== CONT TestService_AuthMiddleware_OIDC16642026/10/26 22:36:20 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3LjliYjAwYTMwLTZjYTQtNGVkOS04NWRhLTZjMmNiMDlkZWIyMXgxNzkzMDU0MTc4MTk2MTc3OTQx parts=101665--- PASS: TestFailedS3DeleteKeepsTombstone (0.50s)1666=== CONT TestGracefulShutdownDrainsInflight16672026/10/26 22:36:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16682026/10/26 22:36:20 INFO Starting HTTP server address=127.0.0.1:3552516692026/10/26 22:36:20 INFO Shutdown signal received, draining in-flight requests timeout=10s16702026/10/26 22:36:20 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3LmU5ODdlYzdiLThlMjMtNDg5OS04YTgzLWNjNGVmOGZmNGUyNHgxNzkzMDU0MTc4MjA2NTExMTYz parts=1016712026/10/26 22:36:20 INFO Received complete push request method=POST path=/api/pushes/1/complete1672--- PASS: TestGCBugBareHashReferences (0.57s)1673=== CONT TestService_readinessHandler1674--- PASS: TestReadProxyNarStreaming (0.31s)1675=== CONT TestGenerateLandingPage16762026/10/26 22:36:20 INFO Received cleanup request method=DELETE path=/api/pending_closures1677--- PASS: TestGenerateLandingPage (0.01s)1678=== CONT TestGCTaskStore_CompletedAllowsNewTask1679=== CONT TestGCTaskStore_PhaseUpdates1680--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1681=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1682--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)16832026/10/26 22:36:20 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket80/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""16842026/10/26 22:36:20 INFO Aborted multipart uploads count=0 kept=116852026/10/26 22:36:20 INFO Completed push id=1 objects=6 duration=16.726939ms1686--- PASS: TestMetricsCommit (1.60s)1687=== CONT TestClientCADerivations16882026/10/26 22:36:20 INFO Received cleanup request method=DELETE path=/api/pending_closures16892026/10/26 22:36:20 INFO Aborted multipart uploads count=1 kept=01690--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.95s)1691=== CONT TestClientIntegration1692--- PASS: TestPush_CompleteCommitsEveryRoot (3.10s)1693=== CONT TestReadProxyContentNegotiation1694--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1695=== CONT TestGCTaskStore_Fail1696--- PASS: TestGCTaskStore_Fail (0.00s)1697=== CONT TestGCTaskStore_StartNew1698--- PASS: TestGCTaskStore_StartNew (0.00s)1699=== CONT TestClientPushesUseOnePush1700=== CONT TestGCTaskStore_DeduplicateSameParams1701--- PASS: TestMultipartCleanup (0.53s)1702=== CONT TestCacheConfigHandler1703--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1704=== RUN TestCacheConfigHandler/full_config,_no_issuer1705=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1706=== RUN TestCacheConfigHandler/no_cache_url_configured1707=== PAUSE TestCacheConfigHandler/no_cache_url_configured1708=== RUN TestCacheConfigHandler/no_signing_keys1709=== PAUSE TestCacheConfigHandler/no_signing_keys1710=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1711=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1712=== CONT TestDeleteClosuresRacingPins1713=== NAME TestOrphanedObjectsGC1714 orphaned_objects_gc_test.go:287: GC Test Summary:1715 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1716 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1717 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1718 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1719 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1720=== NAME TestNARDeduplicationMetadataUploadBug1721 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1769981359/001/store/yjwvmv5sn1p4s177ysglc19n1kx0sm1w-file1.txt17222026/10/26 22:36:20 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo1723--- PASS: TestOrphanedObjectsGC (0.80s)1724=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17252026/10/26 22:36:20 INFO Received request for more parts method=POST path=/1726=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17272026/10/26 22:36:20 INFO Received uploads request method=POST path=/1728=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17292026/10/26 22:36:20 INFO Received complete multipart upload request method=POST path=/1730=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17312026/10/26 22:36:20 INFO Received uploads request method=POST path=/1732=== CONT TestProxyWriteTimeout/narinfo1733--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)1734 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1735 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1736 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1737 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)17382026/10/26 22:36:20 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo1739=== CONT TestProxyWriteTimeout/unknown_size1740=== CONT TestProxyWriteTimeout/10_GiB_nar1741=== CONT TestProxyWriteTimeout/1_GiB_nar1742=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1743--- PASS: TestProxyWriteTimeout (0.01s)1744 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1745 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1746 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1747 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)17482026/10/26 22:36:20 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17492026/10/26 22:36:20 WARN mTLS auth: bound subjects configured but subject DN unavailable17502026/10/26 22:36:20 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1751--- PASS: TestConcurrentPinUpdatesAgree (0.93s)1752=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1753--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.21s)1754=== CONT TestPendingClosureWriteTimeout/empty1755=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline17562026/10/26 22:36:20 INFO Received push request method=POST path=/api/pushes17572026/10/26 22:36:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17582026/10/26 22:36:20 INFO Uploading yjwvmv5sn1p4s177ysglc19n1kx0sm1w-file1.txt (160B)17592026/10/26 22:36:20 WARN readiness check failed error="closed pool"17602026/10/26 22:36:20 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"17612026/10/26 22:36:20 WARN Failed to register uploaded object key=yjwvmv5sn1p4s177ysglc19n1kx0sm1w.ls error="server returned 404: 404 page not found\n"17622026/10/26 22:36:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17632026/10/26 22:36:20 INFO Signed narinfos id=1 count=117642026/10/26 22:36:20 INFO Uploading 1 narinfos1765--- PASS: TestService_readinessHandler (0.23s)1766=== CONT TestPendingClosureWriteTimeout/400_objects1767=== CONT TestPendingClosureWriteTimeout/670k_objects1768=== CONT TestParseSingleRange/malformed_no_dash1769=== CONT TestParseSingleRange/start_far_past_EOF1770=== CONT TestParseSingleRange/start_past_EOF17712026/10/26 22:36:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41403/oidc1772=== CONT TestParseSingleRange/single_byte1773=== CONT TestParseSingleRange/suffix1774=== CONT TestParseSingleRange/suffix_exceeds_size1775=== CONT TestParseSingleRange/end_clamped_to_size1776=== CONT TestParseSingleRange/open-ended1777=== CONT TestParseSingleRange/closed1778=== CONT TestParseSingleRange/multi-range_ignored1779=== CONT TestParseSingleRange/malformed_both_empty1780=== CONT TestParseSingleRange/malformed_end_before_start1781=== CONT TestParseSingleRange/unknown_unit1782=== CONT TestParseSingleRange/none1783=== CONT TestIsValidUploadKey/narinfo1784--- PASS: TestParseSingleRange (0.01s)1785 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1786 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1787 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1788 --- PASS: TestParseSingleRange/single_byte (0.00s)1789 --- PASS: TestParseSingleRange/suffix (0.00s)1790 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1791 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1792 --- PASS: TestParseSingleRange/open-ended (0.00s)1793 --- PASS: TestParseSingleRange/closed (0.00s)1794 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1795 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1796 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1797 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1798 --- PASS: TestParseSingleRange/none (0.00s)1799=== CONT TestIsValidUploadKey/realisation_plus_in_output1800=== CONT TestIsValidUploadKey/build_log_equals1801=== CONT TestIsValidUploadKey/build_log_plus_in_name1802=== CONT TestIsValidUploadKey/realisation1803=== CONT TestIsValidUploadKey/build_log_home-manager_file1804=== CONT TestIsValidUploadKey/build_log_question_mark1805=== CONT TestIsValidUploadKey/empty_key1806=== CONT TestIsValidUploadKey/nar_xz1807=== CONT TestIsValidUploadKey/absolute1808=== CONT TestIsValidUploadKey/nar_zst1809=== CONT TestIsValidUploadKey/unknown_type1810=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1811=== CONT TestIsValidUploadKey/traversal_nar1812=== CONT TestIsValidUploadKey/traversal1813=== CONT TestIsValidUploadKey/nix-cache-info1814=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1815=== CONT TestIsValidUploadKey/index.html1816=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1817=== CONT TestIsValidUploadKey/listing1818=== CONT TestIsValidUploadKey/build_log1819=== CONT TestIsValidUploadKey/nar_plain1820=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure1821--- PASS: TestIsValidUploadKey (0.01s)1822 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1823 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1824 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1825 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1826 --- PASS: TestIsValidUploadKey/realisation (0.00s)1827 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1828 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1829 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1830 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1831 --- PASS: TestIsValidUploadKey/absolute (0.00s)1832 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1833 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1834 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1835 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1836 --- PASS: TestIsValidUploadKey/traversal (0.00s)1837 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1838 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1839 --- PASS: TestIsValidUploadKey/index.html (0.00s)1840 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1841 --- PASS: TestIsValidUploadKey/listing (0.00s)1842 --- PASS: TestIsValidUploadKey/build_log (0.00s)1843 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)18442026/10/26 22:36:20 INFO Received uploads request method=POST path=/18452026/10/26 22:36:20 INFO Received uploads request method=POST path=/api/pending_closures18462026/10/26 22:36:20 INFO Received complete push request method=POST path=/api/pushes/1/complete18472026/10/26 22:36:20 WARN Failed to register uploaded object key=yjwvmv5sn1p4s177ysglc19n1kx0sm1w.narinfo error="server returned 404: 404 page not found\n"18482026/10/26 22:36:20 INFO Completed push id=1 objects=3 duration=9.810611ms18492026/10/26 22:36:20 INFO Upload complete. (116ms)1850=== NAME TestNARDeduplicationMetadataUploadBug1851 metadata_upload_test.go:54: Retrieved narinfo from S3:1852 StorePath: /build/TestNARDeduplicationMetadataUploadBug1769981359/001/store/yjwvmv5sn1p4s177ysglc19n1kx0sm1w-file1.txt1853 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1854 Compression: zstd1855 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1856 NarSize: 1601857 References: 1858 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1859 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1860 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1861 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}18622026/10/26 22:36:20 INFO Received push request method=POST path=/api/pushes18632026/10/26 22:36:20 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)18642026/10/26 22:36:20 INFO Uploading 0df5m4sa6c4x9ly0wn2z40bnq0gzvjn7-top (224B)18652026/10/26 22:36:20 INFO Uploading 30sls032bbizdfxknsp5lvx67qn4dlhz-shared-dep (136B)1866=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts1867--- PASS: TestReadProxyHead (0.45s)18682026/10/26 22:36:20 INFO Received request for more parts method=POST path=/1869=== NAME TestNARDeduplicationMetadataUploadBug1870 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1769981359/001/store/4ryybgrsnm44am8x736b1f9nz19sqkyp-file2.txt18712026/10/26 22:36:20 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18722026/10/26 22:36:20 WARN Failed to register uploaded object key=nar/1fn5kscbfl8g8w7b6b6rv3ygdms06aq5c97afijz02ynp9qv47xb.nar.zst error="server returned 404: 404 page not found\n"1873=== NAME TestClientIntegration1874 client_integration_test.go:331: Created store path: /build/TestClientIntegration429492208/002/store/xg8d9q0jdhphbz0s6ym2r1hfm8d53397-test-file.txt18752026/10/26 22:36:20 WARN Failed to register uploaded object key=30sls032bbizdfxknsp5lvx67qn4dlhz.ls error="server returned 404: 404 page not found\n"18762026/10/26 22:36:20 WARN Failed to register uploaded object key=0df5m4sa6c4x9ly0wn2z40bnq0gzvjn7.ls error="server returned 404: 404 page not found\n"18772026/10/26 22:36:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18782026/10/26 22:36:20 INFO Signed narinfos id=1 count=218792026/10/26 22:36:20 INFO Uploading 2 narinfos18802026/10/26 22:36:20 WARN Failed to register uploaded object key=30sls032bbizdfxknsp5lvx67qn4dlhz.narinfo error="server returned 404: 404 page not found\n"18812026/10/26 22:36:20 INFO Received complete push request method=POST path=/api/pushes/1/complete18822026/10/26 22:36:20 WARN Failed to register uploaded object key=0df5m4sa6c4x9ly0wn2z40bnq0gzvjn7.narinfo error="server returned 404: 404 page not found\n"18832026/10/26 22:36:20 INFO Completed push id=1 objects=6 duration=8.89902ms18842026/10/26 22:36:20 INFO Upload complete. (111ms)1885=== NAME TestClientSharedPathCommittedMidPush1886 client_integration_test.go:803: Retrieved narinfo from S3:1887 StorePath: /build/TestClientSharedPathCommittedMidPush4052068062/001/store/30sls032bbizdfxknsp5lvx67qn4dlhz-shared-dep1888 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1889 Compression: zstd1890 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821891 NarSize: 1361892 References: 1893 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1894 client_integration_test.go:803: Retrieved narinfo from S3:1895 StorePath: /build/TestClientSharedPathCommittedMidPush4052068062/001/store/0df5m4sa6c4x9ly0wn2z40bnq0gzvjn7-top1896 URL: nar/1fn5kscbfl8g8w7b6b6rv3ygdms06aq5c97afijz02ynp9qv47xb.nar.zst1897 Compression: zstd1898 NarHash: sha256:1fn5kscbfl8g8w7b6b6rv3ygdms06aq5c97afijz02ynp9qv47xb1899 NarSize: 2241900 References: /build/TestClientSharedPathCommittedMidPush4052068062/001/store/30sls032bbizdfxknsp5lvx67qn4dlhz-shared-dep1901 CA: text:sha256:06xrjz07rsq22328zf11wfqm3w3j63947vwvs1w7a2kr55dydgap19022026/10/26 22:36:20 INFO Received push request method=POST path=/api/pushes19032026/10/26 22:36:20 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19042026/10/26 22:36:20 INFO Received push request method=POST path=/api/pushes19052026/10/26 22:36:20 WARN Failed to register uploaded object key=4ryybgrsnm44am8x736b1f9nz19sqkyp.ls error="server returned 404: 404 page not found\n"19062026/10/26 22:36:20 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign19072026/10/26 22:36:20 INFO Signed narinfos id=2 count=119082026/10/26 22:36:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19092026/10/26 22:36:20 INFO Uploading 1 narinfos19102026/10/26 22:36:20 INFO Uploading xg8d9q0jdhphbz0s6ym2r1hfm8d53397-test-file.txt (152B)1911--- PASS: TestClientSharedPathCommittedMidPush (0.54s)1912=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19132026/10/26 22:36:20 INFO Received complete multipart upload request method=POST path=/19142026/10/26 22:36:20 WARN Failed to register uploaded object key=xg8d9q0jdhphbz0s6ym2r1hfm8d53397.ls error="server returned 404: 404 page not found\n"19152026/10/26 22:36:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19162026/10/26 22:36:20 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"19172026/10/26 22:36:20 INFO Signed narinfos id=1 count=119182026/10/26 22:36:20 INFO Uploading 1 narinfos19192026/10/26 22:36:20 INFO Received complete push request method=POST path=/api/pushes/2/complete19202026/10/26 22:36:20 WARN Failed to register uploaded object key=4ryybgrsnm44am8x736b1f9nz19sqkyp.narinfo error="server returned 404: 404 page not found\n"19212026/10/26 22:36:20 INFO Completed push id=2 objects=3 duration=3.119043ms19222026/10/26 22:36:20 INFO Upload complete. (70ms)1923=== NAME TestClientCADerivations1924 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations878674837/001/store/d5xgjjmpmqkbmgijcnjc7j16ic2f2vhb-ca-test1925=== NAME TestNARDeduplicationMetadataUploadBug1926 metadata_upload_test.go:76: Retrieved narinfo from S3:1927 StorePath: /build/TestNARDeduplicationMetadataUploadBug1769981359/001/store/4ryybgrsnm44am8x736b1f9nz19sqkyp-file2.txt1928 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1929 Compression: zstd1930 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1931 NarSize: 1601932 References: 1933 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1934 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1935 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1936 {"version":1,"root":{"type":"regular","size":44}}19372026/10/26 22:36:20 INFO Received complete push request method=POST path=/api/pushes/1/complete19382026/10/26 22:36:20 WARN Failed to register uploaded object key=xg8d9q0jdhphbz0s6ym2r1hfm8d53397.narinfo error="server returned 404: 404 page not found\n"19392026/10/26 22:36:20 INFO Completed push id=1 objects=3 duration=7.602748ms19402026/10/26 22:36:20 INFO Upload complete. (83ms)1941=== NAME TestClientCADerivations1942 client_ca_test.go:139: Found 1 dependencies (including self)1943--- PASS: TestNARDeduplicationMetadataUploadBug (0.68s)1944=== CONT TestClientErrorHandling/InvalidStorePath19452026/10/26 22:36:20 INFO All 1 paths already cached1946=== NAME TestClientIntegration1947 client_integration_test.go:357: Retrieved narinfo from S3:1948 StorePath: /build/TestClientIntegration429492208/002/store/xg8d9q0jdhphbz0s6ym2r1hfm8d53397-test-file.txt1949 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1950 Compression: zstd1951 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11952 NarSize: 1521953 References: 1954 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk119552026/10/26 22:36:20 INFO Received uploads request method=POST path=/api/pending_closures1956 client_integration_test.go:358: Retrieved .ls file from S3 (compressed size: 77 bytes)1957 client_integration_test.go:358: Decompressed .ls content (64 bytes):1958 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1959=== CONT TestClientErrorHandling/ServerNotAvailable1960--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.46s)19612026/10/26 22:36:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1962=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1963=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1964=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1965=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1966=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1967=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1968=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1969=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1970=== CONT TestClientErrorHandling/InvalidAuthToken19712026/10/26 22:36:20 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3LmIzNDVlYWVmLWM5MDYtNDk0MS1hZjEwLTkzNzJhNGFiOTc2MHgxNzkzMDU0MTc5ODE2MTAwOTc5 parts=1019722026/10/26 22:36:20 INFO Received complete push request method=POST path=/api/pushes/2/complete19732026/10/26 22:36:20 INFO Completed push id=2 objects=4 duration=2.801303ms19742026/10/26 22:36:20 INFO Received push request method=POST path=/api/pushes19752026/10/26 22:36:20 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)19762026/10/26 22:36:20 INFO Uploading w8jqj023svd7wvibg6d6ps2zyc84bn1m-b (216B)19772026/10/26 22:36:20 INFO Uploading ag8b0nw9x833w1446wvs08d14dl40zw1-shared-dep (136B)1978=== CONT TestPush_RejectsBadRequests/root_not_in_objects1979--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.53s)19802026/10/26 22:36:20 INFO Received push request method=POST path=/api/pushes19812026/10/26 22:36:20 WARN Failed to register uploaded object key=pawazl84aj3353s5jhycr3zgn839cprl.ls error="server returned 404: 404 page not found\n"1982=== CONT TestPush_RejectsBadRequests/bad_root19832026/10/26 22:36:20 WARN Failed to register uploaded object key=w8jqj023svd7wvibg6d6ps2zyc84bn1m.ls error="server returned 404: 404 page not found\n"19842026/10/26 22:36:20 INFO Received push request method=POST path=/api/pushes1985=== CONT TestPush_RejectsBadRequests/no_objects19862026/10/26 22:36:20 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19872026/10/26 22:36:20 INFO Received push request method=POST path=/api/pushes19882026/10/26 22:36:20 WARN Failed to register uploaded object key=nar/0i34nr689s8h67d6jfy8li5nr3r68xvbnjp2y6r99b7nin6rpdxa.nar.zst error="server returned 404: 404 page not found\n"1989=== CONT TestPush_RejectsBadRequests/no_roots19902026/10/26 22:36:20 INFO Received push request method=POST path=/api/pushes1991=== CONT TestGCEndsOnShutdown/before_the_run19922026/10/26 22:36:20 INFO Received push request method=POST path=/api/pushes19932026/10/26 22:36:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19942026/10/26 22:36:20 INFO Received push request method=POST path=/api/pushes19952026/10/26 22:36:20 WARN Failed to register uploaded object key=ag8b0nw9x833w1446wvs08d14dl40zw1.ls error="server returned 404: 404 page not found\n"19962026/10/26 22:36:20 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/present19972026/10/26 22:36:20 INFO Signed narinfos id=1 count=319982026/10/26 22:36:20 INFO Uploading 3 narinfos19992026/10/26 22:36:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20002026/10/26 22:36:20 INFO Uploading d5xgjjmpmqkbmgijcnjc7j16ic2f2vhb-ca-test (144B)20012026/10/26 22:36:20 INFO Object in database but missing from S3 key=xg8d9q0jdhphbz0s6ym2r1hfm8d53397.ls20022026/10/26 22:36:20 WARN Found objects in DB but missing from S3, will re-upload count=120032026/10/26 22:36:20 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)2004--- PASS: TestPush_RejectsBadRequests (0.38s)2005 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2006 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2007 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2008 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)20092026/10/26 22:36:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20102026/10/26 22:36:20 WARN Failed to register uploaded object key=log/vzz5lqrbpqnz4w44rhhhn98pgms55jkz-ca-test.drv error="server returned 404: 404 page not found\n"20112026/10/26 22:36:20 WARN Failed to register uploaded object key=ag8b0nw9x833w1446wvs08d14dl40zw1.narinfo error="server returned 404: 404 page not found\n"20122026/10/26 22:36:20 WARN Failed to register uploaded object key=w8jqj023svd7wvibg6d6ps2zyc84bn1m.narinfo error="server returned 404: 404 page not found\n"20132026/10/26 22:36:20 INFO Received complete push request method=POST path=/api/pushes/1/complete20142026/10/26 22:36:20 WARN Failed to register uploaded object key=pawazl84aj3353s5jhycr3zgn839cprl.narinfo error="server returned 404: 404 page not found\n"20152026/10/26 22:36:20 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"20162026/10/26 22:36:20 WARN Failed to register uploaded object key=xg8d9q0jdhphbz0s6ym2r1hfm8d53397.ls error="server returned 404: 404 page not found\n"20172026/10/26 22:36:20 INFO Received complete push request method=POST path=/api/pushes/2/complete20182026/10/26 22:36:20 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3LmFjNzAzNDJiLTEyZDMtNDk4OS04MWRkLTVjNGFiMmJkMjQ4NHgxNzkzMDU0MTc4MTk2MzQ5Njcx parts=1020192026/10/26 22:36:20 INFO Completed push id=2 objects=3 duration=2.437833ms20202026/10/26 22:36:20 INFO Upload complete. (120ms)20212026/10/26 22:36:20 INFO Completed push id=1 objects=8 duration=8.85049ms20222026/10/26 22:36:20 INFO Upload complete. (173ms)2023=== NAME TestClientIntegration2024 client_integration_test.go:375: Retrieved .ls file from S3 (compressed size: 62 bytes)2025=== NAME TestClientPushesUseOnePush2026 client_pushes_test.go:97: Retrieved narinfo from S3:2027 StorePath: /build/TestClientPushesUseOnePush3128992575/001/store/ag8b0nw9x833w1446wvs08d14dl40zw1-shared-dep2028 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2029 Compression: zstd2030 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822031 NarSize: 1362032 References: 2033 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2034=== NAME TestClientIntegration2035 client_integration_test.go:375: Decompressed .ls content (49 bytes):2036 {"version":1,"root":{"type":"regular","size":39}}2037=== NAME TestClientPushesUseOnePush2038 client_pushes_test.go:97: Retrieved narinfo from S3:2039 StorePath: /build/TestClientPushesUseOnePush3128992575/001/store/pawazl84aj3353s5jhycr3zgn839cprl-a2040 URL: nar/0i34nr689s8h67d6jfy8li5nr3r68xvbnjp2y6r99b7nin6rpdxa.nar.zst2041 Compression: zstd2042 NarHash: sha256:0i34nr689s8h67d6jfy8li5nr3r68xvbnjp2y6r99b7nin6rpdxa2043 NarSize: 21620442026/10/26 22:36:20 WARN Failed to register uploaded object key=d5xgjjmpmqkbmgijcnjc7j16ic2f2vhb.ls error="server returned 404: 404 page not found\n"2045 References: /build/TestClientPushesUseOnePush3128992575/001/store/ag8b0nw9x833w1446wvs08d14dl40zw1-shared-dep20462026/10/26 22:36:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign2047 CA: text:sha256:1wjfh6yliizx1d6sjbykqncjnp9i78ihgjri52bjmp1rc01ff2kg20482026/10/26 22:36:20 INFO Signed narinfos id=1 count=120492026/10/26 22:36:20 INFO Uploading 1 narinfos20502026/10/26 22:36:20 WARN Request failed, retrying attempt=2 backoff=215.073858ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2051 client_pushes_test.go:97: Retrieved narinfo from S3:2052 StorePath: /build/TestClientPushesUseOnePush3128992575/001/store/w8jqj023svd7wvibg6d6ps2zyc84bn1m-b2053 URL: nar/0i34nr689s8h67d6jfy8li5nr3r68xvbnjp2y6r99b7nin6rpdxa.nar.zst2054 Compression: zstd2055 NarHash: sha256:0i34nr689s8h67d6jfy8li5nr3r68xvbnjp2y6r99b7nin6rpdxa2056 NarSize: 2162057 References: /build/TestClientPushesUseOnePush3128992575/001/store/ag8b0nw9x833w1446wvs08d14dl40zw1-shared-dep2058 CA: text:sha256:1wjfh6yliizx1d6sjbykqncjnp9i78ihgjri52bjmp1rc01ff2kg20592026/10/26 22:36:20 INFO Received complete push request method=POST path=/api/pushes/1/complete20602026/10/26 22:36:20 WARN Failed to register uploaded object key=d5xgjjmpmqkbmgijcnjc7j16ic2f2vhb.narinfo error="server returned 404: 404 page not found\n"20612026/10/26 22:36:20 INFO Completed push id=1 objects=4 duration=9.270211ms20622026/10/26 22:36:20 INFO Upload complete. (204ms)2063=== NAME TestClientCADerivations2064 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations878674837/001/store/d5xgjjmpmqkbmgijcnjc7j16ic2f2vhb-ca-test2065 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2066 Compression: zstd2067 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2068 NarSize: 1442069 References: 2070 Deriver: /build/TestClientCADerivations878674837/001/store/vzz5lqrbpqnz4w44rhhhn98pgms55jkz-ca-test.drv2071 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2072 client_ca_test.go:185: Checking for realisation files in S3...2073 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2074 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2075=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete2076--- PASS: TestClientPushesUseOnePush (0.66s)2077=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark20782026/10/26 22:36:20 INFO Received push request method=POST path=/api/pushes20792026/10/26 22:36:20 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)20802026/10/26 22:36:20 WARN Failed to register uploaded object key=xg8d9q0jdhphbz0s6ym2r1hfm8d53397.ls error="server returned 404: 404 page not found\n"20812026/10/26 22:36:20 INFO Received complete push request method=POST path=/api/pushes/3/complete20822026/10/26 22:36:20 INFO Completed push id=3 objects=3 duration=3.005183ms20832026/10/26 22:36:20 INFO Upload complete. (62ms)2084=== NAME TestClientIntegration2085 client_integration_test.go:392: Retrieved .ls file from S3 (compressed size: 62 bytes)2086 client_integration_test.go:392: Decompressed .ls content (49 bytes):2087 {"version":1,"root":{"type":"regular","size":39}}2088=== NAME TestClientCADerivations2089 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2090 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2091 error: binary cache 's3://bucket92?endpoint=http://localhost:37279®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations878674837/001/store'2092 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12093--- PASS: TestConnectSerialisesConcurrentMigrations (1.12s)2094=== CONT TestService_RequireScope_OIDC/ops_may_admin2095=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2096=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read20972026/10/26 22:36:20 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]20982026/10/26 22:36:20 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2099=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2100=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2101=== CONT TestService_RequireScope_OIDC/reader_may_not_write2102=== CONT TestService_RequireScope_OIDC/ops_may_not_write2103=== CONT TestService_RequireScope_OIDC/static_token_may_admin2104=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2105=== CONT TestService_RequireScope_OIDC/builder_may_write2106=== CONT TestService_RequireScope_OIDC/static_token_may_write2107=== CONT TestService_RequireScope_OIDC/reader_may_read2108=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2109=== CONT TestService_RequireScope_OIDC/writer_implies_read2110=== CONT TestIsValidCachePath/nar_zst2111=== CONT TestIsValidCachePath/short_hash2112=== CONT TestIsValidCachePath/wrong_extension2113=== CONT TestIsValidCachePath/leading_slash2114=== CONT TestIsValidCachePath/empty2115=== CONT TestIsValidCachePath/nar_uncompressed2116=== CONT TestIsValidCachePath/log2117=== CONT TestIsValidCachePath/ls2118=== CONT TestIsValidCachePath/realisation2119=== CONT TestIsValidCachePath/nar_bz22120=== CONT TestIsValidCachePath/invalid_char_e2121=== CONT TestIsValidCachePath/index.html2122=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2123=== CONT TestIsValidCachePath/nar_xz2124=== CONT TestIsValidCachePath/nix-cache-info2125=== CONT TestIsValidCachePath/narinfo2126=== CONT TestIsValidCachePath/traversal_parent2127=== CONT TestIsValidCachePath/invalid_char_u2128=== CONT TestIsValidCachePath/traversal_in_middle2129=== CONT TestIsValidCachePath/random_path2130=== CONT TestResolveDBConnectionString/nothing_configured2131--- PASS: TestIsValidCachePath (0.00s)2132 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2133 --- PASS: TestIsValidCachePath/short_hash (0.00s)2134 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2135 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2136 --- PASS: TestIsValidCachePath/empty (0.00s)2137 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2138 --- PASS: TestIsValidCachePath/log (0.00s)2139 --- PASS: TestIsValidCachePath/ls (0.00s)2140 --- PASS: TestIsValidCachePath/realisation (0.00s)2141 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2142 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2143 --- PASS: TestIsValidCachePath/index.html (0.00s)2144 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2145 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2146 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2147 --- PASS: TestIsValidCachePath/narinfo (0.00s)2148 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2149 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2150 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2151 --- PASS: TestIsValidCachePath/random_path (0.00s)2152=== CONT TestResolveDBConnectionString/file_when_flag_empty2153=== CONT TestResolveDBConnectionString/flag_wins2154=== CONT TestResolveDBConnectionString/missing_file_is_an_error2155=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2156=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true2157--- PASS: TestResolveDBConnectionString (0.00s)2158 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2159 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2160 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2161 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2162 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2163--- PASS: TestClientCADerivations (0.79s)2164=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false2165=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows2166--- PASS: TestService_RequireScope_OIDC (0.39s)2167 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2168 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2169 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2170 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2171 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2172 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2173 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2174 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2175 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2176 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2177 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2178 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2179 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2180 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)21812026/10/26 22:36:20 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2182=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check21832026/10/26 22:36:21 INFO Received push request method=POST path=/api/pushes21842026/10/26 22:36:21 WARN Request failed, retrying attempt=3 backoff=362.449414ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21852026/10/26 22:36:21 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21862026/10/26 22:36:21 INFO Uploading gf6hdq9768db67zpfgjn95kbymls6ch1-lost-commit.txt (152B)21872026/10/26 22:36:21 INFO Aborted multipart uploads count=0 kept=021882026/10/26 22:36:21 WARN Force mode enabled - objects will be deleted immediately without grace period21892026/10/26 22:36:21 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:37279/bucket103/?delete=\": context canceled"21902026/10/26 22:36:21 INFO Aborted multipart uploads count=0 kept=021912026/10/26 22:36:21 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"21922026/10/26 22:36:21 WARN Force mode enabled - objects will be deleted immediately without grace period21932026/10/26 22:36:21 WARN Failed to register uploaded object key=gf6hdq9768db67zpfgjn95kbymls6ch1.ls error="server returned 404: 404 page not found\n"21942026/10/26 22:36:21 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign21952026/10/26 22:36:21 INFO Signed narinfos id=4 count=121962026/10/26 22:36:21 INFO Uploading 1 narinfos2197=== CONT TestServerTLSConfig/missing_CA_file2198=== CONT TestServerTLSConfig/not_a_PEM_file2199=== CONT TestServerTLSConfig/no_client_CA2200=== CONT TestCacheConfigHandler/full_config,_no_issuer2201=== CONT TestCacheConfigHandler/no_signing_keys2202--- PASS: TestServerTLSConfig (0.00s)2203 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2204 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2205 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2206=== CONT TestCacheConfigHandler/no_cache_url_configured2207=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2208=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected2209--- PASS: TestCacheConfigHandler (0.00s)2210 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2211 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2212 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2213 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2214=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token22152026/10/26 22:36:21 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/OIDC_token_with_wrong_org_rejected22182026/10/26 22:36:21 WARN Authentication failed token_preview=eyJhbGciOi...TfPabSC0qw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2219--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.01s)2220 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.81s)2221 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.81s)22222026/10/26 22:36:21 INFO Received complete push request method=POST path=/api/pushes/4/complete22232026/10/26 22:36:21 WARN Failed to register uploaded object key=gf6hdq9768db67zpfgjn95kbymls6ch1.narinfo error="server returned 404: 404 page not found\n"22242026/10/26 22:36:21 INFO Completed push id=4 objects=3 duration=2.512993ms2225--- PASS: TestGCEndsOnShutdown (0.00s)2226 --- PASS: TestGCEndsOnShutdown/before_the_run (0.27s)2227 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.24s)2228 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.27s)22292026/10/26 22:36:21 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:46251/api/pushes/4/complete\": EOF" url=http://127.0.0.1:46251/api/pushes/4/complete2230--- PASS: TestService_AuthMiddleware_OIDC (0.55s)2231 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2232 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2233 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2234 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)22352026/10/26 22:36:21 INFO Received uploads request method=POST path=/api/pending_closures22362026/10/26 22:36:21 INFO Received uploads request method=POST path=/api/pending_closures22372026/10/26 22:36:21 INFO lead: released remote=192.0.2.1:123422382026/10/26 22:36:21 INFO Aborted multipart uploads count=0 kept=022392026/10/26 22:36:21 WARN Force mode enabled - objects will be deleted immediately without grace period22402026/10/26 22:36:21 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=022412026/10/26 22:36:21 INFO Vacuumed table table=pending_closures2242--- PASS: TestLeadElectsOneAndHandsOver (2.74s)22432026/10/26 22:36:21 INFO Vacuumed table table=pending_objects22442026/10/26 22:36:21 INFO Vacuumed table table=multipart_uploads22452026/10/26 22:36:21 INFO Vacuumed table table=closures22462026/10/26 22:36:21 INFO Vacuumed table table=objects22472026/10/26 22:36:21 INFO Received uploads request method=POST path=/api/pending_closures22482026/10/26 22:36:21 INFO Received complete push request method=POST path=/api/pushes/4/complete22492026-10-26 22:36:21.221 UTC [1467] ERROR: Push does not exist: id=422502026-10-26 22:36:21.221 UTC [1467] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE22512026-10-26 22:36:21.221 UTC [1467] STATEMENT: -- name: CommitPush :one2252 SELECT commit_push($1::bigint)::bigint2253 22542026/10/26 22:36:21 WARN Push not found id=422552026/10/26 22:36:21 INFO Aborted multipart uploads count=0 kept=022562026/10/26 22:36:21 INFO Upload complete. (239ms)2257--- PASS: TestReadProxyContentNegotiation (1.03s)2258=== NAME TestClientIntegration2259 client_integration_test.go:422: Retrieved narinfo from S3:2260 StorePath: /build/TestClientIntegration429492208/002/store/gf6hdq9768db67zpfgjn95kbymls6ch1-lost-commit.txt2261 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst2262 Compression: zstd2263 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2264 NarSize: 1522265 References: 2266 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl22672026/10/26 22:36:21 WARN Force mode enabled - objects will be deleted immediately without grace period2268 client_integration_test.go:425: Testing garbage collection...22692026/10/26 22:36:21 INFO Received uploads request method=POST path=/api/pending_closures22702026/10/26 22:36:21 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=022712026/10/26 22:36:21 INFO Vacuumed table table=pending_closures22722026/10/26 22:36:21 INFO Vacuumed table table=pending_objects22732026/10/26 22:36:21 INFO Vacuumed table table=multipart_uploads22742026/10/26 22:36:21 INFO Vacuumed table table=closures22752026/10/26 22:36:21 INFO Vacuumed table table=objects22762026/10/26 22:36:21 INFO Starting cleanup of old closures method=DELETE path=/api/closures22772026/10/26 22:36:21 INFO Garbage collection started22782026/10/26 22:36:21 INFO Aborted multipart uploads count=0 kept=022792026-10-26 22:36:21.278 UTC [173] LOG: checkpoints are occurring too frequently (10 seconds apart)22802026-10-26 22:36:21.278 UTC [173] HINT: Consider increasing the configuration parameter "max_wal_size".22812026-10-26 22:36:21.278 UTC [173] LOG: checkpoint starting: wal22822026/10/26 22:36:21 WARN Force mode enabled - objects will be deleted immediately without grace period22832026/10/26 22:36:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22842026/10/26 22:36:21 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3LmE3NzAzYTQzLTkwOWItNGY2Ni1iMTIyLWI4NTc0NjJhNDVhZHgxNzkzMDU0MTc4MTkzNTM3MjQ4 parts=102285--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2286 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.25s)2287 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.34s)22882026/10/26 22:36:21 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=022892026/10/26 22:36:21 INFO Vacuumed table table=pending_closures22902026/10/26 22:36:21 INFO Vacuumed table table=pending_objects22912026/10/26 22:36:21 INFO Vacuumed table table=multipart_uploads22922026/10/26 22:36:21 INFO Vacuumed table table=closures22932026/10/26 22:36:21 INFO Vacuumed table table=objects22942026/10/26 22:36:21 WARN Request failed, retrying attempt=4 backoff=741.72512ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2295--- PASS: TestPendingClosureWriteTimeout (0.01s)2296 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2297 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2298 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2299 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.12s)23002026/10/26 22:36:21 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3LmY2OTYwMTBjLTkwNGYtNDVjMi04YjE5LWZhYzdkMTM3ZGNmNXgxNzkzMDU0MTgxMjQ1MDQ0NDc1 error="Access Denied"23012026/10/26 22:36:21 WARN keeping failed pending closure for cleanup to retry the abort id=12302--- PASS: TestPendingClosureFailureTracksEveryUpload (0.00s)2303 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (0.76s)2304 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (0.83s)2305--- PASS: TestDeleteClosuresRacingPins (1.55s)2306=== NAME TestOrphanedObjectsGCStressTest2307 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2308 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion23092026/10/26 22:36:21 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=023102026/10/26 22:36:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23112026/10/26 22:36:21 INFO Received create pin request method=POST path=/api/pins/myapp23122026/10/26 22:36:21 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2428210755/001/store/94yndn3szgckrga14gr8y69l3w66vkys-pinned-file.txt narinfo_key=94yndn3szgckrga14gr8y69l3w66vkys.narinfo23132026/10/26 22:36:21 INFO Starting cleanup of old closures method=DELETE path=/api/closures23142026/10/26 22:36:21 INFO Garbage collection started23152026/10/26 22:36:21 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=NjkxYTg0YTUtY2Q4OS00ZTQ3LTk1NWYtNzVlZjZjOTk0MTU3LjNkYWZiNGM1LWU1OGYtNDg3Yi1hNWUwLWRlMjI4ZWJmZDBjMXgxNzkzMDU0MTc4MTk2NjY2MTAy parts=1023162026/10/26 22:36:21 INFO Aborted multipart uploads count=0 kept=023172026/10/26 22:36:21 WARN Force mode enabled - objects will be deleted immediately without grace period23182026/10/26 22:36:21 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=023192026/10/26 22:36:21 INFO Vacuumed table table=pending_closures23202026/10/26 22:36:21 INFO Vacuumed table table=pending_objects23212026/10/26 22:36:21 INFO Vacuumed table table=multipart_uploads23222026/10/26 22:36:21 INFO Vacuumed table table=closures23232026/10/26 22:36:21 INFO Vacuumed table table=objects23242026-10-26 22:36:21.883 UTC [760] ERROR: could not obtain lock on row in relation "closures"23252026-10-26 22:36:21.883 UTC [760] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23262026-10-26 22:36:21.883 UTC [760] ERROR: could not obtain lock on row in relation "closures"23272026-10-26 22:36:21.883 UTC [760] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23282026-10-26 22:36:21.884 UTC [760] ERROR: could not obtain lock on row in relation "closures"23292026-10-26 22:36:21.884 UTC [760] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23302026-10-26 22:36:21.884 UTC [760] ERROR: could not obtain lock on row in relation "closures"23312026-10-26 22:36:21.884 UTC [760] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23322026-10-26 22:36:21.885 UTC [760] ERROR: could not obtain lock on row in relation "closures"23332026-10-26 22:36:21.885 UTC [760] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT2334--- PASS: TestPush_RootsAreLockedInByteOrder (4.82s)23352026/10/26 22:36:22 WARN Request failed, retrying attempt=5 backoff=1.701271573s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23362026/10/26 22:36:22 WARN Rate limiter enabled after throttle name=s3-test rate=523372026/10/26 22:36:22 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2338=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2339 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102340 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002341--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.21s)2342=== NAME TestOrphanedObjectsGCStressTest2343 orphaned_objects_gc_test.go:503: Stress test completed successfully:2344 orphaned_objects_gc_test.go:504: - Active objects preserved: 202345 orphaned_objects_gc_test.go:505: - Objects deleted: 2102346 orphaned_objects_gc_test.go:506: - Total GC'd: 2102347--- PASS: TestOrphanedObjectsGCStressTest (3.71s)23482026/10/26 22:36:23 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02349=== NAME TestClientIntegration2350 client_integration_test.go:432: Objects in database after GC:2351 client_integration_test.go:432: Successfully deleted all objects with GC --force2352--- PASS: TestClientIntegration (3.12s)2353--- PASS: TestConnectWaitsForAPeerMigration (5.15s)2354=== NAME TestPinProtectsFromGC2355 client_integration_test.go:963: Pin successfully protected closure from garbage collection23562026/10/26 22:36:23 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: TestPinProtectsFromGC (4.69s)23582026/10/26 22:36:23 WARN Request failed, retrying attempt=2 backoff=181.021698ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23592026/10/26 22:36:24 WARN Request failed, retrying attempt=3 backoff=418.201558ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2360--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.65s)23612026/10/26 22:36:24 WARN Request failed, retrying attempt=4 backoff=767.140943ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23622026/10/26 22:36:24 INFO Aborted multipart uploads count=1 kept=023632026/10/26 22:36:24 INFO Received cleanup request method=DELETE path=/api/pending_closures23642026/10/26 22:36:24 INFO Aborted multipart uploads count=1 kept=02365--- PASS: TestPendingCleanupUsesOneCutoff (6.48s)23662026/10/26 22:36:25 WARN Request failed, retrying attempt=5 backoff=1.748021501s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2367--- PASS: TestUploadHandlersRejectOversizedBody (0.68s)2368 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.75s)2369 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.69s)2370 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (6.47s)23712026/10/26 22:36:27 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"23722026/10/26 22:36:27 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-config23732026/10/26 22:36:27 WARN Request failed, retrying attempt=2 backoff=215.932404ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23742026/10/26 22:36:27 WARN Request failed, retrying attempt=3 backoff=411.66394ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23752026/10/26 22:36:27 WARN Request failed, retrying attempt=4 backoff=804.270333ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23762026/10/26 22:36:28 WARN Request failed, retrying attempt=5 backoff=1.485046538s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23772026/10/26 22:36:30 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/26 22:36:30 WARN Request failed, retrying attempt=2 backoff=184.755512ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23792026/10/26 22:36:30 WARN Request failed, retrying attempt=3 backoff=399.492759ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23802026/10/26 22:36:30 WARN Request failed, retrying attempt=4 backoff=812.460029ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23812026/10/26 22:36:31 WARN Request failed, retrying attempt=5 backoff=1.628234342s 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.25s)2384 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.36s)2385 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.65s)2386PASS2387{"timestamp":"2026-10-26T22:36:33.271657835Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:52604","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(397)"}2388{"timestamp":"2026-10-26T22:36:33.271694665Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:53654","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(386)"}23892026-10-26 22:36:33.600 UTC [168] LOG: received smart shutdown request23902026-10-26 22:36:33.605 UTC [168] LOG: background worker "logical replication launcher" (PID 178) exited with exit code 123912026-10-26 22:36:34.783 UTC [173] LOG: checkpoint complete: wrote 10507 buffers (64.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=12.509 s, sync=0.938 s, total=13.505 s; sync files=37080, longest=0.002 s, average=0.001 s; distance=533272 kB, estimate=533272 kB; lsn=0/22953640, redo lsn=0/2202BF2823922026-10-26 22:36:34.785 UTC [173] LOG: shutting down23932026-10-26 22:36:34.786 UTC [173] LOG: checkpoint starting: shutdown immediate23942026-10-26 22:36:34.818 UTC [173] LOG: checkpoint complete: wrote 193 buffers (1.2%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.005 s, sync=0.025 s, total=0.033 s; sync files=124, longest=0.001 s, average=0.001 s; distance=9373 kB, estimate=480882 kB; lsn=0/229536B8, redo lsn=0/229536B823952026-10-26 22:36:34.896 UTC [168] 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 TestValidateToken_WrongAudience2437=== CONT TestValidateToken_MultipleProviders2438=== CONT TestScopes_Rules2439=== CONT TestScopes_ConfigValidation2440=== CONT TestScopes_LegacyProviderDefaultsToWrite2441=== CONT TestPins_ConfigValidation2442=== CONT TestPins_TopLevelShorthand2443=== CONT TestPins_ReservedForMatchingRule2444=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2445=== CONT TestNewValidator_KubernetesRequiresCA2446=== CONT TestValidateToken_KubernetesServiceAccount2447=== CONT TestValidateToken_ValidToken2448=== CONT TestValidateToken_Expired2449=== CONT TestValidateToken_NoMatchingProvider2450--- PASS: TestAudienceForIssuer (0.00s)2451--- PASS: TestScopes_ConfigValidation (0.00s)2452--- PASS: TestPins_ConfigValidation (0.00s)2453=== CONT TestGlobMatch2454=== CONT TestHTTPClientForHasTimeouts2455=== CONT TestValidateToken_BoundClaimsMismatch2456=== CONT TestValidateToken_BoundSubjectMismatch2457=== RUN TestGlobMatch/foo_foo2458=== PAUSE TestGlobMatch/foo_foo2459=== 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/refs/*/main_refs/heads/main2509=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02510=== CONT TestGlobMatch/fo?_foo2511=== CONT TestGlobMatch/*/*_foo2512=== CONT TestGlobMatch/fo?_fooo2513=== CONT TestGlobMatch/foo*bar_foo123bar2514=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2515=== CONT TestGlobMatch/*bar_foobar2516=== CONT TestGlobMatch/foo*_foobar2517=== CONT TestGlobMatch/?oo_foo2518=== CONT TestGlobMatch/*bar_bar2519=== CONT TestGlobMatch/*bar_foo2520=== CONT TestGlobMatch/*_2521=== CONT TestGlobMatch/*_anything2522=== CONT TestGlobMatch/foo*bar_foobarbaz2523=== CONT TestGlobMatch/foo_foo2524=== CONT TestGlobMatch/*/*_foo/bar2525=== CONT TestGlobMatch/?oo_boo2526=== CONT TestGlobMatch/fo?_fo2527=== CONT TestGlobMatch/foo*_bar2528=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2529=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2530=== CONT TestGlobMatch/foo*bar_foobar2531=== CONT TestGlobMatch/foo_bar2532--- PASS: TestGlobMatch (0.01s)2533 --- PASS: TestGlobMatch/foo*_foo (0.00s)2534 --- PASS: TestGlobMatch/fo?_foo (0.00s)2535 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2536 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2537 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2538 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2539 --- PASS: TestGlobMatch/*/*_foo (0.00s)2540 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2541 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2542 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2543 --- PASS: TestGlobMatch/?oo_foo (0.00s)2544 --- PASS: TestGlobMatch/*bar_bar (0.00s)2545 --- PASS: TestGlobMatch/*bar_foo (0.00s)2546 --- PASS: TestGlobMatch/*_ (0.00s)2547 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2548 --- PASS: TestGlobMatch/*_anything (0.00s)2549 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2550 --- PASS: TestGlobMatch/foo_foo (0.00s)2551 --- PASS: TestGlobMatch/?oo_boo (0.00s)2552 --- PASS: TestGlobMatch/fo?_fo (0.00s)2553 --- PASS: TestGlobMatch/foo*_bar (0.00s)2554 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2555 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2556 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2557 --- PASS: TestGlobMatch/foo_bar (0.00s)25582026/10/26 22:36:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34595/oidc25592026/10/26 22:36:38 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12325602026/10/26 22:36:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37797/oidc2561--- PASS: TestValidateToken_Expired (0.05s)2562--- PASS: TestValidateToken_ValidToken (0.05s)25632026/10/26 22:36:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41931/oidc2564--- PASS: TestValidateToken_BoundClaimsMismatch (0.05s)2565--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.06s)25662026/10/26 22:36:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42173/oidc25672026/10/26 22:36:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33133/oidc2568--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.09s)2569--- PASS: TestPins_TopLevelShorthand (0.09s)25702026/10/26 22:36:38 http: TLS handshake error from 127.0.0.1:44200: remote error: tls: bad certificate2571--- PASS: TestNewValidator_KubernetesRequiresCA (0.09s)25722026/10/26 22:36:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42525/oidc2573--- PASS: TestPins_ReservedForMatchingRule (0.11s)25742026/10/26 22:36:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43653/oidc2575--- PASS: TestValidateToken_WrongAudience (0.13s)25762026/10/26 22:36:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33805/oidc2577--- PASS: TestValidateToken_BoundSubjectMismatch (0.14s)25782026/10/26 22:36:38 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:42889/oidc25792026/10/26 22:36:38 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:37175/oidc2580--- PASS: TestValidateToken_MultipleProviders (0.16s)25812026/10/26 22:36:38 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:4259325822026/10/26 22:36:38 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33579/oidc2583--- PASS: TestValidateToken_KubernetesServiceAccount (0.19s)2584--- PASS: TestValidateToken_NoMatchingProvider (0.19s)25852026/10/26 22:36:38 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43817/oidc2586--- PASS: TestScopes_Rules (0.33s)2587--- PASS: TestHTTPClientForHasTimeouts (0.41s)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/26 22:36:39 ERROR Failed to queue paths error="permission denied" count=12614--- PASS: TestServerQueueError (0.00s)2615=== RUN TestServerRefusesOversizedAndNonStoreRequests2616=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2617=== RUN TestGetListenerSocketActivation2618 server_test.go:309: === 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 TestQueueDeduplication2654=== CONT TestShutdownFinishesInFlightPush2655=== RUN TestShutdownFinishesInFlightPush/completes2656=== CONT TestDrainIsolatesPoisonPath2657=== CONT TestDrainTimeoutDuringIsolation2658=== CONT TestWorkerRemoveFailureIsNotProgress2659=== CONT TestDrainTimeout2660=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2661=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2662=== CONT TestWorkerSkipsGCdPaths2663=== CONT TestWorkerUploadsAndRemoves2664=== CONT TestFailedPathPrunedByLaterClosure2665=== CONT TestWorkerPrunesClosureDeps2666=== CONT TestDrainGivesUpWhenServerDown2667=== CONT TestRunNotBlockedByPoisonHead2668=== CONT TestWorkerKeepsPathItCannotStat2669=== CONT TestServerStalledClientDoesNotBlockShutdown2670=== CONT TestServerRefusesOversizedAndNonStoreRequests2671=== CONT TestServerBacksOffOnAcceptErrors2672=== CONT TestQueueEnqueueWaitsOutSlowWriter2673=== CONT TestQueueRetryMovesToBack2674=== CONT TestQueueFetchRemoveLifecycle26752026/10/26 22:36:40 ERROR Accept failed error="too many open files"2676=== CONT TestQueueRemoveLargeClosure2677=== CONT TestQueueConcurrentWriters2678=== CONT TestQueueFetchBatchLimit2679=== CONT TestQueueRemove2680=== PAUSE TestShutdownFinishesInFlightPush/completes2681=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2682=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2683=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2684=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2685=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2686=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2687=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2688=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout26892026/10/26 22:36:40 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2690=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2691=== CONT TestQueueEnqueueAndFetch2692=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2693=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2694=== CONT TestSendPathsEmpty2695=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short2696=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline26972026/10/26 22:36:40 ERROR Refusing path outside the store path=/nix/store store=/nix/store2698--- PASS: TestSendPathsEmpty (0.00s)26992026/10/26 22:36:40 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store27002026/10/26 22:36:40 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store27012026/10/26 22:36:40 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store27022026/10/26 22:36:40 ERROR Accept failed error="too many open files"27032026/10/26 22:36:40 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27042026/10/26 22:36:40 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store27052026/10/26 22:36:40 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store27062026/10/26 22:36:40 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store27072026/10/26 22:36:40 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store27082026/10/26 22:36:40 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store27092026/10/26 22:36:40 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store27102026/10/26 22:36:40 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store27112026/10/26 22:36:40 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store27122026/10/26 22:36:40 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store27132026/10/26 22:36:40 ERROR Failed to decode request error="unexpected EOF"2714--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2715=== CONT TestShutdownFinishesInFlightPush/completes27162026/10/26 22:36:40 ERROR Accept failed error="too many open files"27172026/10/26 22:36:40 ERROR Accept failed error="too many open files"27182026/10/26 22:36:40 INFO Uploading batch count=427192026/10/26 22:36:40 ERROR Upload failed error="upload failed" count=427202026/10/26 22:36:40 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath999728980/002/bbb27212026/10/26 22:36:40 INFO Upload queue status pending=327222026/10/26 22:36:40 INFO Uploading batch count=127232026/10/26 22:36:40 INFO Uploading batch count=427242026/10/26 22:36:40 ERROR Upload failed error="upload failed" count=427252026/10/26 22:36:40 ERROR Upload failed error="upload failed" count=127262026/10/26 22:36:40 INFO Upload queue status pending=227272026/10/26 22:36:40 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat62998653/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat62998653/002/locked/aaa: permission denied"27282026/10/26 22:36:40 INFO Upload queue status pending=227292026/10/26 22:36:40 INFO Upload queue status pending=227302026/10/26 22:36:40 INFO Uploading batch count=427312026/10/26 22:36:40 ERROR Upload failed error="upload failed" count=427322026/10/26 22:36:40 INFO Upload queue status pending=32733--- PASS: TestQueueFetchRemoveLifecycle (0.07s)27342026/10/26 22:36:40 INFO Uploading batch count=22735=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout27362026/10/26 22:36:40 INFO Uploading batch count=227372026/10/26 22:36:40 INFO Uploading batch count=127382026/10/26 22:36:40 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths4180067428/002/nonexistent2739=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27402026/10/26 22:36:40 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat62998653/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat62998653/002/locked/aaa: permission denied"2741--- PASS: TestQueueFetchBatchLimit (0.07s)2742=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths27432026/10/26 22:36:40 INFO Upload queue status pending=22744--- PASS: TestQueueRetryMovesToBack (0.07s)27452026/10/26 22:36:40 INFO Uploading batch count=127462026/10/26 22:36:40 ERROR Upload failed error="upload failed" count=127472026/10/26 22:36:40 INFO Uploading batch count=227482026/10/26 22:36:40 INFO Uploading batch count=227492026/10/26 22:36:40 INFO Uploading batch count=127502026/10/26 22:36:40 ERROR Upload failed error="upload failed" count=127512026/10/26 22:36:40 ERROR Accept failed error="too many open files"2752--- PASS: TestQueueEnqueueAndFetch (0.08s)2753=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch2754--- PASS: TestQueueRemove (0.08s)27552026/10/26 22:36:40 INFO Uploading batch count=227562026/10/26 22:36:40 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat62998653/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat62998653/002/locked/aaa: permission denied"27572026/10/26 22:36:40 INFO Uploading batch count=227582026/10/26 22:36:40 INFO Uploading batch count=127592026/10/26 22:36:40 ERROR Upload failed error="upload failed" count=227602026/10/26 22:36:40 INFO Uploading batch count=127612026/10/26 22:36:40 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2047568129/002/a27622026/10/26 22:36:40 ERROR Upload failed error="upload failed" count=127632026/10/26 22:36:40 ERROR Drain finished with paths left in queue remaining=12764--- PASS: TestQueueDeduplication (0.09s)27652026/10/26 22:36:40 INFO Uploading batch count=127662026/10/26 22:36:40 ERROR Upload failed error="upload failed" count=127672026/10/26 22:36:40 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2047568129/002/b27682026/10/26 22:36:41 INFO Uploading batch count=12769--- PASS: TestWorkerKeepsPathItCannotStat (0.09s)27702026/10/26 22:36:41 ERROR Drain finished with paths left in queue remaining=127712026/10/26 22:36:41 INFO Uploading batch count=227722026/10/26 22:36:41 ERROR Upload failed error="upload failed" count=227732026/10/26 22:36:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2047568129/002/c27742026/10/26 22:36:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2047568129/002/d2775--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.10s)2776--- PASS: TestWorkerSkipsGCdPaths (0.10s)2777--- PASS: TestDrainIsolatesPoisonPath (0.10s)27782026/10/26 22:36:41 INFO Uploading batch count=227792026/10/26 22:36:41 ERROR Upload failed error="upload failed" count=227802026/10/26 22:36:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2047568129/002/e2781--- PASS: TestWorkerPrunesClosureDeps (0.10s)27822026/10/26 22:36:41 INFO Upload queue status pending=22783--- PASS: TestFailedPathPrunedByLaterClosure (0.10s)27842026/10/26 22:36:41 INFO Uploading batch count=227852026/10/26 22:36:41 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2047568129/002/f2786--- PASS: TestWorkerUploadsAndRemoves (0.10s)27872026/10/26 22:36:41 ERROR Drain finished with paths left in queue remaining=1027882026/10/26 22:36:41 INFO Uploading batch count=227892026/10/26 22:36:41 ERROR Upload failed error="upload failed" count=227902026/10/26 22:36:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=12791--- PASS: TestDrainGivesUpWhenServerDown (0.11s)27922026/10/26 22:36:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127932026/10/26 22:36:41 INFO Uploading batch count=227942026/10/26 22:36:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227952026/10/26 22:36:41 INFO Uploading batch count=227962026/10/26 22:36:41 ERROR Upload failed error="upload failed" count=227972026/10/26 22:36:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127982026/10/26 22:36:41 INFO Uploading batch count=227992026/10/26 22:36:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128002026/10/26 22:36:41 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path3940703051/001/nonexistent28012026/10/26 22:36:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228022026/10/26 22:36:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128032026/10/26 22:36:41 INFO Uploading batch count=228042026/10/26 22:36:41 ERROR Upload failed error="upload failed" count=228052026/10/26 22:36:41 INFO Uploading batch count=228062026/10/26 22:36:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128072026/10/26 22:36:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128082026/10/26 22:36:41 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path3940703051/001/nonexistent28092026/10/26 22:36:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228102026/10/26 22:36:41 ERROR Drain finished with paths left in queue remaining=228112026/10/26 22:36:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128122026/10/26 22:36:41 ERROR Drain finished with paths left in queue remaining=228132026/10/26 22:36:41 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path3940703051/001/nonexistent28142026/10/26 22:36:41 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128152026/10/26 22:36:41 ERROR Drain finished with paths left in queue remaining=12816--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2817 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.04s)2818 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.04s)2819 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.05s)28202026/10/26 22:36:41 ERROR Accept failed error="too many open files"28212026/10/26 22:36:41 ERROR Failed to decode request error="read unix /build/hook3963962621/test.sock->@: i/o timeout"28222026/10/26 22:36:41 ERROR Failed to write response error="write unix /build/hook3963962621/test.sock->@: i/o timeout"2823--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)28242026/10/26 22:36:41 ERROR Drain finished with paths left in queue remaining=428252026/10/26 22:36:41 ERROR Upload failed error="context canceled" count=228262026/10/26 22:36:41 ERROR Drain finished with paths left in queue remaining=42827--- PASS: TestDrainTimeout (0.29s)28282026/10/26 22:36:41 ERROR Upload failed error="context canceled" count=228292026/10/26 22:36:41 ERROR Drain finished with paths left in queue remaining=22830--- PASS: TestShutdownFinishesInFlightPush (0.00s)2831 --- PASS: TestShutdownFinishesInFlightPush/completes (0.17s)2832 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.23s)28332026/10/26 22:36:41 ERROR Accept failed error="too many open files"28342026/10/26 22:36:41 ERROR Drain finished with paths left in queue remaining=32835--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2836 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.27s)2837 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.37s)28382026/10/26 22:36:41 ERROR Accept failed error="too many open files"2839--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)2840--- PASS: TestQueueConcurrentWriters (0.69s)28412026/10/26 22:36:41 INFO Uploading batch count=128422026/10/26 22:36:41 INFO Uploading batch count=128432026/10/26 22:36:41 INFO Uploading batch count=128442026/10/26 22:36:41 ERROR Upload failed error="upload failed" count=128452026/10/26 22:36:41 INFO Uploading batch count=128462026/10/26 22:36:41 ERROR Upload failed error="upload failed" count=128472026/10/26 22:36:42 INFO Uploading batch count=128482026/10/26 22:36:42 ERROR Upload failed error="upload failed" count=128492026/10/26 22:36:42 INFO Uploading batch count=128502026/10/26 22:36:42 ERROR Upload failed error="upload failed" count=128512026/10/26 22:36:42 ERROR Drain finished with paths left in queue remaining=12852--- PASS: TestRunNotBlockedByPoisonHead (1.10s)2853--- PASS: TestQueueRemoveLargeClosure (1.54s)2854--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.07s)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 TestExternalSignerProgramErrorKeepsProcess2886=== CONT TestGenerateFingerprint2887=== CONT TestExternalSignerWrongPublicKey2888=== CONT TestSignBatch2889=== CONT TestSignErrors2890=== CONT TestExternalSignerClose2891=== CONT TestNilKeyPublicKey2892=== CONT TestExternalSigner2893--- PASS: TestNilKeyPublicKey (0.00s)2894=== CONT TestParseSigningKey2895=== CONT TestSign2896=== CONT TestExternalSignerErrors2897=== RUN TestParseSigningKey/valid_32-byte_key2898=== CONT TestExternalSignerCancellation2899=== CONT TestExternalSignerRestartsAfterCrash2900=== RUN TestGenerateFingerprint/basic_with_references2901=== PAUSE TestGenerateFingerprint/basic_with_references2902=== RUN TestGenerateFingerprint/no_references2903=== CONT TestExternalSignerRejectsInvalidPublicKey2904=== RUN TestExternalSignerErrors/too_few_signatures2905=== PAUSE TestExternalSignerErrors/too_few_signatures2906=== PAUSE TestParseSigningKey/valid_32-byte_key2907=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2908=== RUN TestExternalSignerErrors/missing_signatures2909=== PAUSE TestGenerateFingerprint/no_references2910=== RUN TestExternalSignerRejectsInvalidPublicKey/#002911=== PAUSE TestExternalSignerErrors/missing_signatures2912=== RUN TestExternalSignerErrors/null_signatures2913=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2914=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2915=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2916=== RUN TestParseSigningKey/no_colon2917=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2918=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002919=== PAUSE TestParseSigningKey/no_colon2920=== RUN TestSignErrors/nil_key2921=== RUN TestParseSigningKey/empty_name2922=== PAUSE TestSignErrors/nil_key2923=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2924=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2925=== PAUSE TestExternalSignerErrors/null_signatures2926=== RUN TestGenerateFingerprint/invalid_nar_hash_length2927=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2928=== RUN TestSignErrors/nil_narinfo2929=== RUN TestExternalSignerErrors/wrong_signatures_shape2930=== PAUSE TestParseSigningKey/empty_name2931=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2932=== RUN TestParseSigningKey/invalid_base642933=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2934=== RUN TestGenerateFingerprint/invalid_store_path_prefix2935--- PASS: TestSign (0.00s)2936=== PAUSE TestSignErrors/nil_narinfo2937=== PAUSE TestParseSigningKey/invalid_base642938=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2939=== RUN TestSignErrors/invalid_narinfo2940=== RUN TestExternalSignerErrors/invalid_signature_base642941=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2942--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2943=== RUN TestParseSigningKey/wrong_length2944=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2945=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2946=== PAUSE TestSignErrors/invalid_narinfo2947=== RUN TestSignErrors/canceled2948=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2949--- PASS: TestExternalSignerWrongPublicKey (0.01s)2950=== RUN TestGenerateFingerprint/invalid_reference_prefix2951=== PAUSE TestParseSigningKey/wrong_length2952=== PAUSE TestExternalSignerErrors/invalid_signature_base642953=== RUN TestExternalSignerErrors/program_error2954=== PAUSE TestSignErrors/canceled2955=== CONT TestSignErrors/nil_key2956=== CONT TestSignErrors/canceled2957=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2958=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2959--- PASS: TestExternalSignerClose (0.01s)2960=== CONT TestGenerateFingerprint/no_references2961=== CONT TestGenerateFingerprint/invalid_nar_hash_length2962=== CONT TestParseSigningKey/no_colon2963=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2964=== CONT TestParseSigningKey/invalid_base642965=== CONT TestParseSigningKey/wrong_length2966=== CONT TestParseSigningKey/empty_name2967=== PAUSE TestExternalSignerErrors/program_error2968=== CONT TestSignErrors/nil_narinfo2969--- PASS: TestSignBatch (0.01s)2970=== CONT TestSignErrors/invalid_narinfo2971=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2972--- PASS: TestSignErrors (0.01s)2973 --- PASS: TestSignErrors/nil_key (0.00s)2974 --- PASS: TestSignErrors/canceled (0.00s)2975 --- PASS: TestSignErrors/nil_narinfo (0.00s)2976 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2977=== CONT TestExternalSignerRejectsInvalidPublicKey/#002978=== CONT TestGenerateFingerprint/invalid_store_path_prefix2979=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2980=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2981=== CONT TestGenerateFingerprint/basic_with_references2982=== CONT TestParseSigningKey/valid_32-byte_key2983=== RUN TestExternalSignerErrors/wrong_shape2984=== CONT TestGenerateFingerprint/invalid_reference_prefix2985=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2986=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2987--- PASS: TestGenerateFingerprint (0.01s)2988 --- PASS: TestGenerateFingerprint/no_references (0.00s)2989 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2990 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2991 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2992 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2993 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2994 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2995=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2996--- PASS: TestParseSigningKey (0.01s)2997 --- PASS: TestParseSigningKey/no_colon (0.00s)2998 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2999 --- PASS: TestParseSigningKey/wrong_length (0.00s)3000 --- PASS: TestParseSigningKey/empty_name (0.00s)3001 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)3002 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)3003=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon3004=== PAUSE TestExternalSignerErrors/wrong_shape3005=== RUN TestExternalSignerErrors/null3006--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.01s)3007 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)3008 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)3009 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)3010 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)3011 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)3012=== PAUSE TestExternalSignerErrors/null3013=== RUN TestExternalSignerErrors/missing_signature_name3014=== PAUSE TestExternalSignerErrors/missing_signature_name3015=== RUN TestExternalSignerErrors/wrong_signature_name3016=== PAUSE TestExternalSignerErrors/wrong_signature_name3017=== RUN TestExternalSignerErrors/wrong_signature_length3018=== PAUSE TestExternalSignerErrors/wrong_signature_length3019=== RUN TestExternalSignerErrors/exit_at_startup3020=== PAUSE TestExternalSignerErrors/exit_at_startup3021=== RUN TestExternalSignerErrors/invalid_JSON3022=== PAUSE TestExternalSignerErrors/invalid_JSON3023=== RUN TestExternalSignerErrors/wrong_id3024=== PAUSE TestExternalSignerErrors/wrong_id3025=== RUN TestExternalSignerErrors/unrequested_key3026=== PAUSE TestExternalSignerErrors/unrequested_key3027=== RUN TestExternalSignerErrors/exit_on_request3028=== PAUSE TestExternalSignerErrors/exit_on_request3029=== CONT TestExternalSignerErrors/too_few_signatures3030=== CONT TestExternalSignerErrors/missing_signature_name3031=== CONT TestExternalSignerErrors/wrong_signatures_shape3032=== CONT TestExternalSignerErrors/null3033=== CONT TestExternalSignerErrors/exit_on_request3034=== CONT TestExternalSignerErrors/wrong_id3035=== CONT TestExternalSignerErrors/unrequested_key3036=== CONT TestExternalSignerErrors/exit_at_startup3037=== CONT TestExternalSignerErrors/wrong_signature_length3038=== CONT TestExternalSignerErrors/invalid_JSON3039=== CONT TestExternalSignerErrors/wrong_signature_name3040=== CONT TestExternalSignerErrors/wrong_shape3041=== CONT TestExternalSignerErrors/program_error3042--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)3043=== CONT TestExternalSignerErrors/invalid_signature_base643044=== CONT TestExternalSignerErrors/missing_signatures3045=== CONT TestExternalSignerErrors/null_signatures3046--- PASS: TestExternalSigner (0.01s)3047--- PASS: TestExternalSignerErrors (0.01s)3048 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)3049 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)3050 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)3051 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)3052 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)3053 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)3054 --- PASS: TestExternalSignerErrors/null (0.01s)3055 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)3056 --- PASS: TestExternalSignerErrors/program_error (0.01s)3057 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)3058 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)3059 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)3060 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)3061 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)3062 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)3063 --- PASS: TestExternalSignerErrors/null_signatures (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 TestServeRejectsGarbage3077=== CONT TestSignErrors3078=== CONT TestServe3079--- PASS: TestServeRejectsGarbage (0.00s)3080=== RUN TestSignErrors/invalid_json3081--- PASS: TestServe (0.00s)3082=== PAUSE TestSignErrors/invalid_json3083=== RUN TestSignErrors/no_prefix3084=== PAUSE TestSignErrors/no_prefix3085=== RUN TestSignErrors/invalid_base643086=== PAUSE TestSignErrors/invalid_base643087=== RUN TestSignErrors/http_error3088=== PAUSE TestSignErrors/http_error3089=== CONT TestSignErrors/invalid_json3090=== CONT TestSignErrors/invalid_base643091=== CONT TestSignErrors/no_prefix3092=== CONT TestSignErrors/http_error3093--- PASS: TestSign (0.01s)3094--- PASS: TestSignErrors (0.00s)3095 --- PASS: TestSignErrors/invalid_json (0.00s)3096 --- PASS: TestSignErrors/invalid_base64 (0.00s)3097 --- PASS: TestSignErrors/no_prefix (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/26 22:36:50 INFO Upload queue status pending=131092026/10/26 22:36:50 INFO Uploading batch count=13110--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.13s)3111PASS3112Running rate limiter tests...3113=== RUN TestAdaptiveRateLimiter_ThreadSafety3114=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3115=== CONT TestAdaptiveRateLimiter_ThreadSafety31162026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=7031172026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=4931182026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=34.331192026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=24.00999999999999831202026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=16.80731212026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=11.76489999999999931222026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=8.2354331232026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=5.76480099999999931242026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531252026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531262026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531272026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531282026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531292026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531302026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531312026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531322026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531332026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531342026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531352026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531362026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531372026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531382026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531392026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531402026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531412026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531422026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531432026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531442026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531452026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531462026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531472026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531482026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531492026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531502026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531512026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531522026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531532026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531542026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531552026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531562026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531572026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531582026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531592026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531602026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531612026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531622026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531632026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531642026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531652026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531662026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531672026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531682026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531692026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531702026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531712026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531722026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531732026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531742026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531752026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531762026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531772026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531782026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531792026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531802026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531812026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531822026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531832026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531842026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531852026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531862026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531872026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531882026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531892026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531902026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531912026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531922026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531932026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531942026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531952026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531962026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531972026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=531982026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=5.12435000000000131992026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=532002026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=532012026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=532022026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=532032026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=532042026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=532052026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=532062026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=532072026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=31.34005851393336432082026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=21.93804095975335532092026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=15.35662867182734832102026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=10.74964007027914432112026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=11.0169836188269932122026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=7.71188853317889232132026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=5.39832197322522432142026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=532152026/10/26 22:36:51 WARN Rate limiter backed off name=test rate=53216--- PASS: TestAdaptiveRateLimiter_ThreadSafety (3.23s)3217PASS