niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #448
· 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.08s)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 130 of 32768000 bytes45--- PASS: TestDumpPathWriterErrorStopsReading (1.22s)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.04s)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 TestDoServerRequestAttachesToken137=== CONT TestStreamPushGivesUpOnDeadServer138=== CONT TestUploadMultipart_FailedPartBufferNotReused139=== CONT TestSetClientTLS140=== CONT TestScriptTokenEmptyCommand141=== CONT TestFileTokenEmpty142=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun143--- PASS: TestScriptTokenEmptyCommand (0.00s)144=== CONT TestFileTokenReadsAndCaches145=== CONT TestScriptTokenNoExpiryRerunsEveryCall146=== CONT TestScriptTokenBadJSON147=== CONT TestScriptTokenDoesNotWaitForItsChildren148=== CONT TestScriptTokenEmptyToken149=== CONT TestEncodeNixBase32WithRealHash150=== CONT TestScriptTokenScriptFails151=== CONT TestStreamPushReportsEveryPath152=== CONT TestTruncatedNARDumpIsNotCompleted153=== CONT TestScriptTokenCachesUntilRefresh154=== CONT TestStreamPushBatchesUnderLoad155=== CONT TestSetClientTLSDoesNotMutateDefaultTransport156=== CONT TestClientSignaturesByStorePath157=== CONT TestStreamPushStartsNothingOnSlotFreedByCancel158=== CONT TestStaticToken159=== CONT TestStreamPushReportsSkippedPaths160=== CONT TestStreamPushStopsWhenCanceled161=== CONT TestSetClientTLSErrors162=== CONT TestFileTokenMissing163=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs164--- PASS: TestEncodeNixBase32WithRealHash (0.00s)165=== CONT TestPartSizeForNAR166=== RUN TestPartSizeForNAR/zero_stays_at_minimum167=== CONT TestShellSplit168=== CONT TestDoWithRetry_FinalResponseBodyReadable169=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false170=== CONT TestShellSplitErrors171--- PASS: TestDoServerRequestAttachesToken (0.01s)172=== CONT TestStreamPushStopsOnCancel173=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum174=== CONT TestDoWithRetry_BodyReplayedViaGetBody175=== CONT TestResolveStorePath176=== CONT TestStreamPushReportsSignatures177--- PASS: TestFileTokenEmpty (0.00s)178--- PASS: TestFileTokenReadsAndCaches (0.00s)179=== RUN TestSetClientTLSErrors/missing_cert_file180=== RUN TestSetClientTLS/rejects_connection_without_client_cert181=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs182=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false183=== CONT TestEncodeNixBase32184=== CONT TestGetStorePathHash185=== CONT TestDumpPathWriterError186=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent187=== CONT TestDumpPathSingleFile188=== RUN TestStreamPushStopsOnCancel/waiting_for_input189=== RUN TestPartSizeForNAR/small_stays_at_minimum190--- PASS: TestFileTokenMissing (0.24s)191=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess192=== CONT TestUploadMultipart_PartsInParallel193=== CONT TestPathInfoCACompatibility194=== RUN TestPathInfoCACompatibility/null_ca_field195=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert196=== CONT TestCompletePendingClosure_NotFoundWithoutKey197=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA198=== PAUSE TestSetClientTLSErrors/missing_cert_file199=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout200=== RUN TestEncodeNixBase32/test_string_hash201=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica202=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true203=== RUN TestGetStorePathHash/valid_store_path204=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier205--- PASS: TestStaticToken (0.00s)206--- PASS: TestClientSignaturesByStorePath (0.00s)207=== PAUSE TestPartSizeForNAR/small_stays_at_minimum208=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input209=== PAUSE TestPathInfoCACompatibility/null_ca_field210=== RUN TestSetClientTLSErrors/missing_key_file211=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA212=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout213=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true214=== PAUSE TestEncodeNixBase32/test_string_hash215=== CONT TestPathInfoHashCompatibility216=== CONT TestRateLimiterFeedback217=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)218=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)219=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon220=== RUN TestRateLimiterFeedback/429_enables_limiter221=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier222=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon223=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry224=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI225=== CONT TestRetryTimeoutOutlastsMaxRetries226=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI227=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum228=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot229=== PAUSE TestSetClientTLSErrors/missing_key_file230=== RUN TestPathInfoCACompatibility/old_string_format_-_text231=== RUN TestSetClientTLS/preserves_debug_logging_transport232=== CONT TestCaseHackSuffix233=== PAUSE TestGetStorePathHash/valid_store_path234=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot235=== PAUSE TestSetClientTLS/preserves_debug_logging_transport236=== RUN TestGetStorePathHash/basename_without_hyphen_should_error237=== PAUSE TestRateLimiterFeedback/429_enables_limiter238=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up239--- PASS: TestStreamPushReportsEveryPath (0.00s)240=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512241--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)242--- PASS: TestShellSplit (0.00s)243--- PASS: TestStreamPushReportsSkippedPaths (0.00s)244--- PASS: TestShellSplitErrors (0.00s)245=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum246=== RUN TestSetClientTLSErrors/missing_ca_file247=== RUN TestEncodeNixBase32/empty_input248=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text249=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot250=== CONT TestFilterOversizedClosures251=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot252=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error253=== CONT TestParsePathInfoJSONMultiplePaths254=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up255=== RUN TestRateLimiterFeedback/503_enables_limiter256=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512257--- PASS: TestStreamPushStopsWhenCanceled (0.00s)258=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts259=== PAUSE TestEncodeNixBase32/empty_input260=== PAUSE TestSetClientTLSErrors/missing_ca_file261=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive262=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot263=== RUN TestFilterOversizedClosures/no_limit_keeps_everything264=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything265=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error266=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error267=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths268=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error269=== PAUSE TestRateLimiterFeedback/503_enables_limiter270--- PASS: TestScriptTokenBadJSON (0.01s)271=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier272=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts273=== CONT TestConvertHashToNix32274=== CONT TestStreamPushIsolatesFailures275=== RUN TestSetClientTLSErrors/invalid_ca_file276=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive277=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot278=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped279=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot280=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped281=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer282=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error283=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot284=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter285=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier286=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter287--- PASS: TestScriptTokenScriptFails (0.24s)288=== RUN TestPartSizeForNAR/1_TiB289--- PASS: TestScriptTokenEmptyToken (0.25s)290=== PAUSE TestSetClientTLSErrors/invalid_ca_file291=== PAUSE TestPartSizeForNAR/1_TiB292=== RUN TestConvertHashToNix32/SRI_format_to_Nix32293=== RUN TestPathInfoCACompatibility/new_structured_format_-_text294=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths295=== RUN TestFilterOversizedClosures/all_closures_skipped296=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure297=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken298=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client299=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter300=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken301=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client302--- PASS: TestStreamPushReportsSignatures (0.00s)303=== CONT TestUploadMultipart_SupersededByPeer304=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client305=== RUN TestUploadMultipart_SupersededByPeer/exists306=== RUN TestPartSizeForNAR/5_TiB_S3_max_object307=== PAUSE TestUploadMultipart_SupersededByPeer/exists308=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text309=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths310=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method311=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32312=== PAUSE TestFilterOversizedClosures/all_closures_skipped313=== CONT TestStreamPushRequestLine314=== CONT TestUploadMultipart_ProducerErrorIsNotEOF315=== CONT TestParsePathInfoJSON316--- PASS: TestResolveStorePath (0.00s)317--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.25s)318=== CONT TestSupersededNARStillUploadsListing319=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client320=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object321=== RUN TestUploadMultipart_SupersededByPeer/missing322=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths323=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method324=== RUN TestConvertHashToNix32/already_Nix32_format325=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter326=== PAUSE TestConvertHashToNix32/already_Nix32_format327=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part328=== RUN TestParsePathInfoJSON/Nix_format329=== CONT TestDumpPathMatchesNix330--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)331--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.25s)332=== RUN TestSupersededNARStillUploadsListing/small_NAR333=== CONT TestRegisterUploadedObjectReusesConnections334=== RUN TestPartSizeForNAR/capped_at_5_GiB335=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs336=== PAUSE TestUploadMultipart_SupersededByPeer/missing337=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout338=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false339=== RUN TestConvertHashToNix32/invalid_format340=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part341=== PAUSE TestParsePathInfoJSON/Nix_format342--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)343=== PAUSE TestSupersededNARStillUploadsListing/small_NAR344=== PAUSE TestPartSizeForNAR/capped_at_5_GiB345=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true346=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary347=== PAUSE TestConvertHashToNix32/invalid_format348=== RUN TestParsePathInfoJSON/Lix_format349--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.00s)350=== CONT TestSetClientTLS/preserves_debug_logging_transport351=== RUN TestSupersededNARStillUploadsListing/dump_cut_short352=== CONT TestSetClientTLS/rejects_connection_without_client_cert353=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary354=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA355=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)356=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short357=== PAUSE TestParsePathInfoJSON/Lix_format358=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512359--- PASS: TestScriptTokenCachesUntilRefresh (0.26s)360=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails361=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI362=== RUN TestParsePathInfoJSON/empty_input363=== PAUSE TestParsePathInfoJSON/empty_input364=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon365=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails366--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.26s)367=== RUN TestParsePathInfoJSON/whitespace_only368=== CONT TestEncodeNixBase32/empty_input369=== PAUSE TestParsePathInfoJSON/whitespace_only370=== CONT TestEncodeNixBase32/test_string_hash371=== CONT TestGetStorePathHash/valid_store_path372--- PASS: TestStreamPushIsolatesFailures (0.00s)373=== RUN TestParsePathInfoJSON/invalid_JSON374=== CONT TestGetStorePathHash/basename_without_hyphen_should_error375=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error376=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error377=== CONT TestSetClientTLSErrors/missing_cert_file378=== PAUSE TestParsePathInfoJSON/invalid_JSON379=== CONT TestSetClientTLSErrors/missing_ca_file380--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.25s)381=== CONT TestSetClientTLSErrors/invalid_ca_file382=== CONT TestSetClientTLSErrors/missing_key_file383=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot384--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.03s)385=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken386=== CONT TestStreamPushStopsOnCancel/waiting_for_input387=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot388=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot389--- PASS: TestStreamPushBatchesUnderLoad (0.25s)390 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)391 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)392--- PASS: TestEncodeNixBase32 (0.01s)393 --- PASS: TestEncodeNixBase32/empty_input (0.00s)394 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)395--- PASS: TestPathInfoHashCompatibility (0.00s)396 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)397 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)398 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)399 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)400--- PASS: TestGetStorePathHash (0.01s)401 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)402 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)403 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)404 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)405--- PASS: TestSetClientTLSErrors (0.26s)406 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)407 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)408 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)409 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)410=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot411=== CONT TestFilterOversizedClosures/no_limit_keeps_everything412=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped413=== CONT TestFilterOversizedClosures/all_closures_skipped414=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier415--- PASS: TestFilterOversizedClosures (0.01s)416 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)417 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)418 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)419--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.05s)420=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up421=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier422=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client423=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client424=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths425--- PASS: TestDumpPathSingleFile (0.07s)426=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths427=== CONT TestPathInfoCACompatibility/null_ca_field428--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)429 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)430 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)431=== CONT TestPathInfoCACompatibility/new_structured_format_-_text432=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive433=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method434=== CONT TestRateLimiterFeedback/503_enables_limiter435=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter436=== CONT TestPathInfoCACompatibility/old_string_format_-_text437=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter438--- PASS: TestCaseHackSuffix (0.07s)439=== CONT TestRateLimiterFeedback/429_enables_limiter440--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.01s)441 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.01s)442 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.01s)443 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.00s)444 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.00s)445 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.01s)446--- PASS: TestPathInfoCACompatibility (0.01s)447 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)448 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)449 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)450 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)451 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)452=== CONT TestUploadMultipart_SupersededByPeer/missing453=== CONT TestUploadMultipart_SupersededByPeer/exists454=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum455=== CONT TestPartSizeForNAR/capped_at_5_GiB456=== CONT TestPartSizeForNAR/5_TiB_S3_max_object457=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts458--- PASS: TestRateLimiterFeedback (0.01s)459 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)460 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)461 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)462 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)463=== CONT TestPartSizeForNAR/1_TiB464=== CONT TestConvertHashToNix32/invalid_format465=== CONT TestPartSizeForNAR/small_stays_at_minimum466=== CONT TestPartSizeForNAR/zero_stays_at_minimum467=== CONT TestConvertHashToNix32/already_Nix32_format468--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)469 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)470 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)471=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part472=== CONT TestConvertHashToNix32/SRI_format_to_Nix32473=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary474=== CONT TestSupersededNARStillUploadsListing/dump_cut_short475=== CONT TestSupersededNARStillUploadsListing/small_NAR476=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails477--- PASS: TestPartSizeForNAR (0.27s)478 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)479 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)480 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)481 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)482 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)483 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)484 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)485=== CONT TestParsePathInfoJSON/Lix_format486=== CONT TestParsePathInfoJSON/empty_input487=== CONT TestParsePathInfoJSON/whitespace_only488=== CONT TestParsePathInfoJSON/Nix_format489=== CONT TestParsePathInfoJSON/invalid_JSON490--- PASS: TestConvertHashToNix32 (0.27s)491 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)492 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)493 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)494--- PASS: TestStreamPushStopsOnCancel (0.01s)495 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.22s)496 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.22s)497 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.22s)498 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.23s)499 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.47s)500 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.47s)501--- PASS: TestParsePathInfoJSON (0.02s)502 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)503 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)504 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)505 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)506 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)507--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.54s)508--- PASS: TestStreamPushStartsNothingOnSlotFreedByCancel (0.81s)509--- PASS: TestDumpPathWriterError (0.57s)510--- PASS: TestSetClientTLS (0.26s)511 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)512 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.03s)513 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.57s)514--- PASS: TestRegisterUploadedObjectReusesConnections (0.73s)515--- PASS: TestStreamPushRequestLine (0.80s)516--- PASS: TestDumpPathMatchesNix (0.88s)517--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.01s)518 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.62s)519 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.65s)520--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)521--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)522--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.88s)523--- PASS: TestUploadMultipart_PartsInParallel (1.87s)524--- PASS: TestSupersededNARStillUploadsListing (0.02s)525 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.32s)526 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.07s)527 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.76s)528--- PASS: TestTruncatedNARDumpIsNotCompleted (2.38s)529--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.25s)530 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.01s)531 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.25s)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/postgres3311661513/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/postgres3311661513/data -l logfile start560561/build/postgres3311661513:5432 - no response5622026-10-29 01:22:24.635 UTC [173] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit5632026-10-29 01:22:24.636 UTC [173] LOG: listening on Unix socket "/build/postgres3311661513/.s.PGSQL.5432"5642026-10-29 01:22:24.647 UTC [180] LOG: database system was shut down at 2026-10-29 01:22:24 UTC5652026-10-29 01:22:24.655 UTC [173] LOG: database system is ready to accept connections566/build/postgres3311661513:5432 - accepting connections567{"timestamp":"2026-10-29T01:22:25.151224374Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"cb051bf1-b031-45d3-b74e-41622034cdda","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(399)"}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/29 01:22:25 INFO lead: acquired remote=192.0.2.1:12346182026/10/29 01:22:26 INFO lead: released remote=192.0.2.1:12346192026/10/29 01:22:26 INFO lead: acquired remote=192.0.2.1:12346202026/10/29 01:22:27 INFO lead: released remote=192.0.2.1:1234621--- PASS: TestLeadIncumbentWinsAfterRestart (2.09s)622=== RUN TestLeadIncumbentAnnouncesAtOnce623=== PAUSE TestLeadIncumbentAnnouncesAtOnce624=== RUN TestLeadEndsOnShutdown625=== PAUSE TestLeadEndsOnShutdown626=== RUN TestLeadEndsWhenItsConnectionHangs6272026/10/29 01:22:27 INFO lead: acquired remote=192.0.2.1:12346282026-10-29 01:22:29.010 UTC [627] FATAL: terminating connection due to administrator command6292026/10/29 01:22:29 INFO lead: acquired remote=192.0.2.1:12346302026/10/29 01:22:30 WARN lead: lock connection lost error="timeout: context deadline exceeded"6312026/10/29 01:22:30 INFO lead: released remote=192.0.2.1:12346322026/10/29 01:22:30 INFO lead: released remote=192.0.2.1:1234633--- PASS: TestLeadEndsWhenItsConnectionHangs (3.09s)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/29 01:22:30 INFO Starting HTTP server address=127.0.0.1:357617482026/10/29 01:22:30 INFO Starting HTTP server address=proxy.sock7492026/10/29 01:22:30 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7502026/10/29 01:22:30 INFO Shutdown signal received, draining in-flight requests timeout=10s751--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.28s)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/29 01:22:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8202026/10/29 01:22:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8212026/10/29 01:22:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8222026/10/29 01:22:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8232026/10/29 01:22:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8242026/10/29 01:22:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8252026/10/29 01:22:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8262026/10/29 01:22:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8272026/10/29 01:22:30 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8282026/10/29 01:22:30 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_MTLSBoundSubjects853=== CONT TestOrphanedObjectsGCStressTest854=== CONT TestPresignedUploadRegisteredBeforeCommit855=== CONT TestCompleteMultipartUnregistered856=== CONT TestService_verifyS3Integrity857=== CONT TestService_createPendingClosureHandler858=== CONT TestService_cleanupPendingClosuresHandler859=== CONT TestGCTaskStore_CompletedAllowsNewTask860=== CONT TestUploadHandlersRejectOversizedBody861=== CONT TestPush_OverlappingRootsStoreOneRowPerKey862=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT863=== CONT TestPush_RejectsBadRequests864=== CONT TestPendingClosureWriteTimeout865=== CONT TestIsValidUploadKey866=== CONT TestUploadHandlersRejectInvalidKeys867=== CONT TestReadRedirectUsesPublicS3URL868=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle869=== CONT TestProxyWriteTimeout870=== CONT TestParseSize871=== CONT TestOrphanedObjectsGC872=== CONT TestService_Rustfstest873=== CONT TestReconnectLeavesObjectsUnlocked874=== CONT TestReadProxyRangeRequest875=== CONT TestPush_CompleteCommitsEveryRoot876--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)877--- PASS: TestParseSize (0.00s)878=== CONT TestSkippedUploadsHandler879=== RUN TestIsValidUploadKey/narinfo880=== RUN TestPendingClosureWriteTimeout/empty881=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info882=== RUN TestProxyWriteTimeout/narinfo883=== CONT TestCompleteMultipartUpload_ErrorButObjectExists884=== PAUSE TestIsValidUploadKey/narinfo885=== PAUSE TestProxyWriteTimeout/narinfo886=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info887=== RUN TestIsValidUploadKey/nar_zst888=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal889=== PAUSE TestPendingClosureWriteTimeout/empty890=== RUN TestProxyWriteTimeout/1_GiB_nar891=== PAUSE TestIsValidUploadKey/nar_zst892=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal893=== RUN TestPendingClosureWriteTimeout/400_objects894=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key895=== RUN TestIsValidUploadKey/nar_xz896=== PAUSE TestProxyWriteTimeout/1_GiB_nar897=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key898=== PAUSE TestPendingClosureWriteTimeout/400_objects899=== PAUSE TestIsValidUploadKey/nar_xz900=== RUN TestIsValidUploadKey/nar_plain901=== PAUSE TestIsValidUploadKey/nar_plain902=== RUN TestPendingClosureWriteTimeout/670k_objects903=== RUN TestProxyWriteTimeout/10_GiB_nar904=== RUN TestIsValidUploadKey/listing905=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key906=== PAUSE TestPendingClosureWriteTimeout/670k_objects907=== PAUSE TestProxyWriteTimeout/10_GiB_nar908=== RUN TestProxyWriteTimeout/unknown_size909=== PAUSE TestIsValidUploadKey/listing9102026/10/29 01:22:30 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000911=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key912=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline913=== CONT TestRedundantMultipartUpload914=== PAUSE TestProxyWriteTimeout/unknown_size915=== RUN TestIsValidUploadKey/build_log916=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline917=== CONT TestPush_SignsNarinfosOfItsPendingObjects918=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit919=== PAUSE TestIsValidUploadKey/build_log920=== RUN TestIsValidUploadKey/build_log_home-manager_file921=== PAUSE TestIsValidUploadKey/build_log_home-manager_file922=== RUN TestIsValidUploadKey/build_log_plus_in_name923=== PAUSE TestIsValidUploadKey/build_log_plus_in_name924=== RUN TestIsValidUploadKey/build_log_question_mark925=== PAUSE TestIsValidUploadKey/build_log_question_mark926=== RUN TestIsValidUploadKey/build_log_equals927=== PAUSE TestIsValidUploadKey/build_log_equals928=== RUN TestIsValidUploadKey/realisation929=== PAUSE TestIsValidUploadKey/realisation930=== RUN TestIsValidUploadKey/realisation_plus_in_output931=== PAUSE TestIsValidUploadKey/realisation_plus_in_output932=== RUN TestIsValidUploadKey/nix-cache-info933=== PAUSE TestIsValidUploadKey/nix-cache-info934=== RUN TestIsValidUploadKey/index.html935=== PAUSE TestIsValidUploadKey/index.html936=== RUN TestIsValidUploadKey/narinfo_key,_nar_type937=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type938=== RUN TestIsValidUploadKey/nar_key,_narinfo_type939=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type940=== RUN TestIsValidUploadKey/listing_key,_narinfo_type941=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type942=== RUN TestIsValidUploadKey/traversal943=== PAUSE TestIsValidUploadKey/traversal944=== RUN TestIsValidUploadKey/traversal_nar945=== PAUSE TestIsValidUploadKey/traversal_nar946=== RUN TestIsValidUploadKey/absolute947=== PAUSE TestIsValidUploadKey/absolute948=== RUN TestIsValidUploadKey/empty_key949=== PAUSE TestIsValidUploadKey/empty_key950=== RUN TestIsValidUploadKey/unknown_type951=== PAUSE TestIsValidUploadKey/unknown_type952=== CONT TestPush_RootsAreLockedInByteOrder953--- PASS: TestSkippedUploadsHandler (0.06s)954=== CONT TestReadRedirectKeepsNarinfoProxied955=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure956=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure957=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart958=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart959=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts960=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts961=== CONT TestPush_CompleteWaitsForCleanupOfThePush9622026/10/29 01:22:32 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"9632026/10/29 01:22:32 WARN mTLS auth: bound subjects configured but subject DN unavailable9642026/10/29 01:22:32 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"965--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (1.08s)966=== CONT TestCreatePin_ReservedPins9672026/10/29 01:22:32 INFO Received uploads request method=POST path=/api/pending_closures9682026/10/29 01:22:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9692026/10/29 01:22:32 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst9702026/10/29 01:22:32 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9712026/10/29 01:22:32 INFO Received uploads request method=POST path=/api/pending_closures972=== CONT TestReadProxyRootRedirectsToIndexHTML973--- PASS: TestCompleteMultipartUnregistered (1.15s)974--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.17s)975=== CONT TestReadRedirectNar976--- PASS: TestService_Rustfstest (1.17s)977=== CONT TestReadProxyOutlastsServerWriteTimeout9782026/10/29 01:22:32 INFO Received cleanup request method=DELETE path=/api/pending_closures9792026/10/29 01:22:32 INFO Aborted multipart uploads count=0 kept=09802026/10/29 01:22:32 INFO Received uploads request method=POST path=/api/pending_closures9812026/10/29 01:22:32 INFO Received cleanup request method=DELETE path=/api/pending_closures9822026/10/29 01:22:32 INFO Aborted multipart uploads count=1 kept=09832026/10/29 01:22:32 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9842026-10-29 01:22:32.211 UTC [704] ERROR: Closure does not exist: id=19852026-10-29 01:22:32.211 UTC [704] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9862026-10-29 01:22:32.211 UTC [704] STATEMENT: -- name: CommitPendingClosure :one987 SELECT commit_pending_closure($1::bigint)::bigint988 989--- PASS: TestService_cleanupPendingClosuresHandler (1.27s)990=== CONT TestReadProxyConditionalGet9912026/10/29 01:22:32 INFO Received uploads request method=POST path=/api/pending_closures9922026/10/29 01:22:32 INFO Received uploads request method=POST path=/api/pending_closures9932026/10/29 01:22:32 INFO Received uploads request method=POST path=/api/pending_closures9942026/10/29 01:22:32 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42401/oidc9952026/10/29 01:22:32 INFO Received uploads request method=POST path=/api/pending_closures996--- PASS: TestReconnectLeavesObjectsUnlocked (1.40s)997=== CONT TestReadProxyDisabled998=== RUN TestPush_RejectsBadRequests/no_roots999=== PAUSE TestPush_RejectsBadRequests/no_roots1000=== RUN TestPush_RejectsBadRequests/no_objects1001=== PAUSE TestPush_RejectsBadRequests/no_objects1002=== RUN TestPush_RejectsBadRequests/bad_root1003=== PAUSE TestPush_RejectsBadRequests/bad_root1004=== RUN TestPush_RejectsBadRequests/root_not_in_objects1005=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1006=== CONT TestPush_RepeatedRootCommitsOnce1007--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.43s)1008=== CONT TestGCTaskStore_GetReturnsLatest1009--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1010=== CONT TestReadProxyHead10112026/10/29 01:22:32 INFO Received push request method=POST path=/api/pushes1012--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (1.56s)1013=== CONT TestLeadEndsOnShutdown10142026/10/29 01:22:32 INFO Received uploads request method=POST path=/api/pending_closures10152026/10/29 01:22:32 INFO Received push request method=POST path=/api/pushes10162026/10/29 01:22:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10172026/10/29 01:22:32 INFO Signed narinfos id=1 count=110182026/10/29 01:22:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10192026/10/29 01:22:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10202026/10/29 01:22:32 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10212026/10/29 01:22:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10222026/10/29 01:22:32 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10232026/10/29 01:22:32 INFO Received uploads request method=POST path=/api/pending_closures10242026/10/29 01:22:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10252026/10/29 01:22:32 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110262026/10/29 01:22:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10272026/10/29 01:22:32 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo10282026/10/29 01:22:32 INFO Received uploads request method=POST path=/api/pending_closures10292026/10/29 01:22:32 INFO Received push request method=POST path=/api/pushes1030=== CONT TestGCTaskStore_PhaseUpdates1031--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.73s)1032--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1033=== CONT TestDeletePinKeepsRowWhenS3Fails10342026/10/29 01:22:32 INFO Received push request method=POST path=/api/pushes1035=== NAME TestOrphanedObjectsGC1036 orphaned_objects_gc_test.go:287: GC Test Summary:1037 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1038 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1039 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1040 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1041 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1042--- PASS: TestReadRedirectUsesPublicS3URL (1.83s)1043=== CONT TestReadProxyInvalidPath10442026/10/29 01:22:32 INFO Received push request method=POST path=/api/pushes1045--- PASS: TestOrphanedObjectsGC (1.85s)1046=== CONT TestPresentReportsOnlyClosureRoots10472026/10/29 01:22:32 INFO Received uploads request method=POST path=/api/pending_closures10482026/10/29 01:22:32 INFO Received uploads request method=POST path=/api/pending_closures10492026/10/29 01:22:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10502026/10/29 01:22:33 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLjdmMDExYjVkLTVlZjQtNDNlYi04MWZhLTkzZWNhYmY1ZmRmY3gxNzkzMjM2OTUyOTQwNTYwMjg41051--- PASS: TestReadProxyRangeRequest (2.08s)1052=== CONT TestReadProxy404And42910532026/10/29 01:22:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10542026/10/29 01:22:33 INFO Received push request method=POST path=/api/pushes10552026/10/29 01:22:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10562026/10/29 01:22:33 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLjdmMDExYjVkLTVlZjQtNDNlYi04MWZhLTkzZWNhYmY1ZmRmY3gxNzkzMjM2OTUyOTQwNTYwMjg4 error="Delete \"http://localhost:37981/bucket24/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLjdmMDExYjVkLTVlZjQtNDNlYi04MWZhLTkzZWNhYmY1ZmRmY3gxNzkzMjM2OTUyOTQwNTYwMjg4\": injected: abort refused"10572026/10/29 01:22:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10582026/10/29 01:22:33 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLjNhZDUzMTM0LTMyYzEtNDc2OS1hNDRjLTFjOWY2MzFhZGRjYXgxNzkzMjM2OTUyMjY1MTA2NDE3 parts=1010592026/10/29 01:22:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10602026/10/29 01:22:33 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLjdmMDExYjVkLTVlZjQtNDNlYi04MWZhLTkzZWNhYmY1ZmRmY3gxNzkzMjM2OTUyOTQwNTYwMjg410612026/10/29 01:22:33 ERROR Failed to register completed object error="get pending object \"nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst\": context canceled" object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst10622026/10/29 01:22:33 INFO Completed upload id=1 objects=2 duration=8.691729ms10632026/10/29 01:22:33 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010642026/10/29 01:22:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10652026/10/29 01:22:33 INFO Received uploads request method=POST path=/api/pending_closures10662026/10/29 01:22:33 INFO Starting cleanup of old closures method=DELETE path=/api/closures10672026/10/29 01:22:33 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=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLjdmMDExYjVkLTVlZjQtNDNlYi04MWZhLTkzZWNhYmY1ZmRmY3gxNzkzMjM2OTUyOTQwNTYwMjg410682026/10/29 01:22:33 INFO Aborted multipart uploads count=0 kept=010692026/10/29 01:22:33 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLjdmMDExYjVkLTVlZjQtNDNlYi04MWZhLTkzZWNhYmY1ZmRmY3gxNzkzMjM2OTUyOTQwNTYwMjg4 parts=11070--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.07s)1071=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded10722026/10/29 01:22:33 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=010732026/10/29 01:22:33 INFO Vacuumed table table=pending_closures10742026/10/29 01:22:33 INFO Vacuumed table table=pending_objects1075=== CONT TestPendingCleanupUsesOneCutoff1076--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.23s)10772026/10/29 01:22:33 INFO Vacuumed table table=multipart_uploads10782026/10/29 01:22:33 INFO Vacuumed table table=closures10792026/10/29 01:22:33 INFO Vacuumed table table=objects10802026/10/29 01:22:33 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001081--- PASS: TestService_createPendingClosureHandler (2.31s)1082=== CONT TestReadProxyNarinfo1083--- PASS: TestReadRedirectNar (1.17s)1084=== CONT TestGCTaskStore_DeduplicateSameParams1085--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1086=== CONT TestObjectStatsUpdatedOncePerCommit1087--- PASS: TestReadRedirectKeepsNarinfoProxied (2.29s)1088=== CONT TestPendingClosureFailureTracksEveryUpload1089=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1090=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1091=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1092=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1093=== CONT TestDeleteClosuresRacingPins10942026/10/29 01:22:33 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10952026/10/29 01:22:33 WARN Refused reserved pin name=worker-x86_64-linux10962026/10/29 01:22:33 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10972026/10/29 01:22:33 INFO Received create pin request method=POST path=/api/pins/my-app10982026/10/29 01:22:33 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10992026/10/29 01:22:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1100--- PASS: TestCreatePin_ReservedPins (1.37s)1101=== CONT TestReadProxyNarStreaming11022026/10/29 01:22:33 INFO Received push request method=POST path=/api/pushes11032026/10/29 01:22:33 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLmM0ZGY4ODNjLTY0NDktNDk2My04NGNkLWMxMGExYTk1MGY4ZngxNzkzMjM2OTUyNTUyNjg3Nzcw parts=1011042026/10/29 01:22:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11052026/10/29 01:22:33 INFO Completed upload id=1 objects=2 duration=10.601642ms11062026/10/29 01:22:33 INFO Received uploads request method=POST path=/api/pending_closures11072026/10/29 01:22:33 INFO Received uploads request method=POST path=/api/pending_closures11082026/10/29 01:22:33 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11092026/10/29 01:22:33 WARN Found objects in DB but missing from S3, will re-upload count=11110--- PASS: TestReadProxyDisabled (1.20s)1111=== CONT TestCacheConfigHandlerMaxNarSize1112--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)11132026/10/29 01:22:33 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete1114=== CONT TestService_AuthMiddleware_OIDC11152026/10/29 01:22:33 INFO Completed upload id=3 objects=2 duration=3.475107ms11162026/10/29 01:22:33 INFO lead: acquired remote=192.0.2.1:12341117--- PASS: TestService_verifyS3Integrity (2.67s)1118=== CONT TestService_healthCheckHandler1119--- PASS: TestReadProxyConditionalGet (1.40s)1120=== CONT TestChildrenInheritRaisedFileLimit11212026/10/29 01:22:33 INFO Received create pin request method=POST path=/api/pins/app1122--- PASS: TestChildrenInheritRaisedFileLimit (0.00s)1123=== CONT TestGCEndsOnShutdown1124=== RUN TestGCEndsOnShutdown/before_the_run1125=== PAUSE TestGCEndsOnShutdown/before_the_run1126=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1127=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1128=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1129=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1130=== CONT TestPresentRefreshesOnlyStaleClosures11312026/10/29 01:22:33 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo11322026/10/29 01:22:33 INFO Received delete pin request method=DELETE path=/api/pins/app11332026/10/29 01:22:33 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket37/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"11342026/10/29 01:22:33 INFO Received delete pin request method=DELETE path=/api/pins/app11352026/10/29 01:22:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11362026/10/29 01:22:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1137--- PASS: TestReadProxyHead (1.32s)1138=== CONT TestService_AuthMiddleware11392026/10/29 01:22:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11402026/10/29 01:22:33 INFO Deleted pin name=app1141--- PASS: TestReadProxyInvalidPath (0.92s)1142=== CONT TestConnectWaitsForAPeerMigration11432026/10/29 01:22:33 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLjg3ZmU1N2MwLTNkZGEtNDYzMi04MTc5LWU0ZWU1YzliMGIzN3gxNzkzMjM2OTUyNzkwNDQ5ODc4 parts=1011442026/10/29 01:22:33 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLjIzMmUyZGRmLWQwYTYtNGQ3Ny05YzdiLWUyOGUwNDY0YjAxNXgxNzkzMjM2OTUyNzM3MDkxODE0 parts=101145--- PASS: TestDeletePinKeepsRowWhenS3Fails (1.05s)1146=== CONT TestCompletedNarNotReofferedAcrossClosures11472026/10/29 01:22:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11482026/10/29 01:22:33 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLmFkZDhjNmU3LTA3YWItNGRhZS1hN2RhLWNhZmU4NjI0YzVkNXgxNzkzMjM2OTUyNjkzNTExMzIx parts=1211492026/10/29 01:22:33 INFO Received uploads request method=POST path=/api/pending_closures1150--- PASS: TestPresentReportsOnlyClosureRoots (0.98s)1151=== CONT TestConcurrentPinUpdatesAgree11522026/10/29 01:22:33 INFO Received uploads request method=POST path=/api/pending_closures11532026/10/29 01:22:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43223/oidc11542026/10/29 01:22:33 INFO Received uploads request method=POST path=/api/pending_closures11552026/10/29 01:22:33 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLjIyYTZiMWIyLTI3YjMtNDgxZS04OTUwLWZhZmQ4NTk1YzU1MHgxNzkzMjM2OTUyODQzNzU3MDIy parts=1011562026/10/29 01:22:33 INFO Received uploads request method=POST path=/api/pending_closures11572026/10/29 01:22:33 INFO Received uploads request method=POST path=/api/pending_closures1158--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.76s)1159=== CONT TestPresentNotReportedWhileGCDeletesClosure1160=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1161=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1162=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1163=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1164=== CONT TestReadProxyNarinfoAlreadyDecompressed11652026/10/29 01:22:33 INFO Received cleanup request method=DELETE path=/api/pending_closures11662026/10/29 01:22:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1167--- PASS: TestObjectStatsUpdatedOncePerCommit (0.76s)1168=== CONT TestCreatePinRejectsBadInput11692026/10/29 01:22:34 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLjVkNjllMTg1LWM0ZTctNGM5YS1iMDkzLTQ0YmJkMTdlMjcxM3gxNzkzMjM2OTUzMDkxODQyODkx parts=101170--- PASS: TestReadProxyNarStreaming (0.76s)1171=== CONT TestGCTaskStore_ConflictDifferentParams1172--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1173=== CONT TestMetricsInventory1174--- PASS: TestPresentRefreshesOnlyStaleClosures (0.57s)1175=== CONT TestReadProxyContentNegotiation1176--- PASS: TestService_healthCheckHandler (0.61s)1177=== CONT TestClientWithDependencies11782026/10/29 01:22:34 INFO Received uploads request method=POST path=/api/pending_closures11792026/10/29 01:22:34 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1180--- PASS: TestService_AuthMiddleware (0.66s)1181=== CONT TestLeadIncumbentAnnouncesAtOnce11822026-10-29 01:22:34.377 UTC [885] ERROR: Push does not exist: id=111832026-10-29 01:22:34.377 UTC [885] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE11842026-10-29 01:22:34.377 UTC [885] STATEMENT: SELECT commit_push($1)11852026/10/29 01:22:34 INFO Received create pin request method=POST path=/api/pins/app11862026/10/29 01:22:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11872026/10/29 01:22:34 INFO Received create pin request method=POST path=/api/pins/app1188--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (2.69s)1189=== CONT TestServerTLSConfig1190=== RUN TestServerTLSConfig/no_client_CA1191=== PAUSE TestServerTLSConfig/no_client_CA1192=== RUN TestServerTLSConfig/missing_CA_file1193=== PAUSE TestServerTLSConfig/missing_CA_file1194=== RUN TestServerTLSConfig/not_a_PEM_file1195=== PAUSE TestServerTLSConfig/not_a_PEM_file1196=== CONT TestObjectStatsTrigger1197=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1198=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1199=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1200=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1201=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1202=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1203=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1204=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1205=== CONT TestConnectSerialisesConcurrentMigrations12062026/10/29 01:22:34 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLmExZjc4ZWUxLTI5MWQtNDFmZi04NWQyLTFhNDQ4NTdkOGU1NHgxNzkzMjM2OTUzNDcyNDQyMjEz parts=101207=== CONT TestService_NativeMTLS12082026/10/29 01:22:34 INFO Received create pin request method=POST path=/api/pins/deploy1209--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.62s)12102026/10/29 01:22:34 INFO Received create pin request method=POST path=/api/pins/deploy12112026/10/29 01:22:34 INFO Received create pin request method=POST path=/api/pins/deploy12122026/10/29 01:22:34 INFO Received create pin request method=POST path=/api/pins/deploy12132026/10/29 01:22:34 INFO Received create pin request method=POST path=/api/pins/deploy12142026/10/29 01:22:34 INFO Received create pin request method=POST path=/api/pins/deploy12152026/10/29 01:22:34 INFO Received create pin request method=POST path=/api/pins/deploy12162026/10/29 01:22:34 INFO Received create pin request method=POST path=/api/pins/deploy12172026/10/29 01:22:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12182026/10/29 01:22:34 INFO lead: released remote=192.0.2.1:123412192026/10/29 01:22:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12202026/10/29 01:22:34 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLjhkODA3MDgwLTRiYzItNDc4Ni05YjlmLTQxZmVjOWI5ZTU5MHgxNzkzMjM2OTUyNzM1OTAxMzUx parts=1012212026-10-29 01:22:34.669 UTC [923] ERROR: duplicate key value violates unique constraint "pg_type_typname_nsp_index"12222026-10-29 01:22:34.669 UTC [923] DETAIL: Key (typname, typnamespace)=(goose_db_version, 2200) already exists.12232026-10-29 01:22:34.669 UTC [923] STATEMENT: CREATE TABLE goose_db_version (1224 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1225 version_id bigint NOT NULL,1226 is_applied boolean NOT NULL,1227 tstamp timestamp NOT NULL DEFAULT now()1228 )12292026/10/29 01:22:34 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLmY2YWEyNDhlLTY4NzYtNDg4Yi04NWFmLWNkMzcyZWVmZDg0MXgxNzkzMjM2OTUyNzkxMTM0ODI5 parts=101230--- PASS: TestLeadEndsOnShutdown (2.17s)12312026/10/29 01:22:34 INFO Received create pin request method=POST path=/api/pins/deploy1232=== CONT TestMultipartCleanup12332026/10/29 01:22:34 WARN Rate limiter enabled after throttle name=s3-test rate=512342026/10/29 01:22:34 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."12352026/10/29 01:22:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12362026/10/29 01:22:34 WARN Rate limiter backed off name=s3-test rate=512372026/10/29 01:22:34 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."1238--- PASS: TestMetricsInventory (0.61s)1239=== CONT TestSweepSkipsRowsLockedByPush12402026/10/29 01:22:34 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLjJjZWQyN2MwLTFhMzAtNDc0My05OGE5LWMzYjViZDYzN2EwMXgxNzkzMjM2OTUyODQxMDMxNDY2 parts=1012412026/10/29 01:22:34 INFO Received complete push request method=POST path=/api/pushes/1/complete12422026/10/29 01:22:34 INFO lead: acquired remote=192.0.2.1:123412432026/10/29 01:22:34 INFO lead: released remote=192.0.2.1:123412442026/10/29 01:22:34 INFO Completed push id=1 objects=4 duration=14.228291ms12452026/10/29 01:22:34 INFO Received push request method=POST path=/api/pushes1246--- PASS: TestReadProxy404And429 (1.77s)1247=== CONT TestResolveDBConnectionString1248=== RUN TestResolveDBConnectionString/flag_wins1249=== PAUSE TestResolveDBConnectionString/flag_wins1250=== RUN TestResolveDBConnectionString/file_when_flag_empty1251=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1252=== RUN TestResolveDBConnectionString/missing_file_is_an_error1253=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1254=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1255=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1256=== RUN TestResolveDBConnectionString/nothing_configured1257=== PAUSE TestResolveDBConnectionString/nothing_configured1258=== CONT TestGCTaskStore_GetEmpty1259=== CONT TestLeadElectsOneAndHandsOver1260--- PASS: TestGCTaskStore_GetEmpty (0.00s)1261=== CONT TestGCTaskStore_StartNew1262--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.46s)1263=== CONT TestIsValidCachePath1264--- PASS: TestGCTaskStore_StartNew (0.00s)1265=== RUN TestIsValidCachePath/narinfo1266=== PAUSE TestIsValidCachePath/narinfo1267=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1268=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1269=== RUN TestIsValidCachePath/nar_zst1270=== PAUSE TestIsValidCachePath/nar_zst1271=== RUN TestIsValidCachePath/nar_xz1272=== PAUSE TestIsValidCachePath/nar_xz1273=== RUN TestIsValidCachePath/nar_bz21274=== PAUSE TestIsValidCachePath/nar_bz21275=== RUN TestIsValidCachePath/nar_uncompressed1276=== PAUSE TestIsValidCachePath/nar_uncompressed1277=== RUN TestIsValidCachePath/ls1278=== PAUSE TestIsValidCachePath/ls1279=== RUN TestIsValidCachePath/log1280=== PAUSE TestIsValidCachePath/log1281=== RUN TestIsValidCachePath/realisation1282=== PAUSE TestIsValidCachePath/realisation1283=== RUN TestIsValidCachePath/nix-cache-info1284=== PAUSE TestIsValidCachePath/nix-cache-info1285=== RUN TestIsValidCachePath/index.html1286=== PAUSE TestIsValidCachePath/index.html1287=== RUN TestIsValidCachePath/traversal_parent1288=== PAUSE TestIsValidCachePath/traversal_parent1289=== RUN TestIsValidCachePath/traversal_in_middle1290=== PAUSE TestIsValidCachePath/traversal_in_middle1291=== RUN TestIsValidCachePath/invalid_char_e1292=== PAUSE TestIsValidCachePath/invalid_char_e1293=== RUN TestIsValidCachePath/invalid_char_u1294=== PAUSE TestIsValidCachePath/invalid_char_u1295=== RUN TestIsValidCachePath/random_path1296=== PAUSE TestIsValidCachePath/random_path1297=== RUN TestIsValidCachePath/empty1298=== PAUSE TestIsValidCachePath/empty1299=== RUN TestIsValidCachePath/leading_slash1300=== PAUSE TestIsValidCachePath/leading_slash1301=== RUN TestIsValidCachePath/wrong_extension1302=== PAUSE TestIsValidCachePath/wrong_extension1303=== RUN TestIsValidCachePath/short_hash1304=== PAUSE TestIsValidCachePath/short_hash1305=== CONT TestPendingClosureFailureAbortsItsUploads13062026/10/29 01:22:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13072026/10/29 01:22:34 INFO Aborted multipart uploads count=0 kept=013082026/10/29 01:22:34 WARN Force mode enabled - objects will be deleted immediately without grace period1309=== NAME TestClientWithDependencies1310 client_integration_test.go:722: Built derivation: /build/TestClientWithDependencies270731308/001/store/wv6v4fqzscrksgqg7wgw7j2ykcvn2zvd-test-script13112026/10/29 01:22:34 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo13122026/10/29 01:22:34 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLjhlNjRhYzg2LWViYzItNDkwNS05MGQ1LTRjYzcwNWIyZTg2ZXgxNzkzMjM2OTUzODIzNjMzMDYz error="Get \"http://127.0.0.1:1/bucket19/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"13132026/10/29 01:22:34 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLjA3MDNlMGEzLTUzNDctNDA2Yy04MWQ0LTNmNWZhN2Q2MjNhZXgxNzkzMjM2OTUzNzk1NDAyOTMy parts=1213142026/10/29 01:22:34 INFO Received cleanup request method=DELETE path=/api/pending_closures13152026/10/29 01:22:34 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13162026/10/29 01:22:34 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13172026/10/29 01:22:34 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo13182026/10/29 01:22:34 INFO Aborted multipart uploads count=1 kept=01319--- PASS: TestObjectStatsTrigger (0.58s)1320=== CONT TestParseSingleRange1321=== CONT TestClientFallsBackToClosures1322--- PASS: TestService_NativeMTLS (0.45s)1323=== RUN TestParseSingleRange/none1324=== PAUSE TestParseSingleRange/none1325=== RUN TestParseSingleRange/unknown_unit1326=== PAUSE TestParseSingleRange/unknown_unit1327=== RUN TestParseSingleRange/multi-range_ignored1328=== PAUSE TestParseSingleRange/multi-range_ignored1329=== RUN TestParseSingleRange/malformed_no_dash1330=== PAUSE TestParseSingleRange/malformed_no_dash1331=== RUN TestParseSingleRange/malformed_both_empty1332=== PAUSE TestParseSingleRange/malformed_both_empty1333=== RUN TestParseSingleRange/malformed_end_before_start1334=== PAUSE TestParseSingleRange/malformed_end_before_start1335=== RUN TestParseSingleRange/closed1336=== PAUSE TestParseSingleRange/closed1337=== RUN TestParseSingleRange/open-ended1338=== PAUSE TestParseSingleRange/open-ended1339=== RUN TestParseSingleRange/end_clamped_to_size1340=== PAUSE TestParseSingleRange/end_clamped_to_size1341=== RUN TestParseSingleRange/suffix1342=== PAUSE TestParseSingleRange/suffix1343=== RUN TestParseSingleRange/suffix_exceeds_size1344=== PAUSE TestParseSingleRange/suffix_exceeds_size1345=== RUN TestParseSingleRange/single_byte1346=== PAUSE TestParseSingleRange/single_byte1347=== RUN TestParseSingleRange/start_past_EOF1348=== PAUSE TestParseSingleRange/start_past_EOF1349=== RUN TestParseSingleRange/start_far_past_EOF1350=== PAUSE TestParseSingleRange/start_far_past_EOF1351=== CONT TestCreatePendingClosureRejectsOversizedNAR13522026/10/29 01:22:35 INFO Received uploads request method=POST path=/api/pending_closures1353=== NAME TestClientWithDependencies1354 client_integration_test.go:724: Found 1 dependencies (including self)1355--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1356=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1357--- PASS: TestConcurrentPinUpdatesAgree (1.22s)1358=== CONT TestClientPushesUseOnePush13592026/10/29 01:22:35 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=013602026/10/29 01:22:35 INFO Vacuumed table table=pending_closures1361--- PASS: TestRedundantMultipartUpload (4.06s)1362=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection13632026/10/29 01:22:35 INFO Vacuumed table table=pending_objects13642026/10/29 01:22:35 INFO Vacuumed table table=multipart_uploads13652026/10/29 01:22:35 INFO Vacuumed table table=closures13662026/10/29 01:22:35 INFO Vacuumed table table=objects13672026/10/29 01:22:35 INFO Received uploads request method=POST path=/api/pending_closures13682026/10/29 01:22:35 INFO Received push request method=POST path=/api/pushes13692026/10/29 01:22:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13702026/10/29 01:22:35 INFO Uploading wv6v4fqzscrksgqg7wgw7j2ykcvn2zvd-test-script (136B)13712026/10/29 01:22:35 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"13722026/10/29 01:22:35 WARN Failed to register uploaded object key=log/pdmp8s8lm880vjg7d44g20lwks5xbjla-test-script.drv error="server returned 404: 404 page not found\n"13732026/10/29 01:22:35 INFO Received cleanup request method=DELETE path=/api/pending_closures13742026/10/29 01:22:35 INFO Aborted multipart uploads count=0 kept=013752026/10/29 01:22:35 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket61/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""13762026/10/29 01:22:35 INFO Aborted multipart uploads count=0 kept=113772026/10/29 01:22:35 WARN Force mode enabled - objects will be deleted immediately without grace period13782026/10/29 01:22:35 INFO Received uploads request method=POST path=/api/pending_closures13792026/10/29 01:22:35 WARN Failed to register uploaded object key=wv6v4fqzscrksgqg7wgw7j2ykcvn2zvd.ls error="server returned 404: 404 page not found\n"13802026/10/29 01:22:35 INFO Received cleanup request method=DELETE path=/api/pending_closures13812026/10/29 01:22:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13822026/10/29 01:22:35 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=013832026/10/29 01:22:35 INFO Signed narinfos id=1 count=113842026/10/29 01:22:35 INFO Vacuumed table table=pending_closures13852026/10/29 01:22:35 INFO Uploading 1 narinfos13862026/10/29 01:22:35 INFO Vacuumed table table=pending_objects13872026/10/29 01:22:35 INFO Aborted multipart uploads count=1 kept=013882026/10/29 01:22:35 INFO Vacuumed table table=multipart_uploads13892026/10/29 01:22:35 INFO Vacuumed table table=closures13902026/10/29 01:22:35 INFO Vacuumed table table=objects13912026/10/29 01:22:35 INFO Aborted multipart uploads count=0 kept=013922026/10/29 01:22:35 INFO Received complete push request method=POST path=/api/pushes/1/complete13932026/10/29 01:22:35 WARN Failed to register uploaded object key=wv6v4fqzscrksgqg7wgw7j2ykcvn2zvd.narinfo error="server returned 404: 404 page not found\n"13942026/10/29 01:22:35 WARN Force mode enabled - objects will be deleted immediately without grace period13952026/10/29 01:22:35 INFO Completed push id=1 objects=4 duration=15.386583ms13962026/10/29 01:22:35 INFO Upload complete. (226ms)13972026/10/29 01:22:35 INFO lead: acquired remote=192.0.2.1:12341398--- PASS: TestMultipartCleanup (0.64s)1399=== CONT TestPinProtectsFromGC14002026/10/29 01:22:35 INFO Aborted multipart uploads count=0 kept=01401--- PASS: TestPendingClosureFailureAbortsItsUploads (0.55s)1402=== CONT TestGCSweepDeliversEachKeyOnce14032026/10/29 01:22:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14042026/10/29 01:22:35 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=014052026/10/29 01:22:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14062026/10/29 01:22:35 WARN Force mode enabled - objects will be deleted immediately without grace period14072026/10/29 01:22:35 INFO Vacuumed table table=pending_closures14082026/10/29 01:22:35 INFO Vacuumed table table=pending_objects14092026/10/29 01:22:35 INFO Vacuumed table table=multipart_uploads14102026/10/29 01:22:35 INFO Vacuumed table table=closures14112026/10/29 01:22:35 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=014122026/10/29 01:22:35 INFO Vacuumed table table=objects14132026/10/29 01:22:35 INFO Vacuumed table table=pending_closures14142026/10/29 01:22:35 INFO Vacuumed table table=pending_objects14152026/10/29 01:22:35 INFO Vacuumed table table=multipart_uploads14162026/10/29 01:22:35 INFO Vacuumed table table=closures14172026/10/29 01:22:35 INFO Vacuumed table table=objects14182026/10/29 01:22:35 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLmEwNzVkNGJhLWU1ZjYtNGY2ZS1iY2Y3LWYxZDhkYTI2MDQyMHgxNzkzMjM2OTUzNDc2NTM0Njgy parts=1014192026/10/29 01:22:35 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLjMzNzhiOGFmLThhN2QtNDQ0MC1iOWQyLTRhYzYzNzNlZTZlYXgxNzkzMjM2OTU0MjgwMjY2NDI3 parts=1214202026/10/29 01:22:35 INFO Received uploads request method=POST path=/api/pending_closures1421=== NAME TestClientWithDependencies1422 client_integration_test.go:740: Skipping nix copy test - isolated store (/build/TestClientWithDependencies270731308/001/store) requires matching store prefix14232026/10/29 01:22:35 INFO Received complete push request method=POST path=/api/pushes/1/complete1424--- PASS: TestSweepSkipsRowsLockedByPush (0.76s)1425=== CONT TestNARDeduplicationMetadataUploadBug14262026/10/29 01:22:35 INFO Completed push id=1 objects=4 duration=14.03581ms1427--- PASS: TestClientWithDependencies (1.32s)1428=== CONT TestClientSharedPathCommittedMidPush1429=== CONT TestForceGCDuringPushOffersSweptObject1430--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.80s)1431=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1432=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1433=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1434=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1435=== CONT TestCommitRacingPendingCleanupKeepsObjects1436--- PASS: TestPush_RepeatedRootCommitsOnce (3.21s)1437=== CONT TestGCSweepSkipsPendingObjects14382026/10/29 01:22:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14392026/10/29 01:22:35 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14402026/10/29 01:22:35 INFO Received uploads request method=POST path=/api/pending_closures14412026/10/29 01:22:35 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLjMxNDBjNzIwLTZlN2ItNGYxNi05NzBkLWNmM2I0YTJjNmM2NHgxNzkzMjM2OTUyNzM4MzI2Nzc3 parts=1014422026/10/29 01:22:35 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLjE0M2IyMmJhLTAzOTYtNDU5YS1hMjI3LTNkNWJhYWZkNjg4OXgxNzkzMjM2OTUyNzg4OTI5Nzc1 parts=1014432026/10/29 01:22:35 INFO Received complete push request method=POST path=/api/pushes/1/complete14442026/10/29 01:22:35 INFO Completed push id=1 objects=6 duration=25.540594ms1445--- PASS: TestConnectSerialisesConcurrentMigrations (1.27s)1446=== CONT TestPushWaitsForSweepHoldingRow1447--- PASS: TestPush_CompleteCommitsEveryRoot (4.79s)1448=== CONT TestSweepRechecksPendingAfterLocking14492026/10/29 01:22:35 INFO Received push request method=POST path=/api/pushes14502026/10/29 01:22:35 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14512026/10/29 01:22:35 INFO Uploading zd75d7gfizncx56kshchihhg7hlhjp79-b (208B)14522026/10/29 01:22:35 INFO Uploading cb15x0jbj6gp9icaxgnckkglgym1xfvg-shared-dep (136B)14532026/10/29 01:22:35 INFO Received create pin request method=POST path=/api/pins/deploy1454--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.90s)1455=== CONT TestGracefulShutdownDrainsInflight14562026/10/29 01:22:35 INFO Starting HTTP server address=127.0.0.1:4456314572026/10/29 01:22:35 INFO Shutdown signal received, draining in-flight requests timeout=10s14582026/10/29 01:22:35 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo14592026/10/29 01:22:35 INFO Aborted multipart uploads count=0 kept=014602026/10/29 01:22:35 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>14612026/10/29 01:22:35 WARN Force mode enabled - objects will be deleted immediately without grace period14622026/10/29 01:22:35 WARN Failed to register uploaded object key=b6ii2fk09784ipz6xz7bb0ndnbbd1732.ls error="server returned 404: 404 page not found\n"14632026/10/29 01:22:35 WARN Failed to register uploaded object key=nar/0shqgl2bk8z07m017d3p633mf0kjgf14hlvnlvnpmqmmkxr9xqbw.nar.zst error="server returned 404: 404 page not found\n"14642026/10/29 01:22:35 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1465=== NAME TestPinProtectsFromGC1466 client_integration_test.go:854: Pinned store path: /build/TestPinProtectsFromGC824333635/001/store/zaxviqsbrfm3nsgd5jcfcjjychvvy5hf-pinned-file.txt1467 client_integration_test.go:855: Unpinned store path: /build/TestPinProtectsFromGC824333635/001/store/rlllazqr68fdr0k8vdh84ia2c5qfc33j-unpinned-file.txt14682026/10/29 01:22:36 INFO Received uploads request method=POST path=/api/pending_closures14692026/10/29 01:22:36 WARN Failed to register uploaded object key=zd75d7gfizncx56kshchihhg7hlhjp79.ls error="server returned 404: 404 page not found\n"1470--- PASS: TestCreatePinRejectsBadInput (1.96s)1471=== CONT TestMetricsCommit14722026/10/29 01:22:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14732026/10/29 01:22:36 WARN Failed to register uploaded object key=cb15x0jbj6gp9icaxgnckkglgym1xfvg.ls error="server returned 404: 404 page not found\n"14742026/10/29 01:22:36 INFO Signed narinfos id=1 count=314752026/10/29 01:22:36 INFO Uploading 3 narinfos14762026/10/29 01:22:36 INFO Received uploads request method=POST path=/api/pending_closures1477=== CONT TestDeduplicatedObjectsRecordedAsPending1478--- PASS: TestGracefulShutdownDrainsInflight (0.08s)14792026/10/29 01:22:36 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14802026/10/29 01:22:36 WARN Failed to register uploaded object key=zd75d7gfizncx56kshchihhg7hlhjp79.narinfo error="server returned 404: 404 page not found\n"14812026/10/29 01:22:36 INFO Uploading 42l375sq6jgw3s1vd5jl9kwjb5532d8p-b (216B)14822026/10/29 01:22:36 INFO Uploading 1m45cwazcq2iwagnvmscjxsrjl8rz90q-shared-dep (136B)1483--- PASS: TestReadProxyNarinfo (2.77s)1484=== CONT TestClientCADerivations14852026/10/29 01:22:36 WARN Failed to register uploaded object key=xrk6qsp721icjbmr4h083ys0sffpwkpn.ls error="server returned 404: 404 page not found\n"14862026/10/29 01:22:36 WARN Failed to register uploaded object key=b6ii2fk09784ipz6xz7bb0ndnbbd1732.narinfo error="server returned 404: 404 page not found\n"14872026/10/29 01:22:36 WARN Failed to register uploaded object key=cb15x0jbj6gp9icaxgnckkglgym1xfvg.narinfo error="server returned 404: 404 page not found\n"14882026/10/29 01:22:36 INFO Received complete push request method=POST path=/api/pushes/1/complete14892026/10/29 01:22:36 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=014902026/10/29 01:22:36 INFO Vacuumed table table=pending_closures14912026/10/29 01:22:36 INFO Vacuumed table table=pending_objects14922026/10/29 01:22:36 INFO Vacuumed table table=multipart_uploads14932026/10/29 01:22:36 INFO Vacuumed table table=closures14942026/10/29 01:22:36 INFO Completed push id=1 objects=8 duration=14.02989ms14952026/10/29 01:22:36 INFO Upload complete. (291ms)14962026/10/29 01:22:36 INFO Vacuumed table table=objects14972026/10/29 01:22:36 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14982026/10/29 01:22:36 WARN Failed to register uploaded object key=nar/15sm4bxvmq784h0kd0rrra7vz819bph9w2k7h3bx9hq2cm0lhj4f.nar.zst error="server returned 404: 404 page not found\n"1499=== NAME TestClientPushesUseOnePush1500 client_pushes_test.go:97: Retrieved narinfo from S3:1501 StorePath: /build/TestClientPushesUseOnePush277232638/001/store/cb15x0jbj6gp9icaxgnckkglgym1xfvg-shared-dep1502 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1503 Compression: zstd1504 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821505 NarSize: 1361506 References: 1507 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1508--- PASS: TestReadProxyContentNegotiation (1.87s)1509=== CONT TestRegisterCompletedObjectNeedsPendingRow1510=== NAME TestClientPushesUseOnePush1511 client_pushes_test.go:97: Retrieved narinfo from S3:1512 StorePath: /build/TestClientPushesUseOnePush277232638/001/store/b6ii2fk09784ipz6xz7bb0ndnbbd1732-a1513 URL: nar/0shqgl2bk8z07m017d3p633mf0kjgf14hlvnlvnpmqmmkxr9xqbw.nar.zst1514 Compression: zstd1515 NarHash: sha256:0shqgl2bk8z07m017d3p633mf0kjgf14hlvnlvnpmqmmkxr9xqbw1516 NarSize: 2081517 References: /build/TestClientPushesUseOnePush277232638/001/store/cb15x0jbj6gp9icaxgnckkglgym1xfvg-shared-dep1518 CA: text:sha256:1z5g23g8rc70vwxrpcdvf9ka19x3kpwb3wfkpdm8d89hflgqh3zg15192026/10/29 01:22:36 WARN Failed to register uploaded object key=42l375sq6jgw3s1vd5jl9kwjb5532d8p.ls error="server returned 404: 404 page not found\n"15202026/10/29 01:22:36 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15212026/10/29 01:22:36 WARN Failed to register uploaded object key=1m45cwazcq2iwagnvmscjxsrjl8rz90q.ls error="server returned 404: 404 page not found\n"15222026/10/29 01:22:36 INFO Signed narinfos id=2 count=215232026/10/29 01:22:36 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15242026/10/29 01:22:36 INFO Signed narinfos id=1 count=215252026/10/29 01:22:36 INFO Uploading 4 narinfos1526 client_pushes_test.go:97: Retrieved narinfo from S3:1527 StorePath: /build/TestClientPushesUseOnePush277232638/001/store/zd75d7gfizncx56kshchihhg7hlhjp79-b1528 URL: nar/0shqgl2bk8z07m017d3p633mf0kjgf14hlvnlvnpmqmmkxr9xqbw.nar.zst1529 Compression: zstd1530 NarHash: sha256:0shqgl2bk8z07m017d3p633mf0kjgf14hlvnlvnpmqmmkxr9xqbw1531 NarSize: 2081532 References: /build/TestClientPushesUseOnePush277232638/001/store/cb15x0jbj6gp9icaxgnckkglgym1xfvg-shared-dep1533 CA: text:sha256:1z5g23g8rc70vwxrpcdvf9ka19x3kpwb3wfkpdm8d89hflgqh3zg1534--- PASS: TestGCSweepDeliversEachKeyOnce (0.71s)1535=== CONT TestClientMultipleUploads15362026/10/29 01:22:36 WARN Failed to register uploaded object key=1m45cwazcq2iwagnvmscjxsrjl8rz90q.narinfo error="server returned 404: 404 page not found\n"15372026/10/29 01:22:36 WARN Failed to register uploaded object key=42l375sq6jgw3s1vd5jl9kwjb5532d8p.narinfo error="server returned 404: 404 page not found\n"15382026/10/29 01:22:36 WARN Failed to register uploaded object key=xrk6qsp721icjbmr4h083ys0sffpwkpn.narinfo error="server returned 404: 404 page not found\n"15392026/10/29 01:22:36 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15402026/10/29 01:22:36 WARN Failed to register uploaded object key=1m45cwazcq2iwagnvmscjxsrjl8rz90q.narinfo error="server returned 404: 404 page not found\n"15412026/10/29 01:22:36 INFO Completed upload id=1 objects=6 duration=11.462805ms15422026/10/29 01:22:36 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15432026/10/29 01:22:36 INFO Completed upload id=2 objects=6 duration=4.049459ms15442026/10/29 01:22:36 INFO Upload complete. (228ms)1545=== NAME TestClientFallsBackToClosures1546 client_pushes_test.go:112: Retrieved narinfo from S3:1547 StorePath: /build/TestClientFallsBackToClosures297786499/001/store/1m45cwazcq2iwagnvmscjxsrjl8rz90q-shared-dep1548 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst15492026/10/29 01:22:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1550 Compression: zstd1551 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821552 NarSize: 1361553 References: 1554 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1555--- PASS: TestClientPushesUseOnePush (1.13s)1556=== CONT TestGetExistingObjectsLocksRows15572026/10/29 01:22:36 INFO Received push request method=POST path=/api/pushes1558=== NAME TestClientFallsBackToClosures1559 client_pushes_test.go:112: Retrieved narinfo from S3:1560 StorePath: /build/TestClientFallsBackToClosures297786499/001/store/xrk6qsp721icjbmr4h083ys0sffpwkpn-a1561 URL: nar/15sm4bxvmq784h0kd0rrra7vz819bph9w2k7h3bx9hq2cm0lhj4f.nar.zst1562 Compression: zstd1563 NarHash: sha256:15sm4bxvmq784h0kd0rrra7vz819bph9w2k7h3bx9hq2cm0lhj4f1564 NarSize: 2161565 References: /build/TestClientFallsBackToClosures297786499/001/store/1m45cwazcq2iwagnvmscjxsrjl8rz90q-shared-dep1566 CA: text:sha256:0p3vr0rbh21lhsj7wjy3mpgb8w4a616izdh69lk7sk6742yqjf3p1567=== NAME TestNARDeduplicationMetadataUploadBug1568 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1666702142/001/store/a5r7x499l0fgcyvm4r7b6h7csabk51v2-file1.txt1569=== NAME TestClientFallsBackToClosures1570 client_pushes_test.go:112: Retrieved narinfo from S3:1571 StorePath: /build/TestClientFallsBackToClosures297786499/001/store/42l375sq6jgw3s1vd5jl9kwjb5532d8p-b1572 URL: nar/15sm4bxvmq784h0kd0rrra7vz819bph9w2k7h3bx9hq2cm0lhj4f.nar.zst1573 Compression: zstd1574 NarHash: sha256:15sm4bxvmq784h0kd0rrra7vz819bph9w2k7h3bx9hq2cm0lhj4f1575 NarSize: 2161576 References: /build/TestClientFallsBackToClosures297786499/001/store/1m45cwazcq2iwagnvmscjxsrjl8rz90q-shared-dep1577 CA: text:sha256:0p3vr0rbh21lhsj7wjy3mpgb8w4a616izdh69lk7sk6742yqjf3p15782026/10/29 01:22:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15792026/10/29 01:22:36 INFO Uploading zaxviqsbrfm3nsgd5jcfcjjychvvy5hf-pinned-file.txt (128B)15802026/10/29 01:22:36 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLmM4ZDE2ZWQyLTY5YzUtNDZmZC04ZjBhLWU5MWRiZjJiYzk1OHgxNzkzMjM2OTU0ODI3MzQzMTI0 parts=1015812026/10/29 01:22:36 INFO Received complete push request method=POST path=/api/pushes/2/complete15822026/10/29 01:22:36 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15832026/10/29 01:22:36 INFO Completed push id=2 objects=4 duration=8.306918ms15842026/10/29 01:22:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15852026/10/29 01:22:36 WARN Failed to register uploaded object key=zaxviqsbrfm3nsgd5jcfcjjychvvy5hf.ls error="server returned 404: 404 page not found\n"15862026/10/29 01:22:36 INFO Signed narinfos id=1 count=115872026/10/29 01:22:36 INFO Uploading 1 narinfos15882026/10/29 01:22:36 INFO Received complete push request method=POST path=/api/pushes/1/complete1589--- PASS: TestClientFallsBackToClosures (1.24s)1590=== CONT TestClientIntegration15912026/10/29 01:22:36 WARN Failed to register uploaded object key=zaxviqsbrfm3nsgd5jcfcjjychvvy5hf.narinfo error="server returned 404: 404 page not found\n"1592--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (5.28s)1593=== CONT TestGenerateLandingPage15942026/10/29 01:22:36 INFO Received uploads request method=POST path=/api/pending_closures1595--- PASS: TestGenerateLandingPage (0.01s)1596=== CONT TestTombstonedObjectOfferedWithoutWaiting15972026/10/29 01:22:36 INFO Aborted multipart uploads count=0 kept=015982026/10/29 01:22:36 INFO Completed push id=1 objects=3 duration=27.270338ms15992026/10/29 01:22:36 INFO Upload complete. (197ms)16002026/10/29 01:22:36 WARN Force mode enabled - objects will be deleted immediately without grace period16012026/10/29 01:22:36 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=016022026/10/29 01:22:36 INFO Received uploads request method=POST path=/api/pending_closures16032026/10/29 01:22:36 INFO Vacuumed table table=pending_closures16042026/10/29 01:22:36 INFO Vacuumed table table=pending_objects16052026/10/29 01:22:36 INFO Vacuumed table table=multipart_uploads16062026/10/29 01:22:36 INFO Vacuumed table table=closures16072026/10/29 01:22:36 INFO Vacuumed table table=objects16082026/10/29 01:22:36 INFO Aborted multipart uploads count=0 kept=016092026/10/29 01:22:36 WARN Force mode enabled - objects will be deleted immediately without grace period16102026/10/29 01:22:36 INFO Received push request method=POST path=/api/pushes16112026/10/29 01:22:36 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=016122026/10/29 01:22:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16132026/10/29 01:22:36 INFO Uploading a5r7x499l0fgcyvm4r7b6h7csabk51v2-file1.txt (160B)16142026/10/29 01:22:36 INFO Vacuumed table table=pending_closures16152026/10/29 01:22:36 INFO Vacuumed table table=pending_objects16162026/10/29 01:22:36 INFO Vacuumed table table=multipart_uploads16172026/10/29 01:22:36 INFO Vacuumed table table=closures16182026/10/29 01:22:36 INFO Vacuumed table table=objects1619--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.81s)1620=== CONT TestPushDedupSurvivesConcurrentGC16212026/10/29 01:22:36 INFO Aborted multipart uploads count=0 kept=016222026/10/29 01:22:36 WARN Failed to register uploaded object key=a5r7x499l0fgcyvm4r7b6h7csabk51v2.ls error="server returned 404: 404 page not found\n"16232026/10/29 01:22:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16242026/10/29 01:22:36 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"16252026/10/29 01:22:36 INFO Signed narinfos id=1 count=116262026/10/29 01:22:36 WARN Force mode enabled - objects will be deleted immediately without grace period16272026/10/29 01:22:36 INFO Uploading 1 narinfos16282026/10/29 01:22:36 INFO Received complete push request method=POST path=/api/pushes/1/complete16292026/10/29 01:22:36 WARN Failed to register uploaded object key=a5r7x499l0fgcyvm4r7b6h7csabk51v2.narinfo error="server returned 404: 404 page not found\n"16302026/10/29 01:22:36 INFO Received push request method=POST path=/api/pushes16312026/10/29 01:22:36 INFO Completed push id=1 objects=3 duration=14.548671ms16322026/10/29 01:22:36 INFO Upload complete. (176ms)1633=== NAME TestNARDeduplicationMetadataUploadBug1634 metadata_upload_test.go:54: Retrieved narinfo from S3:1635 StorePath: /build/TestNARDeduplicationMetadataUploadBug1666702142/001/store/a5r7x499l0fgcyvm4r7b6h7csabk51v2-file1.txt1636 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst16372026/10/29 01:22:36 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1638 Compression: zstd1639 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1640 NarSize: 16016412026/10/29 01:22:36 INFO Uploading rlllazqr68fdr0k8vdh84ia2c5qfc33j-unpinned-file.txt (128B)1642 References: 1643 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1644 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1645 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1646 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1647--- PASS: TestGCSweepSkipsPendingObjects (0.85s)16482026/10/29 01:22:36 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=01649=== CONT TestCacheStatsHandler16502026/10/29 01:22:36 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16512026/10/29 01:22:36 INFO Vacuumed table table=pending_closures16522026/10/29 01:22:36 WARN Failed to register uploaded object key=rlllazqr68fdr0k8vdh84ia2c5qfc33j.ls error="server returned 404: 404 page not found\n"16532026/10/29 01:22:36 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16542026/10/29 01:22:36 INFO Vacuumed table table=pending_objects16552026/10/29 01:22:36 INFO Vacuumed table table=multipart_uploads16562026/10/29 01:22:36 INFO Signed narinfos id=2 count=116572026/10/29 01:22:36 INFO Vacuumed table table=closures16582026/10/29 01:22:36 INFO Received push request method=POST path=/api/pushes16592026/10/29 01:22:36 INFO Uploading 1 narinfos16602026/10/29 01:22:36 INFO Vacuumed table table=objects16612026/10/29 01:22:36 INFO Received complete push request method=POST path=/api/pushes/2/complete16622026/10/29 01:22:36 WARN Failed to register uploaded object key=rlllazqr68fdr0k8vdh84ia2c5qfc33j.narinfo error="server returned 404: 404 page not found\n"16632026/10/29 01:22:36 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16642026/10/29 01:22:36 INFO Uploading p958lbsih744jwghji68m3fjvh1m88ah-top (224B)16652026/10/29 01:22:36 INFO Uploading a3a413xcjrh6mq0v5bmv7zf17i14680f-shared-dep (136B)16662026/10/29 01:22:36 INFO Completed push id=2 objects=3 duration=3.969179ms16672026/10/29 01:22:36 INFO Upload complete. (165ms)1668--- PASS: TestDeleteClosuresRacingPins (3.19s)1669=== CONT TestFailedS3DeleteKeepsTombstone16702026/10/29 01:22:36 INFO lead: released remote=192.0.2.1:12341671--- PASS: TestSweepRechecksPendingAfterLocking (0.78s)1672=== CONT TestGCBugBareHashReferences16732026/10/29 01:22:36 WARN Failed to register uploaded object key=nar/1mqcp0qvd2hjar3z0vppbb4i1n3s6mv37vmlv8ln5wf2sdifp1ar.nar.zst error="server returned 404: 404 page not found\n"16742026/10/29 01:22:36 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1675=== NAME TestNARDeduplicationMetadataUploadBug1676 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1666702142/001/store/mw9w1gn02xa3663alkhwjrisvpyimky5-file2.txt16772026/10/29 01:22:36 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16782026/10/29 01:22:36 WARN Failed to register uploaded object key=p958lbsih744jwghji68m3fjvh1m88ah.ls error="server returned 404: 404 page not found\n"16792026/10/29 01:22:36 WARN Failed to register uploaded object key=a3a413xcjrh6mq0v5bmv7zf17i14680f.ls error="server returned 404: 404 page not found\n"16802026/10/29 01:22:36 INFO Signed narinfos id=1 count=216812026/10/29 01:22:36 INFO Uploading 2 narinfos16822026/10/29 01:22:36 INFO lead: acquired remote=192.0.2.1:123416832026/10/29 01:22:36 INFO Received push request method=POST path=/api/pushes16842026/10/29 01:22:36 INFO Starting cleanup of old closures method=DELETE path=/api/closures16852026/10/29 01:22:36 INFO Garbage collection started16862026/10/29 01:22:36 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16872026/10/29 01:22:36 INFO Received complete push request method=POST path=/api/pushes/1/complete16882026/10/29 01:22:36 WARN Failed to register uploaded object key=a3a413xcjrh6mq0v5bmv7zf17i14680f.narinfo error="server returned 404: 404 page not found\n"16892026/10/29 01:22:36 WARN Failed to register uploaded object key=p958lbsih744jwghji68m3fjvh1m88ah.narinfo error="server returned 404: 404 page not found\n"16902026/10/29 01:22:36 INFO Completed push id=1 objects=6 duration=15.636104ms16912026/10/29 01:22:36 INFO Upload complete. (241ms)1692=== NAME TestClientSharedPathCommittedMidPush16932026/10/29 01:22:36 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLmQ5YTgwYjU0LWZhMGQtNDc5OS04NDQzLTIwNGUzNmJiMjI5NngxNzkzMjM2OTUyNzM3MDc4MTM0 parts=101694 client_integration_test.go:803: Retrieved narinfo from S3:1695 StorePath: /build/TestClientSharedPathCommittedMidPush545314230/001/store/a3a413xcjrh6mq0v5bmv7zf17i14680f-shared-dep1696 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1697 Compression: zstd1698 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821699 NarSize: 1361700 References: 1701 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17022026/10/29 01:22:36 INFO Aborted multipart uploads count=0 kept=01703 client_integration_test.go:803: Retrieved narinfo from S3:1704 StorePath: /build/TestClientSharedPathCommittedMidPush545314230/001/store/p958lbsih744jwghji68m3fjvh1m88ah-top1705 URL: nar/1mqcp0qvd2hjar3z0vppbb4i1n3s6mv37vmlv8ln5wf2sdifp1ar.nar.zst1706 Compression: zstd1707 NarHash: sha256:1mqcp0qvd2hjar3z0vppbb4i1n3s6mv37vmlv8ln5wf2sdifp1ar1708 NarSize: 2241709 References: /build/TestClientSharedPathCommittedMidPush545314230/001/store/a3a413xcjrh6mq0v5bmv7zf17i14680f-shared-dep1710 CA: text:sha256:0zs0s4diavciq1r3qahahays3ahrhc6z33p8gacp29xj6fwnllp217112026/10/29 01:22:36 INFO Received uploads request method=POST path=/api/pending_closures17122026/10/29 01:22:36 WARN Force mode enabled - objects will be deleted immediately without grace period1713--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.68s)1714=== CONT TestService_readinessHandler1715--- PASS: TestClientSharedPathCommittedMidPush (1.15s)1716=== CONT TestGCMetrics17172026/10/29 01:22:36 INFO Received push request method=POST path=/api/pushes17182026/10/29 01:22:36 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=017192026/10/29 01:22:36 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17202026/10/29 01:22:36 INFO Vacuumed table table=pending_closures1721--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.66s)1722=== CONT TestGCAdvisoryLockBlocksConcurrentRun17232026/10/29 01:22:36 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17242026/10/29 01:22:36 INFO Signed narinfos id=2 count=117252026/10/29 01:22:36 WARN Failed to register uploaded object key=mw9w1gn02xa3663alkhwjrisvpyimky5.ls error="server returned 404: 404 page not found\n"17262026/10/29 01:22:36 INFO Uploading 1 narinfos1727=== NAME TestClientCADerivations17282026/10/29 01:22:36 INFO Vacuumed table table=pending_objects1729 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations510041380/001/store/09qcic9cxyvai7994xnwaf5ilzy9dk3w-ca-test17302026/10/29 01:22:36 INFO Vacuumed table table=multipart_uploads17312026/10/29 01:22:36 INFO Vacuumed table table=closures17322026/10/29 01:22:36 INFO Received complete push request method=POST path=/api/pushes/2/complete17332026/10/29 01:22:36 WARN Failed to register uploaded object key=mw9w1gn02xa3663alkhwjrisvpyimky5.narinfo error="server returned 404: 404 page not found\n"17342026/10/29 01:22:36 INFO Vacuumed table table=objects17352026/10/29 01:22:36 INFO Completed push id=2 objects=3 duration=21.713117ms17362026/10/29 01:22:36 INFO Upload complete. (169ms)1737=== NAME TestNARDeduplicationMetadataUploadBug1738 metadata_upload_test.go:76: Retrieved narinfo from S3:1739 StorePath: /build/TestNARDeduplicationMetadataUploadBug1666702142/001/store/mw9w1gn02xa3663alkhwjrisvpyimky5-file2.txt1740 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1741 Compression: zstd1742 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1743 NarSize: 1601744 References: 1745 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1746 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1747 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1748 {"version":1,"root":{"type":"regular","size":44}}1749=== NAME TestClientCADerivations1750 client_ca_test.go:139: Found 1 dependencies (including self)1751--- PASS: TestPushWaitsForSweepHoldingRow (1.15s)1752=== CONT TestGCTaskStore_Fail1753--- PASS: TestGCTaskStore_Fail (0.00s)1754=== CONT TestCacheConfigHandler1755=== RUN TestCacheConfigHandler/full_config,_no_issuer1756=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1757=== RUN TestCacheConfigHandler/no_cache_url_configured1758=== PAUSE TestCacheConfigHandler/no_cache_url_configured1759=== RUN TestCacheConfigHandler/no_signing_keys1760=== PAUSE TestCacheConfigHandler/no_signing_keys1761=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1762=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1763=== CONT TestService_ReadAuthMiddleware1764=== NAME TestClientMultipleUploads1765 client_integration_test.go:467: Created store path 0: /build/TestClientMultipleUploads1520184937/001/store/569i62g9nhwq7m9fc2n879kkp87vwm19-test-file-0.txt1766--- PASS: TestGetExistingObjectsLocksRows (0.71s)1767=== CONT TestService_ReadScope_PublicByDefault1768--- PASS: TestNARDeduplicationMetadataUploadBug (1.35s)1769=== CONT TestClientErrorHandling1770=== RUN TestClientErrorHandling/InvalidStorePath1771=== PAUSE TestClientErrorHandling/InvalidStorePath1772=== RUN TestClientErrorHandling/InvalidAuthToken1773=== PAUSE TestClientErrorHandling/InvalidAuthToken1774=== RUN TestClientErrorHandling/ServerNotAvailable1775=== PAUSE TestClientErrorHandling/ServerNotAvailable1776--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.87s)1777=== CONT TestService_AuthMiddleware_MTLSProxyHeader1778=== CONT TestService_RequireScope_OIDC17792026/10/29 01:22:36 INFO Received uploads request method=POST path=/api/pending_closures1780=== NAME TestClientMultipleUploads1781 client_integration_test.go:467: Created store path 1: /build/TestClientMultipleUploads1520184937/001/store/72q3a2zfgmh2jbd9cinn0n0yrnr0qkqq-test-file-1.txt1782=== NAME TestClientIntegration1783 client_integration_test.go:331: Created store path: /build/TestClientIntegration2018647632/002/store/6mag0zz66cql2va03al4jcz7agnikv9k-test-file.txt1784--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.72s)1785=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17862026/10/29 01:22:37 INFO Received uploads request method=POST path=/1787=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17882026/10/29 01:22:37 INFO Received complete multipart upload request method=POST path=/1789=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17902026/10/29 01:22:37 INFO Received request for more parts method=POST path=/1791=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17922026/10/29 01:22:37 INFO Received uploads request method=POST path=/1793=== CONT TestProxyWriteTimeout/unknown_size1794--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)1795 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1796 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1797 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1798 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1799=== CONT TestProxyWriteTimeout/10_GiB_nar1800=== CONT TestProxyWriteTimeout/1_GiB_nar1801=== CONT TestProxyWriteTimeout/narinfo1802=== CONT TestPendingClosureWriteTimeout/empty1803--- PASS: TestProxyWriteTimeout (0.01s)1804 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1805 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1806 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1807 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1808=== CONT TestPendingClosureWriteTimeout/400_objects1809=== CONT TestPendingClosureWriteTimeout/670k_objects1810=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1811=== NAME TestClientMultipleUploads1812 client_integration_test.go:467: Created store path 2: /build/TestClientMultipleUploads1520184937/001/store/ib40dl46497hbqndhy86ijcnibwib954-test-file-2.txt18132026/10/29 01:22:37 INFO Received uploads request method=POST path=/api/pending_closures1814=== NAME TestOrphanedObjectsGCStressTest1815 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains18162026/10/29 01:22:37 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32975/oidc18172026/10/29 01:22:37 INFO Received push request method=POST path=/api/pushes18182026/10/29 01:22:37 INFO Received uploads request method=POST path=/api/pending_closures1819--- PASS: TestCacheStatsHandler (0.65s)1820=== CONT TestIsValidUploadKey/build_log_plus_in_name1821=== CONT TestIsValidUploadKey/unknown_type1822=== CONT TestIsValidUploadKey/build_log1823=== CONT TestIsValidUploadKey/realisation_plus_in_output1824=== CONT TestIsValidUploadKey/build_log_question_mark1825=== CONT TestIsValidUploadKey/build_log_equals1826=== CONT TestIsValidUploadKey/build_log_home-manager_file1827=== CONT TestIsValidUploadKey/nar_xz18282026/10/29 01:22:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1829=== CONT TestIsValidUploadKey/listing18302026/10/29 01:22:37 INFO Uploading 09qcic9cxyvai7994xnwaf5ilzy9dk3w-ca-test (144B)1831=== CONT TestIsValidUploadKey/nar_plain1832=== CONT TestIsValidUploadKey/nar_zst1833=== CONT TestIsValidUploadKey/narinfo1834=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1835=== CONT TestIsValidUploadKey/absolute1836=== CONT TestIsValidUploadKey/traversal_nar1837=== CONT TestIsValidUploadKey/traversal1838=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1839=== NAME TestOrphanedObjectsGCStressTest1840 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion1841=== CONT TestIsValidUploadKey/index.html1842=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1843=== CONT TestIsValidUploadKey/nix-cache-info1844=== CONT TestIsValidUploadKey/empty_key1845=== CONT TestIsValidUploadKey/realisation1846=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart1847--- PASS: TestIsValidUploadKey (0.02s)1848 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1849 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1850 --- PASS: TestIsValidUploadKey/build_log (0.00s)1851 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1852 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1853 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1854 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1855 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1856 --- PASS: TestIsValidUploadKey/listing (0.00s)1857 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1858 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1859 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1860 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1861 --- PASS: TestIsValidUploadKey/absolute (0.00s)1862 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1863 --- PASS: TestIsValidUploadKey/traversal (0.00s)1864 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1865 --- PASS: TestIsValidUploadKey/index.html (0.00s)1866 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1867 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1868 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1869 --- PASS: TestIsValidUploadKey/realisation (0.00s)18702026/10/29 01:22:37 INFO Received complete multipart upload request method=POST path=/18712026/10/29 01:22:37 WARN Failed to register uploaded object key=log/icmy8kzllzpm7imjiqgi7qs2kkwhm8nj-ca-test.drv error="server returned 404: 404 page not found\n"18722026/10/29 01:22:37 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18732026/10/29 01:22:37 INFO Aborted multipart uploads count=0 kept=018742026/10/29 01:22:37 INFO Received push request method=POST path=/api/pushes18752026/10/29 01:22:37 WARN Failed to register uploaded object key=09qcic9cxyvai7994xnwaf5ilzy9dk3w.ls error="server returned 404: 404 page not found\n"18762026/10/29 01:22:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18772026/10/29 01:22:37 INFO Signed narinfos id=1 count=118782026/10/29 01:22:37 INFO Uploading 1 narinfos18792026/10/29 01:22:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18802026/10/29 01:22:37 INFO Uploading 6mag0zz66cql2va03al4jcz7agnikv9k-test-file.txt (152B)18812026/10/29 01:22:37 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=018822026/10/29 01:22:37 INFO Received complete push request method=POST path=/api/pushes/1/complete18832026/10/29 01:22:37 INFO Vacuumed table table=pending_closures18842026/10/29 01:22:37 WARN Failed to register uploaded object key=09qcic9cxyvai7994xnwaf5ilzy9dk3w.narinfo error="server returned 404: 404 page not found\n"18852026/10/29 01:22:37 INFO Vacuumed table table=pending_objects18862026/10/29 01:22:37 INFO Vacuumed table table=multipart_uploads18872026/10/29 01:22:37 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"18882026/10/29 01:22:37 INFO Completed push id=1 objects=4 duration=15.548773ms18892026/10/29 01:22:37 INFO Upload complete. (292ms)18902026/10/29 01:22:37 INFO Received push request method=POST path=/api/pushes18912026/10/29 01:22:37 WARN Failed to register uploaded object key=6mag0zz66cql2va03al4jcz7agnikv9k.ls error="server returned 404: 404 page not found\n"18922026/10/29 01:22:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18932026/10/29 01:22:37 INFO Signed narinfos id=1 count=118942026/10/29 01:22:37 INFO Uploading 1 narinfos1895=== NAME TestClientCADerivations1896 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations510041380/001/store/09qcic9cxyvai7994xnwaf5ilzy9dk3w-ca-test1897 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1898 Compression: zstd1899 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1900 NarSize: 1441901 References: 1902 Deriver: /build/TestClientCADerivations510041380/001/store/icmy8kzllzpm7imjiqgi7qs2kkwhm8nj-ca-test.drv1903 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1904 client_ca_test.go:185: Checking for realisation files in S3...19052026/10/29 01:22:37 INFO Aborted multipart uploads count=0 kept=019062026/10/29 01:22:37 INFO Aborted multipart uploads count=0 kept=01907 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1908 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache19092026/10/29 01:22:37 INFO Received complete push request method=POST path=/api/pushes/1/complete19102026/10/29 01:22:37 WARN Failed to register uploaded object key=6mag0zz66cql2va03al4jcz7agnikv9k.narinfo error="server returned 404: 404 page not found\n"19112026/10/29 01:22:37 INFO Vacuumed table table=closures19122026/10/29 01:22:37 WARN Force mode enabled - objects will be deleted immediately without grace period19132026/10/29 01:22:37 INFO Vacuumed table table=objects19142026/10/29 01:22:37 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)19152026/10/29 01:22:37 WARN Force mode enabled - objects will be deleted immediately without grace period19162026/10/29 01:22:37 INFO Uploading ib40dl46497hbqndhy86ijcnibwib954-test-file-2.txt (160B)19172026/10/29 01:22:37 INFO Uploading 569i62g9nhwq7m9fc2n879kkp87vwm19-test-file-0.txt (160B)19182026/10/29 01:22:37 INFO Uploading 72q3a2zfgmh2jbd9cinn0n0yrnr0qkqq-test-file-1.txt (160B)19192026/10/29 01:22:37 INFO Completed push id=1 objects=3 duration=11.845315ms19202026/10/29 01:22:37 INFO Upload complete. (192ms)19212026/10/29 01:22:37 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=019222026/10/29 01:22:37 INFO Vacuumed table table=pending_closures19232026/10/29 01:22:37 INFO Vacuumed table table=pending_objects19242026/10/29 01:22:37 INFO Vacuumed table table=multipart_uploads19252026/10/29 01:22:37 INFO Vacuumed table table=closures19262026/10/29 01:22:37 INFO Aborted multipart uploads count=0 kept=019272026/10/29 01:22:37 INFO Vacuumed table table=objects19282026/10/29 01:22:37 WARN Force mode enabled - objects will be deleted immediately without grace period19292026/10/29 01:22:37 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=019302026/10/29 01:22:37 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"19312026/10/29 01:22:37 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."19322026/10/29 01:22:37 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."19332026/10/29 01:22:37 INFO Vacuumed table table=pending_closures19342026/10/29 01:22:37 INFO Vacuumed table table=pending_objects19352026/10/29 01:22:37 INFO Vacuumed table table=multipart_uploads19362026/10/29 01:22:37 WARN Failed to register uploaded object key=569i62g9nhwq7m9fc2n879kkp87vwm19.ls error="server returned 404: 404 page not found\n"19372026/10/29 01:22:37 INFO Vacuumed table table=closures19382026/10/29 01:22:37 INFO Vacuumed table table=objects19392026/10/29 01:22:37 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"19402026/10/29 01:22:37 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"19412026/10/29 01:22:37 WARN Failed to register uploaded object key=72q3a2zfgmh2jbd9cinn0n0yrnr0qkqq.ls error="server returned 404: 404 page not found\n"19422026/10/29 01:22:37 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19432026/10/29 01:22:37 WARN Failed to register uploaded object key=ib40dl46497hbqndhy86ijcnibwib954.ls error="server returned 404: 404 page not found\n"19442026/10/29 01:22:37 INFO Signed narinfos id=1 count=319452026/10/29 01:22:37 INFO Uploading 3 narinfos1946--- PASS: TestFailedS3DeleteKeepsTombstone (0.79s)19472026/10/29 01:22:37 WARN Failed to register uploaded object key=72q3a2zfgmh2jbd9cinn0n0yrnr0qkqq.narinfo error="server returned 404: 404 page not found\n"1948=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts19492026/10/29 01:22:37 WARN readiness check failed error="closed pool"19502026/10/29 01:22:37 INFO Received request for more parts method=POST path=/1951--- PASS: TestPushDedupSurvivesConcurrentGC (0.94s)1952=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19532026/10/29 01:22:37 INFO Received uploads request method=POST path=/19542026/10/29 01:22:37 WARN Failed to register uploaded object key=ib40dl46497hbqndhy86ijcnibwib954.narinfo error="server returned 404: 404 page not found\n"19552026/10/29 01:22:37 INFO Received complete push request method=POST path=/api/pushes/1/complete19562026/10/29 01:22:37 INFO All 1 paths already cached19572026/10/29 01:22:37 WARN Failed to register uploaded object key=569i62g9nhwq7m9fc2n879kkp87vwm19.narinfo error="server returned 404: 404 page not found\n"1958=== NAME TestClientIntegration1959 client_integration_test.go:357: Retrieved narinfo from S3:1960 StorePath: /build/TestClientIntegration2018647632/002/store/6mag0zz66cql2va03al4jcz7agnikv9k-test-file.txt1961 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1962 Compression: zstd1963 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11964 NarSize: 1521965 References: 1966 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11967 client_integration_test.go:358: Retrieved .ls file from S3 (compressed size: 77 bytes)1968 client_integration_test.go:358: Decompressed .ls content (64 bytes):1969 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}19702026/10/29 01:22:37 INFO Completed push id=1 objects=9 duration=18.39792ms1971--- PASS: TestService_readinessHandler (0.64s)19722026/10/29 01:22:37 INFO Upload complete. (230ms)1973=== CONT TestPush_RejectsBadRequests/root_not_in_objects1974=== NAME TestClientMultipleUploads1975 client_integration_test.go:478: Uploaded 3 paths in 305.324272ms19762026/10/29 01:22:37 INFO Received push request method=POST path=/api/pushes1977--- PASS: TestGCMetrics (0.63s)1978=== CONT TestPush_RejectsBadRequests/no_objects1979=== CONT TestPush_RejectsBadRequests/bad_root19802026/10/29 01:22:37 INFO Received push request method=POST path=/api/pushes19812026/10/29 01:22:37 INFO Received push request method=POST path=/api/pushes1982=== CONT TestPush_RejectsBadRequests/no_roots19832026/10/29 01:22:37 INFO Received push request method=POST path=/api/pushes1984=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1985=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1986--- PASS: TestService_ReadAuthMiddleware (0.54s)1987=== CONT TestGCEndsOnShutdown/before_the_run1988--- PASS: TestPush_RejectsBadRequests (1.48s)1989 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1990 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1991 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1992 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1993=== NAME TestClientCADerivations1994 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1995 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1996 error: binary cache 's3://bucket77?endpoint=http://localhost:37981®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations510041380/001/store'1997 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11998--- PASS: TestClientMultipleUploads (1.33s)1999=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete2000--- PASS: TestService_ReadScope_PublicByDefault (0.57s)2001=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark2002--- PASS: TestGCBugBareHashReferences (0.93s)2003=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale2004--- PASS: TestClientCADerivations (1.44s)2005=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh2006--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.60s)20072026/10/29 01:22:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2008=== CONT TestServerTLSConfig/no_client_CA2009=== CONT TestServerTLSConfig/missing_CA_file2010=== CONT TestServerTLSConfig/not_a_PEM_file2011=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2012--- PASS: TestServerTLSConfig (0.00s)2013 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2014 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2015 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2016=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20172026/10/29 01:22:37 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]2018=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20192026/10/29 01:22:37 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20202026/10/29 01:22:37 INFO Received uploads request method=POST path=/api/pending_closures20212026/10/29 01:22:37 WARN Authentication failed token_preview=eyJhbGciOi...-o0DVYlQWg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2022=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2023=== CONT TestResolveDBConnectionString/file_when_flag_empty2024=== CONT TestResolveDBConnectionString/nothing_configured2025=== CONT TestResolveDBConnectionString/missing_file_is_an_error2026=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2027=== CONT TestResolveDBConnectionString/flag_wins2028=== CONT TestIsValidCachePath/nar_zst2029=== CONT TestIsValidCachePath/traversal_parent2030--- PASS: TestResolveDBConnectionString (0.00s)2031 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2032 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2033 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2034 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2035 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2036=== CONT TestIsValidCachePath/nix-cache-info2037=== CONT TestIsValidCachePath/index.html2038=== CONT TestIsValidCachePath/nar_xz2039=== CONT TestIsValidCachePath/ls2040=== CONT TestIsValidCachePath/nar_bz22041=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2042=== CONT TestIsValidCachePath/realisation2043=== CONT TestIsValidCachePath/invalid_char_e2044=== CONT TestIsValidCachePath/narinfo2045=== CONT TestIsValidCachePath/log2046=== CONT TestIsValidCachePath/wrong_extension2047=== CONT TestIsValidCachePath/empty2048=== CONT TestIsValidCachePath/leading_slash2049=== CONT TestIsValidCachePath/random_path2050=== CONT TestIsValidCachePath/traversal_in_middle2051=== CONT TestIsValidCachePath/nar_uncompressed2052=== CONT TestIsValidCachePath/short_hash2053=== CONT TestIsValidCachePath/invalid_char_u2054=== CONT TestParseSingleRange/none2055--- PASS: TestIsValidCachePath (0.01s)2056 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2057 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2058 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2059 --- PASS: TestIsValidCachePath/index.html (0.00s)2060 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2061 --- PASS: TestIsValidCachePath/ls (0.00s)2062 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2063 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2064 --- PASS: TestIsValidCachePath/realisation (0.00s)2065 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2066 --- PASS: TestIsValidCachePath/narinfo (0.00s)2067 --- PASS: TestIsValidCachePath/log (0.00s)2068 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2069 --- PASS: TestIsValidCachePath/empty (0.00s)2070 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2071 --- PASS: TestIsValidCachePath/random_path (0.00s)2072 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2073 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2074 --- PASS: TestIsValidCachePath/short_hash (0.00s)2075 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2076=== CONT TestParseSingleRange/start_far_past_EOF2077=== CONT TestParseSingleRange/single_byte2078=== CONT TestParseSingleRange/start_past_EOF2079=== CONT TestParseSingleRange/suffix2080=== CONT TestParseSingleRange/suffix_exceeds_size2081=== CONT TestParseSingleRange/end_clamped_to_size2082=== CONT TestParseSingleRange/closed2083=== CONT TestParseSingleRange/open-ended2084=== CONT TestParseSingleRange/malformed_both_empty2085=== CONT TestParseSingleRange/malformed_no_dash2086=== CONT TestParseSingleRange/malformed_end_before_start2087=== CONT TestParseSingleRange/unknown_unit2088=== CONT TestParseSingleRange/multi-range_ignored2089=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows2090--- PASS: TestParseSingleRange (0.00s)2091 --- PASS: TestParseSingleRange/none (0.00s)2092 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2093 --- PASS: TestParseSingleRange/single_byte (0.00s)2094 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2095 --- PASS: TestParseSingleRange/suffix (0.00s)2096 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2097 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2098 --- PASS: TestParseSingleRange/closed (0.00s)2099 --- PASS: TestParseSingleRange/open-ended (0.00s)2100 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2101 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2102 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2103 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2104 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)21052026/10/29 01:22:37 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLmFhYTYwNWI4LTFlZTUtNDUzOC1hZTljLWMxYWFlODgxY2UyZHgxNzkzMjM2OTUyNzM3NjcyMDU1 parts=1021062026/10/29 01:22:37 INFO Received push request method=POST path=/api/pushes21072026/10/29 01:22:37 INFO Object in database but missing from S3 key=6mag0zz66cql2va03al4jcz7agnikv9k.ls21082026/10/29 01:22:37 WARN Found objects in DB but missing from S3, will re-upload count=121092026/10/29 01:22:37 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21102026/10/29 01:22:37 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLjQ3N2NlMjA4LTU0OTEtNGRjZC1iMTYzLWM1ZmNmNDc5Yzg0MngxNzkzMjM2OTU2NjI4MTQxNDU3 parts=1021112026/10/29 01:22:37 WARN Failed to register uploaded object key=6mag0zz66cql2va03al4jcz7agnikv9k.ls error="server returned 404: 404 page not found\n"21122026/10/29 01:22:37 INFO Received complete push request method=POST path=/api/pushes/2/complete21132026/10/29 01:22:37 INFO Completed push id=2 objects=3 duration=4.144549ms21142026/10/29 01:22:37 INFO Upload complete. (123ms)2115=== NAME TestClientIntegration2116 client_integration_test.go:375: Retrieved .ls file from S3 (compressed size: 62 bytes)2117 client_integration_test.go:375: Decompressed .ls content (49 bytes):2118 {"version":1,"root":{"type":"regular","size":39}}2119=== RUN TestService_RequireScope_OIDC/builder_may_write2120=== PAUSE TestService_RequireScope_OIDC/builder_may_write2121=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2122=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2123=== RUN TestService_RequireScope_OIDC/ops_may_admin2124=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2125=== RUN TestService_RequireScope_OIDC/ops_may_not_write2126=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2127=== RUN TestService_RequireScope_OIDC/reader_may_not_write2128=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2129=== RUN TestService_RequireScope_OIDC/static_token_may_admin2130=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2131=== RUN TestService_RequireScope_OIDC/static_token_may_write2132=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2133=== RUN TestService_RequireScope_OIDC/reader_may_read2134=== PAUSE TestService_RequireScope_OIDC/reader_may_read2135=== RUN TestService_RequireScope_OIDC/writer_implies_read2136=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2137=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2138=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2139=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc2140=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc2141=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2142=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2143=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2144=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2145=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2146=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2147--- PASS: TestService_AuthMiddleware_OIDC (0.93s)2148 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2149 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2150 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)2151 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2152=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check21532026/10/29 01:22:37 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"21542026/10/29 01:22:37 INFO lead: released remote=192.0.2.1:12342155--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.99s)2156=== CONT TestCacheConfigHandler/full_config,_no_issuer2157=== CONT TestCacheConfigHandler/no_cache_url_configured2158=== CONT TestCacheConfigHandler/no_signing_keys2159=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2160=== CONT TestClientErrorHandling/ServerNotAvailable2161--- PASS: TestCacheConfigHandler (0.00s)2162 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2163 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2164 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2165 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)21662026/10/29 01:22:37 INFO Received uploads request method=POST path=/api/pending_closures2167=== CONT TestClientErrorHandling/InvalidAuthToken2168--- PASS: TestLeadElectsOneAndHandsOver (2.93s)2169=== CONT TestClientErrorHandling/InvalidStorePath2170--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.62s)21712026/10/29 01:22:37 INFO Received push request method=POST path=/api/pushes21722026-10-29 01:22:37.856 UTC [178] LOG: checkpoints are occurring too frequently (13 seconds apart)21732026-10-29 01:22:37.856 UTC [178] HINT: Consider increasing the configuration parameter "max_wal_size".21742026-10-29 01:22:37.856 UTC [178] LOG: checkpoint starting: wal21752026/10/29 01:22:37 INFO Received uploads request method=POST path=/api/pending_closures21762026/10/29 01:22:37 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/present21772026/10/29 01:22:37 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)21782026/10/29 01:22:37 INFO Received complete push request method=POST path=/api/pushes/3/complete21792026/10/29 01:22:37 WARN Failed to register uploaded object key=6mag0zz66cql2va03al4jcz7agnikv9k.ls error="server returned 404: 404 page not found\n"21802026/10/29 01:22:37 INFO Completed push id=3 objects=3 duration=5.187521ms21812026/10/29 01:22:37 INFO Upload complete. (204ms)2182=== NAME TestClientIntegration2183 client_integration_test.go:392: Retrieved .ls file from S3 (compressed size: 62 bytes)2184 client_integration_test.go:392: Decompressed .ls content (49 bytes):2185 {"version":1,"root":{"type":"regular","size":39}}2186=== CONT TestService_RequireScope_OIDC/ops_may_admin2187=== CONT TestService_RequireScope_OIDC/reader_may_read2188=== CONT TestService_RequireScope_OIDC/static_token_may_write2189=== CONT TestService_RequireScope_OIDC/reader_may_not_write2190=== CONT TestService_RequireScope_OIDC/static_token_may_admin2191=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2192=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2193=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2194=== CONT TestService_RequireScope_OIDC/ops_may_not_write2195=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2196=== CONT TestService_RequireScope_OIDC/writer_implies_read2197=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2198=== CONT TestService_RequireScope_OIDC/builder_may_write21992026/10/29 01:22:37 WARN Request failed, retrying attempt=2 backoff=187.077618ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2200=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read22012026/10/29 01:22:37 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]22022026/10/29 01:22:38 INFO Aborted multipart uploads count=0 kept=022032026/10/29 01:22:38 WARN Force mode enabled - objects will be deleted immediately without grace period2204--- PASS: TestService_RequireScope_OIDC (0.75s)2205 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2206 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2207 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2208 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2209 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2210 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2211 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2212 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2213 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2214 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2215 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2216 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2217 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2218 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)22192026/10/29 01:22:38 WARN Rate limiter enabled after throttle name=s3-test rate=522202026/10/29 01:22:38 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2221=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2222 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102223 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002224--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (7.18s)22252026/10/29 01:22:38 INFO Received push request method=POST path=/api/pushes22262026/10/29 01:22:38 INFO Aborted multipart uploads count=0 kept=022272026/10/29 01:22:38 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22282026/10/29 01:22:38 INFO Uploading 1x10qyqifii74nzlmhnrmy8a8n1ikjyr-lost-commit.txt (152B)22292026/10/29 01:22:38 WARN Force mode enabled - objects will be deleted immediately without grace period22302026/10/29 01:22:38 WARN Request failed, retrying attempt=3 backoff=418.712651ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22312026/10/29 01:22:38 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"22322026/10/29 01:22:38 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:37981/bucket104/?delete=\": context canceled"22332026/10/29 01:22:38 INFO Received uploads request method=POST path=/api/pending_closures22342026/10/29 01:22:38 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign22352026/10/29 01:22:38 WARN Failed to register uploaded object key=1x10qyqifii74nzlmhnrmy8a8n1ikjyr.ls error="server returned 404: 404 page not found\n"22362026/10/29 01:22:38 INFO Signed narinfos id=4 count=122372026/10/29 01:22:38 INFO Uploading 1 narinfos22382026/10/29 01:22:38 INFO Aborted multipart uploads count=0 kept=022392026/10/29 01:22:38 INFO Received complete push request method=POST path=/api/pushes/4/complete22402026/10/29 01:22:38 WARN Failed to register uploaded object key=1x10qyqifii74nzlmhnrmy8a8n1ikjyr.narinfo error="server returned 404: 404 page not found\n"22412026/10/29 01:22:38 INFO Completed push id=4 objects=3 duration=3.472197ms22422026/10/29 01:22:38 WARN Force mode enabled - objects will be deleted immediately without grace period22432026/10/29 01:22:38 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:39787/api/pushes/4/complete\": EOF" url=http://127.0.0.1:39787/api/pushes/4/complete2244--- PASS: TestGCEndsOnShutdown (0.00s)2245 --- PASS: TestGCEndsOnShutdown/before_the_run (0.57s)2246 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.65s)2247 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.79s)22482026/10/29 01:22:38 INFO Received uploads request method=POST path=/api/pending_closures22492026/10/29 01:22:38 INFO Aborted multipart uploads count=0 kept=022502026/10/29 01:22:38 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=022512026/10/29 01:22:38 INFO Vacuumed table table=pending_closures22522026/10/29 01:22:38 INFO Vacuumed table table=pending_objects22532026/10/29 01:22:38 INFO Vacuumed table table=multipart_uploads22542026/10/29 01:22:38 INFO Vacuumed table table=closures22552026/10/29 01:22:38 WARN Force mode enabled - objects will be deleted immediately without grace period22562026/10/29 01:22:38 INFO Vacuumed table table=objects22572026/10/29 01:22:38 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=022582026/10/29 01:22:38 INFO Vacuumed table table=pending_closures22592026/10/29 01:22:38 INFO Vacuumed table table=pending_objects22602026/10/29 01:22:38 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLmY1ZWQ3NGU1LWY2MGEtNGE0YS05OGM1LTM3MzAyZjE1ODQ5NXgxNzkzMjM2OTU3NzgzMTc2MTQy error="Access Denied"22612026/10/29 01:22:38 WARN keeping failed pending closure for cleanup to retry the abort id=122622026/10/29 01:22:38 INFO Vacuumed table table=multipart_uploads22632026/10/29 01:22:38 INFO Vacuumed table table=closures22642026/10/29 01:22:38 INFO Vacuumed table table=objects22652026/10/29 01:22:38 INFO Received complete push request method=POST path=/api/pushes/4/complete22662026-10-29 01:22:38.322 UTC [1549] ERROR: Push does not exist: id=422672026-10-29 01:22:38.322 UTC [1549] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE22682026-10-29 01:22:38.322 UTC [1549] STATEMENT: -- name: CommitPush :one2269 SELECT commit_push($1::bigint)::bigint2270 22712026/10/29 01:22:38 WARN Push not found id=422722026/10/29 01:22:38 INFO Upload complete. (248ms)2273=== NAME TestClientIntegration2274 client_integration_test.go:422: Retrieved narinfo from S3:2275 StorePath: /build/TestClientIntegration2018647632/002/store/1x10qyqifii74nzlmhnrmy8a8n1ikjyr-lost-commit.txt2276 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst2277 Compression: zstd2278 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2279 NarSize: 1522280 References: 2281 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2282 client_integration_test.go:425: Testing garbage collection...2283--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2284 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.76s)2285 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.82s)2286--- PASS: TestPendingClosureWriteTimeout (0.02s)2287 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2288 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2289 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2290 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.35s)22912026/10/29 01:22:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22922026/10/29 01:22:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22932026/10/29 01:22:38 INFO Starting cleanup of old closures method=DELETE path=/api/closures22942026/10/29 01:22:38 INFO Garbage collection started22952026/10/29 01:22:38 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLmExODRhNmJhLTMzNDctNDcwMy05MDc0LWJkNDM3NmFlZTQ1ZHgxNzkzMjM2OTUyNzM0Mzc5NzM4 parts=1022962026/10/29 01:22:38 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22972026/10/29 01:22:38 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OTI4ZmI1NDktNjI5MS00MDFlLTg4ZTMtZTJkNmYyOWM2YjNiLmM0MDI4MjE1LTkzZmItNDJiNy1hYmU0LWQ4MThiZDIxNmI5M3gxNzkzMjM2OTU2NjI1NTczNjAy parts=1022982026/10/29 01:22:38 INFO Received complete push request method=POST path=/api/pushes/1/complete22992026/10/29 01:22:38 INFO Aborted multipart uploads count=0 kept=023002026/10/29 01:22:38 INFO Completed push id=1 objects=4 duration=14.551131ms23012026/10/29 01:22:38 WARN Force mode enabled - objects will be deleted immediately without grace period23022026-10-29 01:22:38.436 UTC [789] ERROR: could not obtain lock on row in relation "closures"23032026-10-29 01:22:38.436 UTC [789] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23042026/10/29 01:22:38 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete23052026-10-29 01:22:38.438 UTC [789] ERROR: could not obtain lock on row in relation "closures"23062026-10-29 01:22:38.438 UTC [789] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23072026-10-29 01:22:38.439 UTC [789] ERROR: could not obtain lock on row in relation "closures"23082026-10-29 01:22:38.439 UTC [789] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23092026-10-29 01:22:38.440 UTC [789] ERROR: could not obtain lock on row in relation "closures"23102026-10-29 01:22:38.440 UTC [789] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23112026/10/29 01:22:38 INFO Completed upload id=2 objects=2 duration=2.786056ms23122026-10-29 01:22:38.441 UTC [789] ERROR: could not obtain lock on row in relation "closures"23132026-10-29 01:22:38.441 UTC [789] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT2314--- PASS: TestPendingClosureFailureTracksEveryUpload (0.00s)2315 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (0.98s)2316 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (1.10s)23172026/10/29 01:22:38 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2318--- PASS: TestPush_RootsAreLockedInByteOrder (7.50s)23192026/10/29 01:22:38 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=02320--- PASS: TestMetricsCommit (2.49s)23212026/10/29 01:22:38 INFO Vacuumed table table=pending_closures23222026/10/29 01:22:38 INFO Vacuumed table table=pending_objects23232026/10/29 01:22:38 INFO Vacuumed table table=multipart_uploads23242026/10/29 01:22:38 INFO Vacuumed table table=closures23252026/10/29 01:22:38 INFO Vacuumed table table=objects23262026/10/29 01:22:38 WARN Request failed, retrying attempt=4 backoff=805.040139ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23272026/10/29 01:22:38 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=023282026/10/29 01:22:38 INFO Received create pin request method=POST path=/api/pins/myapp2329--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2330 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (1.08s)2331 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (1.15s)23322026/10/29 01:22:38 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC824333635/001/store/zaxviqsbrfm3nsgd5jcfcjjychvvy5hf-pinned-file.txt narinfo_key=zaxviqsbrfm3nsgd5jcfcjjychvvy5hf.narinfo23332026/10/29 01:22:38 INFO Starting cleanup of old closures method=DELETE path=/api/closures23342026/10/29 01:22:38 INFO Garbage collection started23352026/10/29 01:22:38 INFO Aborted multipart uploads count=0 kept=023362026/10/29 01:22:38 WARN Force mode enabled - objects will be deleted immediately without grace period23372026/10/29 01:22:38 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=023382026/10/29 01:22:38 INFO Vacuumed table table=pending_closures23392026/10/29 01:22:38 INFO Vacuumed table table=pending_objects23402026/10/29 01:22:38 INFO Vacuumed table table=multipart_uploads23412026/10/29 01:22:38 INFO Vacuumed table table=closures23422026/10/29 01:22:38 INFO Vacuumed table table=objects2343--- PASS: TestConnectWaitsForAPeerMigration (5.42s)2344=== NAME TestOrphanedObjectsGCStressTest2345 orphaned_objects_gc_test.go:503: Stress test completed successfully:2346 orphaned_objects_gc_test.go:504: - Active objects preserved: 202347 orphaned_objects_gc_test.go:505: - Objects deleted: 2102348 orphaned_objects_gc_test.go:506: - Total GC'd: 2102349--- PASS: TestOrphanedObjectsGCStressTest (8.33s)23502026/10/29 01:22:39 WARN Request failed, retrying attempt=5 backoff=1.588118977s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23512026/10/29 01:22:39 INFO Aborted multipart uploads count=1 kept=023522026/10/29 01:22:40 INFO Received cleanup request method=DELETE path=/api/pending_closures23532026/10/29 01:22:40 INFO Aborted multipart uploads count=1 kept=02354--- PASS: TestPendingCleanupUsesOneCutoff (6.84s)23552026/10/29 01:22:40 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02356=== NAME TestClientIntegration2357 client_integration_test.go:432: Objects in database after GC:2358 client_integration_test.go:432: Successfully deleted all objects with GC --force2359--- PASS: TestClientIntegration (4.20s)2360=== NAME TestPinProtectsFromGC2361 client_integration_test.go:963: Pin successfully protected closure from garbage collection2362--- PASS: TestPinProtectsFromGC (5.36s)23632026/10/29 01:22:41 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-config23642026/10/29 01:22:41 WARN Request failed, retrying attempt=2 backoff=209.166267ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23652026/10/29 01:22:41 WARN Request failed, retrying attempt=3 backoff=400.443937ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23662026/10/29 01:22:41 WARN Request failed, retrying attempt=4 backoff=752.902806ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23672026/10/29 01:22:42 WARN Request failed, retrying attempt=5 backoff=1.745753393s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23682026/10/29 01:22:44 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"23692026/10/29 01:22:44 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-config23702026/10/29 01:22:44 WARN Request failed, retrying attempt=2 backoff=184.175037ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23712026/10/29 01:22:44 WARN Request failed, retrying attempt=3 backoff=387.425563ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23722026/10/29 01:22:44 WARN Request failed, retrying attempt=4 backoff=855.71239ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23732026/10/29 01:22:45 WARN Request failed, retrying attempt=5 backoff=1.578638879s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23742026/10/29 01:22:47 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_closures23752026/10/29 01:22:47 WARN Request failed, retrying attempt=2 backoff=202.743152ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23762026/10/29 01:22:47 WARN Request failed, retrying attempt=3 backoff=366.253421ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23772026/10/29 01:22:48 WARN Request failed, retrying attempt=4 backoff=858.67907ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23782026/10/29 01:22:48 WARN Request failed, retrying attempt=5 backoff=1.464809154s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2379--- PASS: TestUploadHandlersRejectOversizedBody (0.77s)2380 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (1.00s)2381 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.93s)2382 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (13.12s)2383--- PASS: TestClientErrorHandling (0.00s)2384 --- PASS: TestClientErrorHandling/InvalidStorePath (0.64s)2385 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.75s)2386 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.70s)2387PASS2388{"timestamp":"2026-10-29T01:22:50.462666462Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:43372","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(400)"}23892026-10-29 01:22:51.092 UTC [173] LOG: received smart shutdown request23902026-10-29 01:22:51.098 UTC [173] LOG: background worker "logical replication launcher" (PID 183) exited with exit code 123912026-10-29 01:22:53.238 UTC [178] LOG: checkpoint complete: wrote 9810 buffers (59.9%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=13.707 s, sync=1.557 s, total=15.382 s; sync files=37079, longest=0.003 s, average=0.001 s; distance=534570 kB, estimate=534570 kB; lsn=0/22A7A580, redo lsn=0/221707B823922026-10-29 01:22:53.244 UTC [178] LOG: shutting down23932026-10-29 01:22:53.245 UTC [178] LOG: checkpoint starting: shutdown immediate23942026-10-29 01:22:53.414 UTC [178] LOG: checkpoint complete: wrote 1089 buffers (6.6%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.045 s, sync=0.118 s, total=0.170 s; sync files=422, longest=0.002 s, average=0.001 s; distance=9255 kB, estimate=482039 kB; lsn=0/22A7A5F8, redo lsn=0/22A7A5F823952026-10-29 01:22:53.518 UTC [173] 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_Expired2437=== CONT TestGlobMatch2438=== CONT TestValidateToken_NoMatchingProvider2439=== RUN TestGlobMatch/foo_foo2440=== PAUSE TestGlobMatch/foo_foo2441=== RUN TestGlobMatch/foo_bar2442=== CONT TestValidateToken_ValidToken2443=== CONT TestPins_TopLevelShorthand2444--- PASS: TestAudienceForIssuer (0.00s)2445=== CONT TestPins_ReservedForMatchingRule2446=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2447=== CONT TestNewValidator_KubernetesRequiresCA2448=== CONT TestPins_ConfigValidation2449=== CONT TestValidateToken_BoundSubjectMismatch2450=== CONT TestValidateToken_MultipleProviders2451=== CONT TestScopes_LegacyProviderDefaultsToWrite2452=== CONT TestScopes_ConfigValidation2453=== CONT TestScopes_Rules2454=== CONT TestHTTPClientForHasTimeouts2455=== CONT TestValidateToken_WrongAudience2456=== PAUSE TestGlobMatch/foo_bar2457=== CONT TestValidateToken_KubernetesServiceAccount2458=== CONT TestValidateToken_BoundClaimsMismatch2459--- PASS: TestPins_ConfigValidation (0.01s)2460=== RUN TestGlobMatch/*_2461--- PASS: TestScopes_ConfigValidation (0.00s)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_bar2508=== CONT TestGlobMatch/fo?_fooo2509=== CONT TestGlobMatch/?oo_foo2510=== CONT TestGlobMatch/fo?_fo2511=== CONT TestGlobMatch/refs/*/main_refs/heads/main2512=== CONT TestGlobMatch/fo?_foo2513=== CONT TestGlobMatch/foo*bar_foo123bar2514=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2515=== CONT TestGlobMatch/*bar_foobar2516=== CONT TestGlobMatch/*bar_bar2517=== CONT TestGlobMatch/*/*_foo2518=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2519=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02520=== CONT TestGlobMatch/*/*_foo/bar2521=== CONT TestGlobMatch/?oo_boo2522=== CONT TestGlobMatch/*bar_foo2523=== CONT TestGlobMatch/foo_foo2524=== CONT TestGlobMatch/foo*bar_foobarbaz2525=== CONT TestGlobMatch/foo*_bar2526=== CONT TestGlobMatch/*_2527=== CONT TestGlobMatch/foo*_foobar2528=== CONT TestGlobMatch/*_anything2529=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2530=== CONT TestGlobMatch/foo*_foo2531=== CONT TestGlobMatch/foo*bar_foobar2532--- PASS: TestGlobMatch (0.03s)2533 --- PASS: TestGlobMatch/foo_bar (0.00s)2534 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2535 --- PASS: TestGlobMatch/?oo_foo (0.00s)2536 --- PASS: TestGlobMatch/fo?_fo (0.00s)2537 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2538 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2539 --- PASS: TestGlobMatch/fo?_foo (0.00s)2540 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2541 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2542 --- PASS: TestGlobMatch/*bar_bar (0.00s)2543 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2544 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2545 --- PASS: TestGlobMatch/*/*_foo (0.00s)2546 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2547 --- PASS: TestGlobMatch/*bar_foo (0.00s)2548 --- PASS: TestGlobMatch/?oo_boo (0.00s)2549 --- PASS: TestGlobMatch/foo_foo (0.00s)2550 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2551 --- PASS: TestGlobMatch/foo*_bar (0.00s)2552 --- PASS: TestGlobMatch/*_ (0.00s)2553 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2554 --- PASS: TestGlobMatch/*_anything (0.00s)2555 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2556 --- PASS: TestGlobMatch/foo*_foo (0.00s)2557 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)25582026/10/29 01:22:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36253/oidc2559--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.07s)25602026/10/29 01:22:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38205/oidc2561--- PASS: TestPins_TopLevelShorthand (0.10s)25622026/10/29 01:22:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40373/oidc2563--- PASS: TestValidateToken_BoundSubjectMismatch (0.12s)25642026/10/29 01:22:59 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232565--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.16s)25662026/10/29 01:22:59 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:4671325672026/10/29 01:22:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40305/oidc2568--- PASS: TestValidateToken_KubernetesServiceAccount (0.17s)2569--- PASS: TestPins_ReservedForMatchingRule (0.19s)25702026/10/29 01:22:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36365/oidc25712026/10/29 01:22:59 http: TLS handshake error from 127.0.0.1:55596: remote error: tls: bad certificate2572--- PASS: TestNewValidator_KubernetesRequiresCA (0.21s)2573--- PASS: TestValidateToken_ValidToken (0.22s)25742026/10/29 01:22:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40485/oidc2575--- PASS: TestValidateToken_Expired (0.24s)25762026/10/29 01:22:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36993/oidc25772026/10/29 01:22:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42887/oidc2578--- PASS: TestValidateToken_WrongAudience (0.24s)2579--- PASS: TestScopes_Rules (0.26s)25802026/10/29 01:22:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38069/oidc2581--- PASS: TestValidateToken_BoundClaimsMismatch (0.30s)25822026/10/29 01:22:59 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41821/oidc2583--- PASS: TestValidateToken_NoMatchingProvider (0.34s)2584--- PASS: TestHTTPClientForHasTimeouts (0.42s)25852026/10/29 01:23:00 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37421/oidc25862026/10/29 01:23:00 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:40219/oidc2587--- PASS: TestValidateToken_MultipleProviders (0.58s)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 TestQueueRemoveLargeClosure2607=== PAUSE TestQueueRemoveLargeClosure2608=== RUN TestServerClientIntegration2609--- PASS: TestServerClientIntegration (0.01s)2610=== RUN TestServerQueueError26112026/10/29 01:23:01 ERROR Failed to queue paths error="permission denied" count=12612--- PASS: TestServerQueueError (0.00s)2613=== RUN TestServerRefusesOversizedAndNonStoreRequests2614=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2615=== RUN TestGetListenerSocketActivation2616 server_test.go:309: === RUN TestGetListenerSocketActivation2617 --- PASS: TestGetListenerSocketActivation (0.00s)2618 PASS2619 2620--- PASS: TestGetListenerSocketActivation (1.04s)2621=== RUN TestServerStalledClientDoesNotBlockShutdown2622=== PAUSE TestServerStalledClientDoesNotBlockShutdown2623=== RUN TestServerBacksOffOnAcceptErrors2624=== PAUSE TestServerBacksOffOnAcceptErrors2625=== RUN TestDrainIsolatesPoisonPath2626=== PAUSE TestDrainIsolatesPoisonPath2627=== RUN TestRunNotBlockedByPoisonHead2628=== PAUSE TestRunNotBlockedByPoisonHead2629=== RUN TestDrainGivesUpWhenServerDown2630=== PAUSE TestDrainGivesUpWhenServerDown2631=== RUN TestFailedPathPrunedByLaterClosure2632=== PAUSE TestFailedPathPrunedByLaterClosure2633=== RUN TestWorkerUploadsAndRemoves2634=== PAUSE TestWorkerUploadsAndRemoves2635=== RUN TestWorkerSkipsGCdPaths2636=== PAUSE TestWorkerSkipsGCdPaths2637=== RUN TestWorkerPrunesClosureDeps2638=== PAUSE TestWorkerPrunesClosureDeps2639=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2640=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2641=== RUN TestDrainTimeout2642=== PAUSE TestDrainTimeout2643=== RUN TestDrainTimeoutDuringIsolation2644=== PAUSE TestDrainTimeoutDuringIsolation2645=== RUN TestShutdownFinishesInFlightPush2646=== PAUSE TestShutdownFinishesInFlightPush2647=== RUN TestWorkerRemoveFailureIsNotProgress2648=== PAUSE TestWorkerRemoveFailureIsNotProgress2649=== RUN TestWorkerKeepsPathItCannotStat2650=== PAUSE TestWorkerKeepsPathItCannotStat2651=== CONT TestQueueDeduplication2652=== CONT TestWorkerKeepsPathItCannotStat2653=== CONT TestWorkerRemoveFailureIsNotProgress2654=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2655=== CONT TestShutdownFinishesInFlightPush2656=== RUN TestShutdownFinishesInFlightPush/completes2657=== CONT TestDrainTimeout2658=== CONT TestQueueRemoveLargeClosure2659=== CONT TestQueueFetchRemoveLifecycle2660=== CONT TestQueueFetchBatchLimit2661=== CONT TestServerStalledClientDoesNotBlockShutdown2662=== CONT TestQueueRemove2663=== CONT TestQueueRetryMovesToBack2664=== CONT TestSendPathsEmpty2665=== CONT TestQueueEnqueueAndFetch2666=== CONT TestServerRefusesOversizedAndNonStoreRequests2667=== CONT TestServerBacksOffOnAcceptErrors2668=== CONT TestDrainIsolatesPoisonPath2669=== CONT TestWorkerPrunesClosureDeps2670=== CONT TestQueueConcurrentWriters2671=== CONT TestFailedPathPrunedByLaterClosure2672=== CONT TestWorkerSkipsGCdPaths2673=== CONT TestWorkerUploadsAndRemoves26742026/10/29 01:23:02 ERROR Accept failed error="too many open files"2675=== CONT TestRunNotBlockedByPoisonHead2676=== CONT TestDrainGivesUpWhenServerDown2677=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2678=== PAUSE TestShutdownFinishesInFlightPush/completes26792026/10/29 01:23:02 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2680--- PASS: TestSendPathsEmpty (0.00s)26812026/10/29 01:23:02 ERROR Refusing path outside the store path=/nix/store store=/nix/store2682=== CONT TestDrainTimeoutDuringIsolation2683=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2684=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short26852026/10/29 01:23:02 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store2686=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2687=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch26882026/10/29 01:23:02 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store2689=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2690=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout26912026/10/29 01:23:02 ERROR Accept failed error="too many open files"2692=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch26932026/10/29 01:23:02 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store2694=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2695=== CONT TestShutdownFinishesInFlightPush/completes26962026/10/29 01:23:02 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store2697=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2698=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2699=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths27002026/10/29 01:23:02 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store2701=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2702=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline27032026/10/29 01:23:02 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store27042026/10/29 01:23:02 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store27052026/10/29 01:23:02 ERROR Accept failed error="too many open files"27062026/10/29 01:23:02 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store27072026/10/29 01:23:02 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store27082026/10/29 01:23:02 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store27092026/10/29 01:23:02 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store27102026/10/29 01:23:02 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store27112026/10/29 01:23:02 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store27122026/10/29 01:23:02 ERROR Failed to decode request error="unexpected EOF"2713=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short2714--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.03s)27152026/10/29 01:23:02 ERROR Accept failed error="too many open files"27162026/10/29 01:23:02 ERROR Accept failed error="too many open files"27172026/10/29 01:23:02 INFO Upload queue status pending=227182026/10/29 01:23:02 INFO Upload queue status pending=227192026/10/29 01:23:02 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3606174825/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat3606174825/002/locked/aaa: permission denied"27202026/10/29 01:23:02 INFO Uploading batch count=227212026/10/29 01:23:02 INFO Upload queue status pending=327222026/10/29 01:23:02 INFO Uploading batch count=227232026/10/29 01:23:02 INFO Uploading batch count=227242026/10/29 01:23:02 INFO Uploading batch count=427252026/10/29 01:23:02 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths1012612161/002/nonexistent2726=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch27272026/10/29 01:23:02 ERROR Upload failed error="upload failed" count=42728=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths2729--- PASS: TestQueueFetchBatchLimit (0.11s)2730--- PASS: TestQueueDeduplication (0.11s)27312026/10/29 01:23:02 INFO Uploading batch count=127322026/10/29 01:23:02 ERROR Upload failed error="upload failed" count=127332026/10/29 01:23:02 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3606174825/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat3606174825/002/locked/aaa: permission denied"27342026/10/29 01:23:02 INFO Upload queue status pending=327352026/10/29 01:23:02 INFO Uploading batch count=227362026/10/29 01:23:02 INFO Upload queue status pending=227372026/10/29 01:23:02 INFO Upload queue status pending=227382026/10/29 01:23:02 INFO Uploading batch count=127392026/10/29 01:23:02 INFO Uploading batch count=427402026/10/29 01:23:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath59787321/002/bbb27412026/10/29 01:23:02 ERROR Upload failed error="upload failed" count=127422026/10/29 01:23:02 ERROR Upload failed error="upload failed" count=427432026/10/29 01:23:02 INFO Uploading batch count=127442026/10/29 01:23:02 INFO Uploading batch count=227452026/10/29 01:23:02 INFO Uploading batch count=127462026/10/29 01:23:02 INFO Upload queue status pending=227472026/10/29 01:23:02 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3606174825/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat3606174825/002/locked/aaa: permission denied"27482026/10/29 01:23:02 INFO Uploading batch count=227492026/10/29 01:23:02 ERROR Upload failed error="upload failed" count=227502026/10/29 01:23:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2164418499/002/a2751--- PASS: TestQueueRetryMovesToBack (0.12s)2752=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27532026/10/29 01:23:02 INFO Uploading batch count=427542026/10/29 01:23:02 INFO Uploading batch count=227552026/10/29 01:23:02 ERROR Upload failed error="upload failed" count=42756--- PASS: TestQueueFetchRemoveLifecycle (0.13s)27572026/10/29 01:23:02 INFO Uploading batch count=12758--- PASS: TestQueueEnqueueAndFetch (0.13s)27592026/10/29 01:23:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2164418499/002/b27602026/10/29 01:23:02 INFO Uploading batch count=12761--- PASS: TestWorkerUploadsAndRemoves (0.13s)27622026/10/29 01:23:02 ERROR Drain finished with paths left in queue remaining=127632026/10/29 01:23:02 ERROR Upload failed error="upload failed" count=12764--- PASS: TestQueueRemove (0.14s)2765--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.14s)27662026/10/29 01:23:02 INFO Uploading batch count=227672026/10/29 01:23:02 ERROR Upload failed error="upload failed" count=227682026/10/29 01:23:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2164418499/002/c27692026/10/29 01:23:02 INFO Uploading batch count=127702026/10/29 01:23:02 ERROR Upload failed error="upload failed" count=127712026/10/29 01:23:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2164418499/002/d2772--- PASS: TestWorkerSkipsGCdPaths (0.14s)2773--- PASS: TestWorkerKeepsPathItCannotStat (0.15s)2774--- PASS: TestWorkerPrunesClosureDeps (0.15s)27752026/10/29 01:23:02 INFO Uploading batch count=127762026/10/29 01:23:02 ERROR Upload failed error="upload failed" count=127772026/10/29 01:23:02 INFO Uploading batch count=227782026/10/29 01:23:02 ERROR Upload failed error="upload failed" count=227792026/10/29 01:23:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2164418499/002/e2780--- PASS: TestFailedPathPrunedByLaterClosure (0.15s)27812026/10/29 01:23:02 ERROR Drain finished with paths left in queue remaining=127822026/10/29 01:23:02 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2164418499/002/f27832026/10/29 01:23:02 ERROR Accept failed error="too many open files"27842026/10/29 01:23:02 ERROR Drain finished with paths left in queue remaining=102785--- PASS: TestDrainIsolatesPoisonPath (0.16s)27862026/10/29 01:23:02 INFO Uploading batch count=227872026/10/29 01:23:02 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=22788--- PASS: TestDrainGivesUpWhenServerDown (0.17s)27892026/10/29 01:23:02 INFO Uploading batch count=227902026/10/29 01:23:02 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227912026/10/29 01:23:02 INFO Uploading batch count=227922026/10/29 01:23:02 ERROR Upload failed error="upload failed" count=227932026/10/29 01:23:02 INFO Uploading batch count=227942026/10/29 01:23:02 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127952026/10/29 01:23:02 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227962026/10/29 01:23:02 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127972026/10/29 01:23:02 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path1332462348/001/nonexistent27982026/10/29 01:23:02 ERROR Drain finished with paths left in queue remaining=227992026/10/29 01:23:02 INFO Uploading batch count=228002026/10/29 01:23:02 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128012026/10/29 01:23:02 ERROR Upload failed error="upload failed" count=228022026/10/29 01:23:02 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128032026/10/29 01:23:02 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path1332462348/001/nonexistent28042026/10/29 01:23:02 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128052026/10/29 01:23:02 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128062026/10/29 01:23:02 INFO Uploading batch count=228072026/10/29 01:23:02 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path1332462348/001/nonexistent28082026/10/29 01:23:02 ERROR Upload failed error="upload failed" count=228092026/10/29 01:23:02 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128102026/10/29 01:23:02 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128112026/10/29 01:23:02 ERROR Drain finished with paths left in queue remaining=128122026/10/29 01:23:02 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128132026/10/29 01:23:02 ERROR Drain finished with paths left in queue remaining=22814--- PASS: TestWorkerRemoveFailureIsNotProgress (0.01s)2815 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.08s)2816 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.07s)2817 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.08s)28182026/10/29 01:23:02 ERROR Failed to decode request error="read unix /build/hook2610387050/test.sock->@: i/o timeout"28192026/10/29 01:23:02 ERROR Failed to write response error="write unix /build/hook2610387050/test.sock->@: i/o timeout"2820--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)28212026/10/29 01:23:02 ERROR Upload failed error="context canceled" count=228222026/10/29 01:23:02 ERROR Drain finished with paths left in queue remaining=42823--- PASS: TestDrainTimeout (0.31s)28242026/10/29 01:23:02 ERROR Accept failed error="too many open files"28252026/10/29 01:23:02 ERROR Upload failed error="context canceled" count=228262026/10/29 01:23:02 ERROR Drain finished with paths left in queue remaining=228272026/10/29 01:23:02 ERROR Drain finished with paths left in queue remaining=42828--- PASS: TestShutdownFinishesInFlightPush (0.01s)2829 --- PASS: TestShutdownFinishesInFlightPush/completes (0.23s)2830 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.32s)28312026/10/29 01:23:02 ERROR Drain finished with paths left in queue remaining=32832--- PASS: TestDrainTimeoutDuringIsolation (0.01s)2833 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.30s)2834 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.42s)28352026/10/29 01:23:02 ERROR Accept failed error="too many open files"2836--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)2837--- PASS: TestQueueConcurrentWriters (0.97s)28382026/10/29 01:23:03 INFO Uploading batch count=128392026/10/29 01:23:03 INFO Uploading batch count=128402026/10/29 01:23:03 INFO Uploading batch count=128412026/10/29 01:23:03 ERROR Upload failed error="upload failed" count=128422026/10/29 01:23:03 INFO Uploading batch count=128432026/10/29 01:23:03 ERROR Upload failed error="upload failed" count=128442026/10/29 01:23:03 INFO Uploading batch count=128452026/10/29 01:23:03 ERROR Upload failed error="upload failed" count=128462026/10/29 01:23:03 INFO Uploading batch count=128472026/10/29 01:23:03 ERROR Upload failed error="upload failed" count=128482026/10/29 01:23:03 ERROR Drain finished with paths left in queue remaining=12849--- PASS: TestRunNotBlockedByPoisonHead (1.16s)2850--- PASS: TestQueueRemoveLargeClosure (2.62s)2851PASS2852Running signing tests...2853=== RUN TestExternalSigner2854=== PAUSE TestExternalSigner2855=== RUN TestExternalSignerWrongPublicKey2856=== PAUSE TestExternalSignerWrongPublicKey2857=== RUN TestExternalSignerErrors2858=== PAUSE TestExternalSignerErrors2859=== RUN TestExternalSignerRestartsAfterCrash2860=== PAUSE TestExternalSignerRestartsAfterCrash2861=== RUN TestExternalSignerProgramErrorKeepsProcess2862=== PAUSE TestExternalSignerProgramErrorKeepsProcess2863=== RUN TestExternalSignerClose2864=== PAUSE TestExternalSignerClose2865=== RUN TestExternalSignerRejectsInvalidPublicKey2866=== PAUSE TestExternalSignerRejectsInvalidPublicKey2867=== RUN TestExternalSignerCancellation2868=== PAUSE TestExternalSignerCancellation2869=== RUN TestGenerateFingerprint2870=== PAUSE TestGenerateFingerprint2871=== RUN TestParseSigningKey2872=== PAUSE TestParseSigningKey2873=== RUN TestSign2874=== PAUSE TestSign2875=== RUN TestSignBatch2876=== PAUSE TestSignBatch2877=== RUN TestNilKeyPublicKey2878=== PAUSE TestNilKeyPublicKey2879=== RUN TestSignErrors2880=== PAUSE TestSignErrors2881=== CONT TestExternalSignerClose2882=== CONT TestExternalSignerRestartsAfterCrash2883=== CONT TestGenerateFingerprint2884=== CONT TestExternalSignerRejectsInvalidPublicKey2885=== CONT TestNilKeyPublicKey2886=== RUN TestExternalSignerRejectsInvalidPublicKey/#002887=== CONT TestExternalSignerCancellation2888=== CONT TestSignBatch2889=== CONT TestExternalSignerWrongPublicKey2890=== CONT TestExternalSigner2891=== CONT TestExternalSignerErrors2892=== CONT TestSign2893=== CONT TestExternalSignerProgramErrorKeepsProcess2894=== CONT TestParseSigningKey2895=== CONT TestSignErrors2896=== RUN TestGenerateFingerprint/basic_with_references2897=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002898--- PASS: TestNilKeyPublicKey (0.00s)2899=== RUN TestExternalSignerErrors/null2900=== RUN TestParseSigningKey/valid_32-byte_key2901=== PAUSE TestGenerateFingerprint/basic_with_references2902=== RUN TestGenerateFingerprint/no_references2903=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2904=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2905=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2906=== PAUSE TestGenerateFingerprint/no_references2907=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2908=== PAUSE TestExternalSignerErrors/null2909=== RUN TestExternalSignerErrors/wrong_id2910=== PAUSE TestExternalSignerErrors/wrong_id2911=== RUN TestExternalSignerErrors/missing_signatures2912=== PAUSE TestParseSigningKey/valid_32-byte_key2913=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2914=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2915=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2916=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2917=== PAUSE TestExternalSignerErrors/missing_signatures2918=== RUN TestParseSigningKey/no_colon2919=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2920=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2921=== RUN TestSignErrors/nil_key2922=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2923=== RUN TestExternalSignerErrors/null_signatures2924--- PASS: TestSign (0.01s)2925=== PAUSE TestParseSigningKey/no_colon2926=== PAUSE TestExternalSignerErrors/null_signatures2927=== RUN TestExternalSignerErrors/unrequested_key2928=== RUN TestParseSigningKey/empty_name2929=== PAUSE TestSignErrors/nil_key2930=== RUN TestGenerateFingerprint/invalid_nar_hash_length2931=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2932=== PAUSE TestParseSigningKey/empty_name2933=== RUN TestSignErrors/nil_narinfo2934=== PAUSE TestExternalSignerErrors/unrequested_key2935=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2936--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.01s)2937--- PASS: TestExternalSignerClose (0.01s)2938=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2939=== RUN TestParseSigningKey/invalid_base642940=== PAUSE TestSignErrors/nil_narinfo2941=== RUN TestExternalSignerErrors/wrong_signature_name2942=== RUN TestGenerateFingerprint/invalid_store_path_prefix2943--- PASS: TestExternalSignerWrongPublicKey (0.01s)2944=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2945=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2946=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2947=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2948=== PAUSE TestExternalSignerErrors/wrong_signature_name2949=== RUN TestSignErrors/invalid_narinfo2950=== RUN TestExternalSignerErrors/wrong_signature_length2951=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2952--- PASS: TestSignBatch (0.02s)2953=== PAUSE TestParseSigningKey/invalid_base642954=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2955=== CONT TestExternalSignerRejectsInvalidPublicKey/#002956=== PAUSE TestSignErrors/invalid_narinfo2957=== RUN TestParseSigningKey/wrong_length2958=== PAUSE TestExternalSignerErrors/wrong_signature_length2959=== RUN TestGenerateFingerprint/invalid_reference_prefix2960=== RUN TestSignErrors/canceled2961=== PAUSE TestParseSigningKey/wrong_length2962--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.02s)2963 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2964 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2965 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2966 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2967 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2968=== RUN TestExternalSignerErrors/program_error2969=== CONT TestParseSigningKey/empty_name2970=== PAUSE TestSignErrors/canceled2971=== CONT TestParseSigningKey/valid_32-byte_key2972=== CONT TestParseSigningKey/no_colon2973=== CONT TestParseSigningKey/wrong_length2974=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2975=== CONT TestParseSigningKey/invalid_base642976--- PASS: TestExternalSignerRestartsAfterCrash (0.02s)2977=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2978=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2979=== CONT TestGenerateFingerprint/basic_with_references2980=== CONT TestGenerateFingerprint/invalid_nar_hash_length2981=== CONT TestSignErrors/nil_narinfo2982=== CONT TestSignErrors/nil_key2983=== CONT TestSignErrors/canceled2984=== CONT TestSignErrors/invalid_narinfo2985=== PAUSE TestExternalSignerErrors/program_error2986=== CONT TestGenerateFingerprint/no_references2987=== CONT TestGenerateFingerprint/invalid_store_path_prefix2988=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2989=== CONT TestGenerateFingerprint/invalid_reference_prefix2990--- PASS: TestParseSigningKey (0.02s)2991 --- PASS: TestParseSigningKey/empty_name (0.00s)2992 --- PASS: TestParseSigningKey/no_colon (0.00s)2993 --- PASS: TestParseSigningKey/wrong_length (0.00s)2994 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2995 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2996 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2997=== RUN TestExternalSignerErrors/exit_at_startup2998--- PASS: TestExternalSigner (0.02s)2999=== PAUSE TestExternalSignerErrors/exit_at_startup3000--- PASS: TestSignErrors (0.02s)3001 --- PASS: TestSignErrors/nil_narinfo (0.00s)3002 --- PASS: TestSignErrors/nil_key (0.00s)3003 --- PASS: TestSignErrors/canceled (0.00s)3004 --- PASS: TestSignErrors/invalid_narinfo (0.00s)3005=== RUN TestExternalSignerErrors/wrong_shape3006--- PASS: TestGenerateFingerprint (0.02s)3007 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)3008 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)3009 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)3010 --- PASS: TestGenerateFingerprint/no_references (0.00s)3011 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)3012 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)3013 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)3014=== PAUSE TestExternalSignerErrors/wrong_shape3015=== RUN TestExternalSignerErrors/missing_signature_name3016=== PAUSE TestExternalSignerErrors/missing_signature_name3017=== RUN TestExternalSignerErrors/invalid_signature_base643018=== PAUSE TestExternalSignerErrors/invalid_signature_base643019=== RUN TestExternalSignerErrors/exit_on_request3020=== PAUSE TestExternalSignerErrors/exit_on_request3021=== RUN TestExternalSignerErrors/invalid_JSON3022=== PAUSE TestExternalSignerErrors/invalid_JSON3023=== RUN TestExternalSignerErrors/wrong_signatures_shape3024=== PAUSE TestExternalSignerErrors/wrong_signatures_shape3025=== RUN TestExternalSignerErrors/too_few_signatures3026=== PAUSE TestExternalSignerErrors/too_few_signatures3027=== CONT TestExternalSignerErrors/wrong_id3028=== CONT TestExternalSignerErrors/unrequested_key3029=== CONT TestExternalSignerErrors/wrong_signatures_shape3030=== CONT TestExternalSignerErrors/invalid_JSON3031=== CONT TestExternalSignerErrors/too_few_signatures3032=== CONT TestExternalSignerErrors/invalid_signature_base643033=== CONT TestExternalSignerErrors/exit_on_request3034=== CONT TestExternalSignerErrors/missing_signature_name3035=== CONT TestExternalSignerErrors/wrong_shape3036=== CONT TestExternalSignerErrors/wrong_signature_length3037=== CONT TestExternalSignerErrors/exit_at_startup3038=== CONT TestExternalSignerErrors/null_signatures3039=== CONT TestExternalSignerErrors/program_error3040=== CONT TestExternalSignerErrors/null3041=== CONT TestExternalSignerErrors/missing_signatures3042--- PASS: TestExternalSignerCancellation (0.03s)3043=== CONT TestExternalSignerErrors/wrong_signature_name3044--- PASS: TestExternalSignerErrors (0.03s)3045 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)3046 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)3047 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)3048 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)3049 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)3050 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)3051 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.01s)3052 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)3053 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)3054 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)3055 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)3056 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)3057 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)3058 --- PASS: TestExternalSignerErrors/wrong_shape (0.01s)3059 --- PASS: TestExternalSignerErrors/null (0.01s)3060 --- PASS: TestExternalSignerErrors/program_error (0.01s)3061PASS3062Running OpenBao signer tests...3063=== RUN TestSign3064=== PAUSE TestSign3065=== RUN TestSignErrors3066=== PAUSE TestSignErrors3067=== RUN TestServe3068=== PAUSE TestServe3069=== RUN TestServeRejectsGarbage3070=== PAUSE TestServeRejectsGarbage3071=== CONT TestSign3072=== CONT TestSignErrors3073=== CONT TestServe3074=== CONT TestServeRejectsGarbage3075=== RUN TestSignErrors/no_prefix3076=== PAUSE TestSignErrors/no_prefix3077=== RUN TestSignErrors/invalid_base643078=== PAUSE TestSignErrors/invalid_base643079=== RUN TestSignErrors/http_error3080=== PAUSE TestSignErrors/http_error3081=== RUN TestSignErrors/invalid_json3082--- PASS: TestServeRejectsGarbage (0.00s)3083=== PAUSE TestSignErrors/invalid_json3084=== CONT TestSignErrors/no_prefix3085=== CONT TestSignErrors/http_error3086--- PASS: TestServe (0.00s)3087=== CONT TestSignErrors/invalid_base643088=== CONT TestSignErrors/invalid_json3089--- PASS: TestSign (0.01s)3090--- PASS: TestSignErrors (0.00s)3091 --- PASS: TestSignErrors/no_prefix (0.01s)3092 --- PASS: TestSignErrors/invalid_base64 (0.01s)3093 --- PASS: TestSignErrors/http_error (0.01s)3094 --- PASS: TestSignErrors/invalid_json (0.01s)3095PASS3096Running niks3-hook command tests...3097=== RUN TestServeSecondSignalEndsDrain3098=== PAUSE TestServeSecondSignalEndsDrain3099=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown3100=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown3101=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown3102=== CONT TestServeSecondSignalEndsDrain3103--- PASS: TestServeSecondSignalEndsDrain (0.11s)31042026/10/29 01:23:08 INFO Upload queue status pending=131052026/10/29 01:23:08 INFO Uploading batch count=13106--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.14s)3107PASS3108Running rate limiter tests...3109=== RUN TestAdaptiveRateLimiter_ThreadSafety3110=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3111=== CONT TestAdaptiveRateLimiter_ThreadSafety31122026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=7031132026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=4931142026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=34.331152026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=24.00999999999999831162026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=16.80731172026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=11.76489999999999931182026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=8.2354331192026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=5.76480099999999931202026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531212026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531222026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531232026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531242026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531252026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531262026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531272026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531282026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531292026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531302026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531312026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531322026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531332026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531342026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531352026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531362026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531372026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531382026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531392026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531402026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531412026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531422026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531432026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531442026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531452026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531462026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531472026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531482026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531492026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531502026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=5.63678500000000131512026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531522026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531532026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531542026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531552026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531562026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531572026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531582026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531592026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531602026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531612026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531622026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531632026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531642026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531652026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531662026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531672026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531682026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531692026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531702026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531712026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531722026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531732026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531742026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531752026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531762026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531772026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531782026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531792026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531802026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531812026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531822026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531832026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531842026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531852026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531862026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531872026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531882026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531892026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531902026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531912026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531922026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531932026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531942026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531952026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531962026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531972026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531982026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=531992026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=532002026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=532012026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=532022026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=532032026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=532042026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=532052026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=532062026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=5.12435000000000132072026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=5.25179258450000232082026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=532092026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=532102026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=532112026/10/29 01:23:09 WARN Rate limiter backed off name=test rate=53212--- PASS: TestAdaptiveRateLimiter_ThreadSafety (2.31s)3213PASS