niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #436
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure18=== PAUSE TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure19=== RUN TestUploadMultipart_PartsInParallel20=== PAUSE TestUploadMultipart_PartsInParallel21=== RUN TestUploadMultipart_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.04s)31=== RUN TestDumpPathCaseHackCollision32--- PASS: TestDumpPathCaseHackCollision (0.00s)33=== RUN TestSupersededNARStillUploadsListing34=== PAUSE TestSupersededNARStillUploadsListing35=== RUN TestTruncatedNARDumpIsNotCompleted36=== PAUSE TestTruncatedNARDumpIsNotCompleted37=== RUN TestDumpPathMatchesNix38=== PAUSE TestDumpPathMatchesNix39=== RUN TestDumpPathSingleFile40=== PAUSE TestDumpPathSingleFile41=== RUN TestDumpPathWriterError42=== PAUSE TestDumpPathWriterError43=== RUN TestDumpPathWriterErrorStopsReading44 nar_test.go:289: read 114 of 32768000 bytes45--- PASS: TestDumpPathWriterErrorStopsReading (0.73s)46=== RUN TestEncodeNixBase3247=== PAUSE TestEncodeNixBase3248=== RUN TestEncodeNixBase32WithRealHash49=== PAUSE TestEncodeNixBase32WithRealHash50=== RUN TestConvertHashToNix3251=== PAUSE TestConvertHashToNix3252=== RUN TestGetStorePathHash53=== PAUSE TestGetStorePathHash54=== RUN TestPathInfoHashCompatibility55=== PAUSE TestPathInfoHashCompatibility56=== RUN TestParsePathInfoJSON57=== PAUSE TestParsePathInfoJSON58=== RUN TestParsePathInfoJSONMultiplePaths59=== PAUSE TestParsePathInfoJSONMultiplePaths60=== RUN TestPathInfoCACompatibility61=== PAUSE TestPathInfoCACompatibility62=== RUN TestUploadPendingObjectsStopsStartingAfterFailure63--- PASS: TestUploadPendingObjectsStopsStartingAfterFailure (0.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 TestUploadBuildLog_FileBodyReplayedOnRetry135=== CONT TestScriptTokenScriptFails136=== CONT TestScriptTokenEmptyCommand137=== CONT TestStreamPushStopsOnCancel138=== CONT TestParsePathInfoJSON139=== CONT TestStreamPushStopsWhenCanceled140=== RUN TestStreamPushStopsOnCancel/waiting_for_input141=== CONT TestScriptTokenDoesNotWaitForItsChildren142=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input143=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs144=== RUN TestParsePathInfoJSON/Nix_format145=== CONT TestShellSplitErrors146=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs147=== PAUSE TestParsePathInfoJSON/Nix_format148=== CONT TestResolveStorePath149=== CONT TestPartSizeForNAR150=== RUN TestPartSizeForNAR/zero_stays_at_minimum151=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum152=== CONT TestShellSplit153=== RUN TestParsePathInfoJSON/Lix_format154=== CONT TestDoWithRetry_FinalResponseBodyReadable155=== CONT TestPathInfoCACompatibility156=== CONT TestStreamPushIsolatesFailures157=== CONT TestParsePathInfoJSONMultiplePaths158=== CONT TestStreamPushRequestLine159=== CONT TestCompletePendingClosure_NotFoundWithoutKey160=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess161=== CONT TestScriptTokenNoExpiryRerunsEveryCall162=== CONT TestSetClientTLS163=== CONT TestScriptTokenEmptyToken164=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent165=== CONT TestEncodeNixBase32WithRealHash166=== CONT TestGetStorePathHash167--- PASS: TestScriptTokenEmptyCommand (0.00s)168=== CONT TestDumpPathMatchesNix169=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot170=== CONT TestUploadMultipart_ProducerErrorIsNotEOF171=== CONT TestRetryTimeoutOutlastsMaxRetries172=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout173=== RUN TestPartSizeForNAR/small_stays_at_minimum174=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun175=== PAUSE TestParsePathInfoJSON/Lix_format176=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure177=== RUN TestPathInfoCACompatibility/null_ca_field178=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths179=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica180=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier181=== RUN TestGetStorePathHash/valid_store_path182--- PASS: TestStreamPushStopsWhenCanceled (0.00s)183=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part184=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths185--- PASS: TestShellSplitErrors (0.00s)186--- PASS: TestShellSplit (0.00s)187--- PASS: TestScriptTokenScriptFails (0.00s)188=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths189=== RUN TestParsePathInfoJSON/empty_input190=== CONT TestSetClientTLSDoesNotMutateDefaultTransport191=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot192=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier193=== PAUSE TestGetStorePathHash/valid_store_path194=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part195=== PAUSE TestParsePathInfoJSON/empty_input196=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary197=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary198--- PASS: TestResolveStorePath (0.00s)199--- PASS: TestEncodeNixBase32WithRealHash (0.00s)200=== PAUSE TestPathInfoCACompatibility/null_ca_field201=== RUN TestPathInfoCACompatibility/old_string_format_-_text202=== PAUSE TestPartSizeForNAR/small_stays_at_minimum203=== RUN TestParsePathInfoJSON/whitespace_only204=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text205=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot206=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum207=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout208=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths209=== CONT TestSetClientTLSErrors210--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.01s)211=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive212=== RUN TestGetStorePathHash/basename_without_hyphen_should_error213=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive214=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot215=== PAUSE TestParsePathInfoJSON/whitespace_only216=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up217=== RUN TestPathInfoCACompatibility/new_structured_format_-_text218=== CONT TestStreamPushBatchesUnderLoad219=== CONT TestStreamPushGivesUpOnDeadServer220=== RUN TestStreamPushBatchesUnderLoad/together221--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)222=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text223=== RUN TestParsePathInfoJSON/invalid_JSON224=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up225=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error226=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum227=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error228=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot229=== CONT TestDoWithRetry_BodyReplayedViaGetBody230=== CONT TestStreamPushReportsEveryPath231=== PAUSE TestStreamPushBatchesUnderLoad/together232=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time233=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method234=== PAUSE TestParsePathInfoJSON/invalid_JSON235=== CONT TestFileTokenEmpty236=== CONT TestUploadMultipart_SupersededByPeer237--- PASS: TestStreamPushIsolatesFailures (0.01s)238=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier239=== CONT TestStreamPushReportsSignatures240=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts241=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error242=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot243=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time244=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts245=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot246=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method247=== CONT TestRateLimiterFeedback248=== RUN TestUploadMultipart_SupersededByPeer/exists249--- PASS: TestScriptTokenEmptyToken (0.01s)250=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier251=== CONT TestPathInfoHashCompatibility252=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error253=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client254=== RUN TestPartSizeForNAR/1_TiB255=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot256=== CONT TestScriptTokenCachesUntilRefresh257=== RUN TestRateLimiterFeedback/429_enables_limiter258=== PAUSE TestUploadMultipart_SupersededByPeer/exists259--- PASS: TestStreamPushReportsEveryPath (0.00s)260=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error261=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)262=== CONT TestStreamPushReportsSkippedPaths263=== CONT TestDumpPathSingleFile264=== CONT TestTruncatedNARDumpIsNotCompleted265=== RUN TestSetClientTLSErrors/missing_cert_file266=== CONT TestClientSignaturesByStorePath267=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer268=== CONT TestEncodeNixBase32269=== CONT TestCaseHackSuffix270=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client271=== RUN TestEncodeNixBase32/test_string_hash272=== CONT TestDumpPathWriterError273=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client274=== CONT TestScriptTokenBadJSON275=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client276=== PAUSE TestEncodeNixBase32/test_string_hash277=== RUN TestEncodeNixBase32/empty_input278=== PAUSE TestPartSizeForNAR/1_TiB279=== RUN TestPartSizeForNAR/5_TiB_S3_max_object280=== PAUSE TestRateLimiterFeedback/429_enables_limiter281=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken282=== RUN TestUploadMultipart_SupersededByPeer/missing283=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken284--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)285=== CONT TestConvertHashToNix32286=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)287=== PAUSE TestSetClientTLSErrors/missing_cert_file288=== CONT TestSupersededNARStillUploadsListing289=== CONT TestRegisterUploadedObjectReusesConnections290=== PAUSE TestEncodeNixBase32/empty_input291=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object292=== PAUSE TestUploadMultipart_SupersededByPeer/missing293--- PASS: TestFileTokenEmpty (0.00s)294=== CONT TestFileTokenMissing295=== RUN TestRateLimiterFeedback/503_enables_limiter296=== RUN TestSetClientTLS/rejects_connection_without_client_cert297=== RUN TestConvertHashToNix32/SRI_format_to_Nix32298=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon299=== RUN TestSetClientTLSErrors/missing_key_file300=== RUN TestSupersededNARStillUploadsListing/small_NAR301=== RUN TestPartSizeForNAR/capped_at_5_GiB302--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.02s)303=== CONT TestFilterOversizedClosures304=== CONT TestUploadMultipart_PartsInParallel305=== PAUSE TestRateLimiterFeedback/503_enables_limiter306=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32307=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon308=== CONT TestFileTokenReadsAndCaches309=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert310=== PAUSE TestSetClientTLSErrors/missing_key_file311=== PAUSE TestSupersededNARStillUploadsListing/small_NAR312=== PAUSE TestPartSizeForNAR/capped_at_5_GiB313=== RUN TestFilterOversizedClosures/no_limit_keeps_everything314--- PASS: TestStreamPushReportsSignatures (0.00s)315=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI316--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)317=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI318=== CONT TestStaticToken319=== RUN TestConvertHashToNix32/already_Nix32_format320=== CONT TestUploadMultipart_FailedPartBufferNotReused321=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part322=== PAUSE TestConvertHashToNix32/already_Nix32_format323=== RUN TestConvertHashToNix32/invalid_format324=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything325=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary326=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter327=== RUN TestSetClientTLSErrors/missing_ca_file328=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA329=== RUN TestSupersededNARStillUploadsListing/dump_cut_short330--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)331=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512332=== CONT TestDoServerRequestAttachesToken333--- PASS: TestScriptTokenCachesUntilRefresh (0.27s)334=== PAUSE TestConvertHashToNix32/invalid_format335=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped336=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter337=== PAUSE TestSetClientTLSErrors/missing_ca_file338=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short339=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths340=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA341=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512342--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)343=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths344=== RUN TestSetClientTLS/preserves_debug_logging_transport345--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)346--- PASS: TestClientSignaturesByStorePath (0.00s)347--- PASS: TestStreamPushReportsSkippedPaths (0.00s)348--- PASS: TestFileTokenMissing (0.00s)349--- PASS: TestFileTokenReadsAndCaches (0.00s)350--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.28s)351=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped352=== PAUSE TestSetClientTLS/preserves_debug_logging_transport353=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout354=== CONT TestParsePathInfoJSON/invalid_JSON355=== RUN TestFilterOversizedClosures/all_closures_skipped356=== CONT TestParsePathInfoJSON/whitespace_only357=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs358=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter359=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter360=== CONT TestParsePathInfoJSON/Lix_format361=== PAUSE TestFilterOversizedClosures/all_closures_skipped362=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails363=== RUN TestSetClientTLSErrors/invalid_ca_file364=== CONT TestStreamPushBatchesUnderLoad/together365=== CONT TestParsePathInfoJSON/Nix_format366=== CONT TestParsePathInfoJSON/empty_input367=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time368=== CONT TestPathInfoCACompatibility/old_string_format_-_text369--- PASS: TestScriptTokenBadJSON (0.27s)370=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method371=== CONT TestPathInfoCACompatibility/new_structured_format_-_text372=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive373=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error374=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error375=== CONT TestGetStorePathHash/valid_store_path376=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client377=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier378--- PASS: TestStaticToken (0.00s)379=== CONT TestGetStorePathHash/basename_without_hyphen_should_error380=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up381=== PAUSE TestSetClientTLSErrors/invalid_ca_file382=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails383--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)384 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)385 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)386=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client387--- PASS: TestParsePathInfoJSON (0.01s)388 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)389 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)390 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)391 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)392 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)393--- PASS: TestDoServerRequestAttachesToken (0.01s)394=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier395--- PASS: TestGetStorePathHash (0.02s)396 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)397 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)398 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)399 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)400=== CONT TestPathInfoCACompatibility/null_ca_field401=== CONT TestStreamPushStopsOnCancel/waiting_for_input402=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot403--- PASS: TestStreamPushBatchesUnderLoad (0.00s)404 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.00s)405 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)406--- PASS: TestPathInfoCACompatibility (0.01s)407 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)408 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)409 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)410 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)411 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)412=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken413=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot414=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot415=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot416--- PASS: TestCaseHackSuffix (0.29s)417=== CONT TestEncodeNixBase32/empty_input418=== CONT TestUploadMultipart_SupersededByPeer/missing419=== CONT TestEncodeNixBase32/test_string_hash420=== CONT TestUploadMultipart_SupersededByPeer/exists421--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.02s)422 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_last_root_committed_by_another_client (0.00s)423 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_committed_earlier (0.00s)424 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.00s)425 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/push_cleaned_up,_first_root_committed_by_another_client (0.00s)426 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.01s)427--- PASS: TestEncodeNixBase32 (0.00s)428 --- PASS: TestEncodeNixBase32/empty_input (0.00s)429 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)430=== CONT TestPartSizeForNAR/zero_stays_at_minimum431=== CONT TestPartSizeForNAR/capped_at_5_GiB432--- PASS: TestUploadMultipart_SupersededByPeer (0.26s)433 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)434 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)435=== CONT TestPartSizeForNAR/5_TiB_S3_max_object436=== CONT TestPartSizeForNAR/1_TiB437=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts438=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum439=== CONT TestPartSizeForNAR/small_stays_at_minimum440=== CONT TestConvertHashToNix32/already_Nix32_format441=== CONT TestConvertHashToNix32/invalid_format442--- PASS: TestPartSizeForNAR (0.28s)443 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)444 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)445 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)446 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)447 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)448 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)449 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)450=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon451=== CONT TestConvertHashToNix32/SRI_format_to_Nix32452=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA453=== CONT TestSetClientTLS/preserves_debug_logging_transport454--- PASS: TestConvertHashToNix32 (0.27s)455 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)456 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)457 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)458--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.32s)459=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)460=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512461--- PASS: TestDumpPathSingleFile (0.31s)462=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI463=== CONT TestRateLimiterFeedback/429_enables_limiter464--- PASS: TestPathInfoHashCompatibility (0.29s)465 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)466 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)467 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)468 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)469=== CONT TestSetClientTLS/rejects_connection_without_client_cert470--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.32s)471=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter472=== CONT TestFilterOversizedClosures/no_limit_keeps_everything473=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter474=== CONT TestRateLimiterFeedback/503_enables_limiter475=== CONT TestFilterOversizedClosures/all_closures_skipped476=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped477--- PASS: TestFilterOversizedClosures (0.03s)478 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)479 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)480 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)481=== CONT TestSetClientTLSErrors/missing_cert_file482=== CONT TestSetClientTLSErrors/invalid_ca_file483=== CONT TestSetClientTLSErrors/missing_key_file484--- PASS: TestRateLimiterFeedback (0.29s)485 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)486 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)487 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)488 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)489=== CONT TestSetClientTLSErrors/missing_ca_file490=== CONT TestSupersededNARStillUploadsListing/small_NAR491=== CONT TestSupersededNARStillUploadsListing/dump_cut_short492=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails493--- PASS: TestDumpPathWriterError (0.31s)494--- PASS: TestSetClientTLSErrors (0.30s)495 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)496 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)497 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)498 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)499--- PASS: TestStreamPushStopsOnCancel (0.03s)500 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.05s)501 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.05s)502 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.05s)503 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)504 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.05s)505 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.05s)506--- PASS: TestSetClientTLS (0.30s)507 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)508 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)509 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.10s)510--- PASS: TestRegisterUploadedObjectReusesConnections (0.41s)511--- PASS: TestDumpPathMatchesNix (0.43s)512--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.00s)513 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.14s)514 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.16s)515--- PASS: TestStreamPushRequestLine (0.46s)516--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)517--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)518--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.10s)519--- PASS: TestUploadMultipart_PartsInParallel (1.12s)520--- PASS: TestSupersededNARStillUploadsListing (0.28s)521 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.02s)522 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.02s)523 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.08s)524--- PASS: TestTruncatedNARDumpIsNotCompleted (1.42s)525--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.01s)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/postgres2416222525/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/postgres2416222525/data -l logfile start556557/build/postgres2416222525:5432 - no response5582026-10-25 19:48:12.207 UTC [169] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5592026-10-25 19:48:12.208 UTC [169] LOG: listening on Unix socket "/build/postgres2416222525/.s.PGSQL.5432"5602026-10-25 19:48:12.213 UTC [176] LOG: database system was shut down at 2026-10-25 19:48:12 UTC5612026-10-25 19:48:12.217 UTC [169] LOG: database system is ready to accept connections562/build/postgres2416222525:5432 - accepting connections563{"timestamp":"2026-10-25T19:48:12.411803368Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"24ee46b6-7d18-4fdd-87fa-9455b2656c67","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(207)"}564=== RUN TestService_AuthMiddleware565=== PAUSE TestService_AuthMiddleware566=== RUN TestService_AuthMiddleware_MTLSProxyHeader567=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader568=== RUN TestService_AuthMiddleware_MTLSBoundSubjects569=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects570=== RUN TestService_ReadAuthMiddleware571=== PAUSE TestService_ReadAuthMiddleware572=== RUN TestService_AuthMiddleware_OIDC573=== PAUSE TestService_AuthMiddleware_OIDC574=== RUN TestService_RequireScope_OIDC575=== PAUSE TestService_RequireScope_OIDC576=== RUN TestService_ReadScope_PublicByDefault577=== PAUSE TestService_ReadScope_PublicByDefault578=== RUN TestCacheConfigHandler579=== PAUSE TestCacheConfigHandler580=== RUN TestCacheStatsHandler581=== PAUSE TestCacheStatsHandler582=== RUN TestClientCADerivations583=== PAUSE TestClientCADerivations584=== RUN TestClientErrorHandling585=== PAUSE TestClientErrorHandling586=== RUN TestClientIntegration587=== PAUSE TestClientIntegration588=== RUN TestClientMultipleUploads589=== PAUSE TestClientMultipleUploads590=== RUN TestClientWithDependencies591=== PAUSE TestClientWithDependencies592=== RUN TestClientSharedPathCommittedMidPush593=== PAUSE TestClientSharedPathCommittedMidPush594=== RUN TestPinProtectsFromGC595=== PAUSE TestPinProtectsFromGC596=== RUN TestClientPushesUseOnePush597=== PAUSE TestClientPushesUseOnePush598=== RUN TestClientFallsBackToClosures599=== PAUSE TestClientFallsBackToClosures600=== RUN TestDeleteClosuresRacingPins601=== PAUSE TestDeleteClosuresRacingPins602=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock603=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock604=== RUN TestResolveDBConnectionString605=== PAUSE TestResolveDBConnectionString606=== RUN TestConnectWaitsForAPeerMigration607=== PAUSE TestConnectWaitsForAPeerMigration608=== RUN TestConnectSerialisesConcurrentMigrations609=== PAUSE TestConnectSerialisesConcurrentMigrations610=== RUN TestLeadElectsOneAndHandsOver611=== PAUSE TestLeadElectsOneAndHandsOver612=== RUN TestLeadIncumbentWinsAfterRestart6132026/10/25 19:48:12 INFO lead: acquired remote=192.0.2.1:12346142026/10/25 19:48:13 INFO lead: released remote=192.0.2.1:12346152026/10/25 19:48:13 INFO lead: acquired remote=192.0.2.1:12346162026/10/25 19:48:14 INFO lead: released remote=192.0.2.1:1234617--- PASS: TestLeadIncumbentWinsAfterRestart (1.93s)618=== RUN TestLeadIncumbentAnnouncesAtOnce619=== PAUSE TestLeadIncumbentAnnouncesAtOnce620=== RUN TestLeadEndsOnShutdown621=== PAUSE TestLeadEndsOnShutdown622=== RUN TestLeadEndsWhenItsConnectionHangs6232026/10/25 19:48:14 INFO lead: acquired remote=192.0.2.1:12346242026-10-25 19:48:15.990 UTC [425] FATAL: terminating connection due to administrator command6252026/10/25 19:48:16 INFO lead: acquired remote=192.0.2.1:12346262026/10/25 19:48:17 WARN lead: lock connection lost error="timeout: context deadline exceeded"6272026/10/25 19:48:17 INFO lead: released remote=192.0.2.1:12346282026/10/25 19:48:17 INFO lead: released remote=192.0.2.1:1234629--- PASS: TestLeadEndsWhenItsConnectionHangs (2.95s)630=== RUN TestGCAdvisoryLockBlocksConcurrentRun631=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun632=== RUN TestGCBugBareHashReferences633=== PAUSE TestGCBugBareHashReferences634=== RUN TestGCMetrics635=== PAUSE TestGCMetrics636=== RUN TestPushDedupSurvivesConcurrentGC637=== PAUSE TestPushDedupSurvivesConcurrentGC638=== RUN TestDeduplicatedObjectsRecordedAsPending639=== PAUSE TestDeduplicatedObjectsRecordedAsPending640=== RUN TestGCSweepSkipsPendingObjects641=== PAUSE TestGCSweepSkipsPendingObjects642=== RUN TestTombstonedObjectOfferedWithoutWaiting643=== PAUSE TestTombstonedObjectOfferedWithoutWaiting644=== RUN TestGCSweepDeliversEachKeyOnce645=== PAUSE TestGCSweepDeliversEachKeyOnce646=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection647=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection648=== RUN TestForceGCDuringPushOffersSweptObject649=== PAUSE TestForceGCDuringPushOffersSweptObject650=== RUN TestFailedS3DeleteKeepsTombstone651=== PAUSE TestFailedS3DeleteKeepsTombstone652=== RUN TestSweepSkipsRowsLockedByPush653=== PAUSE TestSweepSkipsRowsLockedByPush654=== RUN TestRegisterCompletedObjectNeedsPendingRow655=== PAUSE TestRegisterCompletedObjectNeedsPendingRow656=== RUN TestGetExistingObjectsLocksRows657=== PAUSE TestGetExistingObjectsLocksRows658=== RUN TestSweepRechecksPendingAfterLocking659=== PAUSE TestSweepRechecksPendingAfterLocking660=== RUN TestPushWaitsForSweepHoldingRow661=== PAUSE TestPushWaitsForSweepHoldingRow662=== RUN TestCommitRacingPendingCleanupKeepsObjects663=== PAUSE TestCommitRacingPendingCleanupKeepsObjects664=== RUN TestGCEndsOnShutdown665=== PAUSE TestGCEndsOnShutdown666=== RUN TestGCTaskStore_StartNew667=== PAUSE TestGCTaskStore_StartNew668=== RUN TestGCTaskStore_DeduplicateSameParams669=== PAUSE TestGCTaskStore_DeduplicateSameParams670=== RUN TestGCTaskStore_ConflictDifferentParams671=== PAUSE TestGCTaskStore_ConflictDifferentParams672=== RUN TestGCTaskStore_GetEmpty673=== PAUSE TestGCTaskStore_GetEmpty674=== RUN TestGCTaskStore_GetReturnsLatest675=== PAUSE TestGCTaskStore_GetReturnsLatest676=== RUN TestGCTaskStore_CompletedAllowsNewTask677=== PAUSE TestGCTaskStore_CompletedAllowsNewTask678=== RUN TestGCTaskStore_PhaseUpdates679=== PAUSE TestGCTaskStore_PhaseUpdates680=== RUN TestGCTaskStore_Fail681=== PAUSE TestGCTaskStore_Fail682=== RUN TestGracefulShutdownDrainsInflight683=== PAUSE TestGracefulShutdownDrainsInflight684=== RUN TestService_healthCheckHandler685=== PAUSE TestService_healthCheckHandler686=== RUN TestService_readinessHandler687=== PAUSE TestService_readinessHandler688=== RUN TestGenerateLandingPage689=== PAUSE TestGenerateLandingPage690=== RUN TestChildrenInheritRaisedFileLimit691=== PAUSE TestChildrenInheritRaisedFileLimit692=== RUN TestCacheConfigHandlerMaxNarSize693=== PAUSE TestCacheConfigHandlerMaxNarSize694=== RUN TestCreatePendingClosureRejectsOversizedNAR695=== PAUSE TestCreatePendingClosureRejectsOversizedNAR696=== RUN TestNARDeduplicationMetadataUploadBug697=== PAUSE TestNARDeduplicationMetadataUploadBug698=== RUN TestMetricsInventory699=== PAUSE TestMetricsInventory700=== RUN TestMetricsCommit701=== PAUSE TestMetricsCommit702=== RUN TestService_NativeMTLS703=== PAUSE TestService_NativeMTLS704=== RUN TestServerTLSConfig705=== PAUSE TestServerTLSConfig706=== RUN TestMultipartCleanup707=== PAUSE TestMultipartCleanup708=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded709=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded710=== RUN TestPendingCleanupUsesOneCutoff711=== PAUSE TestPendingCleanupUsesOneCutoff712=== RUN TestPendingClosureFailureTracksEveryUpload713=== PAUSE TestPendingClosureFailureTracksEveryUpload714=== RUN TestPendingClosureFailureAbortsItsUploads715=== PAUSE TestPendingClosureFailureAbortsItsUploads716=== RUN TestObjectStatsTrigger717=== PAUSE TestObjectStatsTrigger718=== RUN TestObjectStatsUpdatedOncePerCommit719=== PAUSE TestObjectStatsUpdatedOncePerCommit720=== RUN TestReconnectLeavesObjectsUnlocked721=== PAUSE TestReconnectLeavesObjectsUnlocked722=== RUN TestOrphanedObjectsGC723=== PAUSE TestOrphanedObjectsGC724=== RUN TestOrphanedObjectsGCStressTest725=== PAUSE TestOrphanedObjectsGCStressTest726=== RUN TestCreatePin_ReservedPins727=== PAUSE TestCreatePin_ReservedPins728=== RUN TestConcurrentPinUpdatesAgree729=== PAUSE TestConcurrentPinUpdatesAgree730=== RUN TestCreatePinRejectsBadInput731=== PAUSE TestCreatePinRejectsBadInput732=== RUN TestDeletePinKeepsRowWhenS3Fails733=== PAUSE TestDeletePinKeepsRowWhenS3Fails734=== RUN TestPresentReportsOnlyClosureRoots735=== PAUSE TestPresentReportsOnlyClosureRoots736=== RUN TestPresentRefreshesOnlyStaleClosures737=== PAUSE TestPresentRefreshesOnlyStaleClosures738=== RUN TestPresentNotReportedWhileGCDeletesClosure739=== PAUSE TestPresentNotReportedWhileGCDeletesClosure740=== RUN TestParseSingleRange741=== PAUSE TestParseSingleRange742=== RUN TestProxyHeadersOnlyTrustedOnSocket7432026/10/25 19:48:17 INFO Starting HTTP server address=proxy.sock7442026/10/25 19:48:17 INFO Starting HTTP server address=127.0.0.1:350177452026/10/25 19:48:17 WARN mTLS auth: subject not in bound subjects subject="CN=someone"7462026/10/25 19:48:17 INFO Shutdown signal received, draining in-flight requests timeout=10s747--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.15s)748=== RUN TestIsValidCachePath749=== PAUSE TestIsValidCachePath750=== RUN TestReadProxyNarinfo751=== PAUSE TestReadProxyNarinfo752=== RUN TestReadProxyNarinfoAlreadyDecompressed753=== PAUSE TestReadProxyNarinfoAlreadyDecompressed754=== RUN TestReadProxyContentNegotiation755=== PAUSE TestReadProxyContentNegotiation756=== RUN TestReadProxyNarStreaming757=== PAUSE TestReadProxyNarStreaming758=== RUN TestReadProxy404759=== PAUSE TestReadProxy404760=== RUN TestReadProxyInvalidPath761=== PAUSE TestReadProxyInvalidPath762=== RUN TestReadProxyHead763=== PAUSE TestReadProxyHead764=== RUN TestReadProxyOutlastsServerWriteTimeout765=== PAUSE TestReadProxyOutlastsServerWriteTimeout766=== RUN TestReadProxyConditionalGet767=== PAUSE TestReadProxyConditionalGet768=== RUN TestReadProxyRootRedirectsToIndexHTML769=== PAUSE TestReadProxyRootRedirectsToIndexHTML770=== RUN TestReadProxyDisabled771=== PAUSE TestReadProxyDisabled772=== RUN TestReadRedirectNar773=== PAUSE TestReadRedirectNar774=== RUN TestReadRedirectKeepsNarinfoProxied775=== PAUSE TestReadRedirectKeepsNarinfoProxied776=== RUN TestReadProxyRangeRequest777=== PAUSE TestReadProxyRangeRequest778=== RUN TestReadRedirectUsesPublicS3URL779=== PAUSE TestReadRedirectUsesPublicS3URL780=== RUN TestPush_OverlappingRootsStoreOneRowPerKey781=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey782=== RUN TestPush_CompleteCommitsEveryRoot783=== PAUSE TestPush_CompleteCommitsEveryRoot784=== RUN TestPush_RepeatedRootCommitsOnce785=== PAUSE TestPush_RepeatedRootCommitsOnce786=== RUN TestPush_CompleteWaitsForCleanupOfThePush787=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush788=== RUN TestPush_RootsAreLockedInByteOrder789=== PAUSE TestPush_RootsAreLockedInByteOrder790=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit791=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit792=== RUN TestPush_RejectsBadRequests793=== PAUSE TestPush_RejectsBadRequests794=== RUN TestPush_SignsNarinfosOfItsPendingObjects795=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects796=== RUN TestRedundantMultipartUpload797=== PAUSE TestRedundantMultipartUpload798=== RUN TestCompleteMultipartUpload_ErrorButObjectExists799=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists800=== RUN TestCompletedNarNotReofferedAcrossClosures801=== PAUSE TestCompletedNarNotReofferedAcrossClosures802=== RUN TestPresignedUploadRegisteredBeforeCommit803=== PAUSE TestPresignedUploadRegisteredBeforeCommit804=== RUN TestService_Rustfstest805=== PAUSE TestService_Rustfstest806=== RUN TestParseSize807=== PAUSE TestParseSize808=== RUN TestSkippedUploadsHandler809=== PAUSE TestSkippedUploadsHandler810=== RUN TestSystemdListenerNotActivated811--- PASS: TestSystemdListenerNotActivated (0.00s)812=== RUN TestWatchdogBeatsWhenHealthy813--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)814=== RUN TestWatchdogSkipsWhenUnhealthy8152026/10/25 19:48:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8162026/10/25 19:48:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8172026/10/25 19:48:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8182026/10/25 19:48:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8192026/10/25 19:48:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8202026/10/25 19:48:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8212026/10/25 19:48:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8222026/10/25 19:48:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8232026/10/25 19:48:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"8242026/10/25 19:48:17 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"825--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)826=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle827=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle828=== RUN TestProxyWriteTimeout829=== PAUSE TestProxyWriteTimeout830=== RUN TestPendingClosureWriteTimeout831=== PAUSE TestPendingClosureWriteTimeout832=== RUN TestIsValidUploadKey833=== PAUSE TestIsValidUploadKey834=== RUN TestUploadHandlersRejectInvalidKeys835=== PAUSE TestUploadHandlersRejectInvalidKeys836=== RUN TestUploadHandlersRejectOversizedBody837=== PAUSE TestUploadHandlersRejectOversizedBody838=== RUN TestService_cleanupPendingClosuresHandler839=== PAUSE TestService_cleanupPendingClosuresHandler840=== RUN TestService_createPendingClosureHandler841=== PAUSE TestService_createPendingClosureHandler842=== RUN TestService_verifyS3Integrity843=== PAUSE TestService_verifyS3Integrity844=== RUN TestCompleteMultipartUnregistered845=== PAUSE TestCompleteMultipartUnregistered846=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT847=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT848=== CONT TestSkippedUploadsHandler849=== CONT TestUploadHandlersRejectInvalidKeys850=== CONT TestGracefulShutdownDrainsInflight851=== CONT TestProxyWriteTimeout852=== RUN TestProxyWriteTimeout/narinfo853=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info854=== PAUSE TestProxyWriteTimeout/narinfo855=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info856=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit857=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle8582026/10/25 19:48:17 INFO Starting HTTP server address=127.0.0.1:40881859=== RUN TestProxyWriteTimeout/1_GiB_nar860=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT861=== CONT TestService_Rustfstest862=== CONT TestCompleteMultipartUnregistered863=== CONT TestService_readinessHandler864=== CONT TestService_createPendingClosureHandler8652026/10/25 19:48:17 INFO Shutdown signal received, draining in-flight requests timeout=10s866=== CONT TestService_verifyS3Integrity867=== CONT TestPendingClosureWriteTimeout868=== CONT TestPresignedUploadRegisteredBeforeCommit869=== CONT TestService_healthCheckHandler870=== CONT TestCompletedNarNotReofferedAcrossClosures871=== CONT TestGenerateLandingPage872=== CONT TestRedundantMultipartUpload873=== CONT TestCompleteMultipartUpload_ErrorButObjectExists874=== CONT TestPush_SignsNarinfosOfItsPendingObjects875=== CONT TestPush_RejectsBadRequests876=== CONT TestPush_CompleteWaitsForCleanupOfThePush877=== CONT TestService_ReadScope_PublicByDefault878=== CONT TestService_cleanupPendingClosuresHandler879=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal880=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal881=== PAUSE TestProxyWriteTimeout/1_GiB_nar882=== RUN TestPendingClosureWriteTimeout/empty883=== PAUSE TestPendingClosureWriteTimeout/empty884=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key885=== RUN TestPendingClosureWriteTimeout/400_objects8862026/10/25 19:48:17 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000887=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key888=== RUN TestProxyWriteTimeout/10_GiB_nar889=== PAUSE TestPendingClosureWriteTimeout/400_objects890=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key891=== PAUSE TestProxyWriteTimeout/10_GiB_nar892=== RUN TestPendingClosureWriteTimeout/670k_objects893=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key894=== PAUSE TestPendingClosureWriteTimeout/670k_objects895=== RUN TestProxyWriteTimeout/unknown_size896=== CONT TestPush_CompleteCommitsEveryRoot897=== PAUSE TestProxyWriteTimeout/unknown_size898=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline899=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline900=== CONT TestPush_RootsAreLockedInByteOrder901=== CONT TestGCBugBareHashReferences902=== CONT TestReadRedirectUsesPublicS3URL903--- PASS: TestGenerateLandingPage (0.02s)904=== CONT TestPush_OverlappingRootsStoreOneRowPerKey905--- PASS: TestSkippedUploadsHandler (0.04s)906--- PASS: TestGracefulShutdownDrainsInflight (0.07s)907=== CONT TestGCTaskStore_Fail908--- PASS: TestGCTaskStore_Fail (0.00s)909=== CONT TestReadRedirectKeepsNarinfoProxied9102026/10/25 19:48:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9112026/10/25 19:48:18 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst9122026/10/25 19:48:18 INFO Received uploads request method=POST path=/api/pending_closures913--- PASS: TestCompleteMultipartUnregistered (0.31s)914=== CONT TestSweepSkipsRowsLockedByPush9152026/10/25 19:48:18 INFO Received uploads request method=POST path=/api/pending_closures9162026/10/25 19:48:18 INFO Received uploads request method=POST path=/api/pending_closures9172026/10/25 19:48:18 INFO Received uploads request method=POST path=/api/pending_closures9182026/10/25 19:48:18 INFO Received uploads request method=POST path=/api/pending_closures919=== CONT TestReadRedirectNar920--- PASS: TestService_Rustfstest (0.39s)9212026/10/25 19:48:18 WARN readiness check failed error="closed pool"922--- PASS: TestService_readinessHandler (0.40s)923=== CONT TestReadProxyDisabled9242026/10/25 19:48:18 INFO Received uploads request method=POST path=/api/pending_closures9252026/10/25 19:48:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9262026/10/25 19:48:18 INFO Received push request method=POST path=/api/pushes927--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.45s)928=== CONT TestForceGCDuringPushOffersSweptObject929=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows930=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows931=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check932=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check933=== CONT TestReadProxyConditionalGet9342026/10/25 19:48:18 INFO Received uploads request method=POST path=/api/pending_closures9352026/10/25 19:48:18 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9362026/10/25 19:48:18 INFO Received uploads request method=POST path=/api/pending_closures937--- PASS: TestService_healthCheckHandler (0.52s)938=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection939=== CONT TestReadProxyRootRedirectsToIndexHTML940--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.52s)9412026/10/25 19:48:18 INFO Received uploads request method=POST path=/api/pending_closures9422026/10/25 19:48:18 INFO Received push request method=POST path=/api/pushes9432026/10/25 19:48:18 INFO Received uploads request method=POST path=/api/pending_closures9442026/10/25 19:48:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9452026/10/25 19:48:18 INFO Signed narinfos id=1 count=19462026/10/25 19:48:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9472026/10/25 19:48:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9482026/10/25 19:48:18 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9492026/10/25 19:48:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9502026/10/25 19:48:18 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9512026/10/25 19:48:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9522026/10/25 19:48:18 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19532026/10/25 19:48:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9542026/10/25 19:48:18 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo955=== CONT TestGCTaskStore_GetEmpty956--- PASS: TestService_ReadScope_PublicByDefault (0.59s)957=== CONT TestGCSweepSkipsPendingObjects958--- PASS: TestGCTaskStore_GetEmpty (0.00s)9592026/10/25 19:48:18 INFO Received cleanup request method=DELETE path=/api/pending_closures960--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.60s)961=== CONT TestGCTaskStore_ConflictDifferentParams962--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)963=== CONT TestDeduplicatedObjectsRecordedAsPending9642026/10/25 19:48:18 INFO Aborted multipart uploads count=0 kept=09652026/10/25 19:48:18 INFO Received uploads request method=POST path=/api/pending_closures9662026/10/25 19:48:18 INFO Received push request method=POST path=/api/pushes9672026/10/25 19:48:18 INFO Received cleanup request method=DELETE path=/api/pending_closures9682026/10/25 19:48:18 INFO Aborted multipart uploads count=1 kept=09692026/10/25 19:48:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9702026-10-25 19:48:18.437 UTC [516] ERROR: Closure does not exist: id=19712026-10-25 19:48:18.437 UTC [516] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE9722026-10-25 19:48:18.437 UTC [516] STATEMENT: -- name: CommitPendingClosure :one973 SELECT commit_pending_closure($1::bigint)::bigint974 975--- PASS: TestService_cleanupPendingClosuresHandler (0.66s)976=== CONT TestGCTaskStore_DeduplicateSameParams977--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)978=== CONT TestRegisterCompletedObjectNeedsPendingRow9792026/10/25 19:48:18 INFO Received uploads request method=POST path=/api/pending_closures980=== RUN TestPush_RejectsBadRequests/bad_root981=== PAUSE TestPush_RejectsBadRequests/bad_root982=== RUN TestPush_RejectsBadRequests/root_not_in_objects983=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects984=== RUN TestPush_RejectsBadRequests/no_roots985=== PAUSE TestPush_RejectsBadRequests/no_roots986=== RUN TestPush_RejectsBadRequests/no_objects987=== PAUSE TestPush_RejectsBadRequests/no_objects988=== CONT TestGCTaskStore_PhaseUpdates989=== CONT TestObjectStatsUpdatedOncePerCommit990--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)991--- PASS: TestGCBugBareHashReferences (0.69s)992=== CONT TestGCTaskStore_StartNew993=== CONT TestReadProxy404994--- PASS: TestGCTaskStore_StartNew (0.00s)9952026/10/25 19:48:18 INFO Received uploads request method=POST path=/api/pending_closures9962026/10/25 19:48:18 INFO Received push request method=POST path=/api/pushes9972026/10/25 19:48:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9982026/10/25 19:48:18 INFO Received push request method=POST path=/api/pushes9992026/10/25 19:48:18 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LmNmMmYyZGZiLTc2NzktNGNiNS04ZmRhLTgxMDU5MGViZDJlOXgxNzkyOTU3Njk4NTI4MzcxNDEw1000--- PASS: TestReadRedirectKeepsNarinfoProxied (0.72s)1001=== CONT TestCommitRacingPendingCleanupKeepsObjects10022026/10/25 19:48:18 INFO Received push request method=POST path=/api/pushes10032026/10/25 19:48:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10042026/10/25 19:48:18 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LmMyOGExNGIzLTg4NWQtNDRkMi05YThmLTYzOGE4MDJiNDZjN3gxNzkyOTU3Njk4MTM2NjAxMTIw parts=1010052026/10/25 19:48:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10062026/10/25 19:48:18 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LmNmMmYyZGZiLTc2NzktNGNiNS04ZmRhLTgxMDU5MGViZDJlOXgxNzkyOTU3Njk4NTI4MzcxNDEw error="Delete \"http://localhost:37121/bucket23/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LmNmMmYyZGZiLTc2NzktNGNiNS04ZmRhLTgxMDU5MGViZDJlOXgxNzkyOTU3Njk4NTI4MzcxNDEw\": injected: abort refused"10072026/10/25 19:48:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10082026/10/25 19:48:18 INFO Aborted multipart uploads count=0 kept=010092026/10/25 19:48:18 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LmNmMmYyZGZiLTc2NzktNGNiNS04ZmRhLTgxMDU5MGViZDJlOXgxNzkyOTU3Njk4NTI4MzcxNDEw10102026/10/25 19:48:18 INFO Completed upload id=1 objects=2 duration=14.29643ms10112026/10/25 19:48:18 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001012--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.85s)1013=== CONT TestPushDedupSurvivesConcurrentGC10142026/10/25 19:48:18 INFO Received uploads request method=POST path=/api/pending_closures10152026/10/25 19:48:18 WARN Force mode enabled - objects will be deleted immediately without grace period10162026/10/25 19:48:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010172026/10/25 19:48:18 INFO Vacuumed table table=pending_closures10182026/10/25 19:48:18 INFO Vacuumed table table=pending_objects10192026/10/25 19:48:18 INFO Vacuumed table table=multipart_uploads10202026/10/25 19:48:18 INFO Vacuumed table table=closures10212026/10/25 19:48:18 INFO Vacuumed table table=objects10222026/10/25 19:48:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures10232026/10/25 19:48:18 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LmNmMmYyZGZiLTc2NzktNGNiNS04ZmRhLTgxMDU5MGViZDJlOXgxNzkyOTU3Njk4NTI4MzcxNDEw parts=110242026/10/25 19:48:18 INFO Aborted multipart uploads count=0 kept=010252026/10/25 19:48:18 WARN Force mode enabled - objects will be deleted immediately without grace period10262026/10/25 19:48:18 INFO Aborted multipart uploads count=0 kept=01027--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.94s)1028=== CONT TestReadProxyContentNegotiation10292026/10/25 19:48:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=010302026/10/25 19:48:18 INFO Vacuumed table table=pending_closures10312026/10/25 19:48:18 INFO Vacuumed table table=pending_objects10322026/10/25 19:48:18 INFO Vacuumed table table=multipart_uploads10332026/10/25 19:48:18 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=010342026/10/25 19:48:18 INFO Vacuumed table table=pending_closures10352026/10/25 19:48:18 INFO Vacuumed table table=closures10362026/10/25 19:48:18 INFO Vacuumed table table=pending_objects10372026/10/25 19:48:18 INFO Vacuumed table table=multipart_uploads10382026/10/25 19:48:18 INFO Vacuumed table table=closures10392026/10/25 19:48:18 INFO Vacuumed table table=objects10402026/10/25 19:48:18 INFO Vacuumed table table=objects10412026/10/25 19:48:18 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001042--- PASS: TestReadRedirectNar (0.58s)1043=== CONT TestMetricsCommit1044--- PASS: TestReadRedirectUsesPublicS3URL (0.94s)1045=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1046--- PASS: TestReadProxyDisabled (0.58s)1047=== CONT TestIsValidUploadKey1048=== RUN TestIsValidUploadKey/narinfo1049=== PAUSE TestIsValidUploadKey/narinfo1050=== RUN TestIsValidUploadKey/nar_zst1051=== PAUSE TestIsValidUploadKey/nar_zst1052=== RUN TestIsValidUploadKey/nar_xz1053=== PAUSE TestIsValidUploadKey/nar_xz1054=== RUN TestIsValidUploadKey/nar_plain1055=== PAUSE TestIsValidUploadKey/nar_plain1056=== RUN TestIsValidUploadKey/listing1057=== PAUSE TestIsValidUploadKey/listing1058=== RUN TestIsValidUploadKey/build_log1059=== PAUSE TestIsValidUploadKey/build_log10602026/10/25 19:48:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1061=== RUN TestIsValidUploadKey/build_log_home-manager_file1062=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1063=== RUN TestIsValidUploadKey/build_log_plus_in_name1064=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1065=== RUN TestIsValidUploadKey/build_log_question_mark1066=== PAUSE TestIsValidUploadKey/build_log_question_mark1067=== RUN TestIsValidUploadKey/build_log_equals1068=== PAUSE TestIsValidUploadKey/build_log_equals1069=== RUN TestIsValidUploadKey/realisation1070=== PAUSE TestIsValidUploadKey/realisation1071=== RUN TestIsValidUploadKey/realisation_plus_in_output1072=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1073=== RUN TestIsValidUploadKey/nix-cache-info1074=== PAUSE TestIsValidUploadKey/nix-cache-info1075=== RUN TestIsValidUploadKey/index.html1076=== PAUSE TestIsValidUploadKey/index.html1077=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1078=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1079=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1080=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1081--- PASS: TestSweepSkipsRowsLockedByPush (0.67s)1082=== CONT TestClientFallsBackToClosures1083=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1084=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1085=== RUN TestIsValidUploadKey/traversal1086=== PAUSE TestIsValidUploadKey/traversal1087=== RUN TestIsValidUploadKey/traversal_nar1088=== PAUSE TestIsValidUploadKey/traversal_nar1089=== RUN TestIsValidUploadKey/absolute1090=== PAUSE TestIsValidUploadKey/absolute1091=== RUN TestIsValidUploadKey/empty_key1092=== PAUSE TestIsValidUploadKey/empty_key1093=== RUN TestIsValidUploadKey/unknown_type1094=== PAUSE TestIsValidUploadKey/unknown_type1095=== CONT TestPresentNotReportedWhileGCDeletesClosure1096=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1097=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1098=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1099=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1100=== CONT TestService_NativeMTLS1101--- PASS: TestService_createPendingClosureHandler (0.99s)1102=== CONT TestConnectSerialisesConcurrentMigrations11032026/10/25 19:48:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11042026/10/25 19:48:18 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LmMyYTgzYmZiLWZmYjAtNDFjNC1hYzMwLTVlNDBlNmIxOTUwN3gxNzkyOTU3Njk4MTQ3NDk3ODU5 parts=1211052026/10/25 19:48:18 INFO Received uploads request method=POST path=/api/pending_closures11062026/10/25 19:48:18 INFO Received uploads request method=POST path=/api/pending_closures11072026/10/25 19:48:18 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LmViODE4Zjg0LTdiOGMtNDc3Yi1hZDQyLTEyY2IzYWE5MjNlMHgxNzkyOTU3Njk4MjMwMDc3NjUx parts=101108--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.04s)1109=== CONT TestPinProtectsFromGC1110--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.54s)1111=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock11122026/10/25 19:48:18 INFO Received uploads request method=POST path=/api/pending_closures11132026-10-25 19:48:18.874 UTC [655] ERROR: duplicate key value violates unique constraint "pg_type_typname_nsp_index"11142026-10-25 19:48:18.874 UTC [655] DETAIL: Key (typname, typnamespace)=(goose_db_version, 2200) already exists.11152026-10-25 19:48:18.874 UTC [655] STATEMENT: CREATE TABLE goose_db_version (1116 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1117 version_id bigint NOT NULL,1118 is_applied boolean NOT NULL,1119 tstamp timestamp NOT NULL DEFAULT now()1120 )11212026/10/25 19:48:18 INFO Received uploads request method=POST path=/api/pending_closures11222026/10/25 19:48:18 INFO Aborted multipart uploads count=0 kept=01123=== CONT TestDeleteClosuresRacingPins1124--- PASS: TestReadProxyConditionalGet (0.66s)11252026/10/25 19:48:18 WARN Force mode enabled - objects will be deleted immediately without grace period11262026/10/25 19:48:18 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011272026/10/25 19:48:18 INFO Vacuumed table table=pending_closures11282026/10/25 19:48:18 INFO Vacuumed table table=pending_objects11292026/10/25 19:48:18 INFO Vacuumed table table=multipart_uploads11302026/10/25 19:48:18 INFO Vacuumed table table=closures11312026/10/25 19:48:18 INFO Vacuumed table table=objects1132=== CONT TestConnectWaitsForAPeerMigration1133--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.53s)11342026/10/25 19:48:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11352026/10/25 19:48:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1136--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.52s)1137=== CONT TestService_AuthMiddleware1138--- PASS: TestGCSweepSkipsPendingObjects (0.59s)1139=== CONT TestService_ReadAuthMiddleware11402026/10/25 19:48:18 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LmExNWRlNWEyLWQyNTgtNGFiMS1hMGQ3LTNlZjIyN2MwOWZkN3gxNzkyOTU3Njk4NDI4NTY5Nzgx parts=1011412026/10/25 19:48:18 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LjQ3ODAyOWI0LTE2NzItNDExOC05MjI0LTEyMGYxM2Y4MzRjNHgxNzkyOTU3Njk4MzI4NzU3Nzcx parts=1211422026/10/25 19:48:18 INFO Received uploads request method=POST path=/api/pending_closures11432026/10/25 19:48:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11442026/10/25 19:48:19 INFO Received uploads request method=POST path=/api/pending_closures11452026/10/25 19:48:19 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LmM4MTc2YTIzLWQ0ZDktNDYwMi05ODMwLTMwNGExMmZkNjdhNHgxNzkyOTU3Njk4NDgyMzE3MDkw parts=1011462026/10/25 19:48:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11472026/10/25 19:48:19 INFO Completed upload id=1 objects=2 duration=3.689214ms1148--- PASS: TestObjectStatsUpdatedOncePerCommit (0.54s)1149=== CONT TestClientCADerivations11502026/10/25 19:48:19 INFO Aborted multipart uploads count=0 kept=01151--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.73s)1152=== CONT TestService_AuthMiddleware_MTLSBoundSubjects11532026/10/25 19:48:19 INFO Received uploads request method=POST path=/api/pending_closures11542026/10/25 19:48:19 WARN Force mode enabled - objects will be deleted immediately without grace period11552026/10/25 19:48:19 INFO Received uploads request method=POST path=/api/pending_closures11562026/10/25 19:48:19 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011572026/10/25 19:48:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11582026/10/25 19:48:19 INFO Received uploads request method=POST path=/api/pending_closures11592026/10/25 19:48:19 INFO Vacuumed table table=pending_closures11602026/10/25 19:48:19 INFO Vacuumed table table=pending_objects11612026/10/25 19:48:19 INFO Vacuumed table table=multipart_uploads11622026/10/25 19:48:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11632026/10/25 19:48:19 INFO Vacuumed table table=closures11642026/10/25 19:48:19 INFO Vacuumed table table=objects11652026/10/25 19:48:19 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11662026/10/25 19:48:19 WARN Found objects in DB but missing from S3, will re-upload count=111672026/10/25 19:48:19 INFO Received uploads request method=POST path=/api/pending_closures11682026/10/25 19:48:19 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete11692026/10/25 19:48:19 INFO Completed upload id=3 objects=2 duration=2.556463ms11702026/10/25 19:48:19 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LjkwYjJiY2QwLTg0ZGItNDFmYS04YjRmLTVjZDg4NGZhZmMxOXgxNzkyOTU3Njk4NTY1MzgyNjY3 parts=1011712026/10/25 19:48:19 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LjgyNTU3NWVhLTVjZGMtNDFiMS05YTE3LTllZWQzYTVkYjQ2YXgxNzkyOTU3Njk4NTgzMzMyNDEx parts=101172--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.51s)1173=== CONT TestService_AuthMiddleware_OIDC1174--- PASS: TestService_verifyS3Integrity (1.30s)1175=== CONT TestCreatePendingClosureRejectsOversizedNAR11762026/10/25 19:48:19 INFO Received uploads request method=POST path=/api/pending_closures1177--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1178=== CONT TestClientIntegration11792026/10/25 19:48:19 INFO Received push request method=POST path=/api/pushes1180=== CONT TestResolveDBConnectionString1181--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.36s)1182=== RUN TestResolveDBConnectionString/flag_wins1183=== PAUSE TestResolveDBConnectionString/flag_wins1184=== RUN TestResolveDBConnectionString/file_when_flag_empty1185=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1186=== RUN TestResolveDBConnectionString/missing_file_is_an_error1187=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1188=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1189=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1190=== RUN TestResolveDBConnectionString/nothing_configured1191=== PAUSE TestResolveDBConnectionString/nothing_configured1192=== CONT TestParseSize1193=== CONT TestLeadIncumbentAnnouncesAtOnce1194--- PASS: TestParseSize (0.00s)11952026/10/25 19:48:19 INFO Aborted multipart uploads count=0 kept=011962026/10/25 19:48:19 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=011972026/10/25 19:48:19 INFO Vacuumed table table=pending_closures11982026/10/25 19:48:19 INFO Vacuumed table table=pending_objects11992026/10/25 19:48:19 INFO Vacuumed table table=multipart_uploads12002026/10/25 19:48:19 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12012026/10/25 19:48:19 INFO Vacuumed table table=closures12022026/10/25 19:48:19 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12032026/10/25 19:48:19 INFO Vacuumed table table=objects12042026/10/25 19:48:19 INFO Aborted multipart uploads count=0 kept=012052026/10/25 19:48:19 WARN Force mode enabled - objects will be deleted immediately without grace period12062026/10/25 19:48:19 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=01207--- PASS: TestService_NativeMTLS (0.40s)1208=== CONT TestGCTaskStore_CompletedAllowsNewTask1209=== CONT TestGCMetrics1210--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)12112026/10/25 19:48:19 INFO Vacuumed table table=pending_closures12122026/10/25 19:48:19 INFO Vacuumed table table=pending_objects12132026/10/25 19:48:19 INFO Vacuumed table table=multipart_uploads12142026/10/25 19:48:19 INFO Vacuumed table table=closures12152026/10/25 19:48:19 INFO Vacuumed table table=objects1216--- PASS: TestPushDedupSurvivesConcurrentGC (0.54s)1217=== CONT TestFailedS3DeleteKeepsTombstone12182026/10/25 19:48:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43709/oidc12192026/10/25 19:48:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1220=== NAME TestPinProtectsFromGC1221 client_integration_test.go:854: Pinned store path: /build/TestPinProtectsFromGC2916069015/001/store/xf5sgjr4n4ij5xrd0v3pb5x6yxjhncc4-pinned-file.txt1222 client_integration_test.go:855: Unpinned store path: /build/TestPinProtectsFromGC2916069015/001/store/ia42mcsmbpj0g5mp7nwiawbh4k5m34d3-unpinned-file.txt12232026-10-25 19:48:19.290 UTC [675] ERROR: Push does not exist: id=112242026-10-25 19:48:19.290 UTC [675] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE12252026-10-25 19:48:19.290 UTC [675] STATEMENT: SELECT commit_push($1)12262026/10/25 19:48:19 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LjE1ZWM0ZjcyLTUwNDAtNGMyZS1hY2Y1LTkxYWMyMjQwZGI5YngxNzkyOTU3Njk4MjMwNzYwODc4 parts=1012272026/10/25 19:48:19 INFO Received complete push request method=POST path=/api/pushes/1/complete1228--- PASS: TestService_ReadAuthMiddleware (0.32s)1229=== CONT TestObjectStatsTrigger12302026/10/25 19:48:19 WARN Rate limiter enabled after throttle name=s3-test rate=512312026/10/25 19:48:19 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."12322026/10/25 19:48:19 INFO Completed push id=1 objects=4 duration=7.576329ms12332026/10/25 19:48:19 INFO Received push request method=POST path=/api/pushes12342026/10/25 19:48:19 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1235--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (1.52s)1236=== CONT TestPush_RepeatedRootCommitsOnce1237--- PASS: TestService_AuthMiddleware (0.35s)1238=== CONT TestServerTLSConfig1239=== RUN TestServerTLSConfig/no_client_CA1240=== PAUSE TestServerTLSConfig/no_client_CA1241=== RUN TestServerTLSConfig/missing_CA_file1242=== PAUSE TestServerTLSConfig/missing_CA_file1243=== RUN TestServerTLSConfig/not_a_PEM_file1244=== PAUSE TestServerTLSConfig/not_a_PEM_file1245=== CONT TestReadProxyRangeRequest12462026/10/25 19:48:19 INFO Received uploads request method=POST path=/api/pending_closures12472026/10/25 19:48:19 INFO Received uploads request method=POST path=/api/pending_closures12482026/10/25 19:48:19 INFO Received push request method=POST path=/api/pushes12492026/10/25 19:48:19 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12502026/10/25 19:48:19 INFO Uploading hpj9n291f94b31hnbjvjl4bajy4a8v00-a (216B)12512026/10/25 19:48:19 INFO Uploading 74cixm8j5pmj9lbxxb4a811p6yjfqdsf-shared-dep (136B)12522026/10/25 19:48:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12532026/10/25 19:48:19 INFO Uploading xf5sgjr4n4ij5xrd0v3pb5x6yxjhncc4-pinned-file.txt (128B)12542026/10/25 19:48:19 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"12552026/10/25 19:48:19 WARN mTLS auth: bound subjects configured but subject DN unavailable12562026/10/25 19:48:19 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"12572026/10/25 19:48:19 WARN Failed to register uploaded object key=38f9fpn9wvsqa334fgc6x4xzix24n1s2.ls error="server returned 404: 404 page not found\n"12582026/10/25 19:48:19 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12592026/10/25 19:48:19 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"12602026/10/25 19:48:19 WARN Failed to register uploaded object key=nar/087jlwma15sj16knr49kncak9jcl28d67c52rirj3s8qmds9cv5p.nar.zst error="server returned 404: 404 page not found\n"12612026/10/25 19:48:19 WARN Failed to register uploaded object key=hpj9n291f94b31hnbjvjl4bajy4a8v00.ls error="server returned 404: 404 page not found\n"12622026/10/25 19:48:19 WARN Failed to register uploaded object key=74cixm8j5pmj9lbxxb4a811p6yjfqdsf.ls error="server returned 404: 404 page not found\n"12632026/10/25 19:48:19 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12642026/10/25 19:48:19 INFO Signed narinfos id=1 count=212652026/10/25 19:48:19 WARN Failed to register uploaded object key=xf5sgjr4n4ij5xrd0v3pb5x6yxjhncc4.ls error="server returned 404: 404 page not found\n"12662026/10/25 19:48:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12672026/10/25 19:48:19 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12682026/10/25 19:48:19 INFO Signed narinfos id=1 count=112692026/10/25 19:48:19 INFO Uploading 1 narinfos12702026/10/25 19:48:19 WARN Rate limiter backed off name=s3-test rate=512712026/10/25 19:48:19 INFO Signed narinfos id=2 count=212722026/10/25 19:48:19 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."12732026/10/25 19:48:19 INFO Uploading 4 narinfos12742026/10/25 19:48:19 WARN Failed to register uploaded object key=hpj9n291f94b31hnbjvjl4bajy4a8v00.narinfo error="server returned 404: 404 page not found\n"12752026/10/25 19:48:19 WARN Failed to register uploaded object key=38f9fpn9wvsqa334fgc6x4xzix24n1s2.narinfo error="server returned 404: 404 page not found\n"12762026/10/25 19:48:19 WARN Failed to register uploaded object key=74cixm8j5pmj9lbxxb4a811p6yjfqdsf.narinfo error="server returned 404: 404 page not found\n"1277--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.36s)1278=== CONT TestGCTaskStore_GetReturnsLatest1279--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1280=== CONT TestGCSweepDeliversEachKeyOnce12812026/10/25 19:48:19 INFO Aborted multipart uploads count=0 kept=012822026/10/25 19:48:19 INFO Received complete push request method=POST path=/api/pushes/1/complete12832026/10/25 19:48:19 WARN Failed to register uploaded object key=xf5sgjr4n4ij5xrd0v3pb5x6yxjhncc4.narinfo error="server returned 404: 404 page not found\n"12842026/10/25 19:48:19 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12852026/10/25 19:48:19 WARN Failed to register uploaded object key=74cixm8j5pmj9lbxxb4a811p6yjfqdsf.narinfo error="server returned 404: 404 page not found\n"12862026/10/25 19:48:19 WARN Force mode enabled - objects will be deleted immediately without grace period12872026/10/25 19:48:19 INFO Completed upload id=1 objects=6 duration=7.122625ms12882026/10/25 19:48:19 INFO Completed push id=1 objects=3 duration=8.173814ms12892026/10/25 19:48:19 INFO Upload complete. (96ms)12902026/10/25 19:48:19 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12912026/10/25 19:48:19 INFO Completed upload id=2 objects=6 duration=1.442313ms12922026/10/25 19:48:19 INFO Upload complete. (112ms)1293--- PASS: TestReadProxy404 (0.92s)1294=== CONT TestTombstonedObjectOfferedWithoutWaiting1295=== NAME TestClientFallsBackToClosures1296 client_pushes_test.go:112: Retrieved narinfo from S3:1297 StorePath: /build/TestClientFallsBackToClosures2276597182/001/store/74cixm8j5pmj9lbxxb4a811p6yjfqdsf-shared-dep1298 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1299 Compression: zstd1300 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821301 NarSize: 1361302 References: 1303 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1304 client_pushes_test.go:112: Retrieved narinfo from S3:1305 StorePath: /build/TestClientFallsBackToClosures2276597182/001/store/hpj9n291f94b31hnbjvjl4bajy4a8v00-a1306 URL: nar/087jlwma15sj16knr49kncak9jcl28d67c52rirj3s8qmds9cv5p.nar.zst1307 Compression: zstd1308 NarHash: sha256:087jlwma15sj16knr49kncak9jcl28d67c52rirj3s8qmds9cv5p1309 NarSize: 2161310 References: /build/TestClientFallsBackToClosures2276597182/001/store/74cixm8j5pmj9lbxxb4a811p6yjfqdsf-shared-dep1311 CA: text:sha256:0xf5a71fprrkr5zywc27bm8grcscgm8p58zdahw3kwhfz7jybhkw1312 client_pushes_test.go:112: Retrieved narinfo from S3:1313 StorePath: /build/TestClientFallsBackToClosures2276597182/001/store/38f9fpn9wvsqa334fgc6x4xzix24n1s2-b1314 URL: nar/087jlwma15sj16knr49kncak9jcl28d67c52rirj3s8qmds9cv5p.nar.zst1315 Compression: zstd1316 NarHash: sha256:087jlwma15sj16knr49kncak9jcl28d67c52rirj3s8qmds9cv5p1317 NarSize: 2161318 References: /build/TestClientFallsBackToClosures2276597182/001/store/74cixm8j5pmj9lbxxb4a811p6yjfqdsf-shared-dep1319 CA: text:sha256:0xf5a71fprrkr5zywc27bm8grcscgm8p58zdahw3kwhfz7jybhkw13202026/10/25 19:48:19 INFO lead: acquired remote=192.0.2.1:123413212026/10/25 19:48:19 INFO lead: released remote=192.0.2.1:12341322=== NAME TestClientCADerivations1323 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3098014730/001/store/jb2zjwgb9vhr5zzfa42pcw856qmqia6m-ca-test1324=== NAME TestClientIntegration1325 client_integration_test.go:331: Created store path: /build/TestClientIntegration3545461838/002/store/x8304cmk43h7f47cnwb91zhi9adwv1j7-test-file.txt13262026/10/25 19:48:19 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=01327=== CONT TestOrphanedObjectsGCStressTest1328--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.33s)13292026/10/25 19:48:19 INFO Vacuumed table table=pending_closures13302026/10/25 19:48:19 INFO Vacuumed table table=pending_objects13312026/10/25 19:48:19 INFO Vacuumed table table=multipart_uploads13322026/10/25 19:48:19 INFO Vacuumed table table=closures1333--- PASS: TestClientFallsBackToClosures (0.70s)1334=== CONT TestPendingClosureFailureAbortsItsUploads13352026/10/25 19:48:19 INFO Vacuumed table table=objects13362026/10/25 19:48:19 INFO Aborted multipart uploads count=0 kept=013372026/10/25 19:48:19 WARN Force mode enabled - objects will be deleted immediately without grace period13382026/10/25 19:48:19 INFO Received push request method=POST path=/api/pushes13392026/10/25 19:48:19 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013402026/10/25 19:48:19 INFO Vacuumed table table=pending_closures1341=== NAME TestClientCADerivations1342 client_ca_test.go:139: Found 1 dependencies (including self)13432026/10/25 19:48:19 INFO Vacuumed table table=pending_objects13442026/10/25 19:48:19 INFO Vacuumed table table=multipart_uploads13452026/10/25 19:48:19 INFO Vacuumed table table=closures13462026/10/25 19:48:19 INFO Vacuumed table table=objects13472026/10/25 19:48:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13482026/10/25 19:48:19 INFO Uploading ia42mcsmbpj0g5mp7nwiawbh4k5m34d3-unpinned-file.txt (128B)1349=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1350=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1351=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1352=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1353=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1354=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1355=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1356=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1357=== CONT TestCreatePin_ReservedPins13582026/10/25 19:48:19 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"13592026/10/25 19:48:19 WARN Failed to register uploaded object key=ia42mcsmbpj0g5mp7nwiawbh4k5m34d3.ls error="server returned 404: 404 page not found\n"13602026/10/25 19:48:19 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13612026/10/25 19:48:19 INFO Signed narinfos id=2 count=113622026/10/25 19:48:19 INFO Uploading 1 narinfos1363--- PASS: TestReadProxyContentNegotiation (0.78s)1364=== CONT TestReconnectLeavesObjectsUnlocked13652026/10/25 19:48:19 INFO Received uploads request method=POST path=/api/pending_closures13662026/10/25 19:48:19 INFO Received complete push request method=POST path=/api/pushes/2/complete13672026/10/25 19:48:19 INFO Received push request method=POST path=/api/pushes13682026/10/25 19:48:19 WARN Failed to register uploaded object key=ia42mcsmbpj0g5mp7nwiawbh4k5m34d3.narinfo error="server returned 404: 404 page not found\n"13692026/10/25 19:48:19 INFO Completed push id=2 objects=3 duration=2.667264ms13702026/10/25 19:48:19 INFO Upload complete. (86ms)13712026/10/25 19:48:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13722026/10/25 19:48:19 INFO Uploading x8304cmk43h7f47cnwb91zhi9adwv1j7-test-file.txt (152B)1373--- PASS: TestGCMetrics (0.37s)1374=== CONT TestReadProxyOutlastsServerWriteTimeout13752026/10/25 19:48:19 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"13762026/10/25 19:48:19 WARN Failed to register uploaded object key=x8304cmk43h7f47cnwb91zhi9adwv1j7.ls error="server returned 404: 404 page not found\n"13772026/10/25 19:48:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13782026/10/25 19:48:19 INFO Signed narinfos id=1 count=113792026/10/25 19:48:19 INFO Uploading 1 narinfos13802026/10/25 19:48:19 INFO Received complete push request method=POST path=/api/pushes/1/complete13812026/10/25 19:48:19 WARN Failed to register uploaded object key=x8304cmk43h7f47cnwb91zhi9adwv1j7.narinfo error="server returned 404: 404 page not found\n"13822026/10/25 19:48:19 INFO Starting cleanup of old closures method=DELETE path=/api/closures13832026/10/25 19:48:19 INFO Garbage collection started13842026/10/25 19:48:19 INFO Received push request method=POST path=/api/pushes13852026/10/25 19:48:19 INFO Completed push id=1 objects=3 duration=13.548343ms13862026/10/25 19:48:19 INFO Upload complete. (98ms)1387=== CONT TestReadProxyHead13882026/10/25 19:48:19 INFO Aborted multipart uploads count=0 kept=01389--- PASS: TestObjectStatsTrigger (0.30s)13902026/10/25 19:48:19 WARN Force mode enabled - objects will be deleted immediately without grace period13912026/10/25 19:48:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13922026/10/25 19:48:19 INFO Received push request method=POST path=/api/pushes13932026/10/25 19:48:19 INFO Aborted multipart uploads count=0 kept=013942026/10/25 19:48:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13952026/10/25 19:48:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13962026/10/25 19:48:19 INFO Uploading jb2zjwgb9vhr5zzfa42pcw856qmqia6m-ca-test (144B)13972026/10/25 19:48:19 WARN Force mode enabled - objects will be deleted immediately without grace period13982026/10/25 19:48:19 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LjYzNzM0YzRhLWZkNDctNDhhOC04YzVmLWUyOTRkNTczYjExNHgxNzkyOTU3Njk5MDE1NDk4NzA5 error="Get \"http://127.0.0.1:1/bucket15/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"13992026/10/25 19:48:19 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LjcxM2ZmODhlLTJmZTQtNGM4YS04ZTllLTdkNGE2ZDViMDJkZngxNzkyOTU3Njk4OTk3MTMzNDQy parts=1214002026/10/25 19:48:19 INFO All 1 paths already cached14012026/10/25 19:48:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42823/oidc14022026/10/25 19:48:19 INFO Received cleanup request method=DELETE path=/api/pending_closures1403=== NAME TestClientIntegration1404 client_integration_test.go:357: Retrieved narinfo from S3:1405 StorePath: /build/TestClientIntegration3545461838/002/store/x8304cmk43h7f47cnwb91zhi9adwv1j7-test-file.txt1406 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1407 Compression: zstd1408 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11409 NarSize: 1521410 References: 1411 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk114122026/10/25 19:48:19 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."14132026/10/25 19:48:19 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."14142026/10/25 19:48:19 INFO Completed multipart upload object_key=nar/dddddddddddddddddddddddddddddddd00000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LmVjMjkzN2FmLWQyOWQtNDc0Ni1iN2IwLTI1NjI0N2I2OTg2N3gxNzkyOTU3Njk4NTY0NjgxODIx parts=1014152026/10/25 19:48:19 WARN Failed to register uploaded object key=log/98vbbiisa12fsdavwp0pvsl9gs6pn7ab-ca-test.drv error="server returned 404: 404 page not found\n"14162026/10/25 19:48:19 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"14172026/10/25 19:48:19 INFO Aborted multipart uploads count=1 kept=01418 client_integration_test.go:358: Retrieved .ls file from S3 (compressed size: 77 bytes)1419 client_integration_test.go:358: Decompressed .ls content (64 bytes):1420 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}14212026/10/25 19:48:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14222026/10/25 19:48:19 WARN Failed to register uploaded object key=jb2zjwgb9vhr5zzfa42pcw856qmqia6m.ls error="server returned 404: 404 page not found\n"14232026/10/25 19:48:19 INFO Signed narinfos id=1 count=114242026/10/25 19:48:19 INFO Uploading 1 narinfos14252026/10/25 19:48:19 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=014262026/10/25 19:48:19 INFO Vacuumed table table=pending_closures14272026/10/25 19:48:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14282026/10/25 19:48:19 INFO Received complete push request method=POST path=/api/pushes/1/complete14292026/10/25 19:48:19 WARN Failed to register uploaded object key=jb2zjwgb9vhr5zzfa42pcw856qmqia6m.narinfo error="server returned 404: 404 page not found\n"14302026/10/25 19:48:19 INFO Vacuumed table table=pending_objects14312026/10/25 19:48:19 INFO Vacuumed table table=multipart_uploads1432=== CONT TestOrphanedObjectsGC1433--- PASS: TestFailedS3DeleteKeepsTombstone (0.43s)1434--- PASS: TestReadProxyRangeRequest (0.34s)1435=== CONT TestReadProxyInvalidPath14362026/10/25 19:48:19 INFO Vacuumed table table=closures14372026/10/25 19:48:19 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LmY3YmNiYTFlLTQ3MGEtNDk3Ny05MWY1LTA0ZDM3MDNjNzI1YXgxNzkyOTU3Njk4NTgyOTY1OTg4 parts=1014382026/10/25 19:48:19 INFO Completed push id=1 objects=4 duration=15.095197ms14392026/10/25 19:48:19 INFO Upload complete. (139ms)14402026/10/25 19:48:19 INFO Vacuumed table table=objects14412026/10/25 19:48:19 INFO Received uploads request method=POST path=/api/pending_closures1442--- PASS: TestRedundantMultipartUpload (1.88s)1443=== CONT TestGCEndsOnShutdown1444=== RUN TestGCEndsOnShutdown/before_the_run1445=== PAUSE TestGCEndsOnShutdown/before_the_run1446=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1447=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1448=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1449=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1450=== CONT TestReadProxyNarStreaming1451=== NAME TestClientCADerivations1452 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3098014730/001/store/jb2zjwgb9vhr5zzfa42pcw856qmqia6m-ca-test1453 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1454 Compression: zstd1455 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1456 NarSize: 1441457 References: 1458 Deriver: /build/TestClientCADerivations3098014730/001/store/98vbbiisa12fsdavwp0pvsl9gs6pn7ab-ca-test.drv1459 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1460 client_ca_test.go:185: Checking for realisation files in S3...1461 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1462 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache14632026/10/25 19:48:19 INFO Aborted multipart uploads count=0 kept=014642026/10/25 19:48:19 WARN Force mode enabled - objects will be deleted immediately without grace period14652026/10/25 19:48:19 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1466--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.29s)1467=== CONT TestGCAdvisoryLockBlocksConcurrentRun14682026/10/25 19:48:19 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LmY3YzA3MDFiLWE4ZTktNDM2My1iNmQ4LTZlOTEzNWQ3YjI0NXgxNzkyOTU3Njk5MTA4NzQwOTE5 parts=1014692026/10/25 19:48:19 INFO Received uploads request method=POST path=/api/pending_closures14702026/10/25 19:48:19 INFO Received push request method=POST path=/api/pushes14712026/10/25 19:48:19 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=014722026/10/25 19:48:19 INFO Vacuumed table table=pending_closures14732026/10/25 19:48:19 INFO Vacuumed table table=pending_objects14742026/10/25 19:48:19 INFO Vacuumed table table=multipart_uploads14752026/10/25 19:48:19 INFO Vacuumed table table=closures14762026/10/25 19:48:19 INFO Object in database but missing from S3 key=x8304cmk43h7f47cnwb91zhi9adwv1j7.ls14772026/10/25 19:48:19 WARN Found objects in DB but missing from S3, will re-upload count=114782026/10/25 19:48:19 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14792026/10/25 19:48:19 INFO Vacuumed table table=objects14802026/10/25 19:48:19 INFO Received complete push request method=POST path=/api/pushes/2/complete14812026/10/25 19:48:19 WARN Failed to register uploaded object key=x8304cmk43h7f47cnwb91zhi9adwv1j7.ls error="server returned 404: 404 page not found\n"14822026/10/25 19:48:19 INFO Completed push id=2 objects=3 duration=9.493726ms14832026/10/25 19:48:19 INFO Upload complete. (69ms)1484=== NAME TestClientIntegration1485 client_integration_test.go:375: Retrieved .ls file from S3 (compressed size: 62 bytes)1486 client_integration_test.go:375: Decompressed .ls content (49 bytes):1487 {"version":1,"root":{"type":"regular","size":39}}1488=== CONT TestReadProxyNarinfoAlreadyDecompressed1489--- PASS: TestGCSweepDeliversEachKeyOnce (0.37s)1490=== NAME TestClientCADerivations1491 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1492 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1493 error: binary cache 's3://bucket51?endpoint=http://localhost:37121®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3098014730/001/store'1494 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11495--- PASS: TestPendingClosureFailureAbortsItsUploads (0.31s)1496=== CONT TestLeadEndsOnShutdown1497--- PASS: TestReconnectLeavesObjectsUnlocked (0.29s)1498=== CONT TestReadProxyNarinfo1499--- PASS: TestClientCADerivations (0.78s)1500=== CONT TestPushWaitsForSweepHoldingRow15012026/10/25 19:48:19 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15022026/10/25 19:48:19 WARN Refused reserved pin name=worker-x86_64-linux15032026/10/25 19:48:19 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux15042026/10/25 19:48:19 INFO Received create pin request method=POST path=/api/pins/my-app15052026/10/25 19:48:19 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1506=== CONT TestIsValidCachePath1507=== RUN TestIsValidCachePath/narinfo1508--- PASS: TestCreatePin_ReservedPins (0.41s)1509=== PAUSE TestIsValidCachePath/narinfo1510=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1511=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1512=== RUN TestIsValidCachePath/nar_zst1513=== PAUSE TestIsValidCachePath/nar_zst1514=== RUN TestIsValidCachePath/nar_xz1515=== PAUSE TestIsValidCachePath/nar_xz1516=== RUN TestIsValidCachePath/nar_bz21517=== PAUSE TestIsValidCachePath/nar_bz21518=== RUN TestIsValidCachePath/nar_uncompressed1519=== PAUSE TestIsValidCachePath/nar_uncompressed1520=== RUN TestIsValidCachePath/ls1521=== PAUSE TestIsValidCachePath/ls1522=== RUN TestIsValidCachePath/log1523=== PAUSE TestIsValidCachePath/log1524=== RUN TestIsValidCachePath/realisation1525=== PAUSE TestIsValidCachePath/realisation1526=== RUN TestIsValidCachePath/nix-cache-info1527=== PAUSE TestIsValidCachePath/nix-cache-info1528=== RUN TestIsValidCachePath/index.html1529=== PAUSE TestIsValidCachePath/index.html1530=== RUN TestIsValidCachePath/traversal_parent1531=== PAUSE TestIsValidCachePath/traversal_parent1532=== RUN TestIsValidCachePath/traversal_in_middle1533=== PAUSE TestIsValidCachePath/traversal_in_middle1534=== RUN TestIsValidCachePath/invalid_char_e1535=== PAUSE TestIsValidCachePath/invalid_char_e1536=== RUN TestIsValidCachePath/invalid_char_u1537=== PAUSE TestIsValidCachePath/invalid_char_u1538=== RUN TestIsValidCachePath/random_path1539=== PAUSE TestIsValidCachePath/random_path1540=== RUN TestIsValidCachePath/empty1541=== PAUSE TestIsValidCachePath/empty1542=== RUN TestIsValidCachePath/leading_slash1543=== PAUSE TestIsValidCachePath/leading_slash1544=== RUN TestIsValidCachePath/wrong_extension1545=== PAUSE TestIsValidCachePath/wrong_extension1546=== RUN TestIsValidCachePath/short_hash1547=== PAUSE TestIsValidCachePath/short_hash1548=== CONT TestGetExistingObjectsLocksRows1549--- PASS: TestConnectSerialisesConcurrentMigrations (1.13s)1550=== CONT TestParseSingleRange1551=== RUN TestParseSingleRange/none1552=== PAUSE TestParseSingleRange/none1553=== RUN TestParseSingleRange/unknown_unit1554=== PAUSE TestParseSingleRange/unknown_unit1555=== RUN TestParseSingleRange/multi-range_ignored1556=== PAUSE TestParseSingleRange/multi-range_ignored1557=== RUN TestParseSingleRange/malformed_no_dash1558=== PAUSE TestParseSingleRange/malformed_no_dash1559=== RUN TestParseSingleRange/malformed_both_empty1560=== PAUSE TestParseSingleRange/malformed_both_empty1561=== RUN TestParseSingleRange/malformed_end_before_start1562=== PAUSE TestParseSingleRange/malformed_end_before_start1563=== RUN TestParseSingleRange/closed1564=== PAUSE TestParseSingleRange/closed1565=== RUN TestParseSingleRange/open-ended1566=== PAUSE TestParseSingleRange/open-ended1567=== RUN TestParseSingleRange/end_clamped_to_size1568=== PAUSE TestParseSingleRange/end_clamped_to_size1569=== RUN TestParseSingleRange/suffix1570=== PAUSE TestParseSingleRange/suffix1571=== RUN TestParseSingleRange/suffix_exceeds_size1572=== PAUSE TestParseSingleRange/suffix_exceeds_size1573=== RUN TestParseSingleRange/single_byte1574=== PAUSE TestParseSingleRange/single_byte1575=== RUN TestParseSingleRange/start_past_EOF1576=== PAUSE TestParseSingleRange/start_past_EOF1577=== RUN TestParseSingleRange/start_far_past_EOF1578=== PAUSE TestParseSingleRange/start_far_past_EOF1579=== CONT TestSweepRechecksPendingAfterLocking1580=== CONT TestMultipartCleanup1581--- PASS: TestReadProxyInvalidPath (0.27s)15822026/10/25 19:48:19 INFO Received push request method=POST path=/api/pushes15832026/10/25 19:48:19 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)15842026/10/25 19:48:19 INFO Received complete push request method=POST path=/api/pushes/3/complete15852026/10/25 19:48:19 WARN Failed to register uploaded object key=x8304cmk43h7f47cnwb91zhi9adwv1j7.ls error="server returned 404: 404 page not found\n"15862026/10/25 19:48:19 INFO Completed push id=3 objects=3 duration=4.943645ms15872026/10/25 19:48:19 INFO Upload complete. (126ms)1588=== NAME TestClientIntegration1589 client_integration_test.go:392: Retrieved .ls file from S3 (compressed size: 62 bytes)1590 client_integration_test.go:392: Decompressed .ls content (49 bytes):1591 {"version":1,"root":{"type":"regular","size":39}}1592--- PASS: TestReadProxyHead (0.39s)1593=== CONT TestPresentRefreshesOnlyStaleClosures1594=== CONT TestPendingClosureFailureTracksEveryUpload1595=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1596--- PASS: TestReadProxyNarStreaming (0.38s)1597=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false1598=== RUN TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1599=== PAUSE TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true1600=== CONT TestPendingCleanupUsesOneCutoff16012026/10/25 19:48:20 INFO Received push request method=POST path=/api/pushes1602--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.32s)1603=== CONT TestPresentReportsOnlyClosureRoots16042026/10/25 19:48:20 INFO Received uploads request method=POST path=/api/pending_closures16052026/10/25 19:48:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16062026/10/25 19:48:20 INFO Uploading islx49597a9iksmw5xlj38nhsm9h7xik-lost-commit.txt (152B)16072026/10/25 19:48:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16082026/10/25 19:48:20 INFO lead: acquired remote=192.0.2.1:123416092026/10/25 19:48:20 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"16102026/10/25 19:48:20 WARN Failed to register uploaded object key=islx49597a9iksmw5xlj38nhsm9h7xik.ls error="server returned 404: 404 page not found\n"16112026/10/25 19:48:20 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign16122026/10/25 19:48:20 INFO Signed narinfos id=4 count=116132026/10/25 19:48:20 INFO Uploading 1 narinfos16142026/10/25 19:48:20 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LmNhNDU0NWRmLThmNDYtNDUxMC05MWY2LTVmZTc0ZjkwZmEwZngxNzkyOTU3Njk5MzM2MTkxMDUy parts=1016152026/10/25 19:48:20 INFO Received complete push request method=POST path=/api/pushes/2/complete16162026/10/25 19:48:20 INFO Completed push id=2 objects=4 duration=3.883196ms1617--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.26s)1618=== CONT TestCreatePinRejectsBadInput16192026/10/25 19:48:20 INFO Received complete push request method=POST path=/api/pushes/4/complete16202026/10/25 19:48:20 WARN Failed to register uploaded object key=islx49597a9iksmw5xlj38nhsm9h7xik.narinfo error="server returned 404: 404 page not found\n"16212026/10/25 19:48:20 INFO Completed push id=4 objects=3 duration=2.499743ms16222026/10/25 19:48:20 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:46819/api/pushes/4/complete\": EOF" url=http://127.0.0.1:46819/api/pushes/4/complete1623--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.36s)1624=== CONT TestClientSharedPathCommittedMidPush16252026/10/25 19:48:20 INFO Aborted multipart uploads count=0 kept=016262026/10/25 19:48:20 WARN Force mode enabled - objects will be deleted immediately without grace period16272026/10/25 19:48:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16282026/10/25 19:48:20 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=016292026/10/25 19:48:20 INFO Vacuumed table table=pending_closures16302026/10/25 19:48:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16312026/10/25 19:48:20 INFO Vacuumed table table=pending_objects16322026/10/25 19:48:20 INFO Vacuumed table table=multipart_uploads16332026/10/25 19:48:20 INFO Vacuumed table table=closures16342026/10/25 19:48:20 INFO Received uploads request method=POST path=/api/pending_closures16352026/10/25 19:48:20 INFO Vacuumed table table=objects1636=== CONT TestDeletePinKeepsRowWhenS3Fails1637--- PASS: TestGetExistingObjectsLocksRows (0.30s)16382026/10/25 19:48:20 INFO Completed multipart upload object_key=nar/ffffffffffffffffffffffffffffffff00000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LmZmMDQwMTJjLThiZGQtNGFjMi04YjdmLWE0MWVjZmE0OTE4NXgxNzkyOTU3Njk4NTY1MjA3OTI2 parts=1016392026/10/25 19:48:20 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LjU1ODQ1OTQ3LTMxNDctNGRiYi05NWQ1LTRiYTM2YWI3YmE4YngxNzkyOTU3Njk5NTkzMjQ1ODM0 parts=1016402026/10/25 19:48:20 INFO Received complete push request method=POST path=/api/pushes/4/complete16412026-10-25 19:48:20.227 UTC [702] ERROR: Push does not exist: id=416422026-10-25 19:48:20.227 UTC [702] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE16432026-10-25 19:48:20.227 UTC [702] STATEMENT: -- name: CommitPush :one1644 SELECT commit_push($1::bigint)::bigint1645 16462026/10/25 19:48:20 WARN Push not found id=41647--- PASS: TestSweepRechecksPendingAfterLocking (0.31s)1648=== CONT TestLeadElectsOneAndHandsOver16492026/10/25 19:48:20 INFO Upload complete. (193ms)1650=== NAME TestClientIntegration1651 client_integration_test.go:422: Retrieved narinfo from S3:1652 StorePath: /build/TestClientIntegration3545461838/002/store/islx49597a9iksmw5xlj38nhsm9h7xik-lost-commit.txt1653 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1654 Compression: zstd1655 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1656 NarSize: 1521657 References: 1658 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl16592026/10/25 19:48:20 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"1660 client_integration_test.go:425: Testing garbage collection...16612026/10/25 19:48:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16622026/10/25 19:48:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16632026/10/25 19:48:20 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LjgwMmQwZjVlLTNkNTYtNDU2Ni04ZmQ0LTI3YTBjMTEwZTg2Y3gxNzkyOTU3Njk5MTA5NTY2MDI3 parts=1016642026/10/25 19:48:20 INFO Received complete push request method=POST path=/api/pushes/1/complete16652026/10/25 19:48:20 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LjYyMmU5MmYwLTAwZTItNDI1NS05OTJjLTJjOTMxNGMyMmNhY3gxNzkyOTU3Njk4NTgzMzgwMjMx parts=1016662026/10/25 19:48:20 INFO Received complete push request method=POST path=/api/pushes/1/complete16672026/10/25 19:48:20 INFO Starting cleanup of old closures method=DELETE path=/api/closures16682026/10/25 19:48:20 INFO Garbage collection started16692026/10/25 19:48:20 INFO Completed push id=1 objects=4 duration=7.359547ms1670--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.57s)1671=== CONT TestClientPushesUseOnePush16722026/10/25 19:48:20 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16732026/10/25 19:48:20 INFO Received uploads request method=POST path=/api/pending_closures1674--- PASS: TestPresentRefreshesOnlyStaleClosures (0.30s)1675=== CONT TestConcurrentPinUpdatesAgree16762026/10/25 19:48:20 INFO Aborted multipart uploads count=0 kept=016772026/10/25 19:48:20 INFO Completed upload id=2 objects=2 duration=8.078433ms16782026/10/25 19:48:20 INFO Completed push id=1 objects=6 duration=14.981837ms16792026/10/25 19:48:20 WARN Force mode enabled - objects will be deleted immediately without grace period16802026/10/25 19:48:20 INFO Received uploads request method=POST path=/api/pending_closures1681--- PASS: TestPush_CompleteCommitsEveryRoot (2.51s)1682=== CONT TestNARDeduplicationMetadataUploadBug16832026/10/25 19:48:20 INFO Received cleanup request method=DELETE path=/api/pending_closures16842026/10/25 19:48:20 INFO Received cleanup request method=DELETE path=/api/pending_closures16852026/10/25 19:48:20 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket79/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""16862026/10/25 19:48:20 INFO Aborted multipart uploads count=0 kept=116872026/10/25 19:48:20 INFO Received create pin request method=POST path=/api/pins/deploy16882026/10/25 19:48:20 INFO Received create pin request method=POST path=/api/pins/deploy16892026/10/25 19:48:20 INFO Received create pin request method=POST path=/api/pins/deploy16902026/10/25 19:48:20 INFO Received create pin request method=POST path=/api/pins/deploy16912026/10/25 19:48:20 INFO Received create pin request method=POST path=/api/pins/deploy16922026/10/25 19:48:20 INFO Received create pin request method=POST path=/api/pins/deploy16932026/10/25 19:48:20 INFO Received create pin request method=POST path=/api/pins/deploy16942026/10/25 19:48:20 INFO Received create pin request method=POST path=/api/pins/deploy16952026/10/25 19:48:20 INFO Received cleanup request method=DELETE path=/api/pending_closures1696--- PASS: TestPresentReportsOnlyClosureRoots (0.26s)1697=== CONT TestMetricsInventory16982026/10/25 19:48:20 INFO Aborted multipart uploads count=1 kept=016992026/10/25 19:48:20 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=017002026/10/25 19:48:20 INFO Vacuumed table table=pending_closures1701--- PASS: TestMetricsCommit (1.59s)1702=== CONT TestCacheStatsHandler17032026/10/25 19:48:20 INFO Vacuumed table table=pending_objects17042026/10/25 19:48:20 INFO Vacuumed table table=multipart_uploads17052026/10/25 19:48:20 INFO Vacuumed table table=closures17062026/10/25 19:48:20 INFO Vacuumed table table=objects1707--- PASS: TestMultipartCleanup (0.44s)1708=== CONT TestClientErrorHandling1709=== RUN TestClientErrorHandling/InvalidStorePath1710=== PAUSE TestClientErrorHandling/InvalidStorePath1711=== RUN TestClientErrorHandling/InvalidAuthToken1712=== PAUSE TestClientErrorHandling/InvalidAuthToken1713=== RUN TestClientErrorHandling/ServerNotAvailable1714=== PAUSE TestClientErrorHandling/ServerNotAvailable1715=== CONT TestCacheConfigHandler1716=== RUN TestCacheConfigHandler/full_config,_no_issuer1717=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1718=== RUN TestCacheConfigHandler/no_cache_url_configured1719=== PAUSE TestCacheConfigHandler/no_cache_url_configured1720=== RUN TestCacheConfigHandler/no_signing_keys1721=== PAUSE TestCacheConfigHandler/no_signing_keys1722=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1723=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1724=== CONT TestService_AuthMiddleware_MTLSProxyHeader17252026/10/25 19:48:20 INFO Received create pin request method=POST path=/api/pins/deploy17262026/10/25 19:48:20 INFO Received create pin request method=POST path=/api/pins/app1727=== NAME TestOrphanedObjectsGC1728 orphaned_objects_gc_test.go:287: GC Test Summary:1729 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1730 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1731 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1732 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1733 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects17342026/10/25 19:48:20 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo17352026/10/25 19:48:20 INFO Received delete pin request method=DELETE path=/api/pins/app17362026/10/25 19:48:20 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket86/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"17372026/10/25 19:48:20 INFO Received delete pin request method=DELETE path=/api/pins/app17382026/10/25 19:48:20 INFO lead: acquired remote=192.0.2.1:12341739--- PASS: TestOrphanedObjectsGC (0.76s)1740=== CONT TestChildrenInheritRaisedFileLimit1741--- PASS: TestChildrenInheritRaisedFileLimit (0.00s)1742=== CONT TestUploadHandlersRejectOversizedBody17432026/10/25 19:48:20 INFO Deleted pin name=app1744--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.24s)1745=== CONT TestClientMultipleUploads17462026/10/25 19:48:20 INFO Received create pin request method=POST path=/api/pins/app17472026/10/25 19:48:20 INFO Received create pin request method=POST path=/api/pins/app17482026/10/25 19:48:20 INFO Received push request method=POST path=/api/pushes17492026/10/25 19:48:20 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)17502026/10/25 19:48:20 INFO Uploading v36ah59pxz9gk478m618p95mdwm9djbi-shared-dep (136B)17512026/10/25 19:48:20 INFO Uploading z4dl4f7hzr355yl0i1s3knjvcg2k92f9-top (224B)17522026/10/25 19:48:20 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17532026/10/25 19:48:20 WARN Failed to register uploaded object key=nar/058d8vzpmd9cgih1a4ivgp2rnw36zn8i8499a4dik87aba14pjb5.nar.zst error="server returned 404: 404 page not found\n"17542026/10/25 19:48:20 WARN Failed to register uploaded object key=z4dl4f7hzr355yl0i1s3knjvcg2k92f9.ls error="server returned 404: 404 page not found\n"17552026/10/25 19:48:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17562026/10/25 19:48:20 WARN Failed to register uploaded object key=v36ah59pxz9gk478m618p95mdwm9djbi.ls error="server returned 404: 404 page not found\n"17572026/10/25 19:48:20 INFO Signed narinfos id=1 count=217582026/10/25 19:48:20 INFO Uploading 2 narinfos17592026/10/25 19:48:20 WARN Failed to register uploaded object key=v36ah59pxz9gk478m618p95mdwm9djbi.narinfo error="server returned 404: 404 page not found\n"1760=== NAME TestNARDeduplicationMetadataUploadBug1761 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug50727278/001/store/sz0b6jgbd7wky16qhy2z1df6iy9v47z6-file1.txt17622026/10/25 19:48:20 INFO Received complete push request method=POST path=/api/pushes/1/complete17632026/10/25 19:48:20 WARN Failed to register uploaded object key=z4dl4f7hzr355yl0i1s3knjvcg2k92f9.narinfo error="server returned 404: 404 page not found\n"17642026/10/25 19:48:20 INFO Completed push id=1 objects=6 duration=6.051315ms17652026/10/25 19:48:20 INFO Upload complete. (87ms)1766=== NAME TestClientSharedPathCommittedMidPush1767 client_integration_test.go:803: Retrieved narinfo from S3:1768 StorePath: /build/TestClientSharedPathCommittedMidPush2094346412/001/store/v36ah59pxz9gk478m618p95mdwm9djbi-shared-dep1769 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1770 Compression: zstd1771 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821772 NarSize: 1361773 References: 1774 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1775 client_integration_test.go:803: Retrieved narinfo from S3:1776 StorePath: /build/TestClientSharedPathCommittedMidPush2094346412/001/store/z4dl4f7hzr355yl0i1s3knjvcg2k92f9-top1777 URL: nar/058d8vzpmd9cgih1a4ivgp2rnw36zn8i8499a4dik87aba14pjb5.nar.zst1778 Compression: zstd1779 NarHash: sha256:058d8vzpmd9cgih1a4ivgp2rnw36zn8i8499a4dik87aba14pjb51780 NarSize: 2241781 References: /build/TestClientSharedPathCommittedMidPush2094346412/001/store/v36ah59pxz9gk478m618p95mdwm9djbi-shared-dep1782 CA: text:sha256:1v3yirg505d52l9pj1ciyy4xzah95417m614s3r6dxwyh83c5znw1783--- PASS: TestCacheStatsHandler (0.24s)1784=== CONT TestService_RequireScope_OIDC1785=== CONT TestClientWithDependencies1786--- PASS: TestMetricsInventory (0.25s)1787=== CONT TestCacheConfigHandlerMaxNarSize1788--- PASS: TestClientSharedPathCommittedMidPush (0.46s)1789=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1790--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)17912026/10/25 19:48:20 INFO Received uploads request method=POST path=/1792=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17932026/10/25 19:48:20 INFO Received request for more parts method=POST path=/1794=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1795--- PASS: TestPushWaitsForSweepHoldingRow (0.79s)1796=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17972026/10/25 19:48:20 INFO Received uploads request method=POST path=/17982026/10/25 19:48:20 INFO Received complete multipart upload request method=POST path=/1799=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1800=== CONT TestPendingClosureWriteTimeout/400_objects1801--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)1802 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1803 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1804 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1805 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1806=== CONT TestProxyWriteTimeout/1_GiB_nar1807=== CONT TestPendingClosureWriteTimeout/empty1808=== CONT TestProxyWriteTimeout/10_GiB_nar1809=== CONT TestProxyWriteTimeout/unknown_size1810=== CONT TestProxyWriteTimeout/narinfo1811=== CONT TestPendingClosureWriteTimeout/670k_objects1812=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1813--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.23s)1814=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1815--- PASS: TestProxyWriteTimeout (0.01s)1816 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1817 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1818 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1819 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)18202026/10/25 19:48:20 INFO Received push request method=POST path=/api/pushes18212026/10/25 19:48:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18222026/10/25 19:48:20 INFO Uploading sz0b6jgbd7wky16qhy2z1df6iy9v47z6-file1.txt (160B)18232026/10/25 19:48:20 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"18242026/10/25 19:48:20 INFO Received push request method=POST path=/api/pushes1825=== NAME TestClientMultipleUploads1826 client_integration_test.go:467: Created store path 0: /build/TestClientMultipleUploads3365035858/001/store/j6ds8kin447gp654j32paigcx9xwyn0l-test-file-0.txt18272026/10/25 19:48:20 WARN Failed to register uploaded object key=sz0b6jgbd7wky16qhy2z1df6iy9v47z6.ls error="server returned 404: 404 page not found\n"18282026/10/25 19:48:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18292026/10/25 19:48:20 INFO Signed narinfos id=1 count=118302026/10/25 19:48:20 INFO Uploading 1 narinfos18312026/10/25 19:48:20 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)18322026/10/25 19:48:20 INFO Uploading g02xkpby34kghzmf7x5zmk17wzqlqk66-shared-dep (136B)18332026/10/25 19:48:20 INFO Uploading axg1y7vb0zdhq3ymf8rfp8dr7vqllram-b (216B)18342026/10/25 19:48:20 INFO Received complete push request method=POST path=/api/pushes/1/complete18352026/10/25 19:48:20 WARN Failed to register uploaded object key=sz0b6jgbd7wky16qhy2z1df6iy9v47z6.narinfo error="server returned 404: 404 page not found\n"18362026/10/25 19:48:20 INFO Completed push id=1 objects=3 duration=6.854603ms18372026/10/25 19:48:20 INFO Upload complete. (84ms)18382026/10/25 19:48:20 WARN Failed to register uploaded object key=axg1y7vb0zdhq3ymf8rfp8dr7vqllram.ls error="server returned 404: 404 page not found\n"18392026/10/25 19:48:20 WARN Failed to register uploaded object key=nar/0wf3fr8ibzd1y59chhn1i3w6pk4ah9x9zmpp3mb8zkva6sf7yxms.nar.zst error="server returned 404: 404 page not found\n"1840=== NAME TestNARDeduplicationMetadataUploadBug1841 metadata_upload_test.go:54: Retrieved narinfo from S3:1842 StorePath: /build/TestNARDeduplicationMetadataUploadBug50727278/001/store/sz0b6jgbd7wky16qhy2z1df6iy9v47z6-file1.txt1843 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1844 Compression: zstd1845 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1846 NarSize: 1601847 References: 1848 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf18492026/10/25 19:48:20 WARN Failed to register uploaded object key=40lizm71y94k5pi856wba84ac656lwi9.ls error="server returned 404: 404 page not found\n"18502026/10/25 19:48:20 WARN Failed to register uploaded object key=g02xkpby34kghzmf7x5zmk17wzqlqk66.ls error="server returned 404: 404 page not found\n"18512026/10/25 19:48:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18522026/10/25 19:48:20 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"18532026/10/25 19:48:20 INFO Signed narinfos id=1 count=318542026/10/25 19:48:20 INFO Uploading 3 narinfos1855 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1856 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1857 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}18582026/10/25 19:48:20 WARN Failed to register uploaded object key=g02xkpby34kghzmf7x5zmk17wzqlqk66.narinfo error="server returned 404: 404 page not found\n"18592026/10/25 19:48:20 INFO Received complete push request method=POST path=/api/pushes/1/complete18602026/10/25 19:48:20 WARN Failed to register uploaded object key=40lizm71y94k5pi856wba84ac656lwi9.narinfo error="server returned 404: 404 page not found\n"18612026/10/25 19:48:20 WARN Failed to register uploaded object key=axg1y7vb0zdhq3ymf8rfp8dr7vqllram.narinfo error="server returned 404: 404 page not found\n"1862=== NAME TestClientMultipleUploads1863 client_integration_test.go:467: Created store path 1: /build/TestClientMultipleUploads3365035858/001/store/9sxzxh2v3nwqizp4kr25v3x65rhi36w1-test-file-1.txt18642026/10/25 19:48:20 INFO Completed push id=1 objects=8 duration=5.937374ms18652026/10/25 19:48:20 INFO Upload complete. (86ms)1866=== NAME TestClientPushesUseOnePush1867 client_pushes_test.go:97: Retrieved narinfo from S3:1868 StorePath: /build/TestClientPushesUseOnePush1474313377/001/store/g02xkpby34kghzmf7x5zmk17wzqlqk66-shared-dep1869 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1870 Compression: zstd1871 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821872 NarSize: 1361873 References: 1874 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1875 client_pushes_test.go:97: Retrieved narinfo from S3:1876 StorePath: /build/TestClientPushesUseOnePush1474313377/001/store/40lizm71y94k5pi856wba84ac656lwi9-a1877 URL: nar/0wf3fr8ibzd1y59chhn1i3w6pk4ah9x9zmpp3mb8zkva6sf7yxms.nar.zst1878 Compression: zstd1879 NarHash: sha256:0wf3fr8ibzd1y59chhn1i3w6pk4ah9x9zmpp3mb8zkva6sf7yxms1880 NarSize: 2161881 References: /build/TestClientPushesUseOnePush1474313377/001/store/g02xkpby34kghzmf7x5zmk17wzqlqk66-shared-dep1882 CA: text:sha256:0vj9wfin3x11v95bgmrpwas3lcnyd1x7z6ww0ga3ndj90kq6h0ph1883 client_pushes_test.go:97: Retrieved narinfo from S3:1884 StorePath: /build/TestClientPushesUseOnePush1474313377/001/store/axg1y7vb0zdhq3ymf8rfp8dr7vqllram-b1885 URL: nar/0wf3fr8ibzd1y59chhn1i3w6pk4ah9x9zmpp3mb8zkva6sf7yxms.nar.zst1886 Compression: zstd1887 NarHash: sha256:0wf3fr8ibzd1y59chhn1i3w6pk4ah9x9zmpp3mb8zkva6sf7yxms1888 NarSize: 2161889 References: /build/TestClientPushesUseOnePush1474313377/001/store/g02xkpby34kghzmf7x5zmk17wzqlqk66-shared-dep1890 CA: text:sha256:0vj9wfin3x11v95bgmrpwas3lcnyd1x7z6ww0ga3ndj90kq6h0ph1891=== NAME TestNARDeduplicationMetadataUploadBug1892 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug50727278/001/store/ar7ixhl5ca4rjdcdn3yjpaxjy4rc602l-file2.txt1893=== NAME TestClientMultipleUploads1894 client_integration_test.go:467: Created store path 2: /build/TestClientMultipleUploads3365035858/001/store/fayyraz72xabsmcwh03bixr7yn0md5jf-test-file-2.txt18952026/10/25 19:48:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1896--- PASS: TestClientPushesUseOnePush (0.47s)1897=== CONT TestPush_RejectsBadRequests/root_not_in_objects18982026/10/25 19:48:20 INFO Received push request method=POST path=/api/pushes1899=== CONT TestPush_RejectsBadRequests/no_objects19002026/10/25 19:48:20 INFO Received push request method=POST path=/api/pushes1901=== CONT TestPush_RejectsBadRequests/no_roots19022026/10/25 19:48:20 INFO Received push request method=POST path=/api/pushes1903=== CONT TestPush_RejectsBadRequests/bad_root19042026/10/25 19:48:20 INFO Received push request method=POST path=/api/pushes19052026/10/25 19:48:20 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1906=== CONT TestIsValidUploadKey/narinfo1907=== CONT TestIsValidUploadKey/realisation1908=== CONT TestIsValidUploadKey/build_log_question_mark1909=== CONT TestIsValidUploadKey/build_log_equals1910=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1911=== CONT TestIsValidUploadKey/build_log_home-manager_file1912=== CONT TestIsValidUploadKey/listing1913=== CONT TestIsValidUploadKey/traversal1914=== CONT TestIsValidUploadKey/nar_plain1915=== CONT TestIsValidUploadKey/unknown_type1916=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1917=== CONT TestIsValidUploadKey/nar_zst1918=== CONT TestIsValidUploadKey/index.html1919=== CONT TestIsValidUploadKey/traversal_nar1920=== CONT TestIsValidUploadKey/build_log1921=== CONT TestIsValidUploadKey/realisation_plus_in_output1922=== CONT TestIsValidUploadKey/nix-cache-info1923=== CONT TestIsValidUploadKey/build_log_plus_in_name1924=== CONT TestIsValidUploadKey/nar_xz1925=== CONT TestIsValidUploadKey/empty_key1926=== CONT TestIsValidUploadKey/absolute1927=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1928=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1929--- PASS: TestIsValidUploadKey (0.00s)1930 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1931 --- PASS: TestIsValidUploadKey/realisation (0.00s)1932 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1933 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1934 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1935 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1936 --- PASS: TestIsValidUploadKey/listing (0.00s)1937 --- PASS: TestIsValidUploadKey/traversal (0.00s)1938 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1939 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1940 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1941 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1942 --- PASS: TestIsValidUploadKey/index.html (0.00s)1943 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1944 --- PASS: TestIsValidUploadKey/build_log (0.00s)1945 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1946 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1947 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1948 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1949 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1950 --- PASS: TestIsValidUploadKey/absolute (0.00s)1951 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)19522026/10/25 19:48:20 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LmNjODJjMDEwLTM2ZjYtNDgwYi05ZjM5LWJkZTc4NzlhMmViN3gxNzkyOTU3Njk4NTY1MzAzNTg3 parts=101953--- PASS: TestPush_RejectsBadRequests (0.72s)1954 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1955 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1956 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1957 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)19582026/10/25 19:48:20 INFO Received uploads request method=POST path=/api/pending_closures19592026/10/25 19:48:20 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LjA4MGExNzVlLWMwYjUtNDkwMC05YmM4LTdhODFiNWY3YzRjYngxNzkyOTU3Njk5NTkyMzI1NzA2 parts=1019602026/10/25 19:48:20 INFO Received push request method=POST path=/api/pushes19612026/10/25 19:48:20 INFO Received complete push request method=POST path=/api/pushes/1/complete19622026/10/25 19:48:20 INFO Received push request method=POST path=/api/pushes19632026/10/25 19:48:20 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19642026/10/25 19:48:20 INFO Aborted multipart uploads count=0 kept=019652026/10/25 19:48:20 INFO Completed push id=1 objects=4 duration=7.132465ms19662026/10/25 19:48:20 WARN Force mode enabled - objects will be deleted immediately without grace period19672026/10/25 19:48:20 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign19682026/10/25 19:48:20 WARN Failed to register uploaded object key=ar7ixhl5ca4rjdcdn3yjpaxjy4rc602l.ls error="server returned 404: 404 page not found\n"19692026/10/25 19:48:20 INFO Signed narinfos id=2 count=119702026/10/25 19:48:20 INFO Uploading 1 narinfos19712026/10/25 19:48:20 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=019722026/10/25 19:48:20 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)19732026/10/25 19:48:20 INFO Uploading j6ds8kin447gp654j32paigcx9xwyn0l-test-file-0.txt (160B)19742026/10/25 19:48:20 INFO Uploading 9sxzxh2v3nwqizp4kr25v3x65rhi36w1-test-file-1.txt (160B)19752026/10/25 19:48:20 INFO Uploading fayyraz72xabsmcwh03bixr7yn0md5jf-test-file-2.txt (160B)19762026/10/25 19:48:20 INFO Received uploads request method=POST path=/api/pending_closures19772026/10/25 19:48:20 INFO Vacuumed table table=pending_closures19782026/10/25 19:48:20 INFO Vacuumed table table=pending_objects19792026/10/25 19:48:20 INFO Vacuumed table table=multipart_uploads19802026/10/25 19:48:20 INFO Vacuumed table table=closures19812026/10/25 19:48:20 INFO Received complete push request method=POST path=/api/pushes/2/complete19822026/10/25 19:48:20 WARN Failed to register uploaded object key=ar7ixhl5ca4rjdcdn3yjpaxjy4rc602l.narinfo error="server returned 404: 404 page not found\n"19832026/10/25 19:48:20 INFO Vacuumed table table=objects19842026/10/25 19:48:20 INFO Completed push id=2 objects=3 duration=1.995938ms19852026/10/25 19:48:20 INFO Upload complete. (59ms)19862026/10/25 19:48:20 INFO Aborted multipart uploads count=0 kept=01987--- PASS: TestDeleteClosuresRacingPins (1.92s)1988=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1989=== NAME TestNARDeduplicationMetadataUploadBug19902026/10/25 19:48:20 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"1991 metadata_upload_test.go:76: Retrieved narinfo from S3:1992 StorePath: /build/TestNARDeduplicationMetadataUploadBug50727278/001/store/ar7ixhl5ca4rjdcdn3yjpaxjy4rc602l-file2.txt1993 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1994 Compression: zstd1995 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1996 NarSize: 1601997 References: 1998 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1999--- PASS: TestPush_RepeatedRootCommitsOnce (1.51s)2000=== CONT TestResolveDBConnectionString/flag_wins2001=== CONT TestResolveDBConnectionString/nothing_configured2002=== CONT TestResolveDBConnectionString/missing_file_is_an_error2003=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2004=== CONT TestResolveDBConnectionString/file_when_flag_empty2005=== CONT TestServerTLSConfig/missing_CA_file2006=== CONT TestServerTLSConfig/not_a_PEM_file20072026/10/25 19:48:20 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"2008--- PASS: TestResolveDBConnectionString (0.00s)2009 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2010 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2011 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2012 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2013 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)20142026/10/25 19:48:20 WARN Failed to register uploaded object key=j6ds8kin447gp654j32paigcx9xwyn0l.ls error="server returned 404: 404 page not found\n"20152026/10/25 19:48:20 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"2016=== CONT TestServerTLSConfig/no_client_CA2017=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20182026/10/25 19:48:20 INFO Received uploads request method=POST path=/api/pending_closures2019--- PASS: TestServerTLSConfig (0.00s)2020 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2021 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2022 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)20232026/10/25 19:48:20 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]2024=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured20252026/10/25 19:48:20 WARN Force mode enabled - objects will be deleted immediately without grace period2026=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2027=== NAME TestNARDeduplicationMetadataUploadBug2028 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)20292026/10/25 19:48:20 WARN Failed to register uploaded object key=9sxzxh2v3nwqizp4kr25v3x65rhi36w1.ls error="server returned 404: 404 page not found\n"20302026/10/25 19:48:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20312026/10/25 19:48:20 WARN Failed to register uploaded object key=fayyraz72xabsmcwh03bixr7yn0md5jf.ls error="server returned 404: 404 page not found\n"20322026/10/25 19:48:20 INFO Signed narinfos id=1 count=320332026/10/25 19:48:20 INFO Uploading 3 narinfos20342026/10/25 19:48:20 WARN Authentication failed token_preview=eyJhbGciOi...TfXIH-zfhQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2035=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2036=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark2037=== NAME TestNARDeduplicationMetadataUploadBug2038 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2039 {"version":1,"root":{"type":"regular","size":44}}2040=== NAME TestClientWithDependencies2041 client_integration_test.go:722: Built derivation: /build/TestClientWithDependencies2649601409/001/store/5rdiifp848fwcf8ncy1fply88phch7av-test-script20422026/10/25 19:48:20 WARN Failed to register uploaded object key=9sxzxh2v3nwqizp4kr25v3x65rhi36w1.narinfo error="server returned 404: 404 page not found\n"20432026/10/25 19:48:20 INFO Received complete push request method=POST path=/api/pushes/1/complete20442026/10/25 19:48:20 WARN Failed to register uploaded object key=j6ds8kin447gp654j32paigcx9xwyn0l.narinfo error="server returned 404: 404 page not found\n"20452026/10/25 19:48:20 WARN Failed to register uploaded object key=fayyraz72xabsmcwh03bixr7yn0md5jf.narinfo error="server returned 404: 404 page not found\n"20462026/10/25 19:48:20 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=020472026/10/25 19:48:20 INFO Vacuumed table table=pending_closures20482026/10/25 19:48:20 INFO Vacuumed table table=pending_objects20492026/10/25 19:48:20 INFO Completed push id=1 objects=9 duration=7.105065ms20502026/10/25 19:48:20 INFO Upload complete. (102ms)20512026/10/25 19:48:20 INFO Vacuumed table table=multipart_uploads2052=== NAME TestClientMultipleUploads2053 client_integration_test.go:478: Uploaded 3 paths in 132.798511ms20542026/10/25 19:48:20 INFO Vacuumed table table=closures2055=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete20562026/10/25 19:48:20 INFO Vacuumed table table=objects2057--- PASS: TestService_AuthMiddleware_OIDC (0.44s)2058 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2059 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2060 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)2061 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2062--- PASS: TestNARDeduplicationMetadataUploadBug (0.57s)2063=== CONT TestGCEndsOnShutdown/before_the_run2064=== NAME TestClientWithDependencies2065 client_integration_test.go:724: Found 1 dependencies (including self)20662026/10/25 19:48:20 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36825/oidc2067--- PASS: TestClientMultipleUploads (0.45s)2068=== CONT TestIsValidCachePath/nar_xz2069=== CONT TestIsValidCachePath/short_hash2070=== CONT TestIsValidCachePath/traversal_parent2071=== CONT TestIsValidCachePath/wrong_extension2072=== CONT TestIsValidCachePath/leading_slash2073=== CONT TestIsValidCachePath/random_path2074=== CONT TestIsValidCachePath/empty2075=== CONT TestIsValidCachePath/invalid_char_e2076=== CONT TestIsValidCachePath/traversal_in_middle2077=== CONT TestIsValidCachePath/invalid_char_u2078=== CONT TestIsValidCachePath/index.html2079=== CONT TestIsValidCachePath/nar_bz22080=== CONT TestIsValidCachePath/nix-cache-info2081=== CONT TestIsValidCachePath/ls2082=== CONT TestIsValidCachePath/log2083=== CONT TestIsValidCachePath/nar_zst2084=== CONT TestIsValidCachePath/realisation2085=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2086=== CONT TestIsValidCachePath/nar_uncompressed2087=== CONT TestIsValidCachePath/narinfo2088=== CONT TestParseSingleRange/multi-range_ignored2089--- PASS: TestIsValidCachePath (0.00s)2090 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2091 --- PASS: TestIsValidCachePath/short_hash (0.00s)2092 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2093 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2094 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2095 --- PASS: TestIsValidCachePath/random_path (0.00s)2096 --- PASS: TestIsValidCachePath/empty (0.00s)2097 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2098 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2099 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2100 --- PASS: TestIsValidCachePath/index.html (0.00s)2101 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2102 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2103 --- PASS: TestIsValidCachePath/ls (0.00s)2104 --- PASS: TestIsValidCachePath/log (0.00s)2105 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2106 --- PASS: TestIsValidCachePath/realisation (0.00s)2107 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2108 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2109 --- PASS: TestIsValidCachePath/narinfo (0.00s)2110=== CONT TestParseSingleRange/closed2111=== CONT TestParseSingleRange/start_far_past_EOF2112=== CONT TestParseSingleRange/start_past_EOF2113=== CONT TestParseSingleRange/single_byte2114=== CONT TestParseSingleRange/suffix_exceeds_size2115=== CONT TestParseSingleRange/suffix2116=== CONT TestParseSingleRange/end_clamped_to_size2117=== CONT TestParseSingleRange/malformed_no_dash2118=== CONT TestParseSingleRange/malformed_end_before_start2119=== CONT TestParseSingleRange/malformed_both_empty2120=== CONT TestParseSingleRange/unknown_unit2121=== CONT TestParseSingleRange/none2122=== CONT TestParseSingleRange/open-ended2123=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false2124--- PASS: TestParseSingleRange (0.00s)2125 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2126 --- PASS: TestParseSingleRange/closed (0.00s)2127 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2128 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2129 --- PASS: TestParseSingleRange/single_byte (0.00s)2130 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2131 --- PASS: TestParseSingleRange/suffix (0.00s)2132 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2133 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2134 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2135 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2136 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2137 --- PASS: TestParseSingleRange/none (0.00s)2138 --- PASS: TestParseSingleRange/open-ended (0.00s)2139=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart2140=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart2141=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts2142=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts2143=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure2144=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure2145=== CONT TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true2146=== CONT TestClientErrorHandling/InvalidAuthToken2147--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2148 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.26s)2149 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.33s)21502026/10/25 19:48:20 INFO Received push request method=POST path=/api/pushes21512026/10/25 19:48:20 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21522026/10/25 19:48:20 INFO Uploading 5rdiifp848fwcf8ncy1fply88phch7av-test-script (136B)21532026/10/25 19:48:20 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"21542026/10/25 19:48:20 WARN Failed to register uploaded object key=log/2pgkm94nx9ws51ikxrqz48kg817f1df6-test-script.drv error="server returned 404: 404 page not found\n"21552026/10/25 19:48:21 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21562026/10/25 19:48:21 INFO Signed narinfos id=1 count=121572026/10/25 19:48:21 INFO Uploading 1 narinfos21582026-10-25 19:48:21.015 UTC [174] LOG: checkpoints are occurring too frequently (9 seconds apart)21592026-10-25 19:48:21.015 UTC [174] HINT: Consider increasing the configuration parameter "max_wal_size".21602026-10-25 19:48:21.015 UTC [174] LOG: checkpoint starting: wal21612026/10/25 19:48:21 WARN Failed to register uploaded object key=5rdiifp848fwcf8ncy1fply88phch7av.ls error="server returned 404: 404 page not found\n"21622026/10/25 19:48:21 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo21632026/10/25 19:48:21 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo21642026/10/25 19:48:21 INFO Received complete push request method=POST path=/api/pushes/1/complete21652026/10/25 19:48:21 WARN Failed to register uploaded object key=5rdiifp848fwcf8ncy1fply88phch7av.narinfo error="server returned 404: 404 page not found\n"21662026/10/25 19:48:21 INFO Completed push id=1 objects=4 duration=5.598391ms21672026/10/25 19:48:21 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>21682026/10/25 19:48:21 INFO Upload complete. (160ms)21692026/10/25 19:48:21 INFO Aborted multipart uploads count=0 kept=02170--- PASS: TestConcurrentPinUpdatesAgree (0.83s)2171=== CONT TestClientErrorHandling/InvalidStorePath21722026/10/25 19:48:21 WARN Force mode enabled - objects will be deleted immediately without grace period21732026/10/25 19:48:21 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=021742026/10/25 19:48:21 INFO Vacuumed table table=pending_closures21752026/10/25 19:48:21 INFO Vacuumed table table=pending_objects21762026/10/25 19:48:21 INFO Vacuumed table table=multipart_uploads21772026/10/25 19:48:21 INFO Vacuumed table table=closures21782026/10/25 19:48:21 INFO Vacuumed table table=objects2179=== NAME TestClientWithDependencies2180 client_integration_test.go:740: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2649601409/001/store) requires matching store prefix2181--- PASS: TestReadProxyNarinfo (1.34s)2182=== CONT TestClientErrorHandling/ServerNotAvailable21832026/10/25 19:48:21 INFO lead: released remote=192.0.2.1:123421842026/10/25 19:48:21 INFO Aborted multipart uploads count=0 kept=021852026/10/25 19:48:21 INFO Aborted multipart uploads count=0 kept=021862026/10/25 19:48:21 WARN Force mode enabled - objects will be deleted immediately without grace period21872026/10/25 19:48:21 WARN Force mode enabled - objects will be deleted immediately without grace period2188=== CONT TestCacheConfigHandler/full_config,_no_issuer2189--- PASS: TestClientWithDependencies (0.57s)2190=== CONT TestCacheConfigHandler/no_signing_keys2191=== CONT TestCacheConfigHandler/no_cache_url_configured2192=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2193=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart2194--- PASS: TestCacheConfigHandler (0.00s)2195 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2196 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2197 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2198 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)21992026/10/25 19:48:21 INFO Received complete multipart upload request method=POST path=/22002026/10/25 19:48:21 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:37121/bucket102/?delete=\": context canceled"2201=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure2202--- PASS: TestLeadEndsOnShutdown (1.39s)22032026/10/25 19:48:21 INFO Received uploads request method=POST path=/22042026/10/25 19:48:21 INFO Received uploads request method=POST path=/api/pending_closures2205=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts22062026/10/25 19:48:21 INFO Received request for more parts method=POST path=/2207--- PASS: TestGCEndsOnShutdown (0.00s)2208 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.36s)2209 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.33s)2210 --- PASS: TestGCEndsOnShutdown/before_the_run (0.32s)22112026/10/25 19:48:21 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/present22122026/10/25 19:48:21 INFO Received uploads request method=POST path=/api/pending_closures2213=== RUN TestService_RequireScope_OIDC/builder_may_write2214=== PAUSE TestService_RequireScope_OIDC/builder_may_write2215=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2216=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2217=== RUN TestService_RequireScope_OIDC/ops_may_admin2218=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2219=== RUN TestService_RequireScope_OIDC/ops_may_not_write2220=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2221=== RUN TestService_RequireScope_OIDC/reader_may_not_write2222=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2223=== RUN TestService_RequireScope_OIDC/static_token_may_admin2224=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2225=== RUN TestService_RequireScope_OIDC/static_token_may_write2226=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2227=== RUN TestService_RequireScope_OIDC/reader_may_read2228=== PAUSE TestService_RequireScope_OIDC/reader_may_read2229=== RUN TestService_RequireScope_OIDC/writer_implies_read2230=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2231=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2232=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2233=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc2234=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc2235=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2236=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2237=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2238=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2239=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2240=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2241=== CONT TestService_RequireScope_OIDC/reader_may_not_write2242=== CONT TestService_RequireScope_OIDC/static_token_may_write2243=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2244=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2245=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read22462026/10/25 19:48:21 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]2247=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2248=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2249=== CONT TestService_RequireScope_OIDC/ops_may_not_write2250=== CONT TestService_RequireScope_OIDC/static_token_may_admin2251=== CONT TestService_RequireScope_OIDC/reader_may_read2252=== CONT TestService_RequireScope_OIDC/writer_implies_read2253=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2254=== CONT TestService_RequireScope_OIDC/ops_may_admin2255=== CONT TestService_RequireScope_OIDC/builder_may_write22562026/10/25 19:48:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22572026/10/25 19:48:21 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LmJiNjFiN2M2LTZiNDItNGI3Ny05MGUyLWFhNTgwZmE4YjY4MHgxNzkyOTU3Njk4NTY1NjI0ODkw parts=102258--- PASS: TestService_RequireScope_OIDC (0.68s)2259 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2260 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2261 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2262 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2263 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2264 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2265 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2266 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2267 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2268 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2269 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2270 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2271 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2272 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)22732026/10/25 19:48:21 INFO Received create pin request method=POST path=/api/pins/deploy22742026/10/25 19:48:21 WARN Request failed, retrying attempt=2 backoff=200.0972ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22752026/10/25 19:48:21 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo22762026/10/25 19:48:21 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2277--- PASS: TestCreatePinRejectsBadInput (1.23s)22782026/10/25 19:48:21 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22792026/10/25 19:48:21 WARN Request failed, retrying attempt=3 backoff=437.375557ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22802026/10/25 19:48:21 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=022812026/10/25 19:48:21 INFO Received create pin request method=POST path=/api/pins/myapp22822026/10/25 19:48:21 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2916069015/001/store/xf5sgjr4n4ij5xrd0v3pb5x6yxjhncc4-pinned-file.txt narinfo_key=xf5sgjr4n4ij5xrd0v3pb5x6yxjhncc4.narinfo22832026/10/25 19:48:21 INFO Starting cleanup of old closures method=DELETE path=/api/closures22842026/10/25 19:48:21 INFO Garbage collection started22852026/10/25 19:48:21 INFO Aborted multipart uploads count=0 kept=022862026/10/25 19:48:21 WARN Force mode enabled - objects will be deleted immediately without grace period2287--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2288 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.75s)2289 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.80s)22902026/10/25 19:48:21 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=022912026/10/25 19:48:21 INFO lead: released remote=192.0.2.1:123422922026/10/25 19:48:21 INFO Vacuumed table table=pending_closures22932026/10/25 19:48:21 INFO Vacuumed table table=pending_objects22942026/10/25 19:48:21 INFO Vacuumed table table=multipart_uploads22952026/10/25 19:48:21 INFO Vacuumed table table=closures22962026/10/25 19:48:21 INFO Vacuumed table table=objects2297--- PASS: TestPendingClosureWriteTimeout (0.01s)2298 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2299 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2300 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2301 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.06s)23022026/10/25 19:48:21 INFO lead: acquired remote=192.0.2.1:123423032026/10/25 19:48:21 WARN Failed to abort multipart upload key=nar/ssssssssssssssssssssssssssssssssssssssssssssssssssss.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2Ljg5YjE0NGQwLTc3MTUtNGEwOC05NzI3LTM1ODFkMmJkMjZlOHgxNzkyOTU3NzAxMjU5MTI3MTc2 error="Access Denied"23042026/10/25 19:48:21 WARN keeping failed pending closure for cleanup to retry the abort id=123052026/10/25 19:48:21 INFO Received complete multipart upload request method=POST path=/api/multipart/complete23062026/10/25 19:48:21 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggggg00000000000000000000.nar.zst upload_id=MzdhNGJmYzgtYmVkZS00YzY5LWJlOTEtMWVjNTk5ZGNkODc2LjI0NjBlZjM2LTE4N2EtNDU2Ni1iMTY0LWYwZmU0ZjhiMGEzNngxNzkyOTU3Njk4NTY1MzcyMzA3 parts=102307--- PASS: TestPendingClosureFailureTracksEveryUpload (0.00s)2308 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=false (0.83s)2309 --- PASS: TestPendingClosureFailureTracksEveryUpload/refuse_aborts=true (0.85s)23102026-10-25 19:48:21.808 UTC [587] ERROR: could not obtain lock on row in relation "closures"23112026-10-25 19:48:21.808 UTC [587] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23122026-10-25 19:48:21.808 UTC [587] ERROR: could not obtain lock on row in relation "closures"23132026-10-25 19:48:21.808 UTC [587] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23142026-10-25 19:48:21.809 UTC [587] ERROR: could not obtain lock on row in relation "closures"23152026-10-25 19:48:21.809 UTC [587] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23162026-10-25 19:48:21.809 UTC [587] ERROR: could not obtain lock on row in relation "closures"23172026-10-25 19:48:21.809 UTC [587] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT23182026-10-25 19:48:21.810 UTC [587] ERROR: could not obtain lock on row in relation "closures"23192026-10-25 19:48:21.810 UTC [587] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT2320=== NAME TestOrphanedObjectsGCStressTest2321 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2322 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion2323--- PASS: TestPush_RootsAreLockedInByteOrder (4.04s)23242026/10/25 19:48:21 WARN Request failed, retrying attempt=4 backoff=780.611268ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23252026/10/25 19:48:22 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02326=== NAME TestClientIntegration2327 client_integration_test.go:432: Objects in database after GC:2328 client_integration_test.go:432: Successfully deleted all objects with GC --force2329--- PASS: TestClientIntegration (3.21s)2330=== NAME TestOrphanedObjectsGCStressTest2331 orphaned_objects_gc_test.go:503: Stress test completed successfully:2332 orphaned_objects_gc_test.go:504: - Active objects preserved: 202333 orphaned_objects_gc_test.go:505: - Objects deleted: 2102334 orphaned_objects_gc_test.go:506: - Total GC'd: 2102335--- PASS: TestOrphanedObjectsGCStressTest (3.17s)23362026/10/25 19:48:22 WARN Request failed, retrying attempt=5 backoff=1.74107267s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23372026/10/25 19:48:22 INFO lead: released remote=192.0.2.1:12342338--- PASS: TestLeadElectsOneAndHandsOver (2.57s)23392026/10/25 19:48:22 WARN Rate limiter enabled after throttle name=s3-test rate=523402026/10/25 19:48:22 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2341=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2342 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102343 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002344--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (5.12s)2345=== NAME TestPinProtectsFromGC2346 client_integration_test.go:963: Pin successfully protected closure from garbage collection2347--- PASS: TestPinProtectsFromGC (4.80s)2348--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.61s)2349--- PASS: TestConnectWaitsForAPeerMigration (5.63s)23502026/10/25 19:48:24 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-config23512026/10/25 19:48:24 WARN Request failed, retrying attempt=2 backoff=218.265862ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23522026/10/25 19:48:24 WARN Request failed, retrying attempt=3 backoff=416.886508ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23532026/10/25 19:48:25 WARN Request failed, retrying attempt=4 backoff=808.749711ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23542026/10/25 19:48:26 WARN Request failed, retrying attempt=5 backoff=1.703733632s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23552026/10/25 19:48:26 INFO Aborted multipart uploads count=1 kept=023562026/10/25 19:48:26 INFO Received cleanup request method=DELETE path=/api/pending_closures23572026/10/25 19:48:26 INFO Aborted multipart uploads count=1 kept=02358--- PASS: TestPendingCleanupUsesOneCutoff (6.33s)23592026/10/25 19:48:27 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"23602026/10/25 19:48:27 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23612026/10/25 19:48:27 WARN Request failed, retrying attempt=2 backoff=191.714504ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23622026/10/25 19:48:28 WARN Request failed, retrying attempt=3 backoff=365.729395ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23632026/10/25 19:48:28 WARN Request failed, retrying attempt=4 backoff=726.290936ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23642026/10/25 19:48:29 WARN Request failed, retrying attempt=5 backoff=1.478073106s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config23652026/10/25 19:48:30 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23662026/10/25 19:48:30 WARN Request failed, retrying attempt=2 backoff=209.35022ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23672026/10/25 19:48:31 WARN Request failed, retrying attempt=3 backoff=375.493131ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23682026/10/25 19:48:31 WARN Request failed, retrying attempt=4 backoff=791.292277ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures23692026/10/25 19:48:32 WARN Request failed, retrying attempt=5 backoff=1.75078511s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2370--- PASS: TestClientErrorHandling (0.00s)2371 --- PASS: TestClientErrorHandling/InvalidStorePath (0.24s)2372 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.46s)2373 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.81s)2374--- PASS: TestUploadHandlersRejectOversizedBody (0.51s)2375 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.89s)2376 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.86s)2377 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (14.92s)2378PASS2379{"timestamp":"2026-10-25T19:48:36.102657372Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:60184","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(207)"}2380{"timestamp":"2026-10-25T19:48:36.104215327Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:59650","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(200)"}2381{"timestamp":"2026-10-25T19:48:36.104528149Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:59340","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(202)"}23822026-10-25 19:48:36.735 UTC [169] LOG: received smart shutdown request23832026-10-25 19:48:36.741 UTC [169] LOG: background worker "logical replication launcher" (PID 179) exited with exit code 123842026-10-25 19:48:37.790 UTC [174] LOG: checkpoint complete: wrote 9084 buffers (55.4%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=15.896 s, sync=0.827 s, total=16.775 s; sync files=37080, longest=0.006 s, average=0.001 s; distance=534695 kB, estimate=534695 kB; lsn=0/22B2CCB8, redo lsn=0/2218FB4023852026-10-25 19:48:37.796 UTC [174] LOG: shutting down23862026-10-25 19:48:37.796 UTC [174] LOG: checkpoint starting: shutdown immediate23872026-10-25 19:48:37.899 UTC [174] LOG: checkpoint complete: wrote 1392 buffers (8.5%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.026 s, sync=0.074 s, total=0.103 s; sync files=544, longest=0.002 s, average=0.001 s; distance=9844 kB, estimate=482210 kB; lsn=0/22B2CD30, redo lsn=0/22B2CD3023882026-10-25 19:48:38.014 UTC [169] LOG: database system is shut down2389Running OIDC tests...2390=== RUN TestAudienceForIssuer2391=== PAUSE TestAudienceForIssuer2392=== RUN TestHTTPClientForHasTimeouts2393=== PAUSE TestHTTPClientForHasTimeouts2394=== RUN TestGlobMatch2395=== PAUSE TestGlobMatch2396=== RUN TestValidateToken_ValidToken2397=== PAUSE TestValidateToken_ValidToken2398=== RUN TestValidateToken_WrongAudience2399=== PAUSE TestValidateToken_WrongAudience2400=== RUN TestValidateToken_Expired2401=== PAUSE TestValidateToken_Expired2402=== RUN TestValidateToken_BoundClaimsMismatch2403=== PAUSE TestValidateToken_BoundClaimsMismatch2404=== RUN TestValidateToken_BoundSubjectMismatch2405=== PAUSE TestValidateToken_BoundSubjectMismatch2406=== RUN TestValidateToken_MultipleProviders2407=== PAUSE TestValidateToken_MultipleProviders2408=== RUN TestValidateToken_NoMatchingProvider2409=== PAUSE TestValidateToken_NoMatchingProvider2410=== RUN TestValidateToken_KubernetesServiceAccount2411=== PAUSE TestValidateToken_KubernetesServiceAccount2412=== RUN TestNewValidator_KubernetesRequiresCA2413=== PAUSE TestNewValidator_KubernetesRequiresCA2414=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2415=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2416=== RUN TestPins_ReservedForMatchingRule2417=== PAUSE TestPins_ReservedForMatchingRule2418=== RUN TestPins_TopLevelShorthand2419=== PAUSE TestPins_TopLevelShorthand2420=== RUN TestPins_ConfigValidation2421=== PAUSE TestPins_ConfigValidation2422=== RUN TestScopes_LegacyProviderDefaultsToWrite2423=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2424=== RUN TestScopes_Rules2425=== PAUSE TestScopes_Rules2426=== RUN TestScopes_ConfigValidation2427=== PAUSE TestScopes_ConfigValidation2428=== CONT TestValidateToken_ValidToken2429=== CONT TestPins_TopLevelShorthand2430=== CONT TestValidateToken_BoundSubjectMismatch2431=== CONT TestScopes_ConfigValidation2432=== CONT TestPins_ReservedForMatchingRule2433=== CONT TestPins_ConfigValidation2434=== CONT TestNewValidator_KubernetesRequiresCA2435=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2436=== CONT TestScopes_Rules2437=== CONT TestValidateToken_Expired2438=== CONT TestValidateToken_MultipleProviders2439=== CONT TestValidateToken_NoMatchingProvider2440=== CONT TestScopes_LegacyProviderDefaultsToWrite2441=== CONT TestValidateToken_BoundClaimsMismatch2442=== CONT TestGlobMatch2443=== RUN TestGlobMatch/foo_foo2444=== CONT TestValidateToken_WrongAudience2445=== PAUSE TestGlobMatch/foo_foo2446=== RUN TestGlobMatch/foo_bar2447=== PAUSE TestGlobMatch/foo_bar2448=== RUN TestGlobMatch/*_2449=== PAUSE TestGlobMatch/*_2450=== RUN TestGlobMatch/*_anything2451=== PAUSE TestGlobMatch/*_anything2452=== RUN TestGlobMatch/foo*_foo2453=== PAUSE TestGlobMatch/foo*_foo2454=== RUN TestGlobMatch/foo*_foobar2455=== CONT TestHTTPClientForHasTimeouts2456=== CONT TestAudienceForIssuer2457=== CONT TestValidateToken_KubernetesServiceAccount2458--- PASS: TestScopes_ConfigValidation (0.01s)2459--- PASS: TestPins_ConfigValidation (0.01s)2460--- PASS: TestAudienceForIssuer (0.00s)2461=== PAUSE TestGlobMatch/foo*_foobar2462=== RUN TestGlobMatch/foo*_bar2463=== PAUSE TestGlobMatch/foo*_bar2464=== RUN TestGlobMatch/*bar_bar2465=== PAUSE TestGlobMatch/*bar_bar2466=== RUN TestGlobMatch/*bar_foobar2467=== PAUSE TestGlobMatch/*bar_foobar2468=== RUN TestGlobMatch/*bar_foo2469=== PAUSE TestGlobMatch/*bar_foo2470=== RUN TestGlobMatch/foo*bar_foobar2471=== PAUSE TestGlobMatch/foo*bar_foobar2472=== RUN TestGlobMatch/foo*bar_foo123bar2473=== PAUSE TestGlobMatch/foo*bar_foo123bar2474=== RUN TestGlobMatch/foo*bar_foobarbaz2475=== PAUSE TestGlobMatch/foo*bar_foobarbaz2476=== RUN TestGlobMatch/*/*_foo/bar2477=== PAUSE TestGlobMatch/*/*_foo/bar2478=== RUN TestGlobMatch/*/*_foo2479=== PAUSE TestGlobMatch/*/*_foo2480=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2481=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2482=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02483=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02484=== RUN TestGlobMatch/refs/*/main_refs/heads/main2485=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2486=== RUN TestGlobMatch/fo?_foo2487=== PAUSE TestGlobMatch/fo?_foo2488=== RUN TestGlobMatch/fo?_fo2489=== PAUSE TestGlobMatch/fo?_fo2490=== RUN TestGlobMatch/fo?_fooo2491=== PAUSE TestGlobMatch/fo?_fooo2492=== RUN TestGlobMatch/?oo_foo2493=== PAUSE TestGlobMatch/?oo_foo2494=== RUN TestGlobMatch/?oo_boo2495=== PAUSE TestGlobMatch/?oo_boo2496=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2497=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2498=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2499=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2500=== CONT TestGlobMatch/*_2501=== CONT TestGlobMatch/foo*_bar2502=== CONT TestGlobMatch/foo*bar_foobarbaz2503=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2504=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2505=== CONT TestGlobMatch/?oo_foo2506=== CONT TestGlobMatch/refs/*/main_refs/heads/main2507=== CONT TestGlobMatch/foo*_foobar2508=== CONT TestGlobMatch/foo*_foo2509=== CONT TestGlobMatch/foo_bar2510=== CONT TestGlobMatch/fo?_fooo2511=== CONT TestGlobMatch/foo_foo2512=== CONT TestGlobMatch/?oo_boo2513=== CONT TestGlobMatch/*/*_foo2514=== CONT TestGlobMatch/fo?_foo2515=== CONT TestGlobMatch/*_anything2516=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02517=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2518=== CONT TestGlobMatch/*bar_bar2519=== CONT TestGlobMatch/foo*bar_foobar2520=== CONT TestGlobMatch/foo*bar_foo123bar2521=== CONT TestGlobMatch/*bar_foo2522=== CONT TestGlobMatch/*/*_foo/bar2523=== CONT TestGlobMatch/fo?_fo2524=== CONT TestGlobMatch/*bar_foobar2525--- PASS: TestGlobMatch (0.00s)2526 --- PASS: TestGlobMatch/*_ (0.00s)2527 --- PASS: TestGlobMatch/foo*_bar (0.00s)2528 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2529 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2530 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2531 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2532 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2533 --- PASS: TestGlobMatch/?oo_foo (0.00s)2534 --- PASS: TestGlobMatch/foo*_foo (0.00s)2535 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2536 --- PASS: TestGlobMatch/foo_foo (0.00s)2537 --- PASS: TestGlobMatch/*_anything (0.00s)2538 --- PASS: TestGlobMatch/*bar_bar (0.00s)2539 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2540 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2541 --- PASS: TestGlobMatch/*bar_foo (0.00s)2542 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2543 --- PASS: TestGlobMatch/foo_bar (0.00s)2544 --- PASS: TestGlobMatch/?oo_boo (0.00s)2545 --- PASS: TestGlobMatch/*/*_foo (0.00s)2546 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2547 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2548 --- PASS: TestGlobMatch/fo?_fo (0.00s)2549 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2550 --- PASS: TestGlobMatch/fo?_foo (0.00s)25512026/10/25 19:48:44 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12325522026/10/25 19:48:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33957/oidc2553--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.08s)2554--- PASS: TestScopes_Rules (0.08s)25552026/10/25 19:48:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33545/oidc25562026/10/25 19:48:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33225/oidc2557--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.10s)2558--- PASS: TestValidateToken_BoundClaimsMismatch (0.11s)25592026/10/25 19:48:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34573/oidc2560--- PASS: TestValidateToken_WrongAudience (0.15s)25612026/10/25 19:48:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43301/oidc25622026/10/25 19:48:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46331/oidc2563--- PASS: TestValidateToken_Expired (0.20s)2564--- PASS: TestValidateToken_ValidToken (0.20s)2565--- PASS: TestHTTPClientForHasTimeouts (0.20s)25662026/10/25 19:48:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40947/oidc2567--- PASS: TestValidateToken_BoundSubjectMismatch (0.24s)25682026/10/25 19:48:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45821/oidc2569--- PASS: TestPins_TopLevelShorthand (0.26s)25702026/10/25 19:48:44 http: TLS handshake error from 127.0.0.1:56344: remote error: tls: bad certificate2571--- PASS: TestNewValidator_KubernetesRequiresCA (0.31s)25722026/10/25 19:48:44 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:461652573--- PASS: TestValidateToken_KubernetesServiceAccount (0.32s)25742026/10/25 19:48:44 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37983/oidc25752026/10/25 19:48:44 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:46341/oidc25762026/10/25 19:48:44 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:34877/oidc2577--- PASS: TestValidateToken_NoMatchingProvider (0.40s)2578--- PASS: TestValidateToken_MultipleProviders (0.40s)25792026/10/25 19:48:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35169/oidc2580--- PASS: TestPins_ReservedForMatchingRule (0.77s)2581PASS2582Running hook tests...2583=== RUN TestSendPathsEmpty2584=== PAUSE TestSendPathsEmpty2585=== RUN TestQueueEnqueueAndFetch2586=== PAUSE TestQueueEnqueueAndFetch2587=== RUN TestQueueDeduplication2588=== PAUSE TestQueueDeduplication2589=== RUN TestQueueRemove2590=== PAUSE TestQueueRemove2591=== RUN TestQueueFetchBatchLimit2592=== PAUSE TestQueueFetchBatchLimit2593=== RUN TestQueueRetryMovesToBack2594=== PAUSE TestQueueRetryMovesToBack2595=== RUN TestQueueFetchRemoveLifecycle2596=== PAUSE TestQueueFetchRemoveLifecycle2597=== RUN TestQueueConcurrentWriters2598=== PAUSE TestQueueConcurrentWriters2599=== RUN TestQueueEnqueueWaitsOutSlowWriter2600=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2601=== RUN TestQueueRemoveLargeClosure2602=== PAUSE TestQueueRemoveLargeClosure2603=== RUN TestServerClientIntegration2604--- PASS: TestServerClientIntegration (0.01s)2605=== RUN TestServerQueueError26062026/10/25 19:48:46 ERROR Failed to queue paths error="permission denied" count=12607--- PASS: TestServerQueueError (0.00s)2608=== RUN TestServerRefusesOversizedAndNonStoreRequests2609=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2610=== RUN TestGetListenerSocketActivation2611 server_test.go:309: === RUN TestGetListenerSocketActivation2612 --- PASS: TestGetListenerSocketActivation (0.00s)2613 PASS2614 2615--- PASS: TestGetListenerSocketActivation (1.29s)2616=== RUN TestServerStalledClientDoesNotBlockShutdown2617=== PAUSE TestServerStalledClientDoesNotBlockShutdown2618=== RUN TestServerBacksOffOnAcceptErrors2619=== PAUSE TestServerBacksOffOnAcceptErrors2620=== RUN TestDrainIsolatesPoisonPath2621=== PAUSE TestDrainIsolatesPoisonPath2622=== RUN TestRunNotBlockedByPoisonHead2623=== PAUSE TestRunNotBlockedByPoisonHead2624=== RUN TestDrainGivesUpWhenServerDown2625=== PAUSE TestDrainGivesUpWhenServerDown2626=== RUN TestFailedPathPrunedByLaterClosure2627=== PAUSE TestFailedPathPrunedByLaterClosure2628=== RUN TestWorkerUploadsAndRemoves2629=== PAUSE TestWorkerUploadsAndRemoves2630=== RUN TestWorkerSkipsGCdPaths2631=== PAUSE TestWorkerSkipsGCdPaths2632=== RUN TestWorkerPrunesClosureDeps2633=== PAUSE TestWorkerPrunesClosureDeps2634=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2635=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2636=== RUN TestDrainTimeout2637=== PAUSE TestDrainTimeout2638=== RUN TestDrainTimeoutDuringIsolation2639=== PAUSE TestDrainTimeoutDuringIsolation2640=== RUN TestShutdownFinishesInFlightPush2641=== PAUSE TestShutdownFinishesInFlightPush2642=== RUN TestWorkerRemoveFailureIsNotProgress2643=== PAUSE TestWorkerRemoveFailureIsNotProgress2644=== RUN TestWorkerKeepsPathItCannotStat2645=== PAUSE TestWorkerKeepsPathItCannotStat2646=== CONT TestQueueEnqueueAndFetch2647=== CONT TestFailedPathPrunedByLaterClosure2648=== CONT TestRunNotBlockedByPoisonHead2649=== CONT TestWorkerUploadsAndRemoves2650=== CONT TestWorkerRemoveFailureIsNotProgress2651=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2652=== CONT TestWorkerKeepsPathItCannotStat2653=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2654=== CONT TestWorkerPrunesClosureDeps2655=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2656=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2657=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2658=== CONT TestWorkerSkipsGCdPaths2659=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2660=== CONT TestShutdownFinishesInFlightPush2661=== RUN TestShutdownFinishesInFlightPush/completes2662=== CONT TestDrainTimeoutDuringIsolation2663=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2664=== CONT TestDrainTimeout2665=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2666=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2667=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2668=== CONT TestQueueConcurrentWriters2669=== PAUSE TestShutdownFinishesInFlightPush/completes2670=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2671=== CONT TestQueueFetchBatchLimit2672=== CONT TestQueueFetchRemoveLifecycle2673=== CONT TestServerRefusesOversizedAndNonStoreRequests2674=== CONT TestServerBacksOffOnAcceptErrors2675=== CONT TestServerStalledClientDoesNotBlockShutdown2676=== CONT TestSendPathsEmpty2677=== CONT TestQueueRetryMovesToBack26782026/10/25 19:48:47 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store26792026/10/25 19:48:47 ERROR Accept failed error="too many open files"26802026/10/25 19:48:47 ERROR Refusing path outside the store path=/nix/store store=/nix/store2681=== CONT TestDrainGivesUpWhenServerDown26822026/10/25 19:48:47 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store26832026/10/25 19:48:47 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store26842026/10/25 19:48:47 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store2685=== CONT TestQueueEnqueueWaitsOutSlowWriter2686=== CONT TestDrainIsolatesPoisonPath2687=== CONT TestQueueRemoveLargeClosure26882026/10/25 19:48:47 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26892026/10/25 19:48:47 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26902026/10/25 19:48:47 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store2691=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2692=== CONT TestQueueRemove2693=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2694--- PASS: TestSendPathsEmpty (0.00s)26952026/10/25 19:48:47 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store2696=== CONT TestQueueDeduplication2697=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short2698=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline26992026/10/25 19:48:47 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store27002026/10/25 19:48:47 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store27012026/10/25 19:48:47 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store27022026/10/25 19:48:47 ERROR Accept failed error="too many open files"27032026/10/25 19:48:47 ERROR Accept failed error="too many open files"27042026/10/25 19:48:47 ERROR Accept failed error="too many open files"27052026/10/25 19:48:47 ERROR Failed to decode request error="read unix /build/hook2824140146/test.sock->@: i/o timeout"27062026/10/25 19:48:47 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store27072026/10/25 19:48:47 ERROR Failed to write response error="write unix /build/hook2824140146/test.sock->@: i/o timeout"2708--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.34s)2709=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path27102026/10/25 19:48:47 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store27112026/10/25 19:48:47 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store27122026/10/25 19:48:47 ERROR Failed to decode request error="unexpected EOF"2713--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.35s)2714=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths27152026/10/25 19:48:47 ERROR Accept failed error="too many open files"27162026/10/25 19:48:47 INFO Uploading batch count=427172026/10/25 19:48:47 ERROR Upload failed error="upload failed" count=42718--- PASS: TestQueueEnqueueAndFetch (0.47s)2719=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch27202026/10/25 19:48:47 INFO Upload queue status pending=22721--- PASS: TestQueueFetchRemoveLifecycle (0.47s)2722=== CONT TestShutdownFinishesInFlightPush/completes27232026/10/25 19:48:47 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3674170713/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat3674170713/002/locked/aaa: permission denied"27242026/10/25 19:48:47 INFO Upload queue status pending=227252026/10/25 19:48:47 INFO Uploading batch count=427262026/10/25 19:48:47 INFO Uploading batch count=227272026/10/25 19:48:47 ERROR Upload failed error="upload failed" count=427282026/10/25 19:48:47 INFO Upload queue status pending=327292026/10/25 19:48:47 INFO Uploading batch count=227302026/10/25 19:48:47 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2304665055/002/nonexistent27312026/10/25 19:48:47 INFO Upload queue status pending=227322026/10/25 19:48:47 INFO Uploading batch count=227332026/10/25 19:48:47 ERROR Accept failed error="too many open files"27342026/10/25 19:48:47 INFO Uploading batch count=227352026/10/25 19:48:47 ERROR Upload failed error="upload failed" count=227362026/10/25 19:48:47 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown849295130/002/a27372026/10/25 19:48:47 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path2788493932/001/nonexistent27382026/10/25 19:48:47 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown849295130/002/b27392026/10/25 19:48:47 INFO Uploading batch count=12740--- PASS: TestQueueRetryMovesToBack (0.47s)2741=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout27422026/10/25 19:48:47 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127432026/10/25 19:48:47 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3674170713/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat3674170713/002/locked/aaa: permission denied"27442026/10/25 19:48:47 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path2788493932/001/nonexistent27452026/10/25 19:48:47 INFO Uploading batch count=427462026/10/25 19:48:47 ERROR Upload failed error="upload failed" count=427472026/10/25 19:48:47 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127482026/10/25 19:48:47 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path2788493932/001/nonexistent27492026/10/25 19:48:47 INFO Upload queue status pending=327502026/10/25 19:48:47 INFO Uploading batch count=227512026/10/25 19:48:47 ERROR Upload failed error="upload failed" count=227522026/10/25 19:48:47 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown849295130/002/c2753--- PASS: TestQueueDeduplication (0.48s)27542026/10/25 19:48:47 INFO Uploading batch count=127552026/10/25 19:48:47 ERROR Upload failed error="upload failed" count=127562026/10/25 19:48:47 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127572026/10/25 19:48:47 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2746934686/002/bbb2758--- PASS: TestQueueFetchBatchLimit (0.48s)27592026/10/25 19:48:47 INFO Uploading batch count=227602026/10/25 19:48:47 INFO Uploading batch count=127612026/10/25 19:48:47 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown849295130/002/d27622026/10/25 19:48:47 ERROR Drain finished with paths left in queue remaining=127632026/10/25 19:48:47 ERROR Upload failed error="upload failed" count=127642026/10/25 19:48:47 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat3674170713/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat3674170713/002/locked/aaa: permission denied"27652026/10/25 19:48:47 INFO Uploading batch count=127662026/10/25 19:48:47 ERROR Drain finished with paths left in queue remaining=127672026/10/25 19:48:47 INFO Uploading batch count=227682026/10/25 19:48:47 ERROR Upload failed error="upload failed" count=227692026/10/25 19:48:47 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown849295130/002/e2770--- PASS: TestQueueRemove (0.48s)27712026/10/25 19:48:47 INFO Uploading batch count=127722026/10/25 19:48:47 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown849295130/002/f27732026/10/25 19:48:47 ERROR Upload failed error="upload failed" count=127742026/10/25 19:48:47 INFO Uploading batch count=12775--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.49s)2776--- PASS: TestWorkerKeepsPathItCannotStat (0.50s)27772026/10/25 19:48:47 INFO Uploading batch count=127782026/10/25 19:48:47 ERROR Upload failed error="upload failed" count=127792026/10/25 19:48:47 ERROR Drain finished with paths left in queue remaining=102780--- PASS: TestWorkerUploadsAndRemoves (0.51s)2781--- PASS: TestWorkerSkipsGCdPaths (0.50s)27822026/10/25 19:48:47 INFO Uploading batch count=127832026/10/25 19:48:47 ERROR Upload failed error="upload failed" count=127842026/10/25 19:48:47 ERROR Drain finished with paths left in queue remaining=127852026/10/25 19:48:47 INFO Upload queue status pending=227862026/10/25 19:48:47 INFO Upload queue status pending=22787--- PASS: TestFailedPathPrunedByLaterClosure (0.51s)2788--- PASS: TestDrainGivesUpWhenServerDown (0.50s)27892026/10/25 19:48:47 INFO Uploading batch count=227902026/10/25 19:48:47 INFO Uploading batch count=22791--- PASS: TestWorkerPrunesClosureDeps (0.51s)27922026/10/25 19:48:47 INFO Uploading batch count=227932026/10/25 19:48:47 ERROR Upload failed error="upload failed" count=227942026/10/25 19:48:47 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=12795--- PASS: TestDrainIsolatesPoisonPath (0.50s)27962026/10/25 19:48:47 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127972026/10/25 19:48:47 INFO Uploading batch count=227982026/10/25 19:48:47 ERROR Upload failed error="upload failed" count=227992026/10/25 19:48:47 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128002026/10/25 19:48:47 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128012026/10/25 19:48:47 INFO Uploading batch count=228022026/10/25 19:48:47 ERROR Upload failed error="upload failed" count=228032026/10/25 19:48:47 INFO Uploading batch count=228042026/10/25 19:48:47 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128052026/10/25 19:48:47 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=128062026/10/25 19:48:47 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228072026/10/25 19:48:47 ERROR Drain finished with paths left in queue remaining=228082026/10/25 19:48:47 INFO Uploading batch count=228092026/10/25 19:48:47 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228102026/10/25 19:48:47 INFO Uploading batch count=228112026/10/25 19:48:47 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=228122026/10/25 19:48:47 ERROR Drain finished with paths left in queue remaining=22813--- PASS: TestWorkerRemoveFailureIsNotProgress (0.01s)2814 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.15s)2815 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.17s)2816 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.06s)28172026/10/25 19:48:47 ERROR Accept failed error="too many open files"28182026/10/25 19:48:48 ERROR Drain finished with paths left in queue remaining=428192026/10/25 19:48:48 ERROR Upload failed error="context canceled" count=228202026/10/25 19:48:48 ERROR Drain finished with paths left in queue remaining=42821--- PASS: TestDrainTimeout (0.68s)28222026/10/25 19:48:48 ERROR Upload failed error="context canceled" count=228232026/10/25 19:48:48 ERROR Drain finished with paths left in queue remaining=22824--- PASS: TestShutdownFinishesInFlightPush (0.01s)2825 --- PASS: TestShutdownFinishesInFlightPush/completes (0.15s)2826 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.23s)28272026/10/25 19:48:48 ERROR Drain finished with paths left in queue remaining=32828--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2829 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.64s)2830 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.77s)28312026/10/25 19:48:48 ERROR Accept failed error="too many open files"2832--- PASS: TestServerBacksOffOnAcceptErrors (0.95s)2833--- PASS: TestQueueConcurrentWriters (0.99s)28342026/10/25 19:48:48 INFO Uploading batch count=128352026/10/25 19:48:48 INFO Uploading batch count=128362026/10/25 19:48:48 INFO Uploading batch count=128372026/10/25 19:48:48 ERROR Upload failed error="upload failed" count=128382026/10/25 19:48:48 INFO Uploading batch count=128392026/10/25 19:48:48 ERROR Upload failed error="upload failed" count=128402026/10/25 19:48:48 INFO Uploading batch count=128412026/10/25 19:48:48 ERROR Upload failed error="upload failed" count=128422026/10/25 19:48:48 INFO Uploading batch count=128432026/10/25 19:48:48 ERROR Upload failed error="upload failed" count=128442026/10/25 19:48:48 ERROR Drain finished with paths left in queue remaining=12845--- PASS: TestRunNotBlockedByPoisonHead (1.53s)2846--- PASS: TestQueueRemoveLargeClosure (3.28s)2847--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.46s)2848PASS2849Running signing tests...2850=== RUN TestExternalSigner2851=== PAUSE TestExternalSigner2852=== RUN TestExternalSignerWrongPublicKey2853=== PAUSE TestExternalSignerWrongPublicKey2854=== RUN TestExternalSignerErrors2855=== PAUSE TestExternalSignerErrors2856=== RUN TestExternalSignerRestartsAfterCrash2857=== PAUSE TestExternalSignerRestartsAfterCrash2858=== RUN TestExternalSignerProgramErrorKeepsProcess2859=== PAUSE TestExternalSignerProgramErrorKeepsProcess2860=== RUN TestExternalSignerClose2861=== PAUSE TestExternalSignerClose2862=== RUN TestExternalSignerRejectsInvalidPublicKey2863=== PAUSE TestExternalSignerRejectsInvalidPublicKey2864=== RUN TestExternalSignerCancellation2865=== PAUSE TestExternalSignerCancellation2866=== RUN TestGenerateFingerprint2867=== PAUSE TestGenerateFingerprint2868=== RUN TestParseSigningKey2869=== PAUSE TestParseSigningKey2870=== RUN TestSign2871=== PAUSE TestSign2872=== RUN TestSignBatch2873=== PAUSE TestSignBatch2874=== RUN TestNilKeyPublicKey2875=== PAUSE TestNilKeyPublicKey2876=== RUN TestSignErrors2877=== PAUSE TestSignErrors2878=== CONT TestExternalSignerWrongPublicKey2879=== CONT TestSignErrors2880=== CONT TestSignBatch2881=== RUN TestSignErrors/nil_key2882=== PAUSE TestSignErrors/nil_key2883=== RUN TestSignErrors/nil_narinfo2884=== PAUSE TestSignErrors/nil_narinfo2885=== CONT TestExternalSignerProgramErrorKeepsProcess2886--- PASS: TestExternalSignerWrongPublicKey (0.02s)2887=== CONT TestExternalSignerRejectsInvalidPublicKey2888=== RUN TestExternalSignerRejectsInvalidPublicKey/#002889=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002890=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2891=== CONT TestSign2892=== CONT TestNilKeyPublicKey2893=== CONT TestGenerateFingerprint2894=== CONT TestParseSigningKey2895=== CONT TestExternalSignerCancellation2896=== CONT TestExternalSignerRestartsAfterCrash2897=== RUN TestSignErrors/invalid_narinfo2898=== CONT TestExternalSigner2899=== CONT TestExternalSignerErrors2900=== CONT TestExternalSignerClose2901--- PASS: TestNilKeyPublicKey (0.00s)2902=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2903=== RUN TestGenerateFingerprint/basic_with_references2904=== RUN TestParseSigningKey/valid_32-byte_key2905=== PAUSE TestSignErrors/invalid_narinfo2906=== RUN TestExternalSignerErrors/missing_signature_name2907=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2908=== PAUSE TestGenerateFingerprint/basic_with_references2909=== PAUSE TestParseSigningKey/valid_32-byte_key2910=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2911=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2912=== RUN TestSignErrors/canceled2913=== PAUSE TestSignErrors/canceled2914=== PAUSE TestExternalSignerErrors/missing_signature_name2915=== RUN TestExternalSignerErrors/wrong_signature_name2916=== PAUSE TestExternalSignerErrors/wrong_signature_name2917=== RUN TestExternalSignerErrors/invalid_signature_base642918=== PAUSE TestExternalSignerErrors/invalid_signature_base642919--- PASS: TestSign (0.00s)2920=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2921=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2922=== CONT TestSignErrors/invalid_narinfo2923=== RUN TestExternalSignerErrors/null_signatures2924--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2925=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2926=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2927=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2928=== PAUSE TestExternalSignerErrors/null_signatures2929=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2930=== RUN TestGenerateFingerprint/no_references2931=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2932=== RUN TestExternalSignerErrors/wrong_signature_length2933=== RUN TestParseSigningKey/no_colon2934=== PAUSE TestGenerateFingerprint/no_references2935=== PAUSE TestParseSigningKey/no_colon2936=== RUN TestParseSigningKey/empty_name2937=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2938=== PAUSE TestParseSigningKey/empty_name2939=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2940=== RUN TestParseSigningKey/invalid_base642941=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2942=== PAUSE TestParseSigningKey/invalid_base642943=== RUN TestParseSigningKey/wrong_length2944=== CONT TestSignErrors/nil_narinfo2945=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2946=== PAUSE TestParseSigningKey/wrong_length2947=== RUN TestGenerateFingerprint/invalid_nar_hash_length2948=== CONT TestParseSigningKey/no_colon2949=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2950=== RUN TestGenerateFingerprint/invalid_store_path_prefix2951=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2952=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2953=== RUN TestGenerateFingerprint/invalid_reference_prefix2954=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2955=== CONT TestGenerateFingerprint/no_references2956=== CONT TestGenerateFingerprint/invalid_store_path_prefix2957=== CONT TestGenerateFingerprint/invalid_reference_prefix2958=== CONT TestGenerateFingerprint/invalid_nar_hash_length2959=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2960=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2961=== CONT TestGenerateFingerprint/basic_with_references2962=== CONT TestParseSigningKey/valid_32-byte_key2963--- PASS: TestGenerateFingerprint (0.01s)2964 --- PASS: TestGenerateFingerprint/no_references (0.00s)2965 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2966 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2967 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2968 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2969 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2970 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2971=== CONT TestParseSigningKey/invalid_base642972=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2973=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2974--- PASS: TestSignBatch (0.01s)2975=== CONT TestExternalSignerRejectsInvalidPublicKey/#002976=== PAUSE TestExternalSignerErrors/wrong_signature_length2977=== CONT TestSignErrors/nil_key2978=== CONT TestParseSigningKey/wrong_length2979=== CONT TestParseSigningKey/empty_name2980=== CONT TestSignErrors/canceled2981--- PASS: TestExternalSignerClose (0.00s)2982=== RUN TestExternalSignerErrors/exit_at_startup2983=== PAUSE TestExternalSignerErrors/exit_at_startup2984=== RUN TestExternalSignerErrors/exit_on_request2985=== PAUSE TestExternalSignerErrors/exit_on_request2986=== RUN TestExternalSignerErrors/missing_signatures2987--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.01s)2988 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2989 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2990 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2991 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2992 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2993=== PAUSE TestExternalSignerErrors/missing_signatures2994--- PASS: TestParseSigningKey (0.01s)2995 --- PASS: TestParseSigningKey/no_colon (0.00s)2996 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2997 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2998 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2999 --- PASS: TestParseSigningKey/wrong_length (0.00s)3000 --- PASS: TestParseSigningKey/empty_name (0.00s)3001=== RUN TestExternalSignerErrors/too_few_signatures3002=== PAUSE TestExternalSignerErrors/too_few_signatures3003=== RUN TestExternalSignerErrors/program_error3004=== PAUSE TestExternalSignerErrors/program_error3005=== RUN TestExternalSignerErrors/wrong_shape3006=== PAUSE TestExternalSignerErrors/wrong_shape3007=== RUN TestExternalSignerErrors/null3008--- PASS: TestSignErrors (0.02s)3009 --- PASS: TestSignErrors/invalid_narinfo (0.00s)3010 --- PASS: TestSignErrors/nil_narinfo (0.00s)3011 --- PASS: TestSignErrors/nil_key (0.00s)3012 --- PASS: TestSignErrors/canceled (0.00s)3013=== PAUSE TestExternalSignerErrors/null3014=== RUN TestExternalSignerErrors/invalid_JSON3015=== PAUSE TestExternalSignerErrors/invalid_JSON3016=== RUN TestExternalSignerErrors/wrong_id3017=== PAUSE TestExternalSignerErrors/wrong_id3018=== RUN TestExternalSignerErrors/wrong_signatures_shape3019=== PAUSE TestExternalSignerErrors/wrong_signatures_shape3020=== RUN TestExternalSignerErrors/unrequested_key3021=== PAUSE TestExternalSignerErrors/unrequested_key3022=== CONT TestExternalSignerErrors/invalid_signature_base643023=== CONT TestExternalSignerErrors/wrong_signatures_shape3024=== CONT TestExternalSignerErrors/missing_signatures3025=== CONT TestExternalSignerErrors/wrong_shape3026=== CONT TestExternalSignerErrors/wrong_signature_length3027=== CONT TestExternalSignerErrors/exit_on_request3028=== CONT TestExternalSignerErrors/wrong_id3029=== CONT TestExternalSignerErrors/exit_at_startup3030=== CONT TestExternalSignerErrors/invalid_JSON3031=== CONT TestExternalSignerErrors/null3032=== CONT TestExternalSignerErrors/unrequested_key3033--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)3034=== CONT TestExternalSignerErrors/program_error3035=== CONT TestExternalSignerErrors/null_signatures3036=== CONT TestExternalSignerErrors/too_few_signatures3037=== CONT TestExternalSignerErrors/wrong_signature_name3038=== CONT TestExternalSignerErrors/missing_signature_name3039--- PASS: TestExternalSignerErrors (0.01s)3040 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.00s)3041 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)3042 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)3043 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)3044 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.00s)3045 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)3046 --- PASS: TestExternalSignerErrors/invalid_JSON (0.01s)3047 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)3048 --- PASS: TestExternalSignerErrors/null (0.01s)3049 --- PASS: TestExternalSignerErrors/exit_on_request (0.01s)3050 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)3051 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)3052 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.01s)3053 --- PASS: TestExternalSignerErrors/program_error (0.01s)3054 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)3055 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)3056--- PASS: TestExternalSignerCancellation (0.02s)3057--- PASS: TestExternalSigner (0.02s)3058PASS3059Running OpenBao signer tests...3060=== RUN TestSign3061=== PAUSE TestSign3062=== RUN TestSignErrors3063=== PAUSE TestSignErrors3064=== RUN TestServe3065=== PAUSE TestServe3066=== RUN TestServeRejectsGarbage3067=== PAUSE TestServeRejectsGarbage3068=== CONT TestSignErrors3069=== CONT TestServeRejectsGarbage3070=== CONT TestServe3071=== RUN TestSignErrors/http_error3072--- PASS: TestServeRejectsGarbage (0.00s)3073=== PAUSE TestSignErrors/http_error3074=== RUN TestSignErrors/invalid_json3075=== PAUSE TestSignErrors/invalid_json3076=== CONT TestSign3077--- PASS: TestServe (0.00s)3078=== RUN TestSignErrors/no_prefix3079=== PAUSE TestSignErrors/no_prefix3080=== RUN TestSignErrors/invalid_base643081=== PAUSE TestSignErrors/invalid_base643082=== CONT TestSignErrors/invalid_json3083=== CONT TestSignErrors/invalid_base643084=== CONT TestSignErrors/no_prefix3085=== CONT TestSignErrors/http_error3086--- PASS: TestSign (0.04s)3087--- PASS: TestSignErrors (0.00s)3088 --- PASS: TestSignErrors/invalid_json (0.04s)3089 --- PASS: TestSignErrors/no_prefix (0.03s)3090 --- PASS: TestSignErrors/http_error (0.04s)3091 --- PASS: TestSignErrors/invalid_base64 (0.04s)3092PASS3093Running niks3-hook command tests...3094=== RUN TestServeSecondSignalEndsDrain3095=== PAUSE TestServeSecondSignalEndsDrain3096=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown3097=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown3098=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown3099=== CONT TestServeSecondSignalEndsDrain3100--- PASS: TestServeSecondSignalEndsDrain (0.08s)31012026/10/25 19:48:57 INFO Upload queue status pending=131022026/10/25 19:48:57 INFO Uploading batch count=13103--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.14s)3104PASS3105Running rate limiter tests...3106=== RUN TestAdaptiveRateLimiter_ThreadSafety3107=== PAUSE TestAdaptiveRateLimiter_ThreadSafety3108=== CONT TestAdaptiveRateLimiter_ThreadSafety31092026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=112.7357000000000731102026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=78.9149900000000531112026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=55.2404930000000331122026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=38.6683451000000231132026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=27.0678415700000131142026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=18.94748909900000631152026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=13.26324236930000431162026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=9.28426965851000231172026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=6.49898876095700131182026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531192026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531202026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531212026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531222026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531232026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531242026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531252026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531262026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531272026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531282026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531292026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531302026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531312026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531322026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531332026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531342026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531352026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531362026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531372026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531382026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531392026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531402026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531412026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531422026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531432026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531442026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531452026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531462026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531472026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531482026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531492026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531502026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531512026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531522026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531532026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531542026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531552026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531562026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531572026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531582026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531592026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531602026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531612026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531622026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531632026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531642026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531652026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531662026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531672026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531682026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531692026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531702026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531712026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531722026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531732026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531742026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531752026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531762026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531772026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531782026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531792026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531802026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531812026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=5.12435000000000131822026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531832026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531842026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531852026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531862026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531872026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531882026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=5.12435000000000131892026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531902026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531912026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531922026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531932026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531942026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531952026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=8.25281691850000431962026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=5.77697184295000331972026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531982026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=531992026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=532002026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=532012026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=532022026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=532032026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=12.0829492503758632042026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=8.45806447526310232052026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=5.92064513268417132062026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=9.77240006389012632072026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=6.84068004472308832082026/10/25 19:48:58 WARN Rate limiter backed off name=test rate=53209--- PASS: TestAdaptiveRateLimiter_ThreadSafety (0.08s)3210PASS