niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #431
· 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.03s)31=== RUN TestDumpPathCaseHackCollision32--- PASS: TestDumpPathCaseHackCollision (0.00s)33=== RUN TestSupersededNARStillUploadsListing34=== PAUSE TestSupersededNARStillUploadsListing35=== RUN TestTruncatedNARDumpIsNotCompleted36=== PAUSE TestTruncatedNARDumpIsNotCompleted37=== RUN TestDumpPathMatchesNix38=== PAUSE TestDumpPathMatchesNix39=== RUN TestDumpPathSingleFile40=== PAUSE TestDumpPathSingleFile41=== RUN TestDumpPathWriterError42=== PAUSE TestDumpPathWriterError43=== RUN TestDumpPathWriterErrorStopsReading44 nar_test.go:289: read 114 of 32768000 bytes45--- PASS: TestDumpPathWriterErrorStopsReading (0.57s)46=== RUN TestEncodeNixBase3247=== PAUSE TestEncodeNixBase3248=== RUN TestEncodeNixBase32WithRealHash49=== PAUSE TestEncodeNixBase32WithRealHash50=== RUN TestConvertHashToNix3251=== PAUSE TestConvertHashToNix3252=== RUN TestGetStorePathHash53=== PAUSE TestGetStorePathHash54=== RUN TestPathInfoHashCompatibility55=== PAUSE TestPathInfoHashCompatibility56=== RUN TestParsePathInfoJSON57=== PAUSE TestParsePathInfoJSON58=== RUN TestParsePathInfoJSONMultiplePaths59=== PAUSE TestParsePathInfoJSONMultiplePaths60=== RUN TestPathInfoCACompatibility61=== PAUSE TestPathInfoCACompatibility62=== RUN TestUploadPendingObjectsStopsStartingAfterFailure63--- PASS: TestUploadPendingObjectsStopsStartingAfterFailure (0.02s)64=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent65=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent66=== RUN TestCompletePendingClosure_NotFoundWithoutKey67=== PAUSE TestCompletePendingClosure_NotFoundWithoutKey68=== RUN TestRateLimiterFeedback69=== PAUSE TestRateLimiterFeedback70=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess71=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess72=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer73=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer74=== RUN TestResolveStorePath75=== PAUSE TestResolveStorePath76=== RUN TestDoWithRetry_BodyReplayedViaGetBody77=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody78=== RUN TestRetryTimeoutOutlastsMaxRetries79=== PAUSE TestRetryTimeoutOutlastsMaxRetries80=== RUN TestDoWithRetry_FinalResponseBodyReadable81=== PAUSE TestDoWithRetry_FinalResponseBodyReadable82=== RUN TestShellSplit83=== PAUSE TestShellSplit84=== RUN TestShellSplitErrors85=== PAUSE TestShellSplitErrors86=== RUN TestStreamPushReportsEveryPath87=== PAUSE TestStreamPushReportsEveryPath88=== RUN TestStreamPushBatchesUnderLoad89=== PAUSE TestStreamPushBatchesUnderLoad90=== RUN TestStreamPushIsolatesFailures91=== PAUSE TestStreamPushIsolatesFailures92=== RUN TestStreamPushGivesUpOnDeadServer93=== PAUSE TestStreamPushGivesUpOnDeadServer94=== RUN TestStreamPushRequestLine95=== PAUSE TestStreamPushRequestLine96=== RUN TestStreamPushReportsSignatures97=== PAUSE TestStreamPushReportsSignatures98=== RUN TestStreamPushReportsSkippedPaths99=== PAUSE TestStreamPushReportsSkippedPaths100=== RUN TestClientSignaturesByStorePath101=== PAUSE TestClientSignaturesByStorePath102=== RUN TestStreamPushStopsWhenCanceled103=== PAUSE TestStreamPushStopsWhenCanceled104=== RUN TestStreamPushStopsOnCancel105=== PAUSE TestStreamPushStopsOnCancel106=== RUN TestSetClientTLS107=== PAUSE TestSetClientTLS108=== RUN TestSetClientTLSDoesNotMutateDefaultTransport109=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport110=== RUN TestSetClientTLSErrors111=== PAUSE TestSetClientTLSErrors112=== RUN TestStaticToken113=== PAUSE TestStaticToken114=== RUN TestFileTokenReadsAndCaches115=== PAUSE TestFileTokenReadsAndCaches116=== RUN TestFileTokenMissing117=== PAUSE TestFileTokenMissing118=== RUN TestFileTokenEmpty119=== PAUSE TestFileTokenEmpty120=== RUN TestScriptTokenNoExpiryRerunsEveryCall121=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall122=== RUN TestScriptTokenCachesUntilRefresh123=== PAUSE TestScriptTokenCachesUntilRefresh124=== RUN TestScriptTokenEmptyToken125=== PAUSE TestScriptTokenEmptyToken126=== RUN TestScriptTokenBadJSON127=== PAUSE TestScriptTokenBadJSON128=== RUN TestScriptTokenScriptFails129=== PAUSE TestScriptTokenScriptFails130=== RUN TestScriptTokenEmptyCommand131=== PAUSE TestScriptTokenEmptyCommand132=== RUN TestScriptTokenDoesNotWaitForItsChildren133=== PAUSE TestScriptTokenDoesNotWaitForItsChildren134=== CONT TestRegisterUploadedObjectReusesConnections135=== CONT TestStreamPushGivesUpOnDeadServer136=== CONT TestDoWithRetry_FinalResponseBodyReadable137=== CONT TestStreamPushStopsOnCancel138=== CONT TestStreamPushStopsWhenCanceled139=== CONT TestSetClientTLS140--- PASS: TestStreamPushStopsWhenCanceled (0.00s)141=== CONT TestStreamPushReportsEveryPath142=== CONT TestFileTokenEmpty143=== CONT TestScriptTokenDoesNotWaitForItsChildren144=== CONT TestClientSignaturesByStorePath145=== CONT TestScriptTokenScriptFails146=== CONT TestStreamPushReportsSignatures147=== CONT TestScriptTokenEmptyCommand148=== CONT TestScriptTokenEmptyToken149=== CONT TestStreamPushBatchesUnderLoad150=== CONT TestScriptTokenCachesUntilRefresh151=== CONT TestStreamPushRequestLine152=== CONT TestScriptTokenNoExpiryRerunsEveryCall153=== CONT TestScriptTokenBadJSON154=== CONT TestStreamPushIsolatesFailures155=== CONT TestFileTokenMissing156=== CONT TestShellSplit157=== CONT TestFileTokenReadsAndCaches158=== CONT TestShellSplitErrors159=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry160=== CONT TestStaticToken161=== RUN TestStreamPushStopsOnCancel/waiting_for_input162--- PASS: TestClientSignaturesByStorePath (0.00s)163=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs164=== CONT TestParsePathInfoJSON165=== CONT TestStreamPushReportsSkippedPaths166=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs167=== CONT TestRetryTimeoutOutlastsMaxRetries168=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input169=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot170=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot171=== CONT TestDumpPathWriterError172=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout173=== CONT TestDoWithRetry_BodyReplayedViaGetBody174=== CONT TestSetClientTLSDoesNotMutateDefaultTransport175=== CONT TestDumpPathMatchesNix176=== RUN TestStreamPushBatchesUnderLoad/together177=== CONT TestSetClientTLSErrors178=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica179=== CONT TestRateLimiterFeedback180=== CONT TestPartSizeForNAR181=== CONT TestTruncatedNARDumpIsNotCompleted182--- PASS: TestStreamPushIsolatesFailures (0.01s)183=== CONT TestResolveStorePath184=== CONT TestParsePathInfoJSONMultiplePaths185=== RUN TestParsePathInfoJSON/Nix_format186=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot187=== CONT TestGetStorePathHash188=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths189--- PASS: TestScriptTokenEmptyCommand (0.00s)190=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout191=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess192=== PAUSE TestStreamPushBatchesUnderLoad/together193=== RUN TestRateLimiterFeedback/429_enables_limiter194=== RUN TestPartSizeForNAR/zero_stays_at_minimum195=== RUN TestGetStorePathHash/valid_store_path196=== CONT TestEncodeNixBase32WithRealHash197=== PAUSE TestParsePathInfoJSON/Nix_format198--- PASS: TestFileTokenEmpty (0.01s)199=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer200=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths201=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot202=== CONT TestEncodeNixBase32203=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time204=== RUN TestSetClientTLS/rejects_connection_without_client_cert205=== RUN TestSetClientTLSErrors/missing_cert_file206=== PAUSE TestGetStorePathHash/valid_store_path207=== PAUSE TestSetClientTLSErrors/missing_cert_file208=== RUN TestGetStorePathHash/basename_without_hyphen_should_error209=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum210=== RUN TestParsePathInfoJSON/Lix_format211--- PASS: TestScriptTokenScriptFails (0.00s)212=== CONT TestUploadMultipart_SupersededByPeer213=== RUN TestUploadMultipart_SupersededByPeer/exists214=== PAUSE TestParsePathInfoJSON/Lix_format215=== RUN TestParsePathInfoJSON/empty_input216--- PASS: TestStreamPushReportsEveryPath (0.01s)217--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)218=== PAUSE TestUploadMultipart_SupersededByPeer/exists219=== RUN TestUploadMultipart_SupersededByPeer/missing220--- PASS: TestScriptTokenEmptyToken (0.01s)221=== PAUSE TestUploadMultipart_SupersededByPeer/missing222=== PAUSE TestParsePathInfoJSON/empty_input223=== RUN TestEncodeNixBase32/test_string_hash224=== PAUSE TestEncodeNixBase32/test_string_hash225=== CONT TestUploadMultipart_FailedPartBufferNotReused226=== RUN TestParsePathInfoJSON/whitespace_only227=== PAUSE TestParsePathInfoJSON/whitespace_only228=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert229=== RUN TestParsePathInfoJSON/invalid_JSON230=== PAUSE TestRateLimiterFeedback/429_enables_limiter231=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA232=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time233=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot234=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA235=== RUN TestSetClientTLS/preserves_debug_logging_transport236=== RUN TestSetClientTLSErrors/missing_key_file237=== PAUSE TestSetClientTLS/preserves_debug_logging_transport238=== PAUSE TestSetClientTLSErrors/missing_key_file239=== RUN TestSetClientTLSErrors/missing_ca_file240=== RUN TestPartSizeForNAR/small_stays_at_minimum241=== PAUSE TestSetClientTLSErrors/missing_ca_file242=== RUN TestSetClientTLSErrors/invalid_ca_file243=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths244=== PAUSE TestPartSizeForNAR/small_stays_at_minimum245=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths246=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum247=== RUN TestEncodeNixBase32/empty_input248=== RUN TestRateLimiterFeedback/503_enables_limiter249=== PAUSE TestParsePathInfoJSON/invalid_JSON250=== CONT TestConvertHashToNix32251--- PASS: TestShellSplit (0.00s)252=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure253--- PASS: TestShellSplitErrors (0.00s)254=== CONT TestCaseHackSuffix255=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot256=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error257=== CONT TestSupersededNARStillUploadsListing258=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error259=== RUN TestSupersededNARStillUploadsListing/small_NAR260=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error261=== PAUSE TestSupersededNARStillUploadsListing/small_NAR262=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum263=== RUN TestSupersededNARStillUploadsListing/dump_cut_short264=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts265=== CONT TestUploadMultipart_ProducerErrorIsNotEOF266=== PAUSE TestRateLimiterFeedback/503_enables_limiter267=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part268=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part269=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary270=== PAUSE TestEncodeNixBase32/empty_input271=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun272=== RUN TestConvertHashToNix32/SRI_format_to_Nix32273=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary274--- PASS: TestStaticToken (0.00s)275--- PASS: TestFileTokenMissing (0.00s)276=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot277=== PAUSE TestSetClientTLSErrors/invalid_ca_file278=== CONT TestCompletePendingClosure_NotFoundWithoutKey279=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error280=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short281=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts282=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter283=== CONT TestPathInfoCACompatibility284=== RUN TestPartSizeForNAR/1_TiB285=== RUN TestPathInfoCACompatibility/null_ca_field286=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter287=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32288=== CONT TestDoServerRequestAttachesToken289=== PAUSE TestPartSizeForNAR/1_TiB290=== RUN TestPartSizeForNAR/5_TiB_S3_max_object291=== CONT TestUploadMultipart_PartsInParallel292--- PASS: TestStreamPushReportsSignatures (0.02s)293=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot294=== CONT TestFilterOversizedClosures295=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken296=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken297=== RUN TestFilterOversizedClosures/no_limit_keeps_everything298=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails299=== PAUSE TestPathInfoCACompatibility/null_ca_field300=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter301=== RUN TestConvertHashToNix32/already_Nix32_format302=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object303--- PASS: TestScriptTokenBadJSON (0.01s)304--- PASS: TestFileTokenReadsAndCaches (0.00s)305=== RUN TestPartSizeForNAR/capped_at_5_GiB306=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything307=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent308=== PAUSE TestPartSizeForNAR/capped_at_5_GiB309=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails310=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter311=== RUN TestPathInfoCACompatibility/old_string_format_-_text312=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs313=== CONT TestUploadMultipart_SupersededByPeer/exists314=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout315=== CONT TestStreamPushBatchesUnderLoad/together316=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error317--- PASS: TestStreamPushReportsSkippedPaths (0.01s)318--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.03s)319=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time320=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped321=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier322=== CONT TestPathInfoHashCompatibility323=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text324=== CONT TestDumpPathSingleFile325=== PAUSE TestConvertHashToNix32/already_Nix32_format326=== CONT TestUploadMultipart_SupersededByPeer/missing327--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)328=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)329=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier330=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped331=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive332=== RUN TestConvertHashToNix32/invalid_format333=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive334=== RUN TestPathInfoCACompatibility/new_structured_format_-_text335=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text336--- PASS: TestEncodeNixBase32WithRealHash (0.00s)337=== PAUSE TestConvertHashToNix32/invalid_format338=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method339=== CONT TestSetClientTLS/rejects_connection_without_client_cert340=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method341=== CONT TestSetClientTLS/preserves_debug_logging_transport342=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths343=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths344=== CONT TestParsePathInfoJSON/Lix_format345=== CONT TestParsePathInfoJSON/whitespace_only346=== CONT TestParsePathInfoJSON/Nix_format347=== CONT TestParsePathInfoJSON/empty_input348=== RUN TestFilterOversizedClosures/all_closures_skipped349--- PASS: TestResolveStorePath (0.00s)350=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA351=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)352=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up353=== CONT TestParsePathInfoJSON/invalid_JSON354=== CONT TestEncodeNixBase32/test_string_hash355=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary356=== CONT TestEncodeNixBase32/empty_input357=== CONT TestSetClientTLSErrors/missing_cert_file358--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)359=== CONT TestSetClientTLSErrors/invalid_ca_file360--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)361=== PAUSE TestFilterOversizedClosures/all_closures_skipped362=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon363=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up364=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part365=== CONT TestSetClientTLSErrors/missing_ca_file366=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier367=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier368=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client369=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client370=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client371=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client372=== CONT TestStreamPushStopsOnCancel/waiting_for_input373--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.12s)374=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon375=== CONT TestSetClientTLSErrors/missing_key_file376=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI377=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI378=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512379=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512380=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot381=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot382=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken383--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.13s)384--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)385--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.01s)386--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.14s)387--- PASS: TestDoServerRequestAttachesToken (0.01s)388--- PASS: TestStreamPushBatchesUnderLoad (0.14s)389 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)390 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)391--- PASS: TestParsePathInfoJSONMultiplePaths (0.12s)392 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)393 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)394--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)395 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)396 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)397--- PASS: TestParsePathInfoJSON (0.13s)398 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)399 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)400 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)401 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)402 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)403--- PASS: TestEncodeNixBase32 (0.00s)404 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)405 --- PASS: TestEncodeNixBase32/empty_input (0.00s)406--- PASS: TestSetClientTLSErrors (0.13s)407 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)408 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)409 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)410 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)411--- PASS: TestCaseHackSuffix (0.03s)412=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot413=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot414=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts415=== CONT TestPartSizeForNAR/1_TiB416=== CONT TestPartSizeForNAR/capped_at_5_GiB417=== CONT TestPartSizeForNAR/5_TiB_S3_max_object418=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum419=== CONT TestPartSizeForNAR/small_stays_at_minimum420=== CONT TestPartSizeForNAR/zero_stays_at_minimum421=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter422--- PASS: TestPartSizeForNAR (0.14s)423 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)424 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)425 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)426 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)427 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)428 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)429 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)430=== CONT TestRateLimiterFeedback/503_enables_limiter431=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter432--- PASS: TestDumpPathSingleFile (0.03s)433=== CONT TestSupersededNARStillUploadsListing/dump_cut_short434=== CONT TestRateLimiterFeedback/429_enables_limiter435--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.26s)436=== CONT TestGetStorePathHash/valid_store_path437=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error438=== CONT TestGetStorePathHash/basename_without_hyphen_should_error439=== CONT TestConvertHashToNix32/SRI_format_to_Nix32440=== CONT TestConvertHashToNix32/invalid_format441=== CONT TestConvertHashToNix32/already_Nix32_format442=== CONT TestPathInfoCACompatibility/old_string_format_-_text443--- PASS: TestConvertHashToNix32 (0.02s)444 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)445 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)446 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)447=== CONT TestPathInfoCACompatibility/new_structured_format_-_text448=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method449=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive450=== CONT TestPathInfoCACompatibility/null_ca_field451=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped452=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails453=== CONT TestFilterOversizedClosures/no_limit_keeps_everything454=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier455=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error456=== CONT TestSupersededNARStillUploadsListing/small_NAR457--- PASS: TestPathInfoCACompatibility (0.02s)458 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)459 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)460 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)461 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)462 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)463=== CONT TestFilterOversizedClosures/all_closures_skipped464=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client465--- PASS: TestGetStorePathHash (0.14s)466 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)467 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)468 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)469 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)470--- PASS: TestFilterOversizedClosures (0.02s)471 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)472 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)473 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)474=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client475=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier476--- PASS: TestRateLimiterFeedback (0.14s)477 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)478 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)479 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)480 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.28s)481=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up482--- PASS: TestStreamPushStopsOnCancel (0.16s)483 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.11s)484 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.11s)485 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.11s)486 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.30s)487 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.29s)488 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.29s)489=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)490=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI491=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512492=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon493--- PASS: TestPathInfoHashCompatibility (0.01s)494 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)495 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)496 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)497 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)498--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.33s)499--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.01s)500 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.00s)501 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.00s)502 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.00s)503 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.00s)504 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.01s)505--- PASS: TestDumpPathWriterError (0.48s)506--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.00s)507 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.33s)508 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.35s)509--- PASS: TestSetClientTLS (0.15s)510 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)511 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)512 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.38s)513--- PASS: TestRegisterUploadedObjectReusesConnections (0.60s)514--- PASS: TestStreamPushRequestLine (0.62s)515--- PASS: TestDumpPathMatchesNix (0.61s)516--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)517--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)518--- PASS: TestTruncatedNARDumpIsNotCompleted (1.19s)519--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.13s)520--- PASS: TestUploadMultipart_PartsInParallel (1.19s)521--- PASS: TestSupersededNARStillUploadsListing (0.01s)522 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.04s)523 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.04s)524 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.21s)525--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.03s)526 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.01s)527 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.31s)528PASS529Running server tests...530The files belonging to this database system will be owned by user "nixbld".531This user must also own the server process.532533The database cluster will be initialized with locale "C".534The default database encoding has accordingly been set to "SQL_ASCII".535The default text search configuration will be set to "english".536537Data page checksums are enabled.538539creating directory /build/postgres3970139751/data ... ok540creating subdirectories ... ok541selecting dynamic shared memory implementation ... posix542selecting default "max_connections" ... 100543selecting default "shared_buffers" ... 128MB544selecting default time zone ... UTC545creating configuration files ... ok546running bootstrap script ... ok547performing post-bootstrap initialization ... ok548syncing data to disk ... ok549550initdb: warning: enabling "trust" authentication for local connections551initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.552553Success. You can now start the database server using:554555 pg_ctl -D /build/postgres3970139751/data -l logfile start556557/build/postgres3970139751:5432 - no response5582026-10-25 17:20:43.529 UTC [173] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit5592026-10-25 17:20:43.530 UTC [173] LOG: listening on Unix socket "/build/postgres3970139751/.s.PGSQL.5432"5602026-10-25 17:20:43.534 UTC [180] LOG: database system was shut down at 2026-10-25 17:20:43 UTC5612026-10-25 17:20:43.537 UTC [173] LOG: database system is ready to accept connections562/build/postgres3970139751:5432 - accepting connections563=== RUN TestService_AuthMiddleware564=== PAUSE TestService_AuthMiddleware565=== RUN TestService_AuthMiddleware_MTLSProxyHeader566=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader567=== RUN TestService_AuthMiddleware_MTLSBoundSubjects568=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects569=== RUN TestService_ReadAuthMiddleware570=== PAUSE TestService_ReadAuthMiddleware571=== RUN TestService_AuthMiddleware_OIDC572=== PAUSE TestService_AuthMiddleware_OIDC573=== RUN TestService_RequireScope_OIDC574=== PAUSE TestService_RequireScope_OIDC575=== RUN TestService_ReadScope_PublicByDefault576=== PAUSE TestService_ReadScope_PublicByDefault577=== RUN TestCacheConfigHandler578=== PAUSE TestCacheConfigHandler579=== RUN TestCacheStatsHandler580=== PAUSE TestCacheStatsHandler581=== RUN TestClientCADerivations582=== PAUSE TestClientCADerivations583=== RUN TestClientErrorHandling584=== PAUSE TestClientErrorHandling585=== RUN TestClientIntegration586=== PAUSE TestClientIntegration587=== RUN TestClientMultipleUploads588=== PAUSE TestClientMultipleUploads589=== RUN TestClientWithDependencies590=== PAUSE TestClientWithDependencies591=== RUN TestClientSharedPathCommittedMidPush592=== PAUSE TestClientSharedPathCommittedMidPush593=== RUN TestPinProtectsFromGC594=== PAUSE TestPinProtectsFromGC595=== RUN TestClientPushesUseOnePush596=== PAUSE TestClientPushesUseOnePush597=== RUN TestClientFallsBackToClosures598=== PAUSE TestClientFallsBackToClosures599=== RUN TestDeleteClosuresRacingPins600=== PAUSE TestDeleteClosuresRacingPins601=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock602=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock603=== RUN TestResolveDBConnectionString604=== PAUSE TestResolveDBConnectionString605=== RUN TestConnectWaitsForAPeerMigration606=== PAUSE TestConnectWaitsForAPeerMigration607=== RUN TestConnectSerialisesConcurrentMigrations608=== PAUSE TestConnectSerialisesConcurrentMigrations609=== RUN TestLeadElectsOneAndHandsOver610=== PAUSE TestLeadElectsOneAndHandsOver611=== RUN TestLeadIncumbentWinsAfterRestart6122026/10/25 17:20:44 INFO lead: acquired remote=192.0.2.1:12346132026/10/25 17:20:44 INFO lead: released remote=192.0.2.1:12346142026/10/25 17:20:44 INFO lead: acquired remote=192.0.2.1:12346152026/10/25 17:20:45 INFO lead: released remote=192.0.2.1:1234616--- PASS: TestLeadIncumbentWinsAfterRestart (1.85s)617=== RUN TestLeadIncumbentAnnouncesAtOnce618=== PAUSE TestLeadIncumbentAnnouncesAtOnce619=== RUN TestLeadEndsOnShutdown620=== PAUSE TestLeadEndsOnShutdown621=== RUN TestLeadEndsWhenItsConnectionHangs6222026/10/25 17:20:46 INFO lead: acquired remote=192.0.2.1:12346232026-10-25 17:20:47.428 UTC [366] FATAL: terminating connection due to administrator command6242026/10/25 17:20:47 INFO lead: acquired remote=192.0.2.1:12346252026/10/25 17:20:48 WARN lead: lock connection lost error="timeout: context deadline exceeded"6262026/10/25 17:20:48 INFO lead: released remote=192.0.2.1:12346272026/10/25 17:20:48 INFO lead: released remote=192.0.2.1:1234628--- PASS: TestLeadEndsWhenItsConnectionHangs (2.95s)629=== RUN TestGCAdvisoryLockBlocksConcurrentRun630=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun631=== RUN TestGCBugBareHashReferences632=== PAUSE TestGCBugBareHashReferences633=== RUN TestGCMetrics634=== PAUSE TestGCMetrics635=== RUN TestPushDedupSurvivesConcurrentGC636=== PAUSE TestPushDedupSurvivesConcurrentGC637=== RUN TestDeduplicatedObjectsRecordedAsPending638=== PAUSE TestDeduplicatedObjectsRecordedAsPending639=== RUN TestGCSweepSkipsPendingObjects640=== PAUSE TestGCSweepSkipsPendingObjects641=== RUN TestTombstonedObjectOfferedWithoutWaiting642=== PAUSE TestTombstonedObjectOfferedWithoutWaiting643=== RUN TestGCSweepDeliversEachKeyOnce644=== PAUSE TestGCSweepDeliversEachKeyOnce645=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection646=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection647=== RUN TestForceGCDuringPushOffersSweptObject648=== PAUSE TestForceGCDuringPushOffersSweptObject649=== RUN TestFailedS3DeleteKeepsTombstone650=== PAUSE TestFailedS3DeleteKeepsTombstone651=== RUN TestSweepSkipsRowsLockedByPush652=== PAUSE TestSweepSkipsRowsLockedByPush653=== RUN TestRegisterCompletedObjectNeedsPendingRow654=== PAUSE TestRegisterCompletedObjectNeedsPendingRow655=== RUN TestGetExistingObjectsLocksRows656=== PAUSE TestGetExistingObjectsLocksRows657=== RUN TestSweepRechecksPendingAfterLocking658=== PAUSE TestSweepRechecksPendingAfterLocking659=== RUN TestPushWaitsForSweepHoldingRow660=== PAUSE TestPushWaitsForSweepHoldingRow661=== RUN TestCommitRacingPendingCleanupKeepsObjects662=== PAUSE TestCommitRacingPendingCleanupKeepsObjects663=== RUN TestGCEndsOnShutdown664=== PAUSE TestGCEndsOnShutdown665=== RUN TestGCTaskStore_StartNew666=== PAUSE TestGCTaskStore_StartNew667=== RUN TestGCTaskStore_DeduplicateSameParams668=== PAUSE TestGCTaskStore_DeduplicateSameParams669=== RUN TestGCTaskStore_ConflictDifferentParams670=== PAUSE TestGCTaskStore_ConflictDifferentParams671=== RUN TestGCTaskStore_GetEmpty672=== PAUSE TestGCTaskStore_GetEmpty673=== RUN TestGCTaskStore_GetReturnsLatest674=== PAUSE TestGCTaskStore_GetReturnsLatest675=== RUN TestGCTaskStore_CompletedAllowsNewTask676=== PAUSE TestGCTaskStore_CompletedAllowsNewTask677=== RUN TestGCTaskStore_PhaseUpdates678=== PAUSE TestGCTaskStore_PhaseUpdates679=== RUN TestGCTaskStore_Fail680=== PAUSE TestGCTaskStore_Fail681=== RUN TestGracefulShutdownDrainsInflight682=== PAUSE TestGracefulShutdownDrainsInflight683=== RUN TestService_healthCheckHandler684=== PAUSE TestService_healthCheckHandler685=== RUN TestService_readinessHandler686=== PAUSE TestService_readinessHandler687=== RUN TestGenerateLandingPage688=== PAUSE TestGenerateLandingPage689=== RUN TestChildrenInheritRaisedFileLimit690=== PAUSE TestChildrenInheritRaisedFileLimit691=== RUN TestCacheConfigHandlerMaxNarSize692=== PAUSE TestCacheConfigHandlerMaxNarSize693=== RUN TestCreatePendingClosureRejectsOversizedNAR694=== PAUSE TestCreatePendingClosureRejectsOversizedNAR695=== RUN TestNARDeduplicationMetadataUploadBug696=== PAUSE TestNARDeduplicationMetadataUploadBug697=== RUN TestMetricsInventory698=== PAUSE TestMetricsInventory699=== RUN TestMetricsCommit700=== PAUSE TestMetricsCommit701=== RUN TestService_NativeMTLS702=== PAUSE TestService_NativeMTLS703=== RUN TestServerTLSConfig704=== PAUSE TestServerTLSConfig705=== RUN TestMultipartCleanup706=== PAUSE TestMultipartCleanup707=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded708=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded709=== RUN TestPendingCleanupUsesOneCutoff710=== PAUSE TestPendingCleanupUsesOneCutoff711=== RUN TestPendingClosureFailureTracksEveryUpload712=== PAUSE TestPendingClosureFailureTracksEveryUpload713=== RUN TestPendingClosureFailureAbortsItsUploads714=== PAUSE TestPendingClosureFailureAbortsItsUploads715=== RUN TestObjectStatsTrigger716=== PAUSE TestObjectStatsTrigger717=== RUN TestObjectStatsUpdatedOncePerCommit718=== PAUSE TestObjectStatsUpdatedOncePerCommit719=== RUN TestReconnectLeavesObjectsUnlocked720=== PAUSE TestReconnectLeavesObjectsUnlocked721=== RUN TestOrphanedObjectsGC722=== PAUSE TestOrphanedObjectsGC723=== RUN TestOrphanedObjectsGCStressTest724=== PAUSE TestOrphanedObjectsGCStressTest725=== RUN TestCreatePin_ReservedPins726=== PAUSE TestCreatePin_ReservedPins727=== RUN TestConcurrentPinUpdatesAgree728=== PAUSE TestConcurrentPinUpdatesAgree729=== RUN TestCreatePinRejectsBadInput730=== PAUSE TestCreatePinRejectsBadInput731=== RUN TestDeletePinKeepsRowWhenS3Fails732=== PAUSE TestDeletePinKeepsRowWhenS3Fails733=== RUN TestPresentReportsOnlyClosureRoots734=== PAUSE TestPresentReportsOnlyClosureRoots735=== RUN TestPresentRefreshesOnlyStaleClosures736=== PAUSE TestPresentRefreshesOnlyStaleClosures737=== RUN TestPresentNotReportedWhileGCDeletesClosure738=== PAUSE TestPresentNotReportedWhileGCDeletesClosure739=== RUN TestParseSingleRange740=== PAUSE TestParseSingleRange741=== RUN TestProxyHeadersOnlyTrustedOnSocket7422026/10/25 17:20:48 INFO Starting HTTP server address=proxy.sock7432026/10/25 17:20:48 INFO Starting HTTP server address=127.0.0.1:390917442026/10/25 17:20:49 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7452026/10/25 17:20:49 INFO Shutdown signal received, draining in-flight requests timeout=10s746--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.16s)747=== RUN TestIsValidCachePath748=== PAUSE TestIsValidCachePath749=== RUN TestReadProxyNarinfo750=== PAUSE TestReadProxyNarinfo751=== RUN TestReadProxyNarinfoAlreadyDecompressed752=== PAUSE TestReadProxyNarinfoAlreadyDecompressed753=== RUN TestReadProxyContentNegotiation754=== PAUSE TestReadProxyContentNegotiation755=== RUN TestReadProxyNarStreaming756=== PAUSE TestReadProxyNarStreaming757=== RUN TestReadProxy404758=== PAUSE TestReadProxy404759=== RUN TestReadProxyInvalidPath760=== PAUSE TestReadProxyInvalidPath761=== RUN TestReadProxyHead762=== PAUSE TestReadProxyHead763=== RUN TestReadProxyOutlastsServerWriteTimeout764=== PAUSE TestReadProxyOutlastsServerWriteTimeout765=== RUN TestReadProxyConditionalGet766=== PAUSE TestReadProxyConditionalGet767=== RUN TestReadProxyRootRedirectsToIndexHTML768=== PAUSE TestReadProxyRootRedirectsToIndexHTML769=== RUN TestReadProxyDisabled770=== PAUSE TestReadProxyDisabled771=== RUN TestReadRedirectNar772=== PAUSE TestReadRedirectNar773=== RUN TestReadRedirectKeepsNarinfoProxied774=== PAUSE TestReadRedirectKeepsNarinfoProxied775=== RUN TestReadProxyRangeRequest776=== PAUSE TestReadProxyRangeRequest777=== RUN TestReadRedirectUsesPublicS3URL778=== PAUSE TestReadRedirectUsesPublicS3URL779=== RUN TestPush_OverlappingRootsStoreOneRowPerKey780=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey781=== RUN TestPush_CompleteCommitsEveryRoot782=== PAUSE TestPush_CompleteCommitsEveryRoot783=== RUN TestPush_RepeatedRootCommitsOnce784=== PAUSE TestPush_RepeatedRootCommitsOnce785=== RUN TestPush_CompleteWaitsForCleanupOfThePush786=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush787=== RUN TestPush_RootsAreLockedInByteOrder788=== PAUSE TestPush_RootsAreLockedInByteOrder789=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit790=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit791=== RUN TestPush_RejectsBadRequests792=== PAUSE TestPush_RejectsBadRequests793=== RUN TestPush_SignsNarinfosOfItsPendingObjects794=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects795=== RUN TestRedundantMultipartUpload796=== PAUSE TestRedundantMultipartUpload797=== RUN TestCompleteMultipartUpload_ErrorButObjectExists798=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists799=== RUN TestCompletedNarNotReofferedAcrossClosures800=== PAUSE TestCompletedNarNotReofferedAcrossClosures801=== RUN TestPresignedUploadRegisteredBeforeCommit802=== PAUSE TestPresignedUploadRegisteredBeforeCommit803=== RUN TestService_Rustfstest804=== PAUSE TestService_Rustfstest805=== RUN TestParseSize806=== PAUSE TestParseSize807=== RUN TestSkippedUploadsHandler808=== PAUSE TestSkippedUploadsHandler809=== RUN TestSystemdListenerNotActivated810--- PASS: TestSystemdListenerNotActivated (0.00s)811=== RUN TestWatchdogBeatsWhenHealthy812--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)813=== RUN TestWatchdogSkipsWhenUnhealthy8142026/10/25 17:20:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8152026/10/25 17:20:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8162026/10/25 17:20:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8172026/10/25 17:20:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8182026/10/25 17:20:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8192026/10/25 17:20:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8202026/10/25 17:20:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8212026/10/25 17:20:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8222026/10/25 17:20:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8232026/10/25 17:20:49 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"824--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)825=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle826=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle827=== RUN TestProxyWriteTimeout828=== PAUSE TestProxyWriteTimeout829=== RUN TestPendingClosureWriteTimeout830=== PAUSE TestPendingClosureWriteTimeout831=== RUN TestIsValidUploadKey832=== PAUSE TestIsValidUploadKey833=== RUN TestUploadHandlersRejectInvalidKeys834=== PAUSE TestUploadHandlersRejectInvalidKeys835=== RUN TestUploadHandlersRejectOversizedBody836=== PAUSE TestUploadHandlersRejectOversizedBody837=== RUN TestService_cleanupPendingClosuresHandler838=== PAUSE TestService_cleanupPendingClosuresHandler839=== RUN TestService_createPendingClosureHandler840=== PAUSE TestService_createPendingClosureHandler841=== RUN TestService_verifyS3Integrity842=== PAUSE TestService_verifyS3Integrity843=== RUN TestCompleteMultipartUnregistered844=== PAUSE TestCompleteMultipartUnregistered845=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT846=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT847=== CONT TestService_AuthMiddleware848=== CONT TestReadRedirectNar849=== CONT TestReadProxyRootRedirectsToIndexHTML850=== CONT TestTombstonedObjectOfferedWithoutWaiting851=== CONT TestConcurrentPinUpdatesAgree852=== CONT TestCompleteMultipartUpload_ErrorButObjectExists853=== CONT TestPendingClosureWriteTimeout854=== CONT TestReadProxyConditionalGet855=== CONT TestCreatePinRejectsBadInput856=== CONT TestPendingClosureFailureAbortsItsUploads857=== CONT TestReadProxyInvalidPath858=== CONT TestReadProxyOutlastsServerWriteTimeout859=== CONT TestReadProxy404860=== CONT TestReadProxyNarStreaming861=== CONT TestReadProxyNarinfoAlreadyDecompressed862=== CONT TestReadProxyContentNegotiation863=== CONT TestReadProxyNarinfo864=== CONT TestParseSingleRange865=== CONT TestPresentNotReportedWhileGCDeletesClosure866=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale867=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale868=== CONT TestPresentRefreshesOnlyStaleClosures869=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh870=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh871=== CONT TestCompleteMultipartUnregistered872=== CONT TestPresentReportsOnlyClosureRoots873=== CONT TestIsValidCachePath874=== RUN TestIsValidCachePath/narinfo875=== CONT TestReadProxyHead876=== CONT TestMetricsCommit877=== RUN TestPendingClosureWriteTimeout/empty878=== RUN TestParseSingleRange/none879=== PAUSE TestParseSingleRange/none880=== PAUSE TestPendingClosureWriteTimeout/empty881=== RUN TestPendingClosureWriteTimeout/400_objects882=== PAUSE TestPendingClosureWriteTimeout/400_objects883=== PAUSE TestIsValidCachePath/narinfo884=== RUN TestParseSingleRange/unknown_unit885=== RUN TestPendingClosureWriteTimeout/670k_objects886=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars887=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars888=== RUN TestIsValidCachePath/nar_zst889=== PAUSE TestParseSingleRange/unknown_unit890=== PAUSE TestPendingClosureWriteTimeout/670k_objects891=== RUN TestParseSingleRange/multi-range_ignored892=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline893=== PAUSE TestParseSingleRange/multi-range_ignored894=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline895=== RUN TestParseSingleRange/malformed_no_dash896=== PAUSE TestParseSingleRange/malformed_no_dash897=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle898=== RUN TestParseSingleRange/malformed_both_empty899=== PAUSE TestParseSingleRange/malformed_both_empty900=== RUN TestParseSingleRange/malformed_end_before_start901=== PAUSE TestParseSingleRange/malformed_end_before_start902=== RUN TestParseSingleRange/closed903=== PAUSE TestIsValidCachePath/nar_zst904=== RUN TestIsValidCachePath/nar_xz905=== PAUSE TestIsValidCachePath/nar_xz906=== RUN TestIsValidCachePath/nar_bz2907=== PAUSE TestIsValidCachePath/nar_bz2908=== RUN TestIsValidCachePath/nar_uncompressed909=== PAUSE TestIsValidCachePath/nar_uncompressed910=== RUN TestIsValidCachePath/ls911=== PAUSE TestIsValidCachePath/ls912=== RUN TestIsValidCachePath/log913=== PAUSE TestIsValidCachePath/log914=== RUN TestIsValidCachePath/realisation915=== PAUSE TestIsValidCachePath/realisation916=== RUN TestIsValidCachePath/nix-cache-info917=== PAUSE TestIsValidCachePath/nix-cache-info918=== RUN TestIsValidCachePath/index.html919=== PAUSE TestIsValidCachePath/index.html920=== RUN TestIsValidCachePath/traversal_parent921=== PAUSE TestIsValidCachePath/traversal_parent922=== RUN TestIsValidCachePath/traversal_in_middle923=== PAUSE TestIsValidCachePath/traversal_in_middle924=== RUN TestIsValidCachePath/invalid_char_e925=== PAUSE TestIsValidCachePath/invalid_char_e926=== RUN TestIsValidCachePath/invalid_char_u927=== PAUSE TestIsValidCachePath/invalid_char_u928=== RUN TestIsValidCachePath/random_path929=== PAUSE TestIsValidCachePath/random_path930=== RUN TestIsValidCachePath/empty931=== PAUSE TestIsValidCachePath/empty932=== RUN TestIsValidCachePath/leading_slash933=== PAUSE TestIsValidCachePath/leading_slash934=== RUN TestIsValidCachePath/wrong_extension935=== PAUSE TestIsValidCachePath/wrong_extension936=== RUN TestIsValidCachePath/short_hash937=== PAUSE TestIsValidCachePath/short_hash938=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT939=== PAUSE TestParseSingleRange/closed940=== RUN TestParseSingleRange/open-ended941=== PAUSE TestParseSingleRange/open-ended942=== RUN TestParseSingleRange/end_clamped_to_size943=== PAUSE TestParseSingleRange/end_clamped_to_size944=== RUN TestParseSingleRange/suffix945=== PAUSE TestParseSingleRange/suffix946=== RUN TestParseSingleRange/suffix_exceeds_size947=== PAUSE TestParseSingleRange/suffix_exceeds_size948=== RUN TestParseSingleRange/single_byte949=== PAUSE TestParseSingleRange/single_byte950=== RUN TestParseSingleRange/start_past_EOF951=== PAUSE TestParseSingleRange/start_past_EOF952=== RUN TestParseSingleRange/start_far_past_EOF953=== PAUSE TestParseSingleRange/start_far_past_EOF954=== CONT TestUploadHandlersRejectInvalidKeys955=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info956=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info957=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal958=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal959=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key960=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key961=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key962=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key963=== CONT TestService_verifyS3Integrity964--- PASS: TestReadRedirectNar (0.58s)965=== CONT TestService_createPendingClosureHandler9662026/10/25 17:20:49 INFO Received uploads request method=POST path=/api/pending_closures967--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.60s)968=== CONT TestService_cleanupPendingClosuresHandler9692026/10/25 17:20:49 INFO Received uploads request method=POST path=/api/pending_closures9702026/10/25 17:20:49 INFO Received create pin request method=POST path=/api/pins/deploy9712026/10/25 17:20:49 INFO Received create pin request method=POST path=/api/pins/deploy9722026/10/25 17:20:49 INFO Received create pin request method=POST path=/api/pins/deploy9732026/10/25 17:20:49 INFO Received create pin request method=POST path=/api/pins/deploy9742026/10/25 17:20:49 INFO Received create pin request method=POST path=/api/pins/deploy9752026/10/25 17:20:49 INFO Received create pin request method=POST path=/api/pins/deploy9762026/10/25 17:20:49 INFO Received create pin request method=POST path=/api/pins/deploy9772026/10/25 17:20:49 INFO Received create pin request method=POST path=/api/pins/deploy978--- PASS: TestPendingClosureFailureAbortsItsUploads (0.74s)979=== CONT TestSkippedUploadsHandler9802026/10/25 17:20:49 INFO Client skipped oversized paths paths=3 nar_bytes=50000000009812026/10/25 17:20:50 INFO Received create pin request method=POST path=/api/pins/deploy982--- PASS: TestSkippedUploadsHandler (0.04s)983=== CONT TestProxyWriteTimeout984=== RUN TestProxyWriteTimeout/narinfo985=== PAUSE TestProxyWriteTimeout/narinfo986=== RUN TestProxyWriteTimeout/1_GiB_nar987=== PAUSE TestProxyWriteTimeout/1_GiB_nar988=== RUN TestProxyWriteTimeout/10_GiB_nar989=== PAUSE TestProxyWriteTimeout/10_GiB_nar990=== RUN TestProxyWriteTimeout/unknown_size991=== PAUSE TestProxyWriteTimeout/unknown_size992=== CONT TestUploadHandlersRejectOversizedBody9932026/10/25 17:20:50 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"994--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.80s)995=== CONT TestIsValidUploadKey996=== RUN TestIsValidUploadKey/narinfo997=== PAUSE TestIsValidUploadKey/narinfo998=== RUN TestIsValidUploadKey/nar_zst999=== PAUSE TestIsValidUploadKey/nar_zst1000=== RUN TestIsValidUploadKey/nar_xz1001=== PAUSE TestIsValidUploadKey/nar_xz1002=== RUN TestIsValidUploadKey/nar_plain1003=== PAUSE TestIsValidUploadKey/nar_plain1004=== RUN TestIsValidUploadKey/listing1005=== PAUSE TestIsValidUploadKey/listing1006=== RUN TestIsValidUploadKey/build_log1007=== PAUSE TestIsValidUploadKey/build_log1008=== RUN TestIsValidUploadKey/build_log_home-manager_file1009=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1010=== RUN TestIsValidUploadKey/build_log_plus_in_name1011=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1012=== RUN TestIsValidUploadKey/build_log_question_mark1013=== PAUSE TestIsValidUploadKey/build_log_question_mark1014=== RUN TestIsValidUploadKey/build_log_equals1015=== PAUSE TestIsValidUploadKey/build_log_equals1016=== RUN TestIsValidUploadKey/realisation1017=== PAUSE TestIsValidUploadKey/realisation1018=== RUN TestIsValidUploadKey/realisation_plus_in_output1019=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1020=== RUN TestIsValidUploadKey/nix-cache-info1021=== PAUSE TestIsValidUploadKey/nix-cache-info1022=== RUN TestIsValidUploadKey/index.html1023=== PAUSE TestIsValidUploadKey/index.html1024=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1025=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1026=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1027=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1028=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1029=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1030=== RUN TestIsValidUploadKey/traversal1031=== PAUSE TestIsValidUploadKey/traversal1032=== RUN TestIsValidUploadKey/traversal_nar1033=== PAUSE TestIsValidUploadKey/traversal_nar1034=== RUN TestIsValidUploadKey/absolute1035=== PAUSE TestIsValidUploadKey/absolute1036=== RUN TestIsValidUploadKey/empty_key1037=== PAUSE TestIsValidUploadKey/empty_key1038=== RUN TestIsValidUploadKey/unknown_type1039=== PAUSE TestIsValidUploadKey/unknown_type1040=== CONT TestGCTaskStore_ConflictDifferentParams1041--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1042=== CONT TestOrphanedObjectsGC1043--- PASS: TestService_AuthMiddleware (0.82s)1044=== CONT TestMetricsInventory10452026/10/25 17:20:50 INFO Received push request method=POST path=/api/pushes1046--- PASS: TestReadProxyNarStreaming (0.87s)1047=== CONT TestCreatePin_ReservedPins10482026/10/25 17:20:50 INFO Received create pin request method=POST path=/api/pins/app10492026/10/25 17:20:50 INFO Received create pin request method=POST path=/api/pins/app10502026/10/25 17:20:50 INFO Received uploads request method=POST path=/api/pending_closures1051--- PASS: TestTombstonedObjectOfferedWithoutWaiting (1.05s)1052=== CONT TestCacheConfigHandlerMaxNarSize1053--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1054=== CONT TestOrphanedObjectsGCStressTest10552026/10/25 17:20:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34319/oidc1056--- PASS: TestPresentRefreshesOnlyStaleClosures (1.08s)1057=== CONT TestChildrenInheritRaisedFileLimit1058--- PASS: TestChildrenInheritRaisedFileLimit (0.00s)1059=== CONT TestNARDeduplicationMetadataUploadBug10602026/10/25 17:20:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10612026/10/25 17:20:50 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst10622026/10/25 17:20:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10632026/10/25 17:20:50 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLjQxNDZhODg3LWJmMDktNGJkMC1iZjJiLTRkZTljNjdkM2JhYngxNzkyOTQ4ODQ5OTMzMzM3NDE41064--- PASS: TestCompleteMultipartUnregistered (1.13s)1065=== CONT TestGenerateLandingPage1066--- PASS: TestGenerateLandingPage (0.04s)1067=== CONT TestMultipartCleanup10682026/10/25 17:20:50 INFO Received uploads request method=POST path=/api/pending_closures1069--- PASS: TestPresentReportsOnlyClosureRoots (1.24s)1070=== CONT TestService_readinessHandler1071--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.26s)1072=== CONT TestService_healthCheckHandler10732026/10/25 17:20:50 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLjQxNDZhODg3LWJmMDktNGJkMC1iZjJiLTRkZTljNjdkM2JhYngxNzkyOTQ4ODQ5OTMzMzM3NDE4 error="Delete \"http://localhost:36135/bucket7/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLjQxNDZhODg3LWJmMDktNGJkMC1iZjJiLTRkZTljNjdkM2JhYngxNzkyOTQ4ODQ5OTMzMzM3NDE4\": injected: abort refused"10742026/10/25 17:20:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10752026/10/25 17:20:50 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLjQxNDZhODg3LWJmMDktNGJkMC1iZjJiLTRkZTljNjdkM2JhYngxNzkyOTQ4ODQ5OTMzMzM3NDE41076--- PASS: TestReadProxyInvalidPath (1.33s)1077=== CONT TestGCTaskStore_Fail1078--- PASS: TestGCTaskStore_Fail (0.00s)1079=== CONT TestCreatePendingClosureRejectsOversizedNAR10802026/10/25 17:20:50 INFO Received uploads request method=POST path=/api/pending_closures10812026/10/25 17:20:50 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLjQxNDZhODg3LWJmMDktNGJkMC1iZjJiLTRkZTljNjdkM2JhYngxNzkyOTQ4ODQ5OTMzMzM3NDE4 parts=11082--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1083=== CONT TestGCTaskStore_CompletedAllowsNewTask1084--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1085=== CONT TestGracefulShutdownDrainsInflight10862026/10/25 17:20:50 INFO Starting HTTP server address=127.0.0.1:3849110872026/10/25 17:20:50 INFO Shutdown signal received, draining in-flight requests timeout=10s10882026/10/25 17:20:50 INFO Received uploads request method=POST path=/api/pending_closures1089--- PASS: TestReadProxyConditionalGet (1.36s)1090=== CONT TestGCTaskStore_GetEmpty1091--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.36s)1092=== CONT TestGetExistingObjectsLocksRows1093--- PASS: TestGCTaskStore_GetEmpty (0.00s)1094=== CONT TestGCTaskStore_PhaseUpdates1095--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1096=== CONT TestGCTaskStore_DeduplicateSameParams1097--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1098=== CONT TestPush_RepeatedRootCommitsOnce10992026/10/25 17:20:50 INFO Received uploads request method=POST path=/api/pending_closures1100--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1101=== CONT TestGCEndsOnShutdown1102=== RUN TestGCEndsOnShutdown/before_the_run1103=== PAUSE TestGCEndsOnShutdown/before_the_run1104=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1105=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1106=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1107=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1108=== CONT TestGCTaskStore_GetReturnsLatest1109--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1110=== CONT TestCommitRacingPendingCleanupKeepsObjects11112026/10/25 17:20:50 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo11122026/10/25 17:20:50 INFO Received uploads request method=POST path=/api/pending_closures11132026/10/25 17:20:50 INFO Received uploads request method=POST path=/api/pending_closures11142026/10/25 17:20:50 INFO Received uploads request method=POST path=/api/pending_closures11152026/10/25 17:20:50 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo1116--- PASS: TestReadProxyHead (1.45s)1117=== CONT TestGCTaskStore_StartNew1118--- PASS: TestGCTaskStore_StartNew (0.00s)1119=== CONT TestSweepRechecksPendingAfterLocking1120--- PASS: TestConcurrentPinUpdatesAgree (1.49s)1121=== CONT TestCompletedNarNotReofferedAcrossClosures11222026/10/25 17:20:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11232026/10/25 17:20:50 INFO Received cleanup request method=DELETE path=/api/pending_closures11242026/10/25 17:20:50 INFO Aborted multipart uploads count=0 kept=011252026/10/25 17:20:50 INFO Received uploads request method=POST path=/api/pending_closures11262026/10/25 17:20:50 WARN Rate limiter enabled after throttle name=s3-test rate=511272026/10/25 17:20:50 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."11282026/10/25 17:20:50 INFO Received cleanup request method=DELETE path=/api/pending_closures11292026/10/25 17:20:50 INFO Aborted multipart uploads count=1 kept=011302026/10/25 17:20:50 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11312026-10-25 17:20:50.810 UTC [482] ERROR: Closure does not exist: id=111322026-10-25 17:20:50.810 UTC [482] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE11332026-10-25 17:20:50.810 UTC [482] STATEMENT: -- name: CommitPendingClosure :one1134 SELECT commit_pending_closure($1::bigint)::bigint1135 1136--- PASS: TestService_cleanupPendingClosuresHandler (0.98s)1137=== CONT TestPushWaitsForSweepHoldingRow11382026/10/25 17:20:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11392026/10/25 17:20:50 INFO Received create pin request method=POST path=/api/pins/deploy11402026/10/25 17:20:50 WARN Rate limiter backed off name=s3-test rate=51141=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure11422026/10/25 17:20:50 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."1143=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1144=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1145=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1146=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1147=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1148=== CONT TestPush_SignsNarinfosOfItsPendingObjects11492026/10/25 17:20:50 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo11502026/10/25 17:20:50 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLjE1MDNhZTgxLTAwMDQtNGYyOS04YjZjLWYwMmYzNDdjY2VlOHgxNzkyOTQ4ODUwMTMzMDczNzg0 parts=1011512026/10/25 17:20:50 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11522026/10/25 17:20:50 WARN Refused reserved pin name=worker-x86_64-linux11532026/10/25 17:20:50 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11542026/10/25 17:20:50 INFO Received create pin request method=POST path=/api/pins/my-app11552026/10/25 17:20:50 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1156--- PASS: TestMetricsInventory (0.93s)1157=== CONT TestRedundantMultipartUpload1158=== CONT TestPush_CompleteCommitsEveryRoot1159--- PASS: TestCreatePinRejectsBadInput (1.76s)1160--- PASS: TestReadProxy404 (1.75s)1161=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1162--- PASS: TestCreatePin_ReservedPins (0.89s)1163=== CONT TestReadProxyRangeRequest11642026/10/25 17:20:51 INFO Received uploads request method=POST path=/api/pending_closures1165=== NAME TestNARDeduplicationMetadataUploadBug1166 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3464555553/001/store/vi024ic9026hqh0d0c72gl5qz67jm2rc-file1.txt1167--- PASS: TestService_healthCheckHandler (0.54s)1168=== CONT TestPush_RejectsBadRequests11692026/10/25 17:20:51 WARN readiness check failed error="closed pool"1170=== CONT TestPush_RootsAreLockedInByteOrder1171--- PASS: TestService_readinessHandler (0.59s)1172=== NAME TestOrphanedObjectsGC1173 orphaned_objects_gc_test.go:287: GC Test Summary:1174 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1175 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1176 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1177 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1178 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects11792026/10/25 17:20:51 INFO Received cleanup request method=DELETE path=/api/pending_closures11802026/10/25 17:20:51 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket35/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11812026/10/25 17:20:51 INFO Aborted multipart uploads count=0 kept=111822026/10/25 17:20:51 INFO Received cleanup request method=DELETE path=/api/pending_closures11832026/10/25 17:20:51 INFO Aborted multipart uploads count=1 kept=01184=== CONT TestPush_CompleteWaitsForCleanupOfThePush1185--- PASS: TestOrphanedObjectsGC (1.16s)1186--- PASS: TestGetExistingObjectsLocksRows (0.61s)1187=== CONT TestReadRedirectUsesPublicS3URL1188=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1189--- PASS: TestMultipartCleanup (0.75s)11902026/10/25 17:20:51 INFO Received push request method=POST path=/api/pushes11912026/10/25 17:20:51 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11922026/10/25 17:20:51 INFO Uploading vi024ic9026hqh0d0c72gl5qz67jm2rc-file1.txt (160B)1193=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1194--- PASS: TestReadProxyContentNegotiation (1.99s)11952026/10/25 17:20:51 INFO Received push request method=POST path=/api/pushes11962026/10/25 17:20:51 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"11972026/10/25 17:20:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11982026/10/25 17:20:51 INFO Received uploads request method=POST path=/api/pending_closures11992026/10/25 17:20:51 WARN Failed to register uploaded object key=vi024ic9026hqh0d0c72gl5qz67jm2rc.ls error="server returned 404: 404 page not found\n"12002026/10/25 17:20:51 INFO Signed narinfos id=1 count=112012026/10/25 17:20:51 INFO Uploading 1 narinfos12022026/10/25 17:20:51 INFO Aborted multipart uploads count=0 kept=012032026/10/25 17:20:51 WARN Force mode enabled - objects will be deleted immediately without grace period12042026/10/25 17:20:51 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=012052026/10/25 17:20:51 WARN Failed to register uploaded object key=vi024ic9026hqh0d0c72gl5qz67jm2rc.narinfo error="server returned 404: 404 page not found\n"12062026/10/25 17:20:51 INFO Received complete push request method=POST path=/api/pushes/1/complete12072026/10/25 17:20:51 INFO Completed push id=1 objects=3 duration=15.847738ms12082026/10/25 17:20:51 INFO Vacuumed table table=pending_closures12092026/10/25 17:20:51 INFO Upload complete. (115ms)12102026/10/25 17:20:51 INFO Vacuumed table table=pending_objects12112026/10/25 17:20:51 INFO Vacuumed table table=multipart_uploads1212=== NAME TestNARDeduplicationMetadataUploadBug1213 metadata_upload_test.go:54: Retrieved narinfo from S3:1214 StorePath: /build/TestNARDeduplicationMetadataUploadBug3464555553/001/store/vi024ic9026hqh0d0c72gl5qz67jm2rc-file1.txt1215 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1216 Compression: zstd1217 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1218 NarSize: 1601219 References: 1220 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf12212026/10/25 17:20:51 INFO Vacuumed table table=closures12222026/10/25 17:20:51 INFO Vacuumed table table=objects1223 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1224 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1225 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12262026/10/25 17:20:51 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>12272026/10/25 17:20:51 INFO Aborted multipart uploads count=0 kept=012282026/10/25 17:20:51 WARN Force mode enabled - objects will be deleted immediately without grace period12292026/10/25 17:20:51 INFO Received uploads request method=POST path=/api/pending_closures12302026/10/25 17:20:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1231--- PASS: TestReadProxyNarinfo (2.06s)1232=== CONT TestReconnectLeavesObjectsUnlocked1233--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.68s)1234=== CONT TestObjectStatsUpdatedOncePerCommit12352026/10/25 17:20:51 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=012362026/10/25 17:20:51 INFO Vacuumed table table=pending_closures12372026/10/25 17:20:51 INFO Received push request method=POST path=/api/pushes1238=== NAME TestNARDeduplicationMetadataUploadBug1239 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3464555553/001/store/lzxjvirf3rgz460sflmfk0x17h0dh54p-file2.txt12402026/10/25 17:20:51 INFO Vacuumed table table=pending_objects12412026/10/25 17:20:51 INFO Vacuumed table table=multipart_uploads12422026/10/25 17:20:51 INFO Vacuumed table table=closures12432026/10/25 17:20:51 INFO Vacuumed table table=objects12442026/10/25 17:20:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12452026/10/25 17:20:51 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLmRlZWM1NzI2LTYxNTItNGIwMS04MDEzLWMzNDZlZGRlZGEwZngxNzkyOTQ4ODUwNjQxMzIwNzg1 parts=1012462026/10/25 17:20:51 INFO Received uploads request method=POST path=/api/pending_closures12472026/10/25 17:20:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12482026/10/25 17:20:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12492026/10/25 17:20:51 INFO Signed narinfos id=1 count=112502026/10/25 17:20:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1251--- PASS: TestSweepRechecksPendingAfterLocking (0.65s)1252=== CONT TestDeletePinKeepsRowWhenS3Fails12532026/10/25 17:20:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12542026/10/25 17:20:51 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"12552026/10/25 17:20:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12562026/10/25 17:20:51 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"12572026/10/25 17:20:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12582026/10/25 17:20:51 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=112592026/10/25 17:20:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12602026/10/25 17:20:51 INFO Completed upload id=1 objects=2 duration=6.64734ms12612026/10/25 17:20:51 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo12622026/10/25 17:20:51 INFO Received uploads request method=POST path=/api/pending_closures12632026/10/25 17:20:51 INFO Received uploads request method=POST path=/api/pending_closures12642026/10/25 17:20:51 INFO Received uploads request method=POST path=/api/pending_closures12652026/10/25 17:20:51 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLjI2ZTIwNWFkLWRhMmQtNDcyMy05MTg2LWFmNmQyMWQ2MGZhM3gxNzkyOTQ4ODUwNzA0MjQ1MDQ3 parts=1012662026/10/25 17:20:51 INFO Received push request method=POST path=/api/pushes12672026/10/25 17:20:51 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12682026/10/25 17:20:51 INFO Completed upload id=1 objects=2 duration=4.09391ms12692026/10/25 17:20:51 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012702026/10/25 17:20:51 INFO Received uploads request method=POST path=/api/pending_closures1271--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.47s)1272=== CONT TestPendingCleanupUsesOneCutoff12732026/10/25 17:20:51 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo12742026/10/25 17:20:51 WARN Found objects in DB but missing from S3, will re-upload count=112752026/10/25 17:20:51 INFO Starting cleanup of old closures method=DELETE path=/api/closures12762026/10/25 17:20:51 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete12772026/10/25 17:20:51 INFO Aborted multipart uploads count=0 kept=01278=== RUN TestPush_RejectsBadRequests/no_objects1279=== PAUSE TestPush_RejectsBadRequests/no_objects1280=== RUN TestPush_RejectsBadRequests/bad_root1281=== PAUSE TestPush_RejectsBadRequests/bad_root1282=== RUN TestPush_RejectsBadRequests/root_not_in_objects1283=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1284=== RUN TestPush_RejectsBadRequests/no_roots1285=== PAUSE TestPush_RejectsBadRequests/no_roots1286=== CONT TestObjectStatsTrigger12872026/10/25 17:20:51 INFO Completed upload id=3 objects=2 duration=17.906288ms12882026/10/25 17:20:51 INFO Received push request method=POST path=/api/pushes12892026/10/25 17:20:51 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=012902026/10/25 17:20:51 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12912026/10/25 17:20:51 INFO Vacuumed table table=pending_closures12922026/10/25 17:20:51 INFO Vacuumed table table=pending_objects12932026/10/25 17:20:51 INFO Vacuumed table table=multipart_uploads1294--- PASS: TestService_verifyS3Integrity (2.15s)1295=== CONT TestPendingClosureFailureTracksEveryUpload1296=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1297=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false12982026/10/25 17:20:51 WARN Failed to register uploaded object key=lzxjvirf3rgz460sflmfk0x17h0dh54p.ls error="server returned 404: 404 page not found\n"1299=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true13002026/10/25 17:20:51 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign1301=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1302=== CONT TestRegisterCompletedObjectNeedsPendingRow13032026/10/25 17:20:51 INFO Signed narinfos id=2 count=113042026/10/25 17:20:51 INFO Uploading 1 narinfos13052026/10/25 17:20:51 INFO Vacuumed table table=closures13062026/10/25 17:20:51 INFO Vacuumed table table=objects13072026/10/25 17:20:51 INFO Received push request method=POST path=/api/pushes13082026/10/25 17:20:51 INFO Received complete push request method=POST path=/api/pushes/2/complete13092026/10/25 17:20:51 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013102026/10/25 17:20:51 WARN Failed to register uploaded object key=lzxjvirf3rgz460sflmfk0x17h0dh54p.narinfo error="server returned 404: 404 page not found\n"1311=== CONT TestParseSize1312--- PASS: TestReadProxyRangeRequest (0.43s)1313=== CONT TestPresignedUploadRegisteredBeforeCommit1314--- PASS: TestParseSize (0.00s)13152026/10/25 17:20:51 INFO Completed push id=2 objects=3 duration=2.14592ms13162026/10/25 17:20:51 INFO Upload complete. (64ms)1317=== NAME TestNARDeduplicationMetadataUploadBug1318 metadata_upload_test.go:76: Retrieved narinfo from S3:1319 StorePath: /build/TestNARDeduplicationMetadataUploadBug3464555553/001/store/lzxjvirf3rgz460sflmfk0x17h0dh54p-file2.txt1320 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1321 Compression: zstd1322 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1323 NarSize: 1601324 References: 1325 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1326 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1327 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1328 {"version":1,"root":{"type":"regular","size":44}}13292026/10/25 17:20:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1330--- PASS: TestService_createPendingClosureHandler (1.63s)1331=== CONT TestService_Rustfstest13322026/10/25 17:20:51 INFO Received push request method=POST path=/api/pushes1333--- PASS: TestNARDeduplicationMetadataUploadBug (1.12s)1334=== CONT TestPinProtectsFromGC13352026/10/25 17:20:51 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLmMyNWVmZjc3LTVhODktNDBiZi1iYWUwLTRjZDJiYmQzNGM0YngxNzkyOTQ4ODUwMTMzNTM1NjM0 parts=1013362026/10/25 17:20:51 INFO Received complete push request method=POST path=/api/pushes/1/complete13372026/10/25 17:20:51 INFO Received push request method=POST path=/api/pushes13382026/10/25 17:20:51 INFO Completed push id=1 objects=4 duration=20.564178ms13392026/10/25 17:20:51 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13402026/10/25 17:20:51 INFO Received push request method=POST path=/api/pushes13412026/10/25 17:20:51 INFO Completed upload id=2 objects=2 duration=1.507649ms13422026/10/25 17:20:51 INFO Received uploads request method=POST path=/api/pending_closures1343=== CONT TestFailedS3DeleteKeepsTombstone1344--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.31s)1345--- PASS: TestMetricsCommit (2.30s)1346=== CONT TestCacheConfigHandler1347=== RUN TestCacheConfigHandler/full_config,_no_issuer1348=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1349=== RUN TestCacheConfigHandler/no_cache_url_configured1350=== PAUSE TestCacheConfigHandler/no_cache_url_configured1351=== RUN TestCacheConfigHandler/no_signing_keys1352=== PAUSE TestCacheConfigHandler/no_signing_keys1353=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1354=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1355=== CONT TestForceGCDuringPushOffersSweptObject1356=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1357=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1358=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1359=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1360=== CONT TestDeduplicatedObjectsRecordedAsPending1361=== CONT TestGCMetrics1362--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.32s)13632026/10/25 17:20:51 INFO Received create pin request method=POST path=/api/pins/app1364--- PASS: TestReconnectLeavesObjectsUnlocked (0.29s)1365=== CONT TestClientPushesUseOnePush13662026/10/25 17:20:51 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo13672026/10/25 17:20:51 INFO Received delete pin request method=DELETE path=/api/pins/app13682026/10/25 17:20:51 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket57/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"13692026/10/25 17:20:51 INFO Received delete pin request method=DELETE path=/api/pins/app13702026/10/25 17:20:51 INFO Deleted pin name=app1371=== CONT TestClientSharedPathCommittedMidPush1372--- PASS: TestObjectStatsUpdatedOncePerCommit (0.30s)1373--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.28s)1374=== CONT TestClientWithDependencies1375--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.22s)1376=== CONT TestClientIntegration13772026/10/25 17:20:51 INFO Received uploads request method=POST path=/api/pending_closures1378--- PASS: TestReadRedirectUsesPublicS3URL (0.44s)1379=== CONT TestClientErrorHandling1380=== RUN TestClientErrorHandling/InvalidStorePath1381=== PAUSE TestClientErrorHandling/InvalidStorePath1382=== RUN TestClientErrorHandling/InvalidAuthToken1383=== PAUSE TestClientErrorHandling/InvalidAuthToken1384=== RUN TestClientErrorHandling/ServerNotAvailable1385=== PAUSE TestClientErrorHandling/ServerNotAvailable1386=== CONT TestClientCADerivations13872026/10/25 17:20:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13882026/10/25 17:20:51 INFO Received uploads request method=POST path=/api/pending_closures13892026/10/25 17:20:51 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLjBkMTZjZjkwLTY5NzItNGFiNS1iNzM5LWM0YmU3NzZhZjRjOXgxNzkyOTQ4ODUxMjYzODA5NTYx parts=1013902026/10/25 17:20:51 INFO Received cleanup request method=DELETE path=/api/pending_closures13912026/10/25 17:20:51 INFO Received uploads request method=POST path=/api/pending_closures1392=== CONT TestCacheStatsHandler1393--- PASS: TestObjectStatsTrigger (0.40s)13942026/10/25 17:20:51 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst13952026/10/25 17:20:51 INFO Received uploads request method=POST path=/api/pending_closures1396--- PASS: TestService_Rustfstest (0.37s)1397=== CONT TestReadProxyDisabled13982026/10/25 17:20:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1399--- PASS: TestPushWaitsForSweepHoldingRow (1.01s)1400=== CONT TestReadRedirectKeepsNarinfoProxied1401--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.41s)1402=== CONT TestService_ReadAuthMiddleware14032026/10/25 17:20:51 INFO Received uploads request method=POST path=/api/pending_closures14042026/10/25 17:20:51 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLjQ0ODJhMzExLTM4NzAtNGE3YS1iOTg4LTc0ZTVlOTAyN2NjZXgxNzkyOTQ4ODUxMzkxMzQxMTc3 parts=1014052026/10/25 17:20:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14062026/10/25 17:20:51 INFO Received uploads request method=POST path=/api/pending_closures1407=== CONT TestClientMultipleUploads1408--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.34s)14092026/10/25 17:20:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14102026/10/25 17:20:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14112026/10/25 17:20:51 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLmE2ZTcyMDA1LTAwOGYtNDUzNi05MmUzLTYwODBmMTVlNDgzZXgxNzkyOTQ4ODUxMjg1MjI4NTQ5 parts=1214122026/10/25 17:20:51 INFO Received uploads request method=POST path=/api/pending_closures1413=== NAME TestPinProtectsFromGC1414 client_integration_test.go:867: Pinned store path: /build/TestPinProtectsFromGC2189252192/001/store/i9ainr8yg1vncsp022d2nn9h7gjvwc6v-pinned-file.txt1415 client_integration_test.go:868: Unpinned store path: /build/TestPinProtectsFromGC2189252192/001/store/55f72hiblgqaxslwaxl70z0mgs9775fv-unpinned-file.txt14162026/10/25 17:20:51 INFO Aborted multipart uploads count=0 kept=014172026/10/25 17:20:51 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLjEzMmFlOTEzLWU1NDUtNGRjMi1hZTIyLTVhNzA5NWU5MDg5Y3gxNzkyOTQ4ODUxNDUwNjc0Mjcw parts=1014182026/10/25 17:20:51 INFO Aborted multipart uploads count=0 kept=014192026/10/25 17:20:51 WARN Force mode enabled - objects will be deleted immediately without grace period14202026/10/25 17:20:51 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLjJjZmY2YjQwLTcxYjUtNGZmNi04OTc2LWRjZjhkNmIxM2I4MHgxNzkyOTQ4ODUxMzcwNjA5MTk5 parts=1214212026/10/25 17:20:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14222026/10/25 17:20:51 INFO Received uploads request method=POST path=/api/pending_closures14232026/10/25 17:20:51 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=014242026/10/25 17:20:51 WARN Force mode enabled - objects will be deleted immediately without grace period1425=== CONT TestService_ReadScope_PublicByDefault1426--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.22s)14272026/10/25 17:20:51 INFO Vacuumed table table=pending_closures14282026/10/25 17:20:51 INFO Vacuumed table table=pending_objects14292026/10/25 17:20:51 INFO Vacuumed table table=multipart_uploads14302026/10/25 17:20:51 INFO Vacuumed table table=closures14312026/10/25 17:20:51 INFO Vacuumed table table=objects14322026/10/25 17:20:51 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."14332026/10/25 17:20:51 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."14342026/10/25 17:20:51 INFO Received uploads request method=POST path=/api/pending_closures14352026/10/25 17:20:51 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLmE5YmU0YTBmLTRjYjAtNGYzYS05OTViLWEwYWM0NjJjMjkyZHgxNzkyOTQ4ODUxNDcyMjg4NDU3 parts=101436--- PASS: TestFailedS3DeleteKeepsTombstone (0.44s)1437=== CONT TestService_RequireScope_OIDC14382026/10/25 17:20:51 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14392026/10/25 17:20:51 INFO Received push request method=POST path=/api/pushes14402026/10/25 17:20:51 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLmUwMDY0ODRkLTdjZTUtNGRkYi05MTA0LTg0MDI5YzQwNzJlZXgxNzkyOTQ4ODUxNTA4ODk0MDkz parts=101441=== CONT TestService_AuthMiddleware_OIDC1442--- PASS: TestGCMetrics (0.43s)14432026/10/25 17:20:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14442026/10/25 17:20:52 INFO Uploading i9ainr8yg1vncsp022d2nn9h7gjvwc6v-pinned-file.txt (128B)14452026/10/25 17:20:52 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"14462026/10/25 17:20:52 WARN Failed to register uploaded object key=i9ainr8yg1vncsp022d2nn9h7gjvwc6v.ls error="server returned 404: 404 page not found\n"14472026/10/25 17:20:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14482026/10/25 17:20:52 INFO Signed narinfos id=1 count=114492026/10/25 17:20:52 INFO Uploading 1 narinfos14502026/10/25 17:20:52 INFO Received complete push request method=POST path=/api/pushes/1/complete14512026/10/25 17:20:52 WARN Failed to register uploaded object key=i9ainr8yg1vncsp022d2nn9h7gjvwc6v.narinfo error="server returned 404: 404 page not found\n"14522026/10/25 17:20:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37721/oidc14532026/10/25 17:20:52 INFO Completed push id=1 objects=3 duration=4.58453ms14542026/10/25 17:20:52 INFO Upload complete. (74ms)14552026/10/25 17:20:52 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41501/oidc1456=== NAME TestClientIntegration1457 client_integration_test.go:334: Created store path: /build/TestClientIntegration186163848/002/store/1k698s3fn3i2whii3ganr7gl4768qyxm-test-file.txt1458--- PASS: TestCacheStatsHandler (0.25s)1459=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1460=== NAME TestClientWithDependencies1461 client_integration_test.go:735: Built derivation: /build/TestClientWithDependencies3584523868/001/store/zswa33ibkd0fkpbsch6pkjzrx2zjrjhx-test-script1462--- PASS: TestReadProxyDisabled (0.24s)1463=== CONT TestGCSweepDeliversEachKeyOnce14642026/10/25 17:20:52 INFO Received push request method=POST path=/api/pushes14652026/10/25 17:20:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14662026/10/25 17:20:52 INFO Received push request method=POST path=/api/pushes14672026/10/25 17:20:52 INFO Uploading 55f72hiblgqaxslwaxl70z0mgs9775fv-unpinned-file.txt (128B)1468=== NAME TestClientCADerivations1469 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations2056292962/001/store/xazym068sv4x6p8xhljl15ammwqzkm0x-ca-test14702026/10/25 17:20:52 INFO Received push request method=POST path=/api/pushes14712026/10/25 17:20:52 INFO Received push request method=POST path=/api/pushes1472--- PASS: TestService_ReadAuthMiddleware (0.25s)1473=== CONT TestGCSweepSkipsPendingObjects14742026/10/25 17:20:52 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14752026/10/25 17:20:52 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14762026/10/25 17:20:52 INFO Uploading w8q1vykn09a7m4nyhrs5w4i6b3iqhj1a-a (216B)14772026/10/25 17:20:52 INFO Uploading wa5iji372z89x7fdmzrsklbfbaiwn0r7-shared-dep (136B)1478=== NAME TestClientWithDependencies1479 client_integration_test.go:737: Found 1 dependencies (including self)14802026/10/25 17:20:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14812026/10/25 17:20:52 INFO Uploading 1k698s3fn3i2whii3ganr7gl4768qyxm-test-file.txt (152B)14822026/10/25 17:20:52 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14832026/10/25 17:20:52 WARN Failed to register uploaded object key=55f72hiblgqaxslwaxl70z0mgs9775fv.ls error="server returned 404: 404 page not found\n"14842026/10/25 17:20:52 INFO Signed narinfos id=2 count=114852026/10/25 17:20:52 WARN Failed to register uploaded object key=48gf36w68r94an7xssql2zmbnbvh3lzg.ls error="server returned 404: 404 page not found\n"14862026/10/25 17:20:52 INFO Uploading 1 narinfos14872026/10/25 17:20:52 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)14882026/10/25 17:20:52 INFO Uploading npznlnwr40d686k8f0ghq5pwffb5lipj-shared-dep (136B)14892026/10/25 17:20:52 INFO Uploading ykvss9b4gxih8ypi9g02wnmsyiwqjij5-top (224B)14902026/10/25 17:20:52 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14912026/10/25 17:20:52 WARN Failed to register uploaded object key=wa5iji372z89x7fdmzrsklbfbaiwn0r7.ls error="server returned 404: 404 page not found\n"14922026/10/25 17:20:52 WARN Failed to register uploaded object key=w8q1vykn09a7m4nyhrs5w4i6b3iqhj1a.ls error="server returned 404: 404 page not found\n"14932026/10/25 17:20:52 WARN Failed to register uploaded object key=nar/0kr5wia44vi8wn47n7ygw3bslgs4yyjb3i312jlh0l25hqqk1jh1.nar.zst error="server returned 404: 404 page not found\n"14942026/10/25 17:20:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14952026/10/25 17:20:52 INFO Signed narinfos id=1 count=314962026/10/25 17:20:52 INFO Uploading 3 narinfos1497=== NAME TestClientCADerivations1498 client_ca_test.go:139: Found 1 dependencies (including self)14992026/10/25 17:20:52 WARN Failed to register uploaded object key=w8q1vykn09a7m4nyhrs5w4i6b3iqhj1a.narinfo error="server returned 404: 404 page not found\n"15002026/10/25 17:20:52 INFO Received complete push request method=POST path=/api/pushes/2/complete15012026/10/25 17:20:52 WARN Failed to register uploaded object key=55f72hiblgqaxslwaxl70z0mgs9775fv.narinfo error="server returned 404: 404 page not found\n"15022026/10/25 17:20:52 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15032026/10/25 17:20:52 WARN Failed to register uploaded object key=nar/1bwzcy8pgilfxsq0w19wivga7sc25f3w6gsznb9wacvjm7hjym5s.nar.zst error="server returned 404: 404 page not found\n"15042026/10/25 17:20:52 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15052026/10/25 17:20:52 WARN Failed to register uploaded object key=wa5iji372z89x7fdmzrsklbfbaiwn0r7.narinfo error="server returned 404: 404 page not found\n"15062026/10/25 17:20:52 WARN Failed to register uploaded object key=ykvss9b4gxih8ypi9g02wnmsyiwqjij5.ls error="server returned 404: 404 page not found\n"15072026/10/25 17:20:52 INFO Received complete push request method=POST path=/api/pushes/1/complete15082026/10/25 17:20:52 WARN Failed to register uploaded object key=1k698s3fn3i2whii3ganr7gl4768qyxm.ls error="server returned 404: 404 page not found\n"15092026/10/25 17:20:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15102026/10/25 17:20:52 WARN Failed to register uploaded object key=npznlnwr40d686k8f0ghq5pwffb5lipj.ls error="server returned 404: 404 page not found\n"15112026/10/25 17:20:52 WARN Failed to register uploaded object key=48gf36w68r94an7xssql2zmbnbvh3lzg.narinfo error="server returned 404: 404 page not found\n"15122026/10/25 17:20:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15132026/10/25 17:20:52 INFO Signed narinfos id=1 count=115142026/10/25 17:20:52 INFO Uploading 1 narinfos15152026/10/25 17:20:52 INFO Signed narinfos id=1 count=215162026/10/25 17:20:52 INFO Uploading 2 narinfos15172026/10/25 17:20:52 INFO Completed push id=2 objects=3 duration=14.224788ms15182026/10/25 17:20:52 INFO Received complete push request method=POST path=/api/pushes/1/complete15192026/10/25 17:20:52 INFO Upload complete. (89ms)15202026/10/25 17:20:52 WARN Failed to register uploaded object key=1k698s3fn3i2whii3ganr7gl4768qyxm.narinfo error="server returned 404: 404 page not found\n"15212026/10/25 17:20:52 INFO Completed push id=1 objects=8 duration=6.338109ms15222026/10/25 17:20:52 WARN Failed to register uploaded object key=ykvss9b4gxih8ypi9g02wnmsyiwqjij5.narinfo error="server returned 404: 404 page not found\n"15232026/10/25 17:20:52 INFO Upload complete. (86ms)15242026/10/25 17:20:52 INFO Completed push id=1 objects=3 duration=4.28303ms15252026/10/25 17:20:52 INFO Upload complete. (78ms)15262026/10/25 17:20:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15272026/10/25 17:20:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15282026/10/25 17:20:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1529=== NAME TestClientMultipleUploads1530 client_integration_test.go:480: Created store path 0: /build/TestClientMultipleUploads2534729724/001/store/9h7nld53jms1bw6n2dankhd6as5zrkjk-test-file-0.txt1531=== NAME TestClientPushesUseOnePush1532 client_pushes_test.go:97: Retrieved narinfo from S3:1533 StorePath: /build/TestClientPushesUseOnePush1713955127/001/store/wa5iji372z89x7fdmzrsklbfbaiwn0r7-shared-dep1534 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1535 Compression: zstd1536 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821537 NarSize: 1361538 References: 1539 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n15402026-10-25 17:20:52.352 UTC [953] ERROR: Push does not exist: id=115412026-10-25 17:20:52.352 UTC [953] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE15422026-10-25 17:20:52.352 UTC [953] STATEMENT: SELECT commit_push($1)15432026/10/25 17:20:52 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLmEwMTM3Mzk2LTZiYTktNGMyOS1hYWU3LTc4ZmIxYTBkY2FkN3gxNzkyOTQ4ODUxNDUxMjEwNzA5 parts=101544 client_pushes_test.go:97: Retrieved narinfo from S3:1545 StorePath: /build/TestClientPushesUseOnePush1713955127/001/store/w8q1vykn09a7m4nyhrs5w4i6b3iqhj1a-a1546 URL: nar/0kr5wia44vi8wn47n7ygw3bslgs4yyjb3i312jlh0l25hqqk1jh1.nar.zst1547 Compression: zstd1548 NarHash: sha256:0kr5wia44vi8wn47n7ygw3bslgs4yyjb3i312jlh0l25hqqk1jh11549 NarSize: 2161550 References: /build/TestClientPushesUseOnePush1713955127/001/store/wa5iji372z89x7fdmzrsklbfbaiwn0r7-shared-dep1551 CA: text:sha256:1givzi4vfpgwxk8irhkckfmy79x40pfsf8fzhgv2lydqfvf6pc1r15522026/10/25 17:20:52 INFO Received complete push request method=POST path=/api/pushes/1/complete15532026/10/25 17:20:52 WARN Failed to register uploaded object key=npznlnwr40d686k8f0ghq5pwffb5lipj.narinfo error="server returned 404: 404 page not found\n"1554--- PASS: TestService_ReadScope_PublicByDefault (0.41s)1555=== NAME TestClientPushesUseOnePush1556 client_pushes_test.go:97: Retrieved narinfo from S3:1557 StorePath: /build/TestClientPushesUseOnePush1713955127/001/store/48gf36w68r94an7xssql2zmbnbvh3lzg-b1558 URL: nar/0kr5wia44vi8wn47n7ygw3bslgs4yyjb3i312jlh0l25hqqk1jh1.nar.zst1559 Compression: zstd1560 NarHash: sha256:0kr5wia44vi8wn47n7ygw3bslgs4yyjb3i312jlh0l25hqqk1jh11561 NarSize: 2161562 References: /build/TestClientPushesUseOnePush1713955127/001/store/wa5iji372z89x7fdmzrsklbfbaiwn0r7-shared-dep1563 CA: text:sha256:1givzi4vfpgwxk8irhkckfmy79x40pfsf8fzhgv2lydqfvf6pc1r1564=== CONT TestService_NativeMTLS15652026/10/25 17:20:52 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLjBlZTQ4Nzg1LThkN2ItNDAxZi1iNDAwLThjY2NiNzBjZTk2NngxNzkyOTQ4ODUxMjY0ODgwMTUx parts=1015662026/10/25 17:20:52 INFO Received complete push request method=POST path=/api/pushes/1/complete15672026/10/25 17:20:52 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLjVkNzBiMGE1LThmMTgtNDM1My1hYmQ1LWRiZjQ3YTlhOWQ1M3gxNzkyOTQ4ODUxMzkyNzY2OTI2 parts=1015682026/10/25 17:20:52 INFO Completed push id=1 objects=6 duration=4.64875ms15692026/10/25 17:20:52 INFO Upload complete. (297ms)1570=== NAME TestClientSharedPathCommittedMidPush1571 client_integration_test.go:816: Retrieved narinfo from S3:1572 StorePath: /build/TestClientSharedPathCommittedMidPush2592258161/001/store/npznlnwr40d686k8f0ghq5pwffb5lipj-shared-dep1573 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1574 Compression: zstd1575 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821576 NarSize: 1361577 References: 1578 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n15792026/10/25 17:20:52 INFO Completed push id=1 objects=4 duration=5.636319ms1580 client_integration_test.go:816: Retrieved narinfo from S3:1581 StorePath: /build/TestClientSharedPathCommittedMidPush2592258161/001/store/ykvss9b4gxih8ypi9g02wnmsyiwqjij5-top1582 URL: nar/1bwzcy8pgilfxsq0w19wivga7sc25f3w6gsznb9wacvjm7hjym5s.nar.zst1583 Compression: zstd1584 NarHash: sha256:1bwzcy8pgilfxsq0w19wivga7sc25f3w6gsznb9wacvjm7hjym5s1585 NarSize: 2241586 References: /build/TestClientSharedPathCommittedMidPush2592258161/001/store/npznlnwr40d686k8f0ghq5pwffb5lipj-shared-dep1587 CA: text:sha256:1nvp7xqhpx9flps575p4s10lk4kzjwm94d361si4y16424c7k2ws1588--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.15s)1589=== CONT TestServerTLSConfig1590=== RUN TestServerTLSConfig/no_client_CA1591=== PAUSE TestServerTLSConfig/no_client_CA1592=== RUN TestServerTLSConfig/missing_CA_file1593=== PAUSE TestServerTLSConfig/missing_CA_file1594=== RUN TestServerTLSConfig/not_a_PEM_file1595=== PAUSE TestServerTLSConfig/not_a_PEM_file1596=== CONT TestService_AuthMiddleware_MTLSProxyHeader15972026/10/25 17:20:52 INFO Received complete push request method=POST path=/api/pushes/1/complete15982026/10/25 17:20:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15992026/10/25 17:20:52 INFO Received push request method=POST path=/api/pushes16002026/10/25 17:20:52 INFO Completed push id=1 objects=4 duration=10.950598ms1601=== NAME TestClientMultipleUploads1602 client_integration_test.go:480: Created store path 1: /build/TestClientMultipleUploads2534729724/001/store/ka7fw4k1zwnnsb5wgayyj8yw7pmhjk0c-test-file-1.txt16032026/10/25 17:20:52 INFO Received push request method=POST path=/api/pushes16042026/10/25 17:20:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures16052026/10/25 17:20:52 INFO All 1 paths already cached16062026/10/25 17:20:52 INFO Garbage collection started1607=== NAME TestClientIntegration1608 client_integration_test.go:360: Retrieved narinfo from S3:1609 StorePath: /build/TestClientIntegration186163848/002/store/1k698s3fn3i2whii3ganr7gl4768qyxm-test-file.txt1610 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1611 Compression: zstd1612 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11613 NarSize: 1521614 References: 1615 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk116162026/10/25 17:20:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16172026/10/25 17:20:52 INFO Uploading zswa33ibkd0fkpbsch6pkjzrx2zjrjhx-test-script (136B)1618=== CONT TestConnectSerialisesConcurrentMigrations1619--- PASS: TestClientPushesUseOnePush (0.77s)1620=== NAME TestClientIntegration1621 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)1622 client_integration_test.go:361: Decompressed .ls content (64 bytes):1623 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1624--- PASS: TestPush_RepeatedRootCommitsOnce (1.78s)1625=== CONT TestPushDedupSurvivesConcurrentGC1626=== CONT TestGCAdvisoryLockBlocksConcurrentRun1627--- PASS: TestClientSharedPathCommittedMidPush (0.75s)16282026/10/25 17:20:52 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLmUzNjM5YTgwLTZmNTUtNGUxOS05Yzc4LTk3MTZhNTZlMzNmZHgxNzkyOTQ4ODUxNDcyMjQyNzU3 parts=1016292026/10/25 17:20:52 INFO Aborted multipart uploads count=0 kept=016302026/10/25 17:20:52 WARN Failed to register uploaded object key=log/s8m4midv5n3zydjkcak0n18l3jf0n3l6-test-script.drv error="server returned 404: 404 page not found\n"16312026/10/25 17:20:52 WARN Failed to register uploaded object key=zswa33ibkd0fkpbsch6pkjzrx2zjrjhx.ls error="server returned 404: 404 page not found\n"16322026/10/25 17:20:52 WARN Force mode enabled - objects will be deleted immediately without grace period16332026/10/25 17:20:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16342026/10/25 17:20:52 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16352026/10/25 17:20:52 INFO Signed narinfos id=1 count=116362026/10/25 17:20:52 INFO Uploading 1 narinfos16372026/10/25 17:20:52 INFO Received complete push request method=POST path=/api/pushes/1/complete16382026/10/25 17:20:52 WARN Failed to register uploaded object key=zswa33ibkd0fkpbsch6pkjzrx2zjrjhx.narinfo error="server returned 404: 404 page not found\n"16392026/10/25 17:20:52 INFO Completed push id=1 objects=4 duration=6.11757ms16402026/10/25 17:20:52 INFO Upload complete. (274ms)1641=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1642=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1643=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1644=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1645=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1646=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1647=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1648=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1649=== CONT TestGCBugBareHashReferences16502026/10/25 17:20:52 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=01651=== NAME TestClientMultipleUploads1652 client_integration_test.go:480: Created store path 2: /build/TestClientMultipleUploads2534729724/001/store/ld697g0sjaagbfsjhnj5q3hh6l6ja5r8-test-file-2.txt16532026/10/25 17:20:52 INFO Vacuumed table table=pending_closures1654--- PASS: TestReadRedirectKeepsNarinfoProxied (0.57s)1655=== CONT TestLeadIncumbentAnnouncesAtOnce16562026/10/25 17:20:52 INFO Aborted multipart uploads count=0 kept=016572026/10/25 17:20:52 INFO Vacuumed table table=pending_objects16582026/10/25 17:20:52 INFO Vacuumed table table=multipart_uploads16592026/10/25 17:20:52 WARN Force mode enabled - objects will be deleted immediately without grace period16602026/10/25 17:20:52 INFO Vacuumed table table=closures16612026/10/25 17:20:52 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016622026/10/25 17:20:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16632026/10/25 17:20:52 INFO Vacuumed table table=objects16642026/10/25 17:20:52 INFO Vacuumed table table=pending_closures16652026/10/25 17:20:52 INFO Received push request method=POST path=/api/pushes16662026/10/25 17:20:52 INFO Aborted multipart uploads count=0 kept=016672026/10/25 17:20:52 INFO Vacuumed table table=pending_objects16682026/10/25 17:20:52 INFO Vacuumed table table=multipart_uploads16692026/10/25 17:20:52 INFO Received push request method=POST path=/api/pushes16702026/10/25 17:20:52 INFO Vacuumed table table=closures1671=== RUN TestService_RequireScope_OIDC/builder_may_write1672=== PAUSE TestService_RequireScope_OIDC/builder_may_write1673=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1674=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1675=== RUN TestService_RequireScope_OIDC/ops_may_admin1676=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1677=== RUN TestService_RequireScope_OIDC/ops_may_not_write1678=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1679=== RUN TestService_RequireScope_OIDC/reader_may_not_write1680=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1681=== RUN TestService_RequireScope_OIDC/static_token_may_admin1682=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1683=== RUN TestService_RequireScope_OIDC/static_token_may_write1684=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1685=== RUN TestService_RequireScope_OIDC/reader_may_read1686=== PAUSE TestService_RequireScope_OIDC/reader_may_read1687=== RUN TestService_RequireScope_OIDC/writer_implies_read1688=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1689=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1690=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1691=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1692=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc16932026/10/25 17:20:52 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLjNhMGU1Nzk1LTI1NDMtNDhiMi05Yjc1LTA4ZWNjZTM2NTRmMXgxNzkyOTQ4ODUxOTY0MzM5Nzg5 error="Get \"http://127.0.0.1:1/bucket45/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"1694=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1695=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc16962026/10/25 17:20:52 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLmY1MmNjMDQ4LWM2MmYtNDE3Ni1hMWUwLTZkMjUyZjE5MDllYngxNzkyOTQ4ODUxOTU0MjAzMDYw parts=121697=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1698=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1699=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1700=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1701=== CONT TestLeadElectsOneAndHandsOver17022026/10/25 17:20:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17032026/10/25 17:20:52 INFO Uploading xazym068sv4x6p8xhljl15ammwqzkm0x-ca-test (144B)17042026/10/25 17:20:52 WARN Force mode enabled - objects will be deleted immediately without grace period17052026/10/25 17:20:52 INFO Vacuumed table table=objects17062026/10/25 17:20:52 INFO Received cleanup request method=DELETE path=/api/pending_closures1707=== NAME TestClientWithDependencies17082026/10/25 17:20:52 INFO Object in database but missing from S3 key=1k698s3fn3i2whii3ganr7gl4768qyxm.ls1709 client_integration_test.go:753: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3584523868/001/store) requires matching store prefix17102026/10/25 17:20:52 WARN Found objects in DB but missing from S3, will re-upload count=117112026/10/25 17:20:52 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17122026/10/25 17:20:52 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"17132026/10/25 17:20:52 WARN Failed to register uploaded object key=log/8w0ix9c30pcmp4nz133k91qv9snvk65l-ca-test.drv error="server returned 404: 404 page not found\n"17142026/10/25 17:20:52 INFO Aborted multipart uploads count=1 kept=017152026/10/25 17:20:52 INFO Received complete push request method=POST path=/api/pushes/2/complete17162026/10/25 17:20:52 WARN Failed to register uploaded object key=1k698s3fn3i2whii3ganr7gl4768qyxm.ls error="server returned 404: 404 page not found\n"17172026/10/25 17:20:52 INFO Completed push id=2 objects=3 duration=2.87697ms17182026/10/25 17:20:52 INFO Upload complete. (45ms)1719=== NAME TestClientIntegration17202026/10/25 17:20:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1721 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)1722 client_integration_test.go:389: Decompressed .ls content (49 bytes):1723 {"version":1,"root":{"type":"regular","size":39}}17242026/10/25 17:20:52 WARN Failed to register uploaded object key=xazym068sv4x6p8xhljl15ammwqzkm0x.ls error="server returned 404: 404 page not found\n"17252026/10/25 17:20:52 INFO Signed narinfos id=1 count=117262026/10/25 17:20:52 INFO Uploading 1 narinfos17272026/10/25 17:20:52 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=017282026/10/25 17:20:52 INFO Received uploads request method=POST path=/api/pending_closures17292026/10/25 17:20:52 INFO Received complete push request method=POST path=/api/pushes/1/complete17302026/10/25 17:20:52 WARN Failed to register uploaded object key=xazym068sv4x6p8xhljl15ammwqzkm0x.narinfo error="server returned 404: 404 page not found\n"17312026/10/25 17:20:52 INFO Aborted multipart uploads count=0 kept=017322026/10/25 17:20:52 INFO Vacuumed table table=pending_closures1733--- PASS: TestClientWithDependencies (0.83s)1734=== CONT TestLeadEndsOnShutdown17352026/10/25 17:20:52 WARN Force mode enabled - objects will be deleted immediately without grace period17362026/10/25 17:20:52 INFO Vacuumed table table=pending_objects17372026/10/25 17:20:52 INFO Completed push id=1 objects=4 duration=7.629729ms17382026/10/25 17:20:52 INFO Upload complete. (104ms)17392026/10/25 17:20:52 INFO Received push request method=POST path=/api/pushes1740=== NAME TestClientCADerivations1741 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations2056292962/001/store/xazym068sv4x6p8xhljl15ammwqzkm0x-ca-test1742 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1743 Compression: zstd1744 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1745 NarSize: 1441746 References: 1747 Deriver: /build/TestClientCADerivations2056292962/001/store/8w0ix9c30pcmp4nz133k91qv9snvk65l-ca-test.drv1748 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1749 client_ca_test.go:185: Checking for realisation files in S3...1750=== CONT TestDeleteClosuresRacingPins1751--- PASS: TestRedundantMultipartUpload (1.49s)17522026/10/25 17:20:52 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"17532026/10/25 17:20:52 WARN mTLS auth: bound subjects configured but subject DN unavailable17542026/10/25 17:20:52 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1755=== NAME TestClientCADerivations1756 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1757 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache17582026/10/25 17:20:52 INFO Vacuumed table table=multipart_uploads17592026/10/25 17:20:52 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)17602026/10/25 17:20:52 INFO Uploading ka7fw4k1zwnnsb5wgayyj8yw7pmhjk0c-test-file-1.txt (160B)17612026/10/25 17:20:52 INFO Uploading 9h7nld53jms1bw6n2dankhd6as5zrkjk-test-file-0.txt (160B)17622026/10/25 17:20:52 INFO Uploading ld697g0sjaagbfsjhnj5q3hh6l6ja5r8-test-file-2.txt (160B)17632026/10/25 17:20:52 INFO Vacuumed table table=closures17642026/10/25 17:20:52 INFO Aborted multipart uploads count=0 kept=017652026/10/25 17:20:52 INFO Vacuumed table table=objects17662026/10/25 17:20:52 WARN Force mode enabled - objects will be deleted immediately without grace period17672026/10/25 17:20:52 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=01768=== CONT TestConnectWaitsForAPeerMigration17692026/10/25 17:20:52 INFO Vacuumed table table=pending_closures1770--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.47s)17712026/10/25 17:20:52 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=017722026/10/25 17:20:52 INFO Vacuumed table table=pending_objects17732026/10/25 17:20:52 INFO Vacuumed table table=multipart_uploads17742026/10/25 17:20:52 INFO Vacuumed table table=closures17752026/10/25 17:20:52 INFO Vacuumed table table=pending_closures17762026/10/25 17:20:52 INFO Vacuumed table table=objects17772026/10/25 17:20:52 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"17782026/10/25 17:20:52 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"17792026/10/25 17:20:52 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"17802026-10-25 17:20:52.522 UTC [1568] ERROR: duplicate key value violates unique constraint "pg_type_typname_nsp_index"17812026-10-25 17:20:52.522 UTC [1568] DETAIL: Key (typname, typnamespace)=(goose_db_version, 2200) already exists.17822026-10-25 17:20:52.522 UTC [1568] STATEMENT: CREATE TABLE goose_db_version (1783 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1784 version_id bigint NOT NULL,1785 is_applied boolean NOT NULL,1786 tstamp timestamp NOT NULL DEFAULT now()1787 )17882026/10/25 17:20:52 INFO Vacuumed table table=pending_objects17892026/10/25 17:20:52 INFO Vacuumed table table=multipart_uploads17902026/10/25 17:20:52 INFO Vacuumed table table=closures17912026/10/25 17:20:52 INFO Vacuumed table table=objects17922026/10/25 17:20:52 WARN Failed to register uploaded object key=9h7nld53jms1bw6n2dankhd6as5zrkjk.ls error="server returned 404: 404 page not found\n"17932026/10/25 17:20:52 WARN Failed to register uploaded object key=ka7fw4k1zwnnsb5wgayyj8yw7pmhjk0c.ls error="server returned 404: 404 page not found\n"17942026/10/25 17:20:52 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17952026/10/25 17:20:52 WARN Failed to register uploaded object key=ld697g0sjaagbfsjhnj5q3hh6l6ja5r8.ls error="server returned 404: 404 page not found\n"17962026/10/25 17:20:52 INFO Signed narinfos id=1 count=317972026/10/25 17:20:52 INFO Uploading 3 narinfos1798--- PASS: TestGCSweepDeliversEachKeyOnce (0.46s)1799=== CONT TestResolveDBConnectionString1800=== RUN TestResolveDBConnectionString/flag_wins1801=== PAUSE TestResolveDBConnectionString/flag_wins1802=== RUN TestResolveDBConnectionString/file_when_flag_empty1803=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1804=== RUN TestResolveDBConnectionString/missing_file_is_an_error1805=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1806=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1807=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1808=== RUN TestResolveDBConnectionString/nothing_configured1809=== PAUSE TestResolveDBConnectionString/nothing_configured1810=== CONT TestClientFallsBackToClosures18112026/10/25 17:20:52 INFO Received complete push request method=POST path=/api/pushes/1/complete18122026/10/25 17:20:52 WARN Failed to register uploaded object key=ld697g0sjaagbfsjhnj5q3hh6l6ja5r8.narinfo error="server returned 404: 404 page not found\n"18132026/10/25 17:20:52 WARN Failed to register uploaded object key=ka7fw4k1zwnnsb5wgayyj8yw7pmhjk0c.narinfo error="server returned 404: 404 page not found\n"18142026/10/25 17:20:52 WARN Failed to register uploaded object key=9h7nld53jms1bw6n2dankhd6as5zrkjk.narinfo error="server returned 404: 404 page not found\n"18152026/10/25 17:20:52 INFO Completed push id=1 objects=9 duration=5.954339ms18162026/10/25 17:20:52 INFO Upload complete. (92ms)1817=== NAME TestClientMultipleUploads1818 client_integration_test.go:491: Uploaded 3 paths in 121.407606ms1819--- PASS: TestGCSweepSkipsPendingObjects (0.44s)1820=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock18212026/10/25 17:20:52 INFO Received push request method=POST path=/api/pushes18222026/10/25 17:20:52 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)18232026/10/25 17:20:52 WARN mTLS auth: subject not in bound subjects subject="CN=reader"18242026/10/25 17:20:52 WARN mTLS auth: subject not in bound subjects subject="CN=reader"18252026/10/25 17:20:52 INFO Received complete push request method=POST path=/api/pushes/3/complete18262026/10/25 17:20:52 WARN Failed to register uploaded object key=1k698s3fn3i2whii3ganr7gl4768qyxm.ls error="server returned 404: 404 page not found\n"1827--- PASS: TestClientMultipleUploads (0.66s)1828=== CONT TestSweepSkipsRowsLockedByPush18292026/10/25 17:20:52 INFO Completed push id=3 objects=3 duration=10.851469ms18302026/10/25 17:20:52 INFO Upload complete. (59ms)1831=== NAME TestClientIntegration1832 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)1833 client_integration_test.go:405: Decompressed .ls content (49 bytes):1834 {"version":1,"root":{"type":"regular","size":39}}1835=== NAME TestClientCADerivations1836 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1837 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1838 error: binary cache 's3://bucket71?endpoint=http://localhost:36135®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations2056292962/001/store'1839 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11840--- PASS: TestService_NativeMTLS (0.23s)1841=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection1842--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.22s)1843=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1844=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1845--- PASS: TestClientCADerivations (0.94s)18462026/10/25 17:20:52 INFO Received uploads request method=POST path=/api/pending_closures18472026/10/25 17:20:52 INFO Received push request method=POST path=/api/pushes18482026/10/25 17:20:52 INFO lead: acquired remote=192.0.2.1:123418492026/10/25 17:20:52 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18502026/10/25 17:20:52 INFO Uploading kkqhhcgd1l2wd17qdsxnxdvfv95m71gm-lost-commit.txt (152B)18512026/10/25 17:20:52 INFO lead: acquired remote=192.0.2.1:123418522026/10/25 17:20:52 INFO lead: released remote=192.0.2.1:123418532026/10/25 17:20:52 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"18542026/10/25 17:20:52 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign18552026/10/25 17:20:52 INFO Signed narinfos id=4 count=118562026/10/25 17:20:52 INFO Uploading 1 narinfos18572026/10/25 17:20:52 WARN Failed to register uploaded object key=kkqhhcgd1l2wd17qdsxnxdvfv95m71gm.ls error="server returned 404: 404 page not found\n"18582026/10/25 17:20:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1859--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.30s)1860=== CONT TestPendingClosureWriteTimeout/400_objects1861=== CONT TestPendingClosureWriteTimeout/670k_objects1862=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline18632026/10/25 17:20:52 INFO lead: acquired remote=192.0.2.1:123418642026/10/25 17:20:52 INFO Received complete push request method=POST path=/api/pushes/4/complete18652026/10/25 17:20:52 WARN Failed to register uploaded object key=kkqhhcgd1l2wd17qdsxnxdvfv95m71gm.narinfo error="server returned 404: 404 page not found\n"18662026/10/25 17:20:52 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLjBiY2Y1YjJhLTY4MzEtNGI3ZC04MzE4LTI4MGMyMzA1NWZkOXgxNzkyOTQ4ODUxNDUxMjA0OTA5 parts=1018672026/10/25 17:20:52 INFO Received complete push request method=POST path=/api/pushes/1/complete18682026/10/25 17:20:52 INFO Completed push id=4 objects=3 duration=2.19733ms18692026/10/25 17:20:52 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:34991/api/pushes/4/complete\": EOF" url=http://127.0.0.1:34991/api/pushes/4/complete18702026/10/25 17:20:52 INFO Aborted multipart uploads count=0 kept=018712026/10/25 17:20:52 INFO Completed push id=1 objects=6 duration=10.745499ms18722026/10/25 17:20:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18732026/10/25 17:20:52 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=018742026/10/25 17:20:52 INFO Vacuumed table table=pending_closures18752026/10/25 17:20:52 INFO Vacuumed table table=pending_objects18762026/10/25 17:20:52 INFO Vacuumed table table=multipart_uploads18772026/10/25 17:20:52 INFO Vacuumed table table=closures18782026/10/25 17:20:52 INFO Vacuumed table table=objects18792026/10/25 17:20:52 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLmY4YjQ1Mjg2LWQzMzMtNDMyMS04MTZlLWYzN2ViNGIzMGJhNngxNzkyOTQ4ODUxNDcxNjI4MDE3 parts=1018802026/10/25 17:20:52 INFO Aborted multipart uploads count=0 kept=018812026/10/25 17:20:52 WARN Force mode enabled - objects will be deleted immediately without grace period18822026/10/25 17:20:52 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=01883--- PASS: TestPush_CompleteCommitsEveryRoot (1.76s)1884=== CONT TestPendingClosureWriteTimeout/empty18852026/10/25 17:20:52 INFO Vacuumed table table=pending_closures1886=== CONT TestIsValidCachePath/nar_zst1887=== CONT TestIsValidCachePath/wrong_extension1888=== CONT TestIsValidCachePath/leading_slash1889=== CONT TestIsValidCachePath/empty1890=== CONT TestIsValidCachePath/random_path1891=== CONT TestIsValidCachePath/invalid_char_u1892=== CONT TestIsValidCachePath/short_hash1893=== CONT TestIsValidCachePath/traversal_in_middle1894=== CONT TestIsValidCachePath/invalid_char_e1895=== CONT TestIsValidCachePath/index.html1896=== CONT TestIsValidCachePath/traversal_parent1897=== CONT TestIsValidCachePath/realisation1898=== CONT TestIsValidCachePath/log1899=== CONT TestIsValidCachePath/nix-cache-info1900=== CONT TestIsValidCachePath/ls1901=== CONT TestIsValidCachePath/nar_bz21902=== CONT TestIsValidCachePath/nar_xz1903=== CONT TestIsValidCachePath/nar_uncompressed1904=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1905=== CONT TestIsValidCachePath/narinfo1906=== CONT TestParseSingleRange/multi-range_ignored1907--- PASS: TestIsValidCachePath (0.01s)1908 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1909 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1910 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1911 --- PASS: TestIsValidCachePath/empty (0.00s)1912 --- PASS: TestIsValidCachePath/random_path (0.00s)1913 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1914 --- PASS: TestIsValidCachePath/short_hash (0.00s)1915 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1916 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1917 --- PASS: TestIsValidCachePath/index.html (0.00s)1918 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1919 --- PASS: TestIsValidCachePath/realisation (0.00s)1920 --- PASS: TestIsValidCachePath/log (0.00s)1921 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1922 --- PASS: TestIsValidCachePath/ls (0.00s)1923 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1924 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1925 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1926 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1927 --- PASS: TestIsValidCachePath/narinfo (0.00s)19282026/10/25 17:20:52 INFO Vacuumed table table=pending_objects1929=== CONT TestParseSingleRange/end_clamped_to_size1930=== CONT TestParseSingleRange/open-ended19312026/10/25 17:20:52 INFO Vacuumed table table=multipart_uploads1932=== CONT TestParseSingleRange/closed1933=== CONT TestParseSingleRange/malformed_end_before_start1934=== CONT TestParseSingleRange/suffix1935=== CONT TestParseSingleRange/malformed_both_empty1936=== CONT TestParseSingleRange/none1937=== CONT TestParseSingleRange/malformed_no_dash1938=== CONT TestParseSingleRange/start_far_past_EOF1939=== CONT TestParseSingleRange/unknown_unit1940=== CONT TestParseSingleRange/single_byte1941=== CONT TestParseSingleRange/start_past_EOF1942=== CONT TestParseSingleRange/suffix_exceeds_size1943--- PASS: TestParseSingleRange (0.01s)1944 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1945 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1946 --- PASS: TestParseSingleRange/open-ended (0.00s)1947 --- PASS: TestParseSingleRange/closed (0.00s)1948 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1949 --- PASS: TestParseSingleRange/suffix (0.00s)1950 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1951 --- PASS: TestParseSingleRange/none (0.00s)1952 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1953 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1954 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1955 --- PASS: TestParseSingleRange/single_byte (0.00s)1956 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1957 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1958=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19592026/10/25 17:20:52 INFO Received request for more parts method=POST path=/19602026/10/25 17:20:52 INFO Vacuumed table table=closures1961=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19622026/10/25 17:20:52 INFO Received uploads request method=POST path=/1963=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19642026/10/25 17:20:52 INFO Received uploads request method=POST path=/1965=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19662026/10/25 17:20:52 INFO Received complete multipart upload request method=POST path=/1967=== CONT TestProxyWriteTimeout/unknown_size1968--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1969 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1970 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1971 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1972 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1973=== CONT TestProxyWriteTimeout/1_GiB_nar1974=== CONT TestProxyWriteTimeout/10_GiB_nar1975=== CONT TestProxyWriteTimeout/narinfo1976=== CONT TestIsValidUploadKey/nar_xz1977--- PASS: TestProxyWriteTimeout (0.00s)1978 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1979 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1980 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1981 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)19822026/10/25 17:20:52 INFO Vacuumed table table=objects1983=== CONT TestIsValidUploadKey/realisation_plus_in_output1984=== CONT TestIsValidUploadKey/empty_key1985=== CONT TestIsValidUploadKey/absolute1986=== CONT TestIsValidUploadKey/traversal_nar1987=== CONT TestIsValidUploadKey/unknown_type1988=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1989=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1990=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1991=== CONT TestIsValidUploadKey/index.html1992=== CONT TestIsValidUploadKey/traversal1993=== CONT TestIsValidUploadKey/nix-cache-info1994=== CONT TestIsValidUploadKey/build_log1995=== CONT TestIsValidUploadKey/build_log_equals1996=== CONT TestIsValidUploadKey/realisation1997=== CONT TestIsValidUploadKey/build_log_plus_in_name1998=== CONT TestIsValidUploadKey/build_log_home-manager_file1999=== CONT TestIsValidUploadKey/nar_plain2000=== CONT TestIsValidUploadKey/build_log_question_mark2001=== CONT TestIsValidUploadKey/listing2002=== CONT TestIsValidUploadKey/narinfo2003=== CONT TestIsValidUploadKey/nar_zst2004--- PASS: TestIsValidUploadKey (0.00s)2005 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2006 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2007 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2008 --- PASS: TestIsValidUploadKey/absolute (0.00s)2009 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2010 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2011 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2012 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2013 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2014 --- PASS: TestIsValidUploadKey/index.html (0.00s)2015 --- PASS: TestIsValidUploadKey/traversal (0.00s)2016 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2017 --- PASS: TestIsValidUploadKey/build_log (0.00s)2018 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2019 --- PASS: TestIsValidUploadKey/realisation (0.00s)2020 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2021 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2022 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2023 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2024 --- PASS: TestIsValidUploadKey/listing (0.00s)2025 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2026 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2027=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete2028=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark2029--- PASS: TestPushDedupSurvivesConcurrentGC (0.40s)20302026/10/25 17:20:52 INFO Received complete push request method=POST path=/api/pushes/4/complete20312026-10-25 17:20:52.830 UTC [815] ERROR: Push does not exist: id=420322026-10-25 17:20:52.830 UTC [815] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE20332026-10-25 17:20:52.830 UTC [815] STATEMENT: -- name: CommitPush :one2034 SELECT commit_push($1::bigint)::bigint2035 20362026/10/25 17:20:52 WARN Push not found id=420372026/10/25 17:20:52 INFO Upload complete. (191ms)20382026/10/25 17:20:52 INFO Aborted multipart uploads count=0 kept=02039=== NAME TestClientIntegration2040 client_integration_test.go:435: Retrieved narinfo from S3:2041 StorePath: /build/TestClientIntegration186163848/002/store/kkqhhcgd1l2wd17qdsxnxdvfv95m71gm-lost-commit.txt2042 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst2043 Compression: zstd2044 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2045 NarSize: 1522046 References: 2047 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2048 client_integration_test.go:438: Testing garbage collection...20492026/10/25 17:20:52 WARN Force mode enabled - objects will be deleted immediately without grace period20502026/10/25 17:20:52 INFO Received uploads request method=POST path=/api/pending_closures20512026/10/25 17:20:52 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=020522026/10/25 17:20:52 INFO Vacuumed table table=pending_closures20532026/10/25 17:20:52 INFO Vacuumed table table=pending_objects20542026/10/25 17:20:52 INFO Vacuumed table table=multipart_uploads20552026/10/25 17:20:52 INFO Vacuumed table table=closures20562026/10/25 17:20:52 INFO Vacuumed table table=objects20572026/10/25 17:20:52 INFO Aborted multipart uploads count=0 kept=020582026/10/25 17:20:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20592026/10/25 17:20:52 WARN Force mode enabled - objects will be deleted immediately without grace period20602026/10/25 17:20:52 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=020612026/10/25 17:20:52 INFO Vacuumed table table=pending_closures20622026/10/25 17:20:52 INFO Vacuumed table table=pending_objects20632026/10/25 17:20:52 INFO Vacuumed table table=multipart_uploads20642026/10/25 17:20:52 INFO Vacuumed table table=closures20652026/10/25 17:20:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures20662026/10/25 17:20:52 INFO Vacuumed table table=objects20672026/10/25 17:20:52 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLjI4NTk5MWJjLTAyOTEtNGQ0OC1hYmEwLTk3YTg2MjYzNDIwOHgxNzkyOTQ4ODUyMzk0MzkyOTE5 parts=1020682026/10/25 17:20:52 INFO Garbage collection started20692026/10/25 17:20:52 INFO Received complete push request method=POST path=/api/pushes/2/complete20702026/10/25 17:20:52 INFO Completed push id=2 objects=4 duration=3.254919ms20712026/10/25 17:20:52 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"20722026/10/25 17:20:52 INFO Aborted multipart uploads count=0 kept=02073--- PASS: TestSweepSkipsRowsLockedByPush (0.31s)2074=== CONT TestGCEndsOnShutdown/before_the_run20752026/10/25 17:20:52 WARN Force mode enabled - objects will be deleted immediately without grace period20762026/10/25 17:20:52 INFO Received uploads request method=POST path=/api/pending_closures2077--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (1.89s)2078=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts20792026/10/25 17:20:52 INFO Received request for more parts method=POST path=/20802026/10/25 17:20:52 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=02081--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.51s)2082=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart20832026/10/25 17:20:52 INFO Received complete multipart upload request method=POST path=/20842026/10/25 17:20:52 INFO Vacuumed table table=pending_closures20852026/10/25 17:20:52 INFO Vacuumed table table=pending_objects20862026/10/25 17:20:52 INFO Vacuumed table table=multipart_uploads20872026/10/25 17:20:52 INFO Vacuumed table table=closures20882026/10/25 17:20:52 INFO Vacuumed table table=objects20892026/10/25 17:20:52 INFO Received uploads request method=POST path=/api/pending_closures20902026/10/25 17:20:52 INFO Received uploads request method=POST path=/api/pending_closures20912026/10/25 17:20:52 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)20922026/10/25 17:20:52 INFO Uploading dxk7sb40pr3lwi4xgi7xim39mdlx52ws-shared-dep (136B)20932026/10/25 17:20:52 INFO Uploading 45146l1igp1llw7105wx5j5hlncn2205-a (216B)2094=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure20952026/10/25 17:20:53 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"2096--- PASS: TestGCBugBareHashReferences (0.66s)20972026/10/25 17:20:53 INFO Received uploads request method=POST path=/20982026/10/25 17:20:53 WARN Failed to register uploaded object key=2plygragqnj75r9sxd0gf70sgmf8wjzn.ls error="server returned 404: 404 page not found\n"20992026/10/25 17:20:53 WARN Failed to register uploaded object key=dxk7sb40pr3lwi4xgi7xim39mdlx52ws.ls error="server returned 404: 404 page not found\n"21002026/10/25 17:20:53 WARN Failed to register uploaded object key=45146l1igp1llw7105wx5j5hlncn2205.ls error="server returned 404: 404 page not found\n"21012026/10/25 17:20:53 WARN Failed to register uploaded object key=nar/1skslxy0jgn8vlvwmrqxzl3pmbwkrd4cnkq09ygy5v7kq6ffdr3q.nar.zst error="server returned 404: 404 page not found\n"21022026/10/25 17:20:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign21032026/10/25 17:20:53 INFO Signed narinfos id=2 count=22104--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.50s)21052026/10/25 17:20:53 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign2106=== CONT TestPush_RejectsBadRequests/no_objects21072026/10/25 17:20:53 INFO Received push request method=POST path=/api/pushes21082026/10/25 17:20:53 INFO Signed narinfos id=1 count=22109=== CONT TestPush_RejectsBadRequests/root_not_in_objects21102026/10/25 17:20:53 INFO Received push request method=POST path=/api/pushes21112026/10/25 17:20:53 INFO Uploading 4 narinfos2112=== CONT TestPush_RejectsBadRequests/bad_root21132026/10/25 17:20:53 INFO Received push request method=POST path=/api/pushes2114=== CONT TestPush_RejectsBadRequests/no_roots21152026/10/25 17:20:53 INFO Received push request method=POST path=/api/pushes2116=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false21172026/10/25 17:20:53 WARN Failed to register uploaded object key=2plygragqnj75r9sxd0gf70sgmf8wjzn.narinfo error="server returned 404: 404 page not found\n"21182026/10/25 17:20:53 WARN Failed to register uploaded object key=dxk7sb40pr3lwi4xgi7xim39mdlx52ws.narinfo error="server returned 404: 404 page not found\n"21192026/10/25 17:20:53 WARN Failed to register uploaded object key=45146l1igp1llw7105wx5j5hlncn2205.narinfo error="server returned 404: 404 page not found\n"21202026/10/25 17:20:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21212026/10/25 17:20:53 WARN Failed to register uploaded object key=dxk7sb40pr3lwi4xgi7xim39mdlx52ws.narinfo error="server returned 404: 404 page not found\n"21222026/10/25 17:20:53 INFO Aborted multipart uploads count=0 kept=021232026/10/25 17:20:53 INFO Completed upload id=1 objects=6 duration=7.944459ms21242026/10/25 17:20:53 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21252026/10/25 17:20:53 INFO Completed upload id=2 objects=6 duration=2.06515ms2126--- PASS: TestPush_RejectsBadRequests (0.34s)2127 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2128 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2129 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2130 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)21312026/10/25 17:20:53 INFO Upload complete. (202ms)21322026/10/25 17:20:53 WARN Force mode enabled - objects will be deleted immediately without grace period2133=== NAME TestClientFallsBackToClosures2134 client_pushes_test.go:112: Retrieved narinfo from S3:2135 StorePath: /build/TestClientFallsBackToClosures295635278/001/store/dxk7sb40pr3lwi4xgi7xim39mdlx52ws-shared-dep2136 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2137 Compression: zstd2138 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822139 NarSize: 1362140 References: 2141 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n2142 client_pushes_test.go:112: Retrieved narinfo from S3:2143 StorePath: /build/TestClientFallsBackToClosures295635278/001/store/45146l1igp1llw7105wx5j5hlncn2205-a2144 URL: nar/1skslxy0jgn8vlvwmrqxzl3pmbwkrd4cnkq09ygy5v7kq6ffdr3q.nar.zst2145 Compression: zstd2146 NarHash: sha256:1skslxy0jgn8vlvwmrqxzl3pmbwkrd4cnkq09ygy5v7kq6ffdr3q2147 NarSize: 2162148 References: /build/TestClientFallsBackToClosures295635278/001/store/dxk7sb40pr3lwi4xgi7xim39mdlx52ws-shared-dep2149 CA: text:sha256:0kpj6gyxar8jw0ipjhqykndilr8rzljwq2r0zzcji5blh3igqsnr21502026/10/25 17:20:53 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:36135/bucket100/?delete=\": context canceled"2151 client_pushes_test.go:112: Retrieved narinfo from S3:2152 StorePath: /build/TestClientFallsBackToClosures295635278/001/store/2plygragqnj75r9sxd0gf70sgmf8wjzn-b2153 URL: nar/1skslxy0jgn8vlvwmrqxzl3pmbwkrd4cnkq09ygy5v7kq6ffdr3q.nar.zst2154 Compression: zstd2155 NarHash: sha256:1skslxy0jgn8vlvwmrqxzl3pmbwkrd4cnkq09ygy5v7kq6ffdr3q2156 NarSize: 2162157 References: /build/TestClientFallsBackToClosures295635278/001/store/dxk7sb40pr3lwi4xgi7xim39mdlx52ws-shared-dep2158 CA: text:sha256:0kpj6gyxar8jw0ipjhqykndilr8rzljwq2r0zzcji5blh3igqsnr2159=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true21602026/10/25 17:20:53 INFO Aborted multipart uploads count=0 kept=021612026/10/25 17:20:53 WARN Force mode enabled - objects will be deleted immediately without grace period2162--- PASS: TestClientFallsBackToClosures (0.61s)2163=== CONT TestCacheConfigHandler/full_config,_no_issuer2164=== CONT TestCacheConfigHandler/no_cache_url_configured2165=== CONT TestCacheConfigHandler/no_signing_keys2166=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2167=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows2168--- PASS: TestCacheConfigHandler (0.00s)2169 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2170 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2171 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2172 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2173=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check2174=== CONT TestClientErrorHandling/InvalidStorePath2175--- PASS: TestGCEndsOnShutdown (0.00s)2176 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.35s)2177 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.38s)2178 --- PASS: TestGCEndsOnShutdown/before_the_run (0.29s)21792026/10/25 17:20:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21802026/10/25 17:20:53 INFO Received uploads request method=POST path=/api/pending_closures2181--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.76s)2182=== CONT TestClientErrorHandling/InvalidAuthToken21832026/10/25 17:20:53 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLmYzZGM2MmYyLWIxZDgtNGU4MS05MGI2LTgwMGZmMWYxYWEwZXgxNzkyOTQ4ODUxNDcyMjQzMjg3 parts=1021842026/10/25 17:20:53 INFO Received uploads request method=POST path=/api/pending_closures2185=== CONT TestClientErrorHandling/ServerNotAvailable21862026/10/25 17:20:53 INFO Received uploads request method=POST path=/api/pending_closures21872026/10/25 17:20:53 INFO Aborted multipart uploads count=0 kept=021882026-10-25 17:20:53.364 UTC [178] LOG: checkpoints are occurring too frequently (10 seconds apart)21892026-10-25 17:20:53.364 UTC [178] HINT: Consider increasing the configuration parameter "max_wal_size".21902026-10-25 17:20:53.364 UTC [178] LOG: checkpoint starting: wal21912026/10/25 17:20:53 WARN Force mode enabled - objects will be deleted immediately without grace period21922026/10/25 17:20:53 INFO Received uploads request method=POST path=/api/pending_closures21932026/10/25 17:20:53 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=021942026/10/25 17:20:53 INFO Vacuumed table table=pending_closures21952026/10/25 17:20:53 INFO Vacuumed table table=pending_objects21962026/10/25 17:20:53 INFO Vacuumed table table=multipart_uploads21972026/10/25 17:20:53 INFO Vacuumed table table=closures21982026/10/25 17:20:53 INFO Vacuumed table table=objects2199=== CONT TestServerTLSConfig/no_client_CA2200=== CONT TestServerTLSConfig/not_a_PEM_file2201--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2202 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.74s)2203 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.79s)22042026/10/25 17:20:53 INFO Aborted multipart uploads count=0 kept=02205=== CONT TestServerTLSConfig/missing_CA_file2206--- PASS: TestServerTLSConfig (0.00s)2207 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2208 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2209 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2210=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected22112026/10/25 17:20:53 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]2212=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2213=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected22142026/10/25 17:20:53 WARN Force mode enabled - objects will be deleted immediately without grace period22152026/10/25 17:20:53 WARN Authentication failed token_preview=eyJhbGciOi...loexxKbXwA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2216=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2217=== CONT TestService_RequireScope_OIDC/builder_may_write22182026/10/25 17:20:53 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=02219=== CONT TestService_RequireScope_OIDC/static_token_may_write2220=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2221=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc22222026/10/25 17:20:53 INFO Vacuumed table table=pending_closures2223=== CONT TestService_RequireScope_OIDC/writer_implies_read2224=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read22252026/10/25 17:20:53 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]2226=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2227=== CONT TestService_RequireScope_OIDC/static_token_may_admin2228=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2229=== CONT TestService_RequireScope_OIDC/builder_may_not_admin22302026/10/25 17:20:53 INFO Vacuumed table table=pending_objects22312026/10/25 17:20:53 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/present2232=== CONT TestService_RequireScope_OIDC/reader_may_read22332026/10/25 17:20:53 INFO Vacuumed table table=multipart_uploads22342026/10/25 17:20:53 INFO Vacuumed table table=closures2235=== CONT TestService_RequireScope_OIDC/ops_may_not_write2236=== CONT TestService_RequireScope_OIDC/reader_may_not_write2237=== CONT TestService_RequireScope_OIDC/ops_may_admin22382026/10/25 17:20:53 INFO Vacuumed table table=objects2239=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2240=== CONT TestResolveDBConnectionString/nothing_configured2241=== CONT TestResolveDBConnectionString/file_when_flag_empty2242=== CONT TestResolveDBConnectionString/missing_file_is_an_error2243=== CONT TestResolveDBConnectionString/flag_wins2244--- PASS: TestResolveDBConnectionString (0.00s)2245 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2246 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2247 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2248 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2249 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2250--- PASS: TestService_AuthMiddleware_OIDC (0.43s)2251 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2252 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2253 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2254 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2255--- PASS: TestService_RequireScope_OIDC (0.50s)2256 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2257 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2258 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2259 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2260 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2261 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2262 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2263 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2264 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2265 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2266 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2267 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2268 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2269 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2270--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2271 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.28s)2272 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.27s)2273=== NAME TestOrphanedObjectsGCStressTest2274 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains22752026/10/25 17:20:53 WARN Request failed, retrying attempt=2 backoff=219.678413ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2276 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion22772026/10/25 17:20:53 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2278--- PASS: TestConnectSerialisesConcurrentMigrations (1.15s)22792026/10/25 17:20:53 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22802026/10/25 17:20:53 WARN Rate limiter enabled after throttle name=s3-test rate=522812026/10/25 17:20:53 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2282=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2283 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102284 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002285--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.38s)2286--- PASS: TestPendingClosureWriteTimeout (0.02s)2287 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2288 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2289 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2290 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.00s)22912026/10/25 17:20:53 WARN Request failed, retrying attempt=3 backoff=367.957947ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2292--- PASS: TestDeleteClosuresRacingPins (1.25s)22932026/10/25 17:20:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22942026/10/25 17:20:53 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLjIzMzQzMTViLWFlYTktNDg1Yy1hZDVlLTI0NjM3YzQyMTJjZXgxNzkyOTQ4ODUxNDcyMTY5NTE3 parts=1022952026/10/25 17:20:53 INFO lead: released remote=192.0.2.1:12342296--- PASS: TestLeadEndsOnShutdown (1.31s)2297=== NAME TestOrphanedObjectsGCStressTest2298 orphaned_objects_gc_test.go:503: Stress test completed successfully:22992026/10/25 17:20:53 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLjc1ODM1YjcxLTdmNTgtNDMyMi1iMDdlLTU1YmQ3ZGUyN2U5ZXgxNzkyOTQ4ODUzMzI3NjI5Mzkw error="Access Denied"2300 orphaned_objects_gc_test.go:504: - Active objects preserved: 2023012026/10/25 17:20:53 WARN keeping failed pending closure for cleanup to retry the abort id=12302 orphaned_objects_gc_test.go:505: - Objects deleted: 2102303 orphaned_objects_gc_test.go:506: - Total GC'd: 2102304--- PASS: TestPendingClosureFailureTracksEveryUpload (0.00s)2305 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (0.73s)2306 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (0.72s)2307--- PASS: TestOrphanedObjectsGCStressTest (3.56s)23082026/10/25 17:20:53 INFO lead: released remote=192.0.2.1:123423092026/10/25 17:20:53 INFO lead: acquired remote=192.0.2.1:123423102026/10/25 17:20:54 WARN Request failed, retrying attempt=4 backoff=745.325818ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23112026/10/25 17:20:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23122026/10/25 17:20:54 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=NzVhYTdlOTUtOTAwYS00MzY5LTlkNTktMTRjYzdkMjRiMTdmLmI2OGMwN2U1LWJiOWQtNGYwNy1iYTZlLWFiZTg0ZjMzOWQzNHgxNzkyOTQ4ODUxNDcyMjE1Mjk3 parts=1023132026-10-25 17:20:54.379 UTC [755] ERROR: could not obtain lock on row in relation "closures"23142026-10-25 17:20:54.379 UTC [755] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23152026-10-25 17:20:54.379 UTC [755] ERROR: could not obtain lock on row in relation "closures"23162026-10-25 17:20:54.379 UTC [755] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23172026-10-25 17:20:54.380 UTC [755] ERROR: could not obtain lock on row in relation "closures"23182026-10-25 17:20:54.380 UTC [755] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23192026-10-25 17:20:54.380 UTC [755] ERROR: could not obtain lock on row in relation "closures"23202026-10-25 17:20:54.380 UTC [755] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23212026-10-25 17:20:54.381 UTC [755] ERROR: could not obtain lock on row in relation "closures"23222026-10-25 17:20:54.381 UTC [755] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23232026/10/25 17:20:54 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=023242026/10/25 17:20:54 INFO Received create pin request method=POST path=/api/pins/myapp23252026/10/25 17:20:54 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2189252192/001/store/i9ainr8yg1vncsp022d2nn9h7gjvwc6v-pinned-file.txt narinfo_key=i9ainr8yg1vncsp022d2nn9h7gjvwc6v.narinfo23262026/10/25 17:20:54 INFO Starting cleanup of old closures method=DELETE path=/api/closures23272026/10/25 17:20:54 INFO Garbage collection started23282026/10/25 17:20:54 INFO Aborted multipart uploads count=0 kept=02329--- PASS: TestPush_RootsAreLockedInByteOrder (3.31s)23302026/10/25 17:20:54 WARN Force mode enabled - objects will be deleted immediately without grace period23312026/10/25 17:20:54 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=023322026/10/25 17:20:54 INFO Vacuumed table table=pending_closures23332026/10/25 17:20:54 INFO Vacuumed table table=pending_objects23342026/10/25 17:20:54 INFO Vacuumed table table=multipart_uploads23352026/10/25 17:20:54 INFO Vacuumed table table=closures23362026/10/25 17:20:54 INFO Vacuumed table table=objects2337--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.50s)23382026/10/25 17:20:54 WARN Request failed, retrying attempt=5 backoff=1.707268844s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23392026/10/25 17:20:54 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02340=== NAME TestClientIntegration2341 client_integration_test.go:445: Objects in database after GC:2342 client_integration_test.go:445: Successfully deleted all objects with GC --force2343--- PASS: TestClientIntegration (3.25s)23442026/10/25 17:20:54 INFO lead: released remote=192.0.2.1:12342345--- PASS: TestLeadElectsOneAndHandsOver (2.55s)2346=== NAME TestPinProtectsFromGC2347 client_integration_test.go:976: Pin successfully protected closure from garbage collection2348--- PASS: TestPinProtectsFromGC (4.98s)23492026/10/25 17:20:56 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-config23502026/10/25 17:20:56 WARN Request failed, retrying attempt=2 backoff=182.551487ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23512026/10/25 17:20:56 WARN Request failed, retrying attempt=3 backoff=438.275057ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23522026/10/25 17:20:57 WARN Request failed, retrying attempt=4 backoff=831.632182ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2353--- PASS: TestConnectWaitsForAPeerMigration (5.22s)23542026/10/25 17:20:57 INFO Aborted multipart uploads count=1 kept=023552026/10/25 17:20:57 INFO Received cleanup request method=DELETE path=/api/pending_closures23562026/10/25 17:20:57 INFO Aborted multipart uploads count=1 kept=02357--- PASS: TestPendingCleanupUsesOneCutoff (6.44s)23582026/10/25 17:20:58 WARN Request failed, retrying attempt=5 backoff=1.739991965s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2359--- PASS: TestUploadHandlersRejectOversizedBody (0.88s)2360 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.52s)2361 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.56s)2362 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (6.72s)23632026/10/25 17:20:59 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"23642026/10/25 17:20:59 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-config23652026/10/25 17:21:00 WARN Request failed, retrying attempt=2 backoff=190.185555ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23662026/10/25 17:21:00 WARN Request failed, retrying attempt=3 backoff=371.7084ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23672026/10/25 17:21:00 WARN Request failed, retrying attempt=4 backoff=853.989479ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23682026/10/25 17:21:01 WARN Request failed, retrying attempt=5 backoff=1.734631081s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23692026/10/25 17:21:03 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_closures23702026/10/25 17:21:03 WARN Request failed, retrying attempt=2 backoff=203.164965ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23712026/10/25 17:21:03 WARN Request failed, retrying attempt=3 backoff=415.442297ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23722026/10/25 17:21:03 WARN Request failed, retrying attempt=4 backoff=853.72627ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23732026/10/25 17:21:04 WARN Request failed, retrying attempt=5 backoff=1.578916757s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2374--- PASS: TestClientErrorHandling (0.00s)2375 --- PASS: TestClientErrorHandling/InvalidStorePath (0.27s)2376 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.26s)2377 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.00s)2378PASS2379{"timestamp":"2026-10-25T17:21:06.343372802Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:49990","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2386,"threadName":"rustfs-worker","threadId":"ThreadId(134)"}23802026-10-25 17:21:06.745 UTC [173] LOG: received smart shutdown request23812026-10-25 17:21:06.749 UTC [173] LOG: background worker "logical replication launcher" (PID 183) exited with exit code 123822026-10-25 17:21:07.760 UTC [178] LOG: checkpoint complete: wrote 9937 buffers (60.7%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=13.578 s, sync=0.755 s, total=14.397 s; sync files=37079, longest=0.009 s, average=0.001 s; distance=533142 kB, estimate=533142 kB; lsn=0/229D6B30, redo lsn=0/2200B57823832026-10-25 17:21:07.762 UTC [178] LOG: shutting down23842026-10-25 17:21:07.763 UTC [178] LOG: checkpoint starting: shutdown immediate23852026-10-25 17:21:07.815 UTC [178] LOG: checkpoint complete: wrote 269 buffers (1.6%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.007 s, sync=0.043 s, total=0.053 s; sync files=179, longest=0.001 s, average=0.001 s; distance=10029 kB, estimate=480830 kB; lsn=0/229D6BA8, redo lsn=0/229D6BA823862026-10-25 17:21:07.890 UTC [173] LOG: database system is shut down2387Running OIDC tests...2388=== RUN TestAudienceForIssuer2389=== PAUSE TestAudienceForIssuer2390=== RUN TestHTTPClientForHasTimeouts2391=== PAUSE TestHTTPClientForHasTimeouts2392=== RUN TestGlobMatch2393=== PAUSE TestGlobMatch2394=== RUN TestValidateToken_ValidToken2395=== PAUSE TestValidateToken_ValidToken2396=== RUN TestValidateToken_WrongAudience2397=== PAUSE TestValidateToken_WrongAudience2398=== RUN TestValidateToken_Expired2399=== PAUSE TestValidateToken_Expired2400=== RUN TestValidateToken_BoundClaimsMismatch2401=== PAUSE TestValidateToken_BoundClaimsMismatch2402=== RUN TestValidateToken_BoundSubjectMismatch2403=== PAUSE TestValidateToken_BoundSubjectMismatch2404=== RUN TestValidateToken_MultipleProviders2405=== PAUSE TestValidateToken_MultipleProviders2406=== RUN TestValidateToken_NoMatchingProvider2407=== PAUSE TestValidateToken_NoMatchingProvider2408=== RUN TestValidateToken_KubernetesServiceAccount2409=== PAUSE TestValidateToken_KubernetesServiceAccount2410=== RUN TestNewValidator_KubernetesRequiresCA2411=== PAUSE TestNewValidator_KubernetesRequiresCA2412=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2413=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2414=== RUN TestPins_ReservedForMatchingRule2415=== PAUSE TestPins_ReservedForMatchingRule2416=== RUN TestPins_TopLevelShorthand2417=== PAUSE TestPins_TopLevelShorthand2418=== RUN TestPins_ConfigValidation2419=== PAUSE TestPins_ConfigValidation2420=== RUN TestScopes_LegacyProviderDefaultsToWrite2421=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2422=== RUN TestScopes_Rules2423=== PAUSE TestScopes_Rules2424=== RUN TestScopes_ConfigValidation2425=== PAUSE TestScopes_ConfigValidation2426=== CONT TestAudienceForIssuer2427=== CONT TestNewValidator_KubernetesRequiresCA2428=== CONT TestPins_TopLevelShorthand2429--- PASS: TestAudienceForIssuer (0.00s)2430=== CONT TestScopes_Rules2431=== CONT TestGlobMatch2432=== RUN TestGlobMatch/foo_foo2433=== PAUSE TestGlobMatch/foo_foo2434=== RUN TestGlobMatch/foo_bar2435=== PAUSE TestGlobMatch/foo_bar2436=== RUN TestGlobMatch/*_2437=== CONT TestScopes_ConfigValidation2438=== CONT TestValidateToken_ValidToken2439=== CONT TestValidateToken_WrongAudience2440=== CONT TestHTTPClientForHasTimeouts2441=== CONT TestScopes_LegacyProviderDefaultsToWrite2442=== CONT TestPins_ReservedForMatchingRule2443=== CONT TestPins_ConfigValidation2444=== CONT TestValidateToken_NoMatchingProvider2445=== CONT TestValidateToken_MultipleProviders2446=== CONT TestValidateToken_BoundClaimsMismatch2447=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2448=== CONT TestValidateToken_BoundSubjectMismatch2449=== CONT TestValidateToken_KubernetesServiceAccount2450=== CONT TestValidateToken_Expired2451=== PAUSE TestGlobMatch/*_2452--- PASS: TestScopes_ConfigValidation (0.00s)2453--- PASS: TestPins_ConfigValidation (0.00s)2454=== RUN TestGlobMatch/*_anything2455=== PAUSE TestGlobMatch/*_anything2456=== RUN TestGlobMatch/foo*_foo2457=== PAUSE TestGlobMatch/foo*_foo2458=== RUN TestGlobMatch/foo*_foobar2459=== PAUSE TestGlobMatch/foo*_foobar2460=== RUN TestGlobMatch/foo*_bar2461=== PAUSE TestGlobMatch/foo*_bar2462=== RUN TestGlobMatch/*bar_bar2463=== PAUSE TestGlobMatch/*bar_bar2464=== RUN TestGlobMatch/*bar_foobar2465=== PAUSE TestGlobMatch/*bar_foobar2466=== RUN TestGlobMatch/*bar_foo2467=== PAUSE TestGlobMatch/*bar_foo2468=== RUN TestGlobMatch/foo*bar_foobar2469=== PAUSE TestGlobMatch/foo*bar_foobar2470=== RUN TestGlobMatch/foo*bar_foo123bar2471=== PAUSE TestGlobMatch/foo*bar_foo123bar2472=== RUN TestGlobMatch/foo*bar_foobarbaz2473=== PAUSE TestGlobMatch/foo*bar_foobarbaz2474=== RUN TestGlobMatch/*/*_foo/bar2475=== PAUSE TestGlobMatch/*/*_foo/bar2476=== RUN TestGlobMatch/*/*_foo2477=== PAUSE TestGlobMatch/*/*_foo2478=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2479=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2480=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02481=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02482=== RUN TestGlobMatch/refs/*/main_refs/heads/main2483=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2484=== RUN TestGlobMatch/fo?_foo2485=== PAUSE TestGlobMatch/fo?_foo2486=== RUN TestGlobMatch/fo?_fo2487=== PAUSE TestGlobMatch/fo?_fo2488=== RUN TestGlobMatch/fo?_fooo2489=== PAUSE TestGlobMatch/fo?_fooo2490=== RUN TestGlobMatch/?oo_foo2491=== PAUSE TestGlobMatch/?oo_foo2492=== RUN TestGlobMatch/?oo_boo2493=== PAUSE TestGlobMatch/?oo_boo2494=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2495=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2496=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2497=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2498=== CONT TestGlobMatch/*_2499=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02500=== CONT TestGlobMatch/foo*_foobar2501=== CONT TestGlobMatch/foo*_bar2502=== CONT TestGlobMatch/foo*_foo2503=== CONT TestGlobMatch/*_anything2504=== CONT TestGlobMatch/fo?_fo2505=== CONT TestGlobMatch/foo_bar2506=== CONT TestGlobMatch/foo_foo2507=== CONT TestGlobMatch/fo?_fooo2508=== CONT TestGlobMatch/refs/*/main_refs/heads/main2509=== CONT TestGlobMatch/*bar_foo2510=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2511=== CONT TestGlobMatch/?oo_foo2512=== CONT TestGlobMatch/?oo_boo2513=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2514=== CONT TestGlobMatch/foo*bar_foo123bar2515=== CONT TestGlobMatch/*/*_foo/bar2516=== CONT TestGlobMatch/foo*bar_foobar2517=== CONT TestGlobMatch/*bar_foobar2518=== CONT TestGlobMatch/foo*bar_foobarbaz2519=== CONT TestGlobMatch/*bar_bar2520=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2521=== CONT TestGlobMatch/*/*_foo2522=== CONT TestGlobMatch/fo?_foo2523--- PASS: TestGlobMatch (0.01s)2524 --- PASS: TestGlobMatch/*_ (0.00s)2525 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2526 --- PASS: TestGlobMatch/foo*_foo (0.00s)2527 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2528 --- PASS: TestGlobMatch/foo*_bar (0.00s)2529 --- PASS: TestGlobMatch/*_anything (0.00s)2530 --- PASS: TestGlobMatch/fo?_fo (0.00s)2531 --- PASS: TestGlobMatch/foo_bar (0.00s)2532 --- PASS: TestGlobMatch/foo_foo (0.00s)2533 --- PASS: TestGlobMatch/*bar_foo (0.00s)2534 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2535 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2536 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2537 --- PASS: TestGlobMatch/?oo_boo (0.00s)2538 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2539 --- PASS: TestGlobMatch/?oo_foo (0.00s)2540 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2541 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2542 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2543 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2544 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2545 --- PASS: TestGlobMatch/*bar_bar (0.00s)2546 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2547 --- PASS: TestGlobMatch/*/*_foo (0.00s)2548 --- PASS: TestGlobMatch/fo?_foo (0.00s)25492026/10/25 17:21:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39199/oidc25502026/10/25 17:21:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46249/oidc2551--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.03s)2552--- PASS: TestValidateToken_BoundSubjectMismatch (0.03s)25532026/10/25 17:21:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39851/oidc25542026/10/25 17:21:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37747/oidc2555--- PASS: TestValidateToken_ValidToken (0.04s)2556--- PASS: TestScopes_Rules (0.05s)25572026/10/25 17:21:10 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:4536525582026/10/25 17:21:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45161/oidc2559--- PASS: TestValidateToken_WrongAudience (0.09s)2560--- PASS: TestValidateToken_KubernetesServiceAccount (0.09s)25612026/10/25 17:21:10 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232562--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.12s)25632026/10/25 17:21:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38171/oidc2564--- PASS: TestPins_TopLevelShorthand (0.14s)25652026/10/25 17:21:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35003/oidc2566--- PASS: TestValidateToken_BoundClaimsMismatch (0.14s)25672026/10/25 17:21:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36969/oidc2568--- PASS: TestValidateToken_Expired (0.14s)25692026/10/25 17:21:10 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35869/oidc2570--- PASS: TestPins_ReservedForMatchingRule (0.15s)25712026/10/25 17:21:11 http: TLS handshake error from 127.0.0.1:46332: remote error: tls: bad certificate2572--- PASS: TestNewValidator_KubernetesRequiresCA (0.16s)25732026/10/25 17:21:11 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:39193/oidc25742026/10/25 17:21:11 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:45865/oidc2575--- PASS: TestValidateToken_MultipleProviders (0.20s)2576--- PASS: TestHTTPClientForHasTimeouts (0.20s)25772026/10/25 17:21:11 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33021/oidc2578--- PASS: TestValidateToken_NoMatchingProvider (0.31s)2579PASS2580Running hook tests...2581=== RUN TestSendPathsEmpty2582=== PAUSE TestSendPathsEmpty2583=== RUN TestQueueEnqueueAndFetch2584=== PAUSE TestQueueEnqueueAndFetch2585=== RUN TestQueueDeduplication2586=== PAUSE TestQueueDeduplication2587=== RUN TestQueueRemove2588=== PAUSE TestQueueRemove2589=== RUN TestQueueFetchBatchLimit2590=== PAUSE TestQueueFetchBatchLimit2591=== RUN TestQueueRetryMovesToBack2592=== PAUSE TestQueueRetryMovesToBack2593=== RUN TestQueueFetchRemoveLifecycle2594=== PAUSE TestQueueFetchRemoveLifecycle2595=== RUN TestQueueConcurrentWriters2596=== PAUSE TestQueueConcurrentWriters2597=== RUN TestQueueEnqueueWaitsOutSlowWriter2598=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2599=== RUN TestQueueRemoveLargeClosure2600=== PAUSE TestQueueRemoveLargeClosure2601=== RUN TestServerClientIntegration2602--- PASS: TestServerClientIntegration (0.00s)2603=== RUN TestServerQueueError26042026/10/25 17:21:12 ERROR Failed to queue paths error="permission denied" count=12605--- PASS: TestServerQueueError (0.00s)2606=== RUN TestServerRefusesOversizedAndNonStoreRequests2607=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2608=== RUN TestGetListenerSocketActivation2609 server_test.go:329: === RUN TestGetListenerSocketActivation2610 --- PASS: TestGetListenerSocketActivation (0.00s)2611 PASS2612 2613--- PASS: TestGetListenerSocketActivation (1.02s)2614=== RUN TestServerStalledClientDoesNotBlockShutdown2615=== PAUSE TestServerStalledClientDoesNotBlockShutdown2616=== RUN TestServerBacksOffOnAcceptErrors2617=== PAUSE TestServerBacksOffOnAcceptErrors2618=== RUN TestDrainIsolatesPoisonPath2619=== PAUSE TestDrainIsolatesPoisonPath2620=== RUN TestRunNotBlockedByPoisonHead2621=== PAUSE TestRunNotBlockedByPoisonHead2622=== RUN TestDrainGivesUpWhenServerDown2623=== PAUSE TestDrainGivesUpWhenServerDown2624=== RUN TestFailedPathPrunedByLaterClosure2625=== PAUSE TestFailedPathPrunedByLaterClosure2626=== RUN TestWorkerUploadsAndRemoves2627=== PAUSE TestWorkerUploadsAndRemoves2628=== RUN TestWorkerSkipsGCdPaths2629=== PAUSE TestWorkerSkipsGCdPaths2630=== RUN TestWorkerPrunesClosureDeps2631=== PAUSE TestWorkerPrunesClosureDeps2632=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2633=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2634=== RUN TestDrainTimeout2635=== PAUSE TestDrainTimeout2636=== RUN TestDrainTimeoutDuringIsolation2637=== PAUSE TestDrainTimeoutDuringIsolation2638=== RUN TestShutdownFinishesInFlightPush2639=== PAUSE TestShutdownFinishesInFlightPush2640=== RUN TestWorkerRemoveFailureIsNotProgress2641=== PAUSE TestWorkerRemoveFailureIsNotProgress2642=== RUN TestWorkerKeepsPathItCannotStat2643=== PAUSE TestWorkerKeepsPathItCannotStat2644=== CONT TestSendPathsEmpty2645=== CONT TestQueueRemoveLargeClosure2646=== CONT TestDrainIsolatesPoisonPath2647=== CONT TestServerBacksOffOnAcceptErrors2648=== CONT TestServerStalledClientDoesNotBlockShutdown26492026/10/25 17:21:13 ERROR Accept failed error="too many open files"2650=== CONT TestServerRefusesOversizedAndNonStoreRequests2651=== CONT TestWorkerKeepsPathItCannotStat2652=== CONT TestWorkerRemoveFailureIsNotProgress2653=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2654=== CONT TestDrainTimeoutDuringIsolation2655=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2656=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path26572026/10/25 17:21:13 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2658=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2659=== CONT TestQueueConcurrentWriters26602026/10/25 17:21:13 ERROR Refusing path outside the store path=/nix/store store=/nix/store2661=== CONT TestDrainTimeout2662=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure26632026/10/25 17:21:13 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store2664=== CONT TestWorkerPrunesClosureDeps26652026/10/25 17:21:13 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store2666=== CONT TestWorkerUploadsAndRemoves2667=== CONT TestWorkerSkipsGCdPaths2668=== CONT TestQueueEnqueueWaitsOutSlowWriter2669=== CONT TestFailedPathPrunedByLaterClosure26702026/10/25 17:21:13 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store2671=== CONT TestRunNotBlockedByPoisonHead2672=== CONT TestDrainGivesUpWhenServerDown2673=== CONT TestQueueDeduplication26742026/10/25 17:21:13 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store2675=== CONT TestQueueRemove2676=== CONT TestQueueFetchBatchLimit2677=== CONT TestQueueEnqueueAndFetch26782026/10/25 17:21:13 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store2679=== CONT TestQueueRetryMovesToBack2680--- PASS: TestSendPathsEmpty (0.00s)2681=== CONT TestShutdownFinishesInFlightPush2682=== RUN TestShutdownFinishesInFlightPush/completes2683=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch26842026/10/25 17:21:13 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store2685=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline26862026/10/25 17:21:13 ERROR Accept failed error="too many open files"2687=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2688=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2689=== PAUSE TestShutdownFinishesInFlightPush/completes2690=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline26912026/10/25 17:21:13 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store2692=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2693=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2694=== CONT TestQueueFetchRemoveLifecycle2695=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2696=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline26972026/10/25 17:21:13 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store2698=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short26992026/10/25 17:21:13 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store27002026/10/25 17:21:13 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store27012026/10/25 17:21:13 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store27022026/10/25 17:21:13 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store27032026/10/25 17:21:13 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store27042026/10/25 17:21:13 ERROR Failed to decode request error="unexpected EOF"2705--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2706=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths27072026/10/25 17:21:13 ERROR Accept failed error="too many open files"27082026/10/25 17:21:13 ERROR Accept failed error="too many open files"27092026/10/25 17:21:13 INFO Uploading batch count=227102026/10/25 17:21:13 INFO Uploading batch count=127112026/10/25 17:21:13 ERROR Upload failed error="upload failed" count=127122026/10/25 17:21:13 INFO Upload queue status pending=227132026/10/25 17:21:13 INFO Upload queue status pending=227142026/10/25 17:21:13 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat4281161791/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat4281161791/002/locked/aaa: permission denied"27152026/10/25 17:21:13 INFO Uploading batch count=127162026/10/25 17:21:13 INFO Uploading batch count=427172026/10/25 17:21:13 ERROR Upload failed error="upload failed" count=427182026/10/25 17:21:13 INFO Upload queue status pending=327192026/10/25 17:21:13 INFO Uploading batch count=227202026/10/25 17:21:13 INFO Upload queue status pending=22721=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch27222026/10/25 17:21:13 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2027068009/002/nonexistent2723--- PASS: TestQueueFetchBatchLimit (0.05s)27242026/10/25 17:21:13 INFO Uploading batch count=127252026/10/25 17:21:13 INFO Uploading batch count=427262026/10/25 17:21:13 ERROR Upload failed error="upload failed" count=427272026/10/25 17:21:13 INFO Uploading batch count=227282026/10/25 17:21:13 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat4281161791/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat4281161791/002/locked/aaa: permission denied"2729--- PASS: TestQueueRemove (0.05s)2730=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27312026/10/25 17:21:13 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1108078009/002/bbb27322026/10/25 17:21:13 INFO Uploading batch count=22733--- PASS: TestQueueDeduplication (0.05s)2734=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout27352026/10/25 17:21:13 INFO Upload queue status pending=32736--- PASS: TestQueueEnqueueAndFetch (0.05s)2737=== CONT TestShutdownFinishesInFlightPush/completes27382026/10/25 17:21:13 INFO Uploading batch count=127392026/10/25 17:21:13 ERROR Upload failed error="upload failed" count=127402026/10/25 17:21:13 INFO Uploading batch count=227412026/10/25 17:21:13 ERROR Upload failed error="upload failed" count=227422026/10/25 17:21:13 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown873274165/002/a27432026/10/25 17:21:13 INFO Uploading batch count=427442026/10/25 17:21:13 INFO Uploading batch count=127452026/10/25 17:21:13 ERROR Upload failed error="upload failed" count=42746--- PASS: TestQueueRetryMovesToBack (0.05s)27472026/10/25 17:21:13 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat4281161791/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat4281161791/002/locked/aaa: permission denied"27482026/10/25 17:21:13 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown873274165/002/b2749--- PASS: TestQueueFetchRemoveLifecycle (0.06s)27502026/10/25 17:21:13 INFO Uploading batch count=227512026/10/25 17:21:13 INFO Uploading batch count=127522026/10/25 17:21:13 ERROR Upload failed error="upload failed" count=127532026/10/25 17:21:13 ERROR Upload failed error="upload failed" count=227542026/10/25 17:21:13 ERROR Drain finished with paths left in queue remaining=127552026/10/25 17:21:13 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown873274165/002/c27562026/10/25 17:21:13 INFO Uploading batch count=127572026/10/25 17:21:13 ERROR Upload failed error="upload failed" count=127582026/10/25 17:21:13 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown873274165/002/d2759--- PASS: TestWorkerKeepsPathItCannotStat (0.07s)27602026/10/25 17:21:13 INFO Uploading batch count=127612026/10/25 17:21:13 ERROR Upload failed error="upload failed" count=127622026/10/25 17:21:13 INFO Uploading batch count=227632026/10/25 17:21:13 ERROR Upload failed error="upload failed" count=227642026/10/25 17:21:13 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown873274165/002/e2765--- PASS: TestFailedPathPrunedByLaterClosure (0.07s)27662026/10/25 17:21:13 INFO Uploading batch count=227672026/10/25 17:21:13 ERROR Drain finished with paths left in queue remaining=127682026/10/25 17:21:13 ERROR Upload failed error="upload failed" count=227692026/10/25 17:21:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127702026/10/25 17:21:13 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown873274165/002/f27712026/10/25 17:21:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127722026/10/25 17:21:13 INFO Uploading batch count=227732026/10/25 17:21:13 ERROR Upload failed error="upload failed" count=227742026/10/25 17:21:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127752026/10/25 17:21:13 ERROR Drain finished with paths left in queue remaining=1027762026/10/25 17:21:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127772026/10/25 17:21:13 INFO Upload queue status pending=227782026/10/25 17:21:13 INFO Uploading batch count=22779--- PASS: TestDrainIsolatesPoisonPath (0.08s)27802026/10/25 17:21:13 ERROR Upload failed error="upload failed" count=227812026/10/25 17:21:13 INFO Upload queue status pending=227822026/10/25 17:21:13 INFO Uploading batch count=227832026/10/25 17:21:13 ERROR Accept failed error="too many open files"27842026/10/25 17:21:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=12785--- PASS: TestWorkerPrunesClosureDeps (0.07s)2786--- PASS: TestWorkerUploadsAndRemoves (0.07s)27872026/10/25 17:21:13 INFO Uploading batch count=227882026/10/25 17:21:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127892026/10/25 17:21:13 ERROR Drain finished with paths left in queue remaining=22790--- PASS: TestWorkerSkipsGCdPaths (0.08s)2791--- PASS: TestDrainGivesUpWhenServerDown (0.08s)2792--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.08s)27932026/10/25 17:21:13 INFO Uploading batch count=227942026/10/25 17:21:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227952026/10/25 17:21:13 INFO Uploading batch count=227962026/10/25 17:21:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227972026/10/25 17:21:13 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path476882761/001/nonexistent27982026/10/25 17:21:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127992026/10/25 17:21:13 INFO Uploading batch count=228002026/10/25 17:21:13 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path476882761/001/nonexistent28012026/10/25 17:21:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228022026/10/25 17:21:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128032026/10/25 17:21:13 ERROR Drain finished with paths left in queue remaining=228042026/10/25 17:21:13 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path476882761/001/nonexistent28052026/10/25 17:21:13 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128062026/10/25 17:21:13 ERROR Drain finished with paths left in queue remaining=12807--- PASS: TestWorkerRemoveFailureIsNotProgress (0.01s)2808 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.07s)2809 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.03s)2810 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.03s)28112026/10/25 17:21:13 ERROR Accept failed error="too many open files"28122026/10/25 17:21:13 ERROR Failed to decode request error="read unix /build/hook1712352336/test.sock->@: i/o timeout"28132026/10/25 17:21:13 ERROR Failed to write response error="write unix /build/hook1712352336/test.sock->@: i/o timeout"2814--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)28152026/10/25 17:21:13 ERROR Upload failed error="context canceled" count=228162026/10/25 17:21:13 ERROR Drain finished with paths left in queue remaining=42817--- PASS: TestDrainTimeout (0.25s)28182026/10/25 17:21:13 ERROR Drain finished with paths left in queue remaining=428192026/10/25 17:21:13 ERROR Upload failed error="context canceled" count=228202026/10/25 17:21:13 ERROR Drain finished with paths left in queue remaining=22821--- PASS: TestShutdownFinishesInFlightPush (0.00s)2822 --- PASS: TestShutdownFinishesInFlightPush/completes (0.13s)2823 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.22s)28242026/10/25 17:21:13 ERROR Accept failed error="too many open files"28252026/10/25 17:21:13 ERROR Drain finished with paths left in queue remaining=32826--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2827 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.26s)2828 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.36s)2829--- PASS: TestQueueConcurrentWriters (0.52s)28302026/10/25 17:21:13 ERROR Accept failed error="too many open files"2831--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)28322026/10/25 17:21:14 INFO Uploading batch count=128332026/10/25 17:21:14 INFO Uploading batch count=128342026/10/25 17:21:14 INFO Uploading batch count=128352026/10/25 17:21:14 ERROR Upload failed error="upload failed" count=128362026/10/25 17:21:14 INFO Uploading batch count=128372026/10/25 17:21:14 ERROR Upload failed error="upload failed" count=128382026/10/25 17:21:14 INFO Uploading batch count=128392026/10/25 17:21:14 ERROR Upload failed error="upload failed" count=128402026/10/25 17:21:14 INFO Uploading batch count=128412026/10/25 17:21:14 ERROR Upload failed error="upload failed" count=128422026/10/25 17:21:14 ERROR Drain finished with paths left in queue remaining=12843--- PASS: TestRunNotBlockedByPoisonHead (1.08s)2844--- PASS: TestQueueRemoveLargeClosure (1.25s)2845--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.06s)2846PASS2847Running signing tests...2848=== RUN TestExternalSigner2849=== PAUSE TestExternalSigner2850=== RUN TestExternalSignerWrongPublicKey2851=== PAUSE TestExternalSignerWrongPublicKey2852=== RUN TestExternalSignerErrors2853=== PAUSE TestExternalSignerErrors2854=== RUN TestExternalSignerRestartsAfterCrash2855=== PAUSE TestExternalSignerRestartsAfterCrash2856=== RUN TestExternalSignerProgramErrorKeepsProcess2857=== PAUSE TestExternalSignerProgramErrorKeepsProcess2858=== RUN TestExternalSignerClose2859=== PAUSE TestExternalSignerClose2860=== RUN TestExternalSignerRejectsInvalidPublicKey2861=== PAUSE TestExternalSignerRejectsInvalidPublicKey2862=== RUN TestExternalSignerCancellation2863=== PAUSE TestExternalSignerCancellation2864=== RUN TestGenerateFingerprint2865=== PAUSE TestGenerateFingerprint2866=== RUN TestParseSigningKey2867=== PAUSE TestParseSigningKey2868=== RUN TestSign2869=== PAUSE TestSign2870=== RUN TestSignBatch2871=== PAUSE TestSignBatch2872=== RUN TestNilKeyPublicKey2873=== PAUSE TestNilKeyPublicKey2874=== RUN TestSignErrors2875=== PAUSE TestSignErrors2876=== CONT TestExternalSigner2877=== CONT TestExternalSignerRejectsInvalidPublicKey2878=== CONT TestSign2879=== CONT TestSignErrors2880=== CONT TestSignBatch2881=== CONT TestExternalSignerErrors2882=== CONT TestExternalSignerRestartsAfterCrash2883=== RUN TestExternalSignerErrors/exit_at_startup2884=== CONT TestGenerateFingerprint2885=== CONT TestParseSigningKey2886=== CONT TestExternalSignerClose2887=== CONT TestExternalSignerWrongPublicKey2888=== CONT TestExternalSignerProgramErrorKeepsProcess2889=== CONT TestNilKeyPublicKey2890=== CONT TestExternalSignerCancellation2891=== RUN TestExternalSignerRejectsInvalidPublicKey/#002892=== RUN TestParseSigningKey/valid_32-byte_key2893=== PAUSE TestExternalSignerErrors/exit_at_startup2894=== RUN TestGenerateFingerprint/basic_with_references2895--- PASS: TestNilKeyPublicKey (0.00s)2896=== PAUSE TestParseSigningKey/valid_32-byte_key2897=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002898=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2899=== RUN TestExternalSignerErrors/invalid_JSON2900=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2901=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2902=== PAUSE TestGenerateFingerprint/basic_with_references2903=== RUN TestSignErrors/nil_key2904=== RUN TestGenerateFingerprint/no_references2905=== PAUSE TestSignErrors/nil_key2906=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2907=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2908=== PAUSE TestExternalSignerErrors/invalid_JSON2909=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2910=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2911=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2912=== RUN TestSignErrors/nil_narinfo2913=== RUN TestParseSigningKey/no_colon2914--- PASS: TestSign (0.00s)2915=== PAUSE TestGenerateFingerprint/no_references2916=== RUN TestExternalSignerErrors/wrong_shape2917=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2918=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2919=== PAUSE TestSignErrors/nil_narinfo2920--- PASS: TestExternalSignerClose (0.00s)2921=== PAUSE TestParseSigningKey/no_colon2922=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2923=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2924=== RUN TestParseSigningKey/empty_name2925=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2926=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2927=== CONT TestExternalSignerRejectsInvalidPublicKey/#002928=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2929=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2930=== RUN TestSignErrors/invalid_narinfo2931=== PAUSE TestExternalSignerErrors/wrong_shape2932=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2933=== PAUSE TestParseSigningKey/empty_name2934--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2935=== RUN TestParseSigningKey/invalid_base642936=== RUN TestExternalSignerErrors/missing_signatures2937=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2938=== PAUSE TestExternalSignerErrors/missing_signatures2939=== RUN TestGenerateFingerprint/invalid_nar_hash_length2940=== PAUSE TestSignErrors/invalid_narinfo2941=== PAUSE TestParseSigningKey/invalid_base642942--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.01s)2943 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2944 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2945 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2946 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2947 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2948=== RUN TestExternalSignerErrors/too_few_signatures2949=== PAUSE TestExternalSignerErrors/too_few_signatures2950=== RUN TestExternalSignerErrors/null2951=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2952=== RUN TestGenerateFingerprint/invalid_store_path_prefix2953=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2954=== RUN TestSignErrors/canceled2955=== RUN TestParseSigningKey/wrong_length2956--- PASS: TestExternalSignerWrongPublicKey (0.01s)2957=== PAUSE TestExternalSignerErrors/null2958=== RUN TestGenerateFingerprint/invalid_reference_prefix2959=== RUN TestExternalSignerErrors/null_signatures2960=== PAUSE TestSignErrors/canceled2961=== PAUSE TestParseSigningKey/wrong_length2962=== CONT TestSignErrors/nil_narinfo2963=== CONT TestParseSigningKey/valid_32-byte_key2964=== CONT TestParseSigningKey/empty_name2965=== PAUSE TestExternalSignerErrors/null_signatures2966=== CONT TestParseSigningKey/no_colon2967=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2968=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2969=== CONT TestGenerateFingerprint/invalid_reference_prefix2970=== CONT TestGenerateFingerprint/no_references2971=== CONT TestSignErrors/invalid_narinfo2972=== CONT TestSignErrors/canceled2973=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2974=== CONT TestParseSigningKey/wrong_length2975=== CONT TestParseSigningKey/invalid_base642976--- PASS: TestSignBatch (0.01s)2977=== RUN TestExternalSignerErrors/wrong_signature_length2978=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2979=== CONT TestGenerateFingerprint/invalid_store_path_prefix2980=== CONT TestSignErrors/nil_key2981=== CONT TestGenerateFingerprint/basic_with_references2982=== CONT TestGenerateFingerprint/invalid_nar_hash_length2983=== PAUSE TestExternalSignerErrors/wrong_signature_length2984--- PASS: TestSignErrors (0.01s)2985 --- PASS: TestSignErrors/nil_narinfo (0.00s)2986 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2987 --- PASS: TestSignErrors/canceled (0.00s)2988 --- PASS: TestSignErrors/nil_key (0.00s)2989--- PASS: TestParseSigningKey (0.01s)2990 --- PASS: TestParseSigningKey/empty_name (0.00s)2991 --- PASS: TestParseSigningKey/no_colon (0.00s)2992 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2993 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2994 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2995 --- PASS: TestParseSigningKey/wrong_length (0.00s)2996=== RUN TestExternalSignerErrors/unrequested_key2997=== PAUSE TestExternalSignerErrors/unrequested_key2998--- PASS: TestGenerateFingerprint (0.01s)2999 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)3000 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)3001 --- PASS: TestGenerateFingerprint/no_references (0.00s)3002 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)3003 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)3004 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)3005 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)3006=== RUN TestExternalSignerErrors/missing_signature_name3007=== PAUSE TestExternalSignerErrors/missing_signature_name3008=== RUN TestExternalSignerErrors/program_error3009=== PAUSE TestExternalSignerErrors/program_error3010=== RUN TestExternalSignerErrors/exit_on_request3011=== PAUSE TestExternalSignerErrors/exit_on_request3012=== RUN TestExternalSignerErrors/wrong_id3013=== PAUSE TestExternalSignerErrors/wrong_id3014=== RUN TestExternalSignerErrors/wrong_signatures_shape3015=== PAUSE TestExternalSignerErrors/wrong_signatures_shape3016=== RUN TestExternalSignerErrors/wrong_signature_name3017=== PAUSE TestExternalSignerErrors/wrong_signature_name3018=== RUN TestExternalSignerErrors/invalid_signature_base643019=== PAUSE TestExternalSignerErrors/invalid_signature_base643020=== CONT TestExternalSignerErrors/invalid_JSON3021=== CONT TestExternalSignerErrors/program_error3022=== CONT TestExternalSignerErrors/wrong_signature_length3023=== CONT TestExternalSignerErrors/invalid_signature_base643024--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)3025=== CONT TestExternalSignerErrors/wrong_signatures_shape3026=== CONT TestExternalSignerErrors/wrong_id3027=== CONT TestExternalSignerErrors/exit_on_request3028=== CONT TestExternalSignerErrors/missing_signature_name3029=== CONT TestExternalSignerErrors/null3030=== CONT TestExternalSignerErrors/unrequested_key3031=== CONT TestExternalSignerErrors/wrong_signature_name3032=== CONT TestExternalSignerErrors/too_few_signatures3033=== CONT TestExternalSignerErrors/null_signatures3034=== CONT TestExternalSignerErrors/exit_at_startup3035=== CONT TestExternalSignerErrors/wrong_shape3036=== CONT TestExternalSignerErrors/missing_signatures3037--- PASS: TestExternalSigner (0.01s)3038--- PASS: TestExternalSignerErrors (0.01s)3039 --- PASS: TestExternalSignerErrors/invalid_JSON (0.00s)3040 --- PASS: TestExternalSignerErrors/program_error (0.00s)3041 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.00s)3042 --- PASS: TestExternalSignerErrors/wrong_id (0.00s)3043 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.00s)3044 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)3045 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)3046 --- PASS: TestExternalSignerErrors/null_signatures (0.00s)3047 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)3048 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)3049 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)3050 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)3051 --- PASS: TestExternalSignerErrors/null (0.01s)3052 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)3053 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)3054 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)3055--- PASS: TestExternalSignerCancellation (0.02s)3056PASS3057Running OpenBao signer tests...3058=== RUN TestSign3059=== PAUSE TestSign3060=== RUN TestSignErrors3061=== PAUSE TestSignErrors3062=== RUN TestServe3063=== PAUSE TestServe3064=== RUN TestServeRejectsGarbage3065=== PAUSE TestServeRejectsGarbage3066=== CONT TestServeRejectsGarbage3067=== CONT TestSignErrors3068=== CONT TestServe3069=== CONT TestSign3070--- PASS: TestServeRejectsGarbage (0.00s)3071=== RUN TestSignErrors/http_error3072=== PAUSE TestSignErrors/http_error3073--- PASS: TestServe (0.00s)3074=== RUN TestSignErrors/invalid_json3075=== PAUSE TestSignErrors/invalid_json3076=== RUN TestSignErrors/no_prefix3077=== PAUSE TestSignErrors/no_prefix3078=== RUN TestSignErrors/invalid_base643079=== PAUSE TestSignErrors/invalid_base643080=== CONT TestSignErrors/http_error3081=== CONT TestSignErrors/invalid_json3082=== CONT TestSignErrors/no_prefix3083=== CONT TestSignErrors/invalid_base643084--- PASS: TestSign (0.01s)3085--- PASS: TestSignErrors (0.00s)3086 --- PASS: TestSignErrors/no_prefix (0.00s)3087 --- PASS: TestSignErrors/invalid_base64 (0.00s)3088 --- PASS: TestSignErrors/http_error (0.00s)3089 --- PASS: TestSignErrors/invalid_json (0.00s)3090PASS3091Running niks3-hook command tests...3092=== RUN TestServeSecondSignalEndsDrain3093=== PAUSE TestServeSecondSignalEndsDrain3094=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown3095=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown3096=== CONT TestServeSecondSignalEndsDrain3097=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown3098--- PASS: TestServeSecondSignalEndsDrain (0.08s)30992026/10/25 17:21:22 INFO Upload queue status pending=131002026/10/25 17:21:22 INFO Uploading batch count=13101--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.13s)3102PASS3103Running rate limiter tests...3104=== RUN TestAdaptiveRateLimiter_ThreadSafety3105=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3106=== CONT TestAdaptiveRateLimiter_ThreadSafety31072026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=7031082026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=4931092026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=34.331102026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=24.00999999999999831112026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=16.80731122026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=11.76489999999999931132026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=8.2354331142026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=5.76480099999999931152026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531162026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531172026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531182026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531192026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531202026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531212026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531222026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531232026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531242026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531252026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531262026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531272026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531282026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=5.63678500000000131292026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531302026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531312026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531322026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531332026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531342026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531352026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531362026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=5.63678500000000131372026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531382026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531392026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531402026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531412026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531422026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531432026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531442026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531452026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=5.12435000000000131462026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531472026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531482026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531492026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531502026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531512026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531522026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531532026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531542026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531552026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531562026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531572026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531582026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531592026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531602026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531612026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531622026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531632026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531642026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531652026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531662026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531672026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531682026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531692026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531702026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531712026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531722026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531732026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531742026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531752026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531762026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531772026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531782026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=8.25281691850000431792026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=5.77697184295000331802026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531812026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531822026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531832026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=5.12435000000000131842026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531852026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531862026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531872026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531882026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531892026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531902026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531912026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531922026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531932026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531942026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531952026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531962026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531972026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531982026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=531992026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=532002026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=532012026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=532022026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=532032026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=532042026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=532052026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=532062026/10/25 17:21:23 WARN Rate limiter backed off name=test rate=53207--- PASS: TestAdaptiveRateLimiter_ThreadSafety (3.45s)3208PASS